[stunnel-users] It doesn't work.

Mon Mar 11 14:25:19 CET 2013

Hi ,

i have following issue with latest version of stunnel and openssl.

version
======
stunnel - 4.55
openssl - 1.0.1e

stunnel.conf
==========
# Sample stunnel configuration file
# Copyright by Michal Trojnara 2002
# Comment it out on Win32
#cert = /etc/tr69/stunnel.pem
key = /etc/tr69/stunnel.pem
# chroot = /usr/local/var/run/stunnel/
# PID is created inside chroot jail
pid = /var/run/ssl.pid
setuid = root
setgid = root
# Protocol version (all, SSLv2, SSLv3, TLSv1)
sslVersion = TLSv1.2
# Workaround for Eudora bug
#options = DONT_INSERT_EMPTY_FRAGMENTS
# Authentication stuff
verify = 1
# don't forget about c_rehash CApath
# it is located inside chroot jail:
#CApath = /certs
# or simply use CAfile instead:
#CAfile = /usr/local/etc/stunnel/certs.pem
#CAfile = /etc/tr69/ca.crt
# CRL path or file (inside chroot jail):
#CRLpath = /crls
# or simply use CAfile instead:
#CRLfile = /usr/local/etc/stunnel/crls.pem
# Some debugging stuff
debug = 7
output = /var/log/ssl.log
foreground = yes
# Use it for client mode
client = yes
# Service-level configuration
[https]
CAfile = /flash/Cert.pem
accept  = 127.0.0.1:8001
connect = acs.qacafe.com:80
#accept  = 8080

cat /var/log/ssl.log
==============

