Mail delivery times: SASL vs permit_mynetwork

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

Mail delivery times: SASL vs permit_mynetwork

Stephan Seitz-3
Hello!

I try to understand different mail delivery times.

I have a script (phpmailer) that sends 500 mails to a remote mail server.  
The target address is a local /dev/null mailbox. The script uses
SMTPKeepAlive = true; to keep the connection open.

If my client IP is part of mynetworks the time for 500 mails is about 29
seconds.

If I use AUTH (SASL via Dovecot) the time is about 47 seconds. It doesn’t
matter if the connection is protected with STARTTLS or not. The
encryption isn’t the problem.

Sniffing on the network I see that the AUTH command is only sent once at
the beginning, not for every mail.

So I’m wondering why I have such a big time difference.

The postfix version is 3.3.1 (Centos 8).

Many greetings,

        Stephan

--
|    If your life was a horse, you'd have to shoot it.    |
Reply | Threaded
Open this post in threaded view
|

Re: Mail delivery times: SASL vs permit_mynetwork

@lbutlr
On 01 Sep 2020, at 06:30, Stephan Seitz <[hidden email]> wrote:
> So I’m wondering why I have such a big time difference.

You would have to look deeper at the logs and see where the delay is being introduced. This might be hard as it is 3/10th of a second per message.

It could be as simple as the remote severing taking very slightly longer to process for reasons on its end (slower lookup into its tables from the secure ports, for example).




--
I CAN BE ROBBED BUT NEVER DENIED, I TOLD MYSELF. WHY WORRY?  'I too
        cannot be cheated,' snapped Fate. SO I HAVE HEARD.

Reply | Threaded
Open this post in threaded view
|

Re: Mail delivery times: SASL vs permit_mynetwork

Wietse Venema
In reply to this post by Stephan Seitz-3
Stephan Seitz:

> Hello!
>
> I try to understand different mail delivery times.
>
> I have a script (phpmailer) that sends 500 mails to a remote mail server.  
> The target address is a local /dev/null mailbox. The script uses
> SMTPKeepAlive = true; to keep the connection open.
>
> If my client IP is part of mynetworks the time for 500 mails is about 29
> seconds.

That's 5.8ms per delivery.

> If [not in mynetworks] the time is about 47 seconds.

That's 9.4ms per delivery. Looks like your network round-trip time
has increased with abount 1ms, compared to the 'faster' case.

        Wietse
Reply | Threaded
Open this post in threaded view
|

Re: Mail delivery times: SASL vs permit_mynetwork

Stephan Seitz-3
On Di, Sep 01, 2020 at 09:27:03 -0400, Wietse Venema wrote:
>Stephan Seitz:
>> If my client IP is part of mynetworks the time for 500 mails is about
>> 29 seconds.
>That's 5.8ms per delivery.
>
>> If [not in mynetworks] the time is about 47 seconds.
>That's 9.4ms per delivery. Looks like your network round-trip time
>has increased with abount 1ms, compared to the 'faster' case.

Well, it’s reproducible. The first one is always between 28 and 30
seconds, the other one always between 46 and 48 seconds.

Yes, it sounds stupid, but $CUSTOMER wishes to deliver thousands of
mails, and for them it is a huge difference.

        Stephan

--
|    If your life was a horse, you'd have to shoot it.    |
Reply | Threaded
Open this post in threaded view
|

Re: Mail delivery times: SASL vs permit_mynetwork

Stephan Seitz-3
In reply to this post by @lbutlr
On Di, Sep 01, 2020 at 07:18:44 -0600, @lbutlr wrote:
>It could be as simple as the remote severing taking very slightly longer
>to process for reasons on its end (slower lookup into its tables from
>the secure ports, for example).

I used port 25 for both tests, so that I could hope to avoid different
options for smtpd and submission.

So the only difference in the SMTP session should be the AUTH command.

Many greetings,

        Stephan

--
|    If your life was a horse, you'd have to shoot it.    |
Reply | Threaded
Open this post in threaded view
|

Re: Mail delivery times: SASL vs permit_mynetwork

@lbutlr
On 01 Sep 2020, at 07:37, Stephan Seitz <[hidden email]> wrote:
> On Di, Sep 01, 2020 at 07:18:44 -0600, @lbutlr wrote:
>> It could be as simple as the remote severing taking very slightly longer to process for reasons on its end (slower lookup into its tables from the secure ports, for example).
>
> I used port 25 for both tests, so that I could hope to avoid different options for smtpd and submission.
>
> So the only difference in the SMTP session should be the AUTH command.

Do you control the target server? If not, then you have no idea what mechanisms exist on that server.

