[Kolab-devel] IMAPD vs IMAPS
gelpi@corona.it
corona at gelpi.it
Wed Jan 25 19:32:16 CET 2006
Bernhard Reiter wrote:
> Am Montag, 23. Januar 2006 12:57 schrieb gelpi at corona.it:
>
>>Now I configured a client (thunderbird) to access 7 of these accounts
>>(about 1 GB data).
>>
>>All is doing well only if I connect using IMAPD (port 143).
>>
>>If I use imap over ssl (port 993) after a while I got some problems. It
>>seems that the connection closes or dies on the server without
>>notification to the client, that after a timeout must reconnect.
>>
>>This problem is more evident using a mac os x with mail (the client
>>included)
>
>
> It would be interesting to check if this is a generic upstream bug.
> Can you reproduce those problems with a vanilla cyrus imapd,
> maybe on a different distribution, too?
>
Next week I think I can do this test: on RedHat 9.0 install cyrus imapd
(now there is courier imap) and try to syncronized a mac over ssl.
> Another interesting aspect is if you have a similiar problem
> when using TLS over the 143 port. Have you tried this?
>
Yes the problem is the same.
>>Can someone tell me how can I debug what's happening?
>>
>
>
> You could try debugging methods on the imapd, like running
> it under strace to see what is happening while it pauses.
> The pause might also happen at the client of course.
Here is the imapd.log pid 1158 seems to be involved.
Jan 25 18:31:59 dafnen <debug> imap[1158]: executed
Jan 25 18:31:59 dafnen <debug> imap[1158]: accepted connection
Jan 25 18:31:59 dafnen <notice> imap[1158]: TLS server engine: cannot
load CA data
Jan 25 18:31:59 dafnen <debug> imap[1158]: mystore: starting txn 2147483807
Jan 25 18:31:59 dafnen <debug> imap[1158]: mystore: committing txn
2147483807
Jan 25 18:31:59 dafnen <notice> imap[1158]: starttls: TLSv1 with cipher
RC4-SHA (128/128 bits new) no authentication
Jan 25 18:31:59 dafnen <notice> imap[1158]: login: mac.gelpi.it
[192.168.255.5] liste at gelpi.it plaintext+TLS User logged in
Jan 25 18:31:59 dafnen <debug> imap[1158]: seen_db: user liste at gelpi.it
opened /kolab/var/imapd/domain/g/gelpi.it/user/l/lis
te.seen
Jan 25 18:31:59 dafnen <debug> imap[1158]: open: user liste at gelpi.it
opened INBOX
Jan 25 18:31:59 dafnen <debug> imap[1159]: executed
Jan 25 18:31:59 dafnen <debug> imap[1159]: accepted connection
Jan 25 18:31:59 dafnen <notice> imap[1159]: TLS server engine: cannot
load CA data
Jan 25 18:32:00 dafnen <debug> imap[1159]: mystore: starting txn 2147483809
Jan 25 18:32:00 dafnen <debug> imap[1159]: mystore: committing txn
2147483809
Jan 25 18:32:00 dafnen <notice> imap[1159]: starttls: TLSv1 with cipher
RC4-SHA (128/128 bits new) no authentication
Jan 25 18:32:00 dafnen <notice> imap[1159]: login: mac.gelpi.it
[192.168.255.5] liste at gelpi.it plaintext+TLS User logged in
Jan 25 18:32:00 dafnen <debug> imap[1159]: seen_db: user liste at gelpi.it
opened /kolab/var/imapd/domain/g/gelpi.it/user/l/lis
te.seen
Jan 25 18:32:00 dafnen <debug> imap[1159]: open: user liste at gelpi.it
opened INBOX/a-Attivissimo
Jan 25 18:32:01 dafnen <debug> imap[1158]: open: user liste at gelpi.it
opened INBOX/a-CAAT
Jan 25 18:32:01 dafnen <debug> imap[1159]: open: user liste at gelpi.it
opened INBOX/a-CERT
Jan 25 18:32:01 dafnen <debug> imap[1160]: executed
Jan 25 18:32:01 dafnen <debug> imap[1160]: accepted connection
Jan 25 18:32:01 dafnen <notice> imap[1160]: TLS server engine: cannot
load CA data
Jan 25 18:32:02 dafnen <debug> imap[1160]: mystore: starting txn 2147483811
Jan 25 18:32:02 dafnen <debug> imap[1160]: mystore: committing txn
2147483811
Jan 25 18:32:02 dafnen <notice> imap[1160]: starttls: TLSv1 with cipher
RC4-SHA (128/128 bits new) no authentication
Jan 25 18:32:02 dafnen <notice> imap[1160]: login: mac.gelpi.it
[192.168.255.5] liste at gelpi.it plaintext+TLS User logged in
Jan 25 18:32:02 dafnen <debug> imap[1160]: seen_db: user liste at gelpi.it
opened /kolab/var/imapd/domain/g/gelpi.it/user/l/lis
te.seen
Jan 25 18:32:02 dafnen <debug> imap[1160]: open: user liste at gelpi.it
opened INBOX/a-Coelum
The following is last message from pid 1158 for a minute
Jan 25 18:32:02 dafnen <debug> imap[1158]: open: user liste at gelpi.it
opened INBOX/a-CSIG
Jan 25 18:33:03 dafnen <debug> imap[1159]: open: user liste at gelpi.it
opened INBOX/a-Interlex
Jan 25 18:33:04 dafnen <debug> imap[1160]: open: user liste at gelpi.it
opened INBOX/a-JSR
Now pid 1158 restarted
Jan 25 18:33:04 dafnen <debug> imap[1158]: accepted connection
Jan 25 18:33:04 dafnen <debug> imap[1158]: mydelete: starting txn 2147483812
Jan 25 18:33:04 dafnen <debug> imap[1158]: mydelete: committing txn
2147483812
Jan 25 18:33:04 dafnen <debug> imap[1158]: mystore: starting txn 2147483813
Jan 25 18:33:04 dafnen <debug> imap[1158]: mystore: committing txn
2147483813
Jan 25 18:33:04 dafnen <notice> imap[1158]: starttls: TLSv1 with cipher
RC4-SHA (128/128 bits new) no authentication
Jan 25 18:33:04 dafnen <notice> imap[1158]: login: mac.gelpi.it
[192.168.255.5] liste at gelpi.it plaintext+TLS User logged in
Jan 25 18:33:04 dafnen <debug> imap[1158]: open: user liste at gelpi.it
opened INBOX/a-Kolab+Horde
Here follow strace of pid 1158 from last good write and the write at
restart.
I cant' understand this trace but I think interesting this line:
unlink("/kolab/var/imapd/proc/1158") = 0
You can found it in the trace below.
write(6, "Jan 25 18:32:02 dafnen <debug> i"..., 89) = 89
open("/kolab/var/imapd/msg/shutdown", O_RDONLY) = -1 ENOENT (No such
file or directory)
select(1, [0], NULL, NULL, {0, 0}) = 0 (Timeout)
write(1, "\27\3\1\1\204\376\255\36\207\265\36}\361\244*=d\33l\266"...,
393) = 393
time(NULL) = 1138210322
select(1, [0], NULL, NULL, {1800, 0}) = 1 (in [0], left {1800, 0})
time(NULL) = 1138210322
read(0, "\27\3\1\0005", 5) = 5
read(0, "\323\177\2211Q\377\215\310\234\3278>\221\22\300\270\262"...,
53) = 53
times({tms_utime=1, tms_stime=3, tms_cutime=0, tms_cstime=0}) = 68777247
stat64("cyrus.index", {st_mode=S_IFREG|0600, st_size=191176, ...}) = 0
fstat64(14, {st_mode=S_IFREG|0600, st_size=5041396, ...}) = 0
write(1, "\27\3\1\20\24&\302\262\7\'\n2\320\317vdg]4\34\351\0316"...,
4121) = 4121
write(1, "\27\3\1\20\24\v\367{9\347V!J\233%\242\300\323\301\0313"...,
4121) = 4121
write(1, "\27\3\1\20\24\\\263~\234\352\255Q\236\363\32Rr)\25\360"...,
4121) = 4121
write(1, "\27\3\1\20\24\4\244J\353V\fW\251\237\356P@?\205))z6\305"...,
4121) = 4121
write(1, "\27\3\1\20\24-\303\253\346\2407\217a\335\264\305\25\207"...,
4121) = 4121
write(1, "\27\3\1\20\24\336\35S\2146\224\311\\\200\227\346\21ml!"...,
4121) = 4121
write(1, "\27\3\1\20\0248R3\r\363\347\333\244;\363\27{\352\325,\23"...,
4121) = 4121
write(1, "\27\3\1\20\24\26\364X\335\17\366\27\373\0VTS\332\20\4\353"...,
4121) = 4121
write(1, "\27\3\1\20\24)\23?l\326\246\354\0\343\23\272\2;6\324\241"...,
4121) = 4121
write(1, "\27\3\1\20\24\300j\327\200\210Q\376=\247\331\356\312%\223"...,
4121) = 4121
write(1, "\27\3\1\20\24\324>\333\315\234:\276/\235a\215iq\264\27"...,
4121) = 4121
write(1, "\27\3\1\20\24\313\334[w\217\203\361=\32\266\'!\311\221"...,
4121) = 4121
write(1, "\27\3\1\20\24Q\3674\366\361\315\n\376\256oMl@\350\325\37"...,
4121) = 4121
write(1, "\27\3\1\20\24ySc\333n\262_\2255\335G\240\24Q6\0377U\267"...,
4121) = 4121
write(1, "\27\3\1\20\24\202\234\317\354#\260C\312\314\221\335Lf!"...,
4121) = 4121
write(1, "\27\3\1\20\24)\320+\363%\205\357\220\213(;Z\\\355We\35"...,
4121) = 4121
write(1, "\27\3\1\20\24\265\366\242\336\25\206E\217\377\342\376&"...,
4121) = 4121
write(1, "\27\3\1\20\24\242\f\246\30\t#\32\3559\366J#\244;--\221"...,
4121) = 4121
write(1, "\27\3\1\20\24\354\204\1u\237\336\5\1a\277\216+R\2225\202"...,
4121) = 4121
write(1, "\27\3\1\20\24\224i\250\4\371\26L;\273LZ\231\375\326o|\253"...,
4121) = 4121
write(1, "\27\3\1\20\24\22-\3625\276\372\255$^^Z\315XtLW\352\345"...,
4121) = 4121
write(1, "\27\3\1\20\24\235\nQ\200\250\324\20\10\300\264\227\334"...,
4121) = 4121
write(1, "\27\3\1\20\24\212\360\301,W\310M\35\204\363V\331\204\36"...,
4121) = 4121
write(1, "\27\3\1\20\24\275\327\307\376|}\4\206\276z\30\360h6|\30"...,
4121) = 4121
write(1, "\27\3\1\20\24\236\0312\r\325E\374\300,\230\331\312L\306"...,
4121) = 4121
write(1, "\27\3\1\20\24\3406\310,\2563\264\272t\326|\357\266+\374"...,
4121) = 4121
write(1, "\27\3\1\20\24\304\271\211\216sW\25\211\250\256\253\200"...,
4121) = 4121
write(1, "\27\3\1\20\24\3055\223\315l\37\220\267\3\342\370\227W\6"...,
4121) = 4121
write(1, "\27\3\1\20\24\3002T5\300N\271~3T\267c\256nq\3}G\245\261"...,
4121) = 4121
write(1, "\27\3\1\20\24\226\301\336\255\327B\324\234@\212b\240\0"...,
4121) = 4121
write(1, "\27\3\1\20\24]\211\270\320\257\263\245t\312\\\221n.\231"...,
4121) = 4121
write(1, "\27\3\1\20\24|\260\374\245\240:\266N\253\235\354u,#\352"...,
4121) = 4121
write(1, "\27\3\1\20\24\4\357+yr%>\352}\216\225\37\312\272\227\4"...,
4121) = 4121
write(1, "\27\3\1\20\24\t\213\265*L\t\320j`\0Fk\226>\3137\311h\324"...,
4121) = 4121
times({tms_utime=2, tms_stime=3, tms_cutime=0, tms_cstime=0}) = 68777261
open("/kolab/var/imapd/msg/shutdown", O_RDONLY) = -1 ENOENT (No such
file or directory)
select(1, [0], NULL, NULL, {0, 0}) = 0 (Timeout)
write(1, "\27\3\1\n\364\"\316\21\326\274\336<+C|\347s\372\361\27"...,
2809) = 2809
time(NULL) = 1138210322
select(1, [0], NULL, NULL, {1800, 0}) = 1 (in [0], left {1739, 890000})
time(NULL) = 1138210383
read(0, "\25\3\1\0\26", 5) = 5
read(0, "D\315\333\346F\216\v\320\362\267\270\30p:]\21\224\3471"..., 22)
= 22
close(10) = 0
munmap(0xb6a88000, 4096) = 0
unlink("/kolab/var/imapd/proc/1158") = 0
fcntl64(15, F_SETLKW, {type=F_WRLCK, whence=SEEK_SET, start=0, len=0}) = 0
fstat64(15, {st_mode=S_IFREG|0600, st_size=26044, ...}) = 0
stat64("/kolab/var/imapd/domain/g/gelpi.it/user/l/liste.seen",
{st_mode=S_IFREG|0600, st_size=26044, ...}) = 0
fcntl64(15, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=0, len=0}) = 0
munmap(0xb64b4000, 204800) = 0
munmap(0xb5fe2000, 5054464) = 0
close(12) = 0
munmap(0xb6a73000, 234) = 0
close(13) = 0
munmap(0xb6a2c000, 204800) = 0
close(14) = 0
munmap(0xb64e6000, 5054464) = 0
open("/dev/null", O_RDWR) = 10
shutdown(0, 0 /* receive */) = 0
dup2(10, 0) = 0
shutdown(1, 0 /* receive */) = 0
dup2(10, 1) = 1
shutdown(2, 0 /* receive */) = 0
dup2(10, 2) = 2
close(10) = 0
getpid() = 1158
write(3, "\1\0\0\0\206\4\0\0", 8) = 8
rt_sigaction(SIGALRM, {0x8081800, [], SA_ONESHOT}, NULL, 8) = 0
rt_sigaction(SIGHUP, {0x8081800, [], SA_RESTART|SA_ONESHOT}, NULL, 8) = 0
rt_sigaction(SIGINT, {0x8081800, [], SA_RESTART|SA_ONESHOT}, NULL, 8) = 0
rt_sigaction(SIGQUIT, {0x8081800, [], SA_RESTART|SA_ONESHOT}, NULL, 8) = 0
alarm(60) = 0
fcntl64(9, F_SETLKW, {type=F_WRLCK, whence=SEEK_SET, start=0, len=0}) = 0
stat64("/kolab/bin/imapd", {st_mode=S_IFREG|0755, st_size=2873824, ...}) = 0
accept(4, 0, NULL) = 10
fcntl64(9, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=0, len=0}) = 0
alarm(0) = 58
getpid() = 1158
write(3, "\2\0\0\0\206\4\0\0", 8) = 8
uname({sys="Linux", node="dafnen", ...}) = 0
getpid() = 1158
time(NULL) = 1138210384
stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=951, ...}) = 0
write(6, "Jan 25 18:33:04 dafnen <debug> i"..., 63) = 63
The full trace is about 400KB not compressed.
>
>
>>I don't know if this is connected to the fact that mac os x says that
>>/kolab/etc/kolab/cert.pem is not a valid x509 certificate. The reason
>>seems to be that there is not a root certificate over it.
>
>
> You can import the root certifcate of the try-out-ca that Kolab Server
> comes with. Please keep in mind that it actually it is not a full blown
> CA, but mainly serves the purpose of having something to work
> with when testing Kolab.
>
I already done this, but I think mac is confused because the root ca has
the same name as imap certifcate (both are for hostname).
>
>>When I display the certificate tree it is at root level and this seems
>>to be a problem. I'm investigating.
AG
More information about the devel
mailing list