dovecot - Dec 2006 - Authorization client connect failing

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 at email.com

On 13.10.2006, at 8.49, Ryan Hinton wrote:
> 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 think it's usually because dovecot-auth gets stuck, so you should  
rather look at what it's doing at the time. Maybe ktrace it (http:// 
wiki.dovecot.org/Debugging/ProcessTracing). What passdb and userdb  
are you using?



-------------- next part --------------
A non-text attachment was scrubbed...
Name: PGP.sig
Type: application/pgp-signature
Size: 186 bytes
Desc: This is a digitally signed message part
URL:
<http://dovecot.org/pipermail/dovecot/attachments/20061223/ea7fa599/attachment.bin>

On Fri 13 Oct 2006 08:49, Ryan Hinton wrote:
> 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 believe I am seeing the same problem with Dovecot 1.0.rc15, Postfix and 
OpenLDAP on SUSE 10.1

Prior to the problem occurring I see the following in the logs:

"dovecot: child 24628 (auth) killed with signal 6"

It is happening every 1-2 weeks...

-- 

Peter Nixon
http://www.peternixon.net/
PGP Key: http://www.peternixon.net/public.asc
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 189 bytes
Desc: not available
URL:
<http://dovecot.org/pipermail/dovecot/attachments/20070104/3615f658/attachment.bin>