User found but password failure
Trying to figure out which step is causing me not to be able to
login. I am using a password file,
passdb { driver = passwd-file args = scheme=SHA512-CRYPT username_format=%u /etc/dovecot/passwd }
We will assume that the pw I created using 'doveadm pw -s SHA512-CRYPT' matches the password I will be using to login below. I crank the debugging mode,
auth_debug_passwords = yes auth_debug = yes
And then try to login
[root@mail ~]# nc -t localhost 143
- OK [CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE STARTTLS AUTH=PLAIN AUTH=LOGIN AUTH=GSSAPI] Howdy a login raub@example.com password [blank]
which from what I gathered from /var/log/dovecot means it found matching username but did not match password:
secured session=lyJttvyQ9I0AAAAAAAAAAAAAAAAAAAAB lip=::1 rip=::1 lport=143 rport=36340 resp=base64-reply (previous base64 data may contain sensitive data) Aug 26 03:25:52 auth: Debug: passwd-file(raub@example.com,::1,<lyJttvyQ9I0AAAAAAAAAAAAAAAAAAAAB>): lookup: user=raub@example.com file=/etc/dovecot/passwd Aug 26 03:25:52 auth: Debug: client passdb out: OK 1 user=raub@example.com Aug 26 03:25:52 auth: Debug: master in: REQUEST 1520959489 26560 1 63ee7f45236f85fd39573a5c8a2eb46a session_pid=26563 request_auth_token Aug 26 03:25:52 auth-worker(26562): Debug: passwd(raub@example.com,::1,<lyJttvyQ9I0AAAAAAAAAAAAAAAAAAAAB>): lookup Aug 26 03:25:52 auth-worker(26562): Info: passwd(raub@example.com,::1,<lyJttvyQ9I0AAAAAAAAAAAAAAAAAAAAB>): unknown user Aug 26 03:25:52 auth: Debug: passwd-file(raub@example.com,::1,<lyJttvyQ9I0AAAAAAAAAAAAAAAAAAAAB>): lookup: user=raub@example.com file=/etc/dovecot/passwd Aug 26 03:25:52 auth: Error: plain(raub@example.com,::1,<lyJttvyQ9I0AAAAAAAAAAAAAAAAAAAAB>): user not found from any userdbs Aug 26 03:25:52 auth: Debug: master userdb out: NOTFOUND 1520959489 Aug 26 03:25:52 imap: Error: Authenticated user not found from userdb, auth lookup id=1520959489 (auth connected 1 msecs ago, handshake 0 msecs ago, request took 1 msecs, client-pid=26560 client-id=1) Aug 26 03:25:52 imap-login: Info: Internal login failure (pid=26560 id=1) (internal failure, 1 successful auths): user=<raub@example.com>, method=PLAIN, rip=::1, lip=::1, mpid=26563, secured, session=<lyJttvyQ9I0AAAAAAAAAAAAAAAAAAAAB>
Per [1] I decided to see what the response (base64-reply) I am submitting to dovecot looks like:
echo 'base64-reply' | base64 -d raub@example.compassword
Which has the right username and password but follows the userpassword format, not useruserpassword as I was led to believe by [1]. Is that to be expected? If it is then the issue is further down the line.
On 26.8.2019 6.51, Mauricio Tavares via dovecot wrote:
Trying to figure out which step is causing me not to be able to
login. I am using a password file,
passdb { driver = passwd-file args = scheme=SHA512-CRYPT username_format=%u /etc/dovecot/passwd }
We will assume that the pw I created using 'doveadm pw -s SHA512-CRYPT' matches the password I will be using to login below. I crank the debugging mode,
auth_debug_passwords = yes auth_debug = yes
And then try to login
[root@mail ~]# nc -t localhost 143
- OK [CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE STARTTLS AUTH=PLAIN AUTH=LOGIN AUTH=GSSAPI] Howdy a login raub@example.com password [blank]
which from what I gathered from /var/log/dovecot means it found matching username but did not match password:
secured session=lyJttvyQ9I0AAAAAAAAAAAAAAAAAAAAB lip=::1 rip=::1 lport=143 rport=36340 resp=base64-reply (previous base64 data may contain sensitive data) Aug 26 03:25:52 auth: Debug: passwd-file(raub@example.com,::1,<lyJttvyQ9I0AAAAAAAAAAAAAAAAAAAAB>): lookup: user=raub@example.com file=/etc/dovecot/passwd Aug 26 03:25:52 auth: Debug: client passdb out: OK 1 user=raub@example.com Aug 26 03:25:52 auth: Debug: master in: REQUEST 1520959489 26560 1 63ee7f45236f85fd39573a5c8a2eb46a session_pid=26563 request_auth_token Aug 26 03:25:52 auth-worker(26562): Debug: passwd(raub@example.com,::1,<lyJttvyQ9I0AAAAAAAAAAAAAAAAAAAAB>): lookup Aug 26 03:25:52 auth-worker(26562): Info: passwd(raub@example.com,::1,<lyJttvyQ9I0AAAAAAAAAAAAAAAAAAAAB>): unknown user Aug 26 03:25:52 auth: Debug: passwd-file(raub@example.com,::1,<lyJttvyQ9I0AAAAAAAAAAAAAAAAAAAAB>): lookup: user=raub@example.com file=/etc/dovecot/passwd Aug 26 03:25:52 auth: Error: plain(raub@example.com,::1,<lyJttvyQ9I0AAAAAAAAAAAAAAAAAAAAB>): user not found from any userdbs Aug 26 03:25:52 auth: Debug: master userdb out: NOTFOUND 1520959489 Aug 26 03:25:52 imap: Error: Authenticated user not found from userdb, auth lookup id=1520959489 (auth connected 1 msecs ago, handshake 0 msecs ago, request took 1 msecs, client-pid=26560 client-id=1) Aug 26 03:25:52 imap-login: Info: Internal login failure (pid=26560 id=1) (internal failure, 1 successful auths): user=<raub@example.com>, method=PLAIN, rip=::1, lip=::1, mpid=26563, secured, session=<lyJttvyQ9I0AAAAAAAAAAAAAAAAAAAAB>
Per [1] I decided to see what the response (base64-reply) I am submitting to dovecot looks like:
echo 'base64-reply' | base64 -d raub@example.compassword
Which has the right username and password but follows the userpassword format, not useruserpassword as I was led to believe by [1]. Is that to be expected? If it is then the issue is further down the line.
You misunderstood your logs.
Are you sure you have raub@example.com present in /etc/dovecot/passwd? Just having 'raub' there will not work.
Aki
On Mon, Aug 26, 2019 at 2:38 AM Aki Tuomi <aki.tuomi@open-xchange.com> wrote:
On 26.8.2019 6.51, Mauricio Tavares via dovecot wrote:
Trying to figure out which step is causing me not to be able to
login. I am using a password file,
passdb { driver = passwd-file args = scheme=SHA512-CRYPT username_format=%u /etc/dovecot/passwd }
We will assume that the pw I created using 'doveadm pw -s SHA512-CRYPT' matches the password I will be using to login below. I crank the debugging mode,
auth_debug_passwords = yes auth_debug = yes
And then try to login
[root@mail ~]# nc -t localhost 143
- OK [CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE STARTTLS AUTH=PLAIN AUTH=LOGIN AUTH=GSSAPI] Howdy a login raub@example.com password [blank]
which from what I gathered from /var/log/dovecot means it found matching username but did not match password:
secured session=lyJttvyQ9I0AAAAAAAAAAAAAAAAAAAAB lip=::1 rip=::1 lport=143 rport=36340 resp=base64-reply (previous base64 data may contain sensitive data) Aug 26 03:25:52 auth: Debug: passwd-file(raub@example.com,::1,<lyJttvyQ9I0AAAAAAAAAAAAAAAAAAAAB>): lookup: user=raub@example.com file=/etc/dovecot/passwd Aug 26 03:25:52 auth: Debug: client passdb out: OK 1 user=raub@example.com Aug 26 03:25:52 auth: Debug: master in: REQUEST 1520959489 26560 1 63ee7f45236f85fd39573a5c8a2eb46a session_pid=26563 request_auth_token Aug 26 03:25:52 auth-worker(26562): Debug: passwd(raub@example.com,::1,<lyJttvyQ9I0AAAAAAAAAAAAAAAAAAAAB>): lookup Aug 26 03:25:52 auth-worker(26562): Info: passwd(raub@example.com,::1,<lyJttvyQ9I0AAAAAAAAAAAAAAAAAAAAB>): unknown user Aug 26 03:25:52 auth: Debug: passwd-file(raub@example.com,::1,<lyJttvyQ9I0AAAAAAAAAAAAAAAAAAAAB>): lookup: user=raub@example.com file=/etc/dovecot/passwd Aug 26 03:25:52 auth: Error: plain(raub@example.com,::1,<lyJttvyQ9I0AAAAAAAAAAAAAAAAAAAAB>): user not found from any userdbs Aug 26 03:25:52 auth: Debug: master userdb out: NOTFOUND 1520959489 Aug 26 03:25:52 imap: Error: Authenticated user not found from userdb, auth lookup id=1520959489 (auth connected 1 msecs ago, handshake 0 msecs ago, request took 1 msecs, client-pid=26560 client-id=1) Aug 26 03:25:52 imap-login: Info: Internal login failure (pid=26560 id=1) (internal failure, 1 successful auths): user=<raub@example.com>, method=PLAIN, rip=::1, lip=::1, mpid=26563, secured, session=<lyJttvyQ9I0AAAAAAAAAAAAAAAAAAAAB>
Per [1] I decided to see what the response (base64-reply) I am submitting to dovecot looks like:
echo 'base64-reply' | base64 -d raub@example.compassword
Which has the right username and password but follows the userpassword format, not useruserpassword as I was led to believe by [1]. Is that to be expected? If it is then the issue is further down the line.
You misunderstood your logs.
Are you sure you have raub@example.com present in /etc/dovecot/passwd? Just having 'raub' there will not work.
Aki
This is how it looks like (hashes and accounts replaced. I have
two test accounts coming from two different domains I own):
[root@mail ~]# cat /etc/dovecot/passwd raub@example.com:{SHA512-CRYPT}$6$4SEND-MORE-COOKIES raub@other-example.com:{SHA512-CRYPT}$6$ZHI-MOM [root@mail ~]#
On Sun, 25 Aug 2019, Mauricio Tavares wrote:
Per [1] I decided to see what the response (base64-reply) I am submitting to dovecot looks like:
echo 'base64-reply' | base64 -d raub@example.compassword
I think there's a hidden null character netween username and password which you can see using
echo 'base64-reply' | base64 -d | od -c
but as Aki mention, this is probably not relevant to your problem.
Joseph Tam <jtam.home@gmail.com>
On Mon, Aug 26, 2019 at 4:36 PM Joseph Tam via dovecot <dovecot@dovecot.org> wrote:
On Sun, 25 Aug 2019, Mauricio Tavares wrote:
Per [1] I decided to see what the response (base64-reply) I am submitting to dovecot looks like:
echo 'base64-reply' | base64 -d raub@example.compassword
I think there's a hidden null character netween username and password which you can see using
echo 'base64-reply' | base64 -d | od -c
but as Aki mention, this is probably not relevant to your problem.
Joseph Tam <jtam.home@gmail.com>
I was expecting that since the encoding example in [1] inserts two \0 (NULL) characters before encoding, i.e.
printf 'raub@example.com\0raub@example.com\0passwod' | base64
I do not know if I am misreading the logs; maybe Aki can elaborate some more, but I do know the encoding example lists the username twice. And I am getting only it once when decoding the response I found in the log file.
On Mon, Aug 26, 2019 at 4:44 PM Mauricio Tavares <raubvogel@gmail.com> wrote:
On Mon, Aug 26, 2019 at 4:36 PM Joseph Tam via dovecot <dovecot@dovecot.org> wrote:
On Sun, 25 Aug 2019, Mauricio Tavares wrote:
Per [1] I decided to see what the response (base64-reply) I am submitting to dovecot looks like:
echo 'base64-reply' | base64 -d raub@example.compassword
I think there's a hidden null character netween username and password which you can see using
echo 'base64-reply' | base64 -d | od -c
but as Aki mention, this is probably not relevant to your problem.
Joseph Tam <jtam.home@gmail.com>
I was expecting that since the encoding example in [1] inserts two \0 (NULL) characters before encoding, i.e.
printf 'raub@example.com\0raub@example.com\0passwod' | base64
I do not know if I am misreading the logs; maybe Aki can elaborate some more, but I do know the encoding example lists the username twice. And I am getting only it once when decoding the response I found in the log file.
Update: I decided to make my life a bit simpler (this is a test box anyway in a private network; it can't see the outside): drop the encryption.
In my dovecot.conf file I have
passdb { driver = passwd-file args = scheme=plain-md5 username_format=%u /etc/dovecot/passwd }
userdb { driver = passwd-file args = username_format=%u /etc/dovecot/passwd default_fields = uid=virtual gid=virtual home=/var/spool/vmail/example.com/%n }
Where [root@testmail ~]# cat /etc/dovecot/passwd raub@example.com:{plain}password1 [root@testmail ~]# [root@testmail ~]# ls -l /etc/dovecot/passwd -rw------- 1 dovecot dovecot 55 Nov 7 16:01 /etc/dovecot/passwd [root@testmail ~]#
So I try to connect to it (test box so everything carefully unsafe):
raub@desktop:~$ nc -t -v box.in.example.com 143 Connection to box.in.example.com 143 port [tcp/imap2] succeeded!
- OK [CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE STARTTLS AUTH=PLAIN AUTH=LOGIN AUTH=GSSAPI] Howdy a login "raub@example.com" "password1" a NO [UNAVAILABLE] Internal error occurred. Refer to server log for more information. raub@desktop:~$
As in it just dropped the connection there. I then go to /var/log/dovecot Nov 07 15:15:16 auth: Error: plain(raub@example.com,10.0.0.128,<QEHnIcOWYtAKA ACA>): user not found from any userdbs Nov 07 15:15:16 imap: Error: Authenticated user not found from userdb, auth lookup id=3238395905 (auth connected 0 msecs ago, handshake 0 msecs ago, request took 0 msecs, client-pid=3574 client-id=1) Nov 07 15:15:16 imap-login: Info: Internal login failure (pid=3574 id=1) (internal failure, 1 successful auths): user=<raub@example.com>, method=PLAIN, rip=10.0.0.128, lip=172.17.0.4, mpid=3577, session=<QEHnIcOWYtAKAACA>
Why can't it find the user? I thought [1] that %u meant user was saved in the password file as user@domain.com instead of just user. If it did find user, I would expect it to complain about the password.
[1] https://doc.dovecot.org/configuration_manual/config_file/config_variables/
participants (3)
-
Aki Tuomi
-
Joseph Tam
-
Mauricio Tavares