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)

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.

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

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.

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

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?

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.

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

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

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.

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

Comment deleted

Comment deleted

I have tried to make Apache configuration which does not require renegatiation, i.e "SSLVerifyClient require" is specified not at 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

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.

Comment deleted

Comment deleted

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 - [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 - [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)

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: ErrorLog /var/log/apache2/ssl_engine.log LogLevel trace8

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

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 / Index of /

Index of /

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 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 - [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 - [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 - [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)

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.