Hello list,
Is Exim's dovecot driver for LOGIN auth broken or am i doing something
wrong? The PLAIN auth variant is working fine. Attached is the relevant
debug logging from both Dovecot auth as well as Exim.
This is Exim 4.95-4ubuntu2.2 & Dovecot 1:2.3.16+dfsg1-3ubuntu2.1 from
Ubuntu 22.04 Jammy stock packages.
When using AUTH LOGIN method, Exim tells me '435 Unable to authenticate
at present', but Dovecot auth seems to log the authentication as
successful?
The exact same user/pass combo works fine for PLAIN, also included in
the attached debug log file.
Exim config:
| begin authenticators
| dovecot_plain:
| driver = dovecot
| public_name = PLAIN
| server_socket = /run/dovecot/auth-client
| server_set_id = $auth1
|
| dovecot_login:
| driver = dovecot
| public_name = LOGIN
| server_socket = /run/dovecot/auth-client
| server_set_id = $auth1
Dovecot config has:
| auth_mechanisms = plain login
| disable_plaintext_auth = no
As can be seen in the debug logging.
Authentication using 'doveadm' and other methods succeeds fine, so i
doubt this is Dovecot configuration related and why i'm asking here
first. ;)
Thanks!
-Sndr.
--
| I entered 10 puns in a pun contest hoping one would win, but no pun in ten did.
| 4096R/20CC6CD2 - 6D40 1A20 B9AA 87D4 84C7 FBD6 F3A9 9442 20CC 6CD2
31823 SMTP<< AUTH LOGIN
31823 dovecot authentication
31823 auth_dovecot_server 297
31823 auth_dovecot_server 300
31823 received: 'VERSION 1 2'
31823 105 read but unreturned bytes; strcut() gave 3 results: {VERSION} {1} {2} last is <null>
31823 auth_dovecot_server 297
31823 auth_dovecot_server 300
31823 received: 'MECH PLAIN plaintext'
31823 84 read but unreturned bytes; strcut() gave 3 results: {MECH} {PLAIN} {plaintext} last is <null>
31823 auth_dovecot_server 297
31823 auth_dovecot_server 300
31823 received: 'MECH LOGIN plaintext'
31823 63 read but unreturned bytes; strcut() gave 3 results: {MECH} {LOGIN} {plaintext} last is <null>
31823 auth_dovecot_server 297
31823 auth_dovecot_server 300
31823 received: 'SPID 31824'
31823 52 read but unreturned bytes; strcut() gave 2 results: {SPID} {31824} last is <null>
31823 auth_dovecot_server 297
31823 auth_dovecot_server 300
31823 received: 'CUID 1'
31823 45 read but unreturned bytes; strcut() gave 2 results: {CUID} {1} last is <null>
31823 auth_dovecot_server 297
31823 auth_dovecot_server 300
31823 received: 'COOKIE 0c348b5a483a3ec81f1898119d034807'
31823 5 read but unreturned bytes; strcut() gave 2 results: {COOKIE} {0c348b5a483a3ec81f1898119d034807} last is <null>
31823 auth_dovecot_server 297
31823 auth_dovecot_server 300
31823 received: 'DONE'
31823 0 read but unreturned bytes; strcut() gave 1 results: {DONE} last is <null>
31823 sent: 'VERSION 1 0
31823 CPID 31823
31823 AUTH 1 LOGIN service=smtp secured rip=[CLIENTADDR] lip=[SERVERADDR] nologin resp=
31823 '
31823 received: 'CONT 1 VXNlcm5hbWU6'
31823 0 read but unreturned bytes; strcut() gave 3 results: {CONT} {1} {VXNlcm5hbWU6} last is <null>
31823 SMTP>> 334 VXNlcm5hbWU6
31823 tls_write(0x56338111d7d8, 18)
31823 gnutls_record_send(session=0x563381404ac0, buffer=0x56338111d7d8, left=18)
31823 outbytes=18
31823 Calling gnutls_record_recv(session=0x563381404ac0, buffer=0x56338140c7c8, buffersize=4096)
31823 received: 'CONT 1 UGFzc3dvcmQ6'
31823 0 read but unreturned bytes; strcut() gave 3 results: {CONT} {1} {UGFzc3dvcmQ6} last is <null>
31823 SMTP>> 334 UGFzc3dvcmQ6
31823 tls_write(0x56338111d7d8, 18)
31823 gnutls_record_send(session=0x563381404ac0, buffer=0x56338111d7d8, left=18)
31823 outbytes=18
31823 Calling gnutls_record_recv(session=0x563381404ac0, buffer=0x56338140c7c8, buffersize=4096)
31823 received: 'OK 1 user=s.smeenk@[REDACTED] '
31823 0 read but unreturned bytes; strcut() gave 4 results: {OK} {1} {user=s.smeenk@[REDACTED]} {} last is <null>
31823 dovecot_login authenticator server_condition:
31823 $auth1 = s.smeenk@[REDACTED]
31823 $1 = s.smeenk@[REDACTED]
31823 SMTP>> 435 Unable to authenticate at present
dovecot: auth: Debug: auth client connected (pid=0)
dovecot: auth: Debug: client in: AUTH#0111#011LOGIN#011service=smtp#011secured#011rip=[CLIENTADDR]#011lip=[SERVERADDR]#011nologin#011resp=<hidden>
dovecot: auth: Debug: client passdb out: CONT#0111#011VXNlcm5hbWU6
dovecot: auth: Debug: client in: CONT<hidden>
dovecot: auth: Debug: client passdb out: CONT#0111#011UGFzc3dvcmQ6
dovecot: auth: Debug: client in: CONT<hidden>
dovecot: auth: Debug: ldap(s.smeenk@[REDACTED],[CLIENTADDR]): Performing passdb lookup
dovecot: auth: Debug: ldap(s.smeenk@[REDACTED],[CLIENTADDR]): pass search: base=ou=mailboxen [REDACTED]
dovecot: auth: Debug: ldap(s.smeenk@[REDACTED],[CLIENTADDR]): result: MailAdres=s.smeenk@[REDACTED] MailboxPassword={CRYPT}$6$TcU0mG1NHxdX9FV[..]; MailAdres,MailboxPassword unused
dovecot: auth: Debug: ldap(s.smeenk@[REDACTED],[CLIENTADDR]): Finished passdb lookup
dovecot: auth: Debug: auth(s.smeenk@[REDACTED],[CLIENTADDR]): Auth request finished
dovecot: auth: Debug: client passdb out: OK#0111#011user=s.smeenk@[REDACTED]#011
31933 SMTP<< AUTH PLAIN [REDACTED]
31933 dovecot authentication
31933 auth_dovecot_server 297
31933 auth_dovecot_server 300
31933 received: 'VERSION 1 2'
31933 105 read but unreturned bytes; strcut() gave 3 results: {VERSION} {1} {2} last is <null>
31933 auth_dovecot_server 297
31933 auth_dovecot_server 300
31933 received: 'MECH PLAIN plaintext'
31933 84 read but unreturned bytes; strcut() gave 3 results: {MECH} {PLAIN} {plaintext} last is <null>
31933 auth_dovecot_server 297
31933 auth_dovecot_server 300
31933 received: 'MECH LOGIN plaintext'
31933 63 read but unreturned bytes; strcut() gave 3 results: {MECH} {LOGIN} {plaintext} last is <null>
31933 auth_dovecot_server 297
31933 auth_dovecot_server 300
31933 received: 'SPID 31934'
31933 52 read but unreturned bytes; strcut() gave 2 results: {SPID} {31934} last is <null>
31933 auth_dovecot_server 297
31933 auth_dovecot_server 300
31933 received: 'CUID 1'
31933 45 read but unreturned bytes; strcut() gave 2 results: {CUID} {1} last is <null>
31933 auth_dovecot_server 297
31933 auth_dovecot_server 300
31933 received: 'COOKIE 8d427c4d17016b8ceee2bb49b146cbc0'
31933 5 read but unreturned bytes; strcut() gave 2 results: {COOKIE} {8d427c4d17016b8ceee2bb49b146cbc0} last is <null>
31933 auth_dovecot_server 297
31933 auth_dovecot_server 300
31933 received: 'DONE'
31933 0 read but unreturned bytes; strcut() gave 1 results: {DONE} last is <null>
31933 sent: 'VERSION 1 0
31933 CPID 31933
31933 AUTH 1 PLAIN service=smtp secured rip=[CLIENTADDR] lip=[SERVERADDR] nologin resp=[REDACTED]
31933 '
31933 received: 'OK 1 user=s.smeenk@[REDACTED] '
31933 0 read but unreturned bytes; strcut() gave 4 results: {OK} {1} {user=s.smeenk@[REDACTED]} {} last is <null>
31933 dovecot_plain authenticator server_condition:
31933 $auth1 = s.smeenk@[REDACTED]
31933 $1 = s.smeenk@[REDACTED]
31933 SMTP>> 235 Authentication succeeded
dovecot: auth: Debug: auth client connected (pid=0)
dovecot: auth: Debug: client in: AUTH#0111#011PLAIN#011service=smtp#011secured#011rip=[CLIENTADDR]#011lip=[SERVERADDR]#011nologin#011resp=<hidden>
dovecot: auth: Debug: ldap(s.smeenk@[REDACTED],[CLIENTADDR]): Performing passdb lookup
dovecot: auth: Debug: ldap(s.smeenk@[REDACTED],[CLIENTADDR]): pass search: base=ou=mailboxen [REDACTED]
dovecot: auth: Debug: ldap(s.smeenk@[REDACTED],[CLIENTADDR]): result: MailAdres=s.smeenk@[REDACTED] MailboxPassword={CRYPT}$6$TcU0mG1NHxdX9FV[..]; MailAdres,MailboxPassword unused
dovecot: auth: Debug: ldap(s.smeenk@[REDACTED],[CLIENTADDR]): Finished passdb lookup
dovecot: auth: Debug: auth(s.smeenk@[REDACTED],[CLIENTADDR]): Auth request finished
dovecot: auth: Debug: client passdb out: OK#0111#011user=s.smeenk@[REDACTED]#011
