[stunnel-users] stunnel 4.36 execution problem on Solaris 10

Ross Richardson Ross.Richardson at utas.edu.au
Tue May 10 04:43:05 CEST 2011


Unforutnately, although I've got stunnel 4.36 built OK using Sun Studio,
it's not running correctly.

As a test, I'm using stunnel to provide an SSL wrapper for (Apache) httpd.
The first client connection (using curl or "openssl s_client") works
without problem, but subsequent connections just sit there with no log
output (and "truss -f" showing it just sitting at
25346:  read(5, 0xFFBFFB44, 4)          (sleeping...)
).  The stunnel configuration file works perfectly with stunnel-4.34.

Running "netstat -an | fgrep 480" (where 480 is stunnel's listening port)
shows:
- before the first client connection
      *.480                *.*                0      0 49152      0 LISTEN
- after the first [successful] client connection
      *.480                *.*                0      0 49152      0 LISTEN
- after the second client connection attempt [unsuccessful]
      *.480                *.*                0      0 49152      0 LISTEN
  192.168.1.23.48371   192.168.1.23.480    49152      0 49152      0 ESTABLISHED
  192.168.1.23.480     192.168.1.23.48371  49152      0 49152      0 ESTABLISHED


The config file:
================
; global

chroot = /var/stunnel/server/chroot
setuid = stunnel0
setgid = stunnel0
; testing
debug = debug
foreground = yes


[stunnel-server]
libwrap = yes
client = no
accept = 480
connect = 80
key = /etc/local/apache/ssl.key/myhost.key
cert = /etc/local/apache/ssl.crt/myhost.chain
ciphers = HIGH
sslVersion = TLSv1
================


The log:
================
2011.05.10 12:12:42 LOG5[24551:1]: Reading configuration from file /etc/local/stunnel/stunnel.conf.server
2011.05.10 12:12:42 LOG7[24551:1]: Snagged 64 random bytes from //.rnd
2011.05.10 12:12:42 LOG7[24551:1]: Wrote 1024 new random bytes to //.rnd
2011.05.10 12:12:42 LOG7[24551:1]: PRNG seeded successfully
2011.05.10 12:12:43 LOG6[24551:1]: Could not load DH parameters from /etc/local/apache/ssl.crt/myhost.chain
2011.05.10 12:12:43 LOG7[24551:1]: ECDH initialized
2011.05.10 12:12:43 LOG7[24551:1]: Certificate: /etc/local/apache/ssl.crt/myhost.chain
2011.05.10 12:12:43 LOG7[24551:1]: Certificate loaded
2011.05.10 12:12:43 LOG7[24551:1]: Key file: /etc/local/apache/ssl.key/myhost.key
2011.05.10 12:12:43 LOG7[24551:1]: Private key loaded
2011.05.10 12:12:43 LOG7[24551:1]: SSL context initialized for service stunnel-server
2011.05.10 12:12:43 LOG5[24551:1]: Configuration successful
2011.05.10 12:12:43 LOG5[24551:1]: No limit detected for the number of clients
2011.05.10 12:12:43 LOG7[24551:1]: libwrap_init: FD=6 allocated (blocking mode)
2011.05.10 12:12:43 LOG7[24551:1]: libwrap_init: FD=5 allocated (blocking mode)
2011.05.10 12:12:43 LOG7[24551:1]: libwrap_init: FD=7 allocated (blocking mode)
2011.05.10 12:12:43 LOG7[24551:1]: libwrap_init: FD=5 allocated (blocking mode)
2011.05.10 12:12:43 LOG7[24551:1]: libwrap_init: FD=8 allocated (blocking mode)
2011.05.10 12:12:43 LOG7[24551:1]: libwrap_init: FD=5 allocated (blocking mode)
2011.05.10 12:12:43 LOG7[24551:1]: libwrap_init: FD=9 allocated (blocking mode)
2011.05.10 12:12:43 LOG7[24551:1]: libwrap_init: FD=5 allocated (blocking mode)
2011.05.10 12:12:43 LOG7[24551:1]: libwrap_init: FD=10 allocated (blocking mode)
2011.05.10 12:12:43 LOG7[24551:1]: libwrap_init: FD=5 allocated (blocking mode)
2011.05.10 12:12:43 LOG7[24551:1]: signal_pipe: FD=5 allocated (blocking mode)
2011.05.10 12:12:43 LOG7[24551:1]: signal_pipe: FD=11 allocated (blocking mode)
2011.05.10 12:12:43 LOG7[24551:1]: accept socket: FD=12 allocated (non-blocking mode)
2011.05.10 12:12:43 LOG7[24551:1]: Option SO_REUSEADDR set on accept socket
2011.05.10 12:12:43 LOG7[24551:1]: Service stunnel-server bound to 0.0.0.0:480
2011.05.10 12:12:43 LOG7[24551:1]: Service stunnel-server opened FD=12
2011.05.10 12:12:43 LOG7[24551:1]: Created pid file /var/run/stunnel.pid
2011.05.10 12:12:43 LOG5[24551:1]: stunnel 4.36 on sparc-sun-solaris2.10 with OpenSSL 1.0.0d 8 Feb 2011
2011.05.10 12:12:43 LOG5[24551:1]: Threading:PTHREAD SSL:ENGINE Auth:LIBWRAP Sockets:POLL, IPv6
2011.05.10 12:13:30 LOG7[24551:1]: local socket: FD=13 allocated (non-blocking mode)
2011.05.10 12:13:30 LOG7[24551:1]: Service stunnel-server accepted FD=13 from 192.168.1.23:48367
2011.05.10 12:13:30 LOG7[24551:2]: Service stunnel-server started
2011.05.10 12:13:30 LOG7[24551:2]: Waiting for a libwrap process
2011.05.10 12:13:30 LOG7[24551:2]: Acquired libwrap process #0
2011.05.10 12:13:30 LOG7[24551:1]: Dispatching signals from the signal pipe
2011.05.10 12:13:30 LOG7[24551:2]: Releasing libwrap process #0
2011.05.10 12:13:30 LOG7[24551:2]: Released libwrap process #0
2011.05.10 12:13:30 LOG7[24551:2]: Service stunnel-server permitted by libwrap from 192.168.1.23:48367
2011.05.10 12:13:30 LOG5[24551:2]: Service stunnel-server accepted connection from 192.168.1.23:48367
2011.05.10 12:13:30 LOG7[24551:2]: SSL state (accept): before/accept initialization
2011.05.10 12:13:30 LOG7[24551:2]: SSL state (accept): SSLv3 read client hello A
2011.05.10 12:13:30 LOG7[24551:2]: SSL state (accept): SSLv3 write server hello A
2011.05.10 12:13:30 LOG7[24551:2]: SSL state (accept): SSLv3 write certificate A
2011.05.10 12:13:30 LOG7[24551:1]: Signal pipe is empty
2011.05.10 12:13:30 LOG7[24551:1]: Dispatching signals from the signal pipe
2011.05.10 12:13:30 LOG7[24551:2]: SSL state (accept): SSLv3 write key exchange A
2011.05.10 12:13:30 LOG7[24551:2]: SSL state (accept): SSLv3 write server done A
2011.05.10 12:13:30 LOG7[24551:2]: SSL state (accept): SSLv3 flush data
2011.05.10 12:13:30 LOG7[24551:2]: SSL state (accept): SSLv3 read client key exchange A
2011.05.10 12:13:30 LOG7[24551:1]: Signal pipe is empty
2011.05.10 12:13:30 LOG7[24551:1]: Dispatching signals from the signal pipe
2011.05.10 12:13:30 LOG6[24551:1]: Child process 24643 finished with code 0
2011.05.10 12:13:30 LOG7[24551:2]: SSL state (accept): SSLv3 read finished A
2011.05.10 12:13:30 LOG7[24551:2]: SSL state (accept): SSLv3 write change cipher spec A
2011.05.10 12:13:30 LOG7[24551:2]: SSL state (accept): SSLv3 write finished A
2011.05.10 12:13:30 LOG7[24551:2]: SSL state (accept): SSLv3 flush data
2011.05.10 12:13:30 LOG7[24551:2]:    1 items in the session cache
2011.05.10 12:13:30 LOG7[24551:2]:    0 client connects (SSL_connect())
2011.05.10 12:13:30 LOG7[24551:2]:    0 client connects that finished
2011.05.10 12:13:30 LOG7[24551:2]:    0 client renegotiations requested
2011.05.10 12:13:30 LOG7[24551:2]:    1 server connects (SSL_accept())
2011.05.10 12:13:30 LOG7[24551:2]:    1 server connects that finished
2011.05.10 12:13:30 LOG7[24551:2]:    0 server renegotiations requested
2011.05.10 12:13:30 LOG7[24551:2]:    0 session cache hits
2011.05.10 12:13:30 LOG7[24551:2]:    0 external session cache hits
2011.05.10 12:13:30 LOG7[24551:1]: Signal pipe is empty
2011.05.10 12:13:30 LOG7[24551:2]:    0 session cache misses
2011.05.10 12:13:30 LOG7[24551:2]:    0 session cache timeouts
2011.05.10 12:13:30 LOG6[24551:2]: SSL accepted: new session negotiated
2011.05.10 12:13:30 LOG6[24551:2]: Negotiated ciphers: ECDHE-RSA-AES256-SHA SSLv3 Kx=ECDH Au=RSA Enc=AES(256) Mac=SHA1
2011.05.10 12:13:30 LOG7[24551:2]: remote socket: FD=14 allocated (non-blocking mode)
2011.05.10 12:13:30 LOG6[24551:2]: connect_blocking: connecting 127.0.0.1:80
2011.05.10 12:13:30 LOG5[24551:2]: connect_blocking: connected 127.0.0.1:80
2011.05.10 12:13:30 LOG7[24551:1]: Dispatching signals from the signal pipe
2011.05.10 12:13:30 LOG5[24551:2]: Service stunnel-server connected remote server from 127.0.0.1:48368
2011.05.10 12:13:30 LOG7[24551:2]: Remote FD=14 initialized
2011.05.10 12:13:30 LOG7[24551:2]: SSL alert (read): warning: close notify
2011.05.10 12:13:30 LOG7[24551:2]: SSL closed on SSL_read
2011.05.10 12:13:30 LOG7[24551:2]: Sending socket write shutdown
2011.05.10 12:13:30 LOG7[24551:2]: Socket closed on read
2011.05.10 12:13:30 LOG7[24551:2]: Sending SSL write shutdown
2011.05.10 12:13:30 LOG7[24551:2]: SSL alert (write): warning: close notify
2011.05.10 12:13:30 LOG6[24551:2]: SSL_shutdown successfully sent close_notify
2011.05.10 12:13:30 LOG7[24551:1]: Signal pipe is empty
2011.05.10 12:13:30 LOG7[24551:1]: Dispatching signals from the signal pipe
2011.05.10 12:13:30 LOG5[24551:2]: Connection closed: 340 bytes sent to SSL, 169 bytes sent to socket
2011.05.10 12:13:30 LOG7[24551:2]: Service stunnel-server finished (0 left)
2011.05.10 12:13:30 LOG7[24551:2]: str_stats: 0 blocks, 0 bytes
2011.05.10 12:13:30 LOG7[24551:1]: Signal pipe is empty
2011.05.10 12:13:30 LOG7[24551:1]: Dispatching signals from the signal pipe
================


Suggestions welcome.

rlr
-- 
Ross L Richardson               <URL:mailto:Ross.Richardson at utas.edu.au>
Senior Systems Administrator                  Phone : +61 (0)3 6226 6233
Information Technology Resources                Fax : +61 (0)3 6226 7171
University of Tasmania, AUSTRALIA



More information about the stunnel-users mailing list