[stunnel-users] Unable to authenticate with Outlook.com servers (SMTP)

Thu Oct 15 17:03:15 CEST 2015

Greetings,

Running stunnel 5.25 latest beta (2015-10-15), but also had the same
issues on 5.24 final.

My config file looks like this:

debug = debug
output = xxxxx
client = yes
cert = stunnel.pem

[outlook-smtp]
accept = 127.0.0.1:25
connect = smtp-mail.outlook.com:587
protocol = smtp
;protocolUsername = xxxx
;protocolPassword = xxxx
CAfile = ca-certs.pem
checkHost = smtp-mail.outlook.com
OCSPaia = yes
verify = 2

I am testing functionality to make sure that I am able to send mail
with my Outlook.com address. I currently have User/Pass field
commented out, but I've tried with them not commented out, and the
actual values instead of "xxxx" (the app I'm using has fields for
username and password).

My log:

2015.10.15 11:01:24 LOG7[cron]: Cron started
2015.10.15 11:01:24 LOG7[main]: No limit detected for the number of clients
2015.10.15 11:01:24 LOG5[main]: stunnel 5.25 on x86-pc-msvc-1500 platform
2015.10.15 11:01:24 LOG5[main]: Compiled/running with OpenSSL
1.0.2d-fips 9 Jul 2015
2015.10.15 11:01:24 LOG5[main]: Threading:WIN32 Sockets:SELECT,IPv6
TLS:ENGINE,FIPS,OCSP,PSK,SNI
2015.10.15 11:01:24 LOG7[main]: errno: (*_errno())
2015.10.15 11:01:24 LOG7[ui]: GUI message loop initialized
2015.10.15 11:01:24 LOG5[main]: Reading configuration from file stunnel.conf
2015.10.15 11:01:24 LOG5[main]: UTF-8 byte order mark detected
2015.10.15 11:01:24 LOG5[main]: FIPS mode disabled
2015.10.15 11:01:24 LOG7[main]: Compression disabled
2015.10.15 11:01:24 LOG7[main]: PRNG seeded successfully
2015.10.15 11:01:24 LOG6[main]: Initializing service [outlook-smtp]
2015.10.15 11:01:24 LOG6[main]: Loading certificate from file: stunnel.pem
2015.10.15 11:01:24 LOG6[main]: Loading key from file: stunnel.pem
2015.10.15 11:01:24 LOG7[main]: Private key check succeeded
2015.10.15 11:01:24 LOG7[main]: SSL options: 0x03000004 (+0x03000000,
-0x00000000)
2015.10.15 11:01:24 LOG5[main]: Configuration successful
2015.10.15 11:01:24 LOG7[main]: Listening file descriptor created (FD=652)
2015.10.15 11:01:24 LOG7[main]: Service [outlook-smtp] (FD=652) bound
to 127.0.0.1:25
2015.10.15 11:01:31 LOG7[main]: Found 1 ready file descriptor(s)
2015.10.15 11:01:31 LOG7[main]: FD=408 ifds=r-x ofds=---
2015.10.15 11:01:31 LOG7[main]: Service [outlook-smtp] accepted
(FD=692) from 127.0.0.1:58065
2015.10.15 11:01:31 LOG7[main]: Creating a new thread
2015.10.15 11:01:31 LOG7[main]: New thread created
2015.10.15 11:01:31 LOG7[0]: Service [outlook-smtp] started
2015.10.15 11:01:31 LOG5[0]: Service [outlook-smtp] accepted
connection from 127.0.0.1:58065
2015.10.15 11:01:31 LOG6[0]: s_connect: connecting 65.55.176.126:587
2015.10.15 11:01:31 LOG7[0]: s_connect: s_poll_wait 65.55.176.126:587:
waiting 10 seconds
2015.10.15 11:01:31 LOG5[0]: s_connect: connected 65.55.176.126:587
2015.10.15 11:01:31 LOG5[0]: Service [outlook-smtp] connected remote
server from 172.26.1.51:58066
2015.10.15 11:01:31 LOG7[0]: Remote descriptor (FD=704) initialized
2015.10.15 11:01:31 LOG7[0]:  <- 220 BLU436-SMTP245.smtp.hotmail.com
Microsoft ESMTP MAIL Service, Version: 8.0.9200.16384 ready at  Thu,
15 Oct 2015 08:01:34 -0700
2015.10.15 11:01:31 LOG7[0]:  -> 220 BLU436-SMTP245.smtp.hotmail.com
Microsoft ESMTP MAIL Service, Version: 8.0.9200.16384 ready at  Thu,
15 Oct 2015 08:01:34 -0700
2015.10.15 11:01:31 LOG7[0]:  -> EHLO localhost
2015.10.15 11:01:31 LOG7[0]:  <- 250-BLU436-SMTP245.smtp.hotmail.com
Hello [70.90.151.129]
2015.10.15 11:01:31 LOG7[0]:  <- 250-TURN
2015.10.15 11:01:31 LOG7[0]:  <- 250-SIZE 41943040
2015.10.15 11:01:31 LOG7[0]:  <- 250-ETRN
2015.10.15 11:01:31 LOG7[0]:  <- 250-PIPELINING
2015.10.15 11:01:31 LOG7[0]:  <- 250-DSN
2015.10.15 11:01:31 LOG7[0]:  <- 250-ENHANCEDSTATUSCODES
2015.10.15 11:01:31 LOG7[0]:  <- 250-8bitmime
2015.10.15 11:01:31 LOG7[0]:  <- 250-BINARYMIME
2015.10.15 11:01:31 LOG7[0]:  <- 250-CHUNKING
2015.10.15 11:01:31 LOG7[0]:  <- 250-VRFY
2015.10.15 11:01:31 LOG7[0]:  <- 250-TLS
2015.10.15 11:01:31 LOG7[0]:  <- 250-STARTTLS
2015.10.15 11:01:31 LOG7[0]:  <- 250 OK
2015.10.15 11:01:31 LOG7[0]:  -> STARTTLS
2015.10.15 11:01:31 LOG7[0]:  <- 220 2.0.0 SMTP server ready
2015.10.15 11:01:31 LOG6[0]: SNI: sending servername: smtp-mail.outlook.com
2015.10.15 11:01:31 LOG7[0]: SSL state (connect): before/connect initialization
2015.10.15 11:01:31 LOG7[0]: SSL state (connect): SSLv2/v3 write client hello A
2015.10.15 11:01:31 LOG7[0]: SSL state (connect): SSLv3 read server hello A
2015.10.15 11:01:31 LOG7[0]: Verification started at depth=2: C=BE,
O=GlobalSign nv-sa, OU=Root CA, CN=GlobalSign Root CA
2015.10.15 11:01:31 LOG7[0]: CERT: Pre-verification succeeded
2015.10.15 11:01:31 LOG7[0]: OCSP: Ignoring root certificate
2015.10.15 11:01:31 LOG6[0]: Certificate accepted at depth=2: C=BE,
O=GlobalSign nv-sa, OU=Root CA, CN=GlobalSign Root CA
2015.10.15 11:01:31 LOG7[0]: Verification started at depth=1: C=BE,
O=GlobalSign nv-sa, CN=GlobalSign Organization Validation CA - G2
2015.10.15 11:01:31 LOG7[0]: CERT: Pre-verification succeeded
2015.10.15 11:01:31 LOG5[0]: OCSP: Connecting the AIA responder
"http://ocsp.globalsign.com/rootr1"
2015.10.15 11:01:31 LOG6[0]: s_connect: connecting 108.162.232.204:80
2015.10.15 11:01:31 LOG7[0]: s_connect: s_poll_wait
108.162.232.204:80: waiting 10 seconds
2015.10.15 11:01:31 LOG5[0]: s_connect: connected 108.162.232.204:80
2015.10.15 11:01:31 LOG7[0]: OCSP: Connected ocsp.globalsign.com:80
2015.10.15 11:01:31 LOG7[0]: OCSP: Response received
2015.10.15 11:01:31 LOG6[0]: OCSP: Status: good
2015.10.15 11:01:31 LOG6[0]: OCSP: This update: Oct 15 10:27:35 2015 GMT
2015.10.15 11:01:31 LOG6[0]: OCSP: Next update: Oct 19 10:27:35 2015 GMT
2015.10.15 11:01:31 LOG5[0]: OCSP: Certificate accepted
2015.10.15 11:01:31 LOG6[0]: Certificate accepted at depth=1: C=BE,
O=GlobalSign nv-sa, CN=GlobalSign Organization Validation CA - G2
2015.10.15 11:01:31 LOG7[0]: Verification started at depth=0: C=US,
ST=Washington, L=Redmond, O=Microsoft Corporation, CN=*.hotmail.com
2015.10.15 11:01:31 LOG7[0]: CERT: Pre-verification succeeded
2015.10.15 11:01:31 LOG6[0]: CERT: Host name "smtp-mail.outlook.com"
matched with "*.outlook.com"
2015.10.15 11:01:31 LOG5[0]: OCSP: Connecting the AIA responder
"http://ocsp2.globalsign.com/gsorganizationvalg2"
2015.10.15 11:01:31 LOG6[0]: s_connect: connecting 108.162.232.196:80
2015.10.15 11:01:31 LOG7[0]: s_connect: s_poll_wait
108.162.232.196:80: waiting 10 seconds
2015.10.15 11:01:31 LOG5[0]: s_connect: connected 108.162.232.196:80
2015.10.15 11:01:31 LOG7[0]: OCSP: Connected ocsp2.globalsign.com:80
2015.10.15 11:01:31 LOG7[0]: OCSP: Response received
2015.10.15 11:01:31 LOG6[0]: OCSP: Status: good
2015.10.15 11:01:31 LOG6[0]: OCSP: This update: Oct 15 08:26:15 2015 GMT
2015.10.15 11:01:31 LOG6[0]: OCSP: Next update: Oct 16 08:26:15 2015 GMT
2015.10.15 11:01:31 LOG5[0]: OCSP: Certificate accepted
2015.10.15 11:01:31 LOG5[0]: Certificate accepted at depth=0: C=US,
ST=Washington, L=Redmond, O=Microsoft Corporation, CN=*.hotmail.com
2015.10.15 11:01:31 LOG7[0]: SSL state (connect): SSLv3 read server
certificate A
2015.10.15 11:01:31 LOG7[0]: SSL state (connect): SSLv3 read server
key exchange A
2015.10.15 11:01:31 LOG7[0]: SSL state (connect): SSLv3 read server done A
2015.10.15 11:01:31 LOG7[0]: SSL state (connect): SSLv3 write client
key exchange A
2015.10.15 11:01:31 LOG7[0]: SSL state (connect): SSLv3 write change
cipher spec A
2015.10.15 11:01:31 LOG7[0]: SSL state (connect): SSLv3 write finished A
2015.10.15 11:01:31 LOG7[0]: SSL state (connect): SSLv3 flush data
2015.10.15 11:01:31 LOG7[0]: SSL state (connect): SSLv3 read finished A
2015.10.15 11:01:31 LOG7[0]:      1 client connect(s) requested
2015.10.15 11:01:31 LOG7[0]:      1 client connect(s) succeeded
2015.10.15 11:01:31 LOG7[0]:      0 client renegotiation(s) requested
2015.10.15 11:01:31 LOG7[0]:      0 session reuse(s)
2015.10.15 11:01:31 LOG6[0]: SSL connected: new session negotiated
2015.10.15 11:01:31 LOG7[0]: Peer certificate was cached (3461 bytes)
2015.10.15 11:01:31 LOG6[0]: Negotiated TLSv1.2 ciphersuite
ECDHE-RSA-AES256-SHA384 (256-bit encryption)
2015.10.15 11:01:31 LOG7[0]: Compression: null, expansion: null
2015.10.15 11:01:31 LOG6[0]: SSL socket closed (SSL_read)
2015.10.15 11:01:31 LOG7[0]: Sent socket write shutdown
2015.10.15 11:01:31 LOG5[0]: Connection closed: 139 byte(s) sent to
SSL, 351 byte(s) sent to socket
2015.10.15 11:01:31 LOG7[0]: Remote descriptor (FD=704) closed
2015.10.15 11:01:31 LOG7[0]: Local descriptor (FD=692) closed
2015.10.15 11:01:31 LOG7[0]: Service [outlook-smtp] finished (0 left)

I don't see any errors in the log, but Outlook is reporting an
incorrect password on the security section of my Microsoft Account.
More specifically, I'm seeing error 5.7.3: Requested action aborted,
user not authenticated," I know the password works because I set it up
as an account in Outlook 2010 and tested sending the email. It works
great. I am using 2FA with an app-specific password. But I have also
tried without 2FA. I am 100% certain the account name xxxx at outlook.com
and the password are correct. As far as the config file goes, I've
tried just about everything I could find on Google. Nothing works,
always the same error message.

I also experienced similar failures with Gmail.

Any ideas?