Hi,
- legacy customer requirement...
- we will try to remove nodelay
thanks
Am 07.01.2021 um 00:05 schrieb Josef 'Jeff' Sipek:
On Wed, Jan 06, 2021 at 14:07:06 -0500, Josef 'Jeff' Sipek wrote:
Ok, just a quick update. I managed to reproduce it. I'll try to figure out where things went wrong.
Two more questions:
(1) Why are you using a UNION in your SQL statement?
(2) Does the crash still happen if you remove the nodelay parts of the SQL statements?
Thanks,
Jeff.
Thanks,
Jeff.
On Wed, Jan 06, 2021 at 18:22:03 +0100, Harald Leithner wrote:
Hi
Am 06.01.2021 um 18:08 schrieb Josef 'Jeff' Sipek:
On Wed, Jan 06, 2021 at 17:13:05 +0100, Harald Leithner wrote:
Hi,
and the user part with "user@redacted".
I assume you did this for additional privacy, and not because you think that auth_debug_passwords=no should hide usernames as well.
yes
The user uses APOP for authentication, but other users login successfully with APOP.
Do you only use APOP? Or are other authentication schemes affected as well?
No
Can you share your config? (
doveconf -nwill be a good start, any .ext files may be useful as well)yes here is the dovecot -n
[root@mail:~]$ doveconf -n # 2.3.13 (89f716dc2): /etc/dovecot/dovecot.conf # OS: Linux 5.9.16-100.fc32.x86_64 x86_64 Generic release 32 (Generic) # Hostname: xxxx auth_cache_negative_ttl = 10 secs auth_cache_size = 64 k auth_cache_ttl = 30 secs auth_mechanisms = CRAM-MD5 DIGEST-MD5 APOP LOGIN PLAIN auth_username_chars = abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ01234567890.-_@% auth_username_translation = %@AaBbCcDdEeFfGgHhIiJjKkLlMmNnOoPpQqRrSsTtUuVvWwXxYyZz auth_worker_max_count = 150 disable_plaintext_auth = no imap_capability = IMAP4 IMAP4rev1 ACL RIGHTS=texk NAMESPACE CHILDREN SORT QUOTA THREAD=ORDEREDSUBJECT UNSELECT IDLE login_greeting = login_log_format_elements = user=<%u> %r %m %c %k mail_max_userip_connections = 100 passdb { args = /etc/dovecot/sql.conf driver = sql } protocols = imap pop3 service anvil { unix_listener anvil-auth-penalty { mode = 00 } } service auth { unix_listener /var/spool/postfix/private/auth { group = postfix mode = 0660 user = postfix } } service imap-login { client_limit = 300 inet_listener imap { address = xx.xx.xx.xx port = 143 } inet_listener imaps { address = xx.xx.xx.xx port = 993 } process_limit = 15 process_min_avail = 1 service_count = 0 vsz_limit = 512 M } service pop3-login { client_limit = 300 inet_listener pop3 { address = xx.xx.xx.xx port = 110 } inet_listener pop3s { address = xx.xx.xx.xx port = 995 } process_limit = 15 process_min_avail = 1 service_count = 0 vsz_limit = 512 M } service stats { client_limit = 10000 } shutdown_clients = no ssl_alt_cert =
Thanks,
Jeff.
thx
Harald
Here is a stacktrace and a log dump:
Jan 6 16:29:44 mail kernel: auth[2208397]: segfault at ec ip 00007f67fc147174 sp 00007ffeed993150 error 4 in libdovecot.so.0.0.0[7f67fc06e000+fc000] Jan 6 16:29:44 mail kernel: Code: 1f 80 00 00 00 00 41 54 e8 79 fd ff ff 31 f6 49 89 c4 48 89 c7 31 c0 e8 ca f8 ff ff 4c 89 e0 41 5c c3 0f 1f 40 00 53 48 89 fb <f6> 87 ec 00 00 00 04 75 43 48 83 3d 7b aa 0a 00 00 0f 85 50 15 f4 Jan 6 16:29:44 mail systemd[1]: Started Process Core Dump (PID 2208677/UID 0). Jan 6 16:29:44 mail systemd-coredump[2208678]: Process 2208397 (auth) of user 489 dumped core.#012#012Stack trace of thread 2208397:#012#0 0x00007f67fc147174 event_create_passthrough (libdovecot.so.0 + 0x116174)#012#1 0x0000555678812d6e auth_request_finished_event (auth + 0x1bd6e)#012#2 0x00005556788159ae auth_request_log_finished (auth + 0x1e9ae)#012#3 0x0000555678816ee0 n/a (auth + 0x1fee0)#012#4 0x0000555678826dc1 passdb_handle_credentials (auth + 0x2fdc1)#012#5 0x0000555678816c7e n/a (auth + 0x1fc7e)#012#6 0x0000555678824f27 n/a (auth + 0x2df27)#012#7 0x000055567881b02d auth_request_handler_auth_begin (auth + 0x2402d)#012#8 0x000055567880dfaf n/a (auth + 0x16faf)#012#9 0x00007f67fc143a79 io_loop_call_io (libdovecot.so.0 + 0x112a79)#012#10 0x00007f67fc144ae2 io_loop_handler_run_internal (libdovecot.so.0 + 0x113ae2)#012#11 0x00007f67fc143b21 io_loop_handler_run (libdovecot.so.0 + 0x112b21)#012#12 0x00007f67fc143ce0 io_loop_run (libdovecot.so.0 + 0x112ce0)#012#13 0x00007f67fc0b96f3 master_service_run (libdovecot.so.0
- 0x886f3)#012#14 0x000055567880c2db main (auth + 0x152db)#012#15 0x00007f67fbc9d042 __libc_start_main (libc.so.6 + 0x27042)#012#16 0x000055567880c48e _start (auth + 0x1548e)
Jan 6 16:29:44 mail dovecot[2208071]: auth: Debug: client in: AUTH#011134#011PLAIN#011service=imap#011session=tgog/jy4erm5j7ZO#011lip=lan-ip#011rip=client-ip#011lport=143#011rport=47482 Jan 6 16:29:44 mail dovecot[2208071]: auth: Debug: client passdb out: CONT#011134 Jan 6 16:29:44 mail dovecot[2208071]: auth: Debug: client in: CONT<hidden> Jan 6 16:29:44 mail dovecot[2208071]: auth: Debug: sql(user@redacted,client-ip,
): Performing passdb lookup Jan 6 16:29:44 mail dovecot[2208071]: auth: Debug: sql(user@redacted,client-ip, ): cache expired Jan 6 16:29:44 mail dovecot[2208071]: auth-worker(2208404): Debug: conn unix:auth-worker (pid=2208397,uid=489): auth-worker<229>: Handling PASSV request Jan 6 16:29:44 mail dovecot[2208071]: auth-worker(2208404): Debug: conn unix:auth-worker (pid=2208397,uid=489): auth-worker<229>: sql(user@redacted,client-ip, ): Performing passdb lookup Jan 6 16:29:44 mail dovecot[2208071]: auth-worker(2208404): Debug: conn unix:auth-worker (pid=2208397,uid=489): auth-worker<229>: sql(user@redacted,client-ip, ): query: SELECT passwd as password, '127.0.0.1' as host, userid as destuser, passwd AS pass, 'Y' AS nologin, 'Y' AS nodelay, 'Y' AS proxy FROM dbmail_users WHERE userid='user@redacted' UNION (SELECT password as password, '127.0.0.1' as host, username as destuser, password AS pass, 'Y' AS nologin, 'Y' AS nodelay, 'Y' AS proxy FROM sasl_fake_auth WHERE username='user@redacted') limit 1; Jan 6 16:29:44 mail dovecot[2208071]: auth-worker(2208404): conn unix:auth-worker (pid=2208397,uid=489): auth-worker<229>: sql(user@redacted,client-ip, ): Password mismatch Jan 6 16:29:44 mail dovecot[2208071]: auth-worker(2208404): Debug: conn unix:auth-worker (pid=2208397,uid=489): auth-worker<229>: sql(user@redacted,client-ip, ): Finished passdb lookup Jan 6 16:29:44 mail dovecot[2208071]: auth-worker(2208404): Debug: conn unix:auth-worker (pid=2208397,uid=489): auth-worker<229>: Finished Jan 6 16:29:44 mail dovecot[2208071]: auth: Debug: sql(user@redacted,client-ip, ): Finished passdb lookup Jan 6 16:29:44 mail dovecot[2208071]: auth: Debug: auth(user@redacted,client-ip, ): Auth request finished Jan 6 16:29:44 mail dovecot[2208071]: auth: Debug: client in: AUTH#011443#011APOP#011service=pop3#011secured=tls#011session=n58h/jy4a0i5j7ZO#011lip=lan-ip#011rip=client-ip#011lport=995#011rport=18539#011local_name=mail#011resp=<hidden> Jan 6 16:29:44 mail dovecot[2208071]: auth: Debug: sql(user@redacted,client-ip, ): Performing passdb lookup Jan 6 16:29:44 mail dovecot[2208071]: auth: Debug: sql(user@redacted,client-ip, ): cache hit: <hidden>#011host=127.0.0.1#011destuser=user@redacted#011pass=THIS_SHOULD_NOT_GET_LOGGED#011nologin=Y#011nodelay=Y#011proxy=Y Jan 6 16:29:44 mail dovecot[2208071]: auth: Debug: sql(user@redacted,client-ip, ): Finished passdb lookup Jan 6 16:29:44 mail dovecot[2208071]: auth: Debug: auth(user@redacted,client-ip, ): Auth request finished Jan 6 16:29:44 mail dovecot[2208071]: auth: Debug: client passdb out: FAIL#011443#011user=user@redacted#011nodelay#011pass=<hidden>#011nodelay=Y Jan 6 16:29:44 mail dovecot[2208071]: pop3-login: Debug: Ignoring unknown passdb extra field: nodelay Jan 6 16:29:44 mail dovecot[2208071]: pop3-login: Debug: Ignoring unknown passdb extra field: nodelay Jan 6 16:29:44 mail dovecot[2208071]: pop3-login: Disconnected (auth failed, 1 attempts in 0 secs): user=user@redacted, client-ip, APOP, TLS, TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) Jan 6 16:29:44 mail dovecot[2208071]: auth-worker(2208404): Debug: conn unix:auth-worker (pid=2208397,uid=489): Disconnected: Connection closed (fd=-1) Jan 6 16:29:44 mail dovecot[2208071]: auth: Fatal: master: service(auth): child 2208397 killed with signal 11 (core dumped)h-worker<1>: Handling PASSV request Jan 6 16:20:05 mail dovecot[2208071]: auth: Debug: client in: AUTH#01179#011PLAIN#011service=imap#011session=QY6V2zy4FUm5j7YD#011lip=lan-ip#011rip=client-ip#011lport=143#011rport=18709 Jan 6 16:20:05 mail dovecot[2208071]: auth: Debug: client passdb out: CONT#01179 Jan 6 16:20:05 mail dovecot[2208071]: auth: Debug: client in: CONT<hidden> Jan 6 16:20:05 mail dovecot[2208071]: auth: Debug: sql(user@redacted,client-ip,<QY6V2zy4FUm5j7YD>): Performing passdb lookup Jan 6 16:20:05 mail dovecot[2208071]: auth: Debug: sql(user@redacted,client-ip,<QY6V2zy4FUm5j7YD>): cache expired Jan 6 16:20:05 mail dovecot[2208071]: auth-worker(2208083): Debug: conn unix:auth-worker (pid=2208074,uid=489): auth-worker<235>: Handling PASSV request Jan 6 16:20:05 mail dovecot[2208071]: auth-worker(2208083): Debug: conn unix:auth-worker (pid=2208074,uid=489): auth-worker<235>: sql(user@redacted,client-ip,<QY6V2zy4FUm5j7YD>): Performing passdb lookup Jan 6 16:20:05 mail dovecot[2208071]: auth-worker(2208083): Debug: conn unix:auth-worker (pid=2208074,uid=489): auth-worker<235>: sql(user@redacted,client-ip,<QY6V2zy4FUm5j7YD>): query: SELECT passwd as password, '127.0.0.1' as host, userid as destuser, passwd AS pass, 'Y' AS nologin, 'Y' AS nodelay, 'Y' AS proxy FROM dbmail_users WHERE userid='user@redacted' UNION (SELECT password as password, '127.0.0.1' as host, username as destuser, password AS pass, 'Y' AS nologin, 'Y' AS nodelay, 'Y' AS proxy FROM sasl_fake_auth WHERE username='user@redacted') limit 1; Jan 6 16:20:05 mail dovecot[2208071]: auth-worker(2208083): conn unix:auth-worker (pid=2208074,uid=489): auth-worker<235>: sql(user@redacted,client-ip,<QY6V2zy4FUm5j7YD>): Password mismatch Jan 6 16:20:05 mail dovecot[2208071]: auth-worker(2208083): Debug: conn unix:auth-worker (pid=2208074,uid=489): auth-worker<235>: sql(user@redacted,client-ip,<QY6V2zy4FUm5j7YD>): Finished passdb lookup Jan 6 16:20:05 mail dovecot[2208071]: auth-worker(2208083): Debug: conn unix:auth-worker (pid=2208074,uid=489): auth-worker<235>: Finished Jan 6 16:20:05 mail dovecot[2208071]: auth: Debug: sql(user@redacted,client-ip,<QY6V2zy4FUm5j7YD>): Finished passdb lookup Jan 6 16:20:05 mail dovecot[2208071]: auth: Debug: auth(user@redacted,client-ip,<QY6V2zy4FUm5j7YD>): Auth request finished Jan 6 16:20:05 mail dovecot[2208071]: auth: Debug: client in: AUTH#011215#011APOP#011service=pop3#011secured=tls#011session=ZJWX2zy4VzO5j7YD#011lip=lan-ip#011rip=client-ip#011lport=995#011rport=13143#011local_name=mail#011resp=<hidden> Jan 6 16:20:05 mail dovecot[2208071]: auth: Debug: sql(user@redacted,client-ip,<ZJWX2zy4VzO5j7YD>): Performing passdb lookup Jan 6 16:20:05 mail dovecot[2208071]: auth: Debug: sql(user@redacted,client-ip,<ZJWX2zy4VzO5j7YD>): cache hit: <hidden>#011host=127.0.0.1#011destuser=user@redacted#011pass=THIS_SHOULD_NOT_GET_LOGGED#011nologin=Y#011nodelay=Y#011proxy=Y Jan 6 16:20:05 mail dovecot[2208071]: auth: Debug: sql(user@redacted,client-ip,<ZJWX2zy4VzO5j7YD>): Finished passdb lookup Jan 6 16:20:05 mail dovecot[2208071]: auth: Debug: auth(user@redacted,client-ip,<ZJWX2zy4VzO5j7YD>): Auth request finished Jan 6 16:20:05 mail dovecot[2208071]: auth: Debug: client passdb out: FAIL#011215#011user=user@redacted#011nodelay#011pass=<hidden>#011nodelay=Y Jan 6 16:20:05 mail dovecot[2208071]: pop3-login: Debug: Ignoring unknown passdb extra field: nodelay Jan 6 16:20:05 mail dovecot[2208071]: pop3-login: Debug: Ignoring unknown passdb extra field: nodelay Jan 6 16:20:05 mail dovecot[2208071]: pop3-login: Disconnected (auth failed, 1 attempts in 0 secs): user=user@redacted, client-ip, APOP, TLS, TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) Jan 6 16:20:05 mail dovecot[2208071]: auth-worker(2208083): Debug: conn unix:auth-worker (pid=2208074,uid=489): Disconnected: Connection closed (fd=-1) Jan 6 16:20:05 mail dovecot[2208071]: auth: Fatal: master: service(auth): child 2208074 killed with signal 11 (core dumped)
Jan 6 16:20:20 mail dovecot[2208071]: auth: Debug: client in: AUTH#011218#011APOP#011service=pop3#011secured=tls#011session=wXyB3Dy4W0i5j7YD#011lip=lan-ip#011rip=client-ip#011lport=995#011rport=18523#011local_name=mail#011resp=<hidden> Jan 6 16:20:20 mail dovecot[2208071]: auth: Debug: sql(user@redacted,client-ip,<wXyB3Dy4W0i5j7YD>): Performing passdb lookup Jan 6 16:20:20 mail dovecot[2208071]: auth: Debug: sql(user@redacted,client-ip,<wXyB3Dy4W0i5j7YD>): cache hit: <hidden>#011host=127.0.0.1#011destuser=user@redacted#011pass=THIS_SHOULD_NOT_GET_LOGGED#011nologin=Y#011nodelay=Y#011proxy=Y Jan 6 16:20:20 mail dovecot[2208071]: auth: Debug: sql(user@redacted,client-ip,<wXyB3Dy4W0i5j7YD>): Finished passdb lookup Jan 6 16:20:20 mail dovecot[2208071]: auth: Debug: auth(user@redacted,client-ip,<wXyB3Dy4W0i5j7YD>): Auth request finished Jan 6 16:20:20 mail dovecot[2208071]: auth: Debug: client passdb out: FAIL#011218#011user=user@redacted#011nodelay#011pass=<hidden>#011nodelay=Y Jan 6 16:20:20 mail dovecot[2208071]: pop3-login: Debug: Ignoring unknown passdb extra field: nodelay Jan 6 16:20:20 mail dovecot[2208071]: pop3-login: Debug: Ignoring unknown passdb extra field: nodelay Jan 6 16:20:20 mail dovecot[2208071]: pop3-login: Disconnected (auth failed, 1 attempts in 0 secs): user=user@redacted, client-ip, APOP, TLS, TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) Jan 6 16:20:20 mail dovecot[2208071]: auth-worker(2208392): Debug: conn unix:auth-worker (pid=2208385,uid=489): Disconnected: Connection closed (fd=-1) Jan 6 16:20:20 mail dovecot[2208071]: auth: Fatal: master: service(auth): child 2208385 killed with signal 11 (core dumped)
Any help is appreciated thanks
Harald
ITronic
Harald Leithner Wiedner Hauptstraße 120/5.1, 1050 Wien, Austria Tel: +43-1-545 0 604 Mobil: +43-699-123 78 4 78 Mail: leithner@itronic.at | itronic.at
-- ITronic
Harald Leithner Wiedner Hauptstraße 120/5.1, 1050 Wien, Austria Tel: +43-1-545 0 604 Mobil: +43-699-123 78 4 78 Mail: leithner@itronic.at | itronic.at
-- ITronic
Harald Leithner Wiedner Hauptstraße 120/5.1, 1050 Wien, Austria Tel: +43-1-545 0 604 Mobil: +43-699-123 78 4 78 Mail: leithner@itronic.at | itronic.at