Re: Massive LMTP Problems with dovecot

2016-10-20 Thread Ralf Hildebrandt
* Timo Sirainen :
> On 17 Oct 2016, at 17:31, Ralf Hildebrandt  
> wrote:
> > 
> > * Ralf Hildebrandt :
> > 
> >>> It seems to loop in sha1_loop & hash_format_loop
> >> 
> >> The problem occurs in both 2.3 and 2.2 (I just updated to 2.3 to check).
> > 
> > I'm seeing the first occurence of that problem on the 10th of october!
> > 
> > I was using (prior to the 10th)  : 2.3.0~alpha0-1~auto+371
> > On the 10th I upgraded (16:04) to: 2.3.0~alpha0-1~auto+376
> > 
> > I'd think the change must have been introduced between 371 and 376 :)
> > 
> > I then went back to, issues went away: 2.2.25-1~auto+49
> > and the issues reappeared with 2.2.25-1~auto+57
> 
> https://github.com/dovecot/core/commit/9b5fa7fdd9b9f1f61eaddda48036df200fc5e56e
>  should fix this.

Yes, fixed.

-- 
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.hildebra...@charite.de | http://www.charite.de



Re: Massive LMTP Problems with dovecot

2016-10-17 Thread Timo Sirainen
On 17 Oct 2016, at 17:31, Ralf Hildebrandt  wrote:
> 
> * Ralf Hildebrandt :
> 
>>> It seems to loop in sha1_loop & hash_format_loop
>> 
>> The problem occurs in both 2.3 and 2.2 (I just updated to 2.3 to check).
> 
> I'm seeing the first occurence of that problem on the 10th of october!
> 
> I was using (prior to the 10th)  : 2.3.0~alpha0-1~auto+371
> On the 10th I upgraded (16:04) to: 2.3.0~alpha0-1~auto+376
> 
> I'd think the change must have been introduced between 371 and 376 :)
> 
> I then went back to, issues went away: 2.2.25-1~auto+49
> and the issues reappeared with 2.2.25-1~auto+57

https://github.com/dovecot/core/commit/9b5fa7fdd9b9f1f61eaddda48036df200fc5e56e 
should fix this.


Re: Massive LMTP Problems with dovecot

2016-10-17 Thread Ralf Hildebrandt
* Ralf Hildebrandt :

> > It seems to loop in sha1_loop & hash_format_loop
> 
> The problem occurs in both 2.3 and 2.2 (I just updated to 2.3 to check).

I'm seeing the first occurence of that problem on the 10th of october!

I was using (prior to the 10th)  : 2.3.0~alpha0-1~auto+371
On the 10th I upgraded (16:04) to: 2.3.0~alpha0-1~auto+376

I'd think the change must have been introduced between 371 and 376 :)

I then went back to, issues went away: 2.2.25-1~auto+49
and the issues reappeared with 2.2.25-1~auto+57

Does that help?

-- 
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.hildebra...@charite.de | http://www.charite.de



Re: Massive LMTP Problems with dovecot

2016-10-17 Thread Ralf Hildebrandt
* Ralf Hildebrandt :
> * Ralf Hildebrandt :
> > 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 = 
> >gapstart = 
> >off = 0
> >copysiz = 
> > 
> > #1  0x7f3b19195b29 in hash_format_loop (format=, 
> > data=0x7f3b1a524860, size=0) at hash-format.c:150
> >list = 0x7f3b1a4d7f80
> 
> It seems to loop in sha1_loop & hash_format_loop

The problem occurs in both 2.3 and 2.2 (I just updated to 2.3 to check).

-- 
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.hildebra...@charite.de | http://www.charite.de



Re: Massive LMTP Problems with dovecot

2016-10-17 Thread Ralf Hildebrandt
* Ralf Hildebrandt :
> 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 = 
>gapstart = 
>off = 0
>copysiz = 
> 
> #1  0x7f3b19195b29 in hash_format_loop (format=, 
> 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.hildebra...@charite.de | http://www.charite.de



Re: Massive LMTP Problems with dovecot

2016-10-17 Thread Ralf Hildebrandt
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 = 
   gapstart = 
   off = 0
   copysiz = 

#1  0x7f3b19195b29 in hash_format_loop (format=, 
data=0x7f3b1a524860, size=0) at hash-format.c:150
   list = 0x7f3b1a4d7f80

#2  0x7f3b1916f5b8 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 = 
input = 0x7f3b1a528530
base64_input = 0x7f3b1a5286f0
failed = false

#3  astream_part_finish (error_r=0x7ffc00bc2518, astream=) 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@entry=0x7f3b1a4cb030, 
error_r=error_r@entry=0x7ffc00bc2518) at istream-attachment-extractor.c:571
part = 0x7f3b1a4cb228
old_size = 0
ret = 0

#5  0x7f3b1916fbdb in astream_read_next (retry_r=, 
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 = 
ret = 
old_size = 0
error = 0xcf803a94af74800 

#6  i_stream_attachment_extractor_read (stream=0x7f3b1a4cb030) at 
istream-attachment-extractor.c:668
astream = 0x7f3b1a4cb030
retry = false
ret = 

