Slow send with large attachment

0 votes
asked Oct 24, 2018 by FrancescoBo (120 points)

Hi,
I'm trying to send an email with a 20 Mb attachment and this takes more than 2 minutes to do it.
Is this normal?

this is my send code:

Smtp smtp = new Smtp();
smtp.LogWriter = new FileLogWriter("log.txt", LogLevel.Debug);
smtp.Connect("serverName", 5264, SslMode.Implicit);
smtp.Login("Username", "Password");
smtp.Settings.SkipContentTransferEncodingCheck = true;
smtp.Send(message);
smtp.Disconnect();

I have noticed this in the log file:

2018-10-24 18:03:31.526 INFO Smtp(1)[1] Response: 354 End data with <CR><LF>.<CR><LF>
2018-10-24 18:05:03.219 INFO Smtp(1)[1] Response: 250 2.0.0 Ok: queued as 42gFRR3LCpz2L1Hyh

Thanks!

1 Answer

+1 vote
answered Oct 25, 2018 by Lukas Pokorny (100,910 points)

Hi, this is not normal unless you have a very slow connection. However, this is unlikely to be caused by an SMTP client. Do you experience a similar delay when sending the same attachment through the same SMTP server using a third-party mail agent (such as Thunderbird)?

commented Oct 25, 2018 by FrancescoBo (120 points)
I tried to send the same file with thunderbird and it takes 50 seconds
commented Oct 25, 2018 by Lukas Pokorny (100,910 points)
50 seconds still sounds like a bit too much. Would it be possible to determine whether this issue is specific to one particular SMTP server, or does it occur when sending e-mails with long attachments through other SMTP servers?
commented Oct 25, 2018 by Lukas Pokorny (100,910 points)
Additionally, it would be useful if we could review the communication log. It might provide some clues.
commented Oct 25, 2018 by FrancescoBo (120 points)
I tried to send the same file with a through other SMTP server

2018-10-25 15:38:56.472 INFO Smtp(1)[1] Response: 354 Start mail input; end with <CRLF>.<CRLF>
2018-10-25 15:40:31.230 INFO Smtp(1)[1] Response: 250 <5BBEC9650099FD39> Mail accepted
commented Oct 25, 2018 by Lukas Pokorny (100,910 points)
Would it be possible to post the full communication log, or mail it to support@rebex.net?
commented Oct 25, 2018 by FrancescoBo (120 points)
2018-10-25 15:38:53.462 Opening log file.
2018-10-25 15:38:53.462 Using FileLogWriter version 2.0.6198.0.
2018-10-25 15:38:53.675 DEBUG Smtp(1)[1] Info: State changed from 'Disconnected' to 'Connecting'.
2018-10-25 15:38:53.676 INFO Smtp(1)[1] Info: Connecting to sendm.cert.legalmail.it:465 using Smtp 2.0.6198.0.
2018-10-25 15:38:53.743 DEBUG Smtp(1)[1] Info: Connection succeeded.
2018-10-25 15:38:53.751 DEBUG Smtp(1)[1] Info: Upgrading connection to TLS/SSL.
2018-10-25 15:38:53.801 INFO Smtp(1)[1] TLS: State StateChange:Negotiating
2018-10-25 15:38:53.802 DEBUG Smtp(1)[1] TLS: HandshakeMessage:ClientHello was sent.
2018-10-25 15:38:53.867 DEBUG Smtp(1)[1] TLS: HandshakeMessage:ServerHello was received.
2018-10-25 15:38:53.868 INFO Smtp(1)[1] TLS: Using TLS 1.2.
2018-10-25 15:38:53.874 DEBUG Smtp(1)[1] TLS: HandshakeMessage:Certificate was received.
2018-10-25 15:38:53.874 DEBUG Smtp(1)[1] TLS: HandshakeMessage:ServerHelloDone was received.
2018-10-25 15:38:53.879 DEBUG Smtp(1)[1] TLS: Verifying server certificate ('CN=*.cert.legalmail.it, O=InfoCert SpA, OU=Servizi Applicativi, L=Padua, S=Italy, C=IT').
2018-10-25 15:38:53.944 DEBUG Smtp(1)[1] TLS: Certificate verification result: Accept
2018-10-25 15:38:53.953 DEBUG Smtp(1)[1] TLS: HandshakeMessage:ClientKeyExchange was sent.
2018-10-25 15:38:53.983 DEBUG Smtp(1)[1] TLS: CipherSpec:ChangeCipherSpec was sent.
2018-10-25 15:38:53.990 DEBUG Smtp(1)[1] TLS: HandshakeMessage:Finished was sent.
2018-10-25 15:38:54.027 DEBUG Smtp(1)[1] TLS: CipherSpec:ChangeCipherSpec was received.
2018-10-25 15:38:54.030 DEBUG Smtp(1)[1] TLS: HandshakeMessage:Finished was received.
2018-10-25 15:38:54.032 INFO Smtp(1)[1] TLS: State StateChange:Secured
2018-10-25 15:38:54.034 INFO Smtp(1)[1] TLS: Connection secured using cipher: TLS 1.2, RSA, 256bit AES in CBC mode, SHA256
2018-10-25 15:38:54.039 DEBUG Smtp(1)[1] TLS: Session ID:
 0000 |73-77-83-03-D6-A6-C0-C6 41-6F-F8-A6-72-ED-89-9F| sw......Ao..r...
 0010 |34-20-FA-C3-E3-A8-03-67 AC-C6-3E-C3-6E-2E-17-2A| 4 .....g..>.n..*
