authentication error after upgrading client to svn1.8.0-rc2 (accessing a svn1.7.8 server)

[Klaus Welch]

Hi svn team!

since many years i'm using subversion and it's a great piece of software. Thanks for all the work!

I've tried svn1.8-rc2 and it does not work as smooth as with all the previous upgrades.

Scenario is the following:
* server
* apache
* authentication: htdigest
* mod_dav_svn
* svn 1.7.8
* about 10 repositories (individually configured using SVNPath)
* authorization: path-based, one shared svn_authz-file (using [repository*:/path])
* client
* svn 1.7.9
* everything working fine (especially path-based authorisation)


After upgrading the *client* to svn1.8-rc2 a simple
svn info <url> gives the following error:

$>svn info http://domain:port/path
svn: E120190: Error running context: An error occurred during authentication


Playing around with svnauthz validate (server side) says that everything is fine.

I tried the following:
* use svn17x fetch a wc -> ok
* print svn info -> ok
* upgrade the wc using svn180-rc2 -> ok
* print svn info -> ok
* svn up -> the same error as with svn info <url>

There saw a new line in svn info output:
Relative URL: ^/path

It seems to me that the svn180-rc2 client sends an url the svn179 server does not understand and rejects.

Is this intended behavior?

If yes, how to share than an authz file between repositories?


I hope this feedback helps to make subversion a tiny little better.


With best regards,

Klaus

[C. Michael Pilato]

On 05/31/2013 09:09 AM, Klaus Welch wrote:
> After upgrading the *client* to svn1.8-rc2 a simple
> svn info <url> gives the following error:
>
> $>svn info http://domain:port/path
> svn: E120190: Error running context: An error occurred during authentication
>
>
> Playing around with svnauthz validate (server side) says that everything is
> fine.

Oops. authz (authorization) != authentication. Wouldn't expect any
problems with your access file rules based on the error message you got.

