[stunnel-users] Incoming port ignored
Ivan De Masi
de_masi at blu-it.de
Wed Mar 30 09:58:59 CEST 2016
Hello,
I have a strange problem with my stunnel since a view days:
I installed stunnel, because my AV-Scanner (Avira) is not able to scan
e-mail traffic of encrypted connections to my mailprovider.
So I configured both mail-clients (Thunderbird & Outlook) and AV-Scanner to
listen on localhost and stunnel to connect to my mailprovider.
This was working fine for a view days, but stoped some days ago and I'm not
shure why. Maybe when I installed stunnel as a daemon I run into trouble
(will bw another subject).
The encrypted connection to my mailprovider is working and e-mails are
recived and sent, but the AV-scanner doesn't "see" them anymore.
I examined the log and what makes me wonder is, that the when fetching the
e-mails, the configured ports (110/143/25) seem to be ignored:
"Service [df-pop3s] accepted connection from 127.0.0.1:1878" or "Service
[df-pop3s] accepted (FD=472) from 127.0.0.1:1882"
The mails on my host are always bypassed on another port (the longer I run
stunnel they change/increase) - see the log file.
I have installed latest stunnel version (5.31) on Windows 7 (x86).
Any ideas?
Kind regards,
Ivan
Main-config:
[df-pop3s]
client = yes
accept = 127.0.0.1:110
connect = sslin.df.eu:995
verify = 3
CAfile = peer-df-pop3s.pem
checkHost = sslin.df.eu
OCSPaia = yes
[df-imaps]
client = yes
accept = 127.0.0.1:143
connect = sslin.df.eu:993
verify = 3
CAfile = peer-df-imaps.pem
checkHost = sslin.df.eu
OCSPaia = yes
[df-smtps]
client = yes
accept = 127.0.0.1:25
connect = sslout.df.eu:465
verify = 3
CAfile = peer-df-smtps.pem
checkHost = sslout.df.eu
OCSPaia = yes
Log:
2016.03.30 09:22:21 LOG7[main]: No limit detected for the number of clients
2016.03.30 09:22:21 LOG7[cron]: Cron thread initialized
2016.03.30 09:22:21 LOG5[main]: stunnel 5.31 on x86-pc-msvc-1500 platform
2016.03.30 09:22:21 LOG5[main]: Compiled/running with OpenSSL 1.0.2g-fips 1
Mar 2016
2016.03.30 09:22:21 LOG5[main]: Threading:WIN32 Sockets:SELECT,IPv6
TLS:ENGINE,FIPS,OCSP,PSK,SNI
2016.03.30 09:22:21 LOG7[main]: errno: (*_errno())
2016.03.30 09:22:21 LOG7[ui]: GUI message loop initialized
2016.03.30 09:22:21 LOG5[main]: Reading configuration from file stunnel.conf
2016.03.30 09:22:21 LOG5[main]: UTF-8 byte order mark detected
2016.03.30 09:22:21 LOG5[main]: FIPS mode enabled
2016.03.30 09:22:21 LOG7[main]: Compression disabled
2016.03.30 09:22:21 LOG7[main]: Snagged 64 random bytes from C:/.rnd
2016.03.30 09:22:21 LOG7[main]: Wrote 0 new random bytes to C:/.rnd
2016.03.30 09:22:21 LOG7[main]: PRNG seeded successfully
2016.03.30 09:22:21 LOG6[main]: Initializing service [df-pop3s]
2016.03.30 09:22:23 LOG7[main]: No certificate or private key specified
2016.03.30 09:22:23 LOG7[main]: SSL options: 0x03000004 (+0x03000000l,
-0x00000000)
2016.03.30 09:22:23 LOG6[main]: Initializing service [df-imaps]
2016.03.30 09:22:23 LOG7[main]: No certificate or private key specified
2016.03.30 09:22:23 LOG7[main]: SSL options: 0x03000004 (+0x03000000,
-0x00000000)
2016.03.30 09:22:23 LOG6[main]: Initializing service [df-smtps]
2016.03.30 09:22:23 LOG7[main]: No certificate or private key specified
2016.03.30 09:22:23 LOG7[main]: SSL options: 0x03000004 (+0x03000000,
-0x00000000)
2016.03.30 09:22:23 LOG5[main]: Configuration successful
2016.03.30 09:22:23 LOG7[main]: Listening file descriptor created (FD=428)
2016.03.30 09:22:23 LOG7[main]: Service [df-pop3s] (FD=428) bound to
127.0.0.1:110
2016.03.30 09:22:23 LOG7[main]: Listening file descriptor created (FD=432)
2016.03.30 09:22:23 LOG7[main]: Service [df-imaps] (FD=432) bound to
127.0.0.1:143
2016.03.30 09:22:23 LOG7[main]: Listening file descriptor created (FD=436)
2016.03.30 09:22:23 LOG7[main]: Service [df-smtps] (FD=436) bound to
127.0.0.1:25
2016.03.30 09:22:42 LOG7[main]: Found 1 ready file descriptor(s)
2016.03.30 09:22:42 LOG7[main]: FD=352 ifds=r-x ofds=---
2016.03.30 09:22:42 LOG7[main]: FD=428 ifds=r-x ofds=r--
2016.03.30 09:22:42 LOG7[main]: FD=432 ifds=r-x ofds=---
2016.03.30 09:22:42 LOG7[main]: Service [df-pop3s] accepted (FD=460) from
127.0.0.1:1878
2016.03.30 09:22:42 LOG7[main]: Creating a new thread
2016.03.30 09:22:42 LOG7[main]: New thread created
2016.03.30 09:22:42 LOG7[0]: Service [df-pop3s] started
2016.03.30 09:22:42 LOG5[0]: Service [df-pop3s] accepted connection from
127.0.0.1:1878
2016.03.30 09:22:42 LOG6[0]: s_connect: connecting 134.119.18.26:995
2016.03.30 09:22:42 LOG7[0]: s_connect: s_poll_wait 134.119.18.26:995:
waiting 10 seconds
2016.03.30 09:22:42 LOG5[0]: s_connect: connected 134.119.18.26:995
2016.03.30 09:22:42 LOG5[0]: Service [df-pop3s] connected remote server from
192.168.1.2:1879
2016.03.30 09:22:42 LOG7[0]: Remote descriptor (FD=484) initialized
2016.03.30 09:22:42 LOG6[0]: SNI: sending servername: sslin.df.eu
2016.03.30 09:22:42 LOG7[0]: SSL state (connect): before/connect
initialization
2016.03.30 09:22:42 LOG7[0]: SSL state (connect): SSLv2/v3 write client
hello A
2016.03.30 09:22:42 LOG7[0]: SSL state (connect): SSLv3 read server hello A
2016.03.30 09:22:42 LOG7[0]: Verification started at depth=2: C=BE,
O=GlobalSign nv-sa, OU=Root CA, CN=GlobalSign Root CA
2016.03.30 09:22:42 LOG7[0]: CERT: Pre-verification succeeded
2016.03.30 09:22:42 LOG7[0]: OCSP: Ignoring root certificate
2016.03.30 09:22:42 LOG6[0]: Certificate accepted at depth=2: C=BE,
O=GlobalSign nv-sa, OU=Root CA, CN=GlobalSign Root CA
2016.03.30 09:22:42 LOG7[0]: Verification started at depth=1: C=BE,
O=GlobalSign nv-sa, CN=AlphaSSL CA - SHA256 - G2
2016.03.30 09:22:42 LOG7[0]: CERT: Pre-verification succeeded
2016.03.30 09:22:42 LOG5[0]: OCSP: Connecting the AIA responder
"http://ocsp.globalsign.com/rootr1"
2016.03.30 09:22:46 LOG6[0]: s_connect: connecting 104.16.25.216:80
2016.03.30 09:22:46 LOG7[0]: s_connect: s_poll_wait 104.16.25.216:80:
waiting 10 seconds
2016.03.30 09:22:46 LOG5[0]: s_connect: connected 104.16.25.216:80
2016.03.30 09:22:46 LOG7[0]: OCSP: Connected ocsp.globalsign.com:80
2016.03.30 09:22:46 LOG7[0]: OCSP: Response received
2016.03.30 09:22:46 LOG6[0]: OCSP: Status: good
2016.03.30 09:22:46 LOG6[0]: OCSP: This update: Mar 30 05:42:27 2016 GMT
2016.03.30 09:22:46 LOG6[0]: OCSP: Next update: Apr 3 05:42:27 2016 GMT
2016.03.30 09:22:46 LOG5[0]: OCSP: Certificate accepted
2016.03.30 09:22:46 LOG6[0]: Certificate accepted at depth=1: C=BE,
O=GlobalSign nv-sa, CN=AlphaSSL CA - SHA256 - G2
2016.03.30 09:22:46 LOG7[0]: Verification started at depth=0: C=DE,
OU=Domain Control Validated, CN=sslin.df.eu
2016.03.30 09:22:46 LOG7[0]: CERT: Pre-verification succeeded
2016.03.30 09:22:46 LOG6[0]: CERT: Host name "sslin.df.eu" matched with
"sslin.df.eu"
2016.03.30 09:22:46 LOG6[0]: CERT: Locally installed certificate matched
2016.03.30 09:22:46 LOG5[0]: OCSP: Connecting the AIA responder
"http://ocsp2.globalsign.com/gsalphasha2g2"
2016.03.30 09:22:46 LOG6[0]: s_connect: connecting 104.16.25.216:80
2016.03.30 09:22:46 LOG7[0]: s_connect: s_poll_wait 104.16.25.216:80:
waiting 10 seconds
2016.03.30 09:22:46 LOG5[0]: s_connect: connected 104.16.25.216:80
2016.03.30 09:22:46 LOG7[0]: OCSP: Connected ocsp2.globalsign.com:80
2016.03.30 09:22:46 LOG7[0]: OCSP: Response received
2016.03.30 09:22:46 LOG6[0]: OCSP: Status: good
2016.03.30 09:22:46 LOG6[0]: OCSP: This update: Mar 27 21:09:59 2016 GMT
2016.03.30 09:22:46 LOG6[0]: OCSP: Next update: Mar 31 21:09:59 2016 GMT
2016.03.30 09:22:46 LOG5[0]: OCSP: Certificate accepted
2016.03.30 09:22:46 LOG5[0]: Certificate accepted at depth=0: C=DE,
OU=Domain Control Validated, CN=sslin.df.eu
2016.03.30 09:22:46 LOG7[0]: SSL state (connect): SSLv3 read server
certificate A
2016.03.30 09:22:46 LOG7[0]: SSL state (connect): SSLv3 read server key
exchange A
2016.03.30 09:22:46 LOG6[0]: Client certificate not requested
2016.03.30 09:22:46 LOG7[0]: SSL state (connect): SSLv3 read server done A
2016.03.30 09:22:46 LOG7[0]: SSL state (connect): SSLv3 write client key
exchange A
2016.03.30 09:22:46 LOG7[0]: SSL state (connect): SSLv3 write change cipher
spec A
2016.03.30 09:22:46 LOG7[0]: SSL state (connect): SSLv3 write finished A
2016.03.30 09:22:46 LOG7[0]: SSL state (connect): SSLv3 flush data
2016.03.30 09:22:46 LOG7[0]: SSL state (connect): SSLv3 read server session
ticket A
2016.03.30 09:22:46 LOG7[0]: SSL state (connect): SSLv3 read finished A
2016.03.30 09:22:46 LOG7[0]: 1 client connect(s) requested
2016.03.30 09:22:46 LOG7[0]: 1 client connect(s) succeeded
2016.03.30 09:22:46 LOG7[0]: 0 client renegotiation(s) requested
2016.03.30 09:22:46 LOG7[0]: 0 session reuse(s)
2016.03.30 09:22:46 LOG6[0]: SSL connected: new session negotiated
2016.03.30 09:22:46 LOG7[0]: Peer certificate was cached (4539 bytes)
2016.03.30 09:22:46 LOG6[0]: Negotiated TLSv1.2 ciphersuite
ECDHE-RSA-AES128-GCM-SHA256 (128-bit encryption)
2016.03.30 09:22:46 LOG7[0]: Compression: null, expansion: null
2016.03.30 09:23:01 LOG7[0]: SSL alert (read): warning: close notify
2016.03.30 09:23:01 LOG6[0]: SSL closed (SSL_read)
2016.03.30 09:23:01 LOG7[0]: Sent socket write shutdown
2016.03.30 09:23:01 LOG6[0]: Read socket closed (readsocket)
2016.03.30 09:23:01 LOG7[0]: Sending close_notify alert
2016.03.30 09:23:01 LOG7[0]: SSL alert (write): warning: close notify
2016.03.30 09:23:01 LOG6[0]: SSL_shutdown successfully sent close_notify
alert
2016.03.30 09:23:01 LOG5[0]: Connection closed: 304 byte(s) sent to SSL,
545297 byte(s) sent to socket
2016.03.30 09:23:01 LOG7[0]: Remote descriptor (FD=484) closed
2016.03.30 09:23:01 LOG7[0]: Local descriptor (FD=460) closed
2016.03.30 09:23:01 LOG7[0]: Service [df-pop3s] finished (0 left)
2016.03.30 09:23:02 LOG7[main]: Found 1 ready file descriptor(s)
2016.03.30 09:23:02 LOG7[main]: FD=352 ifds=r-x ofds=---
2016.03.30 09:23:02 LOG7[main]: FD=428 ifds=r-x ofds=r--
2016.03.30 09:23:02 LOG7[main]: FD=432 ifds=r-x ofds=---
2016.03.30 09:23:02 LOG7[main]: Service [df-pop3s] accepted (FD=472) from
127.0.0.1:1882
2016.03.30 09:23:02 LOG7[main]: Creating a new thread
2016.03.30 09:23:02 LOG7[main]: New thread created
2016.03.30 09:23:02 LOG7[1]: Service [df-pop3s] started
2016.03.30 09:23:02 LOG5[1]: Service [df-pop3s] accepted connection from
127.0.0.1:1882
2016.03.30 09:23:02 LOG6[1]: s_connect: connecting 134.119.18.26:995
2016.03.30 09:23:02 LOG7[1]: s_connect: s_poll_wait 134.119.18.26:995:
waiting 10 seconds
2016.03.30 09:23:02 LOG5[1]: s_connect: connected 134.119.18.26:995
2016.03.30 09:23:02 LOG5[1]: Service [df-pop3s] connected remote server from
192.168.1.2:1883
2016.03.30 09:23:02 LOG7[1]: Remote descriptor (FD=468) initialized
2016.03.30 09:23:02 LOG6[1]: SNI: sending servername: sslin.df.eu
2016.03.30 09:23:02 LOG7[1]: SSL state (connect): before/connect
initialization
2016.03.30 09:23:02 LOG7[1]: SSL state (connect): SSLv3 write client hello A
2016.03.30 09:23:02 LOG7[1]: SSL state (connect): SSLv3 read server hello A
2016.03.30 09:23:02 LOG7[1]: SSL state (connect): SSLv3 read finished A
2016.03.30 09:23:02 LOG7[1]: SSL state (connect): SSLv3 write change cipher
spec A
2016.03.30 09:23:02 LOG7[1]: SSL state (connect): SSLv3 write finished A
2016.03.30 09:23:02 LOG7[1]: SSL state (connect): SSLv3 flush data
2016.03.30 09:23:02 LOG7[1]: 2 client connect(s) requested
2016.03.30 09:23:02 LOG7[1]: 2 client connect(s) succeeded
2016.03.30 09:23:02 LOG7[1]: 0 client renegotiation(s) requested
2016.03.30 09:23:02 LOG7[1]: 1 session reuse(s)
2016.03.30 09:23:02 LOG6[1]: SSL connected: previous session reused
2016.03.30 09:23:08 LOG7[1]: SSL alert (read): warning: close notify
2016.03.30 09:23:08 LOG6[1]: SSL closed (SSL_read)
2016.03.30 09:23:08 LOG7[1]: Sent socket write shutdown
2016.03.30 09:23:08 LOG6[1]: Read socket closed (readsocket)
2016.03.30 09:23:08 LOG7[1]: Sending close_notify alert
2016.03.30 09:23:08 LOG7[1]: SSL alert (write): warning: close notify
2016.03.30 09:23:08 LOG6[1]: SSL_shutdown successfully sent close_notify
alert
2016.03.30 09:23:08 LOG5[1]: Connection closed: 149 byte(s) sent to SSL,
336471 byte(s) sent to socket
2016.03.30 09:23:08 LOG7[1]: Remote descriptor (FD=468) closed
2016.03.30 09:23:08 LOG7[1]: Local descriptor (FD=472) closed
2016.03.30 09:23:08 LOG7[1]: Service [df-pop3s] finished (0 left)
2016.03.30 09:23:21 LOG6[cron]: Executing cron jobs
2016.03.30 09:23:21 LOG6[cron]: Cron jobs completed in 0 seconds
2016.03.30 09:23:21 LOG7[cron]: Waiting 86400 seconds
More information about the stunnel-users
mailing list