[stunnel-users] Slow sending email through stunnel to Office365

ajreynolds at san.rr.com ajreynolds at san.rr.com
Tue Mar 1 21:44:06 CET 2016


After a bit of experimentation, I've succeeded in getting stunnel 5.31 running on my Windows 2008 r2 server and sending email through SMTP through Office365.  My problem now is that it's quite slow.  I can see a point in the log file where it stops for 5 seconds or more for each email message.  Are there any parameter for stunnel that might help, or do I have to just accept that Office365 is slow?  Here is my stunnel.conf file:

debug = 7
output = stunnel.log
[ms-smtp]
protocol = smtp
client = yes
accept = 587
connect = smtp.office365.com:587

And here is the log file for an email transmission.  Notice the 5 second pause at 12:31:04.  Is there a way to eliminate this pause?

2016.03.01 12:30:21 LOG7[cron]: Cron thread initialized
2016.03.01 12:30:21 LOG7[main]: No limit detected for the number of clients
2016.03.01 12:30:21 LOG5[main]: stunnel 5.31 on x86-pc-msvc-1500 platform
2016.03.01 12:30:21 LOG5[main]: Compiled/running with OpenSSL 1.0.2g-fips  1 Mar 2016
2016.03.01 12:30:21 LOG5[main]: Threading:WIN32 Sockets:SELECT,IPv6 TLS:ENGINE,FIPS,OCSP,PSK,SNI
2016.03.01 12:30:21 LOG7[main]: errno: (*_errno())
2016.03.01 12:30:21 LOG7[service]: GUI message loop initialized
2016.03.01 12:30:21 LOG5[main]: Reading configuration from file stunnel.conf
2016.03.01 12:30:21 LOG5[main]: UTF-8 byte order mark detected
2016.03.01 12:30:21 LOG5[main]: FIPS mode disabled
2016.03.01 12:30:21 LOG7[main]: Compression disabled
2016.03.01 12:30:21 LOG7[main]: Snagged 64 random bytes from C:/.rnd
2016.03.01 12:30:21 LOG7[main]: Wrote 1024 new random bytes to C:/.rnd
2016.03.01 12:30:21 LOG7[main]: PRNG seeded successfully
2016.03.01 12:30:21 LOG6[main]: Initializing service [ms-smtp]
2016.03.01 12:30:21 LOG7[main]: No certificate or private key specified
2016.03.01 12:30:21 LOG4[main]: Service [ms-smtp] needs authentication to prevent MITM attacks
2016.03.01 12:30:21 LOG7[main]: SSL options: 0x03000004 (+0x03000000, -0x00000000)
2016.03.01 12:30:21 LOG5[main]: Configuration successful
2016.03.01 12:30:21 LOG7[main]: Listening file descriptor created (FD=424)
2016.03.01 12:30:21 LOG7[main]: Service [ms-smtp] (FD=424) bound to 0.0.0.0:587
2016.03.01 12:30:58 LOG7[main]: Found 1 ready file descriptor(s)
2016.03.01 12:30:58 LOG7[main]: FD=388 ifds=r-x ofds=---
2016.03.01 12:30:58 LOG7[main]: Service [ms-smtp] accepted (FD=440) from 192.168.8.58:55266
2016.03.01 12:30:58 LOG7[main]: Creating a new thread
2016.03.01 12:30:58 LOG7[main]: New thread created
2016.03.01 12:30:58 LOG7[0]: Service [ms-smtp] started
2016.03.01 12:30:58 LOG5[0]: Service [ms-smtp] accepted connection from 192.168.8.58:55266
2016.03.01 12:30:58 LOG6[0]: failover: round-robin, starting at entry #3
2016.03.01 12:30:58 LOG6[0]: s_connect: connecting 132.245.34.194:587
2016.03.01 12:30:58 LOG7[0]: s_connect: s_poll_wait 132.245.34.194:587: waiting 10 seconds
2016.03.01 12:30:58 LOG5[0]: s_connect: connected 132.245.34.194:587
2016.03.01 12:30:58 LOG5[0]: Service [ms-smtp] connected remote server from 192.168.8.14:55477
2016.03.01 12:30:58 LOG7[0]: Remote descriptor (FD=460) initialized
2016.03.01 12:30:59 LOG7[0]:  <- 220 CY1PR21CA0008.outlook.office365.com Microsoft ESMTP MAIL Service ready at Tue, 1 Mar 2016 20:30:58 +0000
2016.03.01 12:30:59 LOG7[0]:  -> 220 CY1PR21CA0008.outlook.office365.com Microsoft ESMTP MAIL Service ready at Tue, 1 Mar 2016 20:30:58 +0000
2016.03.01 12:30:59 LOG7[0]:  -> EHLO localhost
2016.03.01 12:30:59 LOG7[0]:  <- 250-CY1PR21CA0008.outlook.office365.com Hello [#.#.#.#]
2016.03.01 12:30:59 LOG7[0]:  <- 250-SIZE 157286400
2016.03.01 12:30:59 LOG7[0]:  <- 250-PIPELINING
2016.03.01 12:30:59 LOG7[0]:  <- 250-DSN
2016.03.01 12:30:59 LOG7[0]:  <- 250-ENHANCEDSTATUSCODES
2016.03.01 12:30:59 LOG7[0]:  <- 250-STARTTLS
2016.03.01 12:30:59 LOG7[0]:  <- 250-8BITMIME
2016.03.01 12:30:59 LOG7[0]:  <- 250-BINARYMIME
2016.03.01 12:30:59 LOG7[0]:  <- 250 CHUNKING
2016.03.01 12:30:59 LOG7[0]:  -> STARTTLS
2016.03.01 12:30:59 LOG7[0]:  <- 220 2.0.0 SMTP server ready
2016.03.01 12:30:59 LOG6[0]: SNI: sending servername: smtp.office365.com
2016.03.01 12:30:59 LOG7[0]: SSL state (connect): before/connect initialization
2016.03.01 12:30:59 LOG7[0]: SSL state (connect): SSLv2/v3 write client hello A
2016.03.01 12:30:59 LOG7[0]: SSL state (connect): SSLv3 read server hello A
2016.03.01 12:30:59 LOG6[0]: Certificate verification disabled
2016.03.01 12:30:59 LOG6[0]: Certificate verification disabled
2016.03.01 12:30:59 LOG7[0]: SSL state (connect): SSLv3 read server certificate A
2016.03.01 12:30:59 LOG7[0]: SSL state (connect): SSLv3 read server key exchange A
2016.03.01 12:30:59 LOG6[0]: Empty client CA list
2016.03.01 12:30:59 LOG7[0]: SSL state (connect): SSLv3 read server certificate request A
2016.03.01 12:30:59 LOG7[0]: SSL state (connect): SSLv3 read server done A
2016.03.01 12:30:59 LOG7[0]: SSL state (connect): SSLv3 write client certificate A
2016.03.01 12:30:59 LOG7[0]: SSL state (connect): SSLv3 write client key exchange A
2016.03.01 12:30:59 LOG7[0]: SSL state (connect): SSLv3 write change cipher spec A
2016.03.01 12:30:59 LOG7[0]: SSL state (connect): SSLv3 write finished A
2016.03.01 12:30:59 LOG7[0]: SSL state (connect): SSLv3 flush data
2016.03.01 12:30:59 LOG7[0]: SSL state (connect): SSLv3 read finished A
2016.03.01 12:30:59 LOG7[0]:      1 client connect(s) requested
2016.03.01 12:30:59 LOG7[0]:      1 client connect(s) succeeded
2016.03.01 12:30:59 LOG7[0]:      0 client renegotiation(s) requested
2016.03.01 12:30:59 LOG7[0]:      0 session reuse(s)
2016.03.01 12:30:59 LOG6[0]: SSL connected: new session negotiated
2016.03.01 12:30:59 LOG7[0]: Peer certificate was cached (4882 bytes)
2016.03.01 12:30:59 LOG6[0]: Negotiated TLSv1.2 ciphersuite ECDHE-RSA-AES256-SHA384 (256-bit encryption)
2016.03.01 12:30:59 LOG7[0]: Compression: null, expansion: null
2016.03.01 12:31:04 LOG6[0]: Read socket closed (readsocket)
2016.03.01 12:31:04 LOG7[0]: Sending close_notify alert
2016.03.01 12:31:04 LOG7[0]: SSL alert (write): warning: close notify
2016.03.01 12:31:04 LOG6[0]: SSL_shutdown successfully sent close_notify alert
2016.03.01 12:31:04 LOG6[0]: SSL socket closed (SSL_read)
2016.03.01 12:31:04 LOG7[0]: Sent socket write shutdown
2016.03.01 12:31:04 LOG5[0]: Connection closed: 413 byte(s) sent to SSL, 635 byte(s) sent to socket
2016.03.01 12:31:04 LOG7[0]: Remote descriptor (FD=460) closed
2016.03.01 12:31:04 LOG7[0]: Local descriptor (FD=440) closed
2016.03.01 12:31:04 LOG7[0]: Service [ms-smtp] finished (0 left)

Thanks very much,
Andy




More information about the stunnel-users mailing list