Crash in director for secure lmtp proxy connections

Marcus Fenner mfenner at physik.hu-berlin.de
Wed Nov 21 15:21:38 EET 2018


Hi,

After updating some of our director servers from 2.2.36 to 2.3.3
(dcead646b) we experience crashes in about 1/5000 mails in lmtp delivery:

Nov 13 12:23:36 Fatal: lmtp(113620): master: service(lmtp): child 113620
killed with signal 6 (core dumped)
Nov 13 12:23:36 Panic: lmtp(113623): file ostream-dot.c: line 208
(o_stream_dot_sendv): assertion failed: ((size_t)ret == sent + added)
Nov 13 12:23:36 Error: lmtp(113623): Raw backtrace:
/usr/lib64/dovecot/libdovecot.so.0(+0xe34fb) [0x7f31d89134fb] ->
/usr/lib64/dovecot/libdovecot.so.0(+0xe3597) [0x7f31d8913597] ->
/usr/lib64/dovecot/libdovecot.so.0(+0x51207) [0x7f31d8881207] ->
/usr/lib64/dovecot/libdovecot.so.0(+0x4eeef) [0x7f31d887eeef] ->
/usr/lib64/dovecot/libdovecot.so.0(+0x107cf8) [0x7f31d8937cf8] ->
/usr/lib64/dovecot/libdovecot.so.0(o_stream_sendv+0x32) [0x7f31d89382c2]
-> /usr/lib64/dovecot/libdovecot.so.0(io_stream_copy+0x5a)
[0x7f31d8938b6a] ->
/usr/lib64/dovecot/libdovecot.so.0(o_stream_send_istream+0x53)
[0x7f31d8938873] ->
/usr/lib64/dovecot/libdovecot.so.0(smtp_client_command_send_more+0x145)
[0x7f31d8890805] -> /usr/lib64/dovecot/libdovecot.so.0(+0x660dd)
[0x7f31d88960dd] ->
/usr/lib64/dovecot/libssl_iostream_openssl.so(+0xa7e1) [0x7f31d864a7e1]
-> /usr/lib64/dovecot/libdovecot.so.0(+0x10a558) [0x7f31d893a558] ->
/usr/lib64/dovecot/libdovecot.so.0(io_loop_call_io+0x73)
[0x7f31d892a203] ->
/usr/lib64/dovecot/libdovecot.so.0(io_loop_handler_run_internal+0x136)
[0x7f31d892b8b6] ->
/usr/lib64/dovecot/libdovecot.so.0(io_loop_handler_run+0x50)
[0x7f31d892a2b0] -> /usr/lib64/dovecot/libdovecot.so.0(io_loop_run+0x48)
[0x7f31d892a418] ->
/usr/lib64/dovecot/libdovecot.so.0(master_service_run+0x17)
[0x7f31d88a95a7] -> dovecot/lmtp(main+0x245) [0x555b8b59cea5] ->
/lib64/libc.so.6(__libc_start_main+0xf3) [0x7f31d867c413] ->
dovecot/lmtp(_start+0x2e) [0x555b8b59cfbe]
Nov 13 12:23:36 Fatal: lmtp(113623): master: service(lmtp): child 113623
killed with signal 6 (core dumped)

On the backend servers the only message is
lmtp(9571): Disconnect from 192.168.1.56: Connection closed (in DATA)

This happens for every server with this version every time postfix tries
to resend the mail.

After removing "starttls=y" from the static passdb entry, the mail is
sent successfully. Starting with version 2.3.2 the lmtp proxy uses
starttls as well, therefore the error seems to be there. I've not been
able to figure out, if this has to do with the content of the mails,
because they are from many different sources.

