Postfix doesn't respect 250-SIZE value

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
19 messages Options
Reply | Threaded
Open this post in threaded view
|

Postfix doesn't respect 250-SIZE value

florian
Hi,

I'm facing a strange issue that I never saw before.

I have to relay an email with a big size (>20MB). My postfix server is
accepting emails with a size up to 50Mo, so I did received this email.
However, the server to which I need to send the email only accept message
with a size lower than 12MB.

Usually postfix detect this after the EHLO command and just end the
communication before sending a bounce to the sender.

But in my case, postfix is sending the email anyway untill the remote server
send an error "552 Data size exceeded". When it does that, postfix doesn't
see it and we can see TCP retransmit of the last TCP segment untill there is
a timeout.

I end up with this error in my log file:

dsn=4.4.2, status=deferred (conversation with XXXXX [XX.XX.XX.XX] timed out
while sending message body)

Here is the email in postqueue :

8CA2E5EFD9  25397994 Thu Sep 28 16:30:17 XXXXX@XXXXX
(lost connection with XXXXX [XX.XX.XX.XX] while sending message body)
                                         XXXXX

You can see the size of 25397994 bytes (24MB)

Here is the begining of the SMTP exchange :

220 SMTP Welcome
EHLO XXXXXXXXXXXX
250-SIZE 12582912
250-DSN
250-ENHANCEDSTATUSCODES
250-AUTH NTLM
250-8BITMIME
250 OK
MAIL FROM:<XXXXXXX@XXX>
250 2.1.0 Sender OK
RCPT TO:<XXXX@XXXX> ORCPT=rfc822;XXX@XXXX
250 2.1.5 Recipient OK
DATA
354 Start mail input; end with <CRLF>.<CRLF>


You can see the "250-SIZE 12582912" which means the server only accept
emails of less than 12MB.

However, postfix continue to send the email.

And finally, you can see below a screenshot of a wireshark capture where we
see the TCP retransmissions.

<http://postfix.1071664.n5.nabble.com/file/t6668/capture.png>


I am running postfix version 2.11.0 :

# postconf -d | grep mail_version
mail_version = 2.11.0

Thank you




--
Sent from: http://postfix.1071664.n5.nabble.com/Postfix-Users-f2.html
Reply | Threaded
Open this post in threaded view
|

Re: Postfix doesn't respect 250-SIZE value

Matus UHLAR - fantomas
On 05.10.17 05:46, florian wrote:

>I have to relay an email with a big size (>20MB). My postfix server is
>accepting emails with a size up to 50Mo, so I did received this email.
>However, the server to which I need to send the email only accept message
>with a size lower than 12MB.
>
>Usually postfix detect this after the EHLO command and just end the
>communication before sending a bounce to the sender.
>
>But in my case, postfix is sending the email anyway untill the remote server
>send an error "552 Data size exceeded". When it does that, postfix doesn't
>see it and we can see TCP retransmit of the last TCP segment untill there is
>a timeout.
>
>I end up with this error in my log file:
>
>dsn=4.4.2, status=deferred (conversation with XXXXX [XX.XX.XX.XX] timed out
>while sending message body)

maybe a firewall in the path drops remaining data...

>Here is the email in postqueue :
>
>8CA2E5EFD9  25397994 Thu Sep 28 16:30:17 XXXXX@XXXXX
>(lost connection with XXXXX [XX.XX.XX.XX] while sending message body)
>                                         XXXXX
>
>You can see the size of 25397994 bytes (24MB)
>
>Here is the begining of the SMTP exchange :
>
>220 SMTP Welcome
>EHLO XXXXXXXXXXXX
>250-SIZE 12582912
>250-DSN
>250-ENHANCEDSTATUSCODES
>250-AUTH NTLM
>250-8BITMIME
>250 OK
>MAIL FROM:<XXXXXXX@XXX>
>250 2.1.0 Sender OK
>RCPT TO:<XXXX@XXXX> ORCPT=rfc822;XXX@XXXX
>250 2.1.5 Recipient OK
>DATA
>354 Start mail input; end with <CRLF>.<CRLF>

are you sure postfix sees exactly this conversation?
I don't see the SIZE= parameter in MAIL FROM:
--
Matus UHLAR - fantomas, [hidden email] ; http://www.fantomas.sk/
Warning: I wish NOT to receive e-mail advertising to this address.
Varovanie: na tuto adresu chcem NEDOSTAVAT akukolvek reklamnu postu.
Save the whales. Collect the whole set.
Reply | Threaded
Open this post in threaded view
|

Re: Postfix doesn't respect 250-SIZE value

Wietse Venema
In reply to this post by florian
florian:
> Hi,
>
> I'm facing a strange issue that I never saw before.
>
> I have to relay an email with a big size (>20MB). My postfix server is
> accepting emails with a size up to 50Mo, so I did received this email.
> However, the server to which I need to send the email only accept message
> with a size lower than 12MB.

Postfix stores size information in the queue file.  What size does the
queue manager log fot this specific message?

> Usually postfix detect this after the EHLO command and just end the
> communication before sending a bounce to the sender.

Right. This suggests that either the size information in the queue file is
wrong, or that the SIZE announcement was malformed (i.e. buggy SMTP server).
This requires a packet-level dump to see if there are stray carriage-returns
or other unexpected content in thhe EHLO response.

> But in my case, postfix is sending the email anyway untill the remote server
> send an error "552 Data size exceeded". When it does that, postfix doesn't
> see it and we can see TCP retransmit of the last TCP segment untill there is
> a timeout.

