dovecot - Oct 2016 - Massive LMTP Problems with dovecot

> We'll need the `dovecot -n` output first.
Here we go:
> # 2.2.devel (933d16f): /etc/dovecot/dovecot.conf
> # Pigeonhole version 0.4.devel (63f9b42)
> # OS: Linux 3.13.0-98-generic x86_64 Ubuntu 14.04.5 LTS 
> default_vsz_limit = 2 G
> lmtp_user_concurrency_limit = 10000
> mail_attachment_dir = /home/copymail/attachments
> mail_location = mdbox:~/mdbox
> mail_plugins = zlib fts fts_lucene
> mdbox_rotate_size = 128 M
> 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 = username_format=%u /etc/dovecot/passwd
>   driver = passwd-file
> }
> plugin {
>   fts = lucene
>   fts_autoindex = yes
>   fts_languages = de,en
>   fts_lucene = whitespace_chars=@.
>   sieve = file:~/sieve;active=~/.dovecot.sieve
>   zlib_save = gz
>   zlib_save_level = 5
> }
> protocols = " imap lmtp"
> service imap-login {
>   inet_listener imap {
>     address = 127.0.0.1
>     port = 143
>   }
>   inet_listener imaps {
>     port = 993
>     ssl = yes
>   }
> }
> service lmtp {
>   inet_listener lmtp {
>     address = 141.42.1.208
>     port = 1025
>   }
>   unix_listener /var/spool/postfix/private/dovecot-lmtp {
>     group = postfix
>     mode = 0660
>     user = postfix
>   }
> }
> ssl_ca = /etc/ssl/certs/ca-certificates.crt
> ssl_cert = </etc/ssl/certs/mail-cbf.pem
> ssl_cipher_list =
EECDH+ECDSA+AESGCM:EECDH+aRSA+AESGCM:EECDH+ECDSA+SHA384:EECDH+ECDSA+SHA256:EECDH+aRSA+SHA384:EECDH+aRSA+SHA256:EECDH+aRSA+RC4:EECDH:EDH+aRSA:!aNULL:!eNULL:!LOW:!3DES:!MD5:!EXP:!PSK:!SRP:!DSS:!RC4
> ssl_key =  # hidden, use -P to show it
> ssl_prefer_server_ciphers = yes
> ssl_protocols = !SSLv2 !SSLv3
> userdb {
>   args = username_format=%u /etc/dovecot/passwd
>   driver = passwd-file
> }
> protocol lmtp {
>   mail_plugins = zlib fts fts_lucene
> }
Ralf Hildebrandt
  Gesch?ftsbereich IT | Abteilung Netzwerk
  Charit? - Universit?tsmedizin Berlin
  Campus Benjamin Franklin
  Hindenburgdamm 30 | D-12203 Berlin
  Tel. +49 30 450 570 155 | Fax: +49 30 450 570 962
  ralf.hildebrandt at charite.de | http://www.charite.de

I attached gdb top a long running LMTP process:

#0  sha1_loop (ctxt=0x7f3b1a4d7fa0, input=0x7f3b1a524860, len=0) at sha1.c:216
       input_c = 0x7f3b1a524860 "\211PNG\r\n\032\n"
       gaplen = <optimized out>
       gapstart = <optimized out>
       off = 0
       copysiz = <optimized out>

#1  0x00007f3b19195b29 in hash_format_loop (format=<optimized out>,
data=0x7f3b1a524860, size=0) at hash-format.c:150
       list = 0x7f3b1a4d7f80

#2  0x00007f3b1916f5b8 in astream_decode_base64(astream=0x7f3b1a4cb030) at
istream-attachment-extractor.c:388
        part = 0x7f3b1a4cb228
        output = 0x7f3b1a5288c0
        size = 0
        buf = 0x7f3b1a528070
        outfd = 24
        extra_buf = 0x0
        data = 0x7f3b1a52484e "iW"
        ret = <optimized out>
        input = 0x7f3b1a528530
        base64_input = 0x7f3b1a5286f0
        failed = false

