User found but password failure

[Aki Tuomi]

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 at 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 at 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 at example.com,::1,<lyJttvyQ9I0AAAAAAAAAAAAAAAAAAAAB>):
> lookup: user=raub at example.com file=/etc/dovecot/passwd
> Aug 26 03:25:52 auth: Debug: client passdb out: OK      1
> user=raub at 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 at example.com,::1,<lyJttvyQ9I0AAAAAAAAAAAAAAAAAAAAB>):
> lookup
> Aug 26 03:25:52 auth-worker(26562): Info:
> passwd(raub at example.com,::1,<lyJttvyQ9I0AAAAAAAAAAAAAAAAAAAAB>):
> unknown user
> Aug 26 03:25:52 auth: Debug:
> passwd-file(raub at example.com,::1,<lyJttvyQ9I0AAAAAAAAAAAAAAAAAAAAB>):
> lookup: user=raub at example.com file=/etc/dovecot/passwd
> Aug 26 03:25:52 auth: Error:
> plain(raub at 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 at 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 at 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.
>
> [1] https://wiki.dovecot.org/Debugging/Authentication


You misunderstood your logs.

Are you sure you have raub at example.com present in /etc/dovecot/passwd?
Just having 'raub' there will not work.

Aki