Hello, and thank you in advance for your valuable time.
I am running Dovecot v1.0.rc15 on an OpenBSD 3.9 i386 machine (no time to upgrade yet). I downloaded the source from the dovecot site, compiled and installed without any problem. The server starts up find and runs for a while. After a few hours to a few days, the server stops sending the CAPABILITY statement when a client tries to login. I found a few descriptions of this problem on the web, but no satisfactory resolution.
I added some debugging code to the functions in auth-client.c and got the following traces. Included in this email are a successful login attempt, a failed attempt, and a startup trace. I am not a UNIX sockets guru and don't know the dovecot internals well enough to figure out what's wrong. I am happy to add/remove debugging code as requested to help track down the problem, although it may take a few days for the server to hang again. I hope someone can help me figure out the problem so my mail server works reliably!
Here is a successful login attempt.
Dec 9 10:34:45 myhost dovecot: imap-login: DEBUG:: auth_client_is_connected? Dec 9 10:34:45 myhost dovecot: imap-login: DEBUG:: auth_client_get_available_mechs Dec 9 10:34:45 myhost dovecot: imap-login: DEBUG:: auth_client_new Dec 9 10:34:45 myhost dovecot: imap-login: DEBUG:: auth_client_new_external Dec 9 10:34:45 myhost dovecot: imap-login: DEBUG:: auth_client_connect_missing_servers Dec 9 10:34:45 myhost dovecot: imap-login: DEBUG:: creating file descriptor for path... Dec 9 10:34:45 myhost dovecot: imap-login: default Dec 9 10:34:45 myhost dovecot: imap-login: DEBUG:: auth_client_set_connect_notify Dec 9 10:34:45 myhost dovecot: imap-login: DEBUG:: auth_client_find_mech Dec 9 10:34:45 myhost dovecot: imap-login: DEBUG:: auth_client_is_connected? Dec 9 10:34:47 myhost dovecot: imap-login: DEBUG:: auth_client_is_connected? Dec 9 10:34:47 myhost dovecot: imap-login: DEBUG:: auth_client_find_mech Dec 9 10:34:47 myhost dovecot: imap-login: Login: user=<myuser>, method=plain, rip=1.2.3.client, lip=1.2.3.server, TLS Dec 9 11:02:13 myhost dovecot: IMAP(myuser): Disconnected: Logged out Dec 9 11:02:13 myhost dovecot: imap-login: DEBUG:: auth_client_free Dec 9 11:02:13 myhost dovecot: imap-login: DEBUG:: auth_client_is_connected?
The "creating file" output is from auth_server_connection_new(...) and dumps the requested path on the next line. Following is a failed attempt. The failure messages continue about every 5 seconds thereafter until I kill dovecot and restart.
Dec 9 16:26:53 myhost dovecot: imap-login: DEBUG:: auth_client_is_connected? Dec 9 16:26:53 myhost dovecot: imap-login: DEBUG:: auth_client_get_available_mechs Dec 9 16:26:53 myhost dovecot: imap-login: DEBUG:: auth_client_new Dec 9 16:26:53 myhost dovecot: imap-login: DEBUG:: auth_client_new_external Dec 9 16:26:53 myhost dovecot: imap-login: DEBUG:: auth_client_connect_missing_servers Dec 9 16:26:53 myhost dovecot: imap-login: DEBUG:: auth_client_set_connect_notify Dec 9 16:26:58 myhost dovecot: imap-login: DEBUG:: reconnect_timeout Dec 9 16:26:58 myhost dovecot: imap-login: DEBUG:: auth_client_connect_missing_servers Dec 9 16:26:58 myhost dovecot: imap-login: DEBUG:: auth_client_is_connected? Dec 9 16:27:03 myhost dovecot: imap-login: DEBUG:: reconnect_timeout Dec 9 16:27:03 myhost dovecot: imap-login: DEBUG:: auth_client_connect_missing_servers Dec 9 16:27:03 myhost dovecot: imap-login: DEBUG:: auth_client_is_connected? Dec 9 16:27:04 myhost dovecot: imap-login: DEBUG:: auth_client_is_connected? Dec 9 16:27:04 myhost dovecot: imap-login: DEBUG:: auth_client_find_mech Dec 9 16:27:04 myhost dovecot: imap-login: Login: user=<myuser>, method=plain, rip=1.2.3.client, lip=1.2.3.server, TLS Dec 9 16:27:08 myhost dovecot: imap-login: DEBUG:: reconnect_timeout Dec 9 16:27:08 myhost dovecot: imap-login: DEBUG:: auth_client_connect_missing_servers Dec 9 16:27:08 myhost dovecot: imap-login: DEBUG:: auth_client_is_connected? Dec 9 16:27:13 myhost dovecot: imap-login: DEBUG:: reconnect_timeout Dec 9 16:27:13 myhost dovecot: imap-login: DEBUG:: auth_client_connect_missing_servers Dec 9 16:27:13 myhost dovecot: imap-login: DEBUG:: auth_client_is_connected? Dec 9 16:27:18 myhost dovecot: imap-login: DEBUG:: reconnect_timeout Dec 9 16:27:18 myhost dovecot: imap-login: DEBUG:: auth_client_connect_missing_servers Dec 9 16:27:18 myhost dovecot: imap-login: DEBUG:: auth_client_is_connected? Dec 9 16:27:23 myhost dovecot: imap-login: DEBUG:: reconnect_timeout
Here is the startup trace. After this I see 3 imap-login processes.
Dec 9 15:32:33 myhost dovecot: Dovecot v1.0.rc15 starting up Dec 9 15:32:33 myhost dovecot: Generating Diffie-Hellman parameters for the first time. This may take a while.. Dec 9 15:32:35 myhost dovecot: imap-login: DEBUG:: auth_client_new Dec 9 15:32:35 myhost dovecot: imap-login: DEBUG:: auth_client_new Dec 9 15:32:35 myhost dovecot: imap-login: DEBUG:: auth_client_new_external Dec 9 15:32:35 myhost dovecot: imap-login: DEBUG:: auth_client_new_external Dec 9 15:32:35 myhost dovecot: imap-login: DEBUG:: auth_client_connect_missing_servers Dec 9 15:32:35 myhost dovecot: imap-login: DEBUG:: auth_client_connect_missing_servers Dec 9 15:32:35 myhost dovecot: imap-login: DEBUG:: auth_client_new Dec 9 15:32:35 myhost dovecot: imap-login: DEBUG:: creating file descriptor for path... Dec 9 15:32:35 myhost dovecot: imap-login: DEBUG:: creating file descriptor for path... Dec 9 15:32:35 myhost dovecot: imap-login: DEBUG:: auth_client_new_external Dec 9 15:32:35 myhost dovecot: imap-login: default Dec 9 15:32:35 myhost dovecot: imap-login: default Dec 9 15:32:35 myhost dovecot: imap-login: DEBUG:: auth_client_connect_missing_servers Dec 9 15:32:35 myhost dovecot: imap-login: DEBUG:: creating file descriptor for path... Dec 9 15:32:35 myhost dovecot: imap-login: default Dec 9 15:32:35 myhost dovecot: imap-login: DEBUG:: auth_client_set_connect_notify Dec 9 15:32:35 myhost dovecot: imap-login: DEBUG:: auth_client_set_connect_notify Dec 9 15:32:35 myhost dovecot: imap-login: DEBUG:: auth_client_find_mech Dec 9 15:32:35 myhost dovecot: imap-login: DEBUG:: auth_client_find_mech Dec 9 15:32:35 myhost dovecot: imap-login: DEBUG:: auth_client_set_connect_notify Dec 9 15:32:35 myhost dovecot: imap-login: DEBUG:: auth_client_is_connected? Dec 9 15:32:35 myhost dovecot: imap-login: DEBUG:: auth_client_is_connected? Dec 9 15:32:35 myhost dovecot: imap-login: DEBUG:: auth_client_find_mech Dec 9 15:32:35 myhost dovecot: imap-login: DEBUG:: auth_client_is_connected?
Thank you!
Ryan Hinton iobass@email.com