Bug 39653

Summary:	dummy connections should avoid SSL vhosts
Product:	Apache httpd-2	Reporter:	Arkadi Shishlov <arkadi>
Component:	Core	Assignee:	Apache HTTPD Bugs Mailing List <bugs>
Status:	RESOLVED FIXED
Severity:	enhancement	CC:	bjorn.wiberg, brian, f.malfatto, markus, takashi.asfbugzilla, uhlar
Priority:	P2
Version:	2.2.6
Target Milestone:	---
Hardware:	Other
OS:	other

Description Arkadi Shishlov 2006-05-24 12:39:32 UTC

Apache is started with mod_ssl enabled. When doing graceful restart a lot of
messages about SSL handshake failed are written to error.log. Every apache child
process thinks incoming connection is arrived. The restart is completed sucessfully.
The OS is FreeBSD 4.11.

[Wed May 24 14:12:27 2006] [notice] Graceful restart requested, doing restart
[Wed May 24 14:12:27 2006] [info] [client 62.85.37.81] Connection to child 1
established (server idea.hosting.lv:443)
[Wed May 24 14:12:27 2006] [info] [client 62.85.37.81] Connection to child 5
established (server idea.hosting.lv:443)
[Wed May 24 14:12:27 2006] [info] [client 62.85.37.81] Connection to child 6
established (server idea.hosting.lv:443)
[Wed May 24 14:12:27 2006] [info] [client 62.85.37.81] Connection to child 2
established (server idea.hosting.lv:443)
[Wed May 24 14:12:27 2006] [info] [client 62.85.37.81] Connection to child 0
established (server idea.hosting.lv:443)
[Wed May 24 14:12:27 2006] [info] [client 62.85.37.81] Connection to child 7
established (server idea.hosting.lv:443)
[Wed May 24 14:12:27 2006] [info] [client 62.85.37.81] Connection to child 4
established (server idea.hosting.lv:443)
[Wed May 24 14:12:27 2006] [info] [client 62.85.37.81] Connection to child 8
established (server idea.hosting.lv:443)
[Wed May 24 14:12:27 2006] [info] [client 62.85.37.81] Connection to child 3
established (server idea.hosting.lv:443)
[Wed May 24 14:12:27 2006] [info] [client 62.85.37.81] Connection to child 9
established (server idea.hosting.lv:443)
[Wed May 24 14:12:27 2006] [info] Seeding PRNG with 136 bytes of entropy
[Wed May 24 14:12:27 2006] [info] Seeding PRNG with 136 bytes of entropy
[Wed May 24 14:12:27 2006] [info] Seeding PRNG with 136 bytes of entropy
[Wed May 24 14:12:27 2006] [info] Seeding PRNG with 136 bytes of entropy
[Wed May 24 14:12:27 2006] [info] Seeding PRNG with 136 bytes of entropy
[Wed May 24 14:12:27 2006] [info] Seeding PRNG with 136 bytes of entropy
[Wed May 24 14:12:27 2006] [info] Seeding PRNG with 136 bytes of entropy
[Wed May 24 14:12:27 2006] [info] Seeding PRNG with 136 bytes of entropy
[Wed May 24 14:12:27 2006] [info] Seeding PRNG with 136 bytes of entropy
[Wed May 24 14:12:27 2006] [info] Seeding PRNG with 136 bytes of entropy
[Wed May 24 14:12:27 2006] [info] [client 62.85.37.81] SSL handshake failed:
HTTP spoken on HTTPS port; trying to send HTML er
[Wed May 24 14:12:27 2006] [info] [client 62.85.37.81] SSL handshake failed:
HTTP spoken on HTTPS port; trying to send HTML er
[Wed May 24 14:12:27 2006] [info] [client 62.85.37.81] SSL handshake failed:
HTTP spoken on HTTPS port; trying to send HTML er
[Wed May 24 14:12:27 2006] [info] [client 62.85.37.81] SSL handshake failed:
HTTP spoken on HTTPS port; trying to send HTML er
[Wed May 24 14:12:27 2006] [info] [client 62.85.37.81] SSL handshake failed:
HTTP spoken on HTTPS port; trying to send HTML er
[Wed May 24 14:12:27 2006] [info] [client 62.85.37.81] SSL handshake failed:
HTTP spoken on HTTPS port; trying to send HTML er
[Wed May 24 14:12:27 2006] [info] [client 62.85.37.81] SSL handshake failed:
HTTP spoken on HTTPS port; trying to send HTML er
[Wed May 24 14:12:27 2006] [info] [client 62.85.37.81] SSL handshake failed:
HTTP spoken on HTTPS port; trying to send HTML er
[Wed May 24 14:12:27 2006] [info] [client 62.85.37.81] SSL handshake failed:
HTTP spoken on HTTPS port; trying to send HTML er
[Wed May 24 14:12:27 2006] [info] [client 62.85.37.81] SSL handshake failed:
HTTP spoken on HTTPS port; trying to send HTML er
[Wed May 24 14:12:27 2006] [info] SSL Library Error: 336027804
error:1407609C:SSL routines:SSL23_GET_CLIENT_HELLO:http request
[Wed May 24 14:12:27 2006] [info] SSL Library Error: 336027804
error:1407609C:SSL routines:SSL23_GET_CLIENT_HELLO:http request
[Wed May 24 14:12:27 2006] [info] SSL Library Error: 336027804
error:1407609C:SSL routines:SSL23_GET_CLIENT_HELLO:http request
[Wed May 24 14:12:27 2006] [info] SSL Library Error: 336027804
error:1407609C:SSL routines:SSL23_GET_CLIENT_HELLO:http request
[Wed May 24 14:12:27 2006] [info] SSL Library Error: 336027804
error:1407609C:SSL routines:SSL23_GET_CLIENT_HELLO:http request
[Wed May 24 14:12:27 2006] [info] SSL Library Error: 336027804
error:1407609C:SSL routines:SSL23_GET_CLIENT_HELLO:http request
[Wed May 24 14:12:27 2006] [info] SSL Library Error: 336027804
error:1407609C:SSL routines:SSL23_GET_CLIENT_HELLO:http request
[Wed May 24 14:12:27 2006] [info] SSL Library Error: 336027804
error:1407609C:SSL routines:SSL23_GET_CLIENT_HELLO:http request
[Wed May 24 14:12:27 2006] [info] SSL Library Error: 336027804
error:1407609C:SSL routines:SSL23_GET_CLIENT_HELLO:http request

