SSL Handshake time out

SSL Handshake time out

am 09.03.2004 15:38:52 von Joe Pearson

This is a multi-part message in MIME format.
--------------090209090901060905050704
Content-Type: text/plain; charset=us-ascii; format=flowed
Content-Transfer-Encoding: 7bit

Hello,

I have a server that has been reaching max clients serveral times per
day. When I look at apache-status, 90% of the children are in "Reading
Request" state. Most of them stay in that state until the apache
"Timeout" is reached. However, some of the children stay reading until I
restart http. Since this causes my server to become unresponsive, I've
lowered the Timeout to 200, which helps somewhat, but we still have the
problem.

Here is server status of a couple of stuck processes:

Srv PID Acc M CPU SS Req Conn Child Slot Client VHost Request
*0-3* 30078 0/2188/2188 *R* 18.95 895 0 0.0 4.30 4.30 ? ?
...reading..
*1-3* 30079 0/2168/2168 *R* 20.22 1 0 0.0 6.59 6.59 ? ?
...reading..


Why do the processes stay "reading" when they have surpassed the
timeout? I've seen other people post about this problem but no one ever
responds.

Here is the ssl log for these "stuck" processes and it usually ends with
"SSL handshake timed out"

[05/Mar/2004 05:52:08 21978] [info] Connection to child 10 established
(server www3.homecu.net:443, client 66.153.14.11)
[05/Mar/2004 05:52:08 21978] [info] Seeding PRNG with 1160 bytes of
entropy
[05/Mar/2004 05:52:08 21978] [trace] OpenSSL: Handshake: start
[05/Mar/2004 05:52:08 21978] [trace] OpenSSL: Loop: before/accept
initialization
[05/Mar/2004 05:52:08 21978] [trace] Inter-Process Session Cache:
request=GET status=FOUND
id=AABA019681BD42892F8E6F1B30AA9AD295FC1ED0FEEA47F5AB13FB427 087CE5C
(session reuse)
[05/Mar/2004 05:52:08 21978] [trace] OpenSSL: Loop: SSLv3 read client
hello A
[05/Mar/2004 05:52:08 21978] [trace] OpenSSL: Loop: SSLv3 write server
hello A
[05/Mar/2004 05:52:08 21978] [trace] OpenSSL: Loop: SSLv3 write change
cipher spec A
[05/Mar/2004 05:52:08 21978] [trace] OpenSSL: Loop: SSLv3 write finished A
[05/Mar/2004 05:52:08 21978] [trace] OpenSSL: Loop: SSLv3 flush data
[05/Mar/2004 05:52:08 21978] [trace] OpenSSL: Loop: SSLv3 read finished A
[05/Mar/2004 05:52:08 21978] [trace] OpenSSL: Handshake: done
[05/Mar/2004 05:52:08 21978] [info] Connection: Client IP:
66.153.14.11, Protocol: SSLv3, Cipher: RC4-MD5 (128/128 bits)
[05/Mar/2004 05:52:09 21978] [info] Initial (No.1) HTTPS request
received for child 10 (server www3.homecu.net:443)
[05/Mar/2004 05:52:09 21978] [info] Connection to child 10 closed with
unclean shutdown (server www3.homecu.net:443, client 66.153.14.11)
[05/Mar/2004 05:52:12 21978] [info] Connection to child 10 established
(server www3.homecu.net:443, client 66.153.14.11)
[05/Mar/2004 05:52:12 21978] [info] Seeding PRNG with 1160 bytes of
entropy
[05/Mar/2004 05:52:12 21978] [trace] OpenSSL: Handshake: start
[05/Mar/2004 05:52:12 21978] [trace] OpenSSL: Loop: before/accept
initialization
[05/Mar/2004 05:52:13 21978] [trace] OpenSSL: Loop: SSLv3 read client
hello A
[05/Mar/2004 05:52:13 21978] [trace] OpenSSL: Loop: SSLv3 write server
hello A
[05/Mar/2004 05:52:13 21978] [trace] OpenSSL: Loop: SSLv3 write change
cipher spec A
[05/Mar/2004 05:52:13 21978] [trace] OpenSSL: Loop: SSLv3 write finished A
[05/Mar/2004 05:52:13 21978] [trace] OpenSSL: Loop: SSLv3 flush data
[05/Mar/2004 05:52:13 21978] [trace] OpenSSL: Loop: SSLv3 read finished A
[05/Mar/2004 05:52:13 21978] [trace] OpenSSL: Handshake: done
[05/Mar/2004 05:52:13 21978] [info] Connection: Client IP:
66.153.14.11, Protocol: SSLv3, Cipher: RC4-MD5 (128/128 bits)
[05/Mar/2004 05:52:13 21978] [info] Initial (No.1) HTTPS request
received for child 10 (server www3.homecu.net:443)
[05/Mar/2004 05:52:13 21978] [info] Connection to child 10 closed with
unclean shutdown (server www3.homecu.net:443, client 66.153.14.11)
[05/Mar/2004 05:52:32 21978] [info] Connection to child 10 established
(server www3.homecu.net:443, client 66.153.14.11)
[05/Mar/2004 05:52:32 21978] [info] Seeding PRNG with 1160 bytes of
entropy
[05/Mar/2004 05:52:32 21978] [trace] OpenSSL: Handshake: start
[05/Mar/2004 05:52:32 21978] [trace] OpenSSL: Loop: before/accept
initialization
[05/Mar/2004 05:55:53 21978] [trace] OpenSSL: Exit: error in SSLv2/v3
read client hello A
[05/Mar/2004 05:55:53 21978] [error] SSL handshake timed out (client
66.153.14.11, server www3.homecu.net:443)