The server is buggy. SMTP does not allow servers to respond until
the client sends end-of-data.

        Wietse
Reply | Threaded
Open this post in threaded view
|

Re: Postfix doesn't respect 250-SIZE value

Viktor Dukhovni
In reply to this post by florian

> On Oct 5, 2017, at 8:46 AM, florian <[hidden email]> wrote:
>
> 220 SMTP Welcome
> EHLO XXXXXXXXXXXX
> 250-SIZE 12582912
> 250-DSN
> 250-ENHANCEDSTATUSCODES
> 250-AUTH NTLM
> 250-8BITMIME
> 250 OK
> MAIL FROM:<XXXXXXX@XXX>
> 250 2.1.0 Sender OK
> RCPT TO:<XXXX@XXXX> ORCPT=rfc822;XXX@XXXX
> 250 2.1.5 Recipient OK
> DATA
> 354 Start mail input; end with <CRLF>.<CRLF>

Postfix sends "SIZE=" in "MAIL FROM" unless it is going to do 8bit to 7bit
downgrade:

        case SMTP_STATE_MAIL:
            request->msg_stats.reuse_count = session->reuse_count;
            GETTIMEOFDAY(&request->msg_stats.conn_setup_done);
            REWRITE_ADDRESS(session->scratch2, request->sender);
            QUOTE_ADDRESS(session->scratch, vstring_str(session->scratch2));
            vstring_sprintf(next_command, "MAIL FROM:<%s>",
                            vstring_str(session->scratch));
            /* XXX Don't announce SIZE if we're going to MIME downgrade. */
            if (session->features & SMTP_FEATURE_SIZE   /* RFC 1870 */
                && !SMTP_MIME_DOWNGRADE(session, request))
                vstring_sprintf_append(next_command, " SIZE=%lu",
                                       request->data_size);
            if (session->features & SMTP_FEATURE_8BITMIME) {    /* RFC 1652 */
                if (strcmp(request->encoding, MAIL_ATTR_ENC_8BIT) == 0)
                    vstring_strcat(next_command, " BODY=8BITMIME");
                else if (strcmp(request->encoding, MAIL_ATTR_ENC_7BIT) == 0)
                    vstring_strcat(next_command, " BODY=7BIT");
                else if (strcmp(request->encoding, MAIL_ATTR_ENC_NONE) != 0)
                    msg_warn("%s: unknown content encoding: %s",
                             request->queue_id, request->encoding);
            }

So it would appear (if your reported transcript is accurate) that
Postfix did not believe the peer to be 8BITMIME-capable.  Since
the SMTP server's EHLO reply does in fact include 8BITMIME, I can
only conclude that you have some sort of filter in place on the
EHLO keywords or server reply.

Post configuration details.  http://www.postfix.org/DEBUG_README.html

Try to avoid links to pictures.  Use "tshark" instead of "wireshark",
and post text.

--
        Viktor.

Reply | Threaded
Open this post in threaded view
|

Re: Postfix doesn't respect 250-SIZE value

florian
In reply to this post by Matus UHLAR - fantomas

>    are you sure postfix sees exactly this conversation?
>    I don't see the SIZE= parameter in MAIL FROM:

Correct me if I’m wrong, but I think this is because I use version 2.11 of postfix and this feature has been introduced in version 3.0.


Reply | Threaded
Open this post in threaded view
|

Re: Postfix doesn't respect 250-SIZE value

florian
In reply to this post by Wietse Venema
>    Postfix stores size information in the queue file.  What size does the
>    queue manager log fot this specific message?

Here are the information in queue file, as shown by a “postcat –q” on the message queue ID :

*** ENVELOPE RECORDS deferred/3/2/A/32A559F491 ***
message_size:        13870598             816               1               0        13870598
message_arrival_time: Fri Oct  6 10:12:35 2017
create_time: Fri Oct  6 10:12:35 2017

(note this is a deferent message than from my last email, but the problem is the same).


>    Right. This suggests that either the size information in the queue file is
>    wrong, or that the SIZE announcement was malformed (i.e. buggy SMTP server).
>    This requires a packet-level dump to see if there are stray carriage-returns
>    or other unexpected content in thhe EHLO response.

I have done such network capture. Here is the hex-dump of the server response after EHLO command (as displayed by tshark):

0000  00 50 56 9b 64 b4 00 50 56 9b 30 58 08 00 45 00   .PV.d..PV.0X..E.
0010  00 8e 1e da 40 00 37 06 fb ca d5 29 8e 67 ac 11   ....@.7....).g..
0020  19 23 00 19 fc 26 f3 55 0e 57 8b 00 b0 b3 80 18   .#...&.U.W......
0030  04 02 25 56 00 00 01 01 08 0a 8b eb 30 0d 51 41   ..%V........0.QA
0040  c6 84 32 35 30 2d 53 49 5a 45 20 31 32 35 38 32   ..250-SIZE 12582
0050  39 31 32 0d 0a 32 35 30 2d 44 53 4e 0d 0a 32 35   912..250-DSN..25
0060  30 2d 45 4e 48 41 4e 43 45 44 53 54 41 54 55 53   0-ENHANCEDSTATUS
0070  43 4f 44 45 53 0d 0a 32 35 30 2d 41 55 54 48 20   CODES..250-AUTH
0080  4e 54 4c 4d 0d 0a 32 35 30 2d 38 42 49 54 4d 49   NTLM..250-8BITMI
0090  4d 45 0d 0a 32 35 30 20 4f 4b 0d 0a               ME..250 OK..


>    The server is buggy. SMTP does not allow servers to respond until
>    the client sends end-of-data.
   
