Closed Bug 725652 Opened 12 years ago Closed 8 years ago

SSL client auth broken on Apache, when a directory of CA certificates is specified

Categories

(Core :: Security: PSM, defect)

Product:
Core
Component:
Security: PSM
Version:
10 Branch
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

()

Status:
RESOLVED INVALID

People

(Reporter: calestyo, Unassigned)

References

(
URL
)

Details

User Agent: Mozilla/5.0 (X11; Linux x86_64; rv:10.0) Gecko/20100101 Firefox/10.0 Iceweasel/10.0
Build ID: 20120205110156

Steps to reproduce:

I have a Apache HTTPD Server 2.2.16 running, compiled against OpenSSL 0.9.8o.

There are name based virtual hosts configured on it. SNI is enabled.
There is a default name based virtual host, which is actually never used (it's ServerName is set to localhost) and several further name based virtual hosts.

The CA certs are added to Firefox and enabled.

I try to access one of the later.

When SSL client authentication is disabled, accessing the SNI host works.
When I however configure the server to demand SSL client authentication accessing fails.

I get the certificate selection dialog (even with the correct subset of certificates proposed).
But when I choose one, Firefox aborts with:
SSL peer cannot verify your certificate.
(Error code: ssl_error_bad_cert_alert)

The server log shows:
[Thu Feb 09 15:54:43 2012] [info] [client 192.168.180.174] Connection to child 1 established (server localhost:443)
[Thu Feb 09 15:54:43 2012] [info] Seeding PRNG with 1312 bytes of entropy
[Thu Feb 09 15:54:43 2012] [debug] ssl_engine_kernel.c(1866): OpenSSL: Handshake: start
[Thu Feb 09 15:54:43 2012] [debug] ssl_engine_kernel.c(1874): OpenSSL: Loop: before/accept initialization
[Thu Feb 09 15:54:43 2012] [debug] ssl_engine_io.c(1882): OpenSSL: read 11/11 bytes from BIO#7fac223174d0 [mem: 7fac22337c40] (BIO dump follows)
[Thu Feb 09 15:54:43 2012] [debug] ssl_engine_io.c(1815): +-------------------------------------------------------------------------+
[Thu Feb 09 15:54:43 2012] [debug] ssl_engine_io.c(1854): | 0000: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:54:43 2012] [debug] ssl_engine_io.c(1860): +-------------------------------------------------------------------------+
[Thu Feb 09 15:54:43 2012] [debug] ssl_engine_io.c(1882): OpenSSL: read 172/172 bytes from BIO#7fac223174d0 [mem: 7fac22337c4b] (BIO dump follows)
[Thu Feb 09 15:54:43 2012] [debug] ssl_engine_io.c(1815): +-------------------------------------------------------------------------+
[Thu Feb 09 15:54:43 2012] [debug] ssl_engine_io.c(1854): | 0000: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:54:43 2012] [debug] ssl_engine_io.c(1854): | 0010: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:54:43 2012] [debug] ssl_engine_io.c(1854): | 0020: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:54:43 2012] [debug] ssl_engine_io.c(1854): | 0030: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:54:43 2012] [debug] ssl_engine_io.c(1854): | 0040: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:54:43 2012] [debug] ssl_engine_io.c(1854): | 0050: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:54:43 2012] [debug] ssl_engine_io.c(1854): | 0060: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:54:43 2012] [debug] ssl_engine_io.c(1854): | 0070: 00 00 23 00 21 00 00 1e-6c 63 67 2d 6c 72 7a 2d  ..#.!...lcg-lrz- |
[Thu Feb 09 15:54:43 2012] [debug] ssl_engine_io.c(1854): | 0080: 6d 6f 6e 69 74 6f 72 69-6e 67 2e 67 72 69 64 2e  monitoring.grid. |
[Thu Feb 09 15:54:43 2012] [debug] ssl_engine_io.c(1854): | 0090: 6c 72 7a 2e 64 65 00 0a-00 08 00 06 00 17 00 18  lrz.de.......... |
[Thu Feb 09 15:54:43 2012] [debug] ssl_engine_io.c(1854): | 00a0: 00 19 00 0b 00 02 01 00-00 23                    .........#       |
[Thu Feb 09 15:54:43 2012] [debug] ssl_engine_io.c(1858): | 0172 - <SPACES/NULS>
[Thu Feb 09 15:54:43 2012] [debug] ssl_engine_io.c(1860): +-------------------------------------------------------------------------+
[Thu Feb 09 15:54:43 2012] [debug] ssl_engine_kernel.c(1987): [client 192.168.180.174] SSL virtual host for servername lcg-lrz-monitoring.grid.lrz.de found
[Thu Feb 09 15:54:43 2012] [error] [client 192.168.180.174] Certificate Verification: Error (20): unable to get local issuer certificate
[Thu Feb 09 15:54:43 2012] [info] [client 192.168.180.174] SSL library error 1 in handshake (server localhost:443)
[Thu Feb 09 15:54:43 2012] [info] SSL Library Error: 336105650 error:140890B2:SSL routines:SSL3_GET_CLIENT_CERTIFICATE:no certificate returned
[Thu Feb 09 15:54:43 2012] [info] [client 192.168.180.174] Connection closed to child 1 with abortive shutdown (server lcg-lrz-monitoring.grid.lrz.de:443)

