dovecot - Oct 2010 - 2.0.5 Error: Timeout waiting for handshake from auth server.

Hello,

Upgraded from 1.2.x to 2.0.5, converted configuration as described in 
http://wiki2.dovecot.org/Upgrading/2.0 and now I'm unable to log in to 
imap server. Dovecot error.log shows:

Oct 21 09:52:48 imap-login: Error: Timeout waiting for handshake from 
auth server. my pid=13338, input bytes=0
Oct 21 09:52:48 imap-login: Error: Timeout waiting for handshake from 
auth server. my pid=13364, input bytes=0
Oct 21 09:52:48 imap-login: Error: Timeout waiting for handshake from 
auth server. my pid=13337, input bytes=0
Oct 21 09:52:48 imap-login: Error: Timeout waiting for handshake from 
auth server. my pid=13350, input bytes=0
Oct 21 09:52:48 imap-login: Error: Timeout waiting for handshake from 
auth server. my pid=13335, input bytes=0
Oct 21 09:52:48 imap-login: Error: Timeout waiting for handshake from 
auth server. my pid=13360, input bytes=0

I'm using pam with winbind for authentication.

/etc/pam.d/dovecot contains:

auth	required pam_winbind.so
account	sufficient pam_winbind.so

And it used to work perfectly with 1.1 and 1.2 series of dovecot.

What could be the problem with 2.0.5?

-- 
Veiko

On Thu, 2010-10-21 at 10:57 +0300, Veiko Kukk wrote:
> Oct 21 09:52:48 imap-login: Error: Timeout waiting for handshake from 
> auth server. my pid=13338, input bytes=0
auth process is hanging or imap-login is connecting to wrong server.

First try deleting everything from Dovecot's base_dir (/var/run/dovecot/
or something).

If that doesn't help, show your doveconf -n output.

Also once started, show "ps aux|grep dovecot" output and "strace
-tt -p
`pidof auth`" output for a few seconds.

check your mail log, if you get this:
Authentication service cannot retrieve authentication info

then it could be related to this bug:
http://bugs.debian.org/cgi-bin/bugreport.cgi?bug=566844

if you do have that issue let me know, and I'll look up our notes to
post a work around.


On Thu, Oct 21, 2010 at 3:57 AM, Veiko Kukk <veiko.kukk at ekp.ee>
wrote:
> Hello,
>
> Upgraded from 1.2.x to 2.0.5, converted configuration as described in
> http://wiki2.dovecot.org/Upgrading/2.0 and now I'm unable to log in to
imap
> server. Dovecot error.log shows:
>
> Oct 21 09:52:48 imap-login: Error: Timeout waiting for handshake from auth
> server. my pid=13338, input bytes=0
> Oct 21 09:52:48 imap-login: Error: Timeout waiting for handshake from auth
> server. my pid=13364, input bytes=0
> Oct 21 09:52:48 imap-login: Error: Timeout waiting for handshake from auth
> server. my pid=13337, input bytes=0
> Oct 21 09:52:48 imap-login: Error: Timeout waiting for handshake from auth
> server. my pid=13350, input bytes=0
> Oct 21 09:52:48 imap-login: Error: Timeout waiting for handshake from auth
> server. my pid=13335, input bytes=0
> Oct 21 09:52:48 imap-login: Error: Timeout waiting for handshake from auth
> server. my pid=13360, input bytes=0
>
> I'm using pam with winbind for authentication.
>
> /etc/pam.d/dovecot contains:
>
> auth ? ?required pam_winbind.so
> account sufficient pam_winbind.so
>
> And it used to work perfectly with 1.1 and 1.2 series of dovecot.
>
> What could be the problem with 2.0.5?
>
> --
> Veiko
>

On 10/21/2010 06:42 PM, Timo Sirainen wrote:
> On Thu, 2010-10-21 at 10:57 +0300, Veiko Kukk wrote:
> Also once started, show "ps aux|grep dovecot" output and
"strace -tt -p
> `pidof auth`" output for a few seconds.
Noticed in error.log:

Oct 22 17:45:24 config: Warning: service auth { client_limit=4096 } is 
lower than required under max. load (4896)
Oct 22 17:45:24 master: Error: service(auth): child 15857 killed with 
signal 11 (core dumps disabled)
Oct 22 17:45:24 master: Error: service(auth): command startup failed, 
throttling

-- 
Veiko

On Fri, 2010-10-22 at 17:49 +0300, Veiko Kukk wrote:
> Oct 22 17:45:24 config: Warning: service auth { client_limit=4096 } is 
> lower than required under max. load (4896)
> Oct 22 17:45:24 master: Error: service(auth): child 15857 killed with 
> signal 11 (core dumps disabled)
Well, this is the reason. It crashes. gdb backtrace would be helpful in
solving this.

You should be able to get a core dump by:

1. Set:

service auth {
  user = root
}

2. Run "ulimit -c unlimited" before starting Dovecot. If it still says
"core dumps disabled" in the log file, it means that your init script
disabled them again. Then you could e.g. just run "dovecot" directly
without init script.

You can then get gdb backtrace with:

gdb /usr/local/libexec/dovecot/auth /var/run/dovecot/core
bt full

If there are any problems, http://dovecot.org/bugreport.html may be
helpful.