Hello,
after migrating from self-compiled Dovecot 2.3.3 to Dovecot 2.3.8 from the repository (Ubuntu 18.04 LTS "Bionic" packages) I have issues with the submission service. If I send an email, it will not be forwarded and I get the following error message:
Oct 11 09:29:01 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Panic: file smtp-client-connection.c: line 1212 (smtp_client_connection_established): assertion failed: (!conn->connect_succeeded) Oct 11 09:29:01 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Error: Raw backtrace: /usr/lib/dovecot/libdovecot.so.0(+0xe7f7e) [0x7f64b1f76f7e] -> /usr/lib/dovecot/libdovecot.so.0(+0xe8021) [0x7f64b1f77021] -> /usr/lib/dovecot/libdovecot.so.0(i_fatal+0) [0x7f64b1ecfaf4] -> /usr/lib/dovecot/libdovecot.so.0(+0x50ec8) [0x7f64b1edfec8] -> /usr/lib/dovecot/libdovecot.so.0(+0x51078) [0x7f64b1ee0078] -> /usr/lib/dovecot/libdovecot.so.0(+0x541f4) [0x7f64b1ee31f4] -> /usr/lib/dovecot/libdovecot.so.0(smtp_client_command_input_reply+0x1f8) [0x7f64b1edb738] -> /usr/lib/dovecot/libdovecot.so.0(+0x54a93) [0x7f64b1ee3a93] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_call_io+0x6f) [0x7f64b1f909af] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_handler_run_internal+0x13c) [0x7f64b1f9237c] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_handler_run+0x4c) [0x7f64b1f90abc] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_run+0x38) [0x7f64b1f90cd8] -> /usr/lib/dovecot/libdovecot.so.0(master_service_run+0x13) [0x7f64b1eff053] -> dovecot/submission hativ@example.com fec0:810c:c0c0:8a0:342a:8478:1ee:4f8e GREETING [0x55dcc748fec1] -> /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xe7) [0x7f64b1abfb97] -> dovecot/submission hativ@example.com fec0:810c:c0c0:8a0:342a:8478:1ee:4f8e GREETING [0x55dcc749009a]
Does somebody has any idea? The problem has been taking me months, now I want to finally update to the current version.
Full debug log: Oct 11 09:29:00 srv2 dovecot: submission-login: Login: user=< hativ@example.com>, method=PLAIN, rip=fec0:810c:c0c0:8a0:342a:8478:1ee:4f8e, lip=fec0:4f8:1c0c:8099::1, mpid=15819, TLS, session=<XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+O> Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: Loading modules from directory: /usr/lib/dovecot/modules Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: Module loaded: /usr/lib/dovecot/modules/lib01_acl_plugin.so Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: Module loaded: /usr/lib/dovecot/modules/lib10_mail_crypt_plugin.so Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: Module loaded: /usr/lib/dovecot/modules/lib10_quota_plugin.so Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: Module loaded: /usr/lib/dovecot/modules/lib15_notify_plugin.so Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: Module loaded: /usr/lib/dovecot/modules/lib20_mail_log_plugin.so Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: Module loaded: /usr/lib/dovecot/modules/lib20_quota_clone_plugin.so Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: Module loaded: /usr/lib/dovecot/modules/lib20_replication_plugin.so Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: Added userdb setting: plugin/mail_crypt_private_password=<hidden> Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: Added userdb setting: plugin/mail_crypt_save_version=0 Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: Added userdb setting: plugin/quota_rule=*:bytes=0 Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: Effective uid=998, gid=998, home=/srv/mail/example.com/hativ Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: Quota root: name= backend=count args= Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: Quota rule: root= mailbox=* bytes=0 messages=0 Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: Quota grace: root= bytes=0 (10%) Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: Namespace INBOX: type=private, prefix=, sep=, inbox=yes, hidden=no, list=yes, subscriptions=yes location=sdbox:~/ Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: fs: root=/srv/mail/example.com/hativ, index=, indexpvt=, control=, inbox=, alt= Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: acl: initializing backend with data: vfile Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: acl: acl username = hativ@example.com Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: acl: owner = 1 Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: acl vfile: Global ACLs disabled Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: Namespace Shared: type=shared, prefix=Shared/%u/, sep=, inbox=no, hidden=no, list=children, subscriptions=yes location=sdbox:%h/:INDEXPVT=~/shares/%u Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: shared: root=/var/run/dovecot, index=, indexpvt=, control=, inbox=, alt= Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: acl: initializing backend with data: vfile Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: acl: acl username = hativ@example.com Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: acl: owner = 0 Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: acl vfile: Global ACLs disabled Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: quota: quota_over_flag check: quota_over_script unset - skipping Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: smtp-server: conn [fec0:810c:c0c0:8a0:342a:8478:1ee:4f8e]:47314 [1]: Server accepted connection (fd=7) Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: smtp-server: conn [fec0:810c:c0c0:8a0:342a:8478:1ee:4f8e]:47314 [1]: Connection created Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: smtp-client: conn mta2.example.com:25 [1]: Connection created Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: smtp-client: conn mta2.example.com:25 [1]: Looking up IP address Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: smtp-client: conn mta2.example.com:25 [1]: DNS lookup successful; got 2 IPs Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: smtp-server: conn [fec0:810c:c0c0:8a0:342a:8478:1ee:4f8e]:47314 [1]: Sent: 235 2.7.0 Logged in. Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: smtp-client: conn mta2.example.com:25 [1]: Connecting to 10.46.163.91:25 Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: smtp-client: conn mta2.example.com:25 (10.46.163.91:25) [1]: Connecting Oct 11 09:29:00 srv2 postfix/smtpd[15229]: connect from srv2[10.46.163.91] Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: smtp-client: conn mta2.example.com:25 (10.46.163.91:25) [1]: Waiting for connect (fd=8) to finish for max 0 msecs Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: smtp-client: conn mta2.example.com:25 (10.46.163.91:25) [1]: Client connected (fd=8) Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: smtp-client: conn mta2.example.com:25 (10.46.163.91:25) [1]: Connected to server (from 10.46.163.91:60230) Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: smtp-client: conn mta2.example.com:25 (10.46.163.91:25) [1]: Received greeting from server: 220 mta2.example.com ESMTP Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: smtp-client: conn mta2.example.com:25 (10.46.163.91:25) [1]: Sending EHLO handshake Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: smtp-client: conn mta2.example.com:25 (10.46.163.91:25) [1]: command EHLO: Submitted with priority Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: smtp-client: conn mta2.example.com:25 (10.46.163.91:25) [1]: command EHLO: Sent: EHLO mda1-2.example.com Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: smtp-client: conn mta2.example.com:25 (10.46.163.91:25) [1]: command EHLO: Got reply (1/1): 250 mta2.example.com PIPELINING SIZE 51200000 ETRN STARTTLS AUTH DIGEST-MD5 CRAM-MD5 NTLM XCLIENT NAME ADDR PROTO HELO REVERSE_NAME PORT LOGIN DESTADDR DESTPORT ENHANCEDSTATUSCODES 8BITMIME SMTPUTF8 (1 commands pending, 0 commands queued) Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: smtp-client: conn mta2.example.com:25 (10.46.163.91:25) [1]: Received handshake reply Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: smtp-client: conn mta2.example.com:25 (10.46.163.91:25) [1]: Received server capabilities Oct 11 09:29:01 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: smtp-client: conn mta2.example.com:25 (10.46.163.91:25) [1]: Starting TLS Oct 11 09:29:01 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: smtp-client: conn mta2.example.com:25 (10.46.163.91:25) [1]: command STARTTLS: Submitted with priority Oct 11 09:29:01 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: smtp-client: conn mta2.example.com:25 (10.46.163.91:25) [1]: command EHLO: Destroy (0 commands pending, 1 commands queued) Oct 11 09:29:01 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: smtp-client: conn mta2.example.com:25 (10.46.163.91:25) [1]: command STARTTLS: Sent: STARTTLS Oct 11 09:29:01 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: smtp-client: conn mta2.example.com:25 (10.46.163.91:25) [1]: command STARTTLS: Got reply (1/1): 220 2.0.0 Ready to start TLS (1 commands pending, 0 commands queued) Oct 11 09:29:01 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: smtp-client: conn mta2.example.com:25 (10.46.163.91:25) [1]: Received STARTTLS reply: 220 2.0.0 Ready to start TLS Oct 11 09:29:01 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: smtp-client: conn mta2.example.com:25 (10.46.163.91:25) [1]: Starting SSL handshake Oct 11 09:29:01 srv2 postfix/smtpd[15229]: Anonymous TLS connection established from srv2[10.46.163.91]: TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) Oct 11 09:29:01 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: smtp-client: conn mta2.example.com:25 (10.46.163.91:25) [1]: SSL handshake successful Oct 11 09:29:01 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Panic: file smtp-client-connection.c: line 1212 (smtp_client_connection_established): assertion failed: (!conn->connect_succeeded) Oct 11 09:29:01 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Error: Raw backtrace: /usr/lib/dovecot/libdovecot.so.0(+0xe7f7e) [0x7f64b1f76f7e] -> /usr/lib/dovecot/libdovecot.so.0(+0xe8021) [0x7f64b1f77021] -> /usr/lib/dovecot/libdovecot.so.0(i_fatal+0) [0x7f64b1ecfaf4] -> /usr/lib/dovecot/libdovecot.so.0(+0x50ec8) [0x7f64b1edfec8] -> /usr/lib/dovecot/libdovecot.so.0(+0x51078) [0x7f64b1ee0078] -> /usr/lib/dovecot/libdovecot.so.0(+0x541f4) [0x7f64b1ee31f4] -> /usr/lib/dovecot/libdovecot.so.0(smtp_client_command_input_reply+0x1f8) [0x7f64b1edb738] -> /usr/lib/dovecot/libdovecot.so.0(+0x54a93) [0x7f64b1ee3a93] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_call_io+0x6f) [0x7f64b1f909af] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_handler_run_internal+0x13c) [0x7f64b1f9237c] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_handler_run+0x4c) [0x7f64b1f90abc] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_run+0x38) [0x7f64b1f90cd8] -> /usr/lib/dovecot/libdovecot.so.0(master_service_run+0x13) [0x7f64b1eff053] -> dovecot/submission hativ@example.com fec0:810c:c0c0:8a0:342a:8478:1ee:4f8e GREETING [0x55dcc748fec1] -> /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xe7) [0x7f64b1abfb97] -> dovecot/submission hativ@example.com fec0:810c:c0c0:8a0:342a:8478:1ee:4f8e GREETING [0x55dcc749009a] Oct 11 09:29:01 srv2 postfix/smtpd[15229]: lost connection after STARTTLS from srv2[10.46.163.91] Oct 11 09:29:01 srv2 postfix/smtpd[15229]: disconnect from srv2[10.46.163.91] ehlo=1 starttls=1 commands=2 Oct 11 09:29:01 srv2 dovecot: submission(hativ@example.com)<15819><XFnL eJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Fatal: master: service(submission): child 15819 killed with signal 6 (core dumped)
Best regards
Hativ