#3  astream_part_finish (error_r=0x7ffc00bc2518, astream=<optimized out>)
at istream-attachment-extractor.c:485
        info = {hash = 0x7f3b1a414c08
"ebd67eb141828144e22a6123b7c9e8ce3401a0db", start_offset = 41786,
encoded_size = 331456, base64_blocks_per_line = 0,
          base64_have_crlf = false, part = 0x0}
        digest_str = 0x7f3b1a414bd0
        data = 0x0
        ret = 0
        input = 0x7f3b1a5288c0
        output = 0x7f3b1a52484e
        size = 139891821412464

#4  astream_end_of_part (astream=astream at entry=0x7f3b1a4cb030,
error_r=error_r at entry=0x7ffc00bc2518) at istream-attachment-extractor.c:571
        part = 0x7f3b1a4cb228
        old_size = 0
        ret = 0

#5  0x00007f3b1916fbdb in astream_read_next (retry_r=<synthetic pointer>,
astream=0x7f3b1a4cb030) at istream-attachment-extractor.c:633
        stream = 0x7f3b1a4cb030
        block = {part = 0x7f3b1a4d8770, hdr = 0x0, 
          data = 0x7f3b19bf91e1
"\n--_008_VI1PR02MB139090A81DDBB9A3973922378AD00VI1PR02MB1390eurp_\nContent-Type:
image/png; name=\"image013.png\"\nContent-Description:
image013.png\nContent-Disposition: inline; filename=\"image013.png\";
si"..., size = 64}
        new_size = <optimized out>
        ret = <optimized out>
        old_size = 0
        error = 0xcf803a94af74800 <error: Cannot access memory at address
0xcf803a94af74800>

#6  i_stream_attachment_extractor_read (stream=0x7f3b1a4cb030) at
istream-attachment-extractor.c:668
        astream = 0x7f3b1a4cb030
        retry = false
        ret = <optimized out>
	
#7  0x00007f3b1919a1c3 in i_stream_read (stream=0x7f3b1a4cb0a0) at istream.c:174
        _stream = 0x7f3b1a4cb030
        old_size = 0
        ret = <optimized out>
        __FUNCTION__ = "i_stream_read"

#8  0x00007f3b194c2c0b in index_attachment_save_continue (ctx=0x7f3b1a4c59a0) at
index-attachment.c:218
        storage = 0x7f3b1a4907a0
        attach = 0x7f3b1a4d8360
        data = <optimized out>
 	size = 1
        ret = <optimized out>

#9  0x00007f3b1945dcd2 in mailbox_save_continue (ctx=ctx at
entry=0x7f3b1a4c59a0) at mail-storage.c:2113
        _data_stack_cur_id = 4
        ret = <optimized out>

#10 0x00007f3b194540ee in mail_storage_try_copy (mail=0x7ffc00bc2658,
_ctx=0x7ffc00bc2658) at mail-copy.c:81
        ctx = 0x7f3b1a4c59a0
        pmail = 0x7ffc00bc2658
        ret = <optimized out>
        input = 0x7f3b1a4c4140

#11 mail_storage_copy (ctx=ctx at entry=0x7f3b1a4c59a0, mail=mail at
entry=0x7f3b1a48b770) at mail-copy.c:107
        __FUNCTION__ = "mail_storage_copy"

#12 0x00007f3b19474806 in mdbox_copy (_ctx=0x7f3b1a4c59a0, mail=0x7f3b1a48b770)
at mdbox-save.c:468
        ctx = 0x7f3b1a4c59a0
        save_mail = 0x7f3b1a48b770
        src_mbox = <optimized out>
        rec = {map_uid = 440968640, save_date = 32571}
        guid_data = 0x7f3b1a4c59a0
	wanted_guid = "p\245H\032;\177\000\000\267\225u\031;\177\000"

#13 0x00007f3b180bd2f1 in fts_copy (ctx=0x7f3b1a4c59a0, mail=0x7f3b1a48b770) at
fts-storage.c:735
        ft = 0x7f3b1a4c4c10
        fbox = <optimized out>

