[2.2.25 auth issue] auth-request.c: line 1049 (auth_request_lookup_credentials): assertion failed: (request->credentials_scheme == scheme)
Leon Kyneur
leon at f-m.fm
Tue Jul 26 02:30:24 UTC 2016
I am also seeing this error since updating to 2.2.25. I do believe it's
only occurring on CRAM-MD5, DIGEST-MD5 and NLTM auth.
# dovecot --version
2.2.25 (7be1766)
Jul 26 02:10:57 auth-worker(11499): Info:
ldap(username,192.168.10.9,<fJJWaYA4GOXa1753>): unknown user - trying
the next passdb
Jul 26 02:10:57 auth-worker(11499): Info:
ldap(username at notallocated.com.au,192.168.10.9,<fJJWaYA4GOXa1753>):
unknown user
Jul 26 02:10:57 auth: Panic: file auth-request.c: line 1069
(auth_request_lookup_credentials): assertion failed:
(request->credentials_scheme == scheme)
Jul 26 02:10:57 auth: Error: Raw backtrace:
/usr/lib64/dovecot/libdovecot.so.0(+0x8d52e) [0x7f8cf859752e] ->
/usr/lib64/dovecot/libdovecot.so.0(+0x8d60e) [0x7f8cf859760e] ->
/usr/lib64/dovecot/libdovecot.so.0(i_fatal+0) [0x7f8cf85361b6] ->
dovecot/auth [1 wait, 0 passdb, 0 userdb](+0x1a3aa) [0x7f8cf8c5d3aa] ->
dovecot/auth [1 wait, 0 passdb, 0 userdb](+0x2714f) [0x7f8cf8c6a14f] ->
dovecot/auth [1 wait, 0 passdb, 0 userdb](+0x19f2b) [0x7f8cf8c5cf2b] ->
dovecot/auth [1 wait, 0 passdb, 0
userdb](auth_request_lookup_credentials_callback+0x73) [0x7f8cf8c5d033]
-> dovecot/auth [1 wait, 0 passdb, 0
userdb](passdb_handle_credentials+0x92) [0x7f8cf8c6d902] -> dovecot/auth
[1 wait, 0 passdb, 0 userdb](+0x2b106) [0x7f8cf8c6e106] -> dovecot/auth
[1 wait, 0 passdb, 0 userdb](+0x2081a) [0x7f8cf8c6381a] ->
/usr/lib64/dovecot/libdovecot.so.0(io_loop_call_io+0x4c)
[0x7f8cf85aae8c] ->
/usr/lib64/dovecot/libdovecot.so.0(io_loop_handler_run_internal+0xff)
[0x7f8cf85ac2ef] ->
/usr/lib64/dovecot/libdovecot.so.0(io_loop_handler_run+0x25)
[0x7f8cf85aaf15] -> /usr/lib64/dovecot/libdovecot.so.0(io_loop_run+0x38)
[0x7f8cf85ab0c8] ->
/usr/lib64/dovecot/libdovecot.so.0(master_service_run+0x13)
[0x7f8cf853c613] -> dovecot/auth [1 wait, 0 passdb, 0
userdb](main+0x3a1) [0x7f8cf8c52be1] ->
/lib64/libc.so.6(__libc_start_main+0xf5) [0x7f8cf7b1fb15] ->
dovecot/auth [1 wait, 0 passdb, 0 userdb](+0xfdd1) [0x7f8cf8c52dd1]
Jul 26 02:10:57 auth: Fatal: master: service(auth): child 11496 killed
with signal 6 (core dumped)
Jul 26 02:10:57 pop3-login: Warning: Auth connection closed with 1
pending requests (max 0 secs, pid=11488, EOF)
Jul 26 02:10:58 auth-worker(11505): Info:
ldap(username at domain.com,192.168.10.9,<fJJWaYA4GOXa1753>): unknown user
- trying the next passdb
Jul 26 02:10:58 auth: Info:
passwd-file(username at domain.com,192.168.10.9,<fJJWaYA4GOXa1753>):
unknown user - trying the next passdb
Jul 26 02:10:58 pop3-login: Info: proxy(username at domain.com): started
proxying to mailstore03.service.int.oss-core.com:110:
user=<username at domain.com>, method=DIGEST-MD5, rip=192.168.10.9,
lip=203.134.11.19, session=<fJJWaYA4GOXa1753>,
orig_user=<username at domain.com>
Jul 26 02:10:58 pop3-login: Info: proxy(username at domain.com):
disconnecting 192.168.10.9 (Disconnected by server(0s idle, in=139,
out=4767)): user=<username at domain.com>, method=DIGEST-MD5,
rip=192.168.10.9, lip=203.134.11.19, session=<fJJWaYA4GOXa1753>,
orig_user=<username at domain.com>
# gdb /usr/libexec/dovecot/auth
core-auth-sig6-user97-group97-pid11496-time1469499057
GNU gdb (GDB) Red Hat Enterprise Linux 7.6.1-80.el7
Copyright (C) 2013 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later
<http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law. Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-redhat-linux-gnu".
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>...
Reading symbols from /usr/libexec/dovecot/auth...Reading symbols from
/usr/lib/debug/usr/libexec/dovecot/auth.debug...done.
done.
[New LWP 11496]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `dovecot/auth'.
Program terminated with signal 6, Aborted.
#0 0x00007f8cf7b335f7 in __GI_raise (sig=sig at entry=6) at
../nptl/sysdeps/unix/sysv/linux/raise.c:56
56 return INLINE_SYSCALL (tgkill, 3, pid, selftid, sig);
(gdb) bt full
#0 0x00007f8cf7b335f7 in __GI_raise (sig=sig at entry=6) at
../nptl/sysdeps/unix/sysv/linux/raise.c:56
resultvar = 0
pid = 11496
selftid = 11496
#1 0x00007f8cf7b34ce8 in __GI_abort () at abort.c:90
save_stage = 2
act = {__sigaction_handler = {sa_handler = 0x1, sa_sigaction =
0x1}, sa_mask = {__val = {31457280, 140727725664896, 140727725664888,
140243452896936, 140243438753907, 140243445984576, 140243452896936, 513,
6889173324748996864,
140727725665136, 140243438919218, 140243452896936,
140727725665024, 0, 140243438919321, 140243452896936}}, sa_flags =
-128374774, sa_restorer = 0x7ffdba192b01}
sigs = {__val = {32, 0 <repeats 15 times>}}
#2 0x00007f8cf8597526 in default_fatal_finish (type=<optimized out>,
status=status at entry=0) at failures.c:201
backtrace = 0x7f8cf93126e0
"/usr/lib64/dovecot/libdovecot.so.0(+0x8d52e) [0x7f8cf859752e] ->
/usr/lib64/dovecot/libdovecot.so.0(+0x8d60e) [0x7f8cf859760e] ->
/usr/lib64/dovecot/libdovecot.so.0(i_fatal+0) [0x7f8cf85361b6] -> dove"...
#3 0x00007f8cf859760e in i_internal_fatal_handler (ctx=0x7ffdba192b50,
format=<optimized out>, args=<optimized out>) at failures.c:670
status = 0
#4 0x00007f8cf85361b6 in i_panic (format=format at entry=0x7f8cf8c7ad40
"file %s: line %d (%s): assertion failed: (%s)") at failures.c:275
ctx = {type = LOG_TYPE_PANIC, exit_status = 0, timestamp = 0x0,
timestamp_usecs = 0}
args = {{gp_offset = 40, fp_offset = 48, overflow_arg_area =
0x7ffdba192c50, reg_save_area = 0x7ffdba192b90}}
#5 0x00007f8cf8c5d3aa in auth_request_lookup_credentials
(request=request at entry=0x7f8cf935bb30,
scheme=scheme at entry=0x7f8cf8c8024d "LANMAN",
callback=callback at entry=0x7f8cf8c6a000 <lm_credentials_callback>) at
auth-request.c:1069
ctx = <optimized out>
__FUNCTION__ = "auth_request_lookup_credentials"
#6 0x00007f8cf8c6a14f in ntlm_credentials_callback (result=<optimized
out>, credentials=<optimized out>, size=<optimized out>,
auth_request=0x7f8cf935bb30) at mech-ntlm.c:171
request = 0x7f8cf935bb30
#7 0x00007f8cf8c5cf2b in auth_request_lookup_credentials_finish
(result=PASSDB_RESULT_USER_UNKNOWN, credentials=credentials at entry=0x0,
size=size at entry=0, request=request at entry=0x7f8cf935bb30) at
auth-request.c:1012
No locals.
#8 0x00007f8cf8c5d033 in auth_request_lookup_credentials_callback
(result=PASSDB_RESULT_USER_UNKNOWN, credentials=0x0, size=0,
request=0x7f8cf935bb30) at auth-request.c:1054
passdb = <optimized out>
cache_cred = 0x7f8cf9312657 ""
cache_scheme = 0xfffffffffffffffd <Address 0xfffffffffffffffd
out of bounds>
__FUNCTION__ = "auth_request_lookup_credentials_callback"
#9 0x00007f8cf8c6d902 in passdb_handle_credentials
(result=result at entry=PASSDB_RESULT_USER_UNKNOWN, password=<optimized
out>, scheme=scheme at entry=0x0, callback=0x7f8cf8c5cfc0
<auth_request_lookup_credentials_callback>,
auth_request=0x7f8cf935bb30) at passdb.c:144
credentials = 0x0
size = 0
#10 0x00007f8cf8c6e106 in lookup_credentials_callback (reply=<optimized
out>, context=<optimized out>) at passdb-blocking.c:119
request = 0x7f8cf935bb30
result = PASSDB_RESULT_USER_UNKNOWN
password = 0x0
scheme = 0x0
#11 0x00007f8cf8c6381a in auth_worker_request_handle
(request=0x7f8cf936f9c0, request=0x7f8cf936f9c0, line=0x7f8cf936bac3
"FAIL\t-3", conn=0x7f8cf934def0) at auth-worker-server.c:303
No locals.
#12 worker_input (conn=0x7f8cf934def0) at auth-worker-server.c:403
line = 0x7f8cf936bac2 "\tFAIL\t-3"
id_str = <optimized out>
id = 5
#13 0x00007f8cf85aae8c in io_loop_call_io (io=0x7f8cf935b520) at
ioloop.c:564
ioloop = 0x7f8cf93197f0
t_id = 2
__FUNCTION__ = "io_loop_call_io"
#14 0x00007f8cf85ac2ef in io_loop_handler_run_internal
(ioloop=ioloop at entry=0x7f8cf93197f0) at ioloop-epoll.c:220
ctx = 0x7f8cf9329960
events = <optimized out>
list = 0x7f8cf935b580
io = <optimized out>
tv = {tv_sec = 59, tv_usec = 999487}
events_count = <optimized out>
msecs = <optimized out>
ret = 1
i = 0
call = <optimized out>
__FUNCTION__ = "io_loop_handler_run_internal"
#15 0x00007f8cf85aaf15 in io_loop_handler_run
(ioloop=ioloop at entry=0x7f8cf93197f0) at ioloop.c:612
No locals.
#16 0x00007f8cf85ab0c8 in io_loop_run (ioloop=0x7f8cf93197f0) at
ioloop.c:588
__FUNCTION__ = "io_loop_run"
#17 0x00007f8cf853c613 in master_service_run (service=0x7f8cf9319690,
callback=<optimized out>) at master-service.c:640
No locals.
#18 0x00007f8cf8c52be1 in main (argc=1, argv=0x7f8cf9319390) at main.c:400
c = <optimized out>
On 09/07/16 15:55, Alexey Asemov (Alex/AT) wrote:
> Hello,
>
> Since updating to 2.2.25, we do have the following issue (seems to be
> related to the new auth policy code):
>
> Jul 9 00:00:14 LXmail01 dovecot: auth-worker(6558):
> sql(user at domain.org,*.*.*.*,<wjpa7SY3nNFR8yTo>): unknown user
> Jul 9 00:00:14 LXmail01 dovecot: auth: Panic: file auth-request.c:
> line 1049 (auth_request_lookup_credentials): assertion failed:
> (request->credentials_scheme == scheme)
> Jul 9 00:00:14 LXmail01 dovecot: auth: Error: Raw backtrace:
> /usr/lib64/dovecot/libdovecot.so.0(+0x8d57e) [0x7f197bd8157e] ->
> /usr/lib64/dovecot/libdovecot.so.0(+0x8d65e) [0x7f197bd8165e] ->
> /usr/lib64/dovecot/libdovecot.so.0(i_fatal+0) [0x7f197bd201f6] ->
> dovecot/auth [1 wait, 0 passdb, 0 userdb](+0x1a15a) [0x7f197c44715a]
> -> dovecot/auth [1 wait, 0 passdb, 0 userdb](+0x26f8f)
> [0x7f197c453f8f] -> dovecot/auth [1 wait, 0 passdb, 0
> userdb](+0x19d2b) [0x7f197c446d2b] -> dovecot/auth [1 wait, 0 passdb,
> 0 userdb](auth_request_lookup_credentials_callback+0x68) [0x7f197c4
> 46e28] -> dovecot/auth [1 wait, 0 passdb, 0
> userdb](passdb_handle_credentials+0x92) [0x7f197c457742] ->
> dovecot/auth [1 wait, 0 passdb, 0 userdb](+0x2af06) [0x7f197c457f06]
> -> dovecot/auth [1
> wait, 0 passdb, 0 userdb](+0x2065a) [0x7f197c44d65a] ->
> /usr/lib64/dovecot/libdovecot.so.0(io_loop_call_io+0x4c)
> [0x7f197bd94edc] ->
> /usr/lib64/dovecot/libdovecot.so.0(io_loop_handler_run_in
> ternal+0xff) [0x7f197bd9633f] ->
> /usr/lib64/dovecot/libdovecot.so.0(io_loop_handler_run+0x25)
> [0x7f197bd94f65] ->
> /usr/lib64/dovecot/libdovecot.so.0(io_loop_run+0x38) [0x7f197bd95118]
> -> /usr
> /lib64/dovecot/libdovecot.so.0(master_service_run+0x13)
> [0x7f197bd26663] -> dovecot/auth [1 wait, 0 passdb, 0
> userdb](main+0x3a1) [0x7f197c43cbe1] ->
> /lib64/libc.so.6(__libc_start_main+0xf5)
> [0x7f197b30ab15] -> dovecot/auth [1 wait, 0 passdb, 0 userdb](+0xfdd1)
> [0x7f197c43cdd1]
> Jul 9 00:00:14 LXmail01 dovecot: auth: Fatal: master: service(auth):
> child 6555 killed with signal 6 (core dumps disabled)
> Jul 9 00:00:14 LXmail01 dovecot: pop3-login: Warning: Auth connection
> closed with 1 pending requests (max 1 secs, pid=8133, EOF)
>
> Environment is MySQL passdb/userdb, we are using plain scheme as
> default and password_noscheme field. In 2.2.24 and below auth worked
> without scratch. Reverting all policy-related commits in 2.2.25 fixes
> this, but I have not dug the details.
>
> KR,
>
> Alex
More information about the dovecot
mailing list