That’s what I thought too. I don’t know what they are using, but it’s not postfix for sure ;-)


Reply | Threaded
Open this post in threaded view
|

Re: Postfix doesn't respect 250-SIZE value

florian
In reply to this post by Viktor Dukhovni

>    Postfix sends "SIZE=" in "MAIL FROM" unless it is going to do 8bit to 7bit
>    downgrade:
>    (source code removed)
   
>    So it would appear (if your reported transcript is accurate) that
>    Postfix did not believe the peer to be 8BITMIME-capable.  Since
>    the SMTP server's EHLO reply does in fact include 8BITMIME, I can
>    only conclude that you have some sort of filter in place on the
>    EHLO keywords or server reply.
   
As said to Matus Uhlar, I think this is because I’m using postfix 2.11 and the 8BITMIME support has been introduced in version 3.0.
Too bad… I’ll see if I can upgrade.


Reply | Threaded
Open this post in threaded view
|

Re: Postfix doesn't respect 250-SIZE value

Viktor Dukhovni

> On Oct 6, 2017, at 5:03 AM, Florian Coulmier <[hidden email]> wrote:
>
>>   Postfix sends "SIZE=" in "MAIL FROM" unless it is going to do 8bit to 7bit
>>   downgrade:
>>   (source code removed)
>
>>   So it would appear (if your reported transcript is accurate) that
>>   Postfix did not believe the peer to be 8BITMIME-capable.  Since
>>   the SMTP server's EHLO reply does in fact include 8BITMIME, I can
>>   only conclude that you have some sort of filter in place on the
>>   EHLO keywords or server reply.
>
> As said to Matus Uhlar, I think this is because I’m using postfix 2.11 and the 8BITMIME support has been introduced in version 3.0.

You really should not make up facts out of thin air, however popular that
might be these days.  Support for sending "SIZE=" in Postfix is at least
19 years old, with the MIME downgrade suppressing dating back 11 years.

https://github.com/vdukhovni/postfix/blame/master/postfix/src/smtp/smtp_proto.c#L1466

> Too bad… I’ll see if I can upgrade.

Waste of time, why don't you post your config as requested.  Also, make sure
that any network captures you are looking at or post are taken directly
from your Postfix machine, and not on the other side of some too-clever
firewall.

--
        Viktor.
Reply | Threaded
Open this post in threaded view
|

Re: Postfix doesn't respect 250-SIZE value

florian
    > You really should not make up facts out of thin air, however popular that
    > might be these days.  Support for sending "SIZE=" in Postfix is at least
    > 19 years old, with the MIME downgrade suppressing dating back 11 years.
   
    > https://github.com/vdukhovni/postfix/blame/master/postfix/src/smtp/smtp_proto.c#L1466

Ok, my bad. I mixed up with UTF8 support. So, 8BITMIME should be supported with my postfix version.
   
    >> Too bad… I’ll see if I can upgrade.
   
    > Waste of time, why don't you post your config as requested.  Also, make sure
    > that any network captures you are looking at or post are taken directly
    > from your Postfix machine, and not on the other side of some too-clever
    > firewall.

I’ve performed my network capture on the server running postfix itself.
Here is my configuration: https://pastebin.com/EKHvEveC

Regards


Reply | Threaded
Open this post in threaded view
|

Re: Postfix doesn't respect 250-SIZE value

Ralf Hildebrandt-2
> Here is my configuration: https://pastebin.com/EKHvEveC

postconf -n
would be more appropriate, I think

--
[*] sys4 AG

https://sys4.de, +49 (89) 30 90 46 64
Schleißheimer Straße 26/MG, 80333 München
                                           
Sitz der Gesellschaft: München, Amtsgericht München: HRB 199263
Vorstand: Patrick Ben Koetter, Marc Schiffbauer
Aufsichtsratsvorsitzender: Florian Kirstein
Reply | Threaded
Open this post in threaded view
|

Re: Postfix doesn't respect 250-SIZE value

Wietse Venema
In reply to this post by florian
Florian Coulmier:

> >    Postfix stores size information in the queue file.  What size does the
> >    queue manager log fot this specific message?
>
> Here are the information in queue file, as shown by a ?postcat ?q? on the message queue ID :
>
> *** ENVELOPE RECORDS deferred/3/2/A/32A559F491 ***
> message_size:        13870598             816               1               0        13870598
> message_arrival_time: Fri Oct  6 10:12:35 2017
> create_time: Fri Oct  6 10:12:35 2017
>
> (note this is a deferent message than from my last email, but the problem is the same).
>
>
> >    Right. This suggests that either the size information in the queue file is
> >    wrong, or that the SIZE announcement was malformed (i.e. buggy SMTP server).
> >    This requires a packet-level dump to see if there are stray carriage-returns
> >    or other unexpected content in thhe EHLO response.
>
> I have done such network capture. Here is the hex-dump of the server response after EHLO command (as displayed by tshark):
>
> 0000  00 50 56 9b 64 b4 00 50 56 9b 30 58 08 00 45 00   .PV.d..PV.0X..E.
> 0010  00 8e 1e da 40 00 37 06 fb ca d5 29 8e 67 ac 11   ....@.7....).g..
> 0020  19 23 00 19 fc 26 f3 55 0e 57 8b 00 b0 b3 80 18   .#...&.U.W......
> 0030  04 02 25 56 00 00 01 01 08 0a 8b eb 30 0d 51 41   ..%V........0.QA
> 0040  c6 84 32 35 30 2d 53 49 5a 45 20 31 32 35 38 32   ..250-SIZE 12582
> 0050  39 31 32 0d 0a 32 35 30 2d 44 53 4e 0d 0a 32 35   912..250-DSN..25
> 0060  30 2d 45 4e 48 41 4e 43 45 44 53 54 41 54 55 53   0-ENHANCEDSTATUS
> 0070  43 4f 44 45 53 0d 0a 32 35 30 2d 41 55 54 48 20   CODES..250-AUTH
> 0080  4e 54 4c 4d 0d 0a 32 35 30 2d 38 42 49 54 4d 49   NTLM..250-8BITMI
> 0090  4d 45 0d 0a 32 35 30 20 4f 4b 0d 0a               ME..250 OK..