One may argue that this is a server error, but I don't think so, as it perfectly works with chromium.
With chromium the server log shows:
[Thu Feb 09 15:59:14 2012] [info] [client 192.168.180.174] Connection to child 134 established (server localhost:443)
[Thu Feb 09 15:59:14 2012] [info] Seeding PRNG with 1312 bytes of entropy
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1866): OpenSSL: Handshake: start
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1874): OpenSSL: Loop: before/accept initialization
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1882): OpenSSL: read 11/11 bytes from BIO#7fac22317410 [mem: 7fac2234ecd0] (BIO dump follows)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1815): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0000: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1858): | 0011 - <SPACES/NULS>
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1860): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1882): OpenSSL: read 111/111 bytes from BIO#7fac22317410 [mem: 7fac2234ecdb] (BIO dump follows)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1815): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0000: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0010: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0020: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0030: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0040: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0050: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0060: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1858): | 0111 - <SPACES/NULS>
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1860): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_scache_shmcb.c(393): ssl_scache_shmcb_retrieve (0xba -> subcache 26)
[Thu Feb 09 15:59:14 2012] [debug] ssl_scache_shmcb.c(680): possible match at idx=0, data=0
[Thu Feb 09 15:59:14 2012] [debug] ssl_scache_shmcb.c(697): shmcb_subcache_retrieve returning matching session
[Thu Feb 09 15:59:14 2012] [debug] ssl_scache_shmcb.c(408): leaving ssl_scache_shmcb_retrieve successfully
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1732): Inter-Process Session Cache: request=GET status=FOUND id=BA3353B885504DC92528C09B9770104A3C3F4BD81846DF9A2850E929FD43054F (session reuse)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1874): OpenSSL: Loop: SSLv3 read client hello A
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1874): OpenSSL: Loop: SSLv3 write server hello A
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1874): OpenSSL: Loop: SSLv3 write change cipher spec A
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1874): OpenSSL: Loop: SSLv3 write finished A
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1874): OpenSSL: Loop: SSLv3 flush data
[Thu Feb 09 15:59:14 2012] [info] [client 192.168.180.174] Connection to child 6 established (server localhost:443)
[Thu Feb 09 15:59:14 2012] [info] Seeding PRNG with 1312 bytes of entropy
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1866): OpenSSL: Handshake: start
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1874): OpenSSL: Loop: before/accept initialization
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1882): OpenSSL: read 11/11 bytes from BIO#7fac223470f0 [mem: 7fac2233d1a0] (BIO dump follows)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1815): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0000: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1858): | 0011 - <SPACES/NULS>
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1860): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1882): OpenSSL: read 111/111 bytes from BIO#7fac223470f0 [mem: 7fac2233d1ab] (BIO dump follows)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1815): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0000: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0010: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0020: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0030: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0040: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0050: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0060: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1858): | 0111 - <SPACES/NULS>
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1860): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_scache_shmcb.c(393): ssl_scache_shmcb_retrieve (0xba -> subcache 26)
[Thu Feb 09 15:59:14 2012] [debug] ssl_scache_shmcb.c(680): possible match at idx=0, data=0
[Thu Feb 09 15:59:14 2012] [debug] ssl_scache_shmcb.c(697): shmcb_subcache_retrieve returning matching session
[Thu Feb 09 15:59:14 2012] [debug] ssl_scache_shmcb.c(408): leaving ssl_scache_shmcb_retrieve successfully
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1732): Inter-Process Session Cache: request=GET status=FOUND id=BA3353B885504DC92528C09B9770104A3C3F4BD81846DF9A2850E929FD43054F (session reuse)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1874): OpenSSL: Loop: SSLv3 read client hello A
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1874): OpenSSL: Loop: SSLv3 write server hello A
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1874): OpenSSL: Loop: SSLv3 write change cipher spec A
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1874): OpenSSL: Loop: SSLv3 write finished A
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1874): OpenSSL: Loop: SSLv3 flush data
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1882): OpenSSL: read 5/5 bytes from BIO#7fac22317410 [mem: 7fac2234ecd0] (BIO dump follows)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1815): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0000: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1860): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1882): OpenSSL: read 1/1 bytes from BIO#7fac22317410 [mem: 7fac2234ecd5] (BIO dump follows)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1815): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0000: 01                                               .                |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1860): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1882): OpenSSL: read 5/5 bytes from BIO#7fac22317410 [mem: 7fac2234ecd0] (BIO dump follows)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1815): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0000: 16 03 00 00 40                                   ....@            |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1860): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1882): OpenSSL: read 64/64 bytes from BIO#7fac22317410 [mem: 7fac2234ecd5] (BIO dump follows)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1815): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0000: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0010: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0020: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0030: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1860): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1874): OpenSSL: Loop: SSLv3 read finished A
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1870): OpenSSL: Handshake: done
[Thu Feb 09 15:59:14 2012] [info] Connection: Client IP: 192.168.180.174, Protocol: SSLv3, Cipher: AES256-SHA (256/256 bits)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1882): OpenSSL: read 5/5 bytes from BIO#7fac223470f0 [mem: 7fac2233d1a0] (BIO dump follows)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1815): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0000: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1860): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1882): OpenSSL: read 1/1 bytes from BIO#7fac223470f0 [mem: 7fac2233d1a5] (BIO dump follows)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1815): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0000: 01                                               .                |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1860): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1882): OpenSSL: read 5/5 bytes from BIO#7fac223470f0 [mem: 7fac2233d1a0] (BIO dump follows)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1815): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0000: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1860): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1882): OpenSSL: read 64/64 bytes from BIO#7fac223470f0 [mem: 7fac2233d1a5] (BIO dump follows)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1815): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0000: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0010: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0020: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0030: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1860): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1874): OpenSSL: Loop: SSLv3 read finished A
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1870): OpenSSL: Handshake: done
[Thu Feb 09 15:59:14 2012] [info] Connection: Client IP: 192.168.180.174, Protocol: SSLv3, Cipher: AES256-SHA (256/256 bits)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1893): OpenSSL: I/O error, 5 bytes expected to read on BIO#7fac223470f0 [mem: 7fac2233d1a0]
[Thu Feb 09 15:59:14 2012] [info] [client 192.168.180.174] (70014)End of file found: SSL input filter read failed.
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1884): OpenSSL: Write: SSL negotiation finished successfully
[Thu Feb 09 15:59:14 2012] [info] [client 192.168.180.174] Connection closed to child 6 with standard shutdown (server localhost:443)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1893): OpenSSL: I/O error, 5 bytes expected to read on BIO#7fac22317410 [mem: 7fac2234ecd0]
[Thu Feb 09 15:59:14 2012] [info] [client 192.168.180.174] (70014)End of file found: SSL input filter read failed.
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1884): OpenSSL: Write: SSL negotiation finished successfully
[Thu Feb 09 15:59:14 2012] [info] [client 192.168.180.174] Connection closed to child 134 with standard shutdown (server localhost:443)
[Thu Feb 09 15:59:14 2012] [info] [client 192.168.180.174] Connection to child 72 established (server localhost:443)
[Thu Feb 09 15:59:14 2012] [info] Seeding PRNG with 1312 bytes of entropy
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1866): OpenSSL: Handshake: start
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1874): OpenSSL: Loop: before/accept initialization
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1882): OpenSSL: read 11/11 bytes from BIO#7fac223315c0 [mem: 7fac22346d80] (BIO dump follows)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1815): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0000: 16 03 00 00 75 01 00 00-71 03                    ....u...q.       |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1858): | 0011 - <SPACES/NULS>
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1860): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1882): OpenSSL: read 111/111 bytes from BIO#7fac223315c0 [mem: 7fac22346d8b] (BIO dump follows)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1815): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0000: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0010: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0020: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0030: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0040: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0050: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0060: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1858): | 0111 - <SPACES/NULS>
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1860): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_scache_shmcb.c(393): ssl_scache_shmcb_retrieve (0xba -> subcache 26)
[Thu Feb 09 15:59:14 2012] [debug] ssl_scache_shmcb.c(680): possible match at idx=0, data=0
[Thu Feb 09 15:59:14 2012] [debug] ssl_scache_shmcb.c(697): shmcb_subcache_retrieve returning matching session
[Thu Feb 09 15:59:14 2012] [debug] ssl_scache_shmcb.c(408): leaving ssl_scache_shmcb_retrieve successfully
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1732): Inter-Process Session Cache: request=GET status=FOUND id=BA3353B885504DC92528C09B9770104A3C3F4BD81846DF9A2850E929FD43054F (session reuse)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1874): OpenSSL: Loop: SSLv3 read client hello A
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1874): OpenSSL: Loop: SSLv3 write server hello A
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1874): OpenSSL: Loop: SSLv3 write change cipher spec A
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1874): OpenSSL: Loop: SSLv3 write finished A
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1874): OpenSSL: Loop: SSLv3 flush data
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1882): OpenSSL: read 5/5 bytes from BIO#7fac223315c0 [mem: 7fac22346d80] (BIO dump follows)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1815): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0000: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1860): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1882): OpenSSL: read 1/1 bytes from BIO#7fac223315c0 [mem: 7fac22346d85] (BIO dump follows)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1815): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0000: 01                                               .                |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1860): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1882): OpenSSL: read 5/5 bytes from BIO#7fac223315c0 [mem: 7fac22346d80] (BIO dump follows)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1815): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0000: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1860): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1882): OpenSSL: read 64/64 bytes from BIO#7fac223315c0 [mem: 7fac22346d85] (BIO dump follows)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1815): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0000: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0010: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0020: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0030: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1860): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1874): OpenSSL: Loop: SSLv3 read finished A
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1870): OpenSSL: Handshake: done
[Thu Feb 09 15:59:14 2012] [info] Connection: Client IP: 192.168.180.174, Protocol: SSLv3, Cipher: AES256-SHA (256/256 bits)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1882): OpenSSL: read 5/5 bytes from BIO#7fac223315c0 [mem: 7fac22346d80] (BIO dump follows)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1815): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0000: 17 03                                            ..               |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1858): | 0005 - <SPACES/NULS>
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1860): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1882): OpenSSL: read 32/32 bytes from BIO#7fac223315c0 [mem: 7fac22346d85] (BIO dump follows)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1815): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0000: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0010: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1860): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1882): OpenSSL: read 5/5 bytes from BIO#7fac223315c0 [mem: 7fac22346d80] (BIO dump follows)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1815): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0000: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1860): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1882): OpenSSL: read 432/432 bytes from BIO#7fac223315c0 [mem: 7fac22346d85] (BIO dump follows)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1815): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0000: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0010: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0020: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0030: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0040: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0050: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0060: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0070: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0080: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0090: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 00a0: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 00b0: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 00c0: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 00d0: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 00e0: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 00f0: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0100: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0110: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0120: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0130: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0140: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0150: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0160: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0170: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0180: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0190: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 01a0: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1860): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1884): OpenSSL: Write: SSL negotiation finished successfully
[Thu Feb 09 15:59:14 2012] [info] [client 192.168.180.174] Connection closed to child 72 with standard shutdown (server localhost:443)
[Thu Feb 09 15:59:14 2012] [info] [client 192.168.180.174] Connection to child 135 established (server localhost:443)
[Thu Feb 09 15:59:14 2012] [info] Seeding PRNG with 1312 bytes of entropy
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1866): OpenSSL: Handshake: start
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1874): OpenSSL: Loop: before/accept initialization
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1882): OpenSSL: read 11/11 bytes from BIO#7fac22331a80 [mem: 7fac2234ecd0] (BIO dump follows)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1815): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0000: 16 03 00 00 75 01 00 00-71 03                    ....u...q.       |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1858): | 0011 - <SPACES/NULS>
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1860): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1882): OpenSSL: read 111/111 bytes from BIO#7fac22331a80 [mem: 7fac2234ecdb] (BIO dump follows)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1815): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0000: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0010: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0020: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0030: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0040: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0050: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0060: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1858): | 0111 - <SPACES/NULS>
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1860): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_scache_shmcb.c(393): ssl_scache_shmcb_retrieve (0xba -> subcache 26)
[Thu Feb 09 15:59:14 2012] [debug] ssl_scache_shmcb.c(680): possible match at idx=0, data=0
[Thu Feb 09 15:59:14 2012] [debug] ssl_scache_shmcb.c(697): shmcb_subcache_retrieve returning matching session
[Thu Feb 09 15:59:14 2012] [debug] ssl_scache_shmcb.c(408): leaving ssl_scache_shmcb_retrieve successfully
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1732): Inter-Process Session Cache: request=GET status=FOUND id=BA3353B885504DC92528C09B9770104A3C3F4BD81846DF9A2850E929FD43054F (session reuse)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1874): OpenSSL: Loop: SSLv3 read client hello A
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1874): OpenSSL: Loop: SSLv3 write server hello A
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1874): OpenSSL: Loop: SSLv3 write change cipher spec A
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1874): OpenSSL: Loop: SSLv3 write finished A
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1874): OpenSSL: Loop: SSLv3 flush data
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1882): OpenSSL: read 5/5 bytes from BIO#7fac22331a80 [mem: 7fac2234ecd0] (BIO dump follows)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1815): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0000: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1860): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1882): OpenSSL: read 1/1 bytes from BIO#7fac22331a80 [mem: 7fac2234ecd5] (BIO dump follows)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1815): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0000: 01                                               .                |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1860): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1882): OpenSSL: read 5/5 bytes from BIO#7fac22331a80 [mem: 7fac2234ecd0] (BIO dump follows)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1815): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0000: 16 03 00 00 40                                   ....@            |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1860): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1882): OpenSSL: read 64/64 bytes from BIO#7fac22331a80 [mem: 7fac2234ecd5] (BIO dump follows)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1815): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0000: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0010: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0020: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0030: 8SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1860): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1874): OpenSSL: Loop: SSLv3 read finished A
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1870): OpenSSL: Handshake: done
[Thu Feb 09 15:59:14 2012] [info] Connection: Client IP: 192.168.180.174, Protocol: SSLv3, Cipher: AES256-SHA (256/256 bits)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1893): OpenSSL: I/O error, 5 bytes expected to read on BIO#7fac22331a80 [mem: 7fac2234ecd0]
[Thu Feb 09 15:59:14 2012] [info] [client 192.168.180.174] (70014)End of file found: SSL input filter read failed.
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1884): OpenSSL: Write: SSL negotiation finished successfully
[Thu Feb 09 15:59:14 2012] [info] [client 192.168.180.174] Connection closed to child 135 with standard shutdown (server localhost:443)
[Thu Feb 09 15:59:14 2012] [info] [client 192.168.180.174] Connection to child 7 established (server localhost:443)
[Thu Feb 09 15:59:14 2012] [info] Seeding PRNG with 1312 bytes of entropy
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1866): OpenSSL: Handshake: start
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1874): OpenSSL: Loop: before/accept initialization
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1882): OpenSSL: read 11/11 bytes from BIO#7fac223470f0 [mem: 7fac2233d1a0] (BIO dump follows)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1815): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0000: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1858): | 0011 - <SPACES/NULS>
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1860): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1882): OpenSSL: read 111/111 bytes from BIO#7fac223470f0 [mem: 7fac2233d1ab] (BIO dump follows)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1815): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0000: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0010: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0020: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0030: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0040: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0050: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0060: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1858): | 0111 - <SPACES/NULS>
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1860): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_scache_shmcb.c(393): ssl_scache_shmcb_retrieve (0xba -> subcache 26)
[Thu Feb 09 15:59:14 2012] [debug] ssl_scache_shmcb.c(680): possible match at idx=0, data=0
[Thu Feb 09 15:59:14 2012] [debug] ssl_scache_shmcb.c(697): shmcb_subcache_retrieve returning matching session
[Thu Feb 09 15:59:14 2012] [debug] ssl_scache_shmcb.c(408): leaving ssl_scache_shmcb_retrieve successfully
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1732): Inter-Process Session Cache: request=GET status=FOUND id=BA3353B885504DC92528C09B9770104A3C3F4BD81846DF9A2850E929FD43054F (session reuse)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1874): OpenSSL: Loop: SSLv3 read client hello A
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1874): OpenSSL: Loop: SSLv3 write server hello A
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1874): OpenSSL: Loop: SSLv3 write change cipher spec A
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1874): OpenSSL: Loop: SSLv3 write finished A
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1874): OpenSSL: Loop: SSLv3 flush data
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1882): OpenSSL: read 5/5 bytes from BIO#7fac223470f0 [mem: 7fac2233d1a0] (BIO dump follows)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1815): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0000: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1860): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1882): OpenSSL: read 1/1 bytes from BIO#7fac223470f0 [mem: 7fac2233d1a5] (BIO dump follows)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1815): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0000: 01                                               .                |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1860): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1882): OpenSSL: read 5/5 bytes from BIO#7fac223470f0 [mem: 7fac2233d1a0] (BIO dump follows)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1815): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0000: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1860): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1882): OpenSSL: read 64/64 bytes from BIO#7fac223470f0 [mem: 7fac2233d1a5] (BIO dump follows)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1815): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0000: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0010: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0020: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0030: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1860): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1874): OpenSSL: Loop: SSLv3 read finished A
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1870): OpenSSL: Handshake: done
[Thu Feb 09 15:59:14 2012] [info] Connection: Client IP: 192.168.180.174, Protocol: SSLv3, Cipher: AES256-SHA (256/256 bits)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1882): OpenSSL: read 5/5 bytes from BIO#7fac223470f0 [mem: 7fac2233d1a0] (BIO dump follows)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1815): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0000: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1858): | 0005 - <SPACES/NULS>
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1860): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1882): OpenSSL: read 32/32 bytes from BIO#7fac223470f0 [mem: 7fac2233d1a5] (BIO dump follows)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1815): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0000: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0010: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1860): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1882): OpenSSL: read 5/5 bytes from BIO#7fac223470f0 [mem: 7fac2233d1a0] (BIO dump follows)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1815): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0000: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1860): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1882): OpenSSL: read 368/368 bytes from BIO#7fac223470f0 [mem: 7fac2233d1a5] (BIO dump follows)
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1815): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0000: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0010: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0020: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0030: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0040: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0050: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0060: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0070: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0080: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0090: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 00a0: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 00b0: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 00c0: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 00d0: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 00e0: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 00f0: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0100: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0110: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0120: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0130: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0140: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0150: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1854): | 0160: SNIP ******************************************************* SNAP |
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_io.c(1860): +-------------------------------------------------------------------------+
[Thu Feb 09 15:59:14 2012] [debug] ssl_engine_kernel.c(1884): OpenSSL: Write: SSL negotiation finished successfully
[Thu Feb 09 15:59:14 2012] [info] [client 192.168.180.174] Connection closed to child 7 with standard shutdown (server localhost:443)


