[stunnel-users] transfer: s_poll_wait: TIMEOUTclose exceeded: closing
Michael Calder
MCalder at globalscape.com
Tue Dec 29 19:02:33 CET 2015
Hi,
I'm new to stunnel and I'm trying to troubleshoot why it currently isn't working. When I first set it up and tested it everything worked fine. I rebuilt everything to do it all again and now it's not working. I'm pretty sure I set everything up the same way. I'm trying to get it to work with AWS SES. Here is my stunnel config:
; Sample stunnel configuration file for Win32 by Michal Trojnara 2002-2015
; Some options used here may be inadequate for your particular configuration
; This sample file does *not* represent stunnel.conf defaults
; Please consult the manual for detailed description of available options
; **************************************************************************
; * Global options *
; **************************************************************************
; Debugging stuff (may be useful for troubleshooting)
debug = debug
;output = stunnel.log
; Enable FIPS 140-2 mode if needed for compliance
;fips = yes
; Microsoft CryptoAPI engine allows for authentication with private keys
; stored in the Windows certificate store
; Each section using this feature also needs the "engineId = capi" option
;engine = capi
; **************************************************************************
; * Service defaults may also be specified in individual service sections *
; **************************************************************************
; Enable support for the insecure SSLv3 protocol
;options = -NO_SSLv3
; These options provide additional security at some performance degradation
;options = SINGLE_ECDH_USE
;options = SINGLE_DH_USE
; **************************************************************************
; * Include all configuration file fragments from the specified folder *
; **************************************************************************
;include = conf.d
; **************************************************************************
; * Service definitions (at least one service has to be defined) *
; **************************************************************************
; ***************************************** Example TLS client mode services
[gmail-pop3]
client = yes
accept = 127.0.0.1:110
connect = pop.gmail.com:995
verify = 2
CAfile = ca-certs.pem
checkHost = pop.gmail.com
OCSPaia = yes
[gmail-imap]
client = yes
accept = 127.0.0.1:143
connect = imap.gmail.com:993
verify = 2
CAfile = ca-certs.pem
checkHost = imap.gmail.com
OCSPaia = yes
[gmail-smtp]
client = yes
accept = 127.0.0.1:25
connect = smtp.gmail.com:465
verify = 2
CAfile = ca-certs.pem
checkHost = smtp.gmail.com
OCSPaia = yes
; Encrypted HTTP proxy authenticated with a client certificate
; located in the Windows certificate store
;[example-proxy]
;client = yes
;accept = 127.0.0.1:8080
;connect = example.com:8443
;engineId = capi
; ***************************************** Example TLS server mode services
;[pop3s]
;accept = 995
;connect = 110
;cert = stunnel.pem
;[imaps]
;accept = 993
;connect = 143
;cert = stunnel.pem
;[ssmtp]
;accept = 465
;connect = 25
;cert = stunnel.pem
; TLS front-end to a web server
;[https]
;accept = 443
;connect = 80
;cert = stunnel.pem
; "TIMEOUTclose = 0" is a workaround for a design flaw in Microsoft SChannel
; Microsoft implementations do not use TLS close-notify alert and thus they
; are vulnerable to truncation attacks
;TIMEOUTclose = 0
; Remote cmd.exe protected with PSK-authenticated TLS
; Create "secrets.txt" containing IDENTITY:KEY pairs
;[cmd]
;accept = 1337
;exec = c:\windows\system32\cmd.exe
;execArgs = cmd.exe
;ciphers = PSK
;PSKsecrets = secrets.txt
; vim:ft=dosini
[smtp-tls-wrapper]
accept = 2525
client = yes
connect = email-smtp.us-east-1.amazonaws.com:2465
delay = yes
Here is the debug from the log file:
2015.12.29 17:42:38 LOG7[main]: No limit detected for the number of clients
2015.12.29 17:42:38 LOG5[main]: stunnel 5.28 on x86-pc-msvc-1500 platform
2015.12.29 17:42:38 LOG5[main]: Compiled/running with OpenSSL 1.0.2e-fips 3 Dec 2015
2015.12.29 17:42:38 LOG5[main]: Threading:WIN32 Sockets:SELECT,IPv6 TLS:ENGINE,FIPS,OCSP,PSK,SNI
2015.12.29 17:42:38 LOG7[main]: errno: (*_errno())
2015.12.29 17:42:38 LOG5[main]: Reading configuration from file stunnel.conf
2015.12.29 17:42:38 LOG5[main]: UTF-8 byte order mark detected
2015.12.29 17:42:38 LOG5[main]: FIPS mode disabled
2015.12.29 17:42:38 LOG7[main]: Compression disabled
2015.12.29 17:42:38 LOG7[main]: Snagged 64 random bytes from C:/.rnd
2015.12.29 17:42:38 LOG7[main]: Wrote 1024 new random bytes to C:/.rnd
2015.12.29 17:42:38 LOG7[main]: PRNG seeded successfully
2015.12.29 17:42:38 LOG6[main]: Initializing service [gmail-pop3]
2015.12.29 17:42:38 LOG7[ui]: GUI message loop initialized
2015.12.29 17:42:38 LOG7[cron]: Cron thread initialized
2015.12.29 17:42:38 LOG7[main]: No certificate or private key specified
2015.12.29 17:42:38 LOG7[main]: SSL options: 0x03000004 (+0x03000000, -0x00000000)
2015.12.29 17:42:38 LOG6[main]: Initializing service [gmail-imap]
2015.12.29 17:42:38 LOG7[main]: No certificate or private key specified
2015.12.29 17:42:38 LOG7[main]: SSL options: 0x03000004 (+0x03000000, -0x00000000)
2015.12.29 17:42:38 LOG6[main]: Initializing service [gmail-smtp]
2015.12.29 17:42:38 LOG7[main]: No certificate or private key specified
2015.12.29 17:42:38 LOG7[main]: SSL options: 0x03000004 (+0x03000000, -0x00000000)
2015.12.29 17:42:38 LOG6[main]: Initializing service [smtp-tls-wrapper]
2015.12.29 17:42:38 LOG7[main]: No certificate or private key specified
2015.12.29 17:42:38 LOG4[main]: Service [smtp-tls-wrapper] needs authentication to prevent MITM attacks
2015.12.29 17:42:38 LOG7[main]: SSL options: 0x03000004 (+0x03000000, -0x00000000)
2015.12.29 17:42:38 LOG5[main]: Configuration successful
2015.12.29 17:42:38 LOG7[main]: Listening file descriptor created (FD=372)
2015.12.29 17:42:38 LOG7[main]: Service [gmail-pop3] (FD=372) bound to 127.0.0.1:110
2015.12.29 17:42:38 LOG7[main]: Listening file descriptor created (FD=376)
2015.12.29 17:42:38 LOG7[main]: Service [gmail-imap] (FD=376) bound to 127.0.0.1:143
2015.12.29 17:42:38 LOG7[main]: Listening file descriptor created (FD=380)
2015.12.29 17:42:38 LOG7[main]: Service [gmail-smtp] (FD=380) bound to 127.0.0.1:25
2015.12.29 17:42:38 LOG7[main]: Listening file descriptor created (FD=384)
2015.12.29 17:42:38 LOG7[main]: Service [smtp-tls-wrapper] (FD=384) bound to 0.0.0.0:2525
2015.12.29 17:43:25 LOG7[main]: Found 1 ready file descriptor(s)
2015.12.29 17:43:25 LOG7[main]: FD=332 ifds=r-x ofds=---
2015.12.29 17:43:25 LOG7[main]: FD=372 ifds=r-x ofds=---
2015.12.29 17:43:25 LOG7[main]: FD=376 ifds=r-x ofds=---
2015.12.29 17:43:25 LOG7[main]: FD=380 ifds=r-x ofds=---
2015.12.29 17:43:25 LOG7[main]: Service [smtp-tls-wrapper] accepted (FD=444) from 127.0.0.1:49510
2015.12.29 17:43:25 LOG7[main]: Creating a new thread
2015.12.29 17:43:25 LOG7[main]: New thread created
2015.12.29 17:43:25 LOG7[0]: Service [smtp-tls-wrapper] started
2015.12.29 17:43:25 LOG5[0]: Service [smtp-tls-wrapper] accepted connection from 127.0.0.1:49510
2015.12.29 17:43:25 LOG6[0]: failover: round-robin, starting at entry #0
2015.12.29 17:43:25 LOG6[0]: s_connect: connecting 54.243.71.143:2465
2015.12.29 17:43:25 LOG7[0]: s_connect: s_poll_wait 54.243.71.143:2465: waiting 10 seconds
2015.12.29 17:43:25 LOG5[0]: s_connect: connected 54.243.71.143:2465
2015.12.29 17:43:25 LOG5[0]: Service [smtp-tls-wrapper] connected remote server from 172.31.49.212:49511
2015.12.29 17:43:25 LOG7[0]: Remote descriptor (FD=468) initialized
2015.12.29 17:43:25 LOG6[0]: SNI: sending servername: email-smtp.us-east-1.amazonaws.com
2015.12.29 17:43:25 LOG7[0]: SSL state (connect): before/connect initialization
2015.12.29 17:43:25 LOG7[0]: SSL state (connect): SSLv2/v3 write client hello A
2015.12.29 17:43:25 LOG7[0]: SSL state (connect): SSLv3 read server hello A
2015.12.29 17:43:25 LOG6[0]: Certificate verification disabled
2015.12.29 17:43:25 LOG6[0]: Certificate verification disabled
2015.12.29 17:43:25 LOG7[0]: SSL state (connect): SSLv3 read server certificate A
2015.12.29 17:43:25 LOG7[0]: SSL state (connect): SSLv3 read server key exchange A
2015.12.29 17:43:25 LOG7[0]: SSL state (connect): SSLv3 read server done A
2015.12.29 17:43:25 LOG7[0]: SSL state (connect): SSLv3 write client key exchange A
2015.12.29 17:43:25 LOG7[0]: SSL state (connect): SSLv3 write change cipher spec A
2015.12.29 17:43:25 LOG7[0]: SSL state (connect): SSLv3 write finished A
2015.12.29 17:43:25 LOG7[0]: SSL state (connect): SSLv3 flush data
2015.12.29 17:43:25 LOG7[0]: SSL state (connect): SSLv3 read server session ticket A
2015.12.29 17:43:25 LOG7[0]: SSL state (connect): SSLv3 read finished A
2015.12.29 17:43:25 LOG7[0]: 1 client connect(s) requested
2015.12.29 17:43:25 LOG7[0]: 1 client connect(s) succeeded
2015.12.29 17:43:25 LOG7[0]: 0 client renegotiation(s) requested
2015.12.29 17:43:25 LOG7[0]: 0 session reuse(s)
2015.12.29 17:43:25 LOG6[0]: SSL connected: new session negotiated
2015.12.29 17:43:25 LOG7[0]: Peer certificate was cached (3667 bytes)
2015.12.29 17:43:25 LOG6[0]: Negotiated TLSv1.2 ciphersuite ECDHE-RSA-AES128-GCM-SHA256 (128-bit encryption)
2015.12.29 17:43:25 LOG7[0]: Compression: null, expansion: null
2015.12.29 17:43:36 LOG7[0]: SSL alert (read): warning: close notify
2015.12.29 17:43:36 LOG6[0]: SSL closed (SSL_read)
2015.12.29 17:43:36 LOG7[0]: Sent socket write shutdown
2015.12.29 17:43:38 LOG6[cron]: Executing cron jobs
2015.12.29 17:43:38 LOG6[cron]: Cron jobs completed in 0 seconds
2015.12.29 17:43:38 LOG7[cron]: Waiting 86400 seconds
2015.12.29 17:44:36 LOG3[0]: transfer: s_poll_wait: TIMEOUTclose exceeded: closing
2015.12.29 17:44:36 LOG5[0]: Connection closed: 995 byte(s) sent to SSL, 397 byte(s) sent to socket
2015.12.29 17:44:36 LOG7[0]: Remote descriptor (FD=468) closed
2015.12.29 17:44:36 LOG7[0]: Local descriptor (FD=444) closed
2015.12.29 17:44:36 LOG7[0]: Service [smtp-tls-wrapper] finished (0 left)
I've searched the web for that TIMEOUTclose message and haven't come up with a solution. I've also attached a packet capture. Any suggestions would be helpful.
Thanks!
Mike
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://www.stunnel.org/pipermail/stunnel-users/attachments/20151229/068e2157/attachment.html>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: stunnel.pcapng
Type: application/octet-stream
Size: 501336 bytes
Desc: stunnel.pcapng
URL: <http://www.stunnel.org/pipermail/stunnel-users/attachments/20151229/068e2157/attachment.obj>
More information about the stunnel-users
mailing list