auth: Panic: file oauth2-request.c assertion failed
Hi,
I'm running a postfix smtp relay server on which users are getting authenticated trough sasl via the dovecot authentication service. This works without problems.
Recently I extended my configuration to authenticate users with the PLAIN mechanism against Azure AD B2C with oauth2 in the future. Important to mention is that currently no users are stored in Azure B2C. I only prepared the hole configuration and authentiucation falls back to mysql database.
Now sometimes I get the error below in my logs (not permanently): ... Dec 7 11:36:49 relay-out1 dovecot: auth: Panic: file oauth2-request.c: line 201 (oauth2_request_start): assertion failed: (oauth2_valid_token(input->token)) Dec 7 11:36:49 relay-out1 dovecot: auth: Error: Raw backtrace: /usr/lib/dovecot/libdovecot.so.0(backtrace_append+0x3d) [0x7f399402e62d] -> /usr/lib/dovecot/libdovecot.so.0(backtrace_get+0x1e) [0x7f399402e74e] -> /usr/lib/dovecot/libdovecot.so.0(+0x1006eb) [0x7f399403b6eb] -> /usr/lib/dovecot/libdovecot.so.0(+0x100781) [0x7f399403b781] -> /usr/lib/dovecot/libdovecot.so.0(+0x54b7c) [0x7f3993f8fb7c] -> /usr/lib/dovecot/libdovecot.so.0(+0x4605a) [0x7f3993f8105a] -> /usr/lib/dovecot/libdovecot.so.0(oauth2_passwd_grant_start+0xfa) [0x7f3993f9870a] -> dovecot/auth(db_oauth2_lookup+0x2ca) [0x560d0804368a] -> dovecot/auth(auth_request_default_verify_plain_continue+0x2d6) [0x560d08026436] -> dovecot/auth(auth_policy_check+0x2b) [0x560d0802071b] -> dovecot/auth(+0x29f72) [0x560d0802ff72] -> dovecot/auth(auth_request_handler_auth_continue+0xf7) [0x560d0802a197] -> dovecot/auth(+0x16c62) [0x560d0801cc62] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_call_io+0x69) [0x7f3994051c29] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_handler_run_internal+0x131) [0x7f3994053251] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_handler_run+0x4c) [0x7f3994051ccc] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_run+0x40) [0x7f3994051e50] -> /usr/lib/dovecot/libdovecot.so.0(master_service_run+0x13) [0x7f3993fc4df3] -> dovecot/auth(main+0x415) [0x560d0801abf5] -> /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xeb) [0x7f3993cee09b] -> dovecot/auth(_start+0x2a) [0x560d0801ad8a] ...
After the error above postfix says the connection to the authentication server was lost: ... Dec 7 11:36:49 relay-out1 rolrelayout1/smtpd[1655601]: warning: domain.com[12.12.12.12]: SASL LOGIN authentication failed: Connection lost to authentication server ...
I was able to make a core dump. ...
gdb /usr/lib/dovecot/auth core.auth.1654357.1670409409
GNU gdb (Debian 8.2.1-2+b3) 8.2.1 ... For help, type "help". Type "apropos word" to search for commands related to "word"... Reading symbols from /usr/lib/dovecot/auth...Reading symbols from /usr/lib/debug/.build-id/bc/f14ed9cc2dda3ee9565fbd7ccd835460008438.debug...done. done. [New LWP 1654357] [Thread debugging using libthread_db enabled] Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1". Core was generated by `dovecot/auth'. Program terminated with signal SIGABRT, Aborted. #0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50 50 ../sysdeps/unix/sysv/linux/raise.c: Datei oder Verzeichnis nicht gefunden. (gdb) bt full #0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50 set = {__val = {0, 1415, 1416, 94613970086496, 10, 139885273538955, 155, 139885273347109, 140724590457408, 118, 206158430224, 140724590457744, 140724590457536, 16888407779496842752, 94613970086472, 139885273131758}} pid = <optimized out> tid = <optimized out> ret = <optimized out> #1 0x00007f3993cec535 in __GI_abort () at abort.c:79 save_stage = 1 act = {__sigaction_handler = {sa_handler = 0x73f, sa_sigaction = 0x73f}, sa_mask = {__val = {1024, 18446744073709551615, 94613971926672, 94613971631792, 139885273108347, 94613970084312, 139885273090236, 94613970084312, 16888407779496842752, 94613970084288, 139885273346402, 140724590457744, 94613970084312, 140724590457744, 139885273346761, 94613970084312}}, sa_flags = -1811749030, sa_restorer = 0x5} sigs = {__val = {32, 0 <repeats 15 times>}} #2 0x00007f3993f8feaf in default_fatal_finish (status=0, type=LOG_TYPE_PANIC) at failures.c:465 backtrace = 0x560d0813e220 "/usr/lib/dovecot/libdovecot.so.0(backtrace_append+0x3d) [0x7f399402e62d] -> /usr/lib/dovecot/libdovecot.so.0(backtrace_get+0x1e) [0x7f399402e74e] -> /usr/lib/dovecot/libdovecot.so.0(+0x1006eb) [0x7f39"... backtrace = <optimized out> recursed = 0 #3 fatal_handler_real (ctx=<optimized out>, format=<optimized out>, args=<optimized out>) at failures.c:477 status = 0 #4 0x00007f399403b781 in i_internal_fatal_handler (ctx=<optimized out>, format=<optimized out>, args=<optimized out>) at failures.c:879 No locals. #5 0x00007f3993f8fb7c in i_panic (format=format@entry=0x7f399407a0e8 "file %s: line %d (%s): assertion failed: (%s)") at failures.c:530 ctx = {type = LOG_TYPE_PANIC, exit_status = 0, timestamp = 0x0, timestamp_usecs = 0, log_prefix = 0x0, log_prefix_type_pos = 0} args = {{gp_offset = 40, fp_offset = 48, overflow_arg_area = 0x7ffcff39b4e0, reg_save_area = 0x7ffcff39b420}} #6 0x00007f3993f8105a in oauth2_request_start (set=0x560d08176150, input=0x7ffcff39b5d0, callback=0x560d08042b50 <db_oauth2_lookup_passwd_grant>, context=0x560d082ffe90, p=0x560d082b7eb0, method=0x7f399407a2c6 "POST", url=0x560d08178480 "https://xxx.b2clogin.com/xxx.onmicrosoft.com/B2C_1_ropc/oauth2/v2.0/token?sc...", payload=0x560d082b7ed8, add_auth_bearer=false) at oauth2-request.c:201 __func__ = "oauth2_request_start" pool = <optimized out> req = <optimized out> #7 0x00007f3993f9870a in oauth2_passwd_grant_start (set=set@entry=0x560d08176150, input=input@entry=0x7ffcff39b5d0, username=0x560d082ffe38 "user.name", password=0x560d082ffe48 "", callback=callback@entry=0x560d08042b50 <db_oauth2_lookup_passwd_grant>, context=context@entry=0x560d082ffe90) at oauth2-request.c:351 pool = 0x560d082b7eb0 payload = 0x560d082b7ed8 #8 0x0000560d0804368a in db_oauth2_lookup (db=0x560d08176060, req=0x560d082ffe90, token=<optimized out>, request=0x560d082ffba8, callback=0x560d080370b0 <oauth2_verify_plain_continue>, context=0x560d082ffba8) at db-oauth2.c:862 input = {token = 0x560d082ffe48 "", service = 0x560d082ffe20 "smtp", local_ip = {family = 2, u = {ip6 = {__in6_u = {__u6_addr8 = "\303\376\374\322", '\000' <repeats 11 times>, __u6_addr16 = {65219, 54012, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {3539795651, 0, 0, 0}}}, ip4 = {s_addr = 3539795651}}}, real_local_ip = {family = 2, u = {ip6 = {__in6_u = {__u6_addr8 = "\303\376\374\322", '\000' <repeats 11 times>, __u6_addr16 = {65219, 54012, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {3539795651, 0, 0, 0}}}, ip4 = {s_addr = 3539795651}}}, remote_ip = {family = 2, u = {ip6 = {__in6_u = {__u6_addr8 = "*\300\070\226", '\000' <repeats 11 times>, __u6_addr16 = {49194, 38456, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {2520301610, 0, 0, 0}}}, ip4 = {s_addr = 2520301610}}}, real_remote_ip = {family = 2, u = {ip6 = {__in6_u = {__u6_addr8 = "*\300\070\226", '\000' <repeats 11 times>, __u6_addr16 = { 49194, 38456, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {2520301610, 0, 0, 0}}}, ip4 = {s_addr = 2520301610}}}, local_port = 0, real_local_port = 0, remote_port = 0, real_remote_port = 0} __func__ = "db_oauth2_lookup" #9 0x0000560d08026436 in auth_request_default_verify_plain_continue (request=0x560d082ffba8, callback=0x560d0803e6f0 <plain_verify_callback>) at auth-request.c:1123 passdb = 0x560d0814da40 result = 22029 cache_key = <optimized out> error = 0x560d082ffe38 "user.name" password = 0x560d082ffe48 "" __func__ = "auth_request_default_verify_plain_continue" #10 0x0000560d0802071b in auth_policy_check (request=<optimized out>, password=<optimized out>, cb=<optimized out>, context=<optimized out>) at auth-policy.c:575 pool = <optimized out> ctx = <optimized out> #11 0x0000560d0802ff72 in mech_plain_auth_continue (request=0x560d082ffba8, data=0x560d0813d368 "user.name", data_size=30) at mech-plain.c:58 authid = <optimized out> authenid = 0x560d0813d377 "user.name" error = 0x560d0813d320 "h\323\023\b\rV" pass = 0x560d0813d388 "" i = <optimized out> len = <optimized out> count = 2 #12 0x0000560d0802a197 in auth_request_handler_auth_continue (handler=0x560d082d1ae8, args=args@entry=0x560d08268e96 "21\tdGhvbWFzLmZlcnJhcmkAdGhvbWFzLmZlcnJhcmkA") at auth-request-handler.c:738 request = 0x560d082ffba8 data = 0x560d08268e99 "dGhvbWFzLmZlcnJhcmkAdGhvbWFzLmZlcnJhcmkA" data_len = 40 buf = 0x560d0813d320 id = 21 #13 0x0000560d0801cc62 in auth_client_handle_line (line=0x560d08268e91 "CONT\t21\tdGhvbWFzLmZlcnJhcmkAdGhvbWFzLmZlcnJhcmkA", conn=0x560d08276d30) at auth-client-connection.c:228 No locals. #14 auth_client_input (conn=<optimized out>) at auth-client-connection.c:311 _data_stack_cur_id = 3 line = <optimized out> ret = <optimized out> #15 0x00007f3994051c29 in io_loop_call_io (io=0x560d0826f240) at ioloop.c:737 ioloop = 0x560d08145f80 t_id = 2 __func__ = "io_loop_call_io" #16 0x00007f3994053251 in io_loop_handler_run_internal (ioloop=ioloop@entry=0x560d08145f80) at ioloop-epoll.c:222 ctx = 0x560d08148600 events = <optimized out> event = 0x560d08148680 list = 0x560d082ae620 io = <optimized out> tv = {tv_sec = 0, tv_usec = 315566} events_count = <optimized out> msecs = <optimized out> ret = <optimized out> i = 0 j = <optimized out> call = <optimized out> __func__ = "io_loop_handler_run_internal" #17 0x00007f3994051ccc in io_loop_handler_run (ioloop=0x560d08145f80) at ioloop.c:789 __func__ = "io_loop_handler_run" #18 0x00007f3994051e50 in io_loop_run (ioloop=0x560d08145f80) at ioloop.c:762 __func__ = "io_loop_run" #19 0x00007f3993fc4df3 in master_service_run (service=0x560d08145dd0, callback=<optimized out>) at master-service.c:869 No locals. #20 0x0000560d0801abf5 in main (argc=<optimized out>, argv=<optimized out>) at main.c:393 c = <optimized out> ...
And "doveconf -n": ...
2.3.19.1 (9b53102964): /etc/dovecot/dovecot.conf
OS: Linux 5.10.0-18-amd64 x86_64 Debian 10.13
Hostname: relay-out1.domain.com
auth_cache_negative_ttl = 0 auth_cache_size = 40 M auth_cache_ttl = 30 days auth_mechanisms = plain login auth_username_chars = abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ01234567890.-_%@ auth_username_translation = %@ auth_verbose = yes auth_verbose_passwords = plain auth_worker_max_count = 100 disable_plaintext_auth = no namespace inbox { inbox = yes location = mailbox Drafts { special_use = \Drafts } mailbox Junk { special_use = \Junk } mailbox Sent { special_use = \Sent } mailbox "Sent Messages" { special_use = \Sent } mailbox Trash { special_use = \Trash } prefix = } passdb { args = /etc/dovecot/dovecot-oauth2.plain.conf.ext driver = oauth2 mechanisms = plain login } passdb { args = /etc/dovecot/dovecot-sql-account.conf driver = sql } service auth { unix_listener /var/spool/postfix/private/auth { group = postfix mode = 0660 user = postfix } } userdb { args = /etc/dovecot/dovecot-sql-account.conf driver = sql } ...
System OS is Debian 10, Dovecot installed from dovecot repository.
Many thanks Urban
Hi,
no one has received the same error? In the meantime I upgraded to dovecot 2.3.20. But the error is still here.
ii dovecot-core 2:2.3.20-3+debian10 amd64 secure POP3/IMAP server - core files ii dovecot-dbg 2:2.3.20-3+debian10 amd64 secure POP3/IMAP server - debug symbols ii dovecot-imapd 2:2.3.20-3+debian10 amd64 secure POP3/IMAP server - IMAP daemon ii dovecot-lmtpd 2:2.3.20-3+debian10 amd64 secure POP3/IMAP server - LMTP server ii dovecot-managesieved 2:2.3.20-3+debian10 amd64 secure POP3/IMAP server - ManageSieve server ii dovecot-mysql 2:2.3.20-3+debian10 amd64 secure POP3/IMAP server - MySQL support ii dovecot-pop3d 2:2.3.20-3+debian10 amd64 secure POP3/IMAP server - POP3 daemon ii dovecot-sieve 2:2.3.20-3+debian10 amd64 secure POP3/IMAP server - Sieve filters support
The error produces also "lmtp" and "quota-status" delays:
... Sep 5 07:43:18 dcot-server-1 dovecot: auth: Panic: file oauth2-request.c: line 201 (oauth2_request_start): assertion failed: (oauth2_valid_token(input->token)) Sep 5 07:43:18 dcot-server-1 dovecot: auth: Error: Raw backtrace: /usr/lib/dovecot/libdovecot.so.0(backtrace_append+0x3d) [0x7f216adab85d] -> /usr/lib/dovecot/libdovecot.so.0(backtrace_get+0x1e) [0x7f216adab97e] -> /usr/lib/dovecot/libdovecot.so.0(+0x10091b) [0x7f216adb891b] -> /usr/lib/dovecot/libdovecot.so.0(+0x1009b1) [0x7f216adb89b1] -> /usr/lib/dovecot/libdovecot.so.0(+0x54b7c) [0x7f216ad0cb7c] -> /usr/lib/dovecot/libdovecot.so.0(+0x4605a) [0x7f216acfe05a] -> /usr/lib/dovecot/libdovecot.so.0(oauth2_passwd_grant_start+0xfa) [0x7f216ad1576a] -> dovecot/auth(db_oauth2_lookup+0x2ca) [0x55f3c150968a] -> dovecot/auth(auth_request_default_verify_plain_continue+0x2d6) [0x55f3c14ec436] -> dovecot/auth(auth_policy_check+0x2b) [0x55f3c14e671b] -> dovecot/auth(+0x29f72) [0x55f3c14f5f72] -> dovecot/auth(+0x1ad83) [0x55f3c14e6d83] -> /usr/lib/dovecot/libdovecot.so.0(+0x83db0) [0x7f216ad3bdb0] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_call_io+0x69) [0x7f216adcee59] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_handler_run_internal+0x131) [0x7f216add0481] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_handler_run+0x4c) [0x7f216adceefc] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_run+0x40) [0x7f216adcf080] -> /usr/lib/dovecot/libdovecot.so.0(master_service_run+0x13) [0x7f216ad41e73] -> dovecot/auth(main+0x415) [0x55f3c14e0bf5] -> /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xeb) [0x7f216aa6c09b] -> dovecot/auth(_start+0x2a) [0x55f3c14e0d8a] Sep 5 07:43:18 dcot-server-1 dovecot: imap(4188908): Error: auth-master: login: request [959315969]: Login auth request failed: Disconnected from auth server, aborting (auth connected 4432 msecs ago, request took 21 msecs, client-pid=4184929 client-id=1741) Sep 5 07:43:18 dcot-server-1 dovecot: auth: Fatal: master: service(auth): child 4184931 killed with signal 6 (core dumps disabled - https://dovecot.org/bugreport.html#coredumps) Sep 5 07:43:18 dcot-server-1 dovecot: lmtp(user@domain.com pid:4185087 session:<IK0DKva/9mT/2z8AtdgOrg>): Error: auth-master: userdb lookup(user@domain.com): write(auth socket) failed: Broken pipe Sep 5 07:43:18 dcot-server-1 dovecot: lmtp(4185087): Error: lmtp-server: conn unix:pid=4188719,uid=101 [68]: rcpt user@domain.com: Failed to lookup user user@domain.com: Internal error occurred. Refer to server log for more information. Sep 5 07:43:18 dcot-server-1 dovecot: quota-status(user2@domain.com pid:4185003 session:<>): Error: auth-master: userdb lookup(user2@domain.com): write(auth socket) failed: Broken pipe Sep 5 07:43:18 dcot-server-1 dovecot: quota-status(4185003): Error: Failed to lookup user user2@domain.com: Internal error occurred. Refer to server log for more information. ...
Have you any idea how i can fix this? Perhaps there is something wrong with my configuration.
Many Thanks Urban
Am 07.12.22 um 14:49 schrieb Urban Loesch:
Hi,
I'm running a postfix smtp relay server on which users are getting authenticated trough sasl via the dovecot authentication service. This works without problems.
Recently I extended my configuration to authenticate users with the PLAIN mechanism against Azure AD B2C with oauth2 in the future. Important to mention is that currently no users are stored in Azure B2C. I only prepared the hole configuration and authentiucation falls back to mysql database.
Now sometimes I get the error below in my logs (not permanently): ... Dec 7 11:36:49 relay-out1 dovecot: auth: Panic: file oauth2-request.c: line 201 (oauth2_request_start): assertion failed: (oauth2_valid_token(input->token)) Dec 7 11:36:49 relay-out1 dovecot: auth: Error: Raw backtrace: /usr/lib/dovecot/libdovecot.so.0(backtrace_append+0x3d) [0x7f399402e62d] -> /usr/lib/dovecot/libdovecot.so.0(backtrace_get+0x1e) [0x7f399402e74e] -> /usr/lib/dovecot/libdovecot.so.0(+0x1006eb) [0x7f399403b6eb] -> /usr/lib/dovecot/libdovecot.so.0(+0x100781) [0x7f399403b781] -> /usr/lib/dovecot/libdovecot.so.0(+0x54b7c) [0x7f3993f8fb7c] -> /usr/lib/dovecot/libdovecot.so.0(+0x4605a) [0x7f3993f8105a] -> /usr/lib/dovecot/libdovecot.so.0(oauth2_passwd_grant_start+0xfa) [0x7f3993f9870a] -> dovecot/auth(db_oauth2_lookup+0x2ca) [0x560d0804368a] -> dovecot/auth(auth_request_default_verify_plain_continue+0x2d6) [0x560d08026436] -> dovecot/auth(auth_policy_check+0x2b) [0x560d0802071b] -> dovecot/auth(+0x29f72) [0x560d0802ff72] -> dovecot/auth(auth_request_handler_auth_continue+0xf7) [0x560d0802a197] -> dovecot/auth(+0x16c62) [0x560d0801cc62] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_call_io+0x69) [0x7f3994051c29] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_handler_run_internal+0x131) [0x7f3994053251] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_handler_run+0x4c) [0x7f3994051ccc] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_run+0x40) [0x7f3994051e50] -> /usr/lib/dovecot/libdovecot.so.0(master_service_run+0x13) [0x7f3993fc4df3] -> dovecot/auth(main+0x415) [0x560d0801abf5] -> /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xeb) [0x7f3993cee09b] -> dovecot/auth(_start+0x2a) [0x560d0801ad8a] ...
After the error above postfix says the connection to the authentication server was lost: ... Dec 7 11:36:49 relay-out1 rolrelayout1/smtpd[1655601]: warning: domain.com[12.12.12.12]: SASL LOGIN authentication failed: Connection lost to authentication server ...
I was able to make a core dump. ...
gdb /usr/lib/dovecot/auth core.auth.1654357.1670409409
GNU gdb (Debian 8.2.1-2+b3) 8.2.1 ... For help, type "help". Type "apropos word" to search for commands related to "word"... Reading symbols from /usr/lib/dovecot/auth...Reading symbols from /usr/lib/debug/.build-id/bc/f14ed9cc2dda3ee9565fbd7ccd835460008438.debug...done. done. [New LWP 1654357] [Thread debugging using libthread_db enabled] Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1". Core was generated by `dovecot/auth'. Program terminated with signal SIGABRT, Aborted. #0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50 50 ../sysdeps/unix/sysv/linux/raise.c: Datei oder Verzeichnis nicht gefunden. (gdb) bt full #0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50 set = {__val = {0, 1415, 1416, 94613970086496, 10, 139885273538955, 155, 139885273347109, 140724590457408, 118, 206158430224, 140724590457744, 140724590457536, 16888407779496842752, 94613970086472, 139885273131758}} pid = <optimized out> tid = <optimized out> ret = <optimized out> #1 0x00007f3993cec535 in __GI_abort () at abort.c:79 save_stage = 1 act = {__sigaction_handler = {sa_handler = 0x73f, sa_sigaction = 0x73f}, sa_mask = {__val = {1024, 18446744073709551615, 94613971926672, 94613971631792, 139885273108347, 94613970084312, 139885273090236, 94613970084312, 16888407779496842752, 94613970084288, 139885273346402, 140724590457744, 94613970084312, 140724590457744, 139885273346761, 94613970084312}}, sa_flags = -1811749030, sa_restorer = 0x5} sigs = {__val = {32, 0 <repeats 15 times>}} #2 0x00007f3993f8feaf in default_fatal_finish (status=0, type=LOG_TYPE_PANIC) at failures.c:465 backtrace = 0x560d0813e220 "/usr/lib/dovecot/libdovecot.so.0(backtrace_append+0x3d) [0x7f399402e62d] -> /usr/lib/dovecot/libdovecot.so.0(backtrace_get+0x1e) [0x7f399402e74e] -> /usr/lib/dovecot/libdovecot.so.0(+0x1006eb) [0x7f39"... backtrace = <optimized out> recursed = 0 #3 fatal_handler_real (ctx=<optimized out>, format=<optimized out>, args=<optimized out>) at failures.c:477 status = 0 #4 0x00007f399403b781 in i_internal_fatal_handler (ctx=<optimized out>, format=<optimized out>, args=<optimized out>) at failures.c:879 No locals. #5 0x00007f3993f8fb7c in i_panic (format=format@entry=0x7f399407a0e8 "file %s: line %d (%s): assertion failed: (%s)") at failures.c:530 ctx = {type = LOG_TYPE_PANIC, exit_status = 0, timestamp = 0x0, timestamp_usecs = 0, log_prefix = 0x0, log_prefix_type_pos = 0} args = {{gp_offset = 40, fp_offset = 48, overflow_arg_area = 0x7ffcff39b4e0, reg_save_area = 0x7ffcff39b420}} #6 0x00007f3993f8105a in oauth2_request_start (set=0x560d08176150, input=0x7ffcff39b5d0, callback=0x560d08042b50 <db_oauth2_lookup_passwd_grant>, context=0x560d082ffe90, p=0x560d082b7eb0, method=0x7f399407a2c6 "POST", url=0x560d08178480 "https://xxx.b2clogin.com/xxx.onmicrosoft.com/B2C_1_ropc/oauth2/v2.0/token?sc...", payload=0x560d082b7ed8, add_auth_bearer=false) at oauth2-request.c:201 __func__ = "oauth2_request_start" pool = <optimized out> req = <optimized out> #7 0x00007f3993f9870a in oauth2_passwd_grant_start (set=set@entry=0x560d08176150, input=input@entry=0x7ffcff39b5d0, username=0x560d082ffe38 "user.name", password=0x560d082ffe48 "", callback=callback@entry=0x560d08042b50 <db_oauth2_lookup_passwd_grant>, context=context@entry=0x560d082ffe90) at oauth2-request.c:351 pool = 0x560d082b7eb0 payload = 0x560d082b7ed8 #8 0x0000560d0804368a in db_oauth2_lookup (db=0x560d08176060, req=0x560d082ffe90, token=<optimized out>, request=0x560d082ffba8, callback=0x560d080370b0 <oauth2_verify_plain_continue>, context=0x560d082ffba8) at db-oauth2.c:862 input = {token = 0x560d082ffe48 "", service = 0x560d082ffe20 "smtp", local_ip = {family = 2, u = {ip6 = {__in6_u = {__u6_addr8 = "\303\376\374\322", '\000' <repeats 11 times>, __u6_addr16 = {65219, 54012, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {3539795651, 0, 0, 0}}}, ip4 = {s_addr = 3539795651}}}, real_local_ip = {family = 2, u = {ip6 = {__in6_u = {__u6_addr8 = "\303\376\374\322", '\000' <repeats 11 times>, __u6_addr16 = {65219, 54012, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {3539795651, 0, 0, 0}}}, ip4 = {s_addr = 3539795651}}}, remote_ip = {family = 2, u = {ip6 = {__in6_u = {__u6_addr8 = "*\300\070\226", '\000' <repeats 11 times>, __u6_addr16 = {49194, 38456, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {2520301610, 0, 0, 0}}}, ip4 = {s_addr = 2520301610}}}, real_remote_ip = {family = 2, u = {ip6 = {__in6_u = {__u6_addr8 = "*\300\070\226", '\000' <repeats 11 times>, __u6_addr16 = { 49194, 38456, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {2520301610, 0, 0, 0}}}, ip4 = {s_addr = 2520301610}}}, local_port = 0, real_local_port = 0, remote_port = 0, real_remote_port = 0} __func__ = "db_oauth2_lookup" #9 0x0000560d08026436 in auth_request_default_verify_plain_continue (request=0x560d082ffba8, callback=0x560d0803e6f0 <plain_verify_callback>) at auth-request.c:1123 passdb = 0x560d0814da40 result = 22029 cache_key = <optimized out> error = 0x560d082ffe38 "user.name" password = 0x560d082ffe48 "" __func__ = "auth_request_default_verify_plain_continue" #10 0x0000560d0802071b in auth_policy_check (request=<optimized out>, password=<optimized out>, cb=<optimized out>, context=<optimized out>) at auth-policy.c:575 pool = <optimized out> ctx = <optimized out> #11 0x0000560d0802ff72 in mech_plain_auth_continue (request=0x560d082ffba8, data=0x560d0813d368 "user.name", data_size=30) at mech-plain.c:58 authid = <optimized out> authenid = 0x560d0813d377 "user.name" error = 0x560d0813d320 "h\323\023\b\rV" pass = 0x560d0813d388 "" i = <optimized out> len = <optimized out> count = 2 #12 0x0000560d0802a197 in auth_request_handler_auth_continue (handler=0x560d082d1ae8, args=args@entry=0x560d08268e96 "21\tdGhvbWFzLmZlcnJhcmkAdGhvbWFzLmZlcnJhcmkA") at auth-request-handler.c:738 request = 0x560d082ffba8 data = 0x560d08268e99 "dGhvbWFzLmZlcnJhcmkAdGhvbWFzLmZlcnJhcmkA" data_len = 40 buf = 0x560d0813d320 id = 21 #13 0x0000560d0801cc62 in auth_client_handle_line (line=0x560d08268e91 "CONT\t21\tdGhvbWFzLmZlcnJhcmkAdGhvbWFzLmZlcnJhcmkA", conn=0x560d08276d30) at auth-client-connection.c:228 No locals. #14 auth_client_input (conn=<optimized out>) at auth-client-connection.c:311 _data_stack_cur_id = 3 line = <optimized out> ret = <optimized out> #15 0x00007f3994051c29 in io_loop_call_io (io=0x560d0826f240) at ioloop.c:737 ioloop = 0x560d08145f80 t_id = 2 __func__ = "io_loop_call_io" #16 0x00007f3994053251 in io_loop_handler_run_internal (ioloop=ioloop@entry=0x560d08145f80) at ioloop-epoll.c:222 ctx = 0x560d08148600 events = <optimized out> event = 0x560d08148680 list = 0x560d082ae620 io = <optimized out> tv = {tv_sec = 0, tv_usec = 315566} events_count = <optimized out> msecs = <optimized out> ret = <optimized out> i = 0 j = <optimized out> call = <optimized out> __func__ = "io_loop_handler_run_internal" #17 0x00007f3994051ccc in io_loop_handler_run (ioloop=0x560d08145f80) at ioloop.c:789 __func__ = "io_loop_handler_run" #18 0x00007f3994051e50 in io_loop_run (ioloop=0x560d08145f80) at ioloop.c:762 __func__ = "io_loop_run" #19 0x00007f3993fc4df3 in master_service_run (service=0x560d08145dd0, callback=<optimized out>) at master-service.c:869 No locals. #20 0x0000560d0801abf5 in main (argc=<optimized out>, argv=<optimized out>) at main.c:393 c = <optimized out> ...
And "doveconf -n": ...
2.3.19.1 (9b53102964): /etc/dovecot/dovecot.conf
OS: Linux 5.10.0-18-amd64 x86_64 Debian 10.13
Hostname: relay-out1.domain.com
auth_cache_negative_ttl = 0 auth_cache_size = 40 M auth_cache_ttl = 30 days auth_mechanisms = plain login auth_username_chars = abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ01234567890.-_%@ auth_username_translation = %@ auth_verbose = yes auth_verbose_passwords = plain auth_worker_max_count = 100 disable_plaintext_auth = no namespace inbox { inbox = yes location = mailbox Drafts { special_use = \Drafts } mailbox Junk { special_use = \Junk } mailbox Sent { special_use = \Sent } mailbox "Sent Messages" { special_use = \Sent } mailbox Trash { special_use = \Trash } prefix = } passdb { args = /etc/dovecot/dovecot-oauth2.plain.conf.ext driver = oauth2 mechanisms = plain login } passdb { args = /etc/dovecot/dovecot-sql-account.conf driver = sql } service auth { unix_listener /var/spool/postfix/private/auth { group = postfix mode = 0660 user = postfix } } userdb { args = /etc/dovecot/dovecot-sql-account.conf driver = sql } ...
System OS is Debian 10, Dovecot installed from dovecot repository.
Many thanks Urban
participants (1)
-
Urban Loesch