https://issues.apache.org/bugzilla/show_bug.cgi?id=52476
Kaspar Brand <[email protected]> changed: What |Removed |Added ---------------------------------------------------------------------------- OS/Version|All |Windows 7 --- Comment #8 from Kaspar Brand <[email protected]> 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: [email protected] For additional commands, e-mail: [email protected]
