httpd-bugs mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From bugzi...@apache.org
Subject DO NOT REPLY [Bug 52476] SSL failures on windows with AcceptFilter https none
Date Wed, 18 Jan 2012 07:47:54 GMT
https://issues.apache.org/bugzilla/show_bug.cgi?id=52476

Kaspar Brand <asfbugz@velox.ch> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
         OS/Version|All                         |Windows 7

--- Comment #8 from Kaspar Brand <asfbugz@velox.ch> 2012-01-18 07:47:54 UTC ---
I'm not really familiar with the I/O layer in mod_ssl, unfortunately, but from
examining the logs provided by Daniel (thanks a lot), there seems to be a
pattern which is common to the failure cases.

In opensslRequest\error.log, we have:

[Tue Jan 17 09:01:00.276626 2012] [ssl:info] [pid 10672:tid 1256] [client
127.0.0.1:55343] AH01964: Connection to child 63 established (server
www.example.com:443)
[Tue Jan 17 09:01:00.276626 2012] [ssl:trace2] [pid 10672:tid 1256]
ssl_engine_rand.c(123): Seeding PRNG with 144 bytes of entropy
[Tue Jan 17 09:01:00.276626 2012] [ssl:trace3] [pid 10672:tid 1256]
ssl_engine_kernel.c(1832): [client 127.0.0.1:55343] OpenSSL: Handshake: start
[Tue Jan 17 09:01:00.276626 2012] [ssl:trace3] [pid 10672:tid 1256]
ssl_engine_kernel.c(1840): [client 127.0.0.1:55343] OpenSSL: Loop:
before/accept initialization
[Tue Jan 17 09:01:00.276626 2012] [core:trace6] [pid 10672:tid 1256]
core_filters.c(502): [client 127.0.0.1:55343] core_output_filter: flushing
because of FLUSH bucket
[Tue Jan 17 09:01:00.276626 2012] [ssl:trace4] [pid 10672:tid 1256]
ssl_engine_io.c(2000): [client 127.0.0.1:55343] OpenSSL: I/O error, 11 bytes
expected to read on BIO#2856280 [mem: 28e0888]
[Tue Jan 17 09:01:00.276626 2012] [ssl:trace3] [pid 10672:tid 1256]
ssl_engine_kernel.c(1869): [client 127.0.0.1:55343] OpenSSL: Exit: error in
SSLv2/v3 read client hello A
[Tue Jan 17 09:01:00.276626 2012] [core:trace6] [pid 10672:tid 1256]
core_filters.c(502): [client 127.0.0.1:55343] core_output_filter: flushing
because of FLUSH bucket
[Tue Jan 17 09:01:00.276626 2012] [ssl:trace4] [pid 10672:tid 1256]
ssl_engine_io.c(2000): [client 127.0.0.1:55343] OpenSSL: I/O error, 11 bytes
expected to read on BIO#2856280 [mem: 28e0888]
[Tue Jan 17 09:01:00.276626 2012] [ssl:trace3] [pid 10672:tid 1256]
ssl_engine_kernel.c(1869): [client 127.0.0.1:55343] OpenSSL: Exit: error in
SSLv2/v3 read client hello A

I'm not sure if there's some artifact in the logging infrastructure (all these
have the same ┬Ásec timestamp), but what is peculiar is that whenever the
request fails, there are two occurrences of "OpenSSL: I/O error, 11 bytes
expected" - i.e., it looks like the same thread (tid 1256, in the above case)
is trying to read the client hello, but apparently doesn't get anything.

For successful requests, the 11-byte read succeeds in the first attempt (see
goodRequest\error.log). Finally, in the firefox8.0.1Request\error.log, there's
this "interesting" combination of events:

[Tue Jan 17 09:03:18.268556 2012] [ssl:info] [pid 1088:tid 1232] [client
127.0.0.1:55354] AH01964: Connection to child 43 established (server
www.example.com:443)
[Tue Jan 17 09:03:18.268556 2012] [ssl:trace2] [pid 1088:tid 1232]
ssl_engine_rand.c(123): Seeding PRNG with 144 bytes of entropy
[Tue Jan 17 09:03:18.268556 2012] [ssl:trace3] [pid 1088:tid 1232]
ssl_engine_kernel.c(1832): [client 127.0.0.1:55354] OpenSSL: Handshake: start
[Tue Jan 17 09:03:18.268556 2012] [ssl:trace3] [pid 1088:tid 1232]
ssl_engine_kernel.c(1840): [client 127.0.0.1:55354] OpenSSL: Loop:
before/accept initialization
[Tue Jan 17 09:03:18.268556 2012] [core:trace6] [pid 1088:tid 1232]
core_filters.c(502): [client 127.0.0.1:55354] core_output_filter: flushing
because of FLUSH bucket
[Tue Jan 17 09:03:18.268556 2012] [ssl:trace4] [pid 1088:tid 1232]
ssl_engine_io.c(2000): [client 127.0.0.1:55354] OpenSSL: I/O error, 11 bytes
expected to read on BIO#2756a80 [mem: 27e0890]
[Tue Jan 17 09:03:18.268556 2012] [ssl:trace3] [pid 1088:tid 1232]
ssl_engine_kernel.c(1869): [client 127.0.0.1:55354] OpenSSL: Exit: error in
SSLv2/v3 read client hello A
[Tue Jan 17 09:03:18.268556 2012] [core:trace6] [pid 1088:tid 1232]
core_filters.c(502): [client 127.0.0.1:55354] core_output_filter: flushing
because of FLUSH bucket
[Tue Jan 17 09:03:18.268556 2012] [ssl:trace4] [pid 1088:tid 1232]
ssl_engine_io.c(1989): [client 127.0.0.1:55354] OpenSSL: read 11/11 bytes from
BIO#2756a80 [mem: 27e0890] (BIO dump follows)

I.e., the first read fails, but the second one succeeds (and again, the
timestamps are identical, but it's unclear if this reflects reality).

-- 
Configure bugmail: https://issues.apache.org/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org


Mime
View raw message