That looks wrong. Where is the first EHLO response line? The above
starts in the middle of the response.

Can you share a packed dump OFF-LIST so I can see what happens between
SENDING ehlo and receiving the reply? The entire TCP connection would
be best.

        Wietse
Reply | Threaded
Open this post in threaded view
|

Re: Postfix doesn't respect 250-SIZE value

florian
In reply to this post by Ralf Hildebrandt-2
    >> Here is my configuration: https://pastebin.com/EKHvEveC
   
    > postconf -n
    > would be more appropriate, I think
   
 Here it is : https://pastebin.com/efFJb2Sq



Reply | Threaded
Open this post in threaded view
|

Re: Postfix doesn't respect 250-SIZE value

florian
In reply to this post by Wietse Venema
    > That looks wrong. Where is the first EHLO response line? The above
    > starts in the middle of the response.
    >
    > Can you share a packed dump OFF-LIST so I can see what happens between
    > SENDING ehlo and receiving the reply? The entire TCP connection would
    > be best.
   
Yes, I extracted only the interesting part. The full dump is here (server with IP X.X.X.X is mine. Server with IP Y.Y.Y.Y is remote MX):

1   0.000000 X.X.X.X -> Y.Y.Y.Y TCP 74 64550 → 25 [SYN] Seq=0 Win=29200 Len=0 MSS=1460 SACK_PERM=1 TSval=1363265141 TSecr=0 WS=128

0000  00 50 56 9b 30 58 00 50 56 9b 64 b4 08 00 45 00   .PV.0X.PV.d...E.
0010  00 3c 76 fb 40 00 40 06 9a fb ac 11 19 23 d5 29   .<v.@.@......#.)
0020  8e 67 fc 26 00 19 8b 00 b0 8e 00 00 00 00 a0 02   .g.&............
0030  72 10 28 f4 00 00 02 04 05 b4 04 02 08 0a 51 41   r.(...........QA
0040  c6 75 00 00 00 00 01 03 03 07                     .u........

  2   0.030649 Y.Y.Y.Y -> X.X.X.X TCP 74 25 → 64550 [SYN, ACK] Seq=0 Ack=1 Win=65535 Len=0 MSS=1300 WS=64 SACK_PERM=1 TSval=2347446220 TSecr=1363265141

0000  00 50 56 9b 64 b4 00 50 56 9b 30 58 08 00 45 00   .PV.d..PV.0X..E.
0010  00 3c 1e d3 40 00 37 06 fc 23 d5 29 8e 67 ac 11   .<..@.7..#.).g..
0020  19 23 00 19 fc 26 f3 55 0e 44 8b 00 b0 8f a0 12   .#...&.U.D......
0030  ff ff 12 f3 00 00 02 04 05 14 01 03 03 06 04 02   ................
0040  08 0a 8b eb 2f cc 51 41 c6 75                     ..../.QA.u

  3   0.030695 X.X.X.X -> Y.Y.Y.Y TCP 66 64550 → 25 [ACK] Seq=1 Ack=1 Win=29312 Len=0 TSval=1363265148 TSecr=2347446220

0000  00 50 56 9b 30 58 00 50 56 9b 64 b4 08 00 45 00   .PV.0X.PV.d...E.
0010  00 34 76 fc 40 00 40 06 9b 02 ac 11 19 23 d5 29   .4v.@.@......#.)
0020  8e 67 fc 26 00 19 8b 00 b0 8f f3 55 0e 45 80 10   .g.&.......U.E..
0030  00 e5 28 ec 00 00 01 01 08 0a 51 41 c6 7c 8b eb   ..(.......QA.|..
0040  2f cc                                             /.

  4   0.063290 Y.Y.Y.Y -> X.X.X.X SMTP 84 S: 220 SMTP Welcome

0000  00 50 56 9b 64 b4 00 50 56 9b 30 58 08 00 45 00   .PV.d..PV.0X..E.
0010  00 46 1e d7 40 00 37 06 fc 15 d5 29 8e 67 ac 11   .F..@.7....).g..
0020  19 23 00 19 fc 26 f3 55 0e 45 8b 00 b0 8f 80 18   .#...&.U.E......
0030  04 02 cf 47 00 00 01 01 08 0a 8b eb 2f ed 51 41   ...G......../.QA
0040  c6 7c 32 32 30 20 53 4d 54 50 20 57 65 6c 63 6f   .|220 SMTP Welco
0050  6d 65 0d 0a                                       me..

  5   0.063310 X.X.X.X -> Y.Y.Y.Y TCP 66 64550 → 25 [ACK] Seq=1 Ack=19 Win=29312 Len=0 TSval=1363265156 TSecr=2347446253

0000  00 50 56 9b 30 58 00 50 56 9b 64 b4 08 00 45 00   .PV.0X.PV.d...E.
0010  00 34 76 fd 40 00 40 06 9b 01 ac 11 19 23 d5 29   .4v.@.@......#.)
0020  8e 67 fc 26 00 19 8b 00 b0 8f f3 55 0e 57 80 10   .g.&.......U.W..
0030  00 e5 28 ec 00 00 01 01 08 0a 51 41 c6 84 8b eb   ..(.......QA....
0040  2f ed                                             /.

  6   0.063357 X.X.X.X -> Y.Y.Y.Y SMTP 102 C: EHLO mx02-out.cloud.vadesecure.com

0000  00 50 56 9b 30 58 00 50 56 9b 64 b4 08 00 45 00   .PV.0X.PV.d...E.
0010  00 58 76 fe 40 00 40 06 9a dc ac 11 19 23 d5 29   .Xv.@.@......#.)
0020  8e 67 fc 26 00 19 8b 00 b0 8f f3 55 0e 57 80 18   .g.&.......U.W..
0030  00 e5 29 10 00 00 01 01 08 0a 51 41 c6 84 8b eb   ..).......QA....
0040  2f ed XX XX XX XX 20 XX XX XX XX 2d XX XX XX 2e   /.EHLO xxxx-xxx.
0050  XX XX XX XX XX 2e XX XX XX XX XX XX XX XX XX XX   xxxxx.xxxxxxxxxx
0060  2e 63 6f 6d 0d 0a                                 .com..

  7   0.096519 Y.Y.Y.Y -> X.X.X.X SMTP 156 S: 250 SIZE 12582912 | 250 DSN | 250 ENHANCEDSTATUSCODES | 250 AUTH NTLM | 250 8BITMIME | 250 OK

0000  00 50 56 9b 64 b4 00 50 56 9b 30 58 08 00 45 00   .PV.d..PV.0X..E.
0010  00 8e 1e da 40 00 37 06 fb ca d5 29 8e 67 ac 11   ....@.7....).g..
0020  19 23 00 19 fc 26 f3 55 0e 57 8b 00 b0 b3 80 18   .#...&.U.W......
0030  04 02 25 56 00 00 01 01 08 0a 8b eb 30 0d 51 41   ..%V........0.QA
0040  c6 84 32 35 30 2d 53 49 5a 45 20 31 32 35 38 32   ..250-SIZE 12582
0050  39 31 32 0d 0a 32 35 30 2d 44 53 4e 0d 0a 32 35   912..250-DSN..25
0060  30 2d 45 4e 48 41 4e 43 45 44 53 54 41 54 55 53   0-ENHANCEDSTATUS
0070  43 4f 44 45 53 0d 0a 32 35 30 2d 41 55 54 48 20   CODES..250-AUTH
0080  4e 54 4c 4d 0d 0a 32 35 30 2d 38 42 49 54 4d 49   NTLM..250-8BITMI
0090  4d 45 0d 0a 32 35 30 20 4f 4b 0d 0a               ME..250 OK..

  8   0.096737 X.X.X.X -> Y.Y.Y.Y SMTP 103 C: MAIL FROM:<[hidden email]>