#14 0x00007f3b1945e16d in mailbox_copy_int (_ctx=_ctx at entry=0x7ffc00bc27a0,
mail=0x7f3b1a48b770) at mail-storage.c:2244
        _data_stack_cur_id = 3
        ctx = 0x7f3b1a4c59a0	
        t = 0x7f3b1a4c4c40
        keywords = 0x0
        pvt_flags = 0
        backend_mail = 0x7f3b1a48b770
        ret = <optimized out>
        __FUNCTION__ = "mailbox_copy_int"

#15 0x00007f3b1945e3e2 in mailbox_save_using_mail (_ctx=_ctx at
entry=0x7ffc00bc27a0, mail=<optimized out>) at mail-storage.c:2295
        ctx = <optimized out>
        __FUNCTION__ = "mailbox_save_using_mail"

#16 0x00007f3b19759789 in mail_deliver_save (ctx=ctx at entry=0x7ffc00bc2930,
mailbox=<optimized out>, flags=flags at entry=0, keywords=keywords at
entry=0x0,
    storage_r=storage_r at entry=0x7ffc00bc2908) at mail-deliver.c:383
       open_ctx = {user = 0x7f3b1a470e40, lda_mailbox_autocreate = false,
lda_mailbox_autosubscribe = false}
       box = 0x7f3b1a4bb610
       trans_flags = <optimized out>
       t = 0x7f3b1a4c4c40
       save_ctx = 0x0
       headers_ctx = 0x0
       kw = 0x0
       error = MAIL_ERROR_NONE
       mailbox_name = 0x7f3b19b8f258 "INBOX"
       errstr = 0x0
       guid = 0x0
       changes = {pool = 0x7f3b1a4502b0, uid_validity = 440869512, saved_uids =
{arr = {buffer = 0x7f3b1995e400
	<lda_setting_parser_info>, element_size = 1476711940}, v = 0x7f3b1995e400
<lda_setting_parser_info>, v_modifiable = 0x7f3b1995e400
<lda_setting_parser_info>},
       ignored_modseq_changes = 440968560, changed = 59, no_read_perm = 127}
       default_save = <optimized out>
       ret = 0
       __FUNCTION__ = "mail_deliver_save"

#17 0x00007f3b19759be3 in mail_deliver (ctx=ctx at entry=0x7ffc00bc2930,
storage_r=storage_r at entry=0x7ffc00bc2908) at mail-deliver.c:493
       ret = <optimized out>

#18 0x00007f3b19b8c24e in client_deliver (session=0x7f3b1a48a570,
src_mail=0x7f3b1a48b770, rcpt=0x7f3b1a44b748, client=0x7f3b1a4502d0)
at commands.c:890
        set_parser = <optimized out>
        line = <optimized out>
        str = <optimized out>
        mail_error = 440730320
        ret = <optimized out>
        input = <optimized out>
        ns = <optimized out>
        delivery_time_started = {tv_sec = 1476711940, tv_usec = 46227}
        sets = <optimized out>
        storage = 0x7f3b1a4907a0
        mail_set = <optimized out>
        username = <optimized out>
        dctx = {pool = 0x7f3b1a48a550, set = 0x7f3b1a45df80, session =
0x7f3b1a48a570, timeout_secs = 30, session_time_msecs = 2, delivery_time_started
= {
            tv_sec = 1476711940, tv_usec = 46227}, dup_ctx = 0x0, session_id =
0x7f3b1a44b4d0 "sl0sAgTWBFiZLwAAplP5LA", src_mail = 0x7f3b1a48b770,
          src_envelope_sender = 0x7f3b1a44b4e8 "hartmut.xxxxxr at
getinge.com", dest_user = 0x7f3b1a470e40,
          dest_addr = 0x7f3b1a44b788 "backup+alexander.xxxxx=charite.de at
backup.invalid",
          final_dest_addr = 0x7f3b1a44b788
"backup+alexander.xxxxx=charite.de at backup.invalid",
dest_mailbox_name = 0x7f3b19b8f258 "INBOX",
          dest_mail = 0x7f3b1a4cb700, var_expand_table = 0x0, tempfail_error =
0x0, tried_default_save = true, saved_mail = false, save_dest_mail = false,
          mailbox_full = false, dsn = false}
          lda_set = <optimized out>
          error = <optimized out>

