ssl re-negotiation error

GoogleCodeExporter commented 9 years ago

What steps will reproduce the problem?

1. using svn from subversion 1.8.4 release
2. Access repository by path like https://svn.company.com/ssl/repo
with corresponding apache configuration

<Location />
    SSLRequireSSL
</Location>

<Location /ssl/>
    SSLUserName SSL_CLIENT_S_DN_CN
    SSLVerifyClient require
    SSLVerifyDepth 1
    ...
</Location>

svn co or update command ends with 
"Error retrieving REPORT: An error occurred during SSL communication", 
while apache produce the follwoing output

[info] Initial (No.1) HTTPS request received for child 4 (server 
svn.company.com:443)
[info] [client 10.121.5.10] Requesting connection re-negotiation
[error] [client 10.121.5.10] insecure SSL re-negotiation required, but a 
pipelined request is present; keepalive disabled
[info] [client 10.121.5.10] Awaiting re-negotiation handshake
[error] [client 10.121.5.10] Re-negotiation handshake failed: Not accepted by 
client!?
[info] [client 10.121.5.10] (70014)End of file found: SSL input filter read 
failed.
[info] [client 10.121.5.10] Connection closed to child 3 with standard shutdown 
(server svn.company.com:443)

Original issue reported on code.google.com by m...@okun.me on 14 Nov 2013 at 2:12

GoogleCodeExporter commented 9 years ago

Where did you obtain/create your Subversion binary?

It would be very interesting to know which serf and which openssl versions are 
used and as neither of these is packaged by Subversion, the fact that you use 
Subversion 1.8.4 doesn't tell us which versions you really used.

Original comment by b...@qqmail.nl on 14 Nov 2013 at 2:49

GoogleCodeExporter commented 9 years ago

I have tried 

TortoiseSVN 1.8.3, Build 24901 - 64 Bit , 2013/10/27 15:38:41
Subversion 1.8.4, -release
apr 1.4.8
apr-util 1.5.2
serf 1.3.2
OpenSSL 1.0.1e 11 Feb 2013
zlib 1.2.8

and 

VisaulSVN command line 1.8.4
with serf 1.3.2

Original comment by m...@okun.me on 14 Nov 2013 at 4:13

GoogleCodeExporter commented 9 years ago

Looks somewhat like issue #114, but that has been fixed in serf 1.3.1.

I'd be much interested in seeing the output of serf with SSL_VERBOSE logging, 
but that requires building svn+serf from source.

Original comment by lieven.govaerts@gmail.com on 14 Nov 2013 at 4:44

GoogleCodeExporter commented 9 years ago

Here it is

