greetings. clients connects normally when not using ssl (stunnel). when using ssl the connection on the client end appears to take about a minute but does eventually work (mail is sent through encrypted). shown below is the log with debug=7 and a space between the area where a "pause" seems to be, ideas on what could be occurring during this time to induce the "pause"?
client = machine making connection. server = machine running stunnel accepting the connection.
2007.02.14 12:24:06 LOG7[69377:134631424]: imaps accepted FD=9 from client:62847 2007.02.14 12:24:06 LOG7[69377:134633984]: imaps started 2007.02.14 12:24:06 LOG7[69377:134633984]: FD 9 in non-blocking mode 2007.02.14 12:24:06 LOG7[69377:134633984]: TCP_NODELAY option set on local socket 2007.02.14 12:24:06 LOG7[69377:134633984]: FD 10 in non-blocking mode 2007.02.14 12:24:06 LOG7[69377:134633984]: FD 11 in non-blocking mode 2007.02.14 12:24:06 LOG7[69377:134633984]: Connection from client: 62847 permitted by libwrap 2007.02.14 12:24:06 LOG5[69377:134633984]: imaps connected from client:62847 2007.02.14 12:24:06 LOG7[69377:134631424]: Cleaning up the signal pipe 2007.02.14 12:24:06 LOG6[69377:134631424]: Child process 69387 finished with code 0 2007.02.14 12:24:06 LOG7[69377:134633984]: SSL state (accept): before/ accept initialization 2007.02.14 12:24:06 LOG7[69377:134633984]: SSL state (accept): SSLv3 read client hello A 2007.02.14 12:24:06 LOG7[69377:134633984]: SSL state (accept): SSLv3 write server hello A 2007.02.14 12:24:06 LOG7[69377:134633984]: SSL state (accept): SSLv3 write certificate A 2007.02.14 12:24:06 LOG7[69377:134633984]: SSL state (accept): SSLv3 write server done A 2007.02.14 12:24:06 LOG7[69377:134633984]: SSL state (accept): SSLv3 flush data 2007.02.14 12:24:06 LOG7[69377:134633984]: SSL state (accept): SSLv3 read client key exchange A 2007.02.14 12:24:06 LOG7[69377:134633984]: SSL state (accept): SSLv3 read finished A 2007.02.14 12:24:06 LOG7[69377:134633984]: SSL state (accept): SSLv3 write change cipher spec A 2007.02.14 12:24:06 LOG7[69377:134633984]: SSL state (accept): SSLv3 write finished A 2007.02.14 12:24:06 LOG7[69377:134633984]: SSL state (accept): SSLv3 flush data 2007.02.14 12:24:06 LOG7[69377:134633984]: 1 items in the session cache 2007.02.14 12:24:06 LOG7[69377:134633984]: 0 client connects (SSL_connect()) 2007.02.14 12:24:06 LOG7[69377:134633984]: 0 client connects that finished 2007.02.14 12:24:06 LOG7[69377:134633984]: 0 client renegotiatations requested 2007.02.14 12:24:06 LOG7[69377:134633984]: 1 server connects (SSL_accept()) 2007.02.14 12:24:06 LOG7[69377:134633984]: 1 server connects that finished 2007.02.14 12:24:06 LOG7[69377:134633984]: 0 server renegotiatiations requested 2007.02.14 12:24:06 LOG7[69377:134633984]: 0 session cache hits 2007.02.14 12:24:06 LOG7[69377:134633984]: 0 session cache misses 2007.02.14 12:24:06 LOG7[69377:134633984]: 0 session cache timeouts 2007.02.14 12:24:06 LOG6[69377:134633984]: SSL accepted: new session negotiated 2007.02.14 12:24:06 LOG6[69377:134633984]: Negotiated ciphers: AES128- SHA SSLv3 Kx=RSA Au=RSA Enc=AES(128) Mac=SHA1 2007.02.14 12:24:06 LOG7[69377:134633984]: FD 10 in non-blocking mode 2007.02.14 12:24:06 LOG7[69377:134633984]: imaps connecting server:143 2007.02.14 12:24:06 LOG7[69377:134633984]: connect_wait: waiting 10 seconds 2007.02.14 12:24:06 LOG7[69377:134633984]: connect_wait: connected 2007.02.14 12:24:06 LOG7[69377:134633984]: Remote FD=10 initialized 2007.02.14 12:24:06 LOG7[69377:134633984]: TCP_NODELAY option set on remote socket 2007.02.14 12:24:08 LOG7[69377:134631424]: ssmtp accepted FD=11 from client:62848 2007.02.14 12:24:08 LOG7[69377:134881280]: ssmtp started 2007.02.14 12:24:08 LOG7[69377:134881280]: FD 11 in non-blocking mode 2007.02.14 12:24:08 LOG7[69377:134881280]: TCP_NODELAY option set on local socket 2007.02.14 12:24:08 LOG7[69377:134881280]: FD 12 in non-blocking mode 2007.02.14 12:24:08 LOG7[69377:134881280]: FD 13 in non-blocking mode 2007.02.14 12:24:08 LOG7[69377:134881280]: Connection from client: 62848 permitted by libwrap 2007.02.14 12:24:08 LOG5[69377:134881280]: ssmtp connected from client:62848 2007.02.14 12:24:08 LOG7[69377:134881280]: SSL state (accept): before/ accept initialization 2007.02.14 12:24:08 LOG7[69377:134631424]: Cleaning up the signal pipe 2007.02.14 12:24:08 LOG6[69377:134631424]: Child process 69391 finished with code 0 2007.02.14 12:24:08 LOG7[69377:134881280]: SSL state (accept): SSLv3 read client hello A 2007.02.14 12:24:08 LOG7[69377:134881280]: SSL state (accept): SSLv3 write server hello A 2007.02.14 12:24:08 LOG7[69377:134881280]: SSL state (accept): SSLv3 write certificate A 2007.02.14 12:24:08 LOG7[69377:134881280]: SSL state (accept): SSLv3 write server done A 2007.02.14 12:24:08 LOG7[69377:134881280]: SSL state (accept): SSLv3 flush data 2007.02.14 12:24:08 LOG7[69377:134881280]: SSL state (accept): SSLv3 read client key exchange A 2007.02.14 12:24:08 LOG7[69377:134881280]: SSL state (accept): SSLv3 read finished A 2007.02.14 12:24:08 LOG7[69377:134881280]: SSL state (accept): SSLv3 write change cipher spec A 2007.02.14 12:24:08 LOG7[69377:134881280]: SSL state (accept): SSLv3 write finished A 2007.02.14 12:24:08 LOG7[69377:134881280]: SSL state (accept): SSLv3 flush data 2007.02.14 12:24:08 LOG7[69377:134881280]: 2 items in the session cache 2007.02.14 12:24:08 LOG7[69377:134881280]: 0 client connects (SSL_connect()) 2007.02.14 12:24:08 LOG7[69377:134881280]: 0 client connects that finished 2007.02.14 12:24:08 LOG7[69377:134881280]: 0 client renegotiatations requested 2007.02.14 12:24:08 LOG7[69377:134881280]: 2 server connects (SSL_accept()) 2007.02.14 12:24:08 LOG7[69377:134881280]: 2 server connects that finished 2007.02.14 12:24:08 LOG7[69377:134881280]: 0 server renegotiatiations requested 2007.02.14 12:24:08 LOG7[69377:134881280]: 0 session cache hits 2007.02.14 12:24:08 LOG7[69377:134881280]: 0 session cache misses 2007.02.14 12:24:08 LOG7[69377:134881280]: 0 session cache timeouts 2007.02.14 12:24:08 LOG6[69377:134881280]: SSL accepted: new session negotiated 2007.02.14 12:24:08 LOG6[69377:134881280]: Negotiated ciphers: AES128- SHA SSLv3 Kx=RSA Au=RSA Enc=AES(128) Mac=SHA1 2007.02.14 12:24:08 LOG7[69377:134881280]: FD 12 in non-blocking mode 2007.02.14 12:24:08 LOG7[69377:134881280]: ssmtp connecting server:25 2007.02.14 12:24:08 LOG7[69377:134881280]: connect_wait: waiting 10 seconds 2007.02.14 12:24:08 LOG7[69377:134881280]: connect_wait: connected 2007.02.14 12:24:08 LOG7[69377:134881280]: Remote FD=12 initialized 2007.02.14 12:24:08 LOG7[69377:134881280]: TCP_NODELAY option set on remote socket
2007.02.14 12:25:06 LOG7[69377:134631424]: imaps accepted FD=13 from client:62850 2007.02.14 12:25:06 LOG7[69377:134882816]: imaps started 2007.02.14 12:25:06 LOG7[69377:134882816]: FD 13 in non-blocking mode 2007.02.14 12:25:06 LOG7[69377:134882816]: TCP_NODELAY option set on local socket 2007.02.14 12:25:06 LOG7[69377:134882816]: FD 14 in non-blocking mode 2007.02.14 12:25:06 LOG7[69377:134882816]: FD 15 in non-blocking mode 2007.02.14 12:25:06 LOG7[69377:134882816]: Connection from client: 62850 permitted by libwrap 2007.02.14 12:25:06 LOG5[69377:134882816]: imaps connected from client:62850 2007.02.14 12:25:06 LOG7[69377:134631424]: Cleaning up the signal pipe 2007.02.14 12:25:06 LOG7[69377:134882816]: SSL state (accept): before/ accept initialization 2007.02.14 12:25:06 LOG6[69377:134631424]: Child process 69478 finished with code 0 2007.02.14 12:25:06 LOG7[69377:134882816]: SSL state (accept): SSLv3 read client hello A 2007.02.14 12:25:06 LOG7[69377:134882816]: SSL state (accept): SSLv3 write server hello A 2007.02.14 12:25:06 LOG7[69377:134882816]: SSL state (accept): SSLv3 write change cipher spec A 2007.02.14 12:25:06 LOG7[69377:134882816]: SSL state (accept): SSLv3 write finished A 2007.02.14 12:25:06 LOG7[69377:134882816]: SSL state (accept): SSLv3 flush data 2007.02.14 12:25:06 LOG7[69377:134882816]: SSL state (accept): SSLv3 read finished A 2007.02.14 12:25:06 LOG7[69377:134882816]: 2 items in the session cache 2007.02.14 12:25:06 LOG7[69377:134882816]: 0 client connects (SSL_connect()) 2007.02.14 12:25:06 LOG7[69377:134882816]: 0 client connects that finished 2007.02.14 12:25:06 LOG7[69377:134882816]: 0 client renegotiatations requested 2007.02.14 12:25:06 LOG7[69377:134882816]: 3 server connects (SSL_accept()) 2007.02.14 12:25:06 LOG7[69377:134882816]: 3 server connects that finished 2007.02.14 12:25:06 LOG7[69377:134882816]: 0 server renegotiatiations requested 2007.02.14 12:25:06 LOG7[69377:134882816]: 1 session cache hits 2007.02.14 12:25:06 LOG7[69377:134882816]: 0 session cache misses 2007.02.14 12:25:06 LOG7[69377:134882816]: 0 session cache timeouts 2007.02.14 12:25:06 LOG6[69377:134882816]: SSL accepted: previous session reused 2007.02.14 12:25:06 LOG7[69377:134882816]: FD 14 in non-blocking mode 2007.02.14 12:25:06 LOG7[69377:134882816]: imaps connecting server:143 2007.02.14 12:25:06 LOG7[69377:134882816]: connect_wait: waiting 10 seconds 2007.02.14 12:25:06 LOG7[69377:134882816]: connect_wait: connected 2007.02.14 12:25:06 LOG7[69377:134882816]: Remote FD=14 initialized 2007.02.14 12:25:06 LOG7[69377:134882816]: TCP_NODELAY option set on remote socket
-- Jason Kawaja, 2-4568 IT Expert, UF Dept of ECE
On Feb 14, 2007, at 12:45 PM, jason kawaja wrote:
greetings. clients connects normally when not using ssl (stunnel). when using ssl the connection on the client end appears to take about a minute but does eventually work (mail is sent through encrypted). shown below is the log with debug=7 and a space between the area where a "pause" seems to be, ideas on what could be occurring during this time to induce the "pause"?
client = machine making connection. server = machine running stunnel accepting the connection.
[snip]
2007.02.14 12:24:08 LOG7[69377:134881280]: TCP_NODELAY option set on remote socket
2007.02.14 12:25:06 LOG7[69377:134631424]: imaps accepted FD=13 from client:62850
[snip]
issue resolved, had nothing to do with stunnel.
-- Jason Kawaja, 2-4568 IT Expert, UF Dept of ECE
-
jason kawaja