#19 client_deliver_next (session=0x7f3b1a48a570,
src_mail=0x7f3b1a48b770, client=0x7f3b1a4502d0) at commands.c:930
        count = <optimized out>
	#20 client_input_data_write_local (input=<optimized out>,
client=0x7f3b1a4502d0) at commands.c:1026
        src_mail = 0x7f3b1a48b770
	        first_uid = 4294967295
		        session = 0x7f3b1a48a570
			        old_uid = 0
				#21 client_input_data_write
(client=0x7f3b1a4502d0) at commands.c:1161
        input = 0x7f3b1a4682f0
	#22 client_input_data_handle (client=0x7f3b1a4502d0) at commands.c:1256
	        data = <optimized out>
		        size = 2366
			        ret = <optimized out>
				#23 0x00007f3b191a3e4c in
io_loop_call_io (io=0x7f3b1a421610) at ioloop.c:584
        ioloop = 0x7f3b1a419750
	        t_id = 2
		        __FUNCTION__ = "io_loop_call_io"
			#24 0x00007f3b191a530a in
io_loop_handler_run_internal (ioloop=ioloop at entry=0x7f3b1a419750) at
ioloop-epoll.c:222
        ctx = 0x7f3b1a41f3b0
	        io = <optimized out>
		        tv = {tv_sec = 299, tv_usec = 999727}
			        events_count = <optimized out>
				        msecs = <optimized out>
					        ret = 1
						        i = 0
							        j <optimized out>
        call = <optimized out>
	        __FUNCTION__ = "io_loop_handler_run_internal"
		#25 0x00007f3b191a3ed5 in io_loop_handler_run
(ioloop=ioloop at entry=0x7f3b1a419750) at ioloop.c:632
No locals.
#26 0x00007f3b191a4078 in io_loop_run (ioloop=0x7f3b1a419750) at
ioloop.c:608
        __FUNCTION__ = "io_loop_run"
	#27 0x00007f3b1912fbe3 in master_service_run
(service=0x7f3b1a4195f0, callback=<optimized out>) at
master-service.c:641
No locals.
#28 0x00007f3b19b8a382 in main (argc=1, argv=0x7f3b1a419390) at
main.c:125
        set_roots = {0x7f3b1995e400 <lda_setting_parser_info>,
0x7f3b19d91580 <lmtp_setting_parser_info>, 0x0}
        service_flags = <optimized out>
	        storage_service_flags = <optimized out>
		        c = <optimized out>
			


-- 
Ralf Hildebrandt
  Gesch?ftsbereich IT | Abteilung Netzwerk
  Charit? - Universit?tsmedizin Berlin
  Campus Benjamin Franklin
  Hindenburgdamm 30 | D-12203 Berlin
  Tel. +49 30 450 570 155 | Fax: +49 30 450 570 962
  ralf.hildebrandt at charite.de | http://www.charite.de

* Ralf Hildebrandt <Ralf.Hildebrandt at
charite.de>:
> I attached gdb top a long running LMTP process:
> 
> #0  sha1_loop (ctxt=0x7f3b1a4d7fa0, input=0x7f3b1a524860, len=0) at
sha1.c:216
>        input_c = 0x7f3b1a524860 "\211PNG\r\n\032\n"
>        gaplen = <optimized out>
>        gapstart = <optimized out>
>        off = 0
>        copysiz = <optimized out>
> 
> #1  0x00007f3b19195b29 in hash_format_loop (format=<optimized out>,
data=0x7f3b1a524860, size=0) at hash-format.c:150
>        list = 0x7f3b1a4d7f80
It seems to loop in sha1_loop & hash_format_loop

-- 
Ralf Hildebrandt
  Gesch?ftsbereich IT | Abteilung Netzwerk
  Charit? - Universit?tsmedizin Berlin
  Campus Benjamin Franklin
  Hindenburgdamm 30 | D-12203 Berlin
  Tel. +49 30 450 570 155 | Fax: +49 30 450 570 962
  ralf.hildebrandt at charite.de | http://www.charite.de