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(00000003)
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))
0000 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]: done recovering cyrus
databases
Jan 13 11:07:55 blade4 master[26043]: about to exec
/usr/lib64/cyrus/idled
Jan 13 11:07:55 blade4 master[25695]: unable to setsocketopt(IP_TOS):
Operation not supported
Jan 13 11:07:55 blade4 master[25695]: ready for work
Jan 13 11:07:55 blade4 master[26046]: about to exec
/usr/lib64/cyrus/ctl_deliver
Jan 13 11:07:55 blade4 master[26047]: about to exec
/usr/lib64/cyrus/ctl_cyrusdb
Jan 13 11:07:55 blade4 master[26045]: about to exec
/usr/lib64/cyrus/tls_prune
Jan 13 11:07:56 blade4 cyr_expire[26046]: SQL backend defaulting to
engine
'sqlite'
Jan 13 11:07:56 blade4 ctl_cyrusdb[26047]: SQL backend defaulting to
engine
'sqlite'
Jan 13 11:07:56 blade4 ctl_cyrusdb[26047]: checkpointing cyrus databases
Jan 13 11:07:56 blade4 ctl_cyrusdb[26047]: archiving database file:
/email/lib/cyrus/mailboxes.db
Jan 13 11:07:56 blade4 tls_prune[26045]: SQL backend defaulting to engine
'sqlite'
Jan 13 11:07:56 blade4 idled[26044]: SQL backend defaulting to engine
'sqlite'
Jan 13 11:07:56 blade4 ctl_cyrusdb[26047]: archiving database file:
/email/lib/cyrus/annotations.db
Jan 13 11:07:56 blade4 ctl_cyrusdb[26047]: done checkpointing cyrus
databases
Jan 13 11:07:56 blade4 master[25695]: process 26047 exited, status 0
Jan 13 11:07:56 blade4 tls_prune[26045]: skiplist: checkpointed
/email/lib/cyrus/tls_sessions.db (1 record, 324 bytes) in 0 seconds
Jan 13 11:07:56 blade4 tls_prune[26045]: tls_prune: purged 0 out of 1
entries
Jan 13 11:07:56 blade4 master[25695]: process 26045 exited, status 0
Jan 13 11:07:56 blade4 cyr_expire[26046]: skiplist: checkpointed
/email/lib/cyrus/deliver.db (800 records, 120752 bytes) in 0 seconds
Jan 13 11:07:59 blade4 cyr_expire[26046]: Expunged 0 out of 475379
messages
from 477 mailboxes
Jan 13 11:07:59 blade4 cyr_expire[26046]: duplicate_prune: pruning
back 3.00
days
Jan 13 11:07:59 blade4 cyr_expire[26046]: duplicate_prune: purged 0
out of 800
entries
Jan 13 11:07:59 blade4 cyr_expire[26046]: DIGEST-MD5 common mech free
Jan 13 11:07:59 blade4 master[25695]: process 26046 exited, status 0
