[2.2.25 auth issue] auth-request.c: line 1049 (auth_request_lookup_credentials): assertion failed: (request->credentials_scheme == scheme)
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@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 [0x7f197c44715a] -> dovecot/auth 1 wait, 0 passdb, 0 userdb [0x7f197c453f8f] -> dovecot/auth 1 wait, 0 passdb, 0 userdb [0x7f197c446d2b] -> dovecot/auth 1 wait, 0 passdb, 0 userdb [0x7f197c4 46e28] -> dovecot/auth 1 wait, 0 passdb, 0 userdb [0x7f197c457742] -> dovecot/auth 1 wait, 0 passdb, 0 userdb [0x7f197c457f06] -> dovecot/auth 1 wait, 0 passdb, 0 userdb [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 [0x7f197c43cbe1] -> /lib64/libc.so.6(__libc_start_main+0xf5) [0x7f197b30ab15] -> dovecot/auth 1 wait, 0 passdb, 0 userdb [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
On 09.07.2016 10: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@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 [0x7f197c44715a] -> dovecot/auth 1 wait, 0 passdb, 0 userdb [0x7f197c453f8f] -> dovecot/auth 1 wait, 0 passdb, 0 userdb [0x7f197c446d2b] -> dovecot/auth 1 wait, 0 passdb, 0 userdb [0x7f197c4 46e28] -> dovecot/auth 1 wait, 0 passdb, 0 userdb [0x7f197c457742] -> dovecot/auth 1 wait, 0 passdb, 0 userdb [0x7f197c457f06] -> dovecot/auth 1 wait, 0 passdb, 0 userdb [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 [0x7f197c43cbe1] -> /lib64/libc.so.6(__libc_start_main+0xf5) [0x7f197b30ab15] -> dovecot/auth 1 wait, 0 passdb, 0 userdb [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
Hi!
Could you provide your doveconf -n so we could debug this?
Aki
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@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 [0x7f8cf8c5d3aa] ->
dovecot/auth 1 wait, 0 passdb, 0 userdb [0x7f8cf8c6a14f] ->
dovecot/auth 1 wait, 0 passdb, 0 userdb [0x7f8cf8c5cf2b] ->
dovecot/auth 1 wait, 0 passdb, 0
userdb [0x7f8cf8c5d033]
-> dovecot/auth 1 wait, 0 passdb, 0
userdb [0x7f8cf8c6d902] -> dovecot/auth
1 wait, 0 passdb, 0 userdb [0x7f8cf8c6e106] -> dovecot/auth
1 wait, 0 passdb, 0 userdb [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 [0x7f8cf8c52be1] ->
/lib64/libc.so.6(__libc_start_main+0xf5) [0x7f8cf7b1fb15] ->
dovecot/auth 1 wait, 0 passdb, 0 userdb [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@domain.com,192.168.10.9,<fJJWaYA4GOXa1753>): unknown user
passwd-file(username@domain.com,192.168.10.9,<fJJWaYA4GOXa1753>):
- trying the next passdb Jul 26 02:10:58 auth: Info:
unknown user - trying the next passdb Jul 26 02:10:58 pop3-login: Info: proxy(username@domain.com): started proxying to mailstore03.service.int.oss-core.com:110: user=<username@domain.com>, method=DIGEST-MD5, rip=192.168.10.9, lip=203.134.11.19, session=<fJJWaYA4GOXa1753>, orig_user=<username@domain.com> Jul 26 02:10:58 pop3-login: Info: proxy(username@domain.com): disconnecting 192.168.10.9 (Disconnected by server(0s idle, in=139, out=4767)): user=<username@domain.com>, method=DIGEST-MD5, rip=192.168.10.9, lip=203.134.11.19, session=<fJJWaYA4GOXa1753>, orig_user=<username@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@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@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@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@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@entry=0x7f8cf935bb30, scheme=scheme@entry=0x7f8cf8c8024d "LANMAN", callback=callback@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@entry=0x0, size=size@entry=0, request=request@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@entry=PASSDB_RESULT_USER_UNKNOWN, password=<optimized out>, scheme=scheme@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@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@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@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 [0x7f197c44715a] -> dovecot/auth 1 wait, 0 passdb, 0 userdb [0x7f197c453f8f] -> dovecot/auth 1 wait, 0 passdb, 0 userdb [0x7f197c446d2b] -> dovecot/auth 1 wait, 0 passdb, 0 userdb [0x7f197c4 46e28] -> dovecot/auth 1 wait, 0 passdb, 0 userdb [0x7f197c457742] -> dovecot/auth 1 wait, 0 passdb, 0 userdb [0x7f197c457f06] -> dovecot/auth 1 wait, 0 passdb, 0 userdb [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 [0x7f197c43cbe1] -> /lib64/libc.so.6(__libc_start_main+0xf5) [0x7f197b30ab15] -> dovecot/auth 1 wait, 0 passdb, 0 userdb [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
participants (3)
-
Aki Tuomi
-
Alexey Asemov (Alex/AT)
-
Leon Kyneur