2013.03.11 18:29:04 LOG5[5849:0]: stunnel 4.55 on mips-openwrt-linux-uclibc
platform
2013.03.11 18:29:04 LOG5[5849:0]: Compiled/running with OpenSSL 1.0.1e 11
Feb 2013
2013.03.11 18:29:04 LOG5[5849:0]: Threading:FORK SSL:+ENGINE+OCSP Auth:none
Sockets:POLL+IPv6
2013.03.11 18:29:04 LOG5[5849:0]: Reading configuration from file
/etc/tr69/stunnel.conf
2013.03.11 18:29:04 LOG7[5849:0]: Compression not enabled
2013.03.11 18:29:04 LOG7[5849:0]: PRNG seeded successfully
2013.03.11 18:29:04 LOG6[5849:0]: Initializing service [https]
2013.03.11 18:29:04 LOG4[5849:0]: Insecure file permissions on
/etc/tr69/stunnel.pem
2013.03.11 18:29:04 LOG7[5849:0]: Loaded verify certificates from
/flash/Cert.pem
2013.03.11 18:29:04 LOG7[5849:0]: Loaded /flash/Cert.pem revocation lookup
file
2013.03.11 18:29:04 LOG7[5849:0]: SSL options set: 0x00000004
2013.03.11 18:29:04 LOG5[5849:0]: Configuration successful
2013.03.11 18:29:04 LOG7[5849:0]: Service [https] (FD=17) bound to
127.0.0.1:8001
2013.03.11 18:29:04 LOG7[5849:0]: Created pid file /var/run/ssl.pid
2013.03.11 18:29:21 LOG7[5849:0]: Service [https] accepted (FD=4) from
127.0.0.1:36039
2013.03.11 18:29:21 LOG7[5920:0]: Service [https] started
2013.03.11 18:29:21 LOG5[5920:0]: Service [https] accepted connection from
127.0.0.1:36039
2013.03.11 18:29:22 LOG6[5920:0]: connect_blocking: connecting 6.0.0.1:80
2013.03.11 18:29:22 LOG7[5920:0]: connect_blocking: s_poll_wait 6.0.0.1:80:
waiting 10 seconds
2013.03.11 18:29:22 LOG5[5920:0]: connect_blocking: connected 6.0.0.1:80
2013.03.11 18:29:22 LOG5[5920:0]: Service [https] connected remote server
from 61.200.100.100:35694
2013.03.11 18:29:22 LOG7[5920:0]: Remote socket (FD=17) initialized
2013.03.11 18:29:22 LOG7[5920:0]: SNI: sending servername: acs.qacafe.com
2013.03.11 18:29:22 LOG7[5920:0]: SSL state (connect): before/connect
initialization
2013.03.11 18:29:22 LOG7[5920:0]: SSL state (connect): SSLv3 write client
hello A
2013.03.11 18:30:15 LOG7[5849:0]: Service [https] accepted (FD=4) from
127.0.0.1:36042
2013.03.11 18:30:15 LOG7[5973:0]: Service [https] started
2013.03.11 18:30:15 LOG5[5973:0]: Service [https] accepted connection from
127.0.0.1:36042
2013.03.11 18:30:15 LOG6[5973:0]: connect_blocking: connecting 6.0.0.1:80
2013.03.11 18:30:15 LOG7[5973:0]: connect_blocking: s_poll_wait 6.0.0.1:80:
waiting 10 seconds
2013.03.11 18:30:15 LOG5[5973:0]: connect_blocking: connected 6.0.0.1:80
2013.03.11 18:30:15 LOG5[5973:0]: Service [https] connected remote server
from 61.200.100.100:35697
2013.03.11 18:30:15 LOG7[5973:0]: Remote socket (FD=17) initialized
2013.03.11 18:30:15 LOG7[5973:0]: SNI: sending servername: acs.qacafe.com
2013.03.11 18:30:15 LOG7[5973:0]: SSL state (connect): before/connect
initialization
2013.03.11 18:30:15 LOG7[5973:0]: SSL state (connect): SSLv3 write client
hello A
2013.03.11 18:31:40 LOG7[5849:0]: Service [https] accepted (FD=4) from
127.0.0.1:49029
2013.03.11 18:31:40 LOG7[6023:0]: Service [https] started
2013.03.11 18:31:40 LOG5[6023:0]: Service [https] accepted connection from
127.0.0.1:49029
2013.03.11 18:31:40 LOG6[6023:0]: connect_blocking: connecting 6.0.0.1:80
2013.03.11 18:31:40 LOG7[6023:0]: connect_blocking: s_poll_wait 6.0.0.1:80:
waiting 10 seconds
2013.03.11 18:31:40 LOG5[6023:0]: connect_blocking: connected 6.0.0.1:80
2013.03.11 18:31:40 LOG5[6023:0]: Service [https] connected remote server
from 61.200.100.100:40051
2013.03.11 18:31:40 LOG7[6023:0]: Remote socket (FD=17) initialized
2013.03.11 18:31:40 LOG7[6023:0]: SNI: sending servername: acs.qacafe.com
2013.03.11 18:31:40 LOG7[6023:0]: SSL state (connect): before/connect
initialization
2013.03.11 18:31:40 LOG7[6023:0]: SSL state (connect): SSLv3 write client
hello A
2013.03.11 18:33:45 LOG7[5849:0]: Service [https] accepted (FD=4) from
127.0.0.1:49032
2013.03.11 18:33:45 LOG7[6074:0]: Service [https] started
2013.03.11 18:33:45 LOG5[6074:0]: Service [https] accepted connection from
127.0.0.1:49032
2013.03.11 18:33:45 LOG6[6074:0]: connect_blocking: connecting 6.0.0.1:80
2013.03.11 18:33:45 LOG7[6074:0]: connect_blocking: s_poll_wait 6.0.0.1:80:
waiting 10 seconds
2013.03.11 18:33:45 LOG5[6074:0]: connect_blocking: connected 6.0.0.1:80
2013.03.11 18:33:45 LOG5[6074:0]: Service [https] connected remote server
from 61.200.100.100:40054
2013.03.11 18:33:45 LOG7[6074:0]: Remote socket (FD=17) initialized
2013.03.11 18:33:45 LOG7[6074:0]: SNI: sending servername: acs.qacafe.com
2013.03.11 18:33:45 LOG7[6074:0]: SSL state (connect): before/connect
initialization
2013.03.11 18:33:45 LOG7[6074:0]: SSL state (connect): SSLv3 write client
hello A
2013.03.11 18:34:22 LOG6[5920:0]: init_ssl: s_poll_wait: TIMEOUTbusy
exceeded: sending reset
2013.03.11 18:34:22 LOG5[5920:0]: Connection reset: 0 byte(s) sent to SSL,
0 byte(s) sent to socket
2013.03.11 18:34:22 LOG7[5920:0]: Remote socket (FD=17) closed
2013.03.11 18:34:22 LOG7[5920:0]: Local socket (FD=4) closed
2013.03.11 18:34:22 LOG7[5920:0]: Service [https] finished
2013.03.11 18:34:22 LOG7[5920:0]: str_stats: 19 block(s), 877 data byte(s),
798 control byte(s)
2013.03.11 18:34:22 LOG7[5849:0]: Dispatching signals from the signal pipe
2013.03.11 18:34:22 LOG7[5849:0]: Processing SIGCHLD
2013.03.11 18:34:22 LOG7[5849:0]: Process 5920 finished with code 0
2013.03.11 18:34:22 LOG7[5849:0]: Signal pipe is empty
2013.03.11 18:35:15 LOG6[5973:0]: init_ssl: s_poll_wait: TIMEOUTbusy
exceeded: sending reset
2013.03.11 18:35:15 LOG5[5973:0]: Connection reset: 0 byte(s) sent to SSL,
0 byte(s) sent to socket
2013.03.11 18:35:15 LOG7[5973:0]: Remote socket (FD=17) closed
2013.03.11 18:35:15 LOG7[5973:0]: Local socket (FD=4) closed
2013.03.11 18:35:15 LOG7[5973:0]: Service [https] finished
2013.03.11 18:35:15 LOG7[5973:0]: str_stats: 19 block(s), 877 data byte(s),
798 control byte(s)
2013.03.11 18:35:15 LOG7[5849:0]: Dispatching signals from the signal pipe
2013.03.11 18:35:15 LOG7[5849:0]: Processing SIGCHLD
2013.03.11 18:35:15 LOG7[5849:0]: Process 5973 finished with code 0
2013.03.11 18:35:15 LOG7[5849:0]: Signal pipe is empty
2013.03.11 18:36:40 LOG6[6023:0]: init_ssl: s_poll_wait: TIMEOUTbusy
exceeded: sending reset
2013.03.11 18:36:40 LOG5[6023:0]: Connection reset: 0 byte(s) sent to SSL,
0 byte(s) sent to socket
2013.03.11 18:36:40 LOG7[6023:0]: Remote socket (FD=17) closed
2013.03.11 18:36:40 LOG7[6023:0]: Local socket (FD=4) closed
2013.03.11 18:36:40 LOG7[6023:0]: Service [https] finished
2013.03.11 18:36:40 LOG7[6023:0]: str_stats: 19 block(s), 877 data byte(s),
798 control byte(s)
2013.03.11 18:36:40 LOG7[5849:0]: Dispatching signals from the signal pipe
2013.03.11 18:36:40 LOG7[5849:0]: Processing SIGCHLD
2013.03.11 18:36:40 LOG7[5849:0]: Process 6023 finished with code 0
2013.03.11 18:36:40 LOG7[5849:0]: Signal pipe is empty
2013.03.11 18:38:45 LOG6[6074:0]: init_ssl: s_poll_wait: TIMEOUTbusy
exceeded: sending reset
2013.03.11 18:38:45 LOG5[6074:0]: Connection reset: 0 byte(s) sent to SSL,
0 byte(s) sent to socket
2013.03.11 18:38:45 LOG7[6074:0]: Remote socket (FD=17) closed
2013.03.11 18:38:45 LOG7[6074:0]: Local socket (FD=4) closed
2013.03.11 18:38:45 LOG7[6074:0]: Service [https] finished
2013.03.11 18:38:45 LOG7[6074:0]: str_stats: 19 block(s), 877 data byte(s),
798 control byte(s)
2013.03.11 18:38:45 LOG7[5849:0]: Dispatching signals from the signal pipe
2013.03.11 18:38:45 LOG7[5849:0]: Processing SIGCHLD
2013.03.11 18:38:45 LOG7[5849:0]: Process 6074 finished with code 0
2013.03.11 18:38:45 LOG7[5849:0]: Signal pipe is empty

Normally under which circumstances this can happen. please help me totally
clue less ...

Rgds,
Ramesh P
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://www.stunnel.org/pipermail/stunnel-users/attachments/20130311/154d8d5f/attachment.html>