Ricardo Machini Barbosa
2018-Apr-04 18:26 UTC
Lmtp issues on dovecot 2.3.x with big messages
Hello,
After update dovecot to version 2.3.x, LMTP stopped to receive big messages
( > 45 MB ).
Messages are being sent to dovecot LMTP by postfix. If I change this email
to another server with dovecot 2.2.x the same message are delivered
immediately.
Log with mail_debug = yes:
Apr? 4 13:36:13 mailsrv01 dovecot: lmtp(190031): Debug: none: root=, index=,
indexpvt=, control=, inbox=, altApr? 4 13:36:13 mailsrv01 dovecot: lmtp(190031):
Connect from 10.0.5.3
Apr? 4 13:36:13 mailsrv01 dovecot:
lmtp(mailto:mailsrv01 at
dominio.com.br)<190031><tkOqEv3+xFpP5gIAZCVTkw>:
Debug: Loading modules from directory: /usr/lib64/dovecot
Apr? 4 13:36:13 mailsrv01 dovecot:
lmtp(mailto:mailsrv01 at
dominio.com.br)<190031><tkOqEv3+xFpP5gIAZCVTkw>:
Debug: Module loaded: /usr/lib64/dovecot/lib10_quota_plugin.so
Apr? 4 13:36:13 mailsrv01 dovecot:
lmtp(mailto:mailsrv01 at
dominio.com.br)<190031><tkOqEv3+xFpP5gIAZCVTkw>:
Debug: Module loaded: /usr/lib64/dovecot/lib20_quota_clone_plugin.so
Apr? 4 13:36:13 mailsrv01 dovecot:
lmtp(mailto:mailsrv01 at
dominio.com.br)<190031><tkOqEv3+xFpP5gIAZCVTkw>:
Debug: Module loaded: /usr/lib64/dovecot/lib90_sieve_plugin.so
Apr? 4 13:36:13 mailsrv01 dovecot:
lmtp(mailto:mailsrv01 at
dominio.com.br)<190031><tkOqEv3+xFpP5gIAZCVTkw>:
Debug: auth USER input: mailto:mailsrv01 at dominio.com.br
home=/mail/data/dovecot/mailbox/dominio.com.br/m/h4/mailsrv01
quota_rule=*:bytes=53687091200
Apr? 4 13:36:13 mailsrv01 dovecot:
lmtp(mailto:mailsrv01 at
dominio.com.br)<190031><tkOqEv3+xFpP5gIAZCVTkw>:
Debug: Added userdb setting: plugin/quota_rule=*:bytes=53687091200
Apr? 4 13:36:13 mailsrv01 dovecot: lmtp(190031): Debug: Effective uid=1000,
gid=1000, home=/mail/data/dovecot/mailbox/dominio.com.br/m/h4/mailsrv01
Apr? 4 13:36:13 mailsrv01 dovecot: lmtp(190031): Debug: Quota root:
name=User quota backend=count argsApr ?4 13:36:13 mailsrv01 dovecot:
lmtp(190031): Debug: Quota rule:
root=User quota mailbox=* bytes=53687091200 messages=0
Apr? 4 13:36:13 mailsrv01 dovecot: lmtp(190031): Debug: Quota rule:
root=User quota mailbox=Itens Exclu?dos bytes=+209715200 messages=0
Apr? 4 13:36:13 mailsrv01 dovecot: lmtp(190031): Debug: Quota warning:
bytes=51002736640 (95%) messages=0 reverse=no command=quota-warning 95
mailto:mailsrv01 at dominio.com.br
Apr? 4 13:36:13 mailsrv01 dovecot: lmtp(190031): Debug: Quota warning:
bytes=42949672960 (80%) messages=0 reverse=no command=quota-warning 80
mailto:mailsrv01 at dominio.com.br
Apr? 4 13:36:13 mailsrv01 dovecot: lmtp(190031): Debug: Quota grace:
root=User quota bytes=5368709120 (10%)
Apr? 4 13:36:13 mailsrv01 dovecot: lmtp(190031): Debug: Namespace inbox:
type=private, prefix=, sep=., inbox=yes, hidden=no, list=yes,
subscriptions=yes
location=mdbox:~/mdbox:ALT=/altstorage/mail/data/dovecot/mailbox/dominio.com
.br/m/h4/mailsrv01/mdbox
Apr? 4 13:36:13 mailsrv01 dovecot: lmtp(190031): Debug: fs:
root=/mail/data/dovecot/mailbox/dominio.com.br/m/h4/mailsrv01/mdbox, index=,
indexpvt=, control=, inbox=,
alt=/altstorage/mail/data/dovecot/mailbox/dominio.com.br/m/h4/mailsrv01/mdbo
x
Apr? 4 13:36:13 mailsrv01 dovecot: lmtp(190031): Debug: quota:
quota_over_flag check: quota_over_script unset - skipping
Apr? 4 13:36:13 mailsrv01 dovecot: lmtp(190031): Debug: INBOX: Mailbox
opened because: quota count
Apr? 4 13:36:14 mailsrv01 dovecot: lmtp(190031): Error: lmtp-server: conn
10.0.5.3:41579 [0]: Connection lost during data transfer:
read(10.0.5.3:41579 [0]) failed: <no error>
Apr? 4 13:36:14 mailsrv01 dovecot: lmtp(190031): Disconnect from 10.0.5.3:
Read failure (state = DATA)
Strace on this process (final lines):
190074 read(15,
"4SJuCeSNxH05pyfK+aO5hKKkrPY8n8TeBNH\r\ngvJ5LrV54YxgtG6Blkx0wfTIxWZ4Z1PU9R1a
7hs7YQadaqfMkPIc5wCP8Ko69eXE8GoRSySpCh2g\r\ns/UA8Hn8K6nwrpscXhd5Vupfttw/mqFX
5WTqCD6DvxUSxdTeTM5YSFvdVhmueK/7Mguba8mkmuY/\r\nlAC580Zxn6CuP8GeLrq31oWOhotx
cXzYkVlGVj7n0yMn9Kf4h0LXZ7o393p8U1o5UnbMPnVsDIz2\r\n9R1617R8H/BWl2vhnxDfXUcF
rqYnVYJBuJxySB6ZwPzonKMlZkU4SjscV4puNW1a/nkvWZPscZij\r\nUqR5YI569WP+FeWx+FUs
oY573fCzjIJbdux3OD1r3zWPEVpYmRbyyS6WJljjkcbizsOOnQ8155q3\r\nhnWdVkkQMbKKF1fa
w+6vpj19q3o01y3RhiPi1J9H8KwavaKn2mFFGwGUEEkH3PGOD9K9bvrzwvpk\r\neu29rrs"...,
8192) = 8192
190074 write(8,
"4SJuCeSNxH05pyfK+aO5hKKkrPY8n8TeBNH\r\ngvJ5LrV54YxgtG6Blkx0wfTIxWZ4Z1PU9R1a
7hs7YQadaqfMkPIc5wCP8Ko69eXE8GoRSySpCh2g\r\ns/UA8Hn8K6nwrpscXhd5Vupfttw/mqFX
5WTqCD6DvxUSxdTeTM5YSFvdVhmueK/7Mguba8mkmuY/\r\nlAC580Zxn6CuP8GeLrq31oWOhotx
cXzYkVlGVj7n0yMn9Kf4h0LXZ7o393p8U1o5UnbMPnVsDIz2\r\n9R1617R8H/BWl2vhnxDfXUcF
rqYnVYJBuJxySB6ZwPzonKMlZkU4SjscV4puNW1a/nkvWZPscZij\r\nUqR5YI569WP+FeWx+FUs
oY573fCzjIJbdux3OD1r3zWPEVpYmRbyyS6WJljjkcbizsOOnQ8155q3\r\nhnWdVkkQMbKKF1fa
w+6vpj19q3o01y3RhiPi1J9H8KwavaKn2mFFGwGUEEkH3PGOD9K9bvrzwvpk\r\neu29rrs"...,
8192) = 8192
190074 read(15,
"S5huvLRmJ+YBc8A8nI9/x5cXQxLfNS28t\r\nylCLVmfo3Yx/BdrhLHxbpXgiwexjAiNsEtnuXA
/iJdWCtn5vmPXGK/HZfENnL8atQ8S6d4T0nwwh\r\nvHFz9ohKouSTuj+UdQRjqAcHNey6vH4wjg
fWP+Fl6v8AbpY2juXFskrwRnkg7shznJ5FfPfjX4ly\r\nz29npvibXtE1S+tSFhvmkWM5IIGB/D
9O3A5r6PhaEnUlCoua/RnNivcjzRR6/wDFLx9BqKXV7f8A\r\njz+0tE07TxENOewK7GUHaHnJ+c
k56DGNtfPngz4gazr1pa2XhN3tdbZwTE7FlgkJ/hVvlUFR745r\r\ngZPDWsapqF7/AGrL4g1TTb
tlMdzBumjI6DbjIwMfoa1tc+C/xI8E2SfEX4fWl1rnhnTWKXN2iGK5\r\nsWxkBouSzE9COPpX0V
Xhyp9h2NqWbwSSmdzHqPjG91lNN+IV9PbS27M4jtZF8pmznDAYH489K+m/\r\nAb6NqEGoX"...,
8192) = 8192
190074 write(8,
"S5huvLRmJ+YBc8A8nI9/x5cXQxLfNS28t\r\nylCLVmfo3Yx/BdrhLHxbpXgiwexjAiNsEtnuXA
/iJdWCtn5vmPXGK/HZfENnL8atQ8S6d4T0nww", 110) = 110
190074 write(2, "\1\004190074 lmtp-server: conn 10.0.5.3:47019 [0]:
Connection lost during data transfer: read(10.0.5.3:47019 [0]) failed: <no
error>\n", 129) = 129
190074 epoll_ctl(12, EPOLL_CTL_DEL, 15, {0, {u32=3831903536,
u64=140298938627376}}) = 0
190074 write(2, "\1\002190074 Disconnect from 10.0.5.3: Read failure (state
= DATA)\n", 63) = 63
190074 close(15)??????????????????????? = 0
190074 close(8)???????????????????????? = 0
190074 brk(0x7f99e469a000)????????????? = 0x7f99e469a000
190074 brk(0x7f99e4697000)????????????? = 0x7f99e4697000
190074 brk(0x7f99e4692000)????????????? = 0x7f99e4692000
190074 close(7)???????????????????????? = 0
190074 munmap(0x7f99df5ae000, 2106232)? = 0
190074 munmap(0x7f99df7b1000, 2190784)? = 0
190074 munmap(0x7f99df3a8000, 2118896)? = 0
190074 munmap(0x7f99df0f8000, 2817696)? = 0
190074 munmap(0x7f99deea7000, 2426160)? = 0
190074 munmap(0x7f99dec98000, 2155816)? = 0
190074 munmap(0x7f99dea7e000, 2201520)? = 0
190074 munmap(0x7f99de831000, 2410344)? = 0
190074 munmap(0x7f99de605000, 2276480)? = 0
190074 munmap(0x7f99de2c2000, 3417832)? = 0
190074 munmap(0x7f99de095000, 2280176)? = 0
190074 munmap(0x7f99dde91000, 2109704)? = 0
190074 munmap(0x7f99ddc8c000, 2113912)? = 0
190074 munmap(0x7f99dda4e000, 2350304)? = 0
190074 munmap(0x7f99dd817000, 2318816)? = 0
190074 munmap(0x7f99dd614000, 2105520)? = 0
190074 epoll_ctl(12, EPOLL_CTL_DEL, 11, {0, {u32=3831812352,
u64=140298938536192}}) = 0
190074 close(11)??????????????????????? = 0
190074 close(10)??????????????????????? = 0
190074 epoll_ctl(12, EPOLL_CTL_DEL, 6, {0, {u32=3831812672,
u64=140298938536512}}) = 0
190074 epoll_ctl(12, EPOLL_CTL_DEL, 13, {0, {u32=3831839376,
u64=140298938563216}}) = 0
190074 close(13)??????????????????????? = 0
190074 close(14)??????????????????????? = 0
190074 munmap(0x7f99e13d1000, 2145864)? = 0
190074 munmap(0x7f99e1165000, 2538792)? = 0
190074 munmap(0x7f99e0d80000, 4083672)? = 0
190074 munmap(0x7f99e0b3c000, 2373600)? = 0
190074 munmap(0x7f99e0855000, 3041984)? = 0
190074 munmap(0x7f99e0651000, 2109872)? = 0
190074 munmap(0x7f99e0425000, 2273704)? = 0
190074 munmap(0x7f99e020f000, 2183696)? = 0
190074 munmap(0x7f99e0004000, 2139216)? = 0
190074 munmap(0x7f99dfe01000, 2105424)? = 0
190074 munmap(0x7f99dfbe7000, 2202248)? = 0
190074 munmap(0x7f99df9c8000, 2221912)? = 0
190074 close(12)??????????????????????? = 0
190074 brk(0x7f99e4691000)????????????? = 0x7f99e4691000
190074 close(9)???????????????????????? = 0
190074 close(4)???????????????????????? = 0
190074 exit_group(0)??????????????????? = ?
190074 +++ exited with 0 +++
Some informations:
uname -a
Linux mailsrv01 2.6.32-696.23.1.el6.x86_64 #1 SMP Tue Mar 13 22:44:18 UTC
2018 x86_64 x86_64 x86_64 GNU/Linux
dovecot --version
2.3.1 (c5a5c0c82)
dovecot -n
# 2.3.1 (c5a5c0c82): /etc/dovecot/dovecot.conf
# Pigeonhole version 0.5.devel (61b47828)
# OS: Linux 2.6.32-696.23.1.el6.x86_64 x86_64 CentOS release 6.9 (Final)
# Hostname: mailsrv01
auth_master_user_separator = *
auth_verbose_passwords = sha1
default_client_limit = 2000
deliver_log_format = subject=%s from:%f sender:%e to: %{to_envelope} size:%p
msgid=%m status=%$ delivery_time=%{delivery_time}
session_time=%{session_time}
disable_plaintext_auth = no
doveadm_allowed_commands = quota get,dsync-server,kick,purge,fts
rescan,altmove,mailbox list,expunge,mailbox status
doveadm_password =? # hidden, use -P to show it
lda_mailbox_autocreate = yes
lda_mailbox_autosubscribe = yes
lmtp_rcpt_check_quota = yes
login_greeting = IMAP4.
login_trusted_networks = x.x.x.x/24
mail_fsync = never
mail_gid = xxx
mail_location = mdbox:~/mdbox:ALT=/altstorage%h/mdbox
mail_plugins = quota quota_clone fts fts_solr zlib
mail_uid = xxx
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 ihave duplicate
vnd.dovecot
.filter
namespace inbox {
? inbox = yes
? list = yes
? location ? mailbox "Itens Enviados" {
??? auto = subscribe
??? special_use = \Sent
? }
? mailbox "Itens Exclu?dos" {
??? auto = subscribe
??? special_use = \Trash
? }
? mailbox Rascunhos {
??? auto = subscribe
??? special_use = \Drafts
? }
? mailbox Spam {
??? auto = subscribe
??? special_use = \Junk
? }
? prefix ? separator = .
}
passdb {
? args = /etc/dovecot/dovecot-ldap.conf.ext
? driver = ldap
}
plugin {
? fts = solr
? fts_solr = url=http://x.x.x.x:8983/solr/dovecot/
? imapsieve_mailbox1_before = file:/etc/dovecot/antispam/report-spam.sieve
? imapsieve_mailbox1_causes = COPY
? imapsieve_mailbox1_name = Spam
? imapsieve_mailbox2_before = file:/etc/dovecot/antispam/report-ham.sieve
? imapsieve_mailbox2_causes = COPY
? imapsieve_mailbox2_from = Spam
? imapsieve_mailbox2_name = *
? last_login_dict = redis:host=x.x.x.x:port=6379
? quota = count:User quota
? quota_clone_dict = redis:host=x.x.x.x:port=6379
? quota_rule = *:bytes=0
? quota_rule2 = Itens Exclu?dos:storage=+xM
? quota_vsizes = yes
? quota_warning = storage=95%% quota-warning 95 %u
? quota_warning2 = storage=80%% quota-warning 80 %u
? sieve = ~/.dovecot.sieve
? sieve_before = /etc/dovecot/sieve/audit.sieve
? sieve_before2 = /etc/dovecot/sieve/duplicate.sieve
? sieve_before3 = /etc/dovecot/sieve/spam.sieve
? sieve_dir = ~/sieve
? sieve_global_extensions = +vnd.dovecot.pipe
? sieve_pipe_bin_dir = /etc/dovecot/antispam
? sieve_plugins = sieve_imapsieve sieve_extprograms
? sieve_vacation_default_period = 7d
? sieve_vacation_max_period = 30d
? sieve_vacation_min_period = 1h
}
protocols = imap pop3 lmtp sieve
service anvil {
? client_limit = 2000
}
service auth {
? client_limit = 2000
}
service doveadm {
? inet_listener {
??? port = 9011
? }
? inet_listener http {
??? port = 9010
? }
? vsz_limit = 768 M
}
service imap-login {
? process_limit = 800
? process_min_avail = 200
? service_count = 1
? vsz_limit = 512 M
}
service imap-postlogin {
? executable = script-login dovecot-postlogin imap
? unix_listener imap-postlogin {
??? user = mail
? }
? user = $default_internal_user
}
service imap {
? executable = imap imap-postlogin
? process_limit = 20000
? vsz_limit = 768 M
}
service indexer-worker {
? vsz_limit = 512 M
}
service lmtp {
? inet_listener lmtp {
??? address = *
??? port = 24
? }
? vsz_limit = 512 M
}
service managesieve-login {
? inet_listener sieve {
??? port = 4190
? }
? process_min_avail = 10
}
service managesieve {
? process_limit = 512
}
service pop3-postlogin {
? executable = script-login dovecot-postlogin pop3
? unix_listener pop3-postlogin {
??? user = mail
? }
? user = $default_internal_user
}
service pop3 {
? executable = pop3 pop3-postlogin
}
service quota-warning {
? executable = script quota-warning
? unix_listener quota-warning {
??? user = mail
? }
}
service stats {
? chroot = empty
? client_limit = 20000
? drop_priv_before_exec = no
? executable = stats
? extra_groups ? group ? idle_kill = 4294967295 secs
? privileged_group ? process_limit = 1
? process_min_avail = 0
? protocol ? service_count = 0
? type ? unix_listener stats-reader {
??? group ??? mode = 0600
??? user ? }
? unix_listener stats-writer {
??? group ??? mode = 0600
? ??user ? }
? user = $default_internal_user
? vsz_limit = 18446744073709551615 B
}
ssl = no
submission_host = x.x.x.x
userdb {
? driver = prefetch
}
userdb {
? args = /etc/dovecot/dovecot-ldap.conf.ext
? driver = ldap
}
verbose_proctitle = yes
protocol lda {
? mail_fsync = optimized
? mail_plugins = quota quota_clone sieve
}
protocol imap {
? imap_max_line_length = 128 k
? mail_max_userip_connections = 30
? mail_plugins = quota quota_clone fts fts_solr zlib imap_quota last_login
imap_sieve
}
protocol lmtp {
? mail_fsync = optimized
? mail_plugins = quota quota_clone sieve
}
protocol pop3 {
? mail_max_userip_connections = 10
? mail_plugins = quota quota_clone fts fts_solr zlib last_login
? pop3_logout_format = in=%i out=%o top=%t/%p, retr=%r/%b, del=%d/%m,
size=%s
? pop3_no_flag_updates = yes
? pop3_save_uidl = yes
? pop3_uidl_format = %08Xu%08Xv
}
Regards,
Ricardo
Op 4/4/2018 om 8:26 PM schreef Ricardo Machini Barbosa:> Hello, > > After update dovecot to version 2.3.x, LMTP stopped to receive big messages > ( > 45 MB ). > Messages are being sent to dovecot LMTP by postfix. If I change this email > to another server with dovecot 2.2.x the same message are delivered > immediately.Confirmed. Starts to fail here around 30Mb. Tested with Swaks. Working on a fix... Regards, Stephan.
Op 4/4/2018 om 11:38 PM schreef Stephan Bosch:> Op 4/4/2018 om 8:26 PM schreef Ricardo Machini Barbosa: >> Hello, >> >> After update dovecot to version 2.3.x, LMTP stopped to receive big messages >> ( > 45 MB ). >> Messages are being sent to dovecot LMTP by postfix. If I change this email >> to another server with dovecot 2.2.x the same message are delivered >> immediately. > Confirmed. Starts to fail here around 30Mb. Tested with Swaks. > > Working on a fix...Problem found. It is an explicit limit of 40Mb (for the 30Mb I saw in my tests, there was also a base64 encoding I forgot about). Will fix both the unhelpful error and the fact that there should be no limit (currently) for LMTP. Regards, Stephan.