/usr/local/bin/svn  co https://svn.company.com/ssl/repo/Math/trunk Math
[2013-11-15T20:10:27.668846+04] buckets/ssl_buckets.c: ssl_encrypt: begin 8000
[2013-11-15T20:10:27.668996+04] buckets/ssl_buckets.c: ssl_encrypt: bucket read 
532 bytes; status 0
[2013-11-15T20:10:27.669086+04] buckets/ssl_buckets.c: 
SSL_connect:before/connect initialization
[2013-11-15T20:10:27.669121+04] buckets/ssl_buckets.c: bio_bucket_write called 
for 144 bytes
[2013-11-15T20:10:27.669135+04] buckets/ssl_buckets.c: SSL_connect:SSLv2/v3 
write client hello A
[2013-11-15T20:10:27.669146+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 7 bytes
[2013-11-15T20:10:27.669154+04] buckets/ssl_buckets.c: bio_bucket_read received 
0 bytes (70014)
[2013-11-15T20:10:27.669168+04] buckets/ssl_buckets.c: SSL_connect:error in 
SSLv2/v3 read server hello A
[2013-11-15T20:10:27.669178+04] buckets/ssl_buckets.c: ssl_encrypt: SSL write: 
-1
[2013-11-15T20:10:27.669194+04] buckets/ssl_buckets.c: ssl_encrypt: SSL write 
error: 2
[2013-11-15T20:10:27.669202+04] buckets/ssl_buckets.c: ssl_encrypt: SSL write 
error: 120103 0
[2013-11-15T20:10:27.669210+04] buckets/ssl_buckets.c: ssl_encrypt read agg: 
120103 70014 0 144
[2013-11-15T20:10:27.669219+04] buckets/ssl_buckets.c: ssl_encrypt finished: 
120103 144 (8 1 9)
[2013-11-15T20:10:27.692776+04] buckets/ssl_buckets.c: ssl_decrypt: begin 8000
[2013-11-15T20:10:27.692854+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 7 bytes
[2013-11-15T20:10:27.692864+04] buckets/ssl_buckets.c: bio_bucket_read waiting: 
(8 1 9)
[2013-11-15T20:10:27.692878+04] buckets/ssl_buckets.c: bio_bucket_read received 
0 bytes (70014)
[2013-11-15T20:10:27.692887+04] buckets/ssl_buckets.c: SSL_connect:error in 
SSLv2/v3 read server hello A
[2013-11-15T20:10:27.692918+04] buckets/ssl_buckets.c: ssl_decrypt: read 4629 
bytes (8000); status: 0
[2013-11-15T20:10:27.692940+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 7 bytes
[2013-11-15T20:10:27.692948+04] buckets/ssl_buckets.c: bio_bucket_read waiting: 
(8 1 9)
[2013-11-15T20:10:27.692956+04] buckets/ssl_buckets.c: bio_bucket_read received 
7 bytes (0)
[2013-11-15T20:10:27.693021+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 83 bytes
[2013-11-15T20:10:27.693032+04] buckets/ssl_buckets.c: bio_bucket_read received 
83 bytes (0)
[2013-11-15T20:10:27.693091+04] buckets/ssl_buckets.c: SSL_connect:SSLv3 read 
server hello A
[2013-11-15T20:10:27.693102+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 5 bytes
[2013-11-15T20:10:27.693111+04] buckets/ssl_buckets.c: bio_bucket_read received 
5 bytes (0)
[2013-11-15T20:10:27.693119+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 3739 bytes
[2013-11-15T20:10:27.693126+04] buckets/ssl_buckets.c: bio_bucket_read received 
3739 bytes (0)
[2013-11-15T20:10:27.695078+04] buckets/ssl_buckets.c: SSL_connect:SSLv3 read 
server certificate A
[2013-11-15T20:10:27.695112+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 5 bytes
[2013-11-15T20:10:27.695123+04] buckets/ssl_buckets.c: bio_bucket_read received 
5 bytes (0)
[2013-11-15T20:10:27.695131+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 781 bytes
[2013-11-15T20:10:27.695139+04] buckets/ssl_buckets.c: bio_bucket_read received 
781 bytes (0)
[2013-11-15T20:10:27.695705+04] buckets/ssl_buckets.c: SSL_connect:SSLv3 read 
server key exchange A
[2013-11-15T20:10:27.695726+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 5 bytes
[2013-11-15T20:10:27.695735+04] buckets/ssl_buckets.c: bio_bucket_read received 
5 bytes (0)
[2013-11-15T20:10:27.695743+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 4 bytes
[2013-11-15T20:10:27.695751+04] buckets/ssl_buckets.c: bio_bucket_read received 
4 bytes (70014)
[2013-11-15T20:10:27.695762+04] buckets/ssl_buckets.c: SSL_connect:SSLv3 read 
server done A
[2013-11-15T20:10:27.699215+04] buckets/ssl_buckets.c: SSL_connect:SSLv3 write 
client key exchange A
[2013-11-15T20:10:27.699416+04] buckets/ssl_buckets.c: SSL_connect:SSLv3 write 
change cipher spec A
[2013-11-15T20:10:27.699458+04] buckets/ssl_buckets.c: SSL_connect:SSLv3 write 
finished A
[2013-11-15T20:10:27.699468+04] buckets/ssl_buckets.c: bio_bucket_write called 
for 214 bytes
[2013-11-15T20:10:27.699476+04] buckets/ssl_buckets.c: bio_bucket_write 
waiting: (0 0 0)
[2013-11-15T20:10:27.699491+04] buckets/ssl_buckets.c: SSL_connect:SSLv3 flush 
data
[2013-11-15T20:10:27.699500+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 5 bytes
[2013-11-15T20:10:27.699512+04] buckets/ssl_buckets.c: bio_bucket_read received 
0 bytes (70014)
[2013-11-15T20:10:27.699520+04] buckets/ssl_buckets.c: SSL_connect:error in 
SSLv3 read finished A
[2013-11-15T20:10:27.699529+04] buckets/ssl_buckets.c: SSL_connect:error in 
SSLv3 read finished A
[2013-11-15T20:10:27.699539+04] buckets/ssl_buckets.c: ssl_decrypt: 11 0 9
[2013-11-15T20:10:27.699560+04] buckets/ssl_buckets.c: ssl_decrypt: begin 8000
[2013-11-15T20:10:27.699573+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 5 bytes
[2013-11-15T20:10:27.699581+04] buckets/ssl_buckets.c: bio_bucket_read waiting: 
(8 1 9)
[2013-11-15T20:10:27.699589+04] buckets/ssl_buckets.c: bio_bucket_read received 
0 bytes (70014)
[2013-11-15T20:10:27.699597+04] buckets/ssl_buckets.c: SSL_connect:error in 
SSLv3 read finished A
[2013-11-15T20:10:27.699612+04] buckets/ssl_buckets.c: ssl_decrypt: 11 0 9
[2013-11-15T20:10:27.699640+04] buckets/ssl_buckets.c: ssl_encrypt: begin 8000
[2013-11-15T20:10:27.699649+04] buckets/ssl_buckets.c: ssl_encrypt: 0 214 9 
(quick read)
[2013-11-15T20:10:27.699975+04] buckets/ssl_buckets.c: ssl_encrypt: begin 8000
[2013-11-15T20:10:27.699996+04] buckets/ssl_buckets.c: ssl_encrypt: reset 70014 
120103 (8 1 9)
[2013-11-15T20:10:27.700010+04] buckets/ssl_buckets.c: ssl_encrypt: bucket read 
532 bytes; status 11
[2013-11-15T20:10:27.700028+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 5 bytes
[2013-11-15T20:10:27.700036+04] buckets/ssl_buckets.c: bio_bucket_read received 
0 bytes (70014)
[2013-11-15T20:10:27.700044+04] buckets/ssl_buckets.c: SSL_connect:error in 
SSLv3 read finished A
[2013-11-15T20:10:27.700052+04] buckets/ssl_buckets.c: ssl_encrypt: SSL write: 
-1
[2013-11-15T20:10:27.700060+04] buckets/ssl_buckets.c: ssl_encrypt: SSL write 
error: 2
[2013-11-15T20:10:27.700068+04] buckets/ssl_buckets.c: ssl_encrypt: SSL write 
error: 120103 0
[2013-11-15T20:10:27.700075+04] buckets/ssl_buckets.c: ssl_encrypt read agg: 
120103 70014 11 0
[2013-11-15T20:10:27.700083+04] buckets/ssl_buckets.c: ssl_encrypt finished: 
120103 0 (8 1 9)
[2013-11-15T20:10:27.702141+04] buckets/ssl_buckets.c: ssl_decrypt: begin 8000
[2013-11-15T20:10:27.702178+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 5 bytes
[2013-11-15T20:10:27.702188+04] buckets/ssl_buckets.c: bio_bucket_read waiting: 
(8 1 9)
[2013-11-15T20:10:27.702196+04] buckets/ssl_buckets.c: bio_bucket_read received 
0 bytes (70014)
[2013-11-15T20:10:27.702205+04] buckets/ssl_buckets.c: SSL_connect:error in 
SSLv3 read finished A
[2013-11-15T20:10:27.702254+04] buckets/ssl_buckets.c: ssl_decrypt: read 75 
bytes (8000); status: 0
[2013-11-15T20:10:27.702274+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 5 bytes
[2013-11-15T20:10:27.702282+04] buckets/ssl_buckets.c: bio_bucket_read waiting: 
(8 1 9)
[2013-11-15T20:10:27.702290+04] buckets/ssl_buckets.c: bio_bucket_read received 
5 bytes (0)
[2013-11-15T20:10:27.702298+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 1 bytes
[2013-11-15T20:10:27.702305+04] buckets/ssl_buckets.c: bio_bucket_read received 
1 bytes (0)
[2013-11-15T20:10:27.702326+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 5 bytes
[2013-11-15T20:10:27.702334+04] buckets/ssl_buckets.c: bio_bucket_read received 
5 bytes (0)
[2013-11-15T20:10:27.702341+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 64 bytes
[2013-11-15T20:10:27.702349+04] buckets/ssl_buckets.c: bio_bucket_read received 
64 bytes (70014)
[2013-11-15T20:10:27.702372+04] buckets/ssl_buckets.c: SSL_connect:SSLv3 read 
finished A
[2013-11-15T20:10:27.702406+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 5 bytes
[2013-11-15T20:10:27.702415+04] buckets/ssl_buckets.c: bio_bucket_read received 
0 bytes (70014)
[2013-11-15T20:10:27.702424+04] buckets/ssl_buckets.c: ssl_decrypt: 11 0 9
[2013-11-15T20:10:27.702434+04] buckets/ssl_buckets.c: ssl_decrypt: begin 8000
[2013-11-15T20:10:27.702441+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 5 bytes
[2013-11-15T20:10:27.702449+04] buckets/ssl_buckets.c: bio_bucket_read waiting: 
(8 1 9)
[2013-11-15T20:10:27.702456+04] buckets/ssl_buckets.c: bio_bucket_read received 
0 bytes (70014)
[2013-11-15T20:10:27.702467+04] buckets/ssl_buckets.c: ssl_decrypt: 11 0 9
[2013-11-15T20:10:27.702486+04] buckets/ssl_buckets.c: ssl_encrypt: begin 8000
[2013-11-15T20:10:27.702494+04] buckets/ssl_buckets.c: ssl_encrypt: reset 70014 
120103 (8 1 9)
[2013-11-15T20:10:27.702504+04] buckets/ssl_buckets.c: ssl_encrypt: bucket read 
532 bytes; status 11
[2013-11-15T20:10:27.702532+04] buckets/ssl_buckets.c: bio_bucket_write called 
for 565 bytes
[2013-11-15T20:10:27.702540+04] buckets/ssl_buckets.c: ssl_encrypt: SSL write: 
532
[2013-11-15T20:10:27.702551+04] buckets/ssl_buckets.c: ssl_encrypt read agg: 11 
70014 11 565
[2013-11-15T20:10:27.702560+04] buckets/ssl_buckets.c: ssl_encrypt finished: 11 
565 (8 1 9)
[2013-11-15T20:10:27.702971+04] buckets/ssl_buckets.c: ssl_encrypt: begin 8000
[2013-11-15T20:10:27.702993+04] buckets/ssl_buckets.c: ssl_encrypt: reset 70014 
11 (8 1 9)
[2013-11-15T20:10:27.703002+04] buckets/ssl_buckets.c: ssl_encrypt read agg: 11 
70014 0 0
[2013-11-15T20:10:27.703010+04] buckets/ssl_buckets.c: ssl_encrypt finished: 11 
0 (8 1 9)
[2013-11-15T20:10:27.703022+04] buckets/ssl_buckets.c: ssl_encrypt: begin 8000
[2013-11-15T20:10:27.703030+04] buckets/ssl_buckets.c: ssl_encrypt: reset 70014 
0 (8 1 9)
[2013-11-15T20:10:27.703039+04] buckets/ssl_buckets.c: ssl_encrypt read agg: 11 
70014 0 0
[2013-11-15T20:10:27.703047+04] buckets/ssl_buckets.c: ssl_encrypt finished: 11 
0 (8 1 9)
[2013-11-15T20:10:27.703298+04] buckets/ssl_buckets.c: ssl_decrypt: begin 8000
[2013-11-15T20:10:27.703319+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 5 bytes
[2013-11-15T20:10:27.703327+04] buckets/ssl_buckets.c: bio_bucket_read received 
0 bytes (70014)
[2013-11-15T20:10:27.703341+04] buckets/ssl_buckets.c: ssl_decrypt: read 37 
bytes (8000); status: 0
[2013-11-15T20:10:27.703350+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 5 bytes
[2013-11-15T20:10:27.703357+04] buckets/ssl_buckets.c: bio_bucket_read received 
5 bytes (0)
[2013-11-15T20:10:27.703365+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 32 bytes
[2013-11-15T20:10:27.703372+04] buckets/ssl_buckets.c: bio_bucket_read received 
32 bytes (70014)
[2013-11-15T20:10:27.703414+04] buckets/ssl_buckets.c: SSL_connect:SSL 
renegotiate ciphers
[2013-11-15T20:10:27.703472+04] buckets/ssl_buckets.c: bio_bucket_write called 
for 213 bytes
[2013-11-15T20:10:27.703489+04] buckets/ssl_buckets.c: SSL_connect:SSLv3 write 
client hello A
[2013-11-15T20:10:27.703497+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 5 bytes
[2013-11-15T20:10:27.703505+04] buckets/ssl_buckets.c: bio_bucket_read received 
0 bytes (70014)
[2013-11-15T20:10:27.703513+04] buckets/ssl_buckets.c: SSL_connect:error in 
SSLv3 read server hello A
[2013-11-15T20:10:27.703522+04] buckets/ssl_buckets.c: ssl_decrypt: 11 0 9
[2013-11-15T20:10:27.703532+04] buckets/ssl_buckets.c: ssl_encrypt: begin 8000
[2013-11-15T20:10:27.703539+04] buckets/ssl_buckets.c: ssl_encrypt: 0 213 9 
(quick read)
[2013-11-15T20:10:27.703798+04] buckets/ssl_buckets.c: ssl_encrypt: begin 8000
[2013-11-15T20:10:27.703818+04] buckets/ssl_buckets.c: ssl_encrypt: reset 70014 
0 (8 1 9)
[2013-11-15T20:10:27.703826+04] buckets/ssl_buckets.c: ssl_encrypt read agg: 11 
70014 0 0
[2013-11-15T20:10:27.703834+04] buckets/ssl_buckets.c: ssl_encrypt finished: 11 
0 (8 1 9)
[2013-11-15T20:10:27.703845+04] buckets/ssl_buckets.c: ssl_encrypt: begin 8000
[2013-11-15T20:10:27.703853+04] buckets/ssl_buckets.c: ssl_encrypt: reset 70014 
0 (8 1 9)
[2013-11-15T20:10:27.703860+04] buckets/ssl_buckets.c: ssl_encrypt read agg: 11 
70014 0 0
[2013-11-15T20:10:27.703868+04] buckets/ssl_buckets.c: ssl_encrypt finished: 11 
0 (8 1 9)
[2013-11-15T20:10:27.727453+04] buckets/ssl_buckets.c: ssl_decrypt: begin 8000
[2013-11-15T20:10:27.727498+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 5 bytes
[2013-11-15T20:10:27.727571+04] buckets/ssl_buckets.c: bio_bucket_read received 
0 bytes (70014)
[2013-11-15T20:10:27.727584+04] buckets/ssl_buckets.c: SSL_connect:error in 
SSLv3 read server hello A
[2013-11-15T20:10:27.727604+04] buckets/ssl_buckets.c: ssl_decrypt: read 5012 
bytes (8000); status: 0
[2013-11-15T20:10:27.727631+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 5 bytes
[2013-11-15T20:10:27.727639+04] buckets/ssl_buckets.c: bio_bucket_read received 
5 bytes (0)
[2013-11-15T20:10:27.727647+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 192 bytes
[2013-11-15T20:10:27.727655+04] buckets/ssl_buckets.c: bio_bucket_read received 
192 bytes (0)
[2013-11-15T20:10:27.727804+04] buckets/ssl_buckets.c: SSL_connect:SSLv3 read 
server hello A
[2013-11-15T20:10:27.727816+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 5 bytes
[2013-11-15T20:10:27.727823+04] buckets/ssl_buckets.c: bio_bucket_read received 
5 bytes (0)
[2013-11-15T20:10:27.727831+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 3760 bytes
[2013-11-15T20:10:27.727839+04] buckets/ssl_buckets.c: bio_bucket_read received 
3760 bytes (0)
[2013-11-15T20:10:27.729142+04] buckets/ssl_buckets.c: SSL_connect:SSLv3 read 
server certificate A
[2013-11-15T20:10:27.729165+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 5 bytes
[2013-11-15T20:10:27.729174+04] buckets/ssl_buckets.c: bio_bucket_read received 
5 bytes (0)
[2013-11-15T20:10:27.729182+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 816 bytes
[2013-11-15T20:10:27.729190+04] buckets/ssl_buckets.c: bio_bucket_read received 
816 bytes (0)
[2013-11-15T20:10:27.729814+04] buckets/ssl_buckets.c: SSL_connect:SSLv3 read 
server key exchange A
[2013-11-15T20:10:27.729839+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 5 bytes
[2013-11-15T20:10:27.729849+04] buckets/ssl_buckets.c: bio_bucket_read received 
5 bytes (0)
[2013-11-15T20:10:27.729857+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 224 bytes
[2013-11-15T20:10:27.729865+04] buckets/ssl_buckets.c: bio_bucket_read received 
224 bytes (70014)
[2013-11-15T20:10:27.729941+04] buckets/ssl_buckets.c: SSL_connect:SSLv3 read 
server certificate request A
[2013-11-15T20:10:27.729952+04] buckets/ssl_buckets.c: SSL_connect:SSLv3 read 
server done A
[2013-11-15T20:10:27.729987+04] buckets/ssl_buckets.c: SSL3 alert 
write:warning:no certificate
[2013-11-15T20:10:27.730004+04] buckets/ssl_buckets.c: SSL_connect:SSLv3 write 
client certificate A
[2013-11-15T20:10:27.733474+04] buckets/ssl_buckets.c: SSL_connect:SSLv3 write 
client key exchange A
[2013-11-15T20:10:27.733556+04] buckets/ssl_buckets.c: SSL_connect:SSLv3 write 
change cipher spec A
[2013-11-15T20:10:27.733580+04] buckets/ssl_buckets.c: SSL_connect:SSLv3 write 
finished A
[2013-11-15T20:10:27.733590+04] buckets/ssl_buckets.c: bio_bucket_write called 
for 308 bytes
[2013-11-15T20:10:27.733599+04] buckets/ssl_buckets.c: SSL_connect:SSLv3 flush 
data
[2013-11-15T20:10:27.733610+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 5 bytes
[2013-11-15T20:10:27.733619+04] buckets/ssl_buckets.c: bio_bucket_read received 
0 bytes (70014)
[2013-11-15T20:10:27.733629+04] buckets/ssl_buckets.c: SSL_connect:error in 
SSLv3 read finished A
[2013-11-15T20:10:27.733641+04] buckets/ssl_buckets.c: ssl_decrypt: 11 0 9
[2013-11-15T20:10:27.733654+04] buckets/ssl_buckets.c: ssl_encrypt: begin 8000
[2013-11-15T20:10:27.733664+04] buckets/ssl_buckets.c: ssl_encrypt: 0 308 9 
(quick read)
[2013-11-15T20:10:27.733826+04] buckets/ssl_buckets.c: ssl_encrypt: begin 8000
[2013-11-15T20:10:27.733849+04] buckets/ssl_buckets.c: ssl_encrypt: reset 70014 
0 (8 1 9)
[2013-11-15T20:10:27.733858+04] buckets/ssl_buckets.c: ssl_encrypt read agg: 11 
70014 0 0
[2013-11-15T20:10:27.733866+04] buckets/ssl_buckets.c: ssl_encrypt finished: 11 
0 (8 1 9)
[2013-11-15T20:10:27.733880+04] buckets/ssl_buckets.c: ssl_encrypt: begin 8000
[2013-11-15T20:10:27.733887+04] buckets/ssl_buckets.c: ssl_encrypt: reset 70014 
0 (8 1 9)
[2013-11-15T20:10:27.733895+04] buckets/ssl_buckets.c: ssl_encrypt read agg: 11 
70014 0 0
[2013-11-15T20:10:27.733903+04] buckets/ssl_buckets.c: ssl_encrypt finished: 11 
0 (8 1 9)
[2013-11-15T20:10:27.734367+04] buckets/ssl_buckets.c: ssl_decrypt: begin 8000
[2013-11-15T20:10:27.734401+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 5 bytes
[2013-11-15T20:10:27.734411+04] buckets/ssl_buckets.c: bio_bucket_read received 
0 bytes (70014)
[2013-11-15T20:10:27.734443+04] buckets/ssl_buckets.c: SSL_connect:error in 
SSLv3 read finished A
[2013-11-15T20:10:27.734460+04] buckets/ssl_buckets.c: ssl_decrypt: read 37 
bytes (8000); status: 0
[2013-11-15T20:10:27.734474+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 5 bytes
[2013-11-15T20:10:27.734482+04] buckets/ssl_buckets.c: bio_bucket_read received 
5 bytes (0)
[2013-11-15T20:10:27.734490+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 32 bytes
[2013-11-15T20:10:27.734497+04] buckets/ssl_buckets.c: bio_bucket_read received 
32 bytes (70014)
[2013-11-15T20:10:27.734531+04] buckets/ssl_buckets.c: SSL3 alert 
read:fatal:handshake failure
[2013-11-15T20:10:27.734568+04] buckets/ssl_buckets.c: SSL_connect:failed in 
SSLv3 read finished A
[2013-11-15T20:10:27.734578+04] buckets/ssl_buckets.c: ssl_decrypt: 120171 0 9
svn: E120171: Unable to connect to a repository at URL 
'https://svn.company.com/ssl/repo/Math/trunk'
svn: E120171: Error running context: An error occurred during SSL communication

From Apache side:

[info] [client 10.121.5.10] Connection to child 4 established (server 
svn.intranet.kintech.ru:443)
[info] Seeding PRNG with 144 bytes of entropy
[info] Initial (No.1) HTTPS request received for child 4 (server 
svn.intranet.kintech.ru:443)
[info] [client 10.121.5.10] Requesting connection re-negotiation
[info] [client 10.121.5.10] Awaiting re-negotiation handshake
[error] [client 10.121.5.10] Re-negotiation handshake failed: Not accepted by 
client!?

Now it is subversion 1.8.4 with serf 1.3.2 and OpenSSL 1.0.0-fips under 
ScientificLinux 6.4

Original comment by m...@okun.me on 15 Nov 2013 at 4:18

GoogleCodeExporter commented 9 years ago

So you didn't cut any lines between:

$ /usr/local/bin/svn  co https://svn.company.com/ssl/repo/Math/trunk Math
[2013-11-15T20:10:27.668846+04] buckets/ssl_buckets.c: ssl_encrypt: begin 8000

IOW, this error happens right away, not after receiving any files from the 
server?

Original comment by lieven.govaerts@gmail.com on 15 Nov 2013 at 4:53

Changed state: Accepted

GoogleCodeExporter commented 9 years ago

It seems situation is slightly different for linux and windows may be because 
of different openssl version.

In the case of tortoisesvn checkout it creates directory structure, then gives 
up with error. 

In the case of linux svn client this error happens right away.

Original comment by m...@okun.me on 15 Nov 2013 at 5:18

GoogleCodeExporter commented 9 years ago

Mike, I'm wondering if serf sends your client certificate during the second 
pass, after the renegotiation request.

It's this line that shouldn't be there: 
[2013-11-15T20:10:27.729987+04] buckets/ssl_buckets.c: SSL3 alert 
write:warning:no certificate

According to the OpenSSL docs, this warning means:
"NC"/"no certificate" A client, that was asked to send a certificate, does not 
send a certificate (SSLv3 only).

Can you look in a (wireshark...) trace? Alternatively, you can send me the 
wireshark trace privately.

Lieven

Original comment by lieven.govaerts@gmail.com on 22 Nov 2013 at 12:54

GoogleCodeExporter commented 9 years ago

I thing no, just because svn does not even request it. I have used "clean" 
virtual machine for this test.

Original comment by m...@okun.me on 22 Nov 2013 at 3:11

GoogleCodeExporter commented 9 years ago

I was able to reproduce the 120171 error with your apache config and svn+serf 
trunk, but with a different client side trace. Haven't found the cause yet 
though, I'll continue searching this weekend.

Original comment by lieven.govaerts@gmail.com on 29 Nov 2013 at 11:03

GoogleCodeExporter commented 9 years ago

So, after a weekend debugging serf and mod_ssl, I think I can safely say the 
root cause of this issue is a bug in OpenSSL.

The problem is easy to reproduce with serf_get (an improved version that 
supports client certificates, I'll commit this later). The trigger is to make 
the client send 2 (or more) pipelined HTTP requests, like this:
$ test/serf_get -n 2 -m GET -c test/server/serfclientcert.p12 
https://localhost/svn/test
The same thing happens with 'svn checkout', where starting with the 3rd 
connection serf has enough pending requests to start sending them pipelined 
(i.e. without waiting for a response).

There are two possible good scenario's:
- mod_ssl reads the first message, initiates a renegotiation to ask for the 
client cert, handles the handshake and then continues with the next message(s). 
- mod_ssl reads both pipelined messages, goes to 'insecure SSL renegotiation' 
mode, initiates a renegotiation to ask for the client cert, handles the 
handshake, responds to the first request and then closes the connection thereby 
discarding all other incoming messages.

What I'm seeing, is that after OpenSSL sends "Hello Request" to the client 
triggering renegotiation, it goes in a state where the only valid data coming 
in is a "Client Hello" message. If you're interested, the code is in 
ssl/s3_pkt.c:1390 (the 'case SSL3_RT_APPLICATION_DATA' block).
The problem is that the client may have send one or more pipelined requests 
that haven't reached the server yet, or at least weren't read by OpenSSL yet 
before it sent the "Hello Request" message. OpenSSL will treat these requests 
as invalid data, and close down with a fatal error.

Due to the behaviour being very dependent on timing of the requests arriving at 
the server the error message is not always identical (I see different fatal 
errors depending on the amount of logging I've enabled in httpd). I've seen the 
error you're seeing, I've also seen an "unexpected message" alert logged by 
serf.

This bug was reported a long time ago in the OpenSSL issue tracker, but it's 
still without solution. See:
http://openssl.6102.n7.nabble.com/Unexpected-message-during-renegotiate-attempt-
tt44422.html#none
http://rt.openssl.org/Ticket/Display.html?id=2146&user=guest&pass=guest
http://rt.openssl.org/Ticket/Display.html?id=2481&user=guest&pass=guest

For this specific scenario there's a possible workaround, by making sure that 
serf sends the first request on each new connection it opens in synchronous 
mode. If renegotiation is needed, it will be handled before the response to the 
first request is returned by the server. We can handle this in serf or it can 
be implemented in Subversion - where similar workarounds are already in place 
(I'm thinking of the proxy probe code introduced in 1.8.1).

That's not going to work for httpd configurations where the SSL config changes 
somewhere deep in the svn tree, so that the renegotiation is triggered when 
there can be many requests underway on the connection. I don't think it's 
possible to workaround OpenSSL in that case.

Lieven

Original comment by lieven.govaerts@gmail.com on 2 Dec 2013 at 10:51

GoogleCodeExporter commented 9 years ago

[deleted comment]

GoogleCodeExporter commented 9 years ago

[deleted comment]

GoogleCodeExporter commented 9 years ago

I have tried to make Apache configuration which does not require renegatiation, 
i.e "SSLVerifyClient require" is specified not at <Location> context but at 
Virtual host. 
With this configuration connection also can not be established:

user@localhost code]$ /usr/local/bin/svn --force-interactive co 
https://svn.intranet.xxxx.xx/ssl/repo/Build
[2013-12-12T18:30:14.259897+04] buckets/ssl_buckets.c: ssl_encrypt: begin 8000
[2013-12-12T18:30:14.259958+04] buckets/ssl_buckets.c: ssl_encrypt: bucket read 
527 bytes; status 0
[2013-12-12T18:30:14.259989+04] buckets/ssl_buckets.c: 
SSL_connect:before/connect initialization
[2013-12-12T18:30:14.260002+04] buckets/ssl_buckets.c: bio_bucket_write called 
for 144 bytes
[2013-12-12T18:30:14.260007+04] buckets/ssl_buckets.c: SSL_connect:SSLv2/v3 
write client hello A
[2013-12-12T18:30:14.260012+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 7 bytes
[2013-12-12T18:30:14.260015+04] buckets/ssl_buckets.c: bio_bucket_read received 
0 bytes (70014)
[2013-12-12T18:30:14.260020+04] buckets/ssl_buckets.c: SSL_connect:error in 
SSLv2/v3 read server hello A
[2013-12-12T18:30:14.260023+04] buckets/ssl_buckets.c: ssl_encrypt: SSL write: 
-1
[2013-12-12T18:30:14.260029+04] buckets/ssl_buckets.c: ssl_encrypt: SSL write 
error: 2
[2013-12-12T18:30:14.260032+04] buckets/ssl_buckets.c: ssl_encrypt: SSL write 
error: 120103 0
[2013-12-12T18:30:14.260035+04] buckets/ssl_buckets.c: ssl_encrypt read agg: 
120103 70014 0 144
[2013-12-12T18:30:14.260038+04] buckets/ssl_buckets.c: ssl_encrypt finished: 
120103 144 (8 1 9)
[2013-12-12T18:30:14.319897+04] buckets/ssl_buckets.c: ssl_decrypt: begin 8000
[2013-12-12T18:30:14.319942+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 7 bytes
[2013-12-12T18:30:14.319947+04] buckets/ssl_buckets.c: bio_bucket_read waiting: 
(8 1 9)
[2013-12-12T18:30:14.319952+04] buckets/ssl_buckets.c: bio_bucket_read received 
0 bytes (70014)
[2013-12-12T18:30:14.319955+04] buckets/ssl_buckets.c: SSL_connect:error in 
SSLv2/v3 read server hello A
[2013-12-12T18:30:14.319968+04] buckets/ssl_buckets.c: ssl_decrypt: read 4786 
bytes (8000); status: 0
[2013-12-12T18:30:14.320041+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 7 bytes
[2013-12-12T18:30:14.320049+04] buckets/ssl_buckets.c: bio_bucket_read waiting: 
(8 1 9)
[2013-12-12T18:30:14.320052+04] buckets/ssl_buckets.c: bio_bucket_read received 
7 bytes (0)
[2013-12-12T18:30:14.320083+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 55 bytes
[2013-12-12T18:30:14.320087+04] buckets/ssl_buckets.c: bio_bucket_read received 
55 bytes (0)
[2013-12-12T18:30:14.320115+04] buckets/ssl_buckets.c: SSL_connect:SSLv3 read 
server hello A
[2013-12-12T18:30:14.320121+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 5 bytes
[2013-12-12T18:30:14.320124+04] buckets/ssl_buckets.c: bio_bucket_read received 
5 bytes (0)
[2013-12-12T18:30:14.320127+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 3739 bytes
[2013-12-12T18:30:14.320130+04] buckets/ssl_buckets.c: bio_bucket_read received 
3739 bytes (0)
[2013-12-12T18:30:14.320838+04] buckets/ssl_buckets.c: SSL_connect:SSLv3 read 
server certificate A
[2013-12-12T18:30:14.320847+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 5 bytes
[2013-12-12T18:30:14.320851+04] buckets/ssl_buckets.c: bio_bucket_read received 
5 bytes (0)
[2013-12-12T18:30:14.320854+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 781 bytes
[2013-12-12T18:30:14.320857+04] buckets/ssl_buckets.c: bio_bucket_read received 
781 bytes (0)
[2013-12-12T18:30:14.321042+04] buckets/ssl_buckets.c: SSL_connect:SSLv3 read 
server key exchange A
[2013-12-12T18:30:14.321046+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 5 bytes
[2013-12-12T18:30:14.321050+04] buckets/ssl_buckets.c: bio_bucket_read received 
5 bytes (0)
[2013-12-12T18:30:14.321053+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 189 bytes
[2013-12-12T18:30:14.321056+04] buckets/ssl_buckets.c: bio_bucket_read received 
189 bytes (70014)
[2013-12-12T18:30:14.321074+04] buckets/ssl_buckets.c: SSL_connect:SSLv3 read 
server certificate request A
[2013-12-12T18:30:14.321078+04] buckets/ssl_buckets.c: SSL_connect:SSLv3 read 
server done A
[2013-12-12T18:30:14.321087+04] buckets/ssl_buckets.c: SSL_connect:SSLv3 write 
client certificate A
[2013-12-12T18:30:14.322406+04] buckets/ssl_buckets.c: SSL_connect:SSLv3 write 
client key exchange A
[2013-12-12T18:30:14.322442+04] buckets/ssl_buckets.c: SSL_connect:SSLv3 write 
change cipher spec A
[2013-12-12T18:30:14.322459+04] buckets/ssl_buckets.c: SSL_connect:SSLv3 write 
finished A
[2013-12-12T18:30:14.322463+04] buckets/ssl_buckets.c: bio_bucket_write called 
for 210 bytes
[2013-12-12T18:30:14.322466+04] buckets/ssl_buckets.c: bio_bucket_write 
waiting: (0 0 0)
[2013-12-12T18:30:14.322471+04] buckets/ssl_buckets.c: SSL_connect:SSLv3 flush 
data
[2013-12-12T18:30:14.322475+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 5 bytes
[2013-12-12T18:30:14.322479+04] buckets/ssl_buckets.c: bio_bucket_read received 
0 bytes (70014)
[2013-12-12T18:30:14.322482+04] buckets/ssl_buckets.c: SSL_connect:error in 
SSLv3 read server session ticket A
[2013-12-12T18:30:14.322486+04] buckets/ssl_buckets.c: SSL_connect:error in 
SSLv3 read server session ticket A
[2013-12-12T18:30:14.322490+04] buckets/ssl_buckets.c: ssl_decrypt: 11 0 9
[2013-12-12T18:30:14.322498+04] buckets/ssl_buckets.c: ssl_decrypt: begin 8000
[2013-12-12T18:30:14.322502+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 5 bytes
[2013-12-12T18:30:14.322506+04] buckets/ssl_buckets.c: bio_bucket_read waiting: 
(8 1 9)
[2013-12-12T18:30:14.322509+04] buckets/ssl_buckets.c: bio_bucket_read received 
0 bytes (70014)
[2013-12-12T18:30:14.322512+04] buckets/ssl_buckets.c: SSL_connect:error in 
SSLv3 read server session ticket A
[2013-12-12T18:30:14.322517+04] buckets/ssl_buckets.c: ssl_decrypt: 11 0 9
[2013-12-12T18:30:14.322528+04] buckets/ssl_buckets.c: ssl_encrypt: begin 8000
[2013-12-12T18:30:14.322531+04] buckets/ssl_buckets.c: ssl_encrypt: 0 210 9 
(quick read)
[2013-12-12T18:30:14.322697+04] buckets/ssl_buckets.c: ssl_encrypt: begin 8000
[2013-12-12T18:30:14.322706+04] buckets/ssl_buckets.c: ssl_encrypt: reset 70014 
120103 (8 1 9)
[2013-12-12T18:30:14.322713+04] buckets/ssl_buckets.c: ssl_encrypt: bucket read 
527 bytes; status 11
[2013-12-12T18:30:14.322719+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 5 bytes
[2013-12-12T18:30:14.322726+04] buckets/ssl_buckets.c: bio_bucket_read received 
0 bytes (70014)
[2013-12-12T18:30:14.322729+04] buckets/ssl_buckets.c: SSL_connect:error in 
SSLv3 read server session ticket A
[2013-12-12T18:30:14.322732+04] buckets/ssl_buckets.c: ssl_encrypt: SSL write: 
-1
[2013-12-12T18:30:14.322736+04] buckets/ssl_buckets.c: ssl_encrypt: SSL write 
error: 2
[2013-12-12T18:30:14.322739+04] buckets/ssl_buckets.c: ssl_encrypt: SSL write 
error: 120103 0
[2013-12-12T18:30:14.322768+04] buckets/ssl_buckets.c: ssl_encrypt read agg: 
120103 70014 11 0
[2013-12-12T18:30:14.322784+04] buckets/ssl_buckets.c: ssl_encrypt finished: 
120103 0 (8 1 9)
[2013-12-12T18:30:14.323085+04] buckets/ssl_buckets.c: ssl_decrypt: begin 8000
[2013-12-12T18:30:14.323099+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 5 bytes
[2013-12-12T18:30:14.323103+04] buckets/ssl_buckets.c: bio_bucket_read waiting: 
(8 1 9)
[2013-12-12T18:30:14.323106+04] buckets/ssl_buckets.c: bio_bucket_read received 
0 bytes (70014)
[2013-12-12T18:30:14.323109+04] buckets/ssl_buckets.c: SSL_connect:error in 
SSLv3 read server session ticket A
[2013-12-12T18:30:14.323115+04] buckets/ssl_buckets.c: ssl_decrypt: read 7 
bytes (8000); status: 0
[2013-12-12T18:30:14.323119+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 5 bytes
[2013-12-12T18:30:14.323122+04] buckets/ssl_buckets.c: bio_bucket_read waiting: 
(8 1 9)
[2013-12-12T18:30:14.323126+04] buckets/ssl_buckets.c: bio_bucket_read received 
5 bytes (0)
[2013-12-12T18:30:14.323129+04] buckets/ssl_buckets.c: bio_bucket_read called 
for 2 bytes
[2013-12-12T18:30:14.323131+04] buckets/ssl_buckets.c: bio_bucket_read received 
2 bytes (70014)
[2013-12-12T18:30:14.323142+04] buckets/ssl_buckets.c: SSL3 alert 
read:fatal:handshake failure
[2013-12-12T18:30:14.323150+04] buckets/ssl_buckets.c: SSL_connect:failed in 
SSLv3 read server session ticket A
[2013-12-12T18:30:14.323154+04] buckets/ssl_buckets.c: ssl_decrypt: 120171 0 0
svn: E120171: Unable to connect to a repository at URL 
'https://svn.intranet.xxxxxx.xx/ssl/repo/Build'
svn: E120171: Error running context: An error occurred during SSL communication

Original comment by m...@okun.me on 12 Dec 2013 at 2:40

GoogleCodeExporter commented 9 years ago

From the log trace I see that the client certificate is uploaded to the server. 
Maybe it's not accepted?

Have a look in the apache error log, if needed increase the logging level to 
trace7 to see the ssl traffic.

Original comment by lieven.govaerts@gmail.com on 30 Dec 2013 at 10:59

GoogleCodeExporter commented 9 years ago

[deleted comment]

GoogleCodeExporter commented 9 years ago

[deleted comment]

GoogleCodeExporter commented 9 years ago

Sorry, this is correct log

[Mon Dec 30 20:30:55 2013] [info] [client 10.121.5.10] Connection to child 0 
established (server svn.intranet.company.ru:443)
[Mon Dec 30 20:30:55 2013] [info] Seeding PRNG with 144 bytes of entropy
[Mon Dec 30 20:30:55 2013] [debug] ssl_engine_kernel.c(1892): OpenSSL: 
Handshake: start
[Mon Dec 30 20:30:55 2013] [debug] ssl_engine_kernel.c(1900): OpenSSL: Loop: 
before/accept initialization
[Mon Dec 30 20:30:55 2013] [debug] ssl_engine_io.c(1939): OpenSSL: read 11/11 
bytes from BIO#80e283200 [mem: 8029ee000] (BIO dump follows)
[Mon Dec 30 20:30:55 2013] [debug] ssl_engine_io.c(1872): 
+-------------------------------------------------------------------------+
[Mon Dec 30 20:30:55 2013] [debug] ssl_engine_io.c(1911): | 0000: 16 03 01 00 
8b 01 00 00-87 03 01                 ...........      |
[Mon Dec 30 20:30:55 2013] [debug] ssl_engine_io.c(1917): 
+-------------------------------------------------------------------------+
[Mon Dec 30 20:30:55 2013] [debug] ssl_engine_io.c(1939): OpenSSL: read 133/133 
bytes from BIO#80e283200 [mem: 8029ee00e] (BIO dump follows)
[Mon Dec 30 20:30:55 2013] [debug] ssl_engine_io.c(1872): 
+-------------------------------------------------------------------------+
[Mon Dec 30 20:30:55 2013] [debug] ssl_engine_io.c(1911): | 0070: 74 72 61 6e 
65 74 2e 6b-69 6e 74 65 63 68 2e 72  tranet.company.r |
[Mon Dec 30 20:30:55 2013] [debug] ssl_engine_io.c(1911): | 0080: 75 00 23      
                                   u.#              |
[Mon Dec 30 20:30:55 2013] [debug] ssl_engine_io.c(1915): | 0133 - <SPACES/NULS>
[Mon Dec 30 20:30:55 2013] [debug] ssl_engine_io.c(1917): 
+-------------------------------------------------------------------------+
[Mon Dec 30 20:30:55 2013] [debug] ssl_engine_kernel.c(2013): [client 
10.121.5.10] SSL virtual host for servername svn.intranet.company.ru found
[Mon Dec 30 20:30:55 2013] [debug] ssl_engine_kernel.c(1900): OpenSSL: Loop: 
SSLv3 read client hello A
[Mon Dec 30 20:30:55 2013] [debug] ssl_engine_kernel.c(1900): OpenSSL: Loop: 
SSLv3 write server hello A
[Mon Dec 30 20:30:55 2013] [debug] ssl_engine_kernel.c(1900): OpenSSL: Loop: 
SSLv3 write certificate A
[Mon Dec 30 20:30:55 2013] [debug] ssl_engine_kernel.c(1254): [client 
10.121.5.10] handing out temporary 1024 bit DH key
[Mon Dec 30 20:30:55 2013] [debug] ssl_engine_kernel.c(1900): OpenSSL: Loop: 
SSLv3 write key exchange A
[Mon Dec 30 20:30:55 2013] [debug] ssl_engine_kernel.c(1900): OpenSSL: Loop: 
SSLv3 write certificate request A
[Mon Dec 30 20:30:55 2013] [debug] ssl_engine_kernel.c(1900): OpenSSL: Loop: 
SSLv3 flush data
[Mon Dec 30 20:30:55 2013] [debug] ssl_engine_io.c(1939): OpenSSL: read 5/5 
bytes from BIO#80e283200 [mem: 8029ee003] (BIO dump follows)
[Mon Dec 30 20:30:55 2013] [debug] ssl_engine_io.c(1872): 
+-------------------------------------------------------------------------+
[Mon Dec 30 20:30:55 2013] [debug] ssl_engine_io.c(1911): | 0000: 16 03 01 00 
07                                   .....            |
[Mon Dec 30 20:30:55 2013] [debug] ssl_engine_io.c(1917): 
+-------------------------------------------------------------------------+
[Mon Dec 30 20:30:55 2013] [debug] ssl_engine_io.c(1939): OpenSSL: read 7/7 
bytes from BIO#80e283200 [mem: 8029ee008] (BIO dump follows)
[Mon Dec 30 20:30:55 2013] [debug] ssl_engine_io.c(1872): 
+-------------------------------------------------------------------------+
[Mon Dec 30 20:30:55 2013] [debug] ssl_engine_io.c(1911): | 0000:               
                        ....             |
[Mon Dec 30 20:30:55 2013] [debug] ssl_engine_io.c(1915): | 0007 - <SPACES/NULS>
[Mon Dec 30 20:30:55 2013] [debug] ssl_engine_io.c(1917): 
+-------------------------------------------------------------------------+
[Mon Dec 30 20:30:55 2013] [debug] ssl_engine_kernel.c(1910): OpenSSL: Write: 
SSLv3 read client certificate B
[Mon Dec 30 20:30:55 2013] [debug] ssl_engine_kernel.c(1929): OpenSSL: Exit: 
error in SSLv3 read client certificate B
[Mon Dec 30 20:30:55 2013] [debug] ssl_engine_kernel.c(1929): OpenSSL: Exit: 
error in SSLv3 read client certificate B
[Mon Dec 30 20:30:55 2013] [info] [client 10.121.5.10] SSL library error 1 in 
handshake (server svn.intranet.company.ru:443)
[Mon Dec 30 20:30:55 2013] [info] SSL Library Error: 336105671 
error:140890C7:SSL routines:SSL3_GET_CLIENT_CERTIFICATE:peer did not return a 
certificate No CAs known to server for verification?
[Mon Dec 30 20:30:55 2013] [info] [client 10.121.5.10] Connection closed to 
child 0 with abortive shutdown (server svn.intranet.company.ru:443)

Original comment by m...@okun.me on 30 Dec 2013 at 4:33

GoogleCodeExporter commented 9 years ago

<deleted two comments with incorrect info to make this thread easier to follow>

Mike, from your latest log it's clear that the client isn't sending a real 
client certificate to the server. The serf log does contain a line 
"SSL_connect:SSLv3 write client certificate A", but on the server side only 7 
bytes are received, whereas the client cert should be 100's of bytes long.

Serf uses OpenSSL to load a .p12 file with the client cert & private key and 
asks for the password if necessary (via a callback to Subversion). OpenSSL then 
parses the p12 file to extract the certificate and send it to the server.
It's not clear to me how it's possible that OpenSSL successfully loads and 
parses the file, but then not send it to the server.

So, some more questions:
1a. Did this work before, with an older svn client using ra_neon?
1b. Can you successfully open files on the server with a web browser?

2. Can you try to use the openssl client to simulate a http connection to the 
server with ssl handshake? This is what I had to do to use the openssl client 
with the client cert that's included in the serf test suite:
a. extract the private key to a file:
   $ openssl pkcs12 -in test/server/serfclientcert.p12 -nocerts -out test/server/serfclientkey.pem 
b. extract the client certificate to a file
   $ openssl pkcs12 -in test/server/serfclientcert.p12 -clcerts -nokeys -out test/server/serfclientcert.pem

Then, I've enabled trace8 logging in my apache server:
<IfModule mod_ssl.c>
    ErrorLog /var/log/apache2/ssl_engine.log
    LogLevel trace8
</IfModule>

Then to connect to my test http server (on lgo-ubuntu1.dev, which I have 
configured with test suite's certificate chain:
$ openssl s_client -connect lgo-ubuntu1.dev:443 -CAfile 
~/dev/serftrunk/serfcerts.pem -cert test/server/serfclientcert.pem -key 
test/server/serfclientkey.pem -pass pass:serftest
(the password is that of the client private key)

If all goes well here, the output should contain the server's certificate chain:
Certificate chain
 0 s:/C=BE/ST=Antwerp/L=Mechelen/O=In Serf we trust, Inc./OU=Test Suite Server/CN=localhost/emailAddress=serfserver@example.com
   i:/C=BE/ST=Antwerp/L=Mechelen/O=In Serf we trust, Inc./OU=Test Suite CA/CN=Serf CA/emailAddress=serfca@example.com
 1 s:/C=BE/ST=Antwerp/L=Mechelen/O=In Serf we trust, Inc./OU=Test Suite CA/CN=Serf CA/emailAddress=serfca@example.com
   i:/C=BE/ST=Antwerp/L=Mechelen/O=In Serf we trust, Inc./OU=Test Suite Root CA/CN=Serf Root CA/emailAddress=serfrootca@example.com
 2 s:/C=BE/ST=Antwerp/L=Mechelen/O=In Serf we trust, Inc./OU=Test Suite Root CA/CN=Serf Root CA/emailAddress=serfrootca@example.com
   i:/C=BE/ST=Antwerp/L=Mechelen/O=In Serf we trust, Inc./OU=Test Suite Root CA/CN=Serf Root CA/emailAddress=serfrootca@example.com
...
Acceptable client certificate CA names
/C=BE/ST=Antwerp/L=Mechelen/O=In Serf we trust, Inc./OU=Test Suite CA/CN=Serf 
CA/emailAddress=serfca@example.com
/C=BE/ST=Antwerp/L=Mechelen/O=In Serf we trust, Inc./OU=Test Suite Root 
CA/CN=Serf Root CA/emailAddress=serfrootca@example.com
...
SSL-Session:
    Protocol  : TLSv1.2
    Cipher    : ECDHE-RSA-AES256-GCM-SHA384
...   
    Timeout   : 300 (sec)
    Verify return code: 0 (ok)
---

It then waits for a http request, so if you type 'GET /' it should fetch that 
page from the server.

Can you send me the console output (masking private information).

Lieven

Original comment by lieven.govaerts@gmail.com on 30 Dec 2013 at 8:31

GoogleCodeExporter commented 9 years ago

1a. Did this work before, with an older svn client using ra_neon?
 Yes, it works with TortoiseSVN 1.7.* with ra_neon with the same server and certificates

1b. Can you successfully open files on the server with a web browser?
 Yes, I have tried with Chrome and Firefox

Connection with openssl client also works properly, I have attached output.

openssl output as you requested:

user@localhost code]$ openssl s_client -connect company.com:443 -CAfile 
/home/user/SVN_CA.pem -cert /home/user/user_cert.pem -key 
/home/user/user_key.pem 
Enter pass phrase for /home/user/user_key.pem:
CONNECTED(00000003)
depth=1 C = RU, ST = Moscow, L = Moscow, O = My Company, OU = Software 
development, CN = company.com CA, emailAddress = e@mail.com
verify return:1
depth=0 C = RU, ST = Moscow, L = Moscow, O = My Company, OU = Software 
development, CN = company.com, emailAddress = e@mail.com
verify return:1
---
Certificate chain
 0 s:/C=RU/ST=Moscow/L=Moscow/O=My Company/OU=Software development/CN=company.com/emailAddress=e@mail.com
   i:/C=RU/ST=Moscow/L=Moscow/O=My Company/OU=Software development/CN=company.com CA/emailAddress=e@mail.com
 1 s:/C=RU/ST=Moscow/L=Moscow/O=My Company/OU=Software development/CN=company.com CA/emailAddress=e@mail.com
   i:/C=RU/ST=Moscow/L=Moscow/O=My Company/OU=Software development/CN=company.com CA/emailAddress=e@mail.com
---
Server certificate
-----BEGIN CERTIFICATE-----
UZp3m1hJb121DSYeMf7VvNW55D+cBzMurGSgNymjMmf4estD
-----END CERTIFICATE-----
subject=/C=RU/ST=Moscow/L=Moscow/O=My Company/OU=Software 
development/CN=company.com/emailAddress=e@mail.com
issuer=/C=RU/ST=Moscow/L=Moscow/O=My Company/OU=Software 
development/CN=company.com CA/emailAddress=e@mail.com
---
Acceptable client certificate CA names
/C=RU/ST=Moscow/L=Moscow/O=My Company/OU=Software development/CN=company.com 
CA/emailAddress=e@mail.com
---
SSL handshake has read 6904 bytes and written 4573 bytes
---
New, TLSv1/SSLv3, Cipher is DHE-RSA-AES256-SHA
Server public key is 4096 bit
Secure Renegotiation IS supported
Compression: NONE
Expansion: NONE
SSL-Session:
    Protocol  : TLSv1
    Cipher    : DHE-RSA-AES256-SHA
    Session-ID: ************
    Session-ID-ctx: 
    Master-Key: ************
    Key-Arg   : None
    Krb5 Principal: None
    PSK identity: None
    PSK identity hint: None
    TLS session ticket lifetime hint: 300 (seconds)
    TLS session ticket:
    0000 - fc 78 0b c7 b3 93 1d f8-c0 b9 ba 29 53 72 c9 64   .x.........)Sr.d
    *************************************************************************
    07f0 - bf f7 cd 50 f8 4f 6c 00-da d1 4f a3 2a ae 36 cd   ...P.Ol...O.*.6.

    Start Time: 1390924732
    Timeout   : 300 (sec)
    Verify return code: 0 (ok)
---
GET /
<!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 3.2 Final//EN">
<html>
 <head>
  <title>Index of /</title>
 </head>
 <body>
<h1>Index of /</h1>
<ul></ul>
<address>Apache/2.2.26 (FreeBSD) DAV/2 PHP/5.4.21 SVN/1.8.5 mod_ssl/2.2.26 
OpenSSL/1.0.1e Server at company.com Port 443</address>
</body></html>
closed

apache error log:

[Tue Jan 28 20:00:31 2014] [info] [client 10.12.6.10] Connection to child 2 
established (server company.com:443)
[Tue Jan 28 20:00:31 2014] [info] Seeding PRNG with 144 bytes of entropy
[Tue Jan 28 20:00:31 2014] [debug] ssl_engine_kernel.c(1892): OpenSSL: 
Handshake: start
[Tue Jan 28 20:00:31 2014] [debug] ssl_engine_kernel.c(1900): OpenSSL: Loop: 
before/accept initialization
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1939): OpenSSL: read 11/11 
bytes from BIO#80e283200 [mem: 8029ee000] (BIO dump follows)
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1872): 
+-------------------------------------------------------------------------+
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1911): | 0000: 16 03 01 00 
6b 01 00 00-67 03 01                 ....k...g..      |
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1917): 
+-------------------------------------------------------------------------+
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1939): OpenSSL: read 101/101 
bytes from BIO#80e283200 [mem: 8029ee00e] (BIO dump follows)
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1872): 
+-------------------------------------------------------------------------+
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1911): | 0050: 09 00 14 00 
11 00 08 00-06 00 03 00 ff 01 00 00  ................ |
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1911): | 0060: 04 00 23      
                                   ..#              |
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1915): | 0101 - <SPACES/NULS>
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1917): 
+-------------------------------------------------------------------------+
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_kernel.c(1900): OpenSSL: Loop: 
SSLv3 read client hello A
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_kernel.c(1900): OpenSSL: Loop: 
SSLv3 write server hello A
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_kernel.c(1900): OpenSSL: Loop: 
SSLv3 write certificate A
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_kernel.c(1254): [client 
10.12.6.10] handing out temporary 1024 bit DH key
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_kernel.c(1900): OpenSSL: Loop: 
SSLv3 write key exchange A
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_kernel.c(1900): OpenSSL: Loop: 
SSLv3 write certificate request A
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_kernel.c(1900): OpenSSL: Loop: 
SSLv3 flush data
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1939): OpenSSL: read 5/5 
bytes from BIO#80e283200 [mem: 8029ee003] (BIO dump follows)
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1872): 
+-------------------------------------------------------------------------+
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1911): | 0000: 16 03 01 0e 
97                                   .....            |
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1917): 
+-------------------------------------------------------------------------+
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1939): OpenSSL: read 
2915/3735 bytes from BIO#80e283200 [mem: 8029ee008] (BIO dump follows)
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1872): 
+-------------------------------------------------------------------------+
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1911): | 0000: 0b 00 0e 93 
00 0e 90 00-07 40 30 82 07 3c 30 82  .........@0..<0. |
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1917): 
+-------------------------------------------------------------------------+
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1939): OpenSSL: read 820/820 
bytes from BIO#80e283200 [mem: 8029eeb6b] (BIO dump follows)
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1872): 
+-------------------------------------------------------------------------+
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1911): | 0000: a8 31 0b 30 
09 06 03 55-04 06 13 02 52 55 31 0f  .1.0...U....RU1. |
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1911): | 0330: 37 a1 e2 f3   
                                   7...             |
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1917): 
+-------------------------------------------------------------------------+
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_kernel.c(1322): [client 
10.12.6.10] Certificate Verification: depth: 1, subject: 
/C=RU/ST=Moscow/L=Moscow/O=My Company/OU=Software development/CN=company.com 
CA/emailAddress=e@mail.com, issuer: /C=RU/ST=Moscow/L=Moscow/O=My 
Company/OU=Software development/CN=company.com CA/emailAddress=e@mail.com
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_kernel.c(1322): [client 
10.12.6.10] Certificate Verification: depth: 0, subject: 
/C=RU/ST=Moscow/L=Moscow/O=My Company/OU=Software 
development/CN=user/emailAddress=user@company.ru, issuer: 
/C=RU/ST=Moscow/L=Moscow/O=My Company/OU=Software development/CN=company.com 
CA/emailAddress=e@mail.com
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_kernel.c(1900): OpenSSL: Loop: 
SSLv3 read client certificate A
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1939): OpenSSL: read 5/5 
bytes from BIO#80e283200 [mem: 8029ee003] (BIO dump follows)
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1872): 
+-------------------------------------------------------------------------+
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1911): | 0000: 16 03 01 00 
86                                   .....            |
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1917): 
+-------------------------------------------------------------------------+
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1939): OpenSSL: read 134/134 
bytes from BIO#80e283200 [mem: 8029ee008] (BIO dump follows)
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1872): 
+-------------------------------------------------------------------------+
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1911): | 0000: 10 00 00 82 
00 80 86 6b-cd 1f 56 4d c1 2b 8a d9  .......k..VM.+.. |
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1917): 
+-------------------------------------------------------------------------+
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_kernel.c(1900): OpenSSL: Loop: 
SSLv3 read client key exchange A
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1939): OpenSSL: read 5/5 
bytes from BIO#80e283200 [mem: 8029ee003] (BIO dump follows)
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1872): 
+-------------------------------------------------------------------------+
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1911): | 0000: 16 03 01 02 
06                                   .....            |
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1917): 
+-------------------------------------------------------------------------+
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1939): OpenSSL: read 518/518 
bytes from BIO#80e283200 [mem: 8029ee008] (BIO dump follows)
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1872): 
+-------------------------------------------------------------------------+
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1911): | 0000: 0f 00 02 02 
02 00 b1 eb-79 d2 5f 57 3d bb d0 24  ........y._W=..$ |
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1917): 
+-------------------------------------------------------------------------+
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_kernel.c(1900): OpenSSL: Loop: 
SSLv3 read certificate verify A
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1939): OpenSSL: read 5/5 
bytes from BIO#80e283200 [mem: 8029ee003] (BIO dump follows)
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1872): 
+-------------------------------------------------------------------------+
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1911): | 0000: ***********   
                                .....            |
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1917): 
+-------------------------------------------------------------------------+
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1939): OpenSSL: read 1/1 
bytes from BIO#80e283200 [mem: 8029ee008] (BIO dump follows)
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1872): 
+-------------------------------------------------------------------------+
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1911): | 0000: ******        
                                   .                |
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1917): 
+-------------------------------------------------------------------------+
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1939): OpenSSL: read 5/5 
bytes from BIO#80e283200 [mem: 8029ee003] (BIO dump follows)
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1872): 
+-------------------------------------------------------------------------+
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1911): | 0000: 16 03 01 00 
30                                   ....0            |
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1917): 
+-------------------------------------------------------------------------+
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1939): OpenSSL: read 48/48 
bytes from BIO#80e283200 [mem: 8029ee008] (BIO dump follows)
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1872): 
+-------------------------------------------------------------------------+
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_io.c(1917): 
+-------------------------------------------------------------------------+
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_kernel.c(1900): OpenSSL: Loop: 
SSLv3 read finished A
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_kernel.c(1900): OpenSSL: Loop: 
SSLv3 write session ticket A
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_kernel.c(1900): OpenSSL: Loop: 
SSLv3 write change cipher spec A
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_kernel.c(1900): OpenSSL: Loop: 
SSLv3 write finished A
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_kernel.c(1900): OpenSSL: Loop: 
SSLv3 flush data
[Tue Jan 28 20:00:33 2014] [debug] ssl_engine_kernel.c(1896): OpenSSL: 
Handshake: done
[Tue Jan 28 20:00:33 2014] [info] Connection: Client IP: 10.12.6.10, Protocol: 
TLSv1, Cipher: DHE-RSA-AES256-SHA (256/256 bits)
[Tue Jan 28 20:00:37 2014] [debug] ssl_engine_io.c(1939): OpenSSL: read 5/5 
bytes from BIO#80e283200 [mem: 8029ee003] (BIO dump follows)
[Tue Jan 28 20:00:37 2014] [debug] ssl_engine_io.c(1872): 
+-------------------------------------------------------------------------+
[Tue Jan 28 20:00:37 2014] [debug] ssl_engine_io.c(1911): | 0000: 17 03 01      
                                   ...              |
