[svn.haxx.se] · SVN Dev · SVN Users · SVN Org · TSVN Dev · TSVN Users · Subclipse Dev · Subclipse Users · this month's index

Re: Error during 'svn export' over http with serf 1.3.1

From: Lieven Govaerts <lieven.govaerts_at_gmail.com>
Date: Sun, 25 Aug 2013 01:41:48 +0200

On Sun, Aug 25, 2013 at 1:36 AM, Johan Corveleyn <jcorvel_at_gmail.com> wrote:
> On Sun, Aug 25, 2013 at 1:25 AM, Lieven Govaerts
> <lieven.govaerts_at_gmail.com> wrote:
>> Summarising our investigation:
>> 1. The error that Johan receives is caused by the body of a 501 Method
>> Not Implemented response (see [1]) being directly appended to a
>> response to a GET request.
>> 2. The request that triggered this response is this: DAV:
>> http://subversion.tigris.org/xmlns/dav/svn/log-revprops
>> So apache thinks the request method is "DAV:" and returns the error.
>> It's not clear to me why apache doesn't send a status line but just
>> the html body of the 501 response, but that's not really the cause of
>> this particular issue.
>>
>> 3. The "DAV: http://subversion.tigris.org/xmlns/dav/svn/log-revprops"
>> request is actually a header of a request.
>> In the pcap file provided by Johan we see the following request:
>> [
>> GET /repos/asf/!svn/rvr/1516638/subversion/tags/1.8.3/subversion/tests/cmdline/upgrade_tests_data/upgrade_absent.tar.bz2
>> HTTP/1.1
>> Host: svn.apache.org
>> User-Agent: SVN/1.9.0-dev (x86-microsoft-windows) serf/1.3.1
>> DAV: http://subversion.tigris.org/xmlns/dav/svn/depth
>>
>> DAV: http://subversion.tigris.org/xmlns/dav/svn/log-revprops
>> ]
>>
>> There is a header missing between .../depth and .../log-revprops,
>> other similar requests have there the header: "DAV:
>> http://subversion.tigris.org/xmlns/dav/svn/mergeinfo". There is a
>> spurious CRLF where the ../mergeinfo header should be.
>>
>> Apache will assume based on the lack of Content-Length or chunked
>> encoding header that the body of this request is empty, so will
>> interpret the CRLF from the missing header as the end of the request.
>> The line "DAV: http://subversion.tigris.org/xmlns/dav/svn/log-revprops"
>> will then be considered the request line of the next request.
>>
>> 4. The question now is (and remains) why that header is missing and
>> replaced by CRLF.
>> Strangely enough, the serf 1.3.1 debug log shows that serf actually
>> wrote that header to the socket layer, yet in the pcap file it's
>> missing.
>> I don't exclude an error in serf's logging yet, but the code (in
>> socket_writev) looks alright to me.
>>
>> Not sure what that means, anti virus modifying packet data maybe?
>>
>> Lieven
>>
>> [1]
>> <!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">
>> <html><head>
>> <title>501 Method Not Implemented</title>
>> </head><body>
>> <h1>Method Not Implemented</h1>
>> <p>DAV: to /xmlns/dav/svn/log-revprops not supported.<br />
>> </p>
>> <hr>
>> <address>Apache/2.2.25 (Unix) DAV/2 mod_wsgi/3.1 Python/2.7.2
>> SVN/1.8.1 mod_ssl/2.2.25 OpenSSL/1.0.1e Server at
>> subversion.tigris.org Port 80</address>
>> </body></html>
>>
>> On Fri, Aug 23, 2013 at 11:51 PM, Johan Corveleyn <jcorvel_at_gmail.com> wrote:
>>> I get an error when exporting
>>> http://svn.apache.org/repos/asf/subversion/tags/1.8.3, with trunk@now
>>> + serf 1.3.1:
>>>
>>> [[[
>>> svn export -q http://svn.apache.org/repos/asf/subversion/tags/1.8.3
>>> ..\..\..\subversion\svn\export-cmd.c:127,
>>> ..\..\..\subversion\libsvn_client\export.c:1441,
>>> ..\..\..\subversion\libsvn_client\export.c:1334,
>>> ..\..\..\subversion\libsvn_ra_serf\update.c:2978,
>>> ..\..\..\subversion\libsvn_ra_serf\util.c:2186,
>>> ..\..\..\subversion\libsvn_ra_serf\util.c:2167,
>>> ..\..\..\subversion\libsvn_ra_serf\update.c:1147: (apr_err=120104)
>>> svn: E120104: ra_serf: An error occurred during decompression
>>> ]]]
>>>
>>> It doesn't happen always, but say 8 times out of 10 (in different
>>> places during the export).
>>>
>>> I haven't been able to reproduce it with serf 1.2.1, nor with serf
>>> 1.3.1 via https. Only with serf 1.3.1 exporting from http.
>
> And apparently I was mistaken here: it does occur also with serf 1.2.1
> (and 1.3.0). I just didn't try long enough with 1.2.1 before (and it
> does seem to happen more rarely, but that might be subjective /
> randomness).

Oh, I still am interested in the debug logs with serf 1.2.1. I see in
your 1.3.1 log that serf sends these smaller requests over two TCP
packets, with the split right at the missing header. This is not
normal, these requests are only a few hundred bytes large and serf has
all the data available to send in one go, as it does on my laptop.
L.

> --
> Johan
Received on 2013-08-25 01:42:38 CEST

This is an archived mail posted to the Subversion Dev mailing list.