You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@subversion.apache.org by Bernd May <be...@net.t-labs.tu-berlin.de> on 2013/07/25 16:25:50 UTC

Problem with SSL Client auth and libserf

Hello,

I am experiencing re-negotiation issues namely connection closed when
trying to use a subversion client >=1.8 against an svn server running

Debian Wheezy
apache 2.2.22
libapache 1.8.1
subversion 1.8.1
openssl 1.0.1e

with ssl client auth.

I have now spent about 4 hours of searching through old ssl client auth
errors in the openssl issues, subversion maillinglist and tried the
following combinations of client libraries and binaries against the
server mentioned above:

* svn client 1.6.9, 1.6.16, 1.6.17, 1.7.11, 1.8.0, 1.8.1
* Openssl 0.9.8g, 0.9.8.k, 0.9.8o, 1.0.0, 1.0.0e

Whenver I use the newer subversion clients (v1.8 and 1.8.1) I receive
the following error on the client side, regardless of the openssl version:

svn: E120108: Unable to connect to a repository at URL
'https://example.com/svn/myrepo'
svn: E120108: Error running context: The server unexpectedly closed the
connection.

Disabling the 'SSLVerifyClient Require' directive yields a successful
listing of the svn content, so this really appears to be related to
client auth.
Using an svn client with libneon also yields a successful repository
listing so this points quite directly at libserf.

On the server side the error messages in debug mode look like this:

... initial ssl connection setup completes ...
[Thu Jul 25 16:20:12 2013] [info] Initial (No.1) HTTPS request received
for child 77 (server inet-svn.net.t-labs.tu-berlin.de:443)
[Thu Jul 25 16:20:12 2013] [debug] ssl_engine_kernel.c(510): [client
<myip>] Changed client verification type will force renegotiation
[Thu Jul 25 16:20:12 2013] [debug] ssl_engine_io.c(1554): [client
<myip>] filling buffer, max size 131072 bytes
[Thu Jul 25 16:20:12 2013] [debug] ssl_engine_io.c(1606): [client
<myip>] total of 131 bytes in buffer, eos=1
[Thu Jul 25 16:20:12 2013] [info] [client <myip>] Requesting connection
re-negotiation
[Thu Jul 25 16:20:12 2013] [debug] ssl_engine_io.c(1908): OpenSSL: I/O
error, 5 bytes expected to read on BIO#7fa9ced2a820 [mem: 7fa9ced082c3]
[Thu Jul 25 16:20:12 2013] [debug] ssl_engine_kernel.c(764): [client
<myip>] Performing full renegotiation: complete handshake protocol
(client does support secure renegotiation)
[Thu Jul 25 16:20:12 2013] [debug] ssl_engine_kernel.c(1866): OpenSSL:
Handshake: start
[Thu Jul 25 16:20:12 2013] [debug] ssl_engine_kernel.c(1874): OpenSSL:
Loop: SSL renegotiate ciphers
[Thu Jul 25 16:20:12 2013] [debug] ssl_engine_kernel.c(1874): OpenSSL:
Loop: SSLv3 write hello request A
[Thu Jul 25 16:20:12 2013] [debug] ssl_engine_kernel.c(1874): OpenSSL:
Loop: SSLv3 flush data
[Thu Jul 25 16:20:12 2013] [debug] ssl_engine_kernel.c(1874): OpenSSL:
Loop: SSLv3 write hello request C
[Thu Jul 25 16:20:12 2013] [info] [client <myip>] Awaiting
re-negotiation handshake
[Thu Jul 25 16:20:12 2013] [debug] ssl_engine_kernel.c(1866): OpenSSL:
Handshake: start
[Thu Jul 25 16:20:12 2013] [debug] ssl_engine_kernel.c(1874): OpenSSL:
Loop: before accept initialization
[Thu Jul 25 16:20:22 2013] [info] [client <myip>] Request body read timeout
[Thu Jul 25 16:20:22 2013] [debug] ssl_engine_io.c(1908): OpenSSL: I/O
error, 5 bytes expected to read on BIO#7fa9ced2a820 [mem: 7fa9ced082c3]
[Thu Jul 25 16:20:22 2013] [debug] ssl_engine_kernel.c(1903): OpenSSL:
Exit: error in SSLv3 read client hello B
[Thu Jul 25 16:20:22 2013] [error] [client <myip>] Re-negotiation
handshake failed: Not accepted by client!?
[Thu Jul 25 16:20:22 2013] [debug] mod_deflate.c(615): [client <myip>]
Zlib: Compressed 0 to 2 : URL /svn/bernd


