On Sun, Aug 25, 2013 at 1:41 AM, Lieven Govaerts
<lieven.govaerts_at_gmail.com> wrote:
> 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.
FYI: another user has reported seeing the same error message (during a
reintegrate merge ... not sure if it's the same issue, but the error
is the same at least):
http://svn.haxx.se/users/archive-2013-09/0070.shtml
--
Johan
Received on 2013-09-09 14:46:55 CEST