0000  00 50 56 9b 30 58 00 50 56 9b 64 b4 08 00 45 00   .PV.0X.PV.d...E.
0010  00 59 76 ff 40 00 40 06 9a da ac 11 19 23 d5 29   .Yv.@.@......#.)
0020  8e 67 fc 26 00 19 8b 00 b0 b3 f3 55 0e b1 80 18   .g.&.......U....
0030  00 e5 29 11 00 00 01 01 08 0a 51 41 c6 8d 8b eb   ..).......QA....
0040  30 0d 4d 41 49 4c 20 46 52 4f 4d 3a 3c XX XX XX   0.MAIL FROM:<xxx
0050  XX XX XX XX XX 2e XX XX XX XX 40 XX XX XX XX XX   xxxxx.xxxx@xxxxx
0060  2e 63 6f 6d 3e 0d 0a                              .com>..

  9   0.128714 Y.Y.Y.Y -> X.X.X.X SMTP 87 S: 250 2.1.0 Sender OK

0000  00 50 56 9b 64 b4 00 50 56 9b 30 58 08 00 45 00   .PV.d..PV.0X..E.
0010  00 49 1e df 40 00 37 06 fc 0a d5 29 8e 67 ac 11   .I..@.7....).g..
0020  19 23 00 19 fc 26 f3 55 0e b1 8b 00 b0 d8 80 18   .#...&.U........
0030  04 02 a9 65 00 00 01 01 08 0a 8b eb 30 2e 51 41   ...e........0.QA
0040  c6 8d 32 35 30 20 32 2e 31 2e 30 20 53 65 6e 64   ..250 2.1.0 Send
0050  65 72 20 4f 4b 0d 0a                              er OK..

 10   0.128822 X.X.X.X -> Y.Y.Y.Y SMTP 140 C: RCPT TO:<[hidden email]> ORCPT=rfc822;[hidden email]

0000  00 50 56 9b 30 58 00 50 56 9b 64 b4 08 00 45 00   .PV.0X.PV.d...E.
0010  00 7e 77 00 40 00 40 06 9a b4 ac 11 19 23 d5 29   .~w.@.@......#.)
0020  8e 67 fc 26 00 19 8b 00 b0 d8 f3 55 0e c6 80 18   .g.&.......U....
0030  00 e5 29 36 00 00 01 01 08 0a 51 41 c6 95 8b eb   ..)6......QA....
0040  30 2e 52 43 50 54 20 54 4f 3a 3c XX 2e XX XX XX   0.RCPT TO:<x.xxx
0050  XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX XX   xx@xxxxxxxxxxxxx
0060  2e 66 72 3e 20 4f 52 43 50 54 3d 72 66 63 38 32   .fr> ORCPT=rfc82
0070  32 3b XX XX XX XX XX XX XX 40 XX XX XX XX XX XX   2;xxxxxx@xxxxxxx
0080  XX XX XX XX XX XX XX 2e 66 72 0d 0a               xxxxxxx.fr..

 11   0.164675 Y.Y.Y.Y -> X.X.X.X SMTP 90 S: 250 2.1.5 Recipient OK