This is a redhat 7.2 box with:
openssl-0.9.6b-35.7
mod_ssl-2.8.12-3
apache-1.3.27-3.7.2
Config file SetEnvIf User-Agent ".*MSIE.*" nokeepalive
ssl-unclean-shutdown downgrade-1.0 force-response-1.0

Any ideas where to go from here to determine why this is happening?

Thanks,
Joe Pearson


--------------090209090901060905050704
Content-Type: text/html; charset=us-ascii
Content-Transfer-Encoding: 7bit








Hello,




I have a server that has been reaching max clients serveral times per
day.  When I look at apache-status, 90% of the children are in "Reading
Request" state.  Most of them stay in that state until the apache
"Timeout" is reached. However, some of the children stay reading until
I restart http.  Since this causes my server to become unresponsive,
I've lowered the Timeout to 200, which helps somewhat, but we still
have the problem.




Here is server status of a couple of stuck processes:



















































Srv PID Acc M CPU SS Req Conn Child Slot Client VHost Request
0-3 30078 0/2188/2188 R 18.95 895 0 0.0 4.30 4.30 ? ? ..reading..
1-3 30079 0/2168/2168 R 20.22 1 0 0.0 6.59 6.59 ? ? ..reading..



Why do the processes stay "reading" when they have surpassed the
timeout?  I've seen other people post about this problem but no one
ever responds.



Here is the ssl log for these "stuck" processes and it usually ends
with "SSL handshake timed out"




[05/Mar/2004 05:52:08 21978] [info]  Connection to child 10 established
(server www3.homecu.net:443, client 66.153.14.11)


[05/Mar/2004 05:52:08 21978] [info]  Seeding PRNG with 1160 bytes of
entropy


[05/Mar/2004 05:52:08 21978] [trace] OpenSSL: Handshake: start


[05/Mar/2004 05:52:08 21978] [trace] OpenSSL: Loop: before/accept
initialization


[05/Mar/2004 05:52:08 21978] [trace] Inter-Process Session Cache:
request=GET status=FOUND
id=AABA019681BD42892F8E6F1B30AA9AD295FC1ED0FEEA47F5AB13FB427 087CE5C
(session reuse)


[05/Mar/2004 05:52:08 21978] [trace] OpenSSL: Loop: SSLv3 read client
hello A


[05/Mar/2004 05:52:08 21978] [trace] OpenSSL: Loop: SSLv3 write server
hello A


[05/Mar/2004 05:52:08 21978] [trace] OpenSSL: Loop: SSLv3 write change
cipher spec A


[05/Mar/2004 05:52:08 21978] [trace] OpenSSL: Loop: SSLv3 write
finished A


[05/Mar/2004 05:52:08 21978] [trace] OpenSSL: Loop: SSLv3 flush data


[05/Mar/2004 05:52:08 21978] [trace] OpenSSL: Loop: SSLv3 read finished
A


[05/Mar/2004 05:52:08 21978] [trace] OpenSSL: Handshake: done


[05/Mar/2004 05:52:08 21978] [info]  Connection: Client IP:
66.153.14.11, Protocol: SSLv3, Cipher: RC4-MD5 (128/128 bits)


[05/Mar/2004 05:52:09 21978] [info]  Initial (No.1) HTTPS request
received for child 10 (server www3.homecu.net:443)


[05/Mar/2004 05:52:09 21978] [info]  Connection to child 10 closed
with unclean shutdown (server www3.homecu.net:443, client 66.153.14.11)