2018-10-25 15:38:54.039 DEBUG Smtp(1)[1] Info: Connection upgraded to TLS/SSL.
2018-10-25 15:38:54.039 DEBUG Smtp(1)[1] Info: State changed from 'Connecting' to 'Reading'.
2018-10-25 15:38:54.051 INFO Smtp(1)[1] Response: 220 sendm.cert.legalmail.it ESMTP Service ready
2018-10-25 15:38:54.054 DEBUG Smtp(1)[1] Info: State changed from 'Reading' to 'Ready'.
2018-10-25 15:38:54.063 DEBUG Smtp(1)[1] Info: State changed from 'Ready' to 'Sending'.
2018-10-25 15:38:54.066 INFO Smtp(1)[1] Command: EHLO construct.****net.local
2018-10-25 15:38:54.066 DEBUG Smtp(1)[1] Info: State changed from 'Sending' to 'Reading'.
2018-10-25 15:38:54.098 INFO Smtp(1)[1] Response: 250-sendm.cert.legalmail.it
2018-10-25 15:38:54.098 INFO Smtp(1)[1] Response: 250-X-CP-SET-SOURCE-IP
2018-10-25 15:38:54.098 INFO Smtp(1)[1] Response: 250-DSN
2018-10-25 15:38:54.098 INFO Smtp(1)[1] Response: 250-8BITMIME
2018-10-25 15:38:54.098 INFO Smtp(1)[1] Response: 250-PIPELINING
2018-10-25 15:38:54.098 INFO Smtp(1)[1] Response: 250-HELP
2018-10-25 15:38:54.098 INFO Smtp(1)[1] Response: 250-AUTH=LOGIN
2018-10-25 15:38:54.098 INFO Smtp(1)[1] Response: 250-AUTH LOGIN PLAIN
2018-10-25 15:38:54.098 INFO Smtp(1)[1] Response: 250-DELIVERBY 300
2018-10-25 15:38:54.098 INFO Smtp(1)[1] Response: 250 SIZE 104857600
2018-10-25 15:38:54.098 DEBUG Smtp(1)[1] Info: State changed from 'Reading' to 'Ready'.
2018-10-25 15:38:54.120 DEBUG Smtp(1)[1] Info: State changed from 'Ready' to 'Sending'.
2018-10-25 15:38:54.120 INFO Smtp(1)[1] Command: AUTH PLAIN ********************************************
2018-10-25 15:38:54.120 DEBUG Smtp(1)[1] Info: State changed from 'Sending' to 'Reading'.
2018-10-25 15:38:54.162 INFO Smtp(1)[1] Response: 235 PLAIN authentication successful
2018-10-25 15:38:54.162 DEBUG Smtp(1)[1] Info: State changed from 'Reading' to 'Ready'.
2018-10-25 15:38:56.353 DEBUG Smtp(1)[1] Info: State changed from 'Ready' to 'Sending'.
2018-10-25 15:38:56.353 INFO Smtp(1)[1] Command: MAIL FROM:<****@legalmail.it> BODY=8BITMIME SIZE=32104361
2018-10-25 15:38:56.353 DEBUG Smtp(1)[1] Info: State changed from 'Sending' to 'Reading'.
2018-10-25 15:38:56.404 INFO Smtp(1)[1] Response: 250 MAIL FROM:<****@legalmail.it> OK
2018-10-25 15:38:56.404 DEBUG Smtp(1)[1] Info: State changed from 'Reading' to 'Ready'.
2018-10-25 15:38:56.408 DEBUG Smtp(1)[1] Info: State changed from 'Ready' to 'Pipelining'.
2018-10-25 15:38:56.408 INFO Smtp(1)[1] Command: RCPT TO:<*****@****.it> NOTIFY=FAILURE
2018-10-25 15:38:56.441 INFO Smtp(1)[1] Response: 250 RCPT TO:<*****@****.it> OK
2018-10-25 15:38:56.442 INFO Smtp(1)[1] Command: DATA
2018-10-25 15:38:56.472 INFO Smtp(1)[1] Response: 354 Start mail input; end with <CRLF>.<CRLF>
2018-10-25 15:40:31.230 INFO Smtp(1)[1] Response: 250 <5BBEC9650099FD39> Mail accepted
2018-10-25 15:40:31.230 DEBUG Smtp(1)[1] Info: State changed from 'Pipelining' to 'Ready'.
2018-10-25 15:40:31.231 DEBUG Smtp(1)[1] Info: State changed from 'Ready' to 'Sending'.
2018-10-25 15:40:31.231 INFO Smtp(1)[1] Command: QUIT
2018-10-25 15:40:31.231 DEBUG Smtp(1)[1] Info: State changed from 'Sending' to 'Reading'.
2018-10-25 15:40:31.233 DEBUG Smtp(1)[1] TLS: Closing TLS socket.
2018-10-25 15:40:31.235 INFO Smtp(1)[1] TLS: Alert Alert:Alert was sent.
2018-10-25 15:40:31.235 INFO Smtp(1)[1] TLS: State StateChange:Closed
2018-10-25 15:40:31.237 DEBUG Smtp(1)[1] Info: State changed from 'Reading' to 'Disconnected'.
commented Oct 26, 2018 by Lukas Pokorny (100,910 points)
Thanks!
Can you please try this using the latest release of Rebex Secure Mail (2018 R3) and post a log for comparison? The latest version sends e-mail data in larger blocks, which might enhance transfer speed on connections where higher number of packets causes issues.
https://www.rebex.net/secure-mail.net/download.aspx
commented Nov 27, 2018 by christian.harter (230 points)
Hallo Lukas,