This happens at least since Firefox 3.6.24 and also in the current 10.0

Any ideas.


Actual results:

SSL negotiation failed.


Expected results:

SSL negotiation should succeed.
Marking this as "major", as it breaks accessing sites.
Severity: normal → major
OS: Linux → All
Hardware: x86_64 → All
I've also reported this to Apache:
https://issues.apache.org/bugzilla/show_bug.cgi?id=52630

Maybe they can help and there is some hint that similar (not equal) SSL/SNI/client_auth setups work with Apache+Firefox.
After more testing it turned out that this only happens when I configured a path with client CA certificates in Apache, not when configured a _single_ CA certificate in a file.

So this might be also a problem in Apache,.. nevertheless... it still does not happen at all with Chromium... so FF is probably also doing something wrong.
My tests now indicate that this is unrelated to SNI and just related with the matter that I have configured a directory of trusted CA certificates.
Therefore changing the bug title.
Summary: SNI broken when client auth required → SSL client auth broken on Apache, when a directory of CA certificates is specified
It seems more and more that this is actually a bug in either Apache or OpenSSL.
So see the Apache bug report for more details.

Nevertheless, it's really strange that it works with Chromium but not with Firefox, so I let this open so that some Firefox developer can have a look and maybe there is still something fishy in FF.
Severity: major → normal
I've posted some more information at the mentioned Apache bug.

It still only occurs with Firefox, so there is still a chance that also something is wrong on Firefox' side.
Component: Untriaged → Security: PSM
Product: Firefox → Core
I have a similar problem, though it's not related to the browser. I suspect this has something to do with Apache/OpenSSL. Here is my setup for WebID authentication (client certificates): 

I am able to replicated the above issue when I configure a VirtualHost with the following directives inside a <Directory>.
<Directory /var/www/auth/>
SSLVerifyClient optional_no_ca
SSLVerifyDepth 9
SSLOptions +StdEnvVars +ExportCertData +OptRenegotiate
</Directory>

However, if I move the above 3 lines outside the <Directory>, it works.
The linked bug was resolved as INVALID (apparently it was a configuration issue).
Status: UNCONFIRMED → RESOLVED
Closed: 8 years ago
Resolution: --- → INVALID
You need to log in before you can comment on or make changes to this bug.