Hi,
after upgrading to stunnel 4.09, we are having 2 problems with it that did not exist in a previous version (our case: stunnel 4.05 without pthreads)
---[ My testsetup is as follows:
* stunnel listening on port 4321, connects to localhost port 13 (daytime) * daytime is enabled in inetd * stunnel was compiled without pthreads * ulimit -u = 8192
---[ problem 1
At first, it works fine. For every incoming connection, the process forks and data is transferred. However, when the connection is closed, the forked process remains hanging for a while (about 1 minute) and then exits.
This in itself is not a real problem, except that it generates a lot of processes. (and maybe causes problem 2 ?)
---[ data and logs concerning problem 1 (process hangs for 1 minute):
I run the following command:
openssl s_client -connect 192.168.2.119:4321
the output follows immediately
The logfile (debug = debug) looks like this:
2005.03.31 14:05:05 LOG7[4552:0]: daytime accepted FD=8 from 192.168.2.103:47200 2005.03.31 14:05:05 LOG7[4552:0]: FD 8 in non-blocking mode 2005.03.31 14:05:05 LOG7[4553:0]: daytime started 2005.03.31 14:05:05 LOG5[4553:0]: daytime connected from 192.168.2.103:47200 2005.03.31 14:05:05 LOG7[4553:0]: SSL state (accept): before/accept initialization 2005.03.31 14:05:05 LOG7[4553:0]: SSL state (accept): SSLv3 read client hello A 2005.03.31 14:05:05 LOG7[4553:0]: SSL state (accept): SSLv3 write server hello A 2005.03.31 14:05:05 LOG7[4553:0]: SSL state (accept): SSLv3 write certificate A 2005.03.31 14:05:05 LOG7[4553:0]: SSL state (accept): SSLv3 write server done A 2005.03.31 14:05:05 LOG7[4553:0]: SSL state (accept): SSLv3 flush data 2005.03.31 14:05:05 LOG7[4553:0]: SSL state (accept): SSLv3 read client key exchange A 2005.03.31 14:05:05 LOG7[4553:0]: SSL state (accept): SSLv3 read finished A 2005.03.31 14:05:05 LOG7[4553:0]: SSL state (accept): SSLv3 write change cipher spec A 2005.03.31 14:05:05 LOG7[4553:0]: SSL state (accept): SSLv3 write finished A 2005.03.31 14:05:05 LOG7[4553:0]: SSL state (accept): SSLv3 flush data 2005.03.31 14:05:05 LOG7[4553:0]: 1 items in the session cache 2005.03.31 14:05:05 LOG7[4553:0]: 0 client connects (SSL_connect()) 2005.03.31 14:05:05 LOG7[4553:0]: 0 client connects that finished 2005.03.31 14:05:05 LOG7[4553:0]: 0 client renegotiatations requested 2005.03.31 14:05:05 LOG7[4553:0]: 1 server connects (SSL_accept()) 2005.03.31 14:05:05 LOG7[4553:0]: 1 server connects that finished 2005.03.31 14:05:05 LOG7[4553:0]: 0 server renegotiatiations requested 2005.03.31 14:05:05 LOG7[4553:0]: 0 session cache hits 2005.03.31 14:05:05 LOG7[4553:0]: 0 session cache misses 2005.03.31 14:05:05 LOG7[4553:0]: 0 session cache timeouts 2005.03.31 14:05:05 LOG6[4553:0]: SSL accepted: new session negotiated 2005.03.31 14:05:05 LOG6[4553:0]: Negotiated ciphers: RC4-SHA SSLv3 Kx=RSA Au=RSA Enc=RC4(128) Mac=SHA1 2005.03.31 14:05:05 LOG7[4553:0]: FD 7 in non-blocking mode 2005.03.31 14:05:05 LOG7[4553:0]: daytime connecting 127.0.0.1:13 2005.03.31 14:05:05 LOG7[4553:0]: connect_wait: waiting 10 seconds 2005.03.31 14:05:05 LOG7[4553:0]: connect_wait: connected 2005.03.31 14:05:05 LOG7[4553:0]: Remote FD=7 initialized 2005.03.31 14:05:05 LOG7[4553:0]: Socket closed on read 2005.03.31 14:05:05 LOG7[4553:0]: SSL write shutdown 2005.03.31 14:05:05 LOG7[4553:0]: SSL alert (write): warning: close notify 2005.03.31 14:05:05 LOG7[4553:0]: SSL_shutdown retrying 2005.03.31 14:05:06 LOG7[4553:0]: SSL alert (read): warning: close notify 2005.03.31 14:05:06 LOG7[4553:0]: SSL closed on SSL_read 2005.03.31 14:05:06 LOG7[4553:0]: Socket write shutdown
When I check netstat, the connection from the client to stunnel is in the CLOSE_WAIT state and the connection from stunnel to the daytime server is in TIME_WAIT state
then 1 minute later, this follows:
2005.03.31 14:06:06 LOG6[4553:0]: s_poll_wait timeout: connection close 2005.03.31 14:06:06 LOG5[4553:0]: Connection closed: 26 bytes sent to SSL, 0 bytes sent to socket 2005.03.31 14:06:06 LOG7[4553:0]: removing pid file /stunnel.pid 2005.03.31 14:06:06 LOG7[4552:0]: Steven: going into client_status with num_clients = 1 2005.03.31 14:06:06 LOG7[4552:0]: Process 4553 finished with code 0 (0 left)
Now, netstat no longer shows the connections in any state.
---[ problem 2 Another problem that was found is that after bombarding stunnel with lots of connections, it stops accepting new connections. This would be normal if all connections remained open, but they are all closed.
This is the error:
Mar 31 13:53:40 hostname stunnel[13044]: Connection rejected: too many clients (>=4000)
netstat only shows +- 500 connections, of which none are aimed at the stunnel process in question (port 4321 in my test setup)
there is only 1 stunnel process active aswell.
I dug into the problem a bit and it probably has to do with num_clients not being decreased after a process is closed (although I can not find any specifics :/)
greets, -- Steven