Thanks!
Marcus
-------------- next part --------------
# 2.3.3 (dcead646b): /etc/dovecot/dovecot.conf
# Pigeonhole version 0.5.3 (f018bbab)
# OS: Linux 4.18.16-300.fc29.x86_64 x86_64 Fedora release 29 (Twenty Nine) 
# Hostname: imap2.example.com
auth_cache_size = 10 M
auth_mechanisms = plain login
auth_username_format = %Ln
auth_verbose = yes
auth_worker_max_count = 900
director_mail_servers = mail1.example.com mail2.example.com mail3.example.com
director_servers = 192.168.1.9 192.168.1.10
doveadm_port = 24245
first_valid_uid = 200
imap_idle_notify_interval = 23 mins
lmtp_proxy = yes
login_log_format_elements = user=<%u> method=%m rip=%r lip=%l mpid=%e %c session=<%{session}> %k
managesieve_notify_capability = mailto
managesieve_sieve_capability = fileinto reject envelope encoded-character vacation subaddress comparator-i;ascii-numeric relational regex imap4flags copy include variables body enotify environment mailbox date index ihave duplicate mime foreverypart extracttext
mbox_write_locks = fcntl
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 = proxy=y nopassword=y starttls=y
  driver = static
}
plugin {
  sieve = file:~/sieve;active=~/.dovecot.sieve
}
protocols = imap pop3 lmtp sieve
service anvil {
  client_limit = 4399
}
service auth {
  client_limit = 4596
}
service director {
  fifo_listener login/proxy-notify {
    mode = 0666
  }
  inet_listener {
    port = 9091
  }
  unix_listener director-userdb {
    mode = 0600
  }
  unix_listener login/director {
    mode = 0666
  }
}
service doveadm {
  inet_listener {
    port = 24245
  }
}
service imap-login {
  executable = imap-login director
  inet_listener imaps {
    ssl = yes
  }
  process_limit = 4096
  process_min_avail = 4
}
service imap {
  process_limit = 10240
}
service lmtp {
  inet_listener lmtp {
    port = 24
  }
}
service managesieve-login {
  executable = managesieve-login director
  inet_listener sieve {
    port = 4190
  }
}
service pop3-login {
  executable = pop3-login director
}
service pop3 {
  process_limit = 1024
}
ssl = required
ssl_ca = </etc/pki/tls/certs/hu.pem
ssl_cert = </etc/pki/dovecot/certs/dovecot.pem
ssl_cipher_list = PROFILE=SYSTEM
ssl_client_ca_file = /etc/pki/tls/cert.pem
ssl_dh = # hidden, use -P to show it
ssl_key = # hidden, use -P to show it
ssl_options = no_compression no_ticket
ssl_prefer_server_ciphers = yes
ssl_require_crl = no
userdb {
  args = /etc/dovecot/dovecot-ldap-userdb.conf.ext
  driver = ldap
}
protocol lmtp {
  auth_socket_path = director-userdb
}
protocol imap {
  mail_max_userip_connections = 30
  mail_plugins = " imap_zlib"
}
protocol doveadm {
  auth_socket_path = director-userdb
}
local 192.168.1.0/21 {
  doveadm_password = # hidden, use -P to show it
}
-------------- next part --------------
#0  0x00007f75824f053f in raise () from /lib64/libc.so.6
No symbol table info available.
#1  0x00007f75824da895 in abort () from /lib64/libc.so.6
No symbol table info available.
#2  0x00007f75826e156f in default_fatal_finish (status=0, type=LOG_TYPE_PANIC) at failures.c:460
        backtrace = 0x5600067a03a0 "/usr/lib64/dovecot/libdovecot.so.0(+0xe34fb) [0x7f75827734fb] -> /usr/lib64/dovecot/libdovecot.so.0(+0xe3597) [0x7f7582773597] -> /usr/lib64/dovecot/libdovecot.so.0(+0x51207) [0x7f75826e1207] -> /usr/"...
        backtrace = <optimized out>
        recursed = 0
#3  fatal_handler_real (ctx=<optimized out>, format=<optimized out>, args=<optimized out>) at failures.c:472
        status = 0
#4  0x00007f7582773597 in i_internal_fatal_handler (ctx=<optimized out>, format=<optimized out>, args=<optimized out>) at failures.c:849
No locals.
#5  0x00007f75826e1207 in i_panic (format=format at entry=0x7f75827ae0d8 "file %s: line %d (%s): assertion failed: (%s)") at failures.c:524
        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 = 0x7fff6be37600, reg_save_area = 0x7fff6be37540}}
#6  0x00007f75826deeef in o_stream_dot_sendv (stream=0x560006904040, iov=0x7fff6be37710, iov_count=1) at ostream-dot.c:208
        iov_new = <optimized out>
        sent = <optimized out>
        count = <optimized out>
        i = <optimized out>
        ret = <optimized out>
        dstream = <optimized out>
        iov_arr = {arr = {buffer = 0x56000679c318, element_size = 16}, v = 0x56000679c318, v_modifiable = 0x56000679c318}
        max_bytes = <optimized out>
        added = <optimized out>
        iov = 0x7fff6be37710
        iov_new = <optimized out>
        sent = <optimized out>
        __func__ = "o_stream_dot_sendv"
        size = <optimized out>
        p = <optimized out>
        iov_count = 1
        stream = 0x560006904040
        max_bytes = <optimized out>
        pend = <optimized out>
        iovn = <optimized out>
        added = <optimized out>
        dstream = <optimized out>
        i = <optimized out>
        ret = <optimized out>
        data = <optimized out>
        add = <optimized out>
        iov_arr = <optimized out>
        count = <optimized out>
        chunk = <optimized out>
        dstream = 0x560006904040
        iov_arr = <optimized out>
        iov_new = <optimized out>
        max_bytes = <optimized out>
        sent = <optimized out>
        added = <optimized out>
        count = <optimized out>
        i = <optimized out>
        ret = <optimized out>
        __func__ = "o_stream_dot_sendv"
        size = <optimized out>
        chunk = <optimized out>
        data = <optimized out>
        p = <optimized out>
        pend = <optimized out>
        iovn = <optimized out>
        add = <optimized out>
#7  0x00007f7582797cf8 in o_stream_sendv_int (stream=0x5600069040e0, iov=<optimized out>, iov_count=<optimized out>, overflow_r=0x7fff6be376e7) at ostream.c:276
        _stream = <optimized out>
        i = <optimized out>
        total_size = 62459
        ret = <optimized out>
        __func__ = "o_stream_sendv_int"