#7  0x7f3b1919a1c3 in i_stream_read (stream=0x7f3b1a4cb0a0) at istream.c:174
_stream = 0x7f3b1a4cb030
old_size = 0
ret = 
__FUNCTION__ = "i_stream_read"

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

#9  0x7f3b1945dcd2 in mailbox_save_continue (ctx=ctx@entry=0x7f3b1a4c59a0) 
at mail-storage.c:2113
_data_stack_cur_id = 4
ret = 

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

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

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

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

#14 0x7f3b1945e16d in mailbox_copy_int (_ctx=_ctx@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 = 
__FUNCTION__ = "mailbox_copy_int"

#15 0x7f3b1945e3e2 in mailbox_save_using_mail 
(_ctx=_ctx@entry=0x7ffc00bc27a0, mail=) at mail-storage.c:2295
ctx = 
__FUNCTION__ = "mailbox_save_using_mail"

#16 0x7f3b19759789 in mail_deliver_save (ctx=ctx@entry=0x7ffc00bc2930, 
mailbox=, flags=flags@entry=0, keywords=keywords@entry=0x0, 
storage_r=storage_r@entry=0x7ffc00bc2908) at mail-deliver.c:383
   open_ctx = {user = 0x7f3b1a470e40, lda_mailbox_autocreate = false, 
lda_mailbox_autosubscribe = false}
   box = 0x7f3b1a4bb610
   trans_flags = 
   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
, element_size = 1476711940}, v = 
0x7f3b1995e400 , v_modifiable = 0x7f3b1995e400 
}, 
   ignored_modseq_changes = 440968560, changed = 59, no_read_perm = 

Re: Massive LMTP Problems with dovecot

2016-10-17 Thread Ralf Hildebrandt
> 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 = 1
> 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 =  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.hildebra...@charite.de | http://www.charite.de



Re: Massive LMTP Problems with dovecot

2016-10-17 Thread Stephan Bosch
Op 10/17/2016 om 3:24 PM schreef Ralf Hildebrandt:
> Currently I'm having massive problems with LMTP delivery into dovcot.
> dovecot/lmtp processes are piling up, eas using considerable amounts
> of CPU:
>
> # ps auxwww|fgrep dove
>
> root 20537  0.0  0.0  18124  1196 ?Ss   15:18   0:00 
> /usr/sbin/dovecot -c /etc/dovecot/dovecot.conf
> dovecot  20541  0.0  0.0   9620  1084 ?S15:18   0:00 dovecot/anvil
> root 20542  0.0  0.0   9752  1264 ?S15:18   0:00 dovecot/log
> root 20544  0.0  0.0  21168  2276 ?S15:18   0:00 
> dovecot/config
> copymail 20580 72.8  0.0  39556  7036 ?R15:18   2:00 dovecot/lmtp
> dovecot  20582  0.0  0.0  18568  1756 ?S15:18   0:00 dovecot/auth
> copymail 20597 77.2  0.0  35688  5136 ?R15:18   2:06 dovecot/lmtp
> copymail 20598 39.3  0.0  38060  5596 ?R15:18   1:04 dovecot/lmtp
> copymail 20613 62.3  0.0  38036  5600 ?R15:18   1:41 dovecot/lmtp
> copymail 20619 56.4  0.0  37732  7448 ?R15:18   1:31 dovecot/lmtp
> copymail 20620 75.9  0.0  35872  5336 ?R15:18   2:03 dovecot/lmtp
> copymail 20627 37.8  0.0  36480  5892 ?R15:18   1:01 dovecot/lmtp
> copymail 20838 60.5  0.0  35640  5036 ?R15:19   0:59 dovecot/lmtp
> copymail 20840 66.3  0.0  35920  5296 ?R15:19   1:04 dovecot/lmtp
> copymail 20841 66.0  0.0  37456  6852 ?R15:19   1:04 dovecot/lmtp
> copymail 20842 64.5  0.0  36424  5808 ?R15:19   1:02 dovecot/lmtp
> copymail 20843 67.6  0.0  39612  7064 ?R15:19   1:05 dovecot/lmtp
>
> doveadm stop won't stop these, I have to use kill -9 on them.
> I already tried disabling fts (entirely), still things won't speed up.
>
> I can't strace:
> # strace -p 20841
> Process 20841 attached
>
> (and that's it)
>
> # dpkg -l|grep dovecot
> ii  dovecot-core2:2.2.25-1~auto+57amd64 secure 
> POP3/IMAP server - core files
> ii  dovecot-imapd   2:2.2.25-1~auto+57amd64 secure 
> POP3/IMAP server - IMAP daemon
> ii  dovecot-lmtpd   2:2.2.25-1~auto+57amd64 secure 
> POP3/IMAP server - LMTP server
> ii  dovecot-lucene  2:2.2.25-1~auto+57amd64 secure 
> POP3/IMAP server - Lucene support
> ii  dovecot-sieve   2:2.2.25-1~auto+57amd64 secure 
> POP3/IMAP server - Sieve filters support
>
> I also tried deleting the mdboxes, that also didn't change anything. 
> Ideas?

We'll need the `dovecot -n` output first.

Also, you could attach gdb to one of these processes and find out where
it is stuck in what looks to be an infinite loop (produce a backtrace).

Regards,

Stephan.