Comment 1 Paul Querna 2006-06-21 09:16:59 UTC

This is caused by the core trying to activate any accept filters that might
leave a process stuck waiting for data from a client.

Comment 2 Joe Orton 2006-06-21 12:15:38 UTC

I don't think it's really worth making real SSL connections to fix this; what
would be useful though is that dummy_connection() could specifically look for a
non-SSL vhost to use.  But ->protocol is not getting set to "https" for such
servers at the moment unless explicitly configured :(

Comment 3 Joe Orton 2006-07-03 11:51:04 UTC

Fixing this is an RFE for the core, current behaviour is not really causing
incorrect server operation, just some error_log spam.

Comment 4 Arkadi Shishlov 2006-07-03 11:54:54 UTC

There are also access_log records. Not nice when monitoring status codes.

Comment 5 Joe Orton 2007-02-27 09:05:54 UTC

*** Bug 41459 has been marked as a duplicate of this bug. ***

Comment 6 Paul Querna 2007-03-05 11:56:12 UTC

*** Bug 41191 has been marked as a duplicate of this bug. ***

Comment 7 Christine Ross 2007-05-22 16:30:57 UTC

I have a new 64 bit apache 2.2.4 server on Solaris 10 with openssl 0.9.8e. When 
I DO NOT have the ssl.conf file included and I "apachectl graceful" to apache, 
all my processes that are gracefully shutdown are shown by a dash (-). When I 
have the Include line for the ssl.conf file uncommented, the number of Gs never 
changes, like it is locked in the graceful shutdown. 

any suggestions

Comment 8 Stavros Korokithakis 2007-07-12 01:42:49 UTC

I have a suspicion that this bug caused my apache to spawn 150 processes (as 
many as MaxClients would allow), thus repeatedly crashing the server (once per 
day).

This bug makes about one request per second, I suspect causing apache to spawn 
multiple instances, although I don't know why it would spawn as many as 
MaxSpareServers and not as many as MaxClients right away.

Comment 9 Takashi Sato 2007-11-27 16:15:38 UTC

*** Bug 43978 has been marked as a duplicate of this bug. ***

Comment 10 Markus Senoner 2007-11-27 23:28:43 UTC

Is there a workaround?
I don't like my access_log filled with several thousand erroneous lines a day

Comment 11 Glenn Nielsen 2007-11-29 14:51:32 UTC

I am seeing the same problem with apache 2.2.6 from ports on FreeBSD 
6.2-RELEASE-p4 FreeBSD 6.2-RELEASE-p4 #0 .

We recently upgraded to Apache 2.2 from Apache 2.0. With apache 2.0 we
could do an apachectl graceful at will with no impact to those visiting
the sites we host. With apache 2.2 apachectl graceful causes a large load
spike which results in a disruption serving requests. We have had to limit
our apachectl graceful's to times when there is low request volume.

Comment 12 Takashi Sato 2007-11-29 15:45:33 UTC

One of the workarounds is using Worker MPM

Comment 13 Glenn Nielsen 2008-01-07 07:51:39 UTC

I reinstalled apache 2.2.6 with the worker MPM on FreeBSD 6.2-RELEASE-p4 #0.

The number of "GET /" 400 480 "-" "-" log entries have pretty much gone away,
I am still seeing a few.

We still see a large load spike when we graceful apache.

Comment 14 Matus "fantomas" Uhlar 2008-08-15 02:21:05 UTC

I fixed this behaviour by putting "listen 443" before "listen 80". Is it possible that apache uses last provided port for connecting to clients?

Comment 15 Joe Orton 2008-12-12 08:09:36 UTC

Best we can do for this is I think as committed to trunk in r726065.