IMAP over SSL (only) handshake hangs

Patrick Boutilier boutilpj at ednet.ns.ca
Sat Nov 9 18:34:13 EST 2019 

Almost sounds like you are running out of entropy. What does this show?

cat /proc/sys/kernel/random/entropy_avail



On 11/9/19 7:16 PM, Helder Guerreiro via Info-cyrus wrote:
> Hi all
> 
> I'm having this exact same problem. Once the daemon is up it takes a 
> while (a random while) to get to this state.
> 
> I'm on Debian 9.11 (stretch) which still is on Cyrus imap 2.5.10.
> 
> Any help would be very much appreciated.
> 
> /Helder
> 
> On 13/01/2015 10.22, Niels Dettenbach wrote:
>> 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
> ----
> 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

-------------- next part --------------
A non-text attachment was scrubbed...
Name: boutilpj.vcf
Type: text/x-vcard
Size: 286 bytes
Desc: not available
URL: <http://lists.andrew.cmu.edu/pipermail/info-cyrus/attachments/20191109/65a5a9f1/attachment.vcf>

More information about the Info-cyrus mailing list