[stunnel-users] transfer: s_poll_wait: TIMEOUTclose exceeded: closing

• Previous message (by thread): [stunnel-users] stunnel 5.28 released
• Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]

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>

• Previous message (by thread): [stunnel-users] stunnel 5.28 released
• Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]