So either the client sent garbage or not what the server expects or
there is some kind of hiccup in the server libraries?

If anyone could point me to a way to further debug this or a solution,
I'd be very gracious
-- 
Technische Universität Berlin - FGINET

Bernd May

System Administration
Sekr. TEL 16
Ernst-Reuter-Platz 7
10587 BERLIN
GERMANY

Mobile: 0160/90257737
E-Mail: bernd@inet.tu-berlin.de
WWW:    inet.tu-berlin.de


Re: Problem with SSL Client auth and libserf

Posted by Bernd May <be...@net.t-labs.tu-berlin.de>.
Hey,

On 26.07.2013 11:14, Lieven Govaerts wrote:> This renegotiation issue
was solved on serf trunk in r2078, details in
> the ticket you opened:
> https://code.google.com/p/serf/issues/detail?id=114
> 
> r2078 applies cleanly to the serf 1.3.x branch, so if you can validate
> the fix before I backport it to 1.3.x that'd be much appreciated!

that was fast - thanks alot!
I just recompiled the complete subversion client because my installed
one was built against libserf-v1.2 and would not work with LD_PRELOAD
with the newer 1.3 libserf. Results look fine

bernd@myhost:~$ /usr/local/bin/svn ls https://example.com/svn/testrepos
README

...but...

This only works in an optimal client auth environment, meaning

* The path to the client certificate is specified in ~
/.subversion/servers in the correct section. Otherwise the following
error will occur:

bernd@myhost:~$ /usr/local/bin/svn ls https://example.com/svn/testrepos
subversion/svn/list-cmd.c:383,
subversion/libsvn_client/list.c:578,
subversion/libsvn_client/list.c:368,
subversion/libsvn_client/ra.c:516,
subversion/libsvn_client/ra.c:393,
subversion/libsvn_ra/ra_loader.c:482: (apr_err=120171)
svn: E120171: Unable to connect to a repository at URL
'https://example.com/svn/testrepos'
subversion/libsvn_ra_serf/serf.c:528,
subversion/libsvn_ra_serf/options.c:508,
subversion/libsvn_ra_serf/util.c:814,
subversion/libsvn_ra_serf/util.c:781: (apr_err=120171)
svn: E120171: Error running context: An error occurred during SSL
communication

* The ~/.subversion/servers file is readable, otherwise svn will segfault:

bernd@myhost:~$ /usr/local/bin/svn ls https://example.com/svn/testrepos
svn: warning: W000013: Can't open file
'/home/bernd/.subversion/servers': Permission denied
Segmentation fault

* When having activated the 'ssl-client-cert-file-prompt=yes' option in
the ~/.subversion/config [auth] section one has to provide a certificate
in pkcs12 format. Otherwise, e.g. when using a PEM encoded cert, one
receives this error:

bernd@myhost:~$ /usr/local/bin/svn ls https://example.com/svn/testrepos
Authentication realm: https://example.com:443
Client certificate filename: /home/bernd/workspace/svn/bernd.pem
OpenSSL cert error: 13 104 168
Authentication realm: https://example.com:443
Client certificate filename: /home/bernd/.subversion/certs/bernd.p12
README

I guess all of them need to be reported to the subversion people though.
I assume they are not directly related to libserf.

Thanks again for the fast help, hope to see that fix in downstream
packes soon :)

-- 
Technische Universität Berlin - FGINET

Bernd May

System Administration
Sekr. TEL 16
Ernst-Reuter-Platz 7
10587 BERLIN
GERMANY

Mobile: 0160/90257737
E-Mail: bernd@inet.tu-berlin.de
WWW:    inet.tu-berlin.de




Re: Problem with SSL Client auth and libserf

Posted by Lieven Govaerts <lg...@apache.org>.
Hi,