0000  00 50 56 9b 64 b4 00 50 56 9b 30 58 08 00 45 00   .PV.d..PV.0X..E.
0010  00 4c 1e e2 40 00 37 06 fc 04 d5 29 8e 67 ac 11   .L..@.7....).g..
0020  19 23 00 19 fc 26 f3 55 0e c6 8b 00 b1 22 80 18   .#...&.U....."..
0030  04 02 e4 53 00 00 01 01 08 0a 8b eb 30 52 51 41   ...S........0RQA
0040  c6 95 32 35 30 20 32 2e 31 2e 35 20 52 65 63 69   ..250 2.1.5 Reci
0050  70 69 65 6e 74 20 4f 4b 0d 0a                     pient OK..

 12   0.164764 X.X.X.X -> Y.Y.Y.Y SMTP 72 C: DATA

0000  00 50 56 9b 30 58 00 50 56 9b 64 b4 08 00 45 00   .PV.0X.PV.d...E.
0010  00 3a 77 01 40 00 40 06 9a f7 ac 11 19 23 d5 29   .:w.@.@......#.)
0020  8e 67 fc 26 00 19 8b 00 b1 22 f3 55 0e de 80 18   .g.&.....".U....
0030  00 e5 28 f2 00 00 01 01 08 0a 51 41 c6 9e 8b eb   ..(.......QA....
0040  30 52 44 41 54 41 0d 0a                           0RDATA..

 13   0.197068 Y.Y.Y.Y -> X.X.X.X SMTP 112 S: 354 Start mail input; end with <CRLF>.<CRLF>

0000  00 50 56 9b 64 b4 00 50 56 9b 30 58 08 00 45 00   .PV.d..PV.0X..E.
0010  00 62 1e ee 40 00 37 06 fb e2 d5 29 8e 67 ac 11   .b..@.7....).g..
0020  19 23 00 19 fc 26 f3 55 0e de 8b 00 b1 28 80 18   .#...&.U.....(..
0030  04 02 0f 11 00 00 01 01 08 0a 8b eb 30 72 51 41   ............0rQA
0040  c6 9e 33 35 34 20 53 74 61 72 74 20 6d 61 69 6c   ..354 Start mail
0050  20 69 6e 70 75 74 3b 20 65 6e 64 20 77 69 74 68    input; end with
0060  20 3c 43 52 4c 46 3e 2e 3c 43 52 4c 46 3e 0d 0a    <CRLF>.<CRLF>..


(more than 10k paquets of data…)

10640  15.358175 X.X.X.X -> Y.Y.Y.Y SMTP 2642 C: DATA fragment, 2576 bytes
10641  15.362672 Y.Y.Y.Y -> X.X.X.X TCP 66 25 → 64550 [ACK] Seq=200 Ack=12584250 Win=95872 Len=0 TSval=2347461552 TSecr=1363268963
10642  15.362688 X.X.X.X -> Y.Y.Y.Y SMTP 2642 C: DATA fragment, 2576 bytes
10643  15.363923 Y.Y.Y.Y -> X.X.X.X SMTP 90 S: 552 Data size exceeded
10644  15.363938 X.X.X.X -> Y.Y.Y.Y SMTP 1354 C: DATA fragment, 1288 bytes
10645  15.519580 X.X.X.X -> Y.Y.Y.Y SMTP 1354 C: DATA fragment, 1288 bytes
10646  15.799532 X.X.X.X -> Y.Y.Y.Y TCP 1354 [TCP Retransmission] 64550 → 25 [ACK] Seq=12584250 Ack=224 Win=29312 Len=1288 TSval=1363269091 TSecr=2347461552
10647  16.351553 X.X.X.X -> Y.Y.Y.Y TCP 1354 [TCP Retransmission] 64550 → 25 [ACK] Seq=12584250 Ack=224 Win=29312 Len=1288 TSval=1363269229 TSecr=2347461552
10648  17.459539 X.X.X.X -> Y.Y.Y.Y TCP 1354 [TCP Retransmission] 64550 → 25 [ACK] Seq=12584250 Ack=224 Win=29312 Len=1288 TSval=1363269506 TSecr=2347461552
10649  19.679610 X.X.X.X -> Y.Y.Y.Y TCP 1354 [TCP Retransmission] 64550 → 25 [ACK] Seq=12584250 Ack=224 Win=29312 Len=1288 TSval=1363270061 TSecr=2347461552
10650  24.107530 X.X.X.X -> Y.Y.Y.Y TCP 1354 [TCP Retransmission] 64550 → 25 [ACK] Seq=12584250 Ack=224 Win=29312 Len=1288 TSval=1363271168 TSecr=2347461552
10651  32.971650 X.X.X.X -> Y.Y.Y.Y TCP 1354 [TCP Retransmission] 64550 → 25 [ACK] Seq=12584250 Ack=224 Win=29312 Len=1288 TSval=1363273384 TSecr=2347461552
10652  50.667578 X.X.X.X -> Y.Y.Y.Y TCP 1354 [TCP Retransmission] 64550 → 25 [ACK] Seq=12584250 Ack=224 Win=29312 Len=1288 TSval=1363277808 TSecr=2347461552
10653  86.059559 X.X.X.X -> Y.Y.Y.Y TCP 1354 [TCP Retransmission] 64550 → 25 [ACK] Seq=12584250 Ack=224 Win=29312 Len=1288 TSval=1363286656 TSecr=2347461552
10654 156.971556 X.X.X.X -> Y.Y.Y.Y TCP 1354 [TCP Retransmission] 64550 → 25 [ACK] Seq=12584250 Ack=224 Win=29312 Len=1288 TSval=1363304384 TSecr=2347461552
10655 195.472753 X.X.X.X -> Y.Y.Y.Y 64550 → 25 [RST, ACK] Seq=12656378 Ack=224 Win=29312 Len=0 TSval=1363314009 TSecr=2347461552