#8  0x00007f75827982c2 in o_stream_sendv (stream=<optimized out>, iov=<optimized out>, iov_count=<optimized out>) at ostream.c:301
        overflow = false
#9  0x00007f7582798b6a in io_stream_copy (outstream=0x5600069040e0, instream=0x560006903eb0) at ostream.c:487
        iov = {iov_base = 0x7f75820baf64, iov_len = 62459}
        data = 0x7f75820baf64 "3mQIn [role=3Dbutton], ._3mQI=\r\nn [type=3Dbutton], ._3mQIn [type=3Dsubmit]=0A=\r\n\t{line-height:initial;=0A=\r\n\twhite-space:normal;=0A=\r\n\ttext-align:left;=0A=\r\n\tfloat:initial;=0A=\r\n\tclear:none;=0A=\r\n\tver"...
        ret = <optimized out>
#10 0x00007f7582798873 in o_stream_send_istream (outstream=outstream at entry=0x5600069040e0, instream=instream at entry=0x560006903eb0) at ostream.c:395
        _outstream = <optimized out>
        old_outstream_offset = <optimized out>
        old_instream_offset = <optimized out>
        res = <optimized out>
        __func__ = "o_stream_send_istream"
#11 0x00007f75826f0805 in smtp_client_command_send_stream (cmd=<optimized out>) at smtp-client-command.c:468
        conn = 0x560006800d08
        stream = 0x560006903eb0
        ret = <optimized out>
        output = 0x5600069040e0
        res = <optimized out>
        conn = <optimized out>
        stream = <optimized out>
        output = <optimized out>
        res = <optimized out>
        ret = <optimized out>
        __func__ = "smtp_client_command_send_stream"
#12 smtp_client_command_send_more (conn=0x560006800d08) at smtp-client-command.c:590
        cmd = 0x560006900a28
        data = <optimized out>
        size = <optimized out>
        sent = <optimized out>
        ret = <optimized out>
        __func__ = "smtp_client_command_send_more"
#13 0x00007f75826f60dd in smtp_client_connection_output (conn=<optimized out>) at smtp-client-connection.c:1085
        ret = 1
#14 0x00007f75824aa7e1 in plain_flush_callback (sstream=0x5600068cc150) at ostream-openssl.c:197
        ostream = 0x5600068cc1f0
        ret = 1
        ret2 = <optimized out>
#15 0x00007f758279a558 in stream_send_io (fstream=0x5600067ffa70) at ostream-file.c:482
        ostream = 0x5600067ffb10
        iostream = 0x5600067ffa70
        use_cork = true
        ret = <optimized out>
#16 0x00007f758278a203 in io_loop_call_io (io=0x56000690e9c0) at ioloop.c:698
        ioloop = 0x5600067a2f00
        t_id = 2
        __func__ = "io_loop_call_io"
#17 0x00007f758278b8b6 in io_loop_handler_run_internal (ioloop=ioloop at entry=0x5600067a2f00) at ioloop-epoll.c:221
        ctx = 0x5600067ac120
        events = <optimized out>
        event = 0x5600067ac190
        list = 0x56000680d4f0
        io = <optimized out>
        tv = {tv_sec = 124, tv_usec = 998210}
        events_count = <optimized out>
        msecs = <optimized out>
        ret = <optimized out>
        i = 0
        j = <optimized out>
        call = <optimized out>
        __func__ = "io_loop_handler_run_internal"
#18 0x00007f758278a2b0 in io_loop_handler_run (ioloop=0x5600067a2f00) at ioloop.c:750
        __func__ = "io_loop_handler_run"
#19 0x00007f758278a418 in io_loop_run (ioloop=0x5600067a2f00) at ioloop.c:723
        __func__ = "io_loop_run"
#20 0x00007f75827095a7 in master_service_run (service=0x5600067a2d90, callback=callback at entry=0x560005e7d080 <client_connected>) at master-service.c:775
No locals.
#21 0x0000560005e7cea5 in main (argc=<optimized out>, argv=<optimized out>) at main.c:158
        set_roots = {0x560005e846e0 <smtp_submit_setting_parser_info>, 0x560005e84680 <lda_setting_parser_info>, 0x560005e84440 <lmtp_setting_parser_info>, 0x0}
        service_flags = <optimized out>
        storage_service_flags = (MAIL_STORAGE_SERVICE_FLAG_USERDB_LOOKUP | MAIL_STORAGE_SERVICE_FLAG_TEMP_PRIV_DROP | MAIL_STORAGE_SERVICE_FLAG_NO_LOG_INIT | MAIL_STORAGE_SERVICE_FLAG_NO_IDLE_TIMEOUT)
        tmp_base_dir = 0x56000679a288 " \\\202\202u\177"
        c = <optimized out>
        error = 0x7f75829dc718 "\360Ɲ\202u\177"
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 833 bytes
Desc: OpenPGP digital signature
URL: <https://dovecot.org/pipermail/dovecot/attachments/20181121/2c81ac6d/attachment.sig>


More information about the dovecot mailing list