[05/Mar/2004 05:52:12 21978] [info]  Connection to child 10 established
(server www3.homecu.net:443, client 66.153.14.11)


[05/Mar/2004 05:52:12 21978] [info]  Seeding PRNG with 1160 bytes of
entropy


[05/Mar/2004 05:52:12 21978] [trace] OpenSSL: Handshake: start


[05/Mar/2004 05:52:12 21978] [trace] OpenSSL: Loop: before/accept
initialization


[05/Mar/2004 05:52:13 21978] [trace] OpenSSL: Loop: SSLv3 read client
hello A


[05/Mar/2004 05:52:13 21978] [trace] OpenSSL: Loop: SSLv3 write server
hello A


[05/Mar/2004 05:52:13 21978] [trace] OpenSSL: Loop: SSLv3 write change
cipher spec A


[05/Mar/2004 05:52:13 21978] [trace] OpenSSL: Loop: SSLv3 write
finished A


[05/Mar/2004 05:52:13 21978] [trace] OpenSSL: Loop: SSLv3 flush data


[05/Mar/2004 05:52:13 21978] [trace] OpenSSL: Loop: SSLv3 read finished
A


[05/Mar/2004 05:52:13 21978] [trace] OpenSSL: Handshake: done


[05/Mar/2004 05:52:13 21978] [info]  Connection: Client IP:
66.153.14.11, Protocol: SSLv3, Cipher: RC4-MD5 (128/128 bits)


[05/Mar/2004 05:52:13 21978] [info]  Initial (No.1) HTTPS request
received for child 10 (server www3.homecu.net:443)


[05/Mar/2004 05:52:13 21978] [info]  Connection to child 10 closed
with unclean shutdown (server www3.homecu.net:443, client 66.153.14.11)


[05/Mar/2004 05:52:32 21978] [info]  Connection to child 10 established
(server www3.homecu.net:443, client 66.153.14.11)


[05/Mar/2004 05:52:32 21978] [info]  Seeding PRNG with 1160 bytes of
entropy


[05/Mar/2004 05:52:32 21978] [trace] OpenSSL: Handshake: start


[05/Mar/2004 05:52:32 21978] [trace] OpenSSL: Loop: before/accept
initialization


[05/Mar/2004 05:55:53 21978] [trace] OpenSSL: Exit: error in SSLv2/v3
read client hello A


[05/Mar/2004 05:55:53 21978] [error] SSL handshake timed out (client
66.153.14.11, server www3.homecu.net:443)




This is a redhat 7.2 box with:


openssl-0.9.6b-35.7


mod_ssl-2.8.12-3


apache-1.3.27-3.7.2


Config file  SetEnvIf User-Agent ".*MSIE.*" nokeepalive
ssl-unclean-shutdown  downgrade-1.0 force-response-1.0




Any ideas where to go from here to determine why this is happening?




Thanks,


Joe Pearson







--------------090209090901060905050704--

____________________________________________________________ __________
Apache Interface to OpenSSL (mod_ssl) www.modssl.org
User Support Mailing List modssl-users@modssl.org
Automated List Manager majordomo@modssl.org

RE: SSL Handshake time out

am 09.03.2004 16:03:02 von John.Airey

-----Original Message-----
From: Joe Pearson [mailto:joe@webdms.com]
Sent: Tuesday, 09 March 2004 14:39
To: modssl-users@modssl.org
Subject: SSL Handshake time out


Hello,

I have a server that has been reaching max clients serveral times per day.
When I look at apache-status, 90% of the children are in "Reading Request"
state. Most of them stay in that state until the apache "Timeout" is
reached. However, some of the children stay reading until I restart http.
Since this causes my server to become unresponsive, I've lowered the Timeout
to 200, which helps somewhat, but we still have the problem.
> [snip]