Is this consistent across many servers? Does the delay scale based on the number of messages (is 1000 message 94 seconds versus 60? How about 5000 messages, 470 seconds versus 300?

Obsessing over a delay of 3 tenths of a second on a remote server you have no control over is going to lead to, probably, nothing but frustration. That said, sure, it COULD be something on your end, but you first would have to find what that delay in your logs, and unless it's really obvious (4 second pause every 100 messages, for example), that's going to be very very hard.


--
"One of the great tragedies of life is the murder of a beautiful
        theory by a gang of brutal facts." - Benjamin Franklin

Reply | Threaded
Open this post in threaded view
|

Re: Mail delivery times: SASL vs permit_mynetwork

Stephan Seitz-3
On Di, Sep 01, 2020 at 07:46:26 -0600, @lbutlr wrote:
>Do you control the target server? If not, then you have no idea what

Yes, I do control the server. This is a simple setup, no spamfilter or
such things. And yes, besides the fact that in one case the sasl user is
logged there aren’t any other differences.

>Is this consistent across many servers? Does the delay scale based on

I only tested with one server, but the results are quite linear.
50 mails = x seconds, 100 mails = 2x seconds, 500 mails = 10x seconds.

If Wietse had said that postfix would do a sasl lookup for every mail
(even if login and password is sent only once), then I would understand.

But I won’t debug the problem any further. It doesn’t seem to be that
obvious so it isn’t really worth it.

Many greetings,

        Stephan

--
|    If your life was a horse, you'd have to shoot it.    |
Reply | Threaded
Open this post in threaded view
|

Re: Mail delivery times: SASL vs permit_mynetwork

Wietse Venema
In reply to this post by Stephan Seitz-3
Stephan Seitz:
> On Di, Sep 01, 2020 at 09:27:03 -0400, Wietse Venema wrote:
> >Stephan Seitz:
> >> If my client IP is part of mynetworks the time for 500 mails is about
> >> 29 seconds.
> >That's 5.8ms per delivery.
> >
> >> If [not in mynetworks] the time is about 47 seconds.
> >That's 9.4ms per delivery. Looks like your network round-trip time
> >has increased with abount 1ms, compared to the 'faster' case.

In case you missed the point, I am talking about network round-trip
delays. Speed-ofo-light stuff.

> Well, it?s reproducible. The first one is always between 28 and 30
> seconds, the other one always between 46 and 48 seconds.

Amazingly, the speed of light is very reproducible.

> Yes, it sounds stupid, but $CUSTOMER wishes to deliver thousands of
> mails, and for them it is a huge difference.

Tell the customer to increase the speed of light, or get closer.

        Wietse
Reply | Threaded
Open this post in threaded view
|

Re: Mail delivery times: SASL vs permit_mynetwork

Bill Cole-3
In reply to this post by Stephan Seitz-3
On 1 Sep 2020, at 8:30, Stephan Seitz wrote:

> Hello!
>
> I try to understand different mail delivery times.
>
> I have a script (phpmailer) that sends 500 mails to a remote mail
> server.  The target address is a local /dev/null mailbox. The script
> uses SMTPKeepAlive = true; to keep the connection open.
>
> If my client IP is part of mynetworks the time for 500 mails is about
> 29 seconds.
>
> If I use AUTH (SASL via Dovecot) the time is about 47 seconds. It
> doesn’t matter if the connection is protected with STARTTLS or not.
> The encryption isn’t the problem.

Did you test by changing the value of $mynetworks and using the same
source machine or are the SASL and $mynetworks sources physically
different machines?

As Wietse said, this could be as simple as machine physical location and
the value of c. It also could be subtle differences between the machines
used which may not even be visible to you if both are virtual.


--
Bill Cole
[hidden email] or [hidden email]
(AKA @grumpybozo and many *@billmail.scconsult.com addresses)
Not For Hire (currently)
Reply | Threaded
Open this post in threaded view
|

Re: Mail delivery times: SASL vs permit_mynetwork

Stephan Seitz-3
On Di, Sep 01, 2020 at 12:59:05 -0400, Bill Cole wrote:
>Did you test by changing the value of $mynetworks and using the same
>source machine or are the SASL and $mynetworks sources physically
>different machines?

No, of course it was the same machine. I’m very sorry, I thought that
would be obvious because the tests wouldn’t be really comparable with
different systems.

It was always the same client, the same server and the same network
connectivity. I only changed $mynetworks and the php script.

Many greetings,

        Stephan

--
|    If your life was a horse, you'd have to shoot it.    |
Reply | Threaded
Open this post in threaded view
|

Re: Mail delivery times: SASL vs permit_mynetwork

Viktor Dukhovni
In reply to this post by Stephan Seitz-3
On Tue, Sep 01, 2020 at 02:30:05PM +0200, Stephan Seitz wrote:

> I try to understand different mail delivery times.

Sure, that's a quantitative analysis, and doing requires looking in
detail at the delivery latencies in the logs of both client and server.
To get help with this, you'll need to post detailed quantitative
metrics, anything else is just pointless wild speculation.

Ideally, after looking at the logs, but before you post them, just
the act of collecting them will help you realise what the problem is,
assuming there is a problem.  You'll to look at both clientside and
server side logs (DO NOT enable *verbose* logging in Postfix).

And make sure that systemd-journald is not throwing away most of
your log messages, its default configuration is abysmal.

> I have a script (phpmailer) that sends 500 mails to a remote mail server.  

Can the script log SMTP activity with millisecond or better time
granularity?  Have you done that?

> The target address is a local /dev/null mailbox. The script uses
> SMTPKeepAlive = true; to keep the connection open.

Have you verified that the connection is actually kept open?

> If my client IP is part of mynetworks the time for 500 mails is about 29
> seconds.

This is anecdata, not data.

> If I use AUTH (SASL via Dovecot) the time is about 47 seconds. It doesn’t
> matter if the connection is protected with STARTTLS or not. The
> encryption isn’t the problem.

This is anecdata, not data.

> So I’m wondering why I have such a big time difference.

So are we.

--
    Viktor.