[stunnel-users] Scan to email failure: RapbianPi3 to Office365
Andrew Culver
aculver at uwo.ca
Mon Apr 3 17:27:49 CEST 2017
Hi Graeme,
We have a number of Toshiba MFDs which use Scan To Email. We are using
stunnel to listen on port 587/TLS and connect to smtp.office365.com:587.
Since I'm listening for TLS and connecting to O365 using TLS, I have 2
services defined. We're running Stunnel 5.40. Can you compile the latest
version?
setuid = stunnel
setgid = stunnel
pid = /usr/local/var/run/stunnel/stunnel.pid
[uwo2local]
accept = 587
cert = /usr/local/etc/stunnel/mtar-withprivatekey.pem
connect = 20587
protocol = smtp
[local2o365]
client = yes
accept = 127.0.0.1:20587
connect = smtp.office365.com:587
protocol = smtp
One advantage of having 2 listeners is that you can run a tcpdump on the lo
interface to capture the traffic, then open it up in Wireshark to look at
the SMTP dialog for any problems. One thing to watch for is that the
sending address that the printer is using (ie the From: header) is an
address that the authenticating user is authorized to send as. Typically
this should be the same address to avoid problems (although this isn't a
Stunnel problem).
Andrew
*Andrew Culver*
System Administrator
Information Technology Services <https://www.uwo.ca/its>
University of Western Ontario <https://www.uwo.ca>
e: aculver at uwo.ca
p: 519-661-2111 x80265 <15196612111,80265>
cal: html <http://goo.gl/wVoDlo> | ics <http://goo.gl/ncUjV0>
On Mon, Apr 3, 2017 at 6:16 AM, Graeme Ellisson <gellisson at gmail.com> wrote:
> 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
>
>
>
>
>
>
>
>
>
>
>
>
>
>
> _______________________________________________
> stunnel-users mailing list
> stunnel-users at stunnel.org
> https://www.stunnel.org/cgi-bin/mailman/listinfo/stunnel-users
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://www.stunnel.org/pipermail/stunnel-users/attachments/20170403/923a6387/attachment.html>
More information about the stunnel-users
mailing list