Gabriele Nencioni
2018-Aug-07 07:35 UTC
Message delivered twice caused by an LMTP error "Got unexpected reply" during upgrade to 2.3
Hi all, we are upgrading our dovecot platform from: # dovecot --version 2.2.15.14 (39f57c379ded+) to # dovecot --version 2.3.2.1 (0719df592) Our platform is debian based and it is configured as director and backend proxy. We have just upgrade only 4 servers (2 directors and 2 backends) and when the lmtp traffic flow goes through an upgraded director and a not-upgraded backend sometimes the following error has been arised: Aug 6 14:31:28 monti-director07 dovecot: lmtp(13463): Error: eMFVIKA/aFuXNAAAhXvSMA: Failed to send message to <test2 at internalinboundcm.eu> at 192.168.72.135:24: Got unexpected reply (1/1 at 210 ms) Aug 6 14:31:28 monti-director07 dovecot: lmtp(13463): Error: eMFVIKA/aFuXNAAAhXvSMA: Failed to send message to <test2 at internalinboundcm.eu> at 192.168.72.135:24: Got unexpected reply (1/1 at 210 ms) where 172.20.44.7 (monti-director07) is a dovecot 2.3.2.1 192.168.72.135 (monti-backend07) is a dovecot 2.2.15.14 When that error occurs an email is delivered twice, as you can see from the following logs. On smtp server you can see the temp fail (by the upgraded director 172.20.44.7), retry and delivered (by a not-upgraded director 172.20.44.3): 20180806 14:31:28.772 core context="Temporary_Delivery_Failure", _fromemail="test1 at internalinboundcm.eu", _toemail="test2 at internalinboundcm.eu", _tos="test2 at internalinboundcm.eu", _size="80294", dip=172.20.44.7 dport=24 type=lmtp msg="4.4.0 Remote server not answering (bad reply)" duration=5 mailfrom=6/6/0/0 rcptto=6/6/0/0 data=6/5/1/0 tls=0/0 20180806 14:32:28.032 core context="Message_Delivered", _fromemail="test1 at internalinboundcm.eu", _toemail="test2 at internalinboundcm.eu", _tos="test2 at internalinboundcm.eu", _size="80294", dip=172.20.44.3 dport=24 type=lmtp msg="2.0.0 <test2 at internalinboundcm.eu> AS1CJtQ/aFsqMAAAj5cnUg Saved" duration=21457 mailfrom=3586/3586/0/0 rcptto=3586/3586/0/0 data=3586/3584/2/0 tls=0/0 and on backend server there are the related two delivered log entries: Aug 6 14:31:28 monti-backend07 dovecot: lmtp(test2 at internalinboundcm.eu)<f0WZF5c/aFuPdgAAj5cnUg>: copy from <lmtp DATA>: box=INBOX, uid=2727, msgid=<005b01d42d80$2101fff0$6305ffd0$@internalinboundcm.eu> Aug 6 14:31:28 monti-backend07 dovecot: lmtp(test2 at internalinboundcm.eu)<f0WZF5c/aFuPdgAAj5cnUg>: f0WZF5c/aFuPdgAAj5cnUg: msgid=<005b01d42d80$2101fff0$6305ffd0$@internalinboundcm.eu>: saved mail to INBOX Aug 6 14:32:28 monti-backend07 dovecot: lmtp(test2 at internalinboundcm.eu)<AS1CJtQ/aFsqMAAAj5cnUg>: copy from <lmtp DATA>: box=INBOX, uid=2728, msgid=<005b01d42d80$2101fff0$6305ffd0$@internalinboundcm.eu> Aug 6 14:32:28 monti-backend07 dovecot: lmtp(test2 at internalinboundcm.eu)<AS1CJtQ/aFsqMAAAj5cnUg>: AS1CJtQ/aFsqMAAAj5cnUg: msgid=<005b01d42d80$2101fff0$6305ffd0$@internalinboundcm.eu>: saved mail to INBOX This is the strace output of dovecot lmtp director process (13463): 13463 1533558688.759362 read(8, "250 2.0.0 <test2 at internalinboundcm.eu> f0WZF5c/aFuPdgAAj5cnUg Saved\r\n", 8012) = 71 <0.000028> 13463 1533558688.759493 sendto(14, "<19>Aug 6 14:31:28 dovecot: lmtp(13463): Error: eMFVIKA/aFuXNAAAhXvSMA: Failed to send message to <test2 at internalinboundcm.eu> at 192.168.72.135:24: Got unexpected reply (1/1 at 210 ms)", 188, MSG_NOSIGNAL, NULL, 0) = 188 <0.000037> So it receives the "Saved" message from backend but it arises the "Got unexpected reply" error anyway.>From tcpdump we have noticed the QUIT response is missed on lmtptrasaction after the "Saved" message from backend at DATA stage: 220 monti-backend07.it.dadainternal Dovecot ready. LHLO monti-director07.it.dadainternal 250-monti-backend07.it.dadainternal 250-8BITMIME 250-ENHANCEDSTATUSCODES 250 PIPELINING MAIL FROM:<test1 at internalinboundcm.eu> RCPT TO:<test2 at internalinboundcm.eu> DATA ...truncated message . 250 2.0.0 <test2 at internalinboundcm.eu> f0WZF5c/aFuPdgAAj5cnUg Saved While it should be something like this: 220 monti-backend07.it.dadainternal Dovecot ready. LHLO monti-director07.it.dadainternal 250-monti-backend07.it.dadainternal 250-8BITMIME 250-ENHANCEDSTATUSCODES 250 PIPELINING MAIL FROM:<test1 at internalinboundcm.eu> RCPT TO:<test2 at internalinboundcm.eu> DATA ...truncated message . 250 2.0.0 <test2 at internalinboundcm.eu> f0WZF5c/aFuPdgAAj5cnUg Saved QUIT 221 2.0.0 OK It follows the both dovecot configurations: # 2.3.2.1 (0719df592): /etc/dovecot/dovecot.conf # OS: Linux 4.9.0-7-amd64 x86_64 Debian 9.5 auth_cache_negative_ttl = 0 auth_verbose = yes auth_worker_max_count = 350 director_mail_servers = 192.168.72.129 192.168.72.130 192.168.72.131 192.168.72.132 192.168.72.133 192.168.72.134 192.168.72.135 192.168.72.136 192.168.72.137 192.168.72.138 192.168.72.139 192.168.72.140 192.168.72.141 192.168.72.142 192.168.72.143 192.168.72.144 192.168.72.145 192.168.72.146 192.168.72.147 192.168.72.148 192.168.72.149 director_servers = 172.20.44.1 172.20.44.2 172.20.44.3 172.20.44.4 172.20.44.5 172.20.44.6 172.20.44.7 172.20.44.8 disable_plaintext_auth = no doveadm_password = # hidden, use -P to show it doveadm_port = 24242 lmtp_proxy = yes log_timestamp = "%Y-%m-%d %H:%M:%S " login_log_format_elements = user=<%Lu> method=%m rip=%r lip=%l mpid=%e %c session=<%{session}> mail_log_prefix = "%s(%Lu)<%{session}>: " mail_max_userip_connections = 500 passdb { args = /etc/dovecot/dovecot-sql.conf driver = sql skip = authenticated } protocols = imap pop3 lmtp service auth-worker { user = dovecot } service auth { client_limit = 0 } service director { fifo_listener login/proxy-notify { mode = 0666 } inet_listener { port = 9090 } unix_listener director-userdb { mode = 0600 } unix_listener login/director { mode = 0666 } } service doveadm { inet_listener { port = 24242 } } service imap-login { client_limit = 12000 executable = imap-login director process_limit = 0 process_min_avail = 4 service_count = 0 } service ipc { unix_listener ipc { user = $default_internal_user } } service lmtp { client_limit = 1 executable = lmtp -L inet_listener lmtp { port = 24 } process_limit = 240 process_min_avail = 20 service_count = 1 } service pop3-login { client_limit = 12000 executable = pop3-login director process_limit = 0 process_min_avail = 4 service_count = 0 } ssl = no userdb { driver = prefetch } userdb { args = /etc/dovecot/dovecot-sql.conf driver = sql } verbose_proctitle = yes protocol doveadm { auth_socket_path = director-userdb } protocol lmtp { auth_socket_path = director-userdb mail_plugins } # 2.2.15.14 (39f57c379ded+): /etc/dovecot/dovecot.conf # OS: Linux 3.2.0-4-amd64 x86_64 Debian 7.9 auth_cache_negative_ttl = 0 auth_worker_max_count = 500 default_vsz_limit = 1 G disable_plaintext_auth = no doveadm_password first_valid_uid = 508 last_valid_uid = 508 lda_mailbox_autocreate = yes log_timestamp = "%Y-%m-%d %H:%M:%S " login_log_format_elements = user=<%Lu> method=%m rip=%r lip=%l mpid=%e %c session=<%{session}> login_trusted_networks = 192.168.72.201 192.168.72.202 192.168.72.203 192.168.72.204 192.168.72.205 192.168.72.206 192.168.72.207 192.168.72.208 mail_fsync = always mail_gid = 508 mail_location = maildir:~/Maildir mail_log_prefix = "%s(%Lu)<%{session}>: " mail_max_userip_connections = 30 mail_plugins = notify mail_log quota mail_uid = 508 maildir_very_dirty_syncs = yes mmap_disable = yes namespace { hidden = yes list = no location prefix separator = . } namespace inbox { inbox = yes location mailbox Drafts { auto = create special_use = \Drafts } mailbox Sent { auto = create special_use = \Sent } mailbox Spam { auto = create special_use = \Junk } mailbox Trash { auto = create special_use = \Trash } prefix = INBOX. separator = . } passdb { args = /etc/dovecot/dovecot-sql.conf driver = sql skip = authenticated } plugin { mail_log_events = delete undelete expunge copy mailbox_delete mailbox_rename mail_log_fields = uid box msgid quota = dict:User quota::file:%h/dovecot-quota quota_exceeded_message = Quota exceeded quota_rule2 = Trash:storage=+100M quota_warning = storage=100%% quota-warning -q 100 -n %n -d %d -e OverQuota quota_warning2 = storage=80%% quota-warning -q 80 -n %n -d %d -e FillQuota quota_warning3 = -storage=99%% quota-warning -q 99 -n %n -d %d -e InQuota sieve = ~/.dovecot.sieve sieve_extensions = +editheader sieve_max_redirects = 15 sieve_vacation_default_period = 1h } quota_full_tempfail = yes service auth-worker { user = dovecot } service auth { client_limit = 15000 } service doveadm { inet_listener { port = 24242 } } service imap-login { process_limit = 0 process_min_avail = 16 service_count = 0 } service imap { executable = imap postlogin process_limit = 7000 service_count = 2300 } service lmtp { client_limit = 1 executable = lmtp -L inet_listener lmtp { address = 192.168.72.129 127.0.0.1 port = 24 } process_limit = 240 process_min_avail = 20 service_count = 10 } service pop3-login { process_limit = 0 process_min_avail = 16 service_count = 0 } service pop3 { executable = pop3 postlogin process_limit = 7000 service_count = 2300 } ssl = no submission_host userdb { driver = prefetch } userdb { args = /etc/dovecot/dovecot-sql.conf driver = sql } verbose_proctitle = yes protocol imap { imap_client_workarounds = delay-newmail mail_plugins = notify mail_log quota imap_quota } protocol pop3 { pop3_client_workarounds = outlook-no-nuls oe-ns-eoh pop3_fast_size_lookups = yes pop3_no_flag_updates = yes pop3_uidl_format = %f } protocol lmtp { mail_plugins = notify mail_log quota sieve passdb { args = /etc/dovecot/dovecot-lmtp.conf driver = sql name } userdb { args = /etc/dovecot/dovecot-lmtp.conf driver = sql name result_failure = return-fail skip = never } } Please could someone help me? How can I fix that error, in order to avoid the duplicated email? Thanks in advance Regards, -- Gabriele Nencioni System Administrator eml gabriele.nencioni at register.it
Stephan Bosch
2018-Aug-08 16:04 UTC
Message delivered twice caused by an LMTP error "Got unexpected reply" during upgrade to 2.3
Hi, Op 07/08/2018 om 09:35 schreef Gabriele Nencioni:> Hi all, > we are upgrading our dovecot platform from: > > # dovecot --version > 2.2.15.14 (39f57c379ded+)Great! A mummy from ancient times. That is going to make reproducing the circumstances here a bit difficult (difficult to get that compiled here anymore). I cannot reproduce anything like that so far with current versions. Can you make a pcap log of the LMTP communication between the two Dovecot hosts? That may give me a clue on which side of the communication is causing the issue. Regards, Stephan.> to > > # dovecot --version > 2.3.2.1 (0719df592) > > Our platform is debian based and it is configured as director and > backend proxy. > > We have just upgrade only 4 servers (2 directors and 2 backends) and > when the lmtp traffic flow goes through an upgraded director and a > not-upgraded backend sometimes the following error has been arised: > Aug 6 14:31:28 monti-director07 dovecot: lmtp(13463): Error: > eMFVIKA/aFuXNAAAhXvSMA: Failed to send message to > <test2 at internalinboundcm.eu> at 192.168.72.135:24: Got unexpected reply > (1/1 at 210 ms) > Aug 6 14:31:28 monti-director07 dovecot: lmtp(13463): Error: > eMFVIKA/aFuXNAAAhXvSMA: Failed to send message to > <test2 at internalinboundcm.eu> at 192.168.72.135:24: Got unexpected reply > (1/1 at 210 ms) > > where > 172.20.44.7 (monti-director07) is a dovecot 2.3.2.1 > 192.168.72.135 (monti-backend07) is a dovecot 2.2.15.14 > > > When that error occurs an email is delivered twice, as you can see from > the following logs. > > On smtp server you can see the temp fail (by the upgraded director > 172.20.44.7), retry and delivered (by a not-upgraded director 172.20.44.3): > 20180806 14:31:28.772 core context="Temporary_Delivery_Failure", > _fromemail="test1 at internalinboundcm.eu", > _toemail="test2 at internalinboundcm.eu", > _tos="test2 at internalinboundcm.eu", _size="80294", dip=172.20.44.7 > dport=24 type=lmtp msg="4.4.0 Remote server not answering (bad reply)" > duration=5 mailfrom=6/6/0/0 rcptto=6/6/0/0 data=6/5/1/0 tls=0/0 > 20180806 14:32:28.032 core context="Message_Delivered", > _fromemail="test1 at internalinboundcm.eu", > _toemail="test2 at internalinboundcm.eu", > _tos="test2 at internalinboundcm.eu", _size="80294", dip=172.20.44.3 > dport=24 type=lmtp msg="2.0.0 <test2 at internalinboundcm.eu> > AS1CJtQ/aFsqMAAAj5cnUg Saved" duration=21457 mailfrom=3586/3586/0/0 > rcptto=3586/3586/0/0 data=3586/3584/2/0 tls=0/0 > > > and on backend server there are the related two delivered log entries: > Aug 6 14:31:28 monti-backend07 dovecot: > lmtp(test2 at internalinboundcm.eu)<f0WZF5c/aFuPdgAAj5cnUg>: copy from > <lmtp DATA>: box=INBOX, uid=2727, > msgid=<005b01d42d80$2101fff0$6305ffd0$@internalinboundcm.eu> > Aug 6 14:31:28 monti-backend07 dovecot: > lmtp(test2 at internalinboundcm.eu)<f0WZF5c/aFuPdgAAj5cnUg>: > f0WZF5c/aFuPdgAAj5cnUg: > msgid=<005b01d42d80$2101fff0$6305ffd0$@internalinboundcm.eu>: saved mail > to INBOX > Aug 6 14:32:28 monti-backend07 dovecot: > lmtp(test2 at internalinboundcm.eu)<AS1CJtQ/aFsqMAAAj5cnUg>: copy from > <lmtp DATA>: box=INBOX, uid=2728, > msgid=<005b01d42d80$2101fff0$6305ffd0$@internalinboundcm.eu> > Aug 6 14:32:28 monti-backend07 dovecot: > lmtp(test2 at internalinboundcm.eu)<AS1CJtQ/aFsqMAAAj5cnUg>: > AS1CJtQ/aFsqMAAAj5cnUg: > msgid=<005b01d42d80$2101fff0$6305ffd0$@internalinboundcm.eu>: saved mail > to INBOX > > > This is the strace output of dovecot lmtp director process (13463): > 13463 1533558688.759362 read(8, "250 2.0.0 <test2 at internalinboundcm.eu> > f0WZF5c/aFuPdgAAj5cnUg Saved\r\n", 8012) = 71 <0.000028> > 13463 1533558688.759493 sendto(14, "<19>Aug 6 14:31:28 dovecot: > lmtp(13463): Error: eMFVIKA/aFuXNAAAhXvSMA: Failed to send message to > <test2 at internalinboundcm.eu> at 192.168.72.135:24: Got unexpected reply > (1/1 at 210 ms)", 188, MSG_NOSIGNAL, NULL, 0) = 188 <0.000037> > > So it receives the "Saved" message from backend but it arises the "Got > unexpected reply" error anyway. > > > From tcpdump we have noticed the QUIT response is missed on lmtp > trasaction after the "Saved" message from backend at DATA stage: > 220 monti-backend07.it.dadainternal Dovecot ready. > LHLO monti-director07.it.dadainternal > 250-monti-backend07.it.dadainternal > 250-8BITMIME > 250-ENHANCEDSTATUSCODES > 250 PIPELINING > MAIL FROM:<test1 at internalinboundcm.eu> > RCPT TO:<test2 at internalinboundcm.eu> > DATA > ...truncated message > > > . > 250 2.0.0 <test2 at internalinboundcm.eu> f0WZF5c/aFuPdgAAj5cnUg Saved > > > While it should be something like this: > > 220 monti-backend07.it.dadainternal Dovecot ready. > LHLO monti-director07.it.dadainternal > 250-monti-backend07.it.dadainternal > 250-8BITMIME > 250-ENHANCEDSTATUSCODES > 250 PIPELINING > MAIL FROM:<test1 at internalinboundcm.eu> > RCPT TO:<test2 at internalinboundcm.eu> > DATA > ...truncated message > > > . > 250 2.0.0 <test2 at internalinboundcm.eu> f0WZF5c/aFuPdgAAj5cnUg Saved > QUIT > 221 2.0.0 OK > > > It follows the both dovecot configurations: > > # 2.3.2.1 (0719df592): /etc/dovecot/dovecot.conf > # OS: Linux 4.9.0-7-amd64 x86_64 Debian 9.5 > auth_cache_negative_ttl = 0 > auth_verbose = yes > auth_worker_max_count = 350 > director_mail_servers = 192.168.72.129 192.168.72.130 192.168.72.131 > 192.168.72.132 192.168.72.133 192.168.72.134 192.168.72.135 > 192.168.72.136 192.168.72.137 192.168.72.138 192.168.72.139 > 192.168.72.140 192.168.72.141 192.168.72.142 192.168.72.143 > 192.168.72.144 192.168.72.145 192.168.72.146 192.168.72.147 > 192.168.72.148 192.168.72.149 > director_servers = 172.20.44.1 172.20.44.2 172.20.44.3 172.20.44.4 > 172.20.44.5 172.20.44.6 172.20.44.7 172.20.44.8 > disable_plaintext_auth = no > doveadm_password = # hidden, use -P to show it > doveadm_port = 24242 > lmtp_proxy = yes > log_timestamp = "%Y-%m-%d %H:%M:%S " > login_log_format_elements = user=<%Lu> method=%m rip=%r lip=%l mpid=%e > %c session=<%{session}> > mail_log_prefix = "%s(%Lu)<%{session}>: " > mail_max_userip_connections = 500 > passdb { > args = /etc/dovecot/dovecot-sql.conf > driver = sql > skip = authenticated > } > protocols = imap pop3 lmtp > service auth-worker { > user = dovecot > } > service auth { > client_limit = 0 > } > service director { > fifo_listener login/proxy-notify { > mode = 0666 > } > inet_listener { > port = 9090 > } > unix_listener director-userdb { > mode = 0600 > } > unix_listener login/director { > mode = 0666 > } > } > service doveadm { > inet_listener { > port = 24242 > } > } > service imap-login { > client_limit = 12000 > executable = imap-login director > process_limit = 0 > process_min_avail = 4 > service_count = 0 > } > service ipc { > unix_listener ipc { > user = $default_internal_user > } > } > service lmtp { > client_limit = 1 > executable = lmtp -L > inet_listener lmtp { > port = 24 > } > process_limit = 240 > process_min_avail = 20 > service_count = 1 > } > service pop3-login { > client_limit = 12000 > executable = pop3-login director > process_limit = 0 > process_min_avail = 4 > service_count = 0 > } > ssl = no > userdb { > driver = prefetch > } > userdb { > args = /etc/dovecot/dovecot-sql.conf > driver = sql > } > verbose_proctitle = yes > protocol doveadm { > auth_socket_path = director-userdb > } > protocol lmtp { > auth_socket_path = director-userdb > mail_plugins > } > > > > # 2.2.15.14 (39f57c379ded+): /etc/dovecot/dovecot.conf > # OS: Linux 3.2.0-4-amd64 x86_64 Debian 7.9 > auth_cache_negative_ttl = 0 > auth_worker_max_count = 500 > default_vsz_limit = 1 G > disable_plaintext_auth = no > doveadm_password > first_valid_uid = 508 > last_valid_uid = 508 > lda_mailbox_autocreate = yes > log_timestamp = "%Y-%m-%d %H:%M:%S " > login_log_format_elements = user=<%Lu> method=%m rip=%r lip=%l mpid=%e > %c session=<%{session}> > login_trusted_networks = 192.168.72.201 192.168.72.202 192.168.72.203 > 192.168.72.204 192.168.72.205 192.168.72.206 192.168.72.207 192.168.72.208 > mail_fsync = always > mail_gid = 508 > mail_location = maildir:~/Maildir > mail_log_prefix = "%s(%Lu)<%{session}>: " > mail_max_userip_connections = 30 > mail_plugins = notify mail_log quota > mail_uid = 508 > maildir_very_dirty_syncs = yes > mmap_disable = yes > namespace { > hidden = yes > list = no > location > prefix > separator = . > } > namespace inbox { > inbox = yes > location > mailbox Drafts { > auto = create > special_use = \Drafts > } > mailbox Sent { > auto = create > special_use = \Sent > } > mailbox Spam { > auto = create > special_use = \Junk > } > mailbox Trash { > auto = create > special_use = \Trash > } > prefix = INBOX. > separator = . > } > passdb { > args = /etc/dovecot/dovecot-sql.conf > driver = sql > skip = authenticated > } > plugin { > mail_log_events = delete undelete expunge copy mailbox_delete > mailbox_rename > mail_log_fields = uid box msgid > quota = dict:User quota::file:%h/dovecot-quota > quota_exceeded_message = Quota exceeded > quota_rule2 = Trash:storage=+100M > quota_warning = storage=100%% quota-warning -q 100 -n %n -d %d -e > OverQuota > quota_warning2 = storage=80%% quota-warning -q 80 -n %n -d %d -e FillQuota > quota_warning3 = -storage=99%% quota-warning -q 99 -n %n -d %d -e InQuota > sieve = ~/.dovecot.sieve > sieve_extensions = +editheader > sieve_max_redirects = 15 > sieve_vacation_default_period = 1h > } > quota_full_tempfail = yes > service auth-worker { > user = dovecot > } > service auth { > client_limit = 15000 > } > service doveadm { > inet_listener { > port = 24242 > } > } > service imap-login { > process_limit = 0 > process_min_avail = 16 > service_count = 0 > } > service imap { > executable = imap postlogin > process_limit = 7000 > service_count = 2300 > } > service lmtp { > client_limit = 1 > executable = lmtp -L > inet_listener lmtp { > address = 192.168.72.129 127.0.0.1 > port = 24 > } > process_limit = 240 > process_min_avail = 20 > service_count = 10 > } > service pop3-login { > process_limit = 0 > process_min_avail = 16 > service_count = 0 > } > service pop3 { > executable = pop3 postlogin > process_limit = 7000 > service_count = 2300 > } > ssl = no > submission_host > userdb { > driver = prefetch > } > userdb { > args = /etc/dovecot/dovecot-sql.conf > driver = sql > } > verbose_proctitle = yes > protocol imap { > imap_client_workarounds = delay-newmail > mail_plugins = notify mail_log quota imap_quota > } > protocol pop3 { > pop3_client_workarounds = outlook-no-nuls oe-ns-eoh > pop3_fast_size_lookups = yes > pop3_no_flag_updates = yes > pop3_uidl_format = %f > } > protocol lmtp { > mail_plugins = notify mail_log quota sieve > passdb { > args = /etc/dovecot/dovecot-lmtp.conf > driver = sql > name > } > userdb { > args = /etc/dovecot/dovecot-lmtp.conf > driver = sql > name > result_failure = return-fail > skip = never > } > } > > > Please could someone help me? > How can I fix that error, in order to avoid the duplicated email? > > > Thanks in advance > Regards, > -- > Gabriele Nencioni > System Administrator > eml gabriele.nencioni at register.it
Gabriele Nencioni
2018-Aug-09 06:15 UTC
Message delivered twice caused by an LMTP error "Got unexpected reply" during upgrade to 2.3
On 08/08/2018 06:04 PM, Stephan Bosch wrote:> HiHi and thanks for your reply.> Can you make a pcap log of the LMTP communication between the two > Dovecot hosts? That may give me a clue on which side of the > communication is causing the issue.Yes sure, where I can send it? Here on list or at your address? Regards -- Gabriele Nencioni System Administrator eml gabriele.nencioni at register.it
Gabriele Nencioni
2018-Aug-16 09:47 UTC
Message delivered twice caused by an LMTP error "Got unexpected reply" during upgrade to 2.3
>>> On 08/09/2018 09:12 AM, Stephan Bosch wrote >>>>>> Can you make a pcap log of the LMTP communication between the two >>>>>> Dovecot hosts? That may give me a clue on which side of the >>>>>> communication is causing the issue. >>>>> Yes sure, where I can send it? >>>>> Here on list or at your address? >>>> >>>> Just send it to me.On 08/16/2018 10:21 AM, Stephan Bosch wrote:> Op 16/08/2018 om 09:46 schreef Gabriele Nencioni: >> On 08/15/2018 06:39 PM, Stephan Bosch wrote: >>> Op 15-8-2018 om 17:19 schreef Stephan Bosch: >>>> >>>> Op 13-8-2018 om 15:50 schreef Gabriele Nencioni: >>>>> So the scenario seems to be: >>>>> the error occurs between old directors and new backends >>>>> and between the new backends and the smtp submission_host (for >>>>> redirection) >>>>> and using the pipeline capability and attaching a file >>>>> >>>>> Let me know if you need more info >>>> In this case it is possible to obtain a debug log by enabling >>>> mail_debug=yes. Can you obtain a full debug log for such a failing >>>> submission session? >> Ok! It is attached. > > That is just weird. Dovecot reports that it cannot fully send the last > bits of the message and right thereafter the reply is received, which > Dovecot then interprets as out-of-sequence. The PCAP files tell me the > final CRLF.CRLF is actually sent to the other side, but somehow Dovecot > thinks it couldn't do that yet. > > Is this problem occurring for any and all SMTP client interactions, or > just every once in a while?Unfortunately it occurs just every once in a while and it is weird because at the second attempt the message is successful delivered or redirected.>>> Also, I don't see anything weird in the PCAP files: the command-reply >>> sequence is OK. This means that this is likely a bug in the current >>> Dovecot version. Those debug logs should tell me more. >> Ok! Which version of dovecot do you suggest to install? >> On debian current stable (stretch) repository there is the version >> number 2.2.27, have we to install it? > > If you're facing big trouble it is usually best to revert to the > previous version that worked I guess.Ok I'm agree! So, about you, which version can I try to install the 2.2.27 or the previous release of the 2.3 version such as v2.3.2 2018-06-29 or v2.3.1 2018-02-29? Regards, -- Gabriele Nencioni System Administrator eml gabriele.nencioni at register.it
Stephan Bosch
2018-Aug-16 10:01 UTC
Message delivered twice caused by an LMTP error "Got unexpected reply" during upgrade to 2.3
Op 16-8-2018 om 11:47 schreef Gabriele Nencioni:>>>> On 08/09/2018 09:12 AM, Stephan Bosch wrote >>>>>>> Can you make a pcap log of the LMTP communication between the two >>>>>>> Dovecot hosts? That may give me a clue on which side of the >>>>>>> communication is causing the issue. >>>>>> Yes sure, where I can send it? >>>>>> Here on list or at your address? >>>>> Just send it to me. > On 08/16/2018 10:21 AM, Stephan Bosch wrote: >> Op 16/08/2018 om 09:46 schreef Gabriele Nencioni: >>> On 08/15/2018 06:39 PM, Stephan Bosch wrote: >>>> Op 15-8-2018 om 17:19 schreef Stephan Bosch: >>>>> Op 13-8-2018 om 15:50 schreef Gabriele Nencioni: >>>>>> So the scenario seems to be: >>>>>> the error occurs between old directors and new backends >>>>>> and between the new backends and the smtp submission_host (for >>>>>> redirection) >>>>>> and using the pipeline capability and attaching a file >>>>>> >>>>>> Let me know if you need more info >>>>> In this case it is possible to obtain a debug log by enabling >>>>> mail_debug=yes. Can you obtain a full debug log for such a failing >>>>> submission session? >>> Ok! It is attached. >> That is just weird. Dovecot reports that it cannot fully send the last >> bits of the message and right thereafter the reply is received, which >> Dovecot then interprets as out-of-sequence. The PCAP files tell me the >> final CRLF.CRLF is actually sent to the other side, but somehow Dovecot >> thinks it couldn't do that yet. >> >> Is this problem occurring for any and all SMTP client interactions, or >> just every once in a while? > Unfortunately it occurs just every once in a while and it is weird > because at the second attempt the message is successful delivered or > redirected.I have a theory. Will try something later today.>>>> Also, I don't see anything weird in the PCAP files: the command-reply >>>> sequence is OK. This means that this is likely a bug in the current >>>> Dovecot version. Those debug logs should tell me more. >>> Ok! Which version of dovecot do you suggest to install? >>> On debian current stable (stretch) repository there is the version >>> number 2.2.27, have we to install it? >> If you're facing big trouble it is usually best to revert to the >> previous version that worked I guess. > Ok I'm agree! > So, about you, which version can I try to install the 2.2.27 or the > previous release of the 2.3 version such as > v2.3.2 2018-06-29 or > v2.3.1 2018-02-29?This would likely happen throughout v2.3. Regards, Stephan.
Seemingly Similar Threads
- Message delivered twice caused by an LMTP error "Got unexpected reply" during upgrade to 2.3
- lmtp Panic Buffer write out of range
- lmtp Panic Buffer write out of range
- Message delivered twice caused by an LMTP error "Got unexpected reply" during upgrade to 2.3
- Message delivered twice caused by an LMTP error "Got unexpected reply" during upgrade to 2.3