dovecot Digest, Vol 225, Issue 73

Fri Jan 28 12:52:42 UTC 2022

>   5. Re: can't authenticate (Christian Mack)
hi Christian

log with debugging resulting from a login attempt pasted at end - to try and make it more readable I removed everything in each line up to "dovecot:" At no point is a password revealed, even in hashed form.

Should also say that the problem is identical on a backup laptop also running devuan 4; I'm not sure if I ever used that machine with dovecot before it was upgraded from devuan 3. Also I tried creating a new user to see if that account could authenticate; it cannot.

>So you only can increase the logging in dovecot for authentication to
>debugging.
>auth_debug=yes
________________________________________________________________________________
auth: Debug: Loading modules from directory: /usr/lib/dovecot/modules/auth
auth: Debug: Module loaded: /usr/lib/dovecot/modules/auth/lib20_auth_var_expand_crypt.so
auth: Debug: Read auth token secret from /run/dovecot/auth-token-secret.dat
auth: Debug: auth client connected (pid=2467)
auth: Debug: client in: AUTH#0111#011PLAIN#011service=imap#011secured#011session=osv6w6PW4tB/AAAB#011lip=127.0.0.1#011rip=127.0.0.1#011lport=143#011rport=53474#011resp=<hidden>
auth: Debug: pam(fred,127.0.0.1,<osv6w6PW4tB/AAAB>): Performing passdb lookup
auth-worker(2469): Debug: Loading modules from directory: /usr/lib/dovecot/modules/auth
auth-worker(2469): Debug: Module loaded: /usr/lib/dovecot/modules/auth/lib20_auth_var_expand_crypt.so
auth-worker(2469): Debug: conn unix:auth-worker (pid=2468,uid=118): Server accepted connection (fd=13)
dovecot: auth-worker(2469): Debug: conn unix:auth-worker (pid=2468,uid=118): Sending version handshake
auth-worker(2469): Debug: conn unix:auth-worker (pid=2468,uid=118): auth-worker<1>: Handling PASSV request
auth-worker(2469): Debug: conn unix:auth-worker (pid=2468,uid=118): auth-worker<1>: pam(fred,127.0.0.1,<osv6w6PW4tB/AAAB>): Performing passdb lookup
auth-worker(2469): Debug: conn unix:auth-worker (pid=2468,uid=118): auth-worker<1>: pam(fred,127.0.0.1,<osv6w6PW4tB/AAAB>): lookup service=dovecot
auth-worker: Error: fatal error: failed to reserve page summary memory
auth-worker(2469): Debug: conn unix:auth-worker (pid=2468,uid=118): auth-worker<1>: pam(fred,127.0.0.1,<osv6w6PW4tB/AAAB>): #1/1 style=1 msg=Password: 
auth-worker: Error: 
auth-worker: Error: runtime stack:
auth-worker: Error: runtime.throw(0x7f3b2a6a8292, 0x25)
auth-worker: Error: #011runtime/panic.go:1116 +0x74 fp=0x7f3b2a3b5b30 sp=0x7f3b2a3b5b00 pc=0x7f3b2a4d6474
auth-worker: Error: runtime.(*pageAlloc).sysInit(0x7f3b2a894428)
auth-worker: Error: #011runtime/mpagealloc_64bit.go:80 +0x185 fp=0x7f3b2a3b5bc0 sp=0x7f3b2a3b5b30 pc=0x7f3b2a4ccb25
auth-worker: Error: runtime.(*pageAlloc).init(0x7f3b2a894428, 0x7f3b2a894420, 0x7f3b2a8aeb18)
auth-worker: Error: #011runtime/mpagealloc.go:317 +0x77 fp=0x7f3b2a3b5be8 sp=0x7f3b2a3b5bc0 pc=0x7f3b2a4ca517
auth-worker: Error: runtime.(*mheap).init(0x7f3b2a894420)
auth-worker: Error: #011runtime/mheap.go:743 +0x24b fp=0x7f3b2a3b5c10 sp=0x7f3b2a3b5be8 pc=0x7f3b2a4c74cb
auth-worker: Error: runtime.mallocinit()
auth-worker: Error: #011runtime/malloc.go:480 +0x109 fp=0x7f3b2a3b5c38 sp=0x7f3b2a3b5c10 pc=0x7f3b2a4acc09
auth-worker: Error: runtime.schedinit()
auth-worker: Error: #011runtime/proc.go:563 +0x65 fp=0x7f3b2a3b5c90 sp=0x7f3b2a3b5c38 pc=0x7f3b2a4d9e25
auth-worker: Error: runtime.rt0_go(0x7ffd65c5e428, 0x2, 0x7ffd65c5e428, 0x7f3b2a3b6700, 0x7f3b2af22ea7, 0x0, 0x7f3b2a3b6700, 0x7f3b2a3b6700, 0xbe848d2612a1e5f4, 0x7ffd65c5cabe, ...)
auth-worker: Error: #011runtime/asm_amd64.s:214 +0x129 fp=0x7f3b2a3b5c98 sp=0x7f3b2a3b5c90 pc=0x7f3b2a508c09
auth: Error: auth worker: Aborted PASSV request for fred: Worker process died unexpectedly
auth: Debug: pam(fred,127.0.0.1,<osv6w6PW4tB/AAAB>): Finished passdb lookup
dovecot: auth: Debug: auth(fred,127.0.0.1,<osv6w6PW4tB/AAAB>): Auth request finished
auth-worker(2469): Fatal: master: service(auth-worker): child 2469 returned error 2
auth-worker(2471): Debug: Loading modules from directory: /usr/lib/dovecot/modules/auth
dovecot: auth-worker(2471): Debug: Module loaded: /usr/lib/dovecot/modules/auth/lib20_auth_var_expand_crypt.so
auth-worker(2471): Debug: conn unix:auth-worker (pid=2468,uid=118): Server accepted connection (fd=13)
auth-worker(2471): Debug: conn unix:auth-worker (pid=2468,uid=118): Sending version handshake
auth: Debug: client passdb out: FAIL#0111#011user=fred#011code=temp_fail
imap-login: Disconnected (auth service reported temporary failure): user=<fred>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured, session=<osv6w6PW4tB/AAAB>
________________________________________________________________________________
>Perhaps you also want to set
>auth_debug_passwords=yes
>for getting the actual password in plain text.
>(Don't forget to disable that afterwards!)
________________________________________________________________________________
auth-worker: Error: fatal error: failed to reserve page summary memory
auth-worker: Error: 
auth-worker: Error: runtime stack:
auth-worker: Error: runtime.throw(0x7fc7df48b292, 0x25)
auth-worker: Error: #011runtime/panic.go:1116 +0x74 fp=0x7fc7df198b30 sp=0x7fc7df198b00 pc=0x7fc7df2b9474
auth-worker: Error: runtime.(*pageAlloc).sysInit(0x7fc7df677428)
auth-worker: Error: #011runtime/mpagealloc_64bit.go:80 +0x185 fp=0x7fc7df198bc0 sp=0x7fc7df198b30 pc=0x7fc7df2afb25
auth-worker: Error: runtime.(*pageAlloc).init(0x7fc7df677428, 0x7fc7df677420, 0x7fc7df691b18)
auth-worker: Error: #011runtime/mpagealloc.go:317 +0x77 fp=0x7fc7df198be8 sp=0x7fc7df198bc0 pc=0x7fc7df2ad517
auth-worker: Error: runtime.(*mheap).init(0x7fc7df677420)
auth-worker: Error: #011runtime/mheap.go:743 +0x24b fp=0x7fc7df198c10 sp=0x7fc7df198be8 pc=0x7fc7df2aa4cb
auth-worker: Error: runtime.mallocinit()
auth-worker: Error: #011runtime/malloc.go:480 +0x109 fp=0x7fc7df198c38 sp=0x7fc7df198c10 pc=0x7fc7df28fc09
auth-worker: Error: runtime.schedinit()
auth-worker: Error: #011runtime/proc.go:563 +0x65 fp=0x7fc7df198c90 sp=0x7fc7df198c38 pc=0x7fc7df2bce25
auth-worker: Error: runtime.rt0_go(0x7ffc6c109f48, 0x2, 0x7ffc6c109f48, 0x7fc7df199700, 0x7fc7dfd05ea7, 0x0, 0x7fc7df199700, 0x7fc7df199700, 0x1de9f8dc88f21cc1, 0x7ffc6c1085de, ...)
auth-worker: Error: #011runtime/asm_amd64.s:214 +0x129 fp=0x7fc7df198c98 sp=0x7fc7df198c90 pc=0x7fc7df2ebc09
auth: Error: auth worker: Aborted PASSV request for fred: Worker process died unexpectedly
auth: Debug: pam(fred,127.0.0.1,<RFd4WqPWytB/AAAB>): Finished passdb lookup
auth: Debug: auth(fred,127.0.0.1,<RFd4WqPWytB/AAAB>): Auth request finished
auth-worker(2282): Fatal: master: service(auth-worker): child 2282 returned error 2
auth-worker(2284): Debug: Loading modules from directory: /usr/lib/dovecot/modules/auth
auth-worker(2284): Debug: Module loaded: /usr/lib/dovecot/modules/auth/lib20_auth_var_expand_crypt.so
auth-worker(2284): Debug: conn unix:auth-worker (pid=2281,uid=118): Server accepted connection (fd=13)
auth-worker(2284): Debug: conn unix:auth-worker (pid=2281,uid=118): Sending version handshake
auth: Debug: client passdb out: FAIL#0111#011user=fred#011code=temp_fail
imap-login: Disconnected (auth service reported temporary failure): user=<fred>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured, session=<RFd4WqPWytB/AAAB>

--
David Matthews
mail at dmatthews.org