[Dovecot] Dovecot 1.1.11 failing to accept SSL/TLS connections

[Mike Brudenell]

Hi (again!) Timo,
2009/3/19 Mike Brudenell <pmb1 at azilo.me.uk>

>
> Grepping the code suggests this is presumably coming
> from src/imap-login/client.c
>
> I'm now peering at the code trying to see if I can spot anything, but have
> to confess to not being too wonderful in the area of sockets etc.
>
> Cheers,
> Mike B-)
>

I've been peering at the code in src/imap-login/client.c and in particular
at client_destroy_oldest() trying to see if there's a way it could end up
killing itself, thinking it was the oldest.

So far I've not got anywhere, other than giving myself a headache, and it's
time for me to go home now.

Just one slight oddity I can't quite fathom...

If I understand client_destroy_oldest() correctly it should destroy a number
of clients when it gets called. In our case login_max_connections is 256, so
I'm thinking that

        destroy_count = max_connections > CLIENT_DESTROY_OLDEST_COUNT*2 ?
                CLIENT_DESTROY_OLDEST_COUNT : I_MIN(max_connections/2, 1);

should set destroy_count to CLIENT_DESTROY_OLDEST_COUNT, which is 16. So I
was expecting to see 16 messages in the log saying "Disconnected: Connection
queue full": one as each client was disconnected, and that these would
therefore appear in very quick succession.

Yet in reality although the message is logged frequently I wouldn't say it
was a quick burst of 16. I'm including an extract of these grepped from the
log (with IP addresses obfuscated for privacy) so you can see what I mean
from their timestamps:

% fgrep 'Connection queue full' dovecot | tail -32
dovecot: Mar 19 13:34:55 Info: imap-login: Disconnected: Connection queue
full (no auth attempts): rip=144.32.N.N, lip=144.32.N.N
dovecot: Mar 19 13:34:55 Info: imap-login: Disconnected: Connection queue
full (no auth attempts): rip=144.32.N.N, lip=144.32.N.N
dovecot: Mar 19 13:34:57 Info: imap-login: Disconnected: Connection queue
full (no auth attempts): rip=144.32.N.N, lip=144.32.N.N, TLS
dovecot: Mar 19 13:34:57 Info: imap-login: Disconnected: Connection queue
full (no auth attempts): rip=144.32.N.N, lip=144.32.N.N
dovecot: Mar 19 13:34:57 Info: imap-login: Disconnected: Connection queue
full (no auth attempts): rip=144.32.N.N, lip=144.32.N.N, TLS handshaking
dovecot: Mar 19 13:35:04 Info: imap-login: Disconnected: Connection queue
full (no auth attempts): rip=82.132.N.N, lip=144.32.N.N, TLS handshaking
dovecot: Mar 19 13:35:09 Info: imap-login: Disconnected: Connection queue
full (no auth attempts): rip=82.132.N.N, lip=144.32.N.N, TLS
dovecot: Mar 19 13:35:09 Info: imap-login: Disconnected: Connection queue
full (no auth attempts): rip=144.32.N.N, lip=144.32.N.N
dovecot: Mar 19 13:36:06 Info: imap-login: Disconnected: Connection queue
full (auth failed, 1 attempts): method=PLAIN, rip=144.32.N.N, lip=144.32.N.N
dovecot: Mar 19 13:36:08 Info: imap-login: Disconnected: Connection queue
full (no auth attempts): rip=144.32.N.N, lip=144.32.N.N
dovecot: Mar 19 13:36:11 Info: imap-login: Disconnected: Connection queue
full (no auth attempts): rip=144.32.N.N, lip=144.32.N.N
dovecot: Mar 19 13:36:15 Info: imap-login: Disconnected: Connection queue
full (no auth attempts): rip=144.32.N.N, lip=144.32.N.N
dovecot: Mar 19 13:36:15 Info: imap-login: Disconnected: Connection queue
full (no auth attempts): rip=144.32.N.N, lip=144.32.N.N
dovecot: Mar 19 13:36:31 Info: imap-login: Disconnected: Connection queue
full (auth failed, 1 attempts): user=<USERNAME>, method=PLAIN,
rip=144.32.N.N, lip=144.32.N.N
dovecot: Mar 19 13:36:31 Info: imap-login: Disconnected: Connection queue
full (no auth attempts): rip=144.32.N.N, lip=144.32.N.N, TLS
dovecot: Mar 19 13:36:54 Info: imap-login: Disconnected: Connection queue
full (no auth attempts): rip=144.32.N.N, lip=144.32.N.N
dovecot: Mar 19 13:36:54 Info: imap-login: Disconnected: Connection queue
full (no auth attempts): rip=144.32.N.N, lip=144.32.N.N
dovecot: Mar 19 13:37:02 Info: imap-login: Disconnected: Connection queue
full (no auth attempts): rip=144.32.N.N, lip=144.32.N.N
dovecot: Mar 19 13:37:26 Info: imap-login: Disconnected: Connection queue
full (no auth attempts): rip=144.32.N.N, lip=144.32.N.N
dovecot: Mar 19 13:37:39 Info: imap-login: Disconnected: Connection queue
full (no auth attempts): rip=82.132.N.N, lip=144.32.N.N, TLS
dovecot: Mar 19 13:37:50 Info: imap-login: Disconnected: Connection queue
full (no auth attempts): rip=144.32.N.N, lip=144.32.N.N, TLS
dovecot: Mar 19 13:38:08 Info: imap-login: Disconnected: Connection queue
full (no auth attempts): rip=144.32.N.N, lip=144.32.N.N, TLS
dovecot: Mar 19 13:38:08 Info: imap-login: Disconnected: Connection queue
full (no auth attempts): rip=86.129.N.N, lip=144.32.N.N, TLS handshaking
dovecot: Mar 19 13:38:09 Info: imap-login: Disconnected: Connection queue
full (no auth attempts): rip=144.32.N.N, lip=144.32.N.N, TLS
dovecot: Mar 19 13:38:09 Info: imap-login: Disconnected: Connection queue
full (no auth attempts): rip=144.32.N.N, lip=144.32.N.N, TLS handshaking
dovecot: Mar 19 13:38:18 Info: imap-login: Disconnected: Connection queue
full (no auth attempts): rip=144.32.N.N, lip=144.32.N.N
dovecot: Mar 19 13:38:20 Info: imap-login: Disconnected: Connection queue
full (no auth attempts): rip=144.32.N.N, lip=144.32.N.N
dovecot: Mar 19 13:38:27 Info: imap-login: Disconnected: Connection queue
full (no auth attempts): rip=144.32.N.N, lip=144.32.N.N
dovecot: Mar 19 13:38:30 Info: imap-login: Disconnected: Connection queue
full (no auth attempts): rip=144.32.N.N, lip=144.32.N.N
dovecot: Mar 19 13:38:30 Info: imap-login: Disconnected: Connection queue
full (no auth attempts): rip=144.32.N.N, lip=144.32.N.N, TLS handshaking
dovecot: Mar 19 13:38:35 Info: imap-login: Disconnected: Connection queue
full (no auth attempts): rip=144.32.N.N, lip=144.32.N.N
dovecot: Mar 19 13:38:36 Info: imap-login: Disconnected: Connection queue
full (no auth attempts): rip=144.32.N.N, lip=144.32.N.N
%

Just thought I'd mention it in case it gives you any ideas.

Cheers,
Mike B-)