Reply | Threaded
Open this post in threaded view
|

Re: Postfix doesn't respect 250-SIZE value

Viktor Dukhovni
On Fri, Oct 06, 2017 at 04:22:38PM +0200, Florian Coulmier wrote:

>     > That looks wrong. Where is the first EHLO response line? The above
>     > starts in the middle of the response.

There's the smoking gun.  Wietse correctly observes the crucial
detail that the first line of the EHLO response (after which follow
the ESMTP options), which ought to lookup like:

        250-<server-hostname> <decorative vanity text>

is missing.

>   7   0.096519 Y.Y.Y.Y -> X.X.X.X SMTP 156 S: 250 SIZE 12582912 | 250 DSN | 250 ENHANCEDSTATUSCODES | 250 AUTH NTLM | 250 8BITMIME | 250 OK
>
> 0000  00 50 56 9b 64 b4 00 50 56 9b 30 58 08 00 45 00   .PV.d..PV.0X..E.
> 0010  00 8e 1e da 40 00 37 06 fb ca d5 29 8e 67 ac 11   ....@.7....).g..
> 0020  19 23 00 19 fc 26 f3 55 0e 57 8b 00 b0 b3 80 18   .#...&.U.W......

The hex dump reveals the actual IPs: 213.41.142.103 -> 172.17.25.35

    $ getent hosts 213.41.142.103
    213.41.142.103    mail.provenceplats.fr

Which suggests that your end (on an RFC1918 IP address of 172.17.25.35)
is behind a NAT firewall, which could part of the problem.  The
SMTP server however does not seem to be reachable from Internet at
large, so the networking topology here is unclear.

> 0030  04 02 25 56 00 00 01 01 08 0a 8b eb 30 0d 51 41   ..%V........0.QA
> 0040  c6 84 32 35 30 2d 53 49 5a 45 20 31 32 35 38 32   ..250-SIZE 12582
> 0050  39 31 32 0d 0a 32 35 30 2d 44 53 4e 0d 0a 32 35   912..250-DSN..25
> 0060  30 2d 45 4e 48 41 4e 43 45 44 53 54 41 54 55 53   0-ENHANCEDSTATUS
> 0070  43 4f 44 45 53 0d 0a 32 35 30 2d 41 55 54 48 20   CODES..250-AUTH
> 0080  4e 54 4c 4d 0d 0a 32 35 30 2d 38 42 49 54 4d 49   NTLM..250-8BITMI
> 0090  4d 45 0d 0a 32 35 30 20 4f 4b 0d 0a               ME..250 OK..

There we have it, the EHLO response omits the first vanity line,
and so SIZE becomes the vanity line, and is ignored.

>   8   0.096737 X.X.X.X -> Y.Y.Y.Y SMTP 103 C: MAIL FROM:<[hidden email]>

This is a correct response when the server does not announce
"SIZE", which is the case here.

> 10642  15.362688 X.X.X.X -> Y.Y.Y.Y SMTP 2642 C: DATA fragment, 2576 bytes
> 10643  15.363923 Y.Y.Y.Y -> X.X.X.X SMTP 90 S: 552 Data size exceeded

This response must follow ".", and the server must not switch back
to command-mode until that happens.  Just hanging up can cause
problems.  Mind you, when the connection is lost mid-transfer,
Postfix will attempt to read any pending premature response
from the server (since Postfix 2.4, 11 years ago):

    https://github.com/vdukhovni/postfix/blame/master/postfix/src/smtp/smtp_proto.c#L2176

                if (!LOST_CONNECTION_INSIDE_DATA)
                    RETURN(smtp_stream_except(state, except,
                                              "sending message body"));

                /*
                 * We will clear the stream error flag to try and read a
                 * premature 5XX response, so it is important to flush any
                 * unwritten data. Otherwise, we will try to flush it again
                 * before reading, which may incur an unnecessary delay and
                 * will prevent the reading of any response that is not
                 * already buffered (bundled with the DATA 354 response).
                 *
                 * Not much point in sending QUIT at this point, skip right to
                 * SMTP_STATE_LAST. The read engine above will likewise avoid
                 * looking for a QUIT response.
                 */
                (void) vstream_fpurge(session->stream, VSTREAM_PURGE_WRITE);
                next_state = SMTP_STATE_LAST;

perhaps your kernel fails deliver that final packe to the Postfix
smtp(8) client due do the preceding connection reset on write, in
which case there's not much Postfix can do.  We don't currently
peek inbound data from the server while writing the message data,
the SMTP protocol is half-duplex...

--
        Viktor.
Reply | Threaded
Open this post in threaded view
|

Re: Postfix doesn't respect 250-SIZE value

