User found but password failure

[Mauricio Tavares]

On Mon, Aug 26, 2019 at 4:44 PM Mauricio Tavares <raubvogel at gmail.com> wrote:
>
> On Mon, Aug 26, 2019 at 4:36 PM Joseph Tam via dovecot
> <dovecot at 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 at 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 at gmail.com>
>
> I was expecting that since the encoding example in [1] inserts two \0
> (NULL) characters before encoding, i.e.
>
> printf 'raub at example.com\0raub at 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.
>
> [1] https://wiki.dovecot.org/Debugging/Authentication

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 at testmail ~]# cat /etc/dovecot/passwd
raub at example.com:{plain}password1
[root at testmail ~]#
[root at testmail ~]# ls -l /etc/dovecot/passwd
-rw------- 1 dovecot dovecot 55 Nov  7 16:01 /etc/dovecot/passwd
[root at testmail ~]#

So I try to connect to it (test box so everything carefully unsafe):

raub at 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 at example.com" "password1"
a NO [UNAVAILABLE] Internal error occurred. Refer to server log for more
information.
raub at 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 at 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 at 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 at 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/