On Thu, Jul 25, 2013 at 4:25 PM, Bernd May
<be...@net.t-labs.tu-berlin.de> wrote:
> Hello,
>
> I am experiencing re-negotiation issues namely connection closed when
> trying to use a subversion client >=1.8 against an svn server running
>
> Debian Wheezy
> apache 2.2.22
> libapache 1.8.1
> subversion 1.8.1
> openssl 1.0.1e
>
> with ssl client auth.

[..]

> [Thu Jul 25 16:20:12 2013] [info] [client <myip>] Requesting connection
> re-negotiation
> [Thu Jul 25 16:20:12 2013] [debug] ssl_engine_io.c(1908): OpenSSL: I/O
> error, 5 bytes expected to read on BIO#7fa9ced2a820 [mem: 7fa9ced082c3]
> [Thu Jul 25 16:20:12 2013] [debug] ssl_engine_kernel.c(764): [client
> <myip>] Performing full renegotiation: complete handshake protocol
> (client does support secure renegotiation)
> [Thu Jul 25 16:20:12 2013] [debug] ssl_engine_kernel.c(1866): OpenSSL:
> Handshake: start
> [Thu Jul 25 16:20:12 2013] [debug] ssl_engine_kernel.c(1874): OpenSSL:
> Loop: SSL renegotiate ciphers
> [Thu Jul 25 16:20:12 2013] [debug] ssl_engine_kernel.c(1874): OpenSSL:
> Loop: SSLv3 write hello request A
> [Thu Jul 25 16:20:12 2013] [debug] ssl_engine_kernel.c(1874): OpenSSL:
> Loop: SSLv3 flush data
> [Thu Jul 25 16:20:12 2013] [debug] ssl_engine_kernel.c(1874): OpenSSL:
> Loop: SSLv3 write hello request C
> [Thu Jul 25 16:20:12 2013] [info] [client <myip>] Awaiting
> re-negotiation handshake
> [Thu Jul 25 16:20:12 2013] [debug] ssl_engine_kernel.c(1866): OpenSSL:
> Handshake: start
> [Thu Jul 25 16:20:12 2013] [debug] ssl_engine_kernel.c(1874): OpenSSL:
> Loop: before accept initialization
> [Thu Jul 25 16:20:22 2013] [info] [client <myip>] Request body read timeout
> [Thu Jul 25 16:20:22 2013] [debug] ssl_engine_io.c(1908): OpenSSL: I/O
> error, 5 bytes expected to read on BIO#7fa9ced2a820 [mem: 7fa9ced082c3]
> [Thu Jul 25 16:20:22 2013] [debug] ssl_engine_kernel.c(1903): OpenSSL:
> Exit: error in SSLv3 read client hello B
> [Thu Jul 25 16:20:22 2013] [error] [client <myip>] Re-negotiation
> handshake failed: Not accepted by client!?
> [Thu Jul 25 16:20:22 2013] [debug] mod_deflate.c(615): [client <myip>]
> Zlib: Compressed 0 to 2 : URL /svn/bernd
>

This renegotiation issue was solved on serf trunk in r2078, details in
the ticket you opened:
https://code.google.com/p/serf/issues/detail?id=114

r2078 applies cleanly to the serf 1.3.x branch, so if you can validate
the fix before I backport it to 1.3.x that'd be much appreciated!

thanks,

Lieven


> --
> Technische Universität Berlin - FGINET
>
> Bernd May
>
> System Administration
> Sekr. TEL 16
> Ernst-Reuter-Platz 7
> 10587 BERLIN
> GERMANY
>
> Mobile: 0160/90257737
> E-Mail: bernd@inet.tu-berlin.de
> WWW:    inet.tu-berlin.de
>

Re: Problem with SSL Client auth and libserf

