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
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/AuthenticationYou 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
On Mon, Aug 26, 2019 at 2:38 AM Aki Tuomi <aki.tuomi at 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 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 >This is how it looks like (hashes and accounts replaced. I have two test accounts coming from two different domains I own): [root at mail ~]# cat /etc/dovecot/passwd raub at example.com:{SHA512-CRYPT}$6$4SEND-MORE-COOKIES raub at other-example.com:{SHA512-CRYPT}$6$ZHI-MOM [root at 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 at example.compasswordI 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>
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