What's your SSLSeesionCache set to? I can't remember the 7.2 settings (It'll
be in the archives though as I've posted the right one before). The Red Hat
9 setting is:

SSLSessionCache dbm:/var/cache/mod_ssl/scache

Of course, 7.2 isn't supported by Red Hat any more, but there is a "legacy"
project to keep patches up to date.

-
John Airey, BSc (Jt Hons), CNA, RHCE
Internet systems support officer, ITCSD, Royal National Institute of the
Blind,
Bakewell Road, Peterborough PE2 6XU,
Tel.: +44 (0) 1733 375299 Fax: +44 (0) 1733 370848 John.Airey@rnib.org.uk

Why do so many people who call themselves christians use the name of Jesus
Christ as a swear word?

-
DISCLAIMER:

NOTICE: The information contained in this email and any attachments is
confidential and may be privileged. If you are not the intended
recipient you should not use, disclose, distribute or copy any of the
content of it or of any attachment; you are requested to notify the
sender immediately of your receipt of the email and then to delete it
and any attachments from your system.

RNIB endeavours to ensure that emails and any attachments generated by
its staff are free from viruses or other contaminants. However, it
cannot accept any responsibility for any such which are transmitted.
We therefore recommend you scan all attachments.

Please note that the statements and views expressed in this email and
any attachments are those of the author and do not necessarily represent
those of RNIB.

RNIB Registered Charity Number: 226227

Website: http://www.rnib.org.uk
____________________________________________________________ __________
Apache Interface to OpenSSL (mod_ssl) www.modssl.org
User Support Mailing List modssl-users@modssl.org
Automated List Manager majordomo@modssl.org

Re: SSL Handshake time out

am 09.03.2004 17:33:20 von Joe Pearson

SSLSessionCache shm:/var/cache/ssl_gcache_data(524288)
I'm not sure why it is set to that, but it is. I have a different
system that does not have this problem and it's session cache is set thus:

SSLSessionCache shm:logs/ssl_scache(512000)

I've also noticed that children that don't get reset when the timeout is
reached, usually end with this:
[09/Mar/2004 08:58:31 18268] [error] SSL handshake timed out (client
164.165.89.
10, server www3.homecu.net:443)
[09/Mar/2004 09:02:23 18268] [error] SSL handshake interrupted by system
[Hint:
Stop button pressed in browser?!] (System error follows)
[09/Mar/2004 09:02:23 18268] [error] System: Connection reset by peer
(errno: 104)

We are subscribed to progeny for Redhat 7.x patches. We tried RHEL and
we had so many problems that we
had to revert back to 7.x until we decide what direction to go.

John.Airey@rnib.org.uk wrote:

>-----Original Message-----
>From: Joe Pearson [mailto:joe@webdms.com]
>Sent: Tuesday, 09 March 2004 14:39
>To: modssl-users@modssl.org
>Subject: SSL Handshake time out
>
>
>Hello,
>
>I have a server that has been reaching max clients serveral times per day.
>When I look at apache-status, 90% of the children are in "Reading Request"
>state. Most of them stay in that state until the apache "Timeout" is
>reached. However, some of the children stay reading until I restart http.
>Since this causes my server to become unresponsive, I've lowered the Timeout
>to 200, which helps somewhat, but we still have the problem.
>
>
>>[snip]
>>
>>
>
>What's your SSLSeesionCache set to? I can't remember the 7.2 settings (It'll
>be in the archives though as I've posted the right one before). The Red Hat
>9 setting is:
>
>SSLSessionCache dbm:/var/cache/mod_ssl/scache
>
>Of course, 7.2 isn't supported by Red Hat any more, but there is a "legacy"
>project to keep patches up to date.
>
>-
>John Airey, BSc (Jt Hons), CNA, RHCE
>Internet systems support officer, ITCSD, Royal National Institute of the
>Blind,
>Bakewell Road, Peterborough PE2 6XU,
>Tel.: +44 (0) 1733 375299 Fax: +44 (0) 1733 370848 John.Airey@rnib.org.uk
>
>Why do so many people who call themselves christians use the name of Jesus
>Christ as a swear word?
>
>-
>DISCLAIMER:
>
>NOTICE: The information contained in this email and any attachments is
>confidential and may be privileged. If you are not the intended
>recipient you should not use, disclose, distribute or copy any of the
>content of it or of any attachment; you are requested to notify the
>sender immediately of your receipt of the email and then to delete it
>and any attachments from your system.
>
>RNIB endeavours to ensure that emails and any attachments generated by
>its staff are free from viruses or other contaminants. However, it
>cannot accept any responsibility for any such which are transmitted.
>We therefore recommend you scan all attachments.
>
>Please note that the statements and views expressed in this email and
>any attachments are those of the author and do not necessarily represent
>those of RNIB.
>
>RNIB Registered Charity Number: 226227
>
>Website: http://www.rnib.org.uk
>___________________________________________________________ ___________
>Apache Interface to OpenSSL (mod_ssl) www.modssl.org
>User Support Mailing List modssl-users@modssl.org
>Automated List Manager majordomo@modssl.org
>
>

____________________________________________________________ __________
Apache Interface to OpenSSL (mod_ssl) www.modssl.org
User Support Mailing List modssl-users@modssl.org
Automated List Manager majordomo@modssl.org