BUG: Authentication client sent unknown handshake command

[Steffen Kaiser]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

On Mon, 21 Jul 2014, Lukas Haase wrote:

>> I provide "doveconf -n" in any case, maybe you can spot an issue?

I don't think, it's your config.
Setup a new server from scratch, without touching anything else on the new 
system [no init.d scripts either], but copy Dovecot to it. And try that 
system.

>>>>> Some time ago my dovecot started to become BUGgy: Evertime I
>>>>> restart the system, dovecot is started but I cannot login. I see
>>>>> the following information in the logs:
>>>>>
>>>>> Jul  4 04:04:36 mail dovecot: auth:
>>>>> passwd-file(user,127.11.91.218,<nfkQjFT9vwCADFra>): no passwd
>>>>> file: /etc/dovecot/imap.passwd Jul  4 04:04:36 mail dovecot:
>>>>> auth: Error: BUG: Authentication client sent unknown handshake
>>>>> command:
>>>>> REQUEST?1183186945?20438?1?a8c7241e7b0778f9f0125da760cd16fa Jul
>>>>> 4 04:04:36 mail dovecot: imap: Error: Authentication server
>>>>> didn't send valid SPID as expected: MECH#011PLAIN#011plaintext
>>>>> Jul  4 04:04:36 mail dovecot: imap: Error: Disconnected from
>>>>> auth server, aborting (client-pid=20438 client-id=1) Jul  4
>>>>> 04:04:36 mail dovecot: imap-login: Internal login failure
>>>>> (pid=20438 id=1) (internal failure, 1 succesful auths):
>>>>> user=<user>, method=PLAIN, rip=127.11.91.218, lip=73.82.101.172,
>>>>> mpid=20439, TLS, session=<nfkQjFT9vwCADFra>
>>>>>
>>>>> It does not help to restart the client. But when I then restart
>>>>> the server service dovecot restart it works again.

You say, _each_ time you restart the system, this happens, but _never_ if 
you start Dovecot manually?

I would first look into:

0) Dovecot v2.1 is pretty old. ;-)

a) Do you have more than one Dovecot version installed.

b) When and how often which Dovecot installation is started.
- -> e.g. is Dovecot started two times? I had some problem, when I started 
Postgres two times in init.d, it worked most of the time, but sometimes 
not.

c) Is Dovecot started too early?
- -> Maybe one dependency (LDAP, PAM, ...) blocks Dovecot, when someone is 
logging in too early and Dovecot gets desync'ed.

d) Your init.d script throws an error, which you don't see on startup and 
which does not happen, if you call the script manually.
- -> yes that can happen.

- -- 
Steffen Kaiser
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.11 (GNU/Linux)

iQEVAwUBU84MYHz1H7kL/d9rAQJEswf/a9OHp7JB9Pghj4Zr+Bws1Hxy1Q/+TaXF
RCL5ttvKLzcTQ5WCgso35AFtu7knERdcSn+BOaknVDHT2IFwZqdmGi0EpxG5F40n
MIIv97SWCu8jj8/wNxHlVhPbEnFvJTK4f4+mFivhSSYZ9ZVJMy/4rDh9ZunsJ7UG
Ri3SSvWAOOAlZLgYafmUX9UMhAfQJihqCRkMGLAc2eAvOuE7iludSJpIT8QWW/nI
ea9+K9NJ+iK6cxHKN23LZ/7bIDhSu6JbG5xjgp0+YdYECsGSGHgDz2noQkgR66Bo
4z+qn/DdITYdx7+mc6kLbnA3dcTEM1Le41eu72lMwo9wioq9I5vu0g==
=WyKT
-----END PGP SIGNATURE-----