[Tue Jan 28 20:00:37 2014] [debug] ssl_engine_io.c(1915): | 0005 - <SPACES/NULS>
[Tue Jan 28 20:00:37 2014] [debug] ssl_engine_io.c(1917): 
+-------------------------------------------------------------------------+
[Tue Jan 28 20:00:37 2014] [debug] ssl_engine_io.c(1939): OpenSSL: read 32/32 
bytes from BIO#80e283200 [mem: 8029ee008] (BIO dump follows)
[Tue Jan 28 20:00:37 2014] [debug] ssl_engine_io.c(1872): 
+-------------------------------------------------------------------------+
[[Tue Jan 28 20:00:37 2014] [debug] ssl_engine_io.c(1911): | 0010: 
1**************************** |
[Tue Jan 28 20:00:37 2014] [debug] ssl_engine_io.c(1917): 
+-------------------------------------------------------------------------+
[Tue Jan 28 20:00:37 2014] [debug] ssl_engine_io.c(1939): OpenSSL: read 5/5 
bytes from BIO#80e283200 [mem: 8029ee003] (BIO dump follows)
[Tue Jan 28 20:00:37 2014] [debug] ssl_engine_io.c(1872): 
+-------------------------------------------------------------------------+
[Tue Jan 28 20:00:37 2014] [debug] ssl_engine_io.c(1911): | 0000: 17 03 01      
                                   ...              |
[Tue Jan 28 20:00:37 2014] [debug] ssl_engine_io.c(1915): | 0005 - <SPACES/NULS>
[Tue Jan 28 20:00:37 2014] [debug] ssl_engine_io.c(1917): 
+-------------------------------------------------------------------------+
[Tue Jan 28 20:00:37 2014] [debug] ssl_engine_io.c(1939): OpenSSL: read 32/32 
bytes from BIO#80e283200 [mem: 8029ee008] (BIO dump follows)
[Tue Jan 28 20:00:37 2014] [debug] ssl_engine_io.c(1872): 
+-------------------------------------------------------------------------+
[Tue Jan 28 20:00:37 2014] [debug] ssl_engine_io.c(1911): | 0000:  |
[Tue Jan 28 20:00:37 2014] [debug] ssl_engine_io.c(1911): | 0010: |
[Tue Jan 28 20:00:37 2014] [debug] ssl_engine_io.c(1917): 
+-------------------------------------------------------------------------+
[Tue Jan 28 20:00:37 2014] [info] Initial (No.1) HTTPS request received for 
child 2 (server company.com:443)
[Tue Jan 28 20:00:37 2014] [debug] ssl_engine_kernel.c(1910): OpenSSL: Write: 
SSL negotiation finished successfully
[Tue Jan 28 20:00:37 2014] [info] [client 10.12.6.10] Connection closed to 
child 2 with standard shutdown (server company.com:443)

Original comment by m...@okun.me on 28 Jan 2014 at 4:16

GoogleCodeExporter commented 9 years ago

We've added a workaround to serf in r2420 that should handle these type of 
renegotiation errors. In short, serf will detect if a renegotiation is 
requested on a connection that has HTTP pipelining enabled, and then fall back 
to a connection with pipelining disabled.
The consequence is that communication will be slower, but only in these 
specific situations.

Original comment by lieven.govaerts@gmail.com on 21 Aug 2014 at 5:39

muthusuba / serf

ssl re-negotiation error #135