Posted by Lieven Govaerts <lg...@apache.org>.
On Thu, Jul 25, 2013 at 8:53 PM, Lieven Govaerts <lg...@apache.org> wrote:
> Hi Bernd,
>
> On Thu, Jul 25, 2013 at 5:56 PM, Lieven Govaerts <lg...@apache.org> wrote:
>> Hi,
>>
>> On Thu, Jul 25, 2013 at 4:25 PM, Bernd May
>> <be...@net.t-labs.tu-berlin.de> wrote:
>>> Hello,
>>>
>>> I am experiencing re-negotiation issues namely connection closed when
>>> trying to use a subversion client >=1.8 against an svn server running
>>>
>>> Debian Wheezy
>>> apache 2.2.22
>>> libapache 1.8.1
>>> subversion 1.8.1
>>> openssl 1.0.1e
>>>
>>> with ssl client auth.
>>>
>>> I have now spent about 4 hours of searching through old ssl client auth
>>> errors in the openssl issues, subversion maillinglist and tried the
>>> following combinations of client libraries and binaries against the
>>> server mentioned above:
>>>
>>> * svn client 1.6.9, 1.6.16, 1.6.17, 1.7.11, 1.8.0, 1.8.1
>>> * Openssl 0.9.8g, 0.9.8.k, 0.9.8o, 1.0.0, 1.0.0e
>>>
>>> Whenver I use the newer subversion clients (v1.8 and 1.8.1) I receive
>>> the following error on the client side, regardless of the openssl version:
>>>
>>> svn: E120108: Unable to connect to a repository at URL
>>> 'https://example.com/svn/myrepo'
>>> svn: E120108: Error running context: The server unexpectedly closed the
>>> connection.
>>>
>>> Disabling the 'SSLVerifyClient Require' directive yields a successful
>>> listing of the svn content, so this really appears to be related to
>>> client auth.
>>> Using an svn client with libneon also yields a successful repository
>>> listing so this points quite directly at libserf.
>
> [..]
>
>>
>> Enabling logging in serf will probably give you more detailed info on
>> the failure on the client side.
>> Logging can be activated by setting these flags in serf_private.h and
>> then rebuilding serf:
>> #define SSL_VERBOSE 1
>> #define CONN_VERBOSE 1
>> #define SOCK_VERBOSE 1
>>
>>
>> If you're using serf 1.2.1 you'll get a lot of log lines (100k+) but
>> the info you'll need will be at the end. Alternatively you can upgrade
>> to serf 1.3.0 where ssl logging has been cleaned up. You can send the
>> log files to the list or to me privately, I'll have a look.
>
>
> the logs you sent (via private mail) did contain all the requested
> info, but it's not enough to analyse the root cause.
>
> However, I can reproduce this by accessing my test repo with svn trunk
> and serf trunk over https, with the "SSLVerifyClient Require" line
> added to the server config. My server setup does not require client
> certificates, so that is not a factor here.

This last sentence doesn't make a lot of sense, it doesn't work
because I hadn't configured my client certificate. I still can't get
it to work with a valid client certificate matching the server certs,
so need to look further.
L.

> Would you mind summarising this problem in a ticket in the serf issue
> tracker at https://code.google.com/p/serf/issues/list ? I'll see what
> I can find.
>
> Lieven
>
>>> --
>>> Technische Universität Berlin - FGINET
>>>
>>> Bernd May
>>>
>>> System Administration
>>> Sekr. TEL 16
>>> Ernst-Reuter-Platz 7
>>> 10587 BERLIN
>>> GERMANY
>>>
>>> Mobile: 0160/90257737
>>> E-Mail: bernd@inet.tu-berlin.de
>>> WWW:    inet.tu-berlin.de
>>>

Re: Problem with SSL Client auth and libserf

Posted by Lieven Govaerts <lg...@apache.org>.
Hi Bernd,