is this issue resolved?

I've got the same problems when sending larger attachments over some smtp servers. Sending a 2 MB attachment takes 3 minutes while sending with .NET SmtpClient takes only about 10 seconds. When trying this on our own exchange server there are no differences in time between Rebex Secure Mail and .NET SmtpClient. Both are very fast.

Is this a known issue?
I use the latest release of Rebex Secure Mail (2018 R3).

Thank you and best regards,
Christian
commented Nov 27, 2018 by Lukas Pokorny (100,910 points)
The user who reported this issue never got back to us, so we were unable to look into it.
But since you are already using the latest version, please give this a try:

1) Try to disable chunking, pipelining, and both before sending the message and let us know whether this has any effect:
    smtp.EnabledExtensions &= ~SmtpExtensions.Pipelining;
    smtp.EnabledExtensions &= ~SmtpExtensions.Chunking;

2) If this doesn't help, create a communication log using LogWriter property (see the code above) and either post it here or mail it to support@rebex.net for analysis.

Thanks!
commented Nov 27, 2018 by christian.harter (230 points)
Thank you very much... disable chunking works. Disable pipelining has no effect.

Best wishes,
Christian
commented Nov 28, 2018 by Lukas Pokorny (100,910 points)
Thanks for letting us know! I guess that .NET SmtpClient doesn't use chunking extension either.
...