Lmtp issues on dovecot 2.3.x with big messages

Ricardo Machini Barbosa ricardomachini at gmail.com
Wed Apr 4 21:26:03 EEST 2018


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=, alt=
Apr  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 args=
Apr  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




More information about the dovecot mailing list