On Thu, Jul 25, 2013 at 5:56 PM, Lieven Govaerts <lg...@apache.org> wrote:
> Hi,
>
> On Thu, Jul 25, 2013 at 4:25 PM, Bernd May
> <be...@net.t-labs.tu-berlin.de> wrote:
>> Hello,
>>
>> I am experiencing re-negotiation issues namely connection closed when
>> trying to use a subversion client >=1.8 against an svn server running
>>
>> Debian Wheezy
>> apache 2.2.22
>> libapache 1.8.1
>> subversion 1.8.1
>> openssl 1.0.1e
>>
>> with ssl client auth.
>>
>> I have now spent about 4 hours of searching through old ssl client auth
>> errors in the openssl issues, subversion maillinglist and tried the
>> following combinations of client libraries and binaries against the
>> server mentioned above:
>>
>> * svn client 1.6.9, 1.6.16, 1.6.17, 1.7.11, 1.8.0, 1.8.1
>> * Openssl 0.9.8g, 0.9.8.k, 0.9.8o, 1.0.0, 1.0.0e
>>
>> Whenver I use the newer subversion clients (v1.8 and 1.8.1) I receive
>> the following error on the client side, regardless of the openssl version:
>>
>> svn: E120108: Unable to connect to a repository at URL
>> 'https://example.com/svn/myrepo'
>> svn: E120108: Error running context: The server unexpectedly closed the
>> connection.
>>
>> Disabling the 'SSLVerifyClient Require' directive yields a successful
>> listing of the svn content, so this really appears to be related to
>> client auth.
>> Using an svn client with libneon also yields a successful repository
>> listing so this points quite directly at libserf.

[..]

>
> Enabling logging in serf will probably give you more detailed info on
> the failure on the client side.
> Logging can be activated by setting these flags in serf_private.h and
> then rebuilding serf:
> #define SSL_VERBOSE 1
> #define CONN_VERBOSE 1
> #define SOCK_VERBOSE 1
>
>
> If you're using serf 1.2.1 you'll get a lot of log lines (100k+) but
> the info you'll need will be at the end. Alternatively you can upgrade
> to serf 1.3.0 where ssl logging has been cleaned up. You can send the
> log files to the list or to me privately, I'll have a look.


the logs you sent (via private mail) did contain all the requested
info, but it's not enough to analyse the root cause.

However, I can reproduce this by accessing my test repo with svn trunk
and serf trunk over https, with the "SSLVerifyClient Require" line
added to the server config. My server setup does not require client
certificates, so that is not a factor here.

Would you mind summarising this problem in a ticket in the serf issue
tracker at https://code.google.com/p/serf/issues/list ? I'll see what
I can find.

Lieven

>> --
>> Technische Universität Berlin - FGINET
>>
>> Bernd May
>>
>> System Administration
>> Sekr. TEL 16
>> Ernst-Reuter-Platz 7
>> 10587 BERLIN
>> GERMANY
>>
>> Mobile: 0160/90257737
>> E-Mail: bernd@inet.tu-berlin.de
>> WWW:    inet.tu-berlin.de
>>

Re: Problem with SSL Client auth and libserf

Posted by Lieven Govaerts <lg...@apache.org>.
Hi,

