[stunnel-users] Scan to email failure: RapbianPi3 to Office365
Graeme Ellisson
gellisson at gmail.com
Mon Apr 3 12:16:21 CEST 2017
Hi.
I recently bought a Pi3 and have loaded Raspbian with Doobs (Previously I
had this running faultlessly under a Windows Server for my Canon multi
function printer that does not support SSL/TLS but only authentication).
After about 8 attempts to get Stunnel4 working (there doesn't seem to be a
later version to install via the command line) I eventually found that
Stunnel4 works fine as long as one doesn't update Dabian from the initial
Doobs install.
So, I now have the service running and listening on port 25 with the
following config file:
debug=7
output=/etc/stunnel/stunnel.log
client=yes
options=NO_SSLv2 (I added this last night after reading a blog)
[SMTP OUT]
sslVersion=TLSv1 (I added this last night after reading a blog)
protocol=smtp
accept=25
connect=smtp.office365.com:587
On restarting the service I see the following which looks okay to my
untrained eye:
2017.04.03 09:42:09 LOG7[3570]: Dispatching signals from the signal pipe
2017.04.03 09:42:09 LOG7[3570]: Processing SIGNAL_TERMINATE
2017.04.03 09:42:09 LOG5[3570]: Terminated
2017.04.03 09:42:09 LOG7[3570]: Closing service [SMTP OUT]
2017.04.03 09:42:09 LOG7[3570]: Service [SMTP OUT] closed (FD=7)
2017.04.03 09:42:09 LOG7[3570]: Service [SMTP OUT] closed
2017.04.03 09:42:09 LOG7[3570]: removing pid file /var/run/stunnel4.pid
2017.04.03 09:42:09 LOG7[3926]: Clients allowed=500
2017.04.03 09:42:09 LOG5[3926]: stunnel 5.06 on arm-unknown-linux-gnueabihf
platform
2017.04.03 09:42:09 LOG5[3926]: Compiled with OpenSSL 1.0.1k 8 Jan 2015
2017.04.03 09:42:09 LOG5[3926]: Running with OpenSSL 1.0.1t 3 May 2016
2017.04.03 09:42:09 LOG5[3926]: Update OpenSSL shared libraries or rebuild
stunnel
2017.04.03 09:42:09 LOG5[3926]: Threading:PTHREAD Sockets:POLL,IPv6,SYSTEMD
SSL:ENGINE,OCSP,FIPS Auth:LIB$
2017.04.03 09:42:09 LOG7[3926]: errno: (*__errno_location ())
2017.04.03 09:42:09 LOG5[3926]: Reading configuration from file
/etc/stunnel/stunnel4.conf
2017.04.03 09:42:09 LOG5[3926]: FIPS mode disabled
2017.04.03 09:42:09 LOG7[3926]: Compression disabled
2017.04.03 09:42:09 LOG7[3926]: Snagged 64 random bytes from /dev/urandom
2017.04.03 09:42:09 LOG7[3926]: PRNG seeded successfully
2017.04.03 09:42:09 LOG6[3926]: Initializing service [SMTP OUT]
2017.04.03 09:42:09 LOG7[3926]: No private key specified
2017.04.03 09:42:09 LOG7[3926]: SSL options: 0x03000004 (+0x03000000,
-0x00000000)
2017.04.03 09:42:09 LOG5[3926]: Configuration successful
2017.04.03 09:42:09 LOG7[3926]: Listening file descriptor created (FD=7)
2017.04.03 09:42:09 LOG7[3926]: Service [SMTP OUT] (FD=7) bound to
0.0.0.0:25
2017.04.03 09:42:09 LOG7[3927]: Created pid file /var/run/stunnel4.pid
When sending a scan from the printer to an email address I see the
following in the log file:
2017.04.03 10:00:05 LOG7[3927]: Service [SMTP OUT] accepted (FD=3) from
192.168.8.99:1085
2017.04.03 10:00:05 LOG7[3960]: Service [SMTP OUT] started
2017.04.03 10:00:05 LOG5[3960]: Service [SMTP OUT] accepted connection from
192.168.8.99:1085
2017.04.03 10:00:05 LOG6[3960]: s_connect: connecting 40.101.73.162:587
2017.04.03 10:00:05 LOG7[3960]: s_connect: s_poll_wait 40.101.73.162:587:
waiting 10 seconds
2017.04.03 10:00:05 LOG5[3960]: s_connect: connected 40.101.73.162:587
2017.04.03 10:00:05 LOG5[3960]: Service [SMTP OUT] connected remote server
from 192.168.8.33:59792
2017.04.03 10:00:05 LOG7[3960]: Remote socket (FD=9) initialized
2017.04.03 10:00:05 LOG7[3960]: <- 220 DB6PR07CA0179.outlook.office365.com
Microsoft ESMTP MAIL Service $
2017.04.03 10:00:05 LOG7[3960]: -> 220 DB6PR07CA0179.outlook.office365.com
Microsoft ESMTP MAIL Service $
2017.04.03 10:00:05 LOG7[3960]: -> EHLO localhost
2017.04.03 10:00:05 LOG7[3960]: <- 250-DB6PR07CA0179.outlook.office365.com
Hello [46.208.253.189]
2017.04.03 10:00:05 LOG7[3960]: <- 250-SIZE 157286400
2017.04.03 10:00:05 LOG7[3960]: <- 250-PIPELINING
2017.04.03 10:00:05 LOG7[3960]: <- 250-DSN
2017.04.03 10:00:05 LOG7[3960]: <- 250-ENHANCEDSTATUSCODES
2017.04.03 10:00:05 LOG7[3960]: <- 250-STARTTLS
2017.04.03 10:00:05 LOG7[3960]: <- 250-8BITMIME
2017.04.03 10:00:05 LOG7[3960]: <- 250-BINARYMIME
2017.04.03 10:00:05 LOG7[3960]: <- 250-CHUNKING
2017.04.03 10:00:05 LOG7[3960]: <- 250 SMTPUTF8
2017.04.03 10:00:05 LOG7[3960]: -> STARTTLS
2017.04.03 10:00:05 LOG7[3960]: <- 220 2.0.0 SMTP server ready
2017.04.03 10:00:05 LOG6[3960]: SNI: sending servername:
outlook.office365.com
2017.04.03 10:00:05 LOG7[3960]: SSL state (connect): before/connect
initialization
2017.04.03 10:00:05 LOG7[3960]: SSL state (connect): unknown state
2017.04.03 10:00:05 LOG7[3960]: SSL state (connect): unknown state
2017.04.03 10:00:05 LOG7[3960]: SSL state (connect): unknown state
2017.04.03 10:00:05 LOG7[3960]: SSL state (connect): unknown state
2017.04.03 10:00:05 LOG7[3960]: SSL state (connect): unknown state
2017.04.03 10:00:05 LOG7[3960]: SSL state (connect): unknown state
2017.04.03 10:00:05 LOG7[3960]: SSL state (connect): unknown state
2017.04.03 10:00:05 LOG7[3960]: SSL state (connect): unknown state
2017.04.03 10:00:05 LOG7[3960]: SSL state (connect): unknown state
2017.04.03 10:00:05 LOG7[3960]: SSL state (connect): unknown state
2017.04.03 10:00:05 LOG7[3960]: SSL state (connect): unknown state
2017.04.03 10:00:05 LOG7[3960]: SSL state (connect): unknown state
2017.04.03 10:00:05 LOG7[3960]: SSL state (connect): unknown state
2017.04.03 10:00:05 LOG7[3960]: 0 items in the session cache
2017.04.03 10:00:05 LOG7[3960]: 2 client connects (SSL_connect())
2017.04.03 10:00:05 LOG7[3960]: 2 client connects that finished
2017.04.03 10:00:05 LOG7[3960]: 0 client renegotiations requested
2017.04.03 10:00:05 LOG7[3960]: 0 server connects (SSL_accept())
2017.04.03 10:00:05 LOG7[3960]: 0 server connects that finished
2017.04.03 10:00:05 LOG7[3960]: 0 server renegotiations requested
2017.04.03 10:00:05 LOG7[3960]: 0 session cache hits
2017.04.03 10:00:05 LOG7[3960]: 0 external session cache hits
2017.04.03 10:00:05 LOG7[3960]: 0 session cache misses
2017.04.03 10:00:05 LOG7[3960]: 0 session cache timeouts
2017.04.03 10:00:05 LOG6[3960]: SSL connected: new session negotiated
2017.04.03 10:00:05 LOG6[3960]: Negotiated TLSv1 ciphersuite
ECDHE-RSA-AES128-SHA (128-bit encryption)
2017.04.03 10:00:05 LOG6[3960]: Compression: null, expansion: null
2017.04.03 10:00:10 LOG6[3960]: SSL socket closed (SSL_read)
2017.04.03 10:00:10 LOG7[3960]: Sent socket write shutdown
2017.04.03 10:00:10 LOG5[3960]: Connection closed: 23 byte(s) sent to SSL,
79 byte(s) sent to socket
2017.04.03 10:00:10 LOG7[3960]: Remote socket (FD=9) closed
2017.04.03 10:00:10 LOG7[3960]: Local socket (FD=3) closed
2017.04.03 10:00:10 LOG7[3960]: Service [SMTP OUT] finished (0 left)
2017.04.03 10:00:20 LOG7[3927]: Service [SMTP OUT] accepted (FD=3) from
192.168.8.99:1086
2017.04.03 10:00:20 LOG7[3961]: Service [SMTP OUT] started
2017.04.03 10:00:20 LOG5[3961]: Service [SMTP OUT] accepted connection from
192.168.8.99:1086
2017.04.03 10:00:20 LOG6[3961]: s_connect: connecting 40.101.72.194:587
2017.04.03 10:00:20 LOG7[3961]: s_connect: s_poll_wait 40.101.72.194:587:
waiting 10 seconds
2017.04.03 10:00:20 LOG5[3961]: s_connect: connected 40.101.72.194:587
2017.04.03 10:00:20 LOG5[3961]: Service [SMTP OUT] connected remote serve
from 192.168.8.33:57422
2017.04.03 10:00:20 LOG7[3961]: Remote socket (FD=9) initialized
2017.04.03 10:00:21 LOG7[3961]: <- 220 DB6PR07CA0014.outlook.office365.com
Microsoft ESMTP MAIL Service $
2017.04.03 10:00:21 LOG7[3961]: -> 220 DB6PR07CA0014.outlook.office365.com
Microsoft ESMTP MAIL Service $
2017.04.03 10:00:21 LOG7[3961]: -> EHLO localhost
2017.04.03 10:00:21 LOG7[3961]: <- 250-DB6PR07CA0014.outlook.office365.com
Hello [46.208.253.189]
2017.04.03 10:00:21 LOG7[3961]: <- 250-SIZE 157286400
2017.04.03 10:00:21 LOG7[3961]: <- 250-PIPELINING
2017.04.03 10:00:21 LOG7[3961]: <- 250-DSN
2017.04.03 10:00:21 LOG7[3961]: <- 250-ENHANCEDSTATUSCODES
2017.04.03 10:00:21 LOG7[3961]: <- 250-STARTTLS
2017.04.03 10:00:21 LOG7[3961]: <- 250-8BITMIME
2017.04.03 10:00:21 LOG7[3961]: <- 250-BINARYMIME
2017.04.03 10:00:21 LOG7[3961]: <- 250-CHUNKING
2017.04.03 10:00:21 LOG7[3961]: <- 250 SMTPUTF8
2017.04.03 10:00:21 LOG7[3961]: -> STARTTLS
2017.04.03 10:00:21 LOG7[3961]: <- 220 2.0.0 SMTP server ready
2017.04.03 10:00:21 LOG6[3961]: SNI: sending servername:
outlook.office365.com
2017.04.03 10:00:21 LOG7[3961]: SSL state (connect): before/connect
initialization
2017.04.03 10:00:21 LOG7[3961]: SSL state (connect): unknown state
2017.04.03 10:00:21 LOG7[3961]: SSL state (connect): unknown state
2017.04.03 10:00:21 LOG7[3961]: SSL state (connect): unknown state
2017.04.03 10:00:21 LOG7[3961]: SSL state (connect): unknown state
2017.04.03 10:00:21 LOG7[3961]: SSL state (connect): unknown state
2017.04.03 10:00:21 LOG7[3961]: SSL state (connect): unknown state
2017.04.03 10:00:21 LOG7[3961]: SSL state (connect): unknown state
2017.04.03 10:00:21 LOG7[3961]: SSL state (connect): unknown state
2017.04.03 10:00:21 LOG7[3961]: SSL state (connect): unknown state
2017.04.03 10:00:21 LOG7[3961]: SSL state (connect): unknown state
2017.04.03 10:00:21 LOG7[3961]: SSL state (connect): unknown state
2017.04.03 10:00:21 LOG7[3961]: SSL state (connect): unknown state
2017.04.03 10:00:21 LOG7[3961]: 0 items in the session cache
2017.04.03 10:00:21 LOG7[3961]: 3 client connects (SSL_connect())
2017.04.03 10:00:21 LOG7[3961]: 3 client connects that finished
2017.04.03 10:00:21 LOG7[3961]: 0 client renegotiations requested
2017.04.03 10:00:21 LOG7[3961]: 0 server connects (SSL_accept())
2017.04.03 10:00:21 LOG7[3961]: 0 server connects that finished
2017.04.03 10:00:21 LOG7[3961]: 0 server renegotiations requested
2017.04.03 10:00:21 LOG7[3961]: 0 session cache hits
2017.04.03 10:00:21 LOG7[3961]: 0 external session cache hits
2017.04.03 10:00:21 LOG7[3961]: 0 session cache misses
2017.04.03 10:00:21 LOG7[3961]: 0 session cache timeouts
2017.04.03 10:00:21 LOG6[3961]: SSL connected: new session negotiated
2017.04.03 10:00:21 LOG6[3961]: Negotiated TLSv1 ciphersuite
ECDHE-RSA-AES128-SHA (128-bit encryption)
2017.04.03 10:00:21 LOG6[3961]: Compression: null, expansion: null
2017.04.03 10:00:26 LOG6[3961]: SSL socket closed (SSL_read)
2017.04.03 10:00:26 LOG7[3961]: Sent socket write shutdown
2017.04.03 10:00:26 LOG5[3961]: Connection closed: 23 byte(s) sent to SSL,
79 byte(s) sent to socket
2017.04.03 10:00:26 LOG7[3961]: Remote socket (FD=9) closed
2017.04.03 10:00:26 LOG7[3961]: Local socket (FD=3) closed
2017.04.03 10:00:26 LOG7[3961]: Service [SMTP OUT] finished (0 left)
At the end of this, no email is received. I can't tell from the above if
the document is not being received by Stunnel from the printer or if
Stunnel can not pass the document to Office365. It looks like TLSv1 is
being negotiated and some data is being sent but then it closes the
connection.
Any help would be much appreciated.
Regards,
Graeme
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://www.stunnel.org/pipermail/stunnel-users/attachments/20170403/a73cf480/attachment.html>
More information about the stunnel-users
mailing list