Hi, I've initiated 11 stunnel processes in the same server. Each of the stunnel process has its own client certificate to communicate to application server. However after sometime of execution, the stunnel processes are crached (dying off) one by one. below is the last portion of my log (with debug level 7). I don't see any critical error in the log. Would appreciate if someone could highlight to me what cause the problem or anyone has similar experience.
2005.01.25 16:02:41 LOG7[2244:1424]: 0 server connects that finished 2005.01.25 16:02:41 LOG7[2244:1424]: 0 server renegotiatiations requested 2005.01.25 16:02:41 LOG7[2244:1424]: 486 session cache hits 2005.01.25 16:02:41 LOG7[2244:1424]: 0 session cache misses 2005.01.25 16:02:41 LOG7[2244:1424]: 0 session cache timeouts 2005.01.25 16:02:41 LOG7[2244:1424]: SSL_read returned WANT_: retrying 2005.01.25 16:02:41 LOG7[2244:1804]: SSL socket closed on SSL_read 2005.01.25 16:02:41 LOG5[2244:1804]: Connection closed: 716 bytes sent to SSL, 359 bytes sent to socket 2005.01.25 16:02:41 LOG7[2244:1804]: HTTP finished (7 left) 2005.01.25 16:02:41 LOG7[2244:1424]: SSL socket closed on SSL_read 2005.01.25 16:02:41 LOG5[2244:1424]: Connection closed: 716 bytes sent to SSL, 304 bytes sent to socket 2005.01.25 16:02:41 LOG7[2244:1424]: HTTP finished (6 left) 2005.01.25 16:02:41 LOG7[2244:2240]: HTTP accepted FD=516 from 10.3.5.137:1405 2005.01.25 16:02:41 LOG7[2244:2240]: FD 516 in non-blocking mode 2005.01.25 16:02:41 LOG7[2244:2240]: Creating a new thread 2005.01.25 16:02:41 LOG7[2244:2240]: New thread created 2005.01.25 16:02:41 LOG7[2244:1252]: HTTP started 2005.01.25 16:02:41 LOG5[2244:1252]: HTTP connected from 10.3.5.137:1405 2005.01.25 16:02:41 LOG7[2244:1252]: FD 704 in non-blocking mode 2005.01.25 16:02:41 LOG7[2244:1252]: HTTP connecting 10.1.11.56:443 2005.01.25 16:02:41 LOG7[2244:1252]: connect_wait: waiting 10 seconds 2005.01.25 16:02:41 LOG7[2244:1252]: connect_wait: connected 2005.01.25 16:02:41 LOG7[2244:1252]: Remote FD=704 initialized 2005.01.25 16:02:41 LOG7[2244:1252]: SSL state (connect): before/connect initialization 2005.01.25 16:02:41 LOG7[2244:1252]: SSL state (connect): SSLv3 write client hello A 2005.01.25 16:02:41 LOG7[2244:1252]: SSL state (connect): SSLv3 read server hello A 2005.01.25 16:02:41 LOG7[2244:1252]: SSL state (connect): SSLv3 read finished A 2005.01.25 16:02:41 LOG7[2244:1252]: SSL state (connect): SSLv3 write change cipher spec A 2005.01.25 16:02:41 LOG7[2244:1252]: SSL state (connect): SSLv3 write finished A 2005.01.25 16:02:41 LOG7[2244:1252]: SSL state (connect): SSLv3 flush data 2005.01.25 16:02:41 LOG7[2244:1252]: 241 items in the session cache 2005.01.25 16:02:41 LOG7[2244:1252]: 979 client connects (SSL_connect()) 2005.01.25 16:02:41 LOG7[2244:1252]: 979 client connects that finished 2005.01.25 16:02:41 LOG7[2244:1252]: 489 client renegotiatations requested 2005.01.25 16:02:41 LOG7[2244:1252]: 0 server connects (SSL_accept()) 2005.01.25 16:02:41 LOG7[2244:1252]: 0 server connects that finished 2005.01.25 16:02:41 LOG7[2244:1252]: 0 server renegotiatiations requested 2005.01.25 16:02:41 LOG7[2244:1252]: 487 session cache hits 2005.01.25 16:02:41 LOG7[2244:1252]: 0 session cache misses 2005.01.25 16:02:41 LOG7[2244:1252]: 0 session cache timeouts 2005.01.25 16:02:41 LOG6[2244:1252]: SSL connected: previous session reused 2005.01.25 16:02:41 LOG7[2244:1252]: SSL state (connect): SSL renegotiate ciphers 2005.01.25 16:02:41 LOG7[2244:1252]: SSL state (connect): SSLv3 write client hello A 2005.01.25 16:02:41 LOG7[2244:1252]: SSL_read returned WANT_: retrying 2005.01.25 16:02:41 LOG7[2244:1252]: SSL_write returned WANT_: retrying 2005.01.25 16:02:41 LOG7[2244:1252]: SSL_read returned WANT_: retrying 2005.01.25 16:02:41 LOG7[2244:1252]: SSL_write returned WANT_: retrying 2005.01.25 16:02:41 LOG7[2244:1252]: SSL_read returned WANT_: retrying 2005.01.25 16:02:41 LOG7[2244:1252]: SSL state (connect): SSLv3 read server hello A 2005.01.25 16:02:41 LOG7[2244:1252]: SSL state (connect): SSLv3 read server certificate A 2005.01.25 16:02:41 LOG7[2244:1252]: SSL state (connect): SSLv3 read server certificate request A 2005.01.25 16:02:41 LOG7[2244:1252]: SSL state (connect): SSLv3 read server done A 2005.01.25 16:02:41 LOG7[2244:1252]: SSL state (connect): SSLv3 write client certificate A 2005.01.25 16:02:41 LOG7[2244:1252]: SSL state (connect): SSLv3 write client key exchange A 2005.01.25 16:02:41 LOG7[2244:1252]: SSL state (connect): SSLv3 write certificate verify A 2005.01.25 16:02:41 LOG7[2244:1252]: SSL state (connect): SSLv3 write change cipher spec A 2005.01.25 16:02:41 LOG7[2244:1252]: SSL state (connect): SSLv3 write finished A 2005.01.25 16:02:41 LOG7[2244:1252]: SSL state (connect): SSLv3 flush data 2005.01.25 16:02:41 LOG7[2244:1252]: SSL_write returned WANT_: retrying 2005.01.25 16:02:41 LOG7[2244:1252]: SSL_read returned WANT_: retrying 2005.01.25 16:02:42 LOG7[2244:1252]: SSL state (connect): SSLv3 read finished A 2005.01.25 16:02:42 LOG7[2244:1252]: 242 items in the session cache 2005.01.25 16:02:42 LOG7[2244:1252]: 980 client connects (SSL_connect()) 2005.01.25 16:02:42 LOG7[2244:1252]: 980 client connects that finished 2005.01.25 16:02:42 LOG7[2244:1252]: 490 client renegotiatations requested 2005.01.25 16:02:42 LOG7[2244:1252]: 0 server connects (SSL_accept()) 2005.01.25 16:02:42 LOG7[2244:1252]: 0 server connects that finished 2005.01.25 16:02:42 LOG7[2244:1252]: 0 server renegotiatiations requested 2005.01.25 16:02:42 LOG7[2244:1252]: 487 session cache hits 2005.01.25 16:02:42 LOG7[2244:1252]: 0 session cache misses 2005.01.25 16:02:42 LOG7[2244:1252]: 0 session cache timeouts 2005.01.25 16:02:42 LOG7[2244:1252]: SSL_read returned WANT_: retrying 2005.01.25 16:02:43 LOG7[2244:2428]: s_poll_wait timeout waiting for SSL close_notify 2005.01.25 16:02:43 LOG7[2244:2284]: s_poll_wait timeout waiting for SSL close_notify 2005.01.25 16:02:43 LOG5[2244:2428]: Connection closed: 606 bytes sent to SSL, 242 bytes sent to socket 2005.01.25 16:02:43 LOG5[2244:2284]: Connection closed: 7758 bytes sent to SSL, 23278 bytes sent to socket 2005.01.25 16:02:43 LOG7[2244:2428]: HTTP finished (6 left) 2005.01.25 16:02:43 LOG7[2244:2284]: HTTP finished (5 left) 2005.01.25 16:02:45 LOG7[2244:1188]: s_poll_wait timeout waiting for SSL close_notify 2005.01.25 16:02:45 LOG5[2244:1188]: Connection closed: 1485 bytes sent to SSL, 7307 bytes sent to socket 2005.01.25 16:02:47 LOG7[2244:2228]: s_poll_wait timeout waiting for SSL close_notify 2005.01.25 16:02:47 LOG5[2244:2228]: Connection closed: 667 bytes sent to SSL, 552 bytes sent to socket 2005.01.25 16:02:49 LOG7[2244:1644]: s_poll_wait timeout waiting for SSL close_notify 2005.01.25 16:02:49 LOG5[2244:1644]: Connection closed: 667 bytes sent to SSL, 552 bytes sent to socket 2005.01.25 16:02:50 LOG7[2244:2268]: s_poll_wait timeout waiting for SSL close_notify 2005.01.25 16:02:50 LOG5[2244:2268]: Connection closed: 418 bytes sent to SSL, 1375 bytes sent to socket 2005.01.25 16:11:14 LOG7[2244:2240]: HTTP accepted FD=796 from 10.3.5.137:3973 2005.01.25 16:11:14 LOG7[2244:2240]: FD 796 in non-blocking mode 2005.01.25 16:11:14 LOG7[2244:2240]: Creating a new thread 2005.01.25 16:11:14 LOG7[2244:2240]: New thread created 2005.01.25 16:11:14 LOG7[2244:992]: HTTP started 2005.01.25 16:11:14 LOG5[2244:992]: HTTP connected from 10.3.5.137:3973 2005.01.25 16:11:14 LOG7[2244:992]: FD 632 in non-blocking mode 2005.01.25 16:11:14 LOG7[2244:992]: HTTP connecting 10.1.11.56:443 2005.01.25 16:11:14 LOG7[2244:992]: connect_wait: waiting 10 seconds 2005.01.25 16:11:14 LOG7[2244:992]: connect_wait: connected 2005.01.25 16:11:14 LOG7[2244:992]: Remote FD=632 initialized 2005.01.25 16:11:14 LOG7[2244:992]: SSL state (connect): before/connect initialization 2005.01.25 16:11:14 LOG7[2244:992]: SSL state (connect): SSLv3 write client hello A 2005.01.25 16:11:14 LOG7[2244:992]: SSL state (connect): SSLv3 read server hello A 2005.01.25 16:11:14 LOG7[2244:992]: SSL state (connect): SSLv3 read finished A 2005.01.25 16:11:14 LOG7[2244:992]: SSL state (connect): SSLv3 write change cipher spec A 2005.01.25 16:11:14 LOG7[2244:992]: SSL state (connect): SSLv3 write finished A 2005.01.25 16:11:14 LOG7[2244:992]: SSL state (connect): SSLv3 flush data 2005.01.25 16:11:14 LOG7[2244:992]: 242 items in the session cache 2005.01.25 16:11:14 LOG7[2244:992]: 981 client connects (SSL_connect()) 2005.01.25 16:11:14 LOG7[2244:992]: 981 client connects that finished 2005.01.25 16:11:14 LOG7[2244:992]: 490 client renegotiatations requested 2005.01.25 16:11:14 LOG7[2244:992]: 0 server connects (SSL_accept()) 2005.01.25 16:11:14 LOG7[2244:992]: 0 server connects that finished 2005.01.25 16:11:14 LOG7[2244:992]: 0 server renegotiatiations requested 2005.01.25 16:11:14 LOG7[2244:992]: 488 session cache hits 2005.01.25 16:11:14 LOG7[2244:992]: 0 session cache misses 2005.01.25 16:11:14 LOG7[2244:992]: 0 session cache timeouts 2005.01.25 16:11:14 LOG6[2244:992]: SSL connected: previous session reused 2005.01.25 16:11:15 LOG7[2244:992]: SSL state (connect): SSL renegotiate ciphers 2005.01.25 16:11:15 LOG7[2244:992]: SSL state (connect): SSLv3 write client hello A 2005.01.25 16:11:15 LOG7[2244:992]: SSL_read returned WANT_: retrying 2005.01.25 16:11:15 LOG7[2244:992]: SSL_write returned WANT_: retrying 2005.01.25 16:11:15 LOG7[2244:992]: SSL_read returned WANT_: retrying 2005.01.25 16:11:15 LOG7[2244:992]: SSL_write returned WANT_: retrying 2005.01.25 16:11:15 LOG7[2244:992]: SSL_read returned WANT_: retrying 2005.01.25 16:11:15 LOG7[2244:992]: SSL state (connect): SSLv3 read server hello A 2005.01.25 16:11:15 LOG7[2244:992]: SSL state (connect): SSLv3 read server certificate A 2005.01.25 16:11:15 LOG7[2244:992]: SSL state (connect): SSLv3 read server certificate request A 2005.01.25 16:11:15 LOG7[2244:992]: SSL state (connect): SSLv3 read server done A 2005.01.25 16:11:15 LOG7[2244:992]: SSL state (connect): SSLv3 write client certificate A 2005.01.25 16:11:15 LOG7[2244:992]: SSL state (connect): SSLv3 write client key exchange A 2005.01.25 16:11:15 LOG7[2244:992]: SSL state (connect): SSLv3 write certificate verify A 2005.01.25 16:11:15 LOG7[2244:992]: SSL state (connect): SSLv3 write change cipher spec A 2005.01.25 16:11:15 LOG7[2244:992]: SSL state (connect): SSLv3 write finished A 2005.01.25 16:11:15 LOG7[2244:992]: SSL state (connect): SSLv3 flush data 2005.01.25 16:11:15 LOG7[2244:992]: SSL_write returned WANT_: retrying 2005.01.25 16:11:15 LOG7[2244:992]: SSL_read returned WANT_: retrying 2005.01.25 16:11:15 LOG7[2244:2268]: HTTP finished (5 left)
thanks and rgds,spl
PinLee_Su@azuretech.com.sg wrote:
I've initiated 11 stunnel processes in the same server.
11 stunnel daemons or 11 threads of a deamon? What is your configuration file?
What does your stunnel display on startup? It could look like this: 2005.01.28 12:04:13 LOG5[3818:1076586880]: stunnel 4.08 on i686-pc-linux-gnu PTHREAD+POLL+IPv6+LIBWRAP with OpenSSL 0.9.7e 25 Oct 2004
Can you create a core file and send the stack backtrace to the list: http://www.network-theory.co.uk/articles/gccdebug.html
It looks like a race condition that was fixed in 4.06...
Best regards, Mike
-
Michal Trojnara -
PinLee_Suļ¼ azuretech.com.sg