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(u...@domain.com pid:4185087 session:<IK0DKva/9mT/2z8AtdgOrg>): Error: auth-master: userdb
lookup(u...@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 u...@domain.com: Failed to lookup
user u...@domain.com: Internal error occurred. Refer to server log for more information.
Sep 5 07:43:18 dcot-server-1 dovecot: quota-status(us...@domain.com pid:4185003 session:<>): Error: auth-master: userdb lookup(us...@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 us...@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?scope=xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx";,
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
_______________________________________________
dovecot mailing list -- dovecot@dovecot.org
To unsubscribe send an email to dovecot-le...@dovecot.org
