Dovecot 2.3.11.3 LMTP dropping connection after first part of multipart message received
Good afternoon
I have been using Dovecot with great success for several months now with one problem:
I have received several messages (3 to date out of a much larger number) which cause Dovecot LMTP to drop the connection with sendmail after only receiving the first part of the message.
Dovecot saves the first part to INBOX, and then drops the link with sendmail as it sees the rest of the data from sendmail as new (and invalid) commands
Sendmail sees the delivery as unsuccessful and requeues the message, so the cycle continues until i kill the queue
These messages are all Multipart MIME
I have attached an extract from the log which shows the above sequence
Finally, I have kept one such message from the sendmail queue (df and qf) should this be useful, but prefer not to post here as not sanitised
Any help in correcting my configuration would be appreciated.
Thanks
Steve
MAIL LOG extract
Dec 9 12:00:10 phone dovecot[179]: lmtp(20774): Connect from local
Dec 9 12:00:10 phone sm-mta-rx[20764]: STARTTLS=client, relay=localhost, version=TLSv1.3, verify=OK, cipher=TLS_AES_256_GCM_SHA384, bits=256/256
Dec 9 12:00:10 phone dovecot[179]: lmtp(20775): Connect from local
Dec 9 12:00:10 phone sm-mta-rx[20763]: STARTTLS=client, relay=localhost, version=TLSv1.3, verify=OK, cipher=TLS_AES_256_GCM_SHA384, bits=256/256
Dec 9 12:00:10 phone dovecot[179]: lmtp(*********)<20775><8EieKDqu0F8nUQAA0J78UA>: msgid=<39113a86-fdbb-4cea-b1c3-d225dff93328@info.ameli.fr mailto:39113a86-fdbb-4cea-b1c3-d225dff93328@info.ameli.fr>: saved mail to INBOX
Dec 9 12:00:10 phone dovecot[179]: lmtp(20775): Disconnect from local: Too many invalid commands. (state=READY)
Dec 9 12:00:10 phone sm-mta-rx[20763]: STARTTLS: write error=syscall error (-1), errno=32, get_error=error:00000000:lib(0):func(0):reason(0), retry=1, ssl_err=5
Dec 9 12:00:10 phone sm-mta-rx[20763]: 0B89mOON016803: SYSERR(root): timeout writing message to localhost: Broken pipe
Dec 9 12:00:10 phone sm-mta-rx[20763]: 0B89mOON016803: 0: fl=0x0, mode=20666: CHR: dev=30/1306024, ino=301, nlink=1, u/gid=0/0, size=0
Dec 9 12:00:10 phone sm-mta-rx[20763]: 0B89mOON016803: 1: fl=0x1, mode=20666: CHR: dev=30/1306024, ino=301, nlink=1, u/gid=0/0, size=0
Dec 9 12:00:10 phone sm-mta-rx[20763]: 0B89mOON016803: 2: fl=0x1, mode=20666: CHR: dev=30/1306024, ino=301, nlink=1, u/gid=0/0, size=0
Dec 9 12:00:10 phone sm-mta-rx[20763]: 0B89mOON016803: 3: fl=0x4002, mode=100600: dev=1/2, ino=26089780, nlink=1, u/gid=0/23, size=2041
Dec 9 12:00:10 phone sm-mta-rx[20763]: 0B89mOON016803: 4: fl=0x0, mode=20666: CHR: dev=30/1306024, ino=575, nlink=1, u/gid=0/0, size=0
Dec 9 12:00:10 phone sm-mta-rx[20763]: 0B89mOON016803: 5: fl=0x2, mode=140666: SOCK localhost->[[UNIX: /var/run/mDNSResponder]]
Dec 9 12:00:10 phone sm-mta-rx[20763]: 0B89mOON016803: 6: fl=0x0, mode=100640: dev=1/2, ino=25887976, nlink=1, u/gid=0/23, size=12288
Dec 9 12:00:10 phone sm-mta-rx[20763]: 0B89mOON016803: 7: fl=0x0, mode=100640: dev=1/2, ino=25887976, nlink=1, u/gid=0/23, size=12288
Dec 9 12:00:10 phone sm-mta-rx[20763]: 0B89mOON016803: 8: fl=0x0, mode=100600: dev=1/2, ino=26088246, nlink=1, u/gid=0/23, size=58024
Dec 9 12:00:10 phone sm-mta-rx[20763]: 0B89mOON016803: 9: fl=0x6, mode=140444: SOCK localhost->(Invalid argument)
Dec 9 12:00:10 phone sm-mta-rx[20763]: 0B89mOON016803: 10: fl=0x6, mode=140444: SOCK localhost->(Invalid argument)
Dec 9 12:00:10 phone sm-mta-rx[20763]: 0B89mOON016803: 11: fl=0x0, mode=100640: dev=1/2, ino=25768590, nlink=1, u/gid=0/23, size=12288
Dec 9 12:00:10 phone sm-mta-rx[20763]: 0B89mOON016803: 12: fl=0x0, mode=100640: dev=1/2, ino=25768590, nlink=1, u/gid=0/23, size=12288
Dec 9 12:00:10 phone sm-mta-rx[20763]: 0B89mOON016803: MCI@0x0: NULL
Dec 9 12:00:10 phone sm-mta-rx[20763]: 0B89mOON016803: MCI@0x7fae2c814818: flags=26404c, delay=1+01:11:31, xdelay=00:00:00, mailer=dovecot, pri=4787366, relay=localhost, dsn=4.4.2, reply=75, stat=Deferred
######################*****############## ### DOVECOT Mailer specification ### ##################*****################## Mdovecot, P=[IPC], F=zDFMPhnul59, S=EnvFromSMTP/HdrFromSMTP, R=EnvToSMTP/HdrFromSMTP, T=DNS/RFC822/X-Unix, A=FILE /var/run/dovecot/lmtp
dovecot -n —————
# 2.3.11.3 (502c39af9): /usr/local/etc/dovecot/dovecot.conf
# Pigeonhole version 0.5.11 (d71e0372)
doveconf: Warning: service auth { client_limit=100 } is lower than required under max. load (300)
doveconf: Warning: service anvil { client_limit=100 } is lower than required under max. load (203)
# OS: Darwin 15.6.0 x86_64
# Hostname: ***************
doveconf: Error: t_readlink(/var/run/dovecot//dovecot.conf) failed: readlink() failed: Permission denied
auth_mechanisms = cram-md5
auth_username_format = %Ln
base_dir = /var/run/dovecot/
default_client_limit = 100
default_internal_group = _dovecot
default_internal_user = _dovecot
default_login_user = _dovenull
hostname =*****************
lda_mailbox_autocreate = yes
mail_gid = 530
mail_home = /var/mail/%d/%n
mail_location = sdbox:~/dbox
mail_uid = 530
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
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 = scheme=SSHA256 username_format=%u /usr/local/etc/dovecot/users
driver = passwd-file
}
plugin {
sieve = file:~/sieve;active=~/.dovecot.sieve
}
postmaster_address = postmaster
protocols = imap lmtp
service auth {
unix_listener auth-userdb {
group = mailusers
mode = 0777
user = _dovecot
}
On 10/12/2020 14:58, Steve Akerman wrote:
Good afternoon
I have been using Dovecot with great success for several months now with one problem:
I have received several messages (3 to date out of a much larger number) which cause Dovecot LMTP to drop the connection with sendmail after only receiving the first part of the message.
Dovecot saves the first part to INBOX, and then drops the link with sendmail as it sees the rest of the data from sendmail as new (and invalid) commands
Sendmail sees the delivery as unsuccessful and requeues the message, so the cycle continues until i kill the queue
These messages are all Multipart MIME
I have attached an extract from the log which shows the above sequence
Finally, I have kept one such message from the sendmail queue (df and qf) should this be useful, but prefer not to post here as not sanitised
Any help in correcting my configuration would be appreciated.
Thanks
Steve
<snip>
Hi Steve
strange as it sounds, looks like your mta is sending the lmtp end of message sequence (<CRLF>.<CRLF>)in the middle of an email.
You might be able to debug it in dovecot with lmtp_rawlog_dir setting which will show the input and output dialog of the lmtp session.
John
Good afternoon
Problem Solved!
After some very useful input from John Fawcett, I have identified that the problem was not Dovecot, but the mailer used for Dovecot in Sendmail; it was missing the F=X flag that double dots any single dots, which are rather common in messages that were badly truncated to 75 line length by Apple Mail and Outlook amongst others.
The correct Mailer spec for Dovecot LMTP is:
######################*****############## ### DOVECOT Mailer specification ### ##################*****################## Mdovecot, P=[IPC], F=zDFMPXhnul59, S=EnvFromSMTP/HdrFromSMTP, R=EnvToSMTP/HdrFromSMTP, T=DNS/RFC822/X-Unix, A=FILE /var/run/dovecot/lmtp
which should be in a file called Dovecot inside sendmail cf/mailers and included in the site mc file as
MAILER(`dovecot’)dnl
As this information is missing from the very good WIKI, could someone add it in order to help others in the future?
Thanks
Steve
On 10 Dec 2020, at 14:58, Steve Akerman steve.akerman@aboukir.com wrote:
Good afternoon
I have been using Dovecot with great success for several months now with one problem:
I have received several messages (3 to date out of a much larger number) which cause Dovecot LMTP to drop the connection with sendmail after only receiving the first part of the message.
Dovecot saves the first part to INBOX, and then drops the link with sendmail as it sees the rest of the data from sendmail as new (and invalid) commands
Sendmail sees the delivery as unsuccessful and requeues the message, so the cycle continues until i kill the queue
These messages are all Multipart MIME
I have attached an extract from the log which shows the above sequence
Finally, I have kept one such message from the sendmail queue (df and qf) should this be useful, but prefer not to post here as not sanitised
Any help in correcting my configuration would be appreciated.
Thanks
Steve
MAIL LOG extract
Dec 9 12:00:10 phone dovecot[179]: lmtp(20774): Connect from local Dec 9 12:00:10 phone sm-mta-rx[20764]: STARTTLS=client, relay=localhost, version=TLSv1.3, verify=OK, cipher=TLS_AES_256_GCM_SHA384, bits=256/256 Dec 9 12:00:10 phone dovecot[179]: lmtp(20775): Connect from local Dec 9 12:00:10 phone sm-mta-rx[20763]: STARTTLS=client, relay=localhost, version=TLSv1.3, verify=OK, cipher=TLS_AES_256_GCM_SHA384, bits=256/256 Dec 9 12:00:10 phone dovecot[179]: lmtp(*********)<20775><8EieKDqu0F8nUQAA0J78UA>: msgid=<39113a86-fdbb-4cea-b1c3-d225dff93328@info.ameli.fr mailto:39113a86-fdbb-4cea-b1c3-d225dff93328@info.ameli.fr>: saved mail to INBOX Dec 9 12:00:10 phone dovecot[179]: lmtp(20775): Disconnect from local: Too many invalid commands. (state=READY) Dec 9 12:00:10 phone sm-mta-rx[20763]: STARTTLS: write error=syscall error (-1), errno=32, get_error=error:00000000:lib(0):func(0):reason(0), retry=1, ssl_err=5 Dec 9 12:00:10 phone sm-mta-rx[20763]: 0B89mOON016803: SYSERR(root): timeout writing message to localhost: Broken pipe Dec 9 12:00:10 phone sm-mta-rx[20763]: 0B89mOON016803: 0: fl=0x0, mode=20666: CHR: dev=30/1306024, ino=301, nlink=1, u/gid=0/0, size=0 Dec 9 12:00:10 phone sm-mta-rx[20763]: 0B89mOON016803: 1: fl=0x1, mode=20666: CHR: dev=30/1306024, ino=301, nlink=1, u/gid=0/0, size=0 Dec 9 12:00:10 phone sm-mta-rx[20763]: 0B89mOON016803: 2: fl=0x1, mode=20666: CHR: dev=30/1306024, ino=301, nlink=1, u/gid=0/0, size=0 Dec 9 12:00:10 phone sm-mta-rx[20763]: 0B89mOON016803: 3: fl=0x4002, mode=100600: dev=1/2, ino=26089780, nlink=1, u/gid=0/23, size=2041 Dec 9 12:00:10 phone sm-mta-rx[20763]: 0B89mOON016803: 4: fl=0x0, mode=20666: CHR: dev=30/1306024, ino=575, nlink=1, u/gid=0/0, size=0 Dec 9 12:00:10 phone sm-mta-rx[20763]: 0B89mOON016803: 5: fl=0x2, mode=140666: SOCK localhost->[[UNIX: /var/run/mDNSResponder]] Dec 9 12:00:10 phone sm-mta-rx[20763]: 0B89mOON016803: 6: fl=0x0, mode=100640: dev=1/2, ino=25887976, nlink=1, u/gid=0/23, size=12288 Dec 9 12:00:10 phone sm-mta-rx[20763]: 0B89mOON016803: 7: fl=0x0, mode=100640: dev=1/2, ino=25887976, nlink=1, u/gid=0/23, size=12288 Dec 9 12:00:10 phone sm-mta-rx[20763]: 0B89mOON016803: 8: fl=0x0, mode=100600: dev=1/2, ino=26088246, nlink=1, u/gid=0/23, size=58024 Dec 9 12:00:10 phone sm-mta-rx[20763]: 0B89mOON016803: 9: fl=0x6, mode=140444: SOCK localhost->(Invalid argument) Dec 9 12:00:10 phone sm-mta-rx[20763]: 0B89mOON016803: 10: fl=0x6, mode=140444: SOCK localhost->(Invalid argument) Dec 9 12:00:10 phone sm-mta-rx[20763]: 0B89mOON016803: 11: fl=0x0, mode=100640: dev=1/2, ino=25768590, nlink=1, u/gid=0/23, size=12288 Dec 9 12:00:10 phone sm-mta-rx[20763]: 0B89mOON016803: 12: fl=0x0, mode=100640: dev=1/2, ino=25768590, nlink=1, u/gid=0/23, size=12288 Dec 9 12:00:10 phone sm-mta-rx[20763]: 0B89mOON016803: MCI@0x0: NULL Dec 9 12:00:10 phone sm-mta-rx[20763]: 0B89mOON016803: MCI@0x7fae2c814818: flags=26404c
, errno=32, herrno=0, exitstat=75, state=8, pid=0, maxsize=0, phase=client DATA 354, mailer=dovecot, status=4.4.2, rstatus=(null), host=localhost, lastuse=Wed Dec 9 12:00:10 2020\n Dec 9 12:00:10 phone sm-mta-rx[20763]: 0B89mOON016803: to= , delay=1+01:11:31, xdelay=00:00:00, mailer=dovecot, pri=4787366, relay=localhost, dsn=4.4.2, reply=75, stat=Deferred######################*****############## ### DOVECOT Mailer specification ### ##################*****################## Mdovecot, P=[IPC], F=zDFMPhnul59, S=EnvFromSMTP/HdrFromSMTP, R=EnvToSMTP/HdrFromSMTP, T=DNS/RFC822/X-Unix, A=FILE /var/run/dovecot/lmtp
participants (2)
-
John Fawcett
-
Steve Akerman