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><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+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><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+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](main+0x3d1) [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](_start+0x2a) [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><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: Loading modules from directory: /usr/lib/dovecot/modules

Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: Module loaded: /usr/lib/dovecot/modules/lib01_acl_plugin.so

Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+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><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: Module loaded: /usr/lib/dovecot/modules/lib10_quota_plugin.so

Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: Module loaded: /usr/lib/dovecot/modules/lib15_notify_plugin.so

Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+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><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+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><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: Module loaded: /usr/lib/dovecot/modules/lib20_replication_plugin.so

Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: Added userdb setting: plugin/mail_crypt_private_password=<hidden>

Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: Added userdb setting: plugin/mail_crypt_save_version=0

Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: Added userdb setting: plugin/quota_rule=*:bytes=0

Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+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><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: Quota root: name= backend=count args=

Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: Quota rule: root= mailbox=* bytes=0 messages=0

Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: Quota grace: root= bytes=0 (10%)

Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+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><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+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><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: acl: initializing backend with data: vfile

Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: acl: acl username = hativ@example.com

Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: acl: owner = 1

Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: acl vfile: Global ACLs disabled

Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+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><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: shared: root=/var/run/dovecot, index=, indexpvt=, control=, inbox=, alt=

Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: acl: initializing backend with data: vfile

Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: acl: acl username = hativ@example.com

Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: acl: owner = 0

Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: acl vfile: Global ACLs disabled

Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: quota: quota_over_flag check: quota_over_script unset - skipping

Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+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><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+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><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: smtp-client: conn mta2.example.com:25 [1]: Connection created

Oct 11 09:29:00 srv2 dovecot: submission(hativ@example.com)<15819><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+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><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+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><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+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><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+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><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+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><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+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><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+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><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+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><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+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><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+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><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+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><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+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><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Debug: smtp-client: conn mta2.example.com:25 (10.46.163.91:25) [1]: SSL handshake successful

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><XFnLeJ2U0rgqAoEMwMAIoDQqhHgB7k+O>: Fatal: master: service(submission): child 15819 killed with signal 6 (core dumped)

Best regards

Hativ