Re: IMAP over SSL (only) handshake hangs
On 01/13/15 11:22 +0100, Niels Dettenbach wrote: While any other IMAP and POP3 ports with and without SSL / TLS are working - connects to imaps (993) just hangs, there is nothing in the logs and a openssl s_client -connect mail.myhost.abc:993 just brings out: CONNECTED(0003) what times out after minutes. Connection to 995 (POP3s) works perfectly. The service is configured (and worked until tonight!): imaps cmd=imapd -s listen=imaps prefork=0 maxchild=150 pop3s cmd=pop3d -s listen=pop3s prefork=0 maxchild=50 A crazy thing is, that connections to localhost seems to work as soon as it uses the IPv6 adress of the localhost (::): imtest -v -s localhost while the IPv4 variant doesnt seem to work: imtest -v -s 127.0.0.1 You may have something else running on tcp:imaps. Verify with: netstat -lp | grep imaps On 01/13/15 12:24 +0100, Niels Dettenbach wrote: Ive done a strace -f -p on the master process which brought out: See /usr/share/doc/cyrus-imapd-2.x/README.Debian.debug.gz for help in debugging a particular service. -- Dan White Cyrus Home Page: http://www.cyrusimap.org/ List Archives/Info: http://lists.andrew.cmu.edu/pipermail/info-cyrus/ To Unsubscribe: https://lists.andrew.cmu.edu/mailman/listinfo/info-cyrus
Re: IMAP over SSL (only) handshake hangs
Am Dienstag, 13. Januar 2015, 08:44:11 schrieben Sie: You may have something else running on tcp:imaps. Verify with: netstat -lp | grep imaps ...sorry, but no: tcp 14 0 0.0.0.0:993 0.0.0.0:* LISTEN 30543/master See /usr/share/doc/cyrus-imapd-2.x/README.Debian.debug.gz for help in debugging a particular service. This is a Debian file - will try to get and check it - may be they have some experience detail within which helps me in this scenario... At least strace gaves me not very useful details so far. many thanks too and best regards, Niels. -- --- Niels Dettenbach Syndicat IT Internet http://www.syndicat.com PGP: https://syndicat.com/pub_key.asc --- signature.asc Description: This is a digitally signed message part. Cyrus Home Page: http://www.cyrusimap.org/ List Archives/Info: http://lists.andrew.cmu.edu/pipermail/info-cyrus/ To Unsubscribe: https://lists.andrew.cmu.edu/mailman/listinfo/info-cyrus
Re: IMAP over SSL (only) handshake hangs
Is it possible you have reached the maxchild limit? --On 13. Januar 2015 11:22:44 +0100 Niels Dettenbach n...@syndicat.com wrote: today i've runned into a very suspicious problem never seen before: While any other IMAP and POP3 ports with and without SSL / TLS are working - connects to imaps (993) just hangs, there is nothing in the logs and a openssl s_client -connect mail.myhost.abc:993 just brings out: CONNECTED(0003) what times out after minutes. Connection to 995 (POP3s) works perfectly. A imtest -v -s against the IP of the machine hangs on: ... I tried to delete tls_sessions and even connecting to localhost (where it is bound too). netstat shows ESTABLISHED on such connections too. The service is configured (and worked until tonight!): imaps cmd=imapd -s listen=imaps prefork=0 maxchild=150 Mit freundlichen Grüßen Sebastian Hagedorn -- .:.Sebastian Hagedorn - Weyertal 121 (Gebäude 133), Zimmer 2.02.:. .:.Regionales Rechenzentrum (RRZK).:. .:.Universität zu Köln / Cologne University - ✆ +49-221-470-89578.:. p7sVxs1f0PMDa.p7s Description: S/MIME cryptographic signature Cyrus Home Page: http://www.cyrusimap.org/ List Archives/Info: http://lists.andrew.cmu.edu/pipermail/info-cyrus/ To Unsubscribe: https://lists.andrew.cmu.edu/mailman/listinfo/info-cyrus
Re: IMAP over SSL (only) handshake hangs
Am Dienstag, 13. Januar 2015, 11:41:30 schrieben Sie:
Is it possible you have reached the maxchild limit?
sorry, but no.
there is just one child and maxchild is 150 and there could be still
constructed new childs.
but thank you very much for your idea...
btw:
The timeout with openssl client gomes with:
write:errno=104
---
no peer certificate available
---
No client certificate CA names sent
---
SSL handshake has read 0 bytes and written 308 bytes
---
New, (NONE), Cipher is (NONE)
Secure Renegotiation IS NOT supported
Compression: NONE
Expansion: NONE
Ive done a
strace -f -p on the master process which brought out:
10.010180 select(43, [7 9 12 14 15 17 18 20 21 24 27 29 30 32 33 35 36 38
39 42], NULL, NULL, {0, 984890}) = 0 (Timeout)
0.986051 socket(PF_LOCAL, SOCK_STREAM, 0) = 44
0.55 connect(44, {sa_family=AF_LOCAL, sun_path=/var/agentx/master},
110) = -1 ENOENT (No such file or directory)
0.40 close(44) = 0
0.36 stat(/etc/resolv.conf, {st_dev=makedev(8, 1), st_ino=927140,
st_mode=S_IFREG|0644, st_nlink=1, st_uid=0, st_gid=0, st_blksize=4096,
st_blocks=8, st_size=115, st_atime=2015/01/06-02:10:04,
st_mtime=2015/01/13-07:30:41, st_ctime=2015/01/13-07:30:41}) = 0
0.48 open(/etc/hosts, O_RDONLY|O_CLOEXEC) = 44
0.31 fstat(44, {st_dev=makedev(8, 1), st_ino=788109, st_mode=S_IFREG|
0644, st_nlink=1, st_uid=0, st_gid=0, st_blksize=4096, st_blocks=8,
st_size=1226, st_atime=2015/01/05-13:34:28, st_mtime=2015/01/13-11:51:37,
st_ctime=2015/01/13-11:51:37}) = 0
0.45 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|
MAP_ANONYMOUS, -1, 0) = 0x7ff295338000
0.29 read(44, # /etc/hosts: Local Host Databas..., 4096) = 1226
0.76 read(44, , 4096)= 0
0.29 close(44) = 0
0.26 munmap(0x7ff295338000, 4096) = 0
0.35 socket(PF_INET, SOCK_STREAM, IPPROTO_IP) = 44
0.34 connect(44, {sa_family=AF_INET, sin_port=htons(705),
sin_addr=inet_addr(127.0.0.1)}, 16) = -1 ECONNREFUSED (Connection refused)
0.83 close(44) = 0
0.38 write(2, Warning: Failed to connect to th..., 64) = 64
0.39 select(43, [7 9 12 14 15 17 18 20 21 24 27 29 30 32 33 35 36 38
39 42], NULL, NULL, {9, 0}
) = 1 (in [12], left {4, 294718})
4.705369 read(12, \2\0\0\0008\32\0\0, 8) = 8
0.76 read(12, \3\0\0\0008\32\0\0, 8) = 8
0.36 read(12, 0x7fff1bb0bbe0, 8) = -1 EAGAIN (Resource temporarily
unavailable)
0.99 select(43, [7 9 11 12 14 15 17 18 20 21 24 27 29 30 32 33 35 36
38 39 42], NULL, NULL, {4, 0}) = 1 (in [12], left {3, 982250})
0.017874 read(12, \1\0\0\0008\32\0\0, 8) = 8
0.38 read(12, 0x7fff1bb0bbe0, 8) = -1 EAGAIN (Resource temporarily
unavailable)
0.000120 select(43, [7 9 12 14 15 17 18 20 21 24 27 29 30 32 33 35 36 38
39 42], NULL, NULL, {4, 0}
) = 0 (Timeout)
4.004195 select(43, [7 9 12 14 15 17 18 20 21 24 27 29 30 32 33 35 36 38
39 42], NULL, NULL, {6, 271546}) = 0 (Timeout)
6.278002 socket(PF_LOCAL, SOCK_STREAM, 0) = 44
0.56 connect(44, {sa_family=AF_LOCAL, sun_path=/var/agentx/master},
110) = -1 ENOENT (No such file or directory)
0.47 close(44) = 0
0.44 stat(/etc/resolv.conf, {st_dev=makedev(8, 1), st_ino=927140,
st_mode=S_IFREG|0644, st_nlink=1, st_uid=0, st_gid=0, st_blksize=4096,
st_blocks=8, st_size=115, st_atime=2015/01/06-02:10:04,
st_mtime=2015/01/13-07:30:41, st_ctime=2015/01/13-07:30:41}) = 0
0.63 open(/etc/hosts, O_RDONLY|O_CLOEXEC) = 44
0.34 fstat(44, {st_dev=makedev(8, 1), st_ino=788109, st_mode=S_IFREG|
0644, st_nlink=1, st_uid=0, st_gid=0, st_blksize=4096, st_blocks=8,
st_size=1226, st_atime=2015/01/05-13:34:28, st_mtime=2015/01/13-11:51:37,
st_ctime=2015/01/13-11:51:37}) = 0
0.40 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|
MAP_ANONYMOUS, -1, 0) = 0x7ff295338000
0.33 read(44, # /etc/hosts: Local Host Databas..., 4096) = 1226
0.52 read(44, , 4096)= 0
0.27 close(44) = 0
0.24 munmap(0x7ff295338000, 4096) = 0
0.47 socket(PF_INET, SOCK_STREAM, IPPROTO_IP) = 44
0.30 connect(44, {sa_family=AF_INET, sin_port=htons(705),
sin_addr=inet_addr(127.0.0.1)}, 16) = -1 ECONNREFUSED (Connection refused)
0.96 close(44) = 0
0.40 write(2, Warning: Failed to connect to th..., 64) = 64
0.34 select(43, [7 9 12 14 15 17 18 20 21 24 27 29 30 32 33 35 36 38
39 42], NULL, NULL, {4, 0}
) = 0 (Timeout)
4.004169 select(43, [7 9 12 14 15 17 18 20 21 24 27 29 30 32 33 35 36 38
39 42], NULL, NULL, {10, 0}) = ? ERESTARTNOHAND (To be restarted if no
handler)
7.662763 --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=6777,
si_uid=129, si_status=0, si_utime=0, si_stime=0} ---
IMAP over SSL (only) handshake hangs
Hi all, today i've runned into a very suspicious problem never seen before: While any other IMAP and POP3 ports with and without SSL / TLS are working - connects to imaps (993) just hangs, there is nothing in the logs and a openssl s_client -connect mail.myhost.abc:993 just brings out: CONNECTED(0003) what times out after minutes. Connection to 995 (POP3s) works perfectly. A imtest -v -s against the IP of the machine hangs on: starting TLS engine setting up TLS connection SSL_connect:before/connect initialization write to 7F185DDB6480 [7F185DDC48F3] (216 bytes = 216 (0xD8)) 16 03 01 00 d3 01 00 00|cf 03 01 da 39 78 63 50 0010 b3 95 c8 e9 2f 11 4c 6c|de 39 e2 01 d1 e5 da 34 0020 61 e7 8d a5 85 68 6d 7a|14 e0 59 00 00 5c c0 14 0030 c0 0a 00 39 00 38 00 88|00 87 c0 0f c0 05 00 35 0040 00 84 c0 13 c0 09 00 33|00 32 00 9a 00 99 00 45 0050 00 44 c0 0e c0 04 00 2f|00 96 00 41 00 07 c0 11 0060 c0 07 c0 0c c0 02 00 05|00 04 c0 12 c0 08 00 16 0070 00 13 c0 0d c0 03 00 0a|00 15 00 12 00 09 00 14 0080 00 11 00 08 00 06 00 03|00 ff 02 01 00 00 49 00 0090 0b 00 04 03 00 01 02 00|0a 00 34 00 32 00 0e 00 00a0 0d 00 19 00 0b 00 0c 00|18 00 09 00 0a 00 16 00 00b0 17 00 08 00 06 00 07 00|14 00 15 00 04 00 05 00 00c0 12 00 13 00 01 00 02 00|03 00 0f 00 10 00 11 00 00d0 23 00 00 00 0f 00 01 01| SSL_connect:SSLv3 write client hello A I tried to delete tls_sessions and even connecting to localhost (where it is bound too). netstat shows ESTABLISHED on such connections too. The service is configured (and worked until tonight!): imaps cmd=imapd -s listen=imaps prefork=0 maxchild=150 pop3s cmd=pop3d -s listen=pop3s prefork=0 maxchild=50 A crazy thing is, that connections to localhost seems to work as soon as it uses the IPv6 adress of the localhost (::): imtest -v -s localhost while the IPv4 variant doesnt seem to work: imtest -v -s 127.0.0.1 Because we did not use any IPv6 on that Gentoo machine i've disabled any IPv6 stuff now which doesnt seem to help. cyrus-imap is compiled with: berkdb nntp pam sieve snmp sqlite ssl tcpd without: -afs -kerberos -mysql -postgres -replication dev-libs/openssl is 1.0.1k compiled with: sse2 tls-heartbeat zlib without: -bindist -gmp -kerberos -rfc3779 -static-libs -test -vanilla anything under Intel Xeon (bare metal). many thanks for any help or ideas where to look further? Some logs: startup: Jan 13 11:06:41 blade4 master[12565]: about to exec /usr/lib64/cyrus/ctl_cyrusdb Jan 13 11:06:41 blade4 ctl_cyrusdb[12565]: SQL backend defaulting to engine 'sqlite' Jan 13 11:06:41 blade4 ctl_cyrusdb[12565]: recovering cyrus databases Jan 13 11:06:41 blade4 ctl_cyrusdb[12565]: skiplist: checkpointed /email/lib/cyrus/mailboxes.db (477 records, 60868 bytes) in 0 seconds Jan 13 11:06:41 blade4 ctl_cyrusdb[12565]: skiplist: checkpointed /email/lib/cyrus/annotations.db (0 records, 144 bytes) in 0 seconds Jan 13 11:06:42 blade4 ctl_cyrusdb[12565]: done recovering cyrus databases Jan 13 11:06:42 blade4 master[12595]: about to exec /usr/lib64/cyrus/idled Jan 13 11:06:42 blade4 master[12598]: about to exec /usr/lib64/cyrus/ctl_deliver Jan 13 11:06:42 blade4 master[12599]: about to exec /usr/lib64/cyrus/ctl_cyrusdb Jan 13 11:06:42 blade4 master[12597]: about to exec /usr/lib64/cyrus/tls_prune Jan 13 11:06:42 blade4 ctl_cyrusdb[12599]: SQL backend defaulting to engine 'sqlite' Jan 13 11:06:42 blade4 ctl_cyrusdb[12599]: checkpointing cyrus databases Jan 13 11:06:42 blade4 ctl_cyrusdb[12599]: archiving database file: /email/lib/cyrus/mailboxes.db Jan 13 11:06:42 blade4 ctl_cyrusdb[12599]: archiving database file: /email/lib/cyrus/annotations.db Jan 13 11:06:42 blade4 ctl_cyrusdb[12599]: done checkpointing cyrus databases Jan 13 11:06:42 blade4 tls_prune[12597]: skiplist: checkpointed /email/lib/cyrus/tls_sessions.db (1 record, 324 bytes) in 0 seconds Jan 13 11:06:42 blade4 cyr_expire[12598]: skiplist: checkpointed /email/lib/cyrus/deliver.db (804 records, 121348 bytes) in 0 seconds and: Jan 13 11:07:54 blade4 master[12559]: exiting on SIGTERM/SIGINT Jan 13 11:07:54 blade4 master[25695]: setrlimit: Unable to set file descriptors limit to -1: Operation not permitted Jan 13 11:07:54 blade4 master[25695]: retrying with 4096 (current max) Jan 13 11:07:54 blade4 master[25695]: process started Jan 13 11:07:54 blade4 master[25699]: about to exec /usr/lib64/cyrus/ctl_cyrusdb Jan 13 11:07:55 blade4 ctl_cyrusdb[25699]: SQL backend defaulting to engine 'sqlite' Jan 13 11:07:55 blade4 ctl_cyrusdb[25699]: recovering cyrus databases Jan 13 11:07:55 blade4 ctl_cyrusdb[25699]: skiplist: checkpointed /email/lib/cyrus/mailboxes.db (477 records, 60868 bytes) in 0 seconds Jan 13 11:07:55 blade4 ctl_cyrusdb[25699]: skiplist: checkpointed /email/lib/cyrus/annotations.db (0 records, 144 bytes) in 0 seconds Jan 13 11:07:55 blade4 ctl_cyrusdb[25699]:
