Mailing List Archive

https://bugs.exim.org/show_bug.cgi?id=2693

--- Comment #2 from Benoit Panizzon <bp@imp.ch> ---
Just got feedback from sender ISP (exim) customer. He re-tested while
pipelining off on our postfix. Result: Problem does not occur. So it is very
likely related to pipelining.

--
You are receiving this mail because:
You are on the CC list for the bug.
--
## List details at https://lists.exim.org/mailman/listinfo/exim-dev Exim details at http://www.exim.org/ ##

https://bugs.exim.org/show_bug.cgi?id=2693

--- Comment #3 from Simon Arlott <bugzilla.exim.simon@arlott.org> ---
The observed behaviour of the three delivery attempts is:
A ok
B defer
C defer
D defer
E defer
F defer

B ok
C defer
D defer
E ok
F ok

E ok
F ok

The recipients are sent in alphabetical order, and they are in this order in
the To: header.

So it's not quite as simple as described. There's no obvious indication of an
SMTP proxy being involved to reorder responses.

--
You are receiving this mail because:
You are on the CC list for the bug.
--
## List details at https://lists.exim.org/mailman/listinfo/exim-dev Exim details at http://www.exim.org/ ##

https://bugs.exim.org/show_bug.cgi?id=2693

--- Comment #4 from Simon Arlott <bugzilla.exim.simon@arlott.org> ---
Created attachment 1359
--> https://bugs.exim.org/attachment.cgi?id=1359&action=edit
Pipelining test case

Exim works correctly when I test it

--
You are receiving this mail because:
You are on the CC list for the bug.
--
## List details at https://lists.exim.org/mailman/listinfo/exim-dev Exim details at http://www.exim.org/ ##

https://bugs.exim.org/show_bug.cgi?id=2693

--- Comment #5 from Simon Arlott <bugzilla.exim.simon@arlott.org> ---
There is a slight variation in the observed scenario. The first two attempts
occur in the same connection. The final attempt is in a new connection several
seconds later. My test case is using three separate executions of Exim.

Could someone modify the test case to replicate this?

--
You are receiving this mail because:
You are on the CC list for the bug.
--
## List details at https://lists.exim.org/mailman/listinfo/exim-dev Exim details at http://www.exim.org/ ##

https://bugs.exim.org/show_bug.cgi?id=2693

--- Comment #6 from Benoit Panizzon <bp@imp.ch> ---
Waiting for feedback from the tech @ sending ISP to learn about the used exim
version and his logs.

Simon, your observation is correct.

The first six recipients are sent in one TCP session. The failed are retried
immediately after the first attempt where only the first recipient got
accepted.

Then the last two are re-sent in a new connection a bit later.

I simplified the description of the issue. Sorry if that caused confusion.

On our side (in front of postfix, where the capture was obtained) we have no
transparent smtp proxy or similar in the connecting which might re-order the
responses. I don't know about the sending side.

-Benoit-

--
You are receiving this mail because:
You are on the CC list for the bug.
--
## List details at https://lists.exim.org/mailman/listinfo/exim-dev Exim details at http://www.exim.org/ ##

https://bugs.exim.org/show_bug.cgi?id=2693

Moritz Friedrich <mf@cyon.ch> changed:

What |Removed |Added
----------------------------------------------------------------------------
CC| |mf@cyon.ch

--- Comment #7 from Moritz Friedrich <mf@cyon.ch> ---
And here is the information from our sending side.

Our Exim version: Exim version 4.94 #2 built 01-Jun-2020 19:51:21
We use the current Exim package from the EPEL 7 repository.

And this is the log output at our end:

2021-02-04 10:56:36 +0100 1l7bMq-0004up-Hz <=
root@mail-gateway-shared07.c***.net U=root P=local S=548
2021-02-04 10:56:37 +0100 1l7bMq-0004up-Hz => be***.b***@b***.ch
F=<root@mail-gateway-shared07.c***.net> R=dnslookup T=remote_smtp
H=asterix.i***.ch [157.161.***.***] C="250 2.0.0 Ok: queued as 60B53C650C"
2021-02-04 10:56:37 +0100 1l7bMq-0004up-Hz => bi***.l***@b***.ch
F=<root@mail-gateway-shared07.c***.net> R=dnslookup T=remote_smtp
H=asterix.i***.ch [157.161.***.***] C="250 2.0.0 Ok: queued as CB397C6586"
2021-02-04 10:56:37 +0100 1l7bMq-0004up-Hz -> da***.r***@b***.ch
F=<root@mail-gateway-shared07.c***.net> R=dnslookup T=remote_smtp
H=asterix.i***.ch [157.161.***.***] C="250 2.0.0 Ok: queued as CB397C6586"
2021-02-04 10:56:37 +0100 1l7bMq-0004up-Hz -> da***.i***@b***.ch
F=<root@mail-gateway-shared07.c***.net> R=dnslookup T=remote_smtp
H=asterix.i***.ch [157.161.***.***] C="250 2.0.0 Ok: queued as CB397C6586"
2021-02-04 10:56:37 +0100 1l7bMq-0004up-Hz == de***.r***@b***.ch R=dnslookup
T=remote_smtp defer (0)
2021-02-04 10:56:37 +0100 1l7bMq-0004up-Hz == du***.s***@b***.ch R=dnslookup
T=remote_smtp defer (0)
2021-02-04 10:56:55 +0100 1l7bMq-0004up-Hz => de***.r***@b***.ch
F=<root@mail-gateway-shared07.c***.net> R=dnslookup T=remote_smtp
H=asterix.i***.ch [157.161.***.***] C="250 2.0.0 Ok: queued as 32746C657E"
2021-02-04 10:56:55 +0100 1l7bMq-0004up-Hz -> du***.s***@b***.ch
F=<root@mail-gateway-shared07.c***.net> R=dnslookup T=remote_smtp
H=asterix.i***.ch [157.161.***.***] C="250 2.0.0 Ok: queued as 32746C657E"
2021-02-04 10:56:55 +0100 1l7bMq-0004up-Hz Completed

--
You are receiving this mail because:
You are on the CC list for the bug.
--
## List details at https://lists.exim.org/mailman/listinfo/exim-dev Exim details at http://www.exim.org/ ##

https://bugs.exim.org/show_bug.cgi?id=2693

--- Comment #8 from Jeremy Harris <jgh146exb@wizmail.org> ---
I'm not seeing the problem. Six recipients were delivered to according to
Exim's log. Was that the number expected? Were the messages in fact received
by the destination accounts?

--
You are receiving this mail because:
You are on the CC list for the bug.
--
## List details at https://lists.exim.org/mailman/listinfo/exim-dev Exim details at http://www.exim.org/ ##

https://bugs.exim.org/show_bug.cgi?id=2693

--- Comment #9 from Moritz Friedrich <mf@cyon.ch> ---
Created attachment 1360
--> https://bugs.exim.org/attachment.cgi?id=1360&action=edit
exim configuration

--
You are receiving this mail because:
You are on the CC list for the bug.
--
## List details at https://lists.exim.org/mailman/listinfo/exim-dev Exim details at http://www.exim.org/ ##

https://bugs.exim.org/show_bug.cgi?id=2693

--- Comment #10 from Benoit Panizzon <bp@imp.ch> ---
Hi Jeremy

Look at Simon Arlott's post about the recipients and how they got rejected.

He has the tcp caputre file (not uploaded as it contains the real email
addresses of our customers).


C defer
D defer

They did never received the email.

E ok
F ok

E ok
F ok

That is a clear hint that exim delivered duplicates.

It looks like the 'defered' status of C and D were passed to recipients E and
F.

--
You are receiving this mail because:
You are on the CC list for the bug.
--
## List details at https://lists.exim.org/mailman/listinfo/exim-dev Exim details at http://www.exim.org/ ##

https://bugs.exim.org/show_bug.cgi?id=2693

--- Comment #11 from Jeremy Harris <jgh146exb@wizmail.org> ---
Ah, it was unclear thanks to the obfuscation of names. Simon seems to be
saying
(comment 3) that it works for him, although (4) obscures that somewhat.
It's also unclear what triggered the second connection 18 seconds later -
and did you manage to check the queue between the two?

I'm assuming this is a stock Exim version, unmodified. Please confirm the
actual version since the bug doesn't have it set.

Since we're looking for most unusual behaviour - I'd also like to verify that
nothing apart from Exim is touching Exim's spool directory and files.

--
You are receiving this mail because:
You are on the CC list for the bug.
--
## List details at https://lists.exim.org/mailman/listinfo/exim-dev Exim details at http://www.exim.org/ ##

https://bugs.exim.org/show_bug.cgi?id=2693

Moritz Friedrich <mf@cyon.ch> changed:

What |Removed |Added
----------------------------------------------------------------------------
Version|N/A |4.94

--- Comment #12 from Moritz Friedrich <mf@cyon.ch> ---
> It's also unclear what triggered the second connection 18 seconds later -
> and did you manage to check the queue between the two?

There has started an Exim queue run:

2021-02-04 10:56:38 +0100 Start queue run: pid=19130
2021-02-04 10:56:44 +0100 1l7bHz-0004f3-Lm ...
2021-02-04 10:56:49 +0100 1l7bH2-0004bv-HV ...
2021-02-04 10:56:54 +0100 1l7bHz-0004f2-89 ...
2021-02-04 10:56:55 +0100 1l7bMq-0004up-Hz => de***.r***@b***.ch
F=<root@mail-gateway-shared07.c***.net> R=dnslookup T=remote_smtp
H=asterix.i***.ch [157.161.***.***] C="250 2.0.0 Ok: queued as 32746C657E"
2021-02-04 10:56:55 +0100 1l7bMq-0004up-Hz -> du***.s***@b***.ch
F=<root@mail-gateway-shared07.c***.net> R=dnslookup T=remote_smtp
H=asterix.i***.ch [157.161.***.***] C="250 2.0.0 Ok: queued as 32746C657E"
2021-02-04 10:56:55 +0100 End queue run: pid=19130

> I'm assuming this is a stock Exim version, unmodified. Please confirm the
> actual version since the bug doesn't have it set.

We use the current Exim release from EPEL7, without any modifications from our
side:
[~]$ exim --version
Exim version 4.94 #2 built 01-Jun-2020 19:51:21
Copyright (c) University of Cambridge, 1995 - 2018
(c) The Exim Maintainers and contributors in ACKNOWLEDGMENTS file, 2007 - 2018
Berkeley DB: Berkeley DB 5.3.21: (May 11, 2012)
Support for: crypteq iconv() IPv6 PAM Perl Expand_dlfunc OpenSSL
Content_Scanning DANE DKIM DNSSEC Event OCSP PIPE_CONNECT PRDR PROXY SOCKS SPF
DMARC TCP_Fast_Open
Lookups (built-in): lsearch wildlsearch nwildlsearch iplsearch cdb dbm dbmjz
dbmnz dnsdb dsearch ldap ldapdn ldapm nis nis0 nisplus passwd sqlite
Authenticators: cram_md5 cyrus_sasl dovecot gsasl plaintext spa tls
Routers: accept dnslookup ipliteral manualroute queryprogram redirect
Transports: appendfile/maildir/mailstore/mbx autoreply lmtp pipe smtp
Malware: f-protd f-prot6d drweb fsecure sophie clamd avast sock cmdline
Fixed never_users: 0
Configure owner: 0:0
Size of off_t: 8
Configuration file is /etc/exim/exim.conf

> Since we're looking for most unusual behaviour - I'd also like to verify that
> nothing apart from Exim is touching Exim's spool directory and files.
Apart from the Exim service, nothing accesses the spool directory and files.

--
You are receiving this mail because:
You are on the CC list for the bug.
--
## List details at https://lists.exim.org/mailman/listinfo/exim-dev Exim details at http://www.exim.org/ ##

https://bugs.exim.org/show_bug.cgi?id=2693

Simon Arlott <bugzilla.exim.simon@arlott.org> changed:

What |Removed |Added
----------------------------------------------------------------------------
Attachment #1359|0 |1
is obsolete| |

--- Comment #13 from Simon Arlott <bugzilla.exim.simon@arlott.org> ---
Created attachment 1361
--> https://bugs.exim.org/attachment.cgi?id=1361&action=edit
Pipelining test case

I've now reproduced this; Exim has special behaviour for 452 responses and
something is going wrong.

In this example, C and D were deferred but Exim thinks E and F were deferred:

1999-03-02 09:44:33 10HmaX-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local
S=sss
1999-03-02 09:44:33 10HmaX-0005vi-00 => a@test.ex <A@test.ex> R=client
T=send_to_server H=127.0.0.1 [127.0.0.1] L C="250 OK id=10HmaY-0005vi-00"
1999-03-02 09:44:33 10HmaX-0005vi-00 => b@test.ex <B@test.ex> R=client
T=send_to_server H=127.0.0.1 [127.0.0.1] L C="250 OK id=10HmaZ-0005vi-00"
1999-03-02 09:44:33 10HmaX-0005vi-00 -> c@test.ex <C@test.ex> R=client
T=send_to_server H=127.0.0.1 [127.0.0.1] L C="250 OK id=10HmaZ-0005vi-00"
1999-03-02 09:44:33 10HmaX-0005vi-00 -> d@test.ex <D@test.ex> R=client
T=send_to_server H=127.0.0.1 [127.0.0.1] L C="250 OK id=10HmaZ-0005vi-00"
1999-03-02 09:44:33 10HmaX-0005vi-00 == e@test.ex <E@test.ex> R=client
T=send_to_server defer (0)
1999-03-02 09:44:33 10HmaX-0005vi-00 == f@test.ex <F@test.ex> R=client
T=send_to_server defer (0)

1999-03-02 09:44:33 10HmaX-0005vi-00 => e@test.ex <E@test.ex> R=client
T=send_to_server H=127.0.0.1 [127.0.0.1] L C="250 OK id=10HmbA-0005vi-00"
1999-03-02 09:44:33 10HmaX-0005vi-00 -> f@test.ex <F@test.ex> R=client
T=send_to_server H=127.0.0.1 [127.0.0.1] L C="250 OK id=10HmbA-0005vi-00"
1999-03-02 09:44:33 10HmaX-0005vi-00 Completed

It's also sending to A twice too, partly because the test case is invoking a
delivery 3 times when it now only requires 2 attempts:

1999-03-02 09:44:33 10HmaY-0005vi-00 => a@test.ex <A@test.ex> R=client
T=send_to_server H=127.0.0.1 [127.0.0.1] L C="250 OK id=10HmbB-0005vi-00"
1999-03-02 09:44:33 10HmaY-0005vi-00 Completed

--
You are receiving this mail because:
You are on the CC list for the bug.
--
## List details at https://lists.exim.org/mailman/listinfo/exim-dev Exim details at http://www.exim.org/ ##

https://bugs.exim.org/show_bug.cgi?id=2693

--- Comment #14 from Moritz Friedrich <mf@cyon.ch> ---
Thank you very much for analysing and reproducing the problem in detail.

At the moment, a workaround would be to send each message in a separate
connection, wouldn't it?
Should it be sufficient to set the value for connection_max_messages to 1 in
the transport?

--
You are receiving this mail because:
You are on the CC list for the bug.
--
## List details at https://lists.exim.org/mailman/listinfo/exim-dev Exim details at http://www.exim.org/ ##

https://bugs.exim.org/show_bug.cgi?id=2693

--- Comment #15 from Simon Arlott <bugzilla.exim.simon@arlott.org> ---
Add to the SMTP transport:
hosts_avoid_pipelining = *

--
You are receiving this mail because:
You are on the CC list for the bug.
--
## List details at https://lists.exim.org/mailman/listinfo/exim-dev Exim details at http://www.exim.org/ ##

https://bugs.exim.org/show_bug.cgi?id=2693

Jeremy Harris <jgh146exb@wizmail.org> changed:

What |Removed |Added
----------------------------------------------------------------------------
Priority|medium |high
Status|NEW |ASSIGNED
Assignee|unallocated@exim.org |jgh146exb@wizmail.org

--- Comment #16 from Jeremy Harris <jgh146exb@wizmail.org> ---
It seems that the coding assumed that a 452 "too many recipients" response to
RCPT would persist, once given, for the remainder of the set of RCPTs.

Hardening demands that Exim doesn't get it wrong when that assumption is
violated.

--
You are receiving this mail because:
You are on the CC list for the bug.
--
## List details at https://lists.exim.org/mailman/listinfo/exim-dev Exim details at http://www.exim.org/ ##

https://bugs.exim.org/show_bug.cgi?id=2693

Jeremy Harris <jgh146exb@wizmail.org> changed:

What |Removed |Added
----------------------------------------------------------------------------
Status|ASSIGNED |WAIT_FIX_CONFIRMATION

--- Comment #17 from Jeremy Harris <jgh146exb@wizmail.org> ---
Fix, I hope, in d6870e76cf.

--
You are receiving this mail because:
You are on the CC list for the bug.
--
## List details at https://lists.exim.org/mailman/listinfo/exim-dev Exim details at http://www.exim.org/ ##

https://bugs.exim.org/show_bug.cgi?id=2693

--- Comment #18 from Simon Arlott <bugzilla.exim.simon@arlott.org> ---
Created attachment 1366
--> https://bugs.exim.org/attachment.cgi?id=1366&action=edit
Test case without pipelining

Ideally the behaviour without pipelining should be the same. Currently Exim
will need to retry 3 times over 3 connections. I've attached an updated version
of the test case to check this (and adjust log_selector).

--
You are receiving this mail because:
You are on the CC list for the bug.
--
## List details at https://lists.exim.org/mailman/listinfo/exim-dev Exim details at http://www.exim.org/ ##

https://bugs.exim.org/show_bug.cgi?id=2693

--- Comment #19 from Jeremy Harris <jgh146exb@wizmail.org> ---
Ideally, yes. But a different bug, not this one. Possibly only an RFE; it's
not wrong to take queue-run iterations to deliver to recipients that get a 4xx.

Meantime, I added your non-pipeline testcase, commenting it a "a baseline"
with a bit of explanation on what's going on. 5ce86c4f55.

--
You are receiving this mail because:
You are on the CC list for the bug.
--
## List details at https://lists.exim.org/mailman/listinfo/exim-dev Exim details at http://www.exim.org/ ##

https://bugs.exim.org/show_bug.cgi?id=2693

Git Commit <git@exim.org> changed:

What |Removed |Added
----------------------------------------------------------------------------
CC| |git@exim.org

--- Comment #20 from Git Commit <git@exim.org> ---
Git commit:
https://git.exim.org/exim.git/commitdiff/5ce86c4f552071ad7408c40324d5211ab2a2da82

commit 5ce86c4f552071ad7408c40324d5211ab2a2da82
Author: Simon Arlott <bugzilla.exim.simon@arlott.org>
AuthorDate: Mon Feb 8 19:04:30 2021 +0000
Commit: Jeremy Harris <jgh146exb@wizmail.org>
CommitDate: Mon Feb 8 19:06:22 2021 +0000

testsuite: expand testcase. bug 2693
----
test/confs/0622 | 9 +++------
test/log/0622 | 43 ++++++++++++++++++++++++++++++++++++++++++-
test/rejectlog/0622 | 7 +++++++
test/scripts/0000-Basic/0622 | 25 +++++++++++++++++++++++++
4 files changed, 77 insertions(+), 7 deletions(-)

--
You are receiving this mail because:
You are on the CC list for the bug.
--
## List details at https://lists.exim.org/mailman/listinfo/exim-dev Exim details at http://www.exim.org/ ##