On Thu, Jul 25, 2013 at 4:25 PM, Bernd May
<be...@net.t-labs.tu-berlin.de> wrote:
> Hello,
>
> I am experiencing re-negotiation issues namely connection closed when
> trying to use a subversion client >=1.8 against an svn server running
>
> Debian Wheezy
> apache 2.2.22
> libapache 1.8.1
> subversion 1.8.1
> openssl 1.0.1e
>
> with ssl client auth.
>
> I have now spent about 4 hours of searching through old ssl client auth
> errors in the openssl issues, subversion maillinglist and tried the
> following combinations of client libraries and binaries against the
> server mentioned above:
>
> * svn client 1.6.9, 1.6.16, 1.6.17, 1.7.11, 1.8.0, 1.8.1
> * Openssl 0.9.8g, 0.9.8.k, 0.9.8o, 1.0.0, 1.0.0e
>
> Whenver I use the newer subversion clients (v1.8 and 1.8.1) I receive
> the following error on the client side, regardless of the openssl version:
>
> svn: E120108: Unable to connect to a repository at URL
> 'https://example.com/svn/myrepo'
> svn: E120108: Error running context: The server unexpectedly closed the
> connection.
>
> Disabling the 'SSLVerifyClient Require' directive yields a successful
> listing of the svn content, so this really appears to be related to
> client auth.
> Using an svn client with libneon also yields a successful repository
> listing so this points quite directly at libserf.
>
> On the server side the error messages in debug mode look like this:
>
> ... initial ssl connection setup completes ...
> [Thu Jul 25 16:20:12 2013] [info] Initial (No.1) HTTPS request received
> for child 77 (server inet-svn.net.t-labs.tu-berlin.de:443)
> [Thu Jul 25 16:20:12 2013] [debug] ssl_engine_kernel.c(510): [client
> <myip>] Changed client verification type will force renegotiation
> [Thu Jul 25 16:20:12 2013] [debug] ssl_engine_io.c(1554): [client
> <myip>] filling buffer, max size 131072 bytes
> [Thu Jul 25 16:20:12 2013] [debug] ssl_engine_io.c(1606): [client
> <myip>] total of 131 bytes in buffer, eos=1
> [Thu Jul 25 16:20:12 2013] [info] [client <myip>] Requesting connection
> re-negotiation
> [Thu Jul 25 16:20:12 2013] [debug] ssl_engine_io.c(1908): OpenSSL: I/O
> error, 5 bytes expected to read on BIO#7fa9ced2a820 [mem: 7fa9ced082c3]
> [Thu Jul 25 16:20:12 2013] [debug] ssl_engine_kernel.c(764): [client
> <myip>] Performing full renegotiation: complete handshake protocol
> (client does support secure renegotiation)
> [Thu Jul 25 16:20:12 2013] [debug] ssl_engine_kernel.c(1866): OpenSSL:
> Handshake: start
> [Thu Jul 25 16:20:12 2013] [debug] ssl_engine_kernel.c(1874): OpenSSL:
> Loop: SSL renegotiate ciphers
> [Thu Jul 25 16:20:12 2013] [debug] ssl_engine_kernel.c(1874): OpenSSL:
> Loop: SSLv3 write hello request A
> [Thu Jul 25 16:20:12 2013] [debug] ssl_engine_kernel.c(1874): OpenSSL:
> Loop: SSLv3 flush data
> [Thu Jul 25 16:20:12 2013] [debug] ssl_engine_kernel.c(1874): OpenSSL:
> Loop: SSLv3 write hello request C
> [Thu Jul 25 16:20:12 2013] [info] [client <myip>] Awaiting
> re-negotiation handshake
> [Thu Jul 25 16:20:12 2013] [debug] ssl_engine_kernel.c(1866): OpenSSL:
> Handshake: start
> [Thu Jul 25 16:20:12 2013] [debug] ssl_engine_kernel.c(1874): OpenSSL:
> Loop: before accept initialization
> [Thu Jul 25 16:20:22 2013] [info] [client <myip>] Request body read timeout
> [Thu Jul 25 16:20:22 2013] [debug] ssl_engine_io.c(1908): OpenSSL: I/O
> error, 5 bytes expected to read on BIO#7fa9ced2a820 [mem: 7fa9ced082c3]
> [Thu Jul 25 16:20:22 2013] [debug] ssl_engine_kernel.c(1903): OpenSSL:
> Exit: error in SSLv3 read client hello B
> [Thu Jul 25 16:20:22 2013] [error] [client <myip>] Re-negotiation
> handshake failed: Not accepted by client!?
> [Thu Jul 25 16:20:22 2013] [debug] mod_deflate.c(615): [client <myip>]
> Zlib: Compressed 0 to 2 : URL /svn/bernd
>

Renegotiation has been tested in serf, maybe it doesn''t work in all cases.

>
> So either the client sent garbage or not what the server expects or
> there is some kind of hiccup in the server libraries?
>
> If anyone could point me to a way to further debug this or a solution,
> I'd be very gracious

Enabling logging in serf will probably give you more detailed info on
the failure on the client side.
Logging can be activated by setting these flags in serf_private.h and
then rebuilding serf:
#define SSL_VERBOSE 1
#define CONN_VERBOSE 1
#define SOCK_VERBOSE 1


If you're using serf 1.2.1 you'll get a lot of log lines (100k+) but
the info you'll need will be at the end. Alternatively you can upgrade
to serf 1.3.0 where ssl logging has been cleaned up. You can send the
log files to the list or to me privately, I'll have a look.

Lieven

> --
> Technische Universität Berlin - FGINET
>
> Bernd May
>
> System Administration
> Sekr. TEL 16
> Ernst-Reuter-Platz 7
> 10587 BERLIN
> GERMANY
>
> Mobile: 0160/90257737
> E-Mail: bernd@inet.tu-berlin.de
> WWW:    inet.tu-berlin.de
>