Wietse Venema
Viktor Dukhovni:

> On Fri, Oct 06, 2017 at 04:22:38PM +0200, Florian Coulmier wrote:
>
> >     > That looks wrong. Where is the first EHLO response line? The above
> >     > starts in the middle of the response.
>
> There's the smoking gun.  Wietse correctly observes the crucial
> detail that the first line of the EHLO response (after which follow
> the ESMTP options), which ought to lookup like:
>
> 250-<server-hostname> <decorative vanity text>
>
> is missing.

I already mentioned that the server (which may be a proxy) is buggy
as hell. This is just one more symptom.

        Wietse
Reply | Threaded
Open this post in threaded view
|

Re: Postfix doesn't respect 250-SIZE value

Matus UHLAR - fantomas
In reply to this post by florian
>>    Right. This suggests that either the size information in the queue file is
>>    wrong, or that the SIZE announcement was malformed (i.e. buggy SMTP server).
>>    This requires a packet-level dump to see if there are stray carriage-returns
>>    or other unexpected content in thhe EHLO response.

On 06.10.17 10:56, Florian Coulmier wrote:

>I have done such network capture. Here is the hex-dump of the server response after EHLO command (as displayed by tshark):
>
>0000  00 50 56 9b 64 b4 00 50 56 9b 30 58 08 00 45 00   .PV.d..PV.0X..E.
>0010  00 8e 1e da 40 00 37 06 fb ca d5 29 8e 67 ac 11   ....@.7....).g..
>0020  19 23 00 19 fc 26 f3 55 0e 57 8b 00 b0 b3 80 18   .#...&.U.W......
>0030  04 02 25 56 00 00 01 01 08 0a 8b eb 30 0d 51 41   ..%V........0.QA
>0040  c6 84 32 35 30 2d 53 49 5a 45 20 31 32 35 38 32   ..250-SIZE 12582
>0050  39 31 32 0d 0a 32 35 30 2d 44 53 4e 0d 0a 32 35   912..250-DSN..25
>0060  30 2d 45 4e 48 41 4e 43 45 44 53 54 41 54 55 53   0-ENHANCEDSTATUS
>0070  43 4f 44 45 53 0d 0a 32 35 30 2d 41 55 54 48 20   CODES..250-AUTH
>0080  4e 54 4c 4d 0d 0a 32 35 30 2d 38 42 49 54 4d 49   NTLM..250-8BITMI
>0090  4d 45 0d 0a 32 35 30 20 4f 4b 0d 0a               ME..250 OK..

just a note: packet capture made by tcpdump can be read with tshark or even
graphics wireshark, that can very nicely display whole SMTP conversation -
use the "Follow TCP conversation" option.

--
Matus UHLAR - fantomas, [hidden email] ; http://www.fantomas.sk/
Warning: I wish NOT to receive e-mail advertising to this address.
Varovanie: na tuto adresu chcem NEDOSTAVAT akukolvek reklamnu postu.
On the other hand, you have different fingers.
Reply | Threaded
Open this post in threaded view
|

Re: Postfix doesn't respect 250-SIZE value

florian
In reply to this post by Viktor Dukhovni
> Which suggests that your end (on an RFC1918 IP address of 172.17.25.35)
> is behind a NAT firewall, which could part of the problem.  The
> SMTP server however does not seem to be reachable from Internet at
> large, so the networking topology here is unclear.

Indeed, only our servers are able to reach this MX. This is the normal behavior.

> There we have it, the EHLO response omits the first vanity line,
> and so SIZE becomes the vanity line, and is ignored.

This is it! Thanks for the information, I was not aware of this RFC subtlety. We’ll reach out to the owner of the MX to see if he can change this behavior.
   
> This response must follow ".", and the server must not switch back
> to command-mode until that happens.  Just hanging up can cause
> problems.  Mind you, when the connection is lost mid-transfer,
> Postfix will attempt to read any pending premature response
> from the server (since Postfix 2.4, 11 years ago):

Another RFC breach that we will notify to the postmaster.


Many thanks for the time you all spent on this issue. Your help was precious on this one.

Florian
   


Reply | Threaded
Open this post in threaded view
|

Re: Postfix doesn't respect 250-SIZE value

Matus UHLAR - fantomas
>> Which suggests that your end (on an RFC1918 IP address of 172.17.25.35)
>> is behind a NAT firewall, which could part of the problem.  The
>> SMTP server however does not seem to be reachable from Internet at
>> large, so the networking topology here is unclear.

On 09.10.17 12:35, Florian Coulmier wrote:
>Indeed, only our servers are able to reach this MX. This is the normal behavior.

then it shouldn't be an MX... maybe you mean in-path mail server?


--
Matus UHLAR - fantomas, [hidden email] ; http://www.fantomas.sk/
Warning: I wish NOT to receive e-mail advertising to this address.
Varovanie: na tuto adresu chcem NEDOSTAVAT akukolvek reklamnu postu.
I just got lost in thought. It was unfamiliar territory.
Reply | Threaded
Open this post in threaded view
|

Re: Postfix doesn't respect 250-SIZE value

Viktor Dukhovni

> On Oct 9, 2017, at 12:53 PM, Matus UHLAR - fantomas <[hidden email]> wrote:
>
>> Indeed, only our servers are able to reach this MX. This is the normal behavior.
>
> then it shouldn't be an MX... maybe you mean in-path mail server?

There's no such rule, and the OP probably does not need such advice.
Let's stay on topic (likely closed for now, as the OP pursues the
issues that cause a malformed EHLO response).

--
        Viktor.