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