It would seem at first blush that the Serf HTTP library that the client uses
is having trouble communicating your user credentials to the server. You've
mentioned that your server uses 'htdigest' style authentication. Are you
able to obtain a wiretrace of a simple 'svn info' activity to share with us?
(You can, of course, anonymize any sensitive information and just explain
when you share it what you've masked.)

--
C. Michael Pilato <cmpi...@collab.net>
CollabNet <> www.collab.net <> Enterprise Cloud Development

[Klaus Welch]

On 05/31/13 15:40, C. Michael Pilato wrote:
> On 05/31/2013 09:09 AM, Klaus Welch wrote:
>> After upgrading the *client* to svn1.8-rc2 a simple
>> svn info <url> gives the following error:
>>
>> $>svn info http://domain:port/path
>> svn: E120190: Error running context: An error occurred during authentication
>>
>>
>> Playing around with svnauthz validate (server side) says that everything is
>> fine.
>
> Oops. authz (authorization) != authentication. Wouldn't expect any
> problems with your access file rules based on the error message you got.
>
> It would seem at first blush that the Serf HTTP library that the client uses
> is having trouble communicating your user credentials to the server. You've
> mentioned that your server uses 'htdigest' style authentication. Are you
> able to obtain a wiretrace of a simple 'svn info' activity to share with us?
> (You can, of course, anonymize any sensitive information and just explain
> when you share it what you've masked.)
>

Wow, fast response.

I'not sure what a wiretrace is. I've inlined related pieces from apache logs.

access.log:
::1 - - [31/May/2013:15:33:34 +0200] "OPTIONS * HTTP/1.0" 200 -
xx.yy.zz.uu - - [31/May/2013:15:46:00 +0200] "OPTIONS /svn/xxx HTTP/1.1" 401 401
xx.yy.zz.uu - aaa.bbb [31/May/2013:15:46:00 +0200] "OPTIONS /svn/xxx HTTP/1.1" 200 189
xx.yy.zz.uu - aaa.bbb [31/May/2013:15:46:00 +0200] "OPTIONS /svn/xxx HTTP/1.1" 200 189
xx.yy.zz.uu - aaa.bbb [31/May/2013:15:46:00 +0200] "PROPFIND /svn/xxx/!svn/rvr/9099 HTTP/1.1" 207 773


xx.yy.zz.uu : ip address
aaa.bbb : account name
xxx : repository path


error.log:
nothing related to the error


With best regards,

Klaus

[C. Michael Pilato]

On 05/31/2013 09:53 AM, Klaus Welch wrote:
> I'not sure what a wiretrace is. I've inlined related pieces from apache logs.
>
> access.log:
> ::1 - - [31/May/2013:15:33:34 +0200] "OPTIONS * HTTP/1.0" 200 -
> xx.yy.zz.uu - - [31/May/2013:15:46:00 +0200] "OPTIONS /svn/xxx HTTP/1.1" 401
> 401
> xx.yy.zz.uu - aaa.bbb [31/May/2013:15:46:00 +0200] "OPTIONS /svn/xxx
> HTTP/1.1" 200 189
> xx.yy.zz.uu - aaa.bbb [31/May/2013:15:46:00 +0200] "OPTIONS /svn/xxx
> HTTP/1.1" 200 189
> xx.yy.zz.uu - aaa.bbb [31/May/2013:15:46:00 +0200] "PROPFIND
> /svn/xxx/!svn/rvr/9099 HTTP/1.1" 207 773

But you got the error on the client? I see no errors in this log at all.

[Welch, Klaus]

________________________________________
From: C. Michael Pilato [cmpi...@collab.net]
Sent: Friday, May 31, 2013 4:30 PM
To: Welch, Klaus
Cc: us...@subversion.apache.org
Subject: Re: authentication error after upgrading client to svn1.8.0-rc2 (accessing a svn1.7.8 server)

On 05/31/2013 09:53 AM, Klaus Welch wrote:
> I'not sure what a wiretrace is. I've inlined related pieces from apache logs.
>
> access.log:
> ::1 - - [31/May/2013:15:33:34 +0200] "OPTIONS * HTTP/1.0" 200 -
> xx.yy.zz.uu - - [31/May/2013:15:46:00 +0200] "OPTIONS /svn/xxx HTTP/1.1" 401
> 401
> xx.yy.zz.uu - aaa.bbb [31/May/2013:15:46:00 +0200] "OPTIONS /svn/xxx
> HTTP/1.1" 200 189
> xx.yy.zz.uu - aaa.bbb [31/May/2013:15:46:00 +0200] "OPTIONS /svn/xxx
> HTTP/1.1" 200 189
> xx.yy.zz.uu - aaa.bbb [31/May/2013:15:46:00 +0200] "PROPFIND
> /svn/xxx/!svn/rvr/9099 HTTP/1.1" 207 773

But you got the error on the client? I see no errors in this log at all.

That's why I'm not sure where to start looking into.

Error message complained about authentication but the correct account was logged in the access.log and
nothing in error.log (where usually such stuff is logged).

Setup is:
* one shell
* both clients (1.7.9 and 1.8.0-rc2) installed in parallel
* doing the same operation with both
* 1.7 binary ok, 1.8 binary fails

On monday I'll check the serf version, remove client side credential, carefully re-check all the build logs.

Hopefully something indicates where to look further.

Many thanks for your support.

With best regards,

Klaus

[Daniel Shahaf]

C. Michael Pilato wrote on Fri, May 31, 2013 at 10:30:58 -0400:
> On 05/31/2013 09:53 AM, Klaus Welch wrote:
> > I'not sure what a wiretrace is. I've inlined related pieces from apache logs.
> >
> > access.log:
> > ::1 - - [31/May/2013:15:33:34 +0200] "OPTIONS * HTTP/1.0" 200 -
> > xx.yy.zz.uu - - [31/May/2013:15:46:00 +0200] "OPTIONS /svn/xxx HTTP/1.1" 401
> > 401
> > xx.yy.zz.uu - aaa.bbb [31/May/2013:15:46:00 +0200] "OPTIONS /svn/xxx
> > HTTP/1.1" 200 189
> > xx.yy.zz.uu - aaa.bbb [31/May/2013:15:46:00 +0200] "OPTIONS /svn/xxx
> > HTTP/1.1" 200 189
> > xx.yy.zz.uu - aaa.bbb [31/May/2013:15:46:00 +0200] "PROPFIND
> > /svn/xxx/!svn/rvr/9099 HTTP/1.1" 207 773
>
> But you got the error on the client? I see no errors in this log at all.

The 207 Multi-Status response might have contained
a <status>401</status> in the response body.

[Daniel Shahaf]

Welch, Klaus wrote on Fri, May 31, 2013 at 14:45:40 +0000:
>
> ________________________________________
> From: C. Michael Pilato [cmpi...@collab.net]
> Sent: Friday, May 31, 2013 4:30 PM
> To: Welch, Klaus
> Cc: us...@subversion.apache.org
> Subject: Re: authentication error after upgrading client to svn1.8.0-rc2 (accessing a svn1.7.8 server)
>
> On 05/31/2013 09:53 AM, Klaus Welch wrote:
> > I'not sure what a wiretrace is. I've inlined related pieces from apache logs.
> >
> > access.log:
> > ::1 - - [31/May/2013:15:33:34 +0200] "OPTIONS * HTTP/1.0" 200 -
> > xx.yy.zz.uu - - [31/May/2013:15:46:00 +0200] "OPTIONS /svn/xxx HTTP/1.1" 401
> > 401
> > xx.yy.zz.uu - aaa.bbb [31/May/2013:15:46:00 +0200] "OPTIONS /svn/xxx
> > HTTP/1.1" 200 189
> > xx.yy.zz.uu - aaa.bbb [31/May/2013:15:46:00 +0200] "OPTIONS /svn/xxx
> > HTTP/1.1" 200 189
> > xx.yy.zz.uu - aaa.bbb [31/May/2013:15:46:00 +0200] "PROPFIND
> > /svn/xxx/!svn/rvr/9099 HTTP/1.1" 207 773
>
> But you got the error on the client? I see no errors in this log at all.
>
> That's why I'm not sure where to start looking into.
>
> Error message complained about authentication but the correct account was logged in the access.log and
> nothing in error.log (where usually such stuff is logged).

Can you share the relevant bits of your httpd.conf? Particularly the
<Location /svn> (or /svn/xxx) block and the authn/authz directives that
govern it.

[C. Michael Pilato]

On 05/31/2013 10:45 AM, Welch, Klaus wrote:
> On monday I'll check the serf version, remove client side credential, carefully re-check all the build logs.
>
> Hopefully something indicates where to look further.

As it turns out, I have been able to reproduce this problem on my laptop
with a simple Digest auth configuration. I'll debug after some lunch.

[Philip Martin]

If your 1.7 client is using neon (the default) but also has serf support
then using --config-option servers:global:http-library=serf will cause
the 1.7 client to use serf which may help narrow down the problem.

It doesn't help that this is another instance of a serf error number
leaking into a Subversion error:
http://subversion.tigris.org/issues/show_bug.cgi?id=4368

Ways to get a network trace:
http://subversion.apache.org/docs/community-guide/debugging.html#net-trace

--
Certified & Supported Apache Subversion Downloads:
http://www.wandisco.com/subversion/download

[C. Michael Pilato]

On 05/31/2013 12:06 PM, C. Michael Pilato wrote:
> On 05/31/2013 10:45 AM, Welch, Klaus wrote:
>> On monday I'll check the serf version, remove client side credential, carefully re-check all the build logs.
>>
>> Hopefully something indicates where to look further.
>
> As it turns out, I have been able to reproduce this problem on my laptop
> with a simple Digest auth configuration. I'll debug after some lunch.

The failure occurs when Serf hits this condition (in its
auth/auth_digest.c:serf__validate_response_digest_auth() function):

/* Incorrect response-digest in Authentication-Info header. */
if (strcmp(rspauth, resp_hdr_hex) != 0) {
return SERF_ERROR_AUTHN_FAILED;
}

Still digging.

[C. Michael Pilato]

On 05/31/2013 01:28 PM, C. Michael Pilato wrote:
> On 05/31/2013 12:06 PM, C. Michael Pilato wrote:
>> On 05/31/2013 10:45 AM, Welch, Klaus wrote:
>>> On monday I'll check the serf version, remove client side credential, carefully re-check all the build logs.
>>>
>>> Hopefully something indicates where to look further.
>>
>> As it turns out, I have been able to reproduce this problem on my laptop
>> with a simple Digest auth configuration. I'll debug after some lunch.
>
> The failure occurs when Serf hits this condition (in its
> auth/auth_digest.c:serf__validate_response_digest_auth() function):
>
> /* Incorrect response-digest in Authentication-Info header. */
> if (strcmp(rspauth, resp_hdr_hex) != 0) {
> return SERF_ERROR_AUTHN_FAILED;
> }
>
> Still digging.

After some more debugging, I find that the problem is the URI comparisons in
that function. On one side, the HA2 digest contributor has been calculated
using the actual URI of the PROPFIND request (.../!svn/rvr/...). On the
side of the comparison, a bit of path information is pulled from the Serf
connection's host_info structure. All works well for the OPTIONS requests,
which both hit the public URI of the repository. But that PROPFIND comes
along and the comparisons fail.

I'll need to take this up with the Serf developers.

[C. Michael Pilato]

Filed an issue for this in the Serf tracker:

https://code.google.com/p/serf/issues/detail?id=102

[C. Michael Pilato]

On 05/31/2013 02:26 PM, C. Michael Pilato wrote:
> Filed an issue for this in the Serf tracker:
>
> https://code.google.com/p/serf/issues/detail?id=102

Just to follow up on this: the Serf devs have fixed the problem, and the
fix will be included in Serf 1.2.1 (which should be released in the next
couple of days).

Thanks so much for your bug report!!

[Klaus Welch]

On 06/03/13 20:31, C. Michael Pilato wrote:
> On 05/31/2013 02:26 PM, C. Michael Pilato wrote:
>> Filed an issue for this in the Serf tracker:
>>
>> https://code.google.com/p/serf/issues/detail?id=102
>
> Just to follow up on this: the Serf devs have fixed the problem, and the
> fix will be included in Serf 1.2.1 (which should be released in the next
> couple of days).
>
> Thanks so much for your bug report!!
>

After rebuilding with serf 1.2.1 i can confirm that my issue is solved. :-)

Many thanks to the svn and serf team for this impressively quick solution.


Klaus