Re: Panic/Assert dns-lookup.c

[tim]

> Aki Tuomi  hat am 30. März 2020 17:39 geschrieben:
>  
> > On 30/03/2020 18:32 t...@linux-daus.de wrote:
> > 
> > > Aki Tuomi  hat am 30. März 2020 16:23 
> > > geschrieben:
> > >
> > > Can you install dovecot-dbg to get debug symbols, open the core in gdb 
> > > and run 
> > > 
> > > bt full
> > > 
> > 
> > Full backtrace:
> > 
> 
> 
> 
> It seems that your configuration ends up passing empty host from the user 
> lookup to DNS resolve. This should be handled earlier of course, if this is 
> really the case.
> 
> Do you have any idea which user is triggering this based on logs? You could 
> try 'doveadm auth lookup ' to see if you are getting bad values? 
> Are you able to turn on 'auth_debug=yes', I understand it might be high 
> volume with 7k logins.

Thanks for the hint! We were able to identify a user with a look in the core 
dump and i think we were able to find the issue. Some user try to authenticate 
with an "alias user" which typically missing the mailbox host information. 
Currently we do some test to verify the issue. If it is so we will modify the 
database lookups to prevent this circumstances.

Tim

Re: Panic/Assert dns-lookup.c

[Aki Tuomi]

> On 30/03/2020 18:32 t...@linux-daus.de wrote:
> 
>  
> Hi Aki,
> 
> > Aki Tuomi  hat am 30. März 2020 16:23 
> > geschrieben:
> >
> > Can you install dovecot-dbg to get debug symbols, open the core in gdb and 
> > run 
> > 
> > bt full
> > 
> 
> Full backtrace:
> 



> 
> Best regards, 
> Tim

It seems that your configuration ends up passing empty host from the user 
lookup to DNS resolve. This should be handled earlier of course, if this is 
really the case.

Do you have any idea which user is triggering this based on logs? You could try 
'doveadm auth lookup ' to see if you are getting bad values? Are you 
able to turn on 'auth_debug=yes', I understand it might be high volume with 7k 
logins.

Aki

Re: Panic/Assert dns-lookup.c

[tim]

Hi Aki,

> Aki Tuomi  hat am 30. März 2020 16:23 geschrieben:
>
> Can you install dovecot-dbg to get debug symbols, open the core in gdb and 
> run 
> 
> bt full
> 

Full backtrace:

:~# gdb /usr/lib/dovecot/auth core.juu
GNU gdb (Debian 7.12-6) 7.12.0.20161007-git
Copyright (C) 2016 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later 
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-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
.
Find the GDB manual and other documentation resources online at:
.
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/cb/2618dd0e1b77c4402bec008554fe08e287dbdd.debug...done.
done.
[New LWP 6133]
[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:51
51  ../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:51
set = {__val = {0, 94322623831496, 1064, 139808200491339, 
139808199398721, 139808200312250, 139808199398721, 121, 206158430224, 
140729958716272, 140729958716064, 139808200058129, 139808202947872, 
139808200088406, 94322623831496,
0}}
pid = 
tid = 
#1  0x7f27a14a442a in __GI_abort () at abort.c:89
save_stage = 2
act = {__sigaction_handler = {sa_handler = 0x7ffe3f32ccb0, sa_sigaction 
= 0x7ffe3f32ccb0}, sa_mask = {__val = {139808123523248, 139808199398721, 
94322623829368, 139808199398721, 139808200058129, 94322623829368, 1048,
  94322623829424, 94322624549952, 0, 139808200311414, 
94322623829368, 140729958716272, 139808199398721, 139808200311801, 
139808199398721}}, sa_flags = -1575372310, sa_restorer = 0x5}
sigs = {__val = {32, 0 }}
#2  0x7f27a21a68a4 in default_fatal_finish (status=0, type=LOG_TYPE_PANIC) 
at failures.c:459
backtrace = 0x55c9327cd5b0 "#0 t_askpass[0x7f27a219b5f0] -> #1 
backtrace_append[0x7f27a219b860] -> #2 backtrace_get[0x7f27a219b9c0] -> #3 
i_syslog_error_handler[0x7f27a21a6840] -> #4 
i_syslog_fatal_handler[0x7f27a21a6970] -> #5 "...
recursed = 0
recursed = 0
#3  fatal_handler_real (ctx=, format=, 
args=) at failures.c:471
status = 0
#4  0x7f27a21a6991 in i_internal_fatal_handler (ctx=, 
format=, args=) at failures.c:848
No locals.
#5  0x7f27a20fc483 in i_panic (format=format@entry=0x7f27a21e7680 "file %s: 
line %d (%s): assertion failed: (%s)") at failures.c:523
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 = 
0x7ffe3f32d4c0, reg_save_area = 0x7ffe3f32d400}}
#6  0x7f27a2170278 in dns_client_lookup_common (client=, 
cmd=cmd@entry=0x7f27a21ed0eb "IP", param=param@entry=0x55c930eca584 "", 
ptr_lookup=ptr_lookup@entry=false,
callback=callback@entry=0x55c930e9b490 , 
context=context@entry=0x55c93287d440, lookup_r=0x55c93287d450) at 
dns-lookup.c:371
lookup = 0x55c932882320
ret = 
__func__ = "dns_client_lookup_common"
pool = 
e = 
#7  0x7f27a21702bd in dns_client_lookup (client=, 
host=host@entry=0x55c930eca584 "", callback=callback@entry=0x55c930e9b490 
, context=context@entry=0x55c93287d440,
lookup_r=lookup_r@entry=0x7f27a21702bd ) at 
dns-lookup.c:421
No locals.
#8  0x7f27a2170313 in dns_lookup (host=host@entry=0x55c930eca584 "", 
set=set@entry=0x7ffe3f32d550, callback=callback@entry=0x55c930e9b490 
, context=context@entry=0x55c93287d440,
lookup_r=0x7f27a21702bd , 
lookup_r@entry=0x55c93287d450) at dns-lookup.c:206
client = 
#9  0x55c930e9b423 in auth_request_proxy_host_lookup 
(callback=0x55c930e9cab0 , 
host=0x55c930eca584 "", request=0x55c932881628) at auth-request.c:2584
dns_set = {dns_client_socket_path = 0x55c930ec5eaf "dns-client", 
timeout_msecs = 1, idle_timeout_msecs = 0, ioloop = 0x0, event_parent = 0x0}
value = 
secs = 32551
#10 auth_request_proxy_finish (request=request@entry=0x55c932881628, 
callback=callback@entry=0x55c930e9cab0 ) 
at auth-request.c:2631
host = 0x55c930eca584 ""
hostip = 0x0
ip = {family = 54288, u = {ip6 = {__in6_u = {__u6_addr8 = 
"\311U\000\000\035\000\000\000\000\000\000\000\360\247\001", __u6_addr16 =

Re: Panic/Assert dns-lookup.c

[Aki Tuomi]

Hi!

Can you install dovecot-dbg to get debug symbols, open the core in gdb and run 

bt full

Aki

> On 30/03/2020 17:21 t...@linux-daus.de wrote:
> 
>  
> Hi,
> 
> currently we deploying Dovecot as imap/pop3 proxy. Every few minutes some 
> panic/assert occurred (we connect roughly 7k - 8k user at one imap proxy with 
> a connection rate of 200/s).
> 
> We activate core dumps. Concerning the sensitive information in the dump we 
> would prefer to not share the dump (e.g. i found our ssl private key in the 
> dump).
> 
> 
> Log/Stack trace:
> 
> Mar 30 15:54:06 imap16 dovecot: auth: Panic: file dns-lookup.c: line 371 
> (dns_client_lookup_common): assertion failed: (param != NULL && *param != 
> '\0')
> Mar 30 15:54:06 imap16 dovecot: auth: Error: Raw backtrace: #0 
> t_askpass[0x7f27a219b5f0] -> #1 backtrace_append[0x7f27a219b860] -> #2 
> backtrace_get[0x7f27a219b9c0] -> #3 i_syslog_error_handler[0x7f27a21a6840] -> 
> #4 i_syslog_fatal_handler[0x7f27a21a6970] -> #5 i_fatal[0x7f27a20fc3b7] -> #6 
> dns_client_connect[0x7f27a216ffb0] -> #7 dns_client_lookup[0x7f27a21702a0] -> 
> #8 auth_request_proxy_finish[0x55c930e9b200] -> #9 
> auth_request_handler_reply[0x55c930e9cee0] -> #10 
> auth_policy_check[0x55c930e93a10] -> #11 auth_request_success[0x55c930e9bcf0] 
> -> #12 auth_request_verify_plain_callback_finish[0x55c930e9a650] -> #13 
> auth_request_verify_plain_callback[0x55c930e9a7a0] -> #14 
> authdb_ldap_deinit[0x7f279faa9f10] -> #15 
> db_ldap_result_iterate_deinit[0x7f279faa7f70] -> #16 
> io_loop_call_io[0x7f27a21c0490] -> #17 
> io_loop_handler_run_internal[0x7f27a21c1e20] -> #18 
> io_loop_handler_run[0x7f27a21c05c0] -> #19 io_loop_run[0x7f27a21c0810] -> #20 
> master_service_run[0x7f27a212d5b0] -> #21 main[0x55c930
 e8
>  dd10] -> #22 __libc_start_main[0x7f27a14901f0] -> #23 _start[0x55c930e8e2c0] 
> -> #24 [no start/end information]
> Mar 30 15:54:06 imap16 dovecot: auth: Fatal: master: service(auth): child 
> 6133 killed with signal 6 (core dumped)
> 
> 
> Config:
> 
> # 2.3.9.2 (844fc8246): /etc/dovecot/dovecot.conf
> # Pigeonhole version 0.5.9 (db4e9a2f)
> # OS: Linux 4.9.0-12-amd64 x86_64 Debian 9.12
> # Hostname: imap16.domain.de
> auth_default_realm = domain.de
> auth_failure_delay = 0
> auth_mechanisms = plain login cram-md5
> auth_username_format = %{if;%d;eq;domain.de;%n...@olddomain.de;%u}
> auth_verbose = yes
> base_dir = /var/run/dovecot/
> default_client_limit = 4096
> default_internal_user = pop
> default_process_limit = 400
> default_vsz_limit = 1 G
> doveadm_password = # hidden, use -P to show it
> first_valid_uid = 48
> import_environment = TZ
> last_valid_uid = 48
> login_trusted_networks = 192.168.11.0/24
> mail_gid = pop
> mail_plugins = " mail_log notify zlib quota"
> mail_uid = pop
> passdb {
>   args = /etc/dovecot/conf.d/dovecot-ldap-domain-proxy.conf.ext
>   driver = ldap
>   result_failure = return-fail
>   result_success = continue-ok
> }
> passdb {
>   args = allow_real_nets=192.168.11.0/24
>   driver = static
>   result_failure = continue-ok
> }
> passdb {
>   args = /etc/dovecot/conf.d/dovecot-ldap-domain-protocol-deny.conf.ext
>   driver = ldap
>   result_failure = return-ok
>   result_success = return-fail
> }
> passdb {
>   args = /etc/dovecot/passdb-domain-ldap-cram.conf.ext
>   driver = ldap
>   mechanisms = CRAM-MD5
>   result_failure = continue-fail
>   result_success = continue-ok
> }
> passdb {
>   args = /etc/dovecot/passdb-domain-ldap.conf.ext
>   driver = ldap
>   mechanisms = LOGIN,PLAIN
>   result_failure = return-fail
>   result_success = continue-ok
> }
> plugin {
>   mail_log_events = delete undelete expunge copy mailbox_delete mailbox_rename
>   mail_log_fields = uid box msgid size
>   zlib_save = gz
>   zlib_save_level = 6
> }
> protocols = " imap pop3"
> service auth {
>   unix_listener auth-client {
> group = dovecot_auth
> mode = 0660
> user = $default_internal_user
>   }
> }
> service doveadm {
>   group = pop
>   inet_listener {
> port = 12345
>   }
>   user = pop
> }
> service imap-login {
>   process_min_avail = 24
>   service_count = 0
> }
> service pop3-login {
>   process_min_avail = 24
>   service_count = 0
> }
> ssl = required
> ssl_cert =  ssl_cipher_list = 
> ECDHE-ECDSA-CHACHA20-POLY1305:ECDHE-RSA-CHACHA20-POLY1305:ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES256-GCM-SHA384:ECDHE-ECDSA-AES128-SHA:ECDHE-ECDSA-AES256-SHA:ECDHE-ECDSA-AES128-SHA256:ECDHE-ECDSA-AES256-SHA384:ECDHE-RSA-AES128-GCM-SHA256:ECDHE-RSA-AES256-GCM-SHA384:ECDHE-RSA-AES128-SHA:ECDHE-RSA-AES256-SHA:ECDHE-RSA-AES128-SHA256:ECDHE-RSA-AES256-SHA384:DHE-RSA-AES128-GCM-SHA256:DHE-RSA-AES256-GCM-SHA384:DHE-RSA-AES128-SHA:DHE-RSA-AES256-SHA:DHE-RSA-AES128-SHA256:DHE-RSA-AES256-SHA256:DHE-RSA-CAMELLIA128-SHA:DHE-RSA-CAMELLIA256-SHA:AES128-GCM-SHA256:AES256-GCM-SHA384:AES128-SHA256:AES256-SHA256:AES128-SHA:AES256-SHA:CAMELLIA128-SHA:CAMELLIA256-SHA
> ssl_dh = # hidden, use -P to show it
> ssl_key = # hidden, use -P to show it
> verbose_proctitle = yes

Panic/Assert dns-lookup.c

[tim]

Hi,

currently we deploying Dovecot as imap/pop3 proxy. Every few minutes some 
panic/assert occurred (we connect roughly 7k - 8k user at one imap proxy with a 
connection rate of 200/s).

We activate core dumps. Concerning the sensitive information in the dump we 
would prefer to not share the dump (e.g. i found our ssl private key in the 
dump).


Log/Stack trace:

Mar 30 15:54:06 imap16 dovecot: auth: Panic: file dns-lookup.c: line 371 
(dns_client_lookup_common): assertion failed: (param != NULL && *param != '\0')
Mar 30 15:54:06 imap16 dovecot: auth: Error: Raw backtrace: #0 
t_askpass[0x7f27a219b5f0] -> #1 backtrace_append[0x7f27a219b860] -> #2 
backtrace_get[0x7f27a219b9c0] -> #3 i_syslog_error_handler[0x7f27a21a6840] -> 
#4 i_syslog_fatal_handler[0x7f27a21a6970] -> #5 i_fatal[0x7f27a20fc3b7] -> #6 
dns_client_connect[0x7f27a216ffb0] -> #7 dns_client_lookup[0x7f27a21702a0] -> 
#8 auth_request_proxy_finish[0x55c930e9b200] -> #9 
auth_request_handler_reply[0x55c930e9cee0] -> #10 
auth_policy_check[0x55c930e93a10] -> #11 auth_request_success[0x55c930e9bcf0] 
-> #12 auth_request_verify_plain_callback_finish[0x55c930e9a650] -> #13 
auth_request_verify_plain_callback[0x55c930e9a7a0] -> #14 
authdb_ldap_deinit[0x7f279faa9f10] -> #15 
db_ldap_result_iterate_deinit[0x7f279faa7f70] -> #16 
io_loop_call_io[0x7f27a21c0490] -> #17 
io_loop_handler_run_internal[0x7f27a21c1e20] -> #18 
io_loop_handler_run[0x7f27a21c05c0] -> #19 io_loop_run[0x7f27a21c0810] -> #20 
master_service_run[0x7f27a212d5b0] -> #21 main[0x55c930e8
 dd10] -> #22 __libc_start_main[0x7f27a14901f0] -> #23 _start[0x55c930e8e2c0] 
-> #24 [no start/end information]
Mar 30 15:54:06 imap16 dovecot: auth: Fatal: master: service(auth): child 6133 
killed with signal 6 (core dumped)


Config:

# 2.3.9.2 (844fc8246): /etc/dovecot/dovecot.conf
# Pigeonhole version 0.5.9 (db4e9a2f)
# OS: Linux 4.9.0-12-amd64 x86_64 Debian 9.12
# Hostname: imap16.domain.de
auth_default_realm = domain.de
auth_failure_delay = 0
auth_mechanisms = plain login cram-md5
auth_username_format = %{if;%d;eq;domain.de;%n...@olddomain.de;%u}
auth_verbose = yes
base_dir = /var/run/dovecot/
default_client_limit = 4096
default_internal_user = pop
default_process_limit = 400
default_vsz_limit = 1 G
doveadm_password = # hidden, use -P to show it
first_valid_uid = 48
import_environment = TZ
last_valid_uid = 48
login_trusted_networks = 192.168.11.0/24
mail_gid = pop
mail_plugins = " mail_log notify zlib quota"
mail_uid = pop
passdb {
  args = /etc/dovecot/conf.d/dovecot-ldap-domain-proxy.conf.ext
  driver = ldap
  result_failure = return-fail
  result_success = continue-ok
}
passdb {
  args = allow_real_nets=192.168.11.0/24
  driver = static
  result_failure = continue-ok
}
passdb {
  args = /etc/dovecot/conf.d/dovecot-ldap-domain-protocol-deny.conf.ext
  driver = ldap
  result_failure = return-ok
  result_success = return-fail
}
passdb {
  args = /etc/dovecot/passdb-domain-ldap-cram.conf.ext
  driver = ldap
  mechanisms = CRAM-MD5
  result_failure = continue-fail
  result_success = continue-ok
}
passdb {
  args = /etc/dovecot/passdb-domain-ldap.conf.ext
  driver = ldap
  mechanisms = LOGIN,PLAIN
  result_failure = return-fail
  result_success = continue-ok
}
plugin {
  mail_log_events = delete undelete expunge copy mailbox_delete mailbox_rename
  mail_log_fields = uid box msgid size
  zlib_save = gz
  zlib_save_level = 6
}
protocols = " imap pop3"
service auth {
  unix_listener auth-client {
group = dovecot_auth
mode = 0660
user = $default_internal_user
  }
}
service doveadm {
  group = pop
  inet_listener {
port = 12345
  }
  user = pop
}
service imap-login {
  process_min_avail = 24
  service_count = 0
}
service pop3-login {
  process_min_avail = 24
  service_count = 0
}
ssl = required
ssl_cert =