Dovecot authorization fails when trying to connect via Mutt but all suggested Dovecot auth tests work
by spenced from LinuxQuestions.org on (#52BHE)
I can't figure out why the dovecot authorization process is dropping the domain from my username when when attempting to connect through my client (mutt).
I'm using the simple auth-password userdb/passdb for authentication, have disabled auth-system (with PAM) for now, (it was clogging up the logs as I am only trying to setup up a virtual user). More explanation at the end.
Code:doveadm auth test -x service=imap user@domain.id
passdb: user@domain.id auth succeeded
extra fields:
user=user@domain.idand
Code:dovecot auth test user@domain.id password
passdb: user@domain.id auth succeeded
extra fields:
user=user@domain.idand
Code:telnet imap.domain.id 143
trying xx.xxx.xx.x
Connected to imap.domain.id
Escape character is '^]'
* OK [CAPABILITY IMAP4rev1 SASL-IR LOGIN-REFERRALS ID ENABLE IDLE LITERAL+ STARTTLS AUTH=PLAIN] Dovecot ready.
a login user password
OK [CAPABILITY IMAP4rev1 SASL-IR LOGIN-REFERRALS ID ENABLE IDLE SORT SORT=DISPLAY THREAD=REFERENCES THREAD=REFS THREAD=ORDEREDSUBJECT MULTIAPPEND URL-PARTIAL CATENATE UNSELECT CHILDREN NAMESPACE UIDPLUS LIST-EXTENDED I18NLEVEL=1 CONDSTORE QRESYNC ESEARCH ESORT SEARCHRES WITHIN CONTEXT=SEARCH LIST-STATUS BINARY MOVE SNIPPET=FUZZY PREVIEW=FUZZY LITERAL+ NOTIFY SPECIAL-USE]
Logged inall good so far
mail.log:
Code:Apr 18 14:42:32 dserver dovecot: auth: Debug: auth client connected (pid=1153208)
Apr 18 14:42:48 dserver dovecot: auth: Debug: client in: AUTH#0111#011PLAIN#011service=imap#011session=9z4GjJejPOpDqz0B#011lip=192.168.1.18#011rip=67.171.61.1#011lport=143#011rport=59964#011resp=AHNwZW5jZXJAZGF2ZXkuaWQAQmVuZGVyYmMx (previous base64 data may contain sensitive data)
Apr 18 14:42:48 dserver dovecot: auth: Debug: passwd-file(user@domain.id,xx.xx.xx.x,<9z4GjJejPOpDqz0B>): Performing passdb lookup
Apr 18 14:42:48 dserver dovecot: auth: Debug: passwd-file(user@domain.id,xx.xx.xx.x,<9z4GjJejPOpDqz0B>): lookup: user=user@domain.id file=/etc/dovecot/users
Apr 18 14:42:48 dserver dovecot: auth: Debug: passwd-file(user@domain.id,xx.xx.xx.x,<9z4GjJejPOpDqz0B>): Finished passdb lookup
Apr 18 14:42:48 dserver dovecot: auth: Debug: auth(user@domain.id,xx.xx.xx.x,<9z4GjJejPOpDqz0B>): Auth request finished
Apr 18 14:42:48 dserver dovecot: auth: Debug: client passdb out: OK#0111#011user=user@domain.id
Apr 18 14:42:48 dserver dovecot: auth: Debug: master in: REQUEST#0112833514497#0111153208#0111#01168847acfe57555a93ec42d643c212c9b#011session_pid=1153448#011request_auth_token
Apr 18 14:42:48 dserver dovecot: auth: Debug: passwd-file(user@domain.id,xx.xx.xx.x,<9z4GjJejPOpDqz0B>): Performing userdb lookup
Apr 18 14:42:48 dserver dovecot: auth: Debug: passwd-file(user@domain.id,xx.xx.xx.x,<9z4GjJejPOpDqz0B>): lookup: user=user@domain.id file=/etc/dovecot/users
Apr 18 14:42:48 dserver dovecot: auth: Debug: passwd-file(user@domain.id,xx.xx.xx.x,<9z4GjJejPOpDqz0B>): Finished userdb lookup
Apr 18 14:42:48 dserver dovecot: auth: Debug: master userdb out: USER#0112833514497#011user#011uid=500#011gid=5000#011home=/var/vmail/domain/user/#011auth_token=10245b24c5981d5c412658bd640ac3dd0a1c3f57
Apr 18 14:42:48 dserver dovecot: imap-login: Login: user=<user@domain.id>, method=PLAIN, rip=xx.xx.xx.x, lip=192.168.1.18, mpid=1153448
Apr 18 14:42:48 dserver dovecot: imap(user@domain.id)<1153448><9z4GjJejPOpDqz0B>: Debug: Effective uid=500, gid=5000, home=/var/vmail/domain.id/user/
Apr 18 14:42:48 dserver dovecot: imap(user@domain.id)<1153448><9z4GjJejPOpDqz0B>: Debug: Home dir not found: /var/vmail/domain.id/user/
Apr 18 14:42:48 dserver dovecot: imap(user@domain.id)<1153448><9z4GjJejPOpDqz0B>: Debug: Namespace inbox: type=private, prefix=, sep=/, inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:~/Maildir
Apr 18 14:42:48 dserver dovecot: imap(user@domian.id)<1153448><9z4GjJejPOpDqz0B>: Debug: maildir++: root=/var/vmail/domain.id/user//Maildir, index=, indexpvt=, control=, inbox=/var/vmail/domain.id/user//Maildir, alt=
Apr 18 14:42:59 dserver dovecot: imap(user@domain.id)<1153448><9z4GjJejPOpDqz0B>: Logged out in=19 out=520 deleted=0 expunged=0 trashed=0 hdr_count=0 hdr_bytes=0 body_count=0 body_bytes=0now the failures:
Code:mutt -f imap://user@domain.id
Password: *******
login failedmail.log:
Code:Apr 18 14:52:24 dserver dovecot: auth: Debug: Loading modules from directory: /usr/lib/dovecot/modules/auth
Apr 18 14:52:24 dserver dovecot: auth: Debug: Module loaded: /usr/lib/dovecot/modules/auth/lib20_auth_var_expand_crypt.so
Apr 18 14:52:24 dserver dovecot: auth: Debug: Read auth token secret from /var/run/dovecot//auth-token-secret.dat
Apr 18 14:52:24 dserver dovecot: auth: Debug: passwd-file /etc/dovecot/users: Read 1 users in 0 secs
Apr 18 14:52:24 dserver dovecot: auth: Debug: auth client connected (pid=1160786)
Apr 18 14:52:33 dserver dovecot: auth: Debug: client in: AUTH#0111#011PLAIN#011service=imap#011secured=tls#011session=fcvlrpejlutDqz0B#011lip=192.168.1.18#011rip=67.171.61.1#011lport=143#011rport=60310#011local_name=davey.id#011ssl_cipher=TLS_AES_256_GCM_SHA384#011ssl_cipher_bits=256#011ssl_pfs=KxANY#011ssl_protocol=TLSv1.3#011resp=c3BlbmNlcgBzcGVuY2VyAEJlbmRlcmJjMQ== (previous base64 data may contain sensitive data)
Apr 18 14:52:33 dserver dovecot: auth: Debug: passwd-file(user,xx.xxx.xx.x,<fcvlrpejlutDqz0B>): Performing passdb lookup
Apr 18 14:52:33 dserver dovecot: auth: Debug: passwd-file(user,xx.xxx.xx.x,<fcvlrpejlutDqz0B>): lookup: user=user file=/etc/dovecot/users
Apr 18 14:52:33 dserver dovecot: auth: passwd-file(user,xx.xxx.xx.x,<fcvlrpejlutDqz0B>): unknown user
Apr 18 14:52:33 dserver dovecot: auth: Debug: passwd-file(user,xx.xxx.xx.x,<fcvlrpejlutDqz0B>): Finished passdb lookup
Apr 18 14:52:33 dserver dovecot: auth: Debug: auth(user,xx.xxx.xx.x,<fcvlrpejlutDqz0B>): Auth request finished
Apr 18 14:52:35 dserver dovecot: auth: Debug: client passdb out: FAIL#0111#011user=user
Apr 18 14:55:24 dserver dovecot: imap-login: Disconnected: Inactivity (auth failed, 1 attempts in 171 secs): user=<user>, method=PLAIN, rip=xx.xxx.xx.x, lip=192.168.1.18, TLSI want my `passdb` file to include the `@domain.id` in the user field to be able to differentiate same username different domains in one file. And also map my mailboxes as:
~/%d/%n/Maildir
It works correctly when I remove the `@domain.id` from the username field in my `passdb` file. I've read all about how dovecot doesn't care about domains and you can manipulate authentication with `%u` or `%n`
The problem is pretty obvious, my fixes just haven't worked. When logging in through Mutt, auth is dropping the `@domain.id` from the username so its not being authenticated in my passdb file. I have tried all combinations of:
Code:auth_username_format = %u
auth_username_format = %nand
Code:passdb {
driver = passwd-file
args = scheme=CRYPT **username_format=%u** /etc/dovecot/passdb
}
passdb {
driver = passwd-file
args = scheme=CRYPT **username_format%n** /etc/dovecot/passdb** is my emphesis
Why would IMAP authentication work differently from my telnet tests than from through Mutt? I did have to temporarily enable cleartext auth to test, but that's not affecting the mismatch of username in my passdb file. Is there somewhere else where username_format (or similar config) is defined? I've scoured everywhere the pass 24 hours.
Any help is greatly appreciated.
I'm using the simple auth-password userdb/passdb for authentication, have disabled auth-system (with PAM) for now, (it was clogging up the logs as I am only trying to setup up a virtual user). More explanation at the end.
Code:doveadm auth test -x service=imap user@domain.id
passdb: user@domain.id auth succeeded
extra fields:
user=user@domain.idand
Code:dovecot auth test user@domain.id password
passdb: user@domain.id auth succeeded
extra fields:
user=user@domain.idand
Code:telnet imap.domain.id 143
trying xx.xxx.xx.x
Connected to imap.domain.id
Escape character is '^]'
* OK [CAPABILITY IMAP4rev1 SASL-IR LOGIN-REFERRALS ID ENABLE IDLE LITERAL+ STARTTLS AUTH=PLAIN] Dovecot ready.
a login user password
OK [CAPABILITY IMAP4rev1 SASL-IR LOGIN-REFERRALS ID ENABLE IDLE SORT SORT=DISPLAY THREAD=REFERENCES THREAD=REFS THREAD=ORDEREDSUBJECT MULTIAPPEND URL-PARTIAL CATENATE UNSELECT CHILDREN NAMESPACE UIDPLUS LIST-EXTENDED I18NLEVEL=1 CONDSTORE QRESYNC ESEARCH ESORT SEARCHRES WITHIN CONTEXT=SEARCH LIST-STATUS BINARY MOVE SNIPPET=FUZZY PREVIEW=FUZZY LITERAL+ NOTIFY SPECIAL-USE]
Logged inall good so far
mail.log:
Code:Apr 18 14:42:32 dserver dovecot: auth: Debug: auth client connected (pid=1153208)
Apr 18 14:42:48 dserver dovecot: auth: Debug: client in: AUTH#0111#011PLAIN#011service=imap#011session=9z4GjJejPOpDqz0B#011lip=192.168.1.18#011rip=67.171.61.1#011lport=143#011rport=59964#011resp=AHNwZW5jZXJAZGF2ZXkuaWQAQmVuZGVyYmMx (previous base64 data may contain sensitive data)
Apr 18 14:42:48 dserver dovecot: auth: Debug: passwd-file(user@domain.id,xx.xx.xx.x,<9z4GjJejPOpDqz0B>): Performing passdb lookup
Apr 18 14:42:48 dserver dovecot: auth: Debug: passwd-file(user@domain.id,xx.xx.xx.x,<9z4GjJejPOpDqz0B>): lookup: user=user@domain.id file=/etc/dovecot/users
Apr 18 14:42:48 dserver dovecot: auth: Debug: passwd-file(user@domain.id,xx.xx.xx.x,<9z4GjJejPOpDqz0B>): Finished passdb lookup
Apr 18 14:42:48 dserver dovecot: auth: Debug: auth(user@domain.id,xx.xx.xx.x,<9z4GjJejPOpDqz0B>): Auth request finished
Apr 18 14:42:48 dserver dovecot: auth: Debug: client passdb out: OK#0111#011user=user@domain.id
Apr 18 14:42:48 dserver dovecot: auth: Debug: master in: REQUEST#0112833514497#0111153208#0111#01168847acfe57555a93ec42d643c212c9b#011session_pid=1153448#011request_auth_token
Apr 18 14:42:48 dserver dovecot: auth: Debug: passwd-file(user@domain.id,xx.xx.xx.x,<9z4GjJejPOpDqz0B>): Performing userdb lookup
Apr 18 14:42:48 dserver dovecot: auth: Debug: passwd-file(user@domain.id,xx.xx.xx.x,<9z4GjJejPOpDqz0B>): lookup: user=user@domain.id file=/etc/dovecot/users
Apr 18 14:42:48 dserver dovecot: auth: Debug: passwd-file(user@domain.id,xx.xx.xx.x,<9z4GjJejPOpDqz0B>): Finished userdb lookup
Apr 18 14:42:48 dserver dovecot: auth: Debug: master userdb out: USER#0112833514497#011user#011uid=500#011gid=5000#011home=/var/vmail/domain/user/#011auth_token=10245b24c5981d5c412658bd640ac3dd0a1c3f57
Apr 18 14:42:48 dserver dovecot: imap-login: Login: user=<user@domain.id>, method=PLAIN, rip=xx.xx.xx.x, lip=192.168.1.18, mpid=1153448
Apr 18 14:42:48 dserver dovecot: imap(user@domain.id)<1153448><9z4GjJejPOpDqz0B>: Debug: Effective uid=500, gid=5000, home=/var/vmail/domain.id/user/
Apr 18 14:42:48 dserver dovecot: imap(user@domain.id)<1153448><9z4GjJejPOpDqz0B>: Debug: Home dir not found: /var/vmail/domain.id/user/
Apr 18 14:42:48 dserver dovecot: imap(user@domain.id)<1153448><9z4GjJejPOpDqz0B>: Debug: Namespace inbox: type=private, prefix=, sep=/, inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:~/Maildir
Apr 18 14:42:48 dserver dovecot: imap(user@domian.id)<1153448><9z4GjJejPOpDqz0B>: Debug: maildir++: root=/var/vmail/domain.id/user//Maildir, index=, indexpvt=, control=, inbox=/var/vmail/domain.id/user//Maildir, alt=
Apr 18 14:42:59 dserver dovecot: imap(user@domain.id)<1153448><9z4GjJejPOpDqz0B>: Logged out in=19 out=520 deleted=0 expunged=0 trashed=0 hdr_count=0 hdr_bytes=0 body_count=0 body_bytes=0now the failures:
Code:mutt -f imap://user@domain.id
Password: *******
login failedmail.log:
Code:Apr 18 14:52:24 dserver dovecot: auth: Debug: Loading modules from directory: /usr/lib/dovecot/modules/auth
Apr 18 14:52:24 dserver dovecot: auth: Debug: Module loaded: /usr/lib/dovecot/modules/auth/lib20_auth_var_expand_crypt.so
Apr 18 14:52:24 dserver dovecot: auth: Debug: Read auth token secret from /var/run/dovecot//auth-token-secret.dat
Apr 18 14:52:24 dserver dovecot: auth: Debug: passwd-file /etc/dovecot/users: Read 1 users in 0 secs
Apr 18 14:52:24 dserver dovecot: auth: Debug: auth client connected (pid=1160786)
Apr 18 14:52:33 dserver dovecot: auth: Debug: client in: AUTH#0111#011PLAIN#011service=imap#011secured=tls#011session=fcvlrpejlutDqz0B#011lip=192.168.1.18#011rip=67.171.61.1#011lport=143#011rport=60310#011local_name=davey.id#011ssl_cipher=TLS_AES_256_GCM_SHA384#011ssl_cipher_bits=256#011ssl_pfs=KxANY#011ssl_protocol=TLSv1.3#011resp=c3BlbmNlcgBzcGVuY2VyAEJlbmRlcmJjMQ== (previous base64 data may contain sensitive data)
Apr 18 14:52:33 dserver dovecot: auth: Debug: passwd-file(user,xx.xxx.xx.x,<fcvlrpejlutDqz0B>): Performing passdb lookup
Apr 18 14:52:33 dserver dovecot: auth: Debug: passwd-file(user,xx.xxx.xx.x,<fcvlrpejlutDqz0B>): lookup: user=user file=/etc/dovecot/users
Apr 18 14:52:33 dserver dovecot: auth: passwd-file(user,xx.xxx.xx.x,<fcvlrpejlutDqz0B>): unknown user
Apr 18 14:52:33 dserver dovecot: auth: Debug: passwd-file(user,xx.xxx.xx.x,<fcvlrpejlutDqz0B>): Finished passdb lookup
Apr 18 14:52:33 dserver dovecot: auth: Debug: auth(user,xx.xxx.xx.x,<fcvlrpejlutDqz0B>): Auth request finished
Apr 18 14:52:35 dserver dovecot: auth: Debug: client passdb out: FAIL#0111#011user=user
Apr 18 14:55:24 dserver dovecot: imap-login: Disconnected: Inactivity (auth failed, 1 attempts in 171 secs): user=<user>, method=PLAIN, rip=xx.xxx.xx.x, lip=192.168.1.18, TLSI want my `passdb` file to include the `@domain.id` in the user field to be able to differentiate same username different domains in one file. And also map my mailboxes as:
~/%d/%n/Maildir
It works correctly when I remove the `@domain.id` from the username field in my `passdb` file. I've read all about how dovecot doesn't care about domains and you can manipulate authentication with `%u` or `%n`
The problem is pretty obvious, my fixes just haven't worked. When logging in through Mutt, auth is dropping the `@domain.id` from the username so its not being authenticated in my passdb file. I have tried all combinations of:
Code:auth_username_format = %u
auth_username_format = %nand
Code:passdb {
driver = passwd-file
args = scheme=CRYPT **username_format=%u** /etc/dovecot/passdb
}
passdb {
driver = passwd-file
args = scheme=CRYPT **username_format%n** /etc/dovecot/passdb** is my emphesis
Why would IMAP authentication work differently from my telnet tests than from through Mutt? I did have to temporarily enable cleartext auth to test, but that's not affecting the mismatch of username in my passdb file. Is there somewhere else where username_format (or similar config) is defined? I've scoured everywhere the pass 24 hours.
Any help is greatly appreciated.