[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: Johan Corveleyn <jcorvel_at_gmail.com>
Date: Mon, 21 Oct 2013 09:46:07 +0200

On Fri, Sep 13, 2013 at 2:46 PM, Ivan Zhakov <ivan_at_visualsvn.com> wrote:
> On Wed, Sep 11, 2013 at 11:54 PM, Bert Huijben <bert_at_qqmail.nl> wrote:
>>> -----Original Message-----
>>> From: Johan Corveleyn [mailto:jcorvel_at_gmail.com]
>>> Sent: dinsdag 10 september 2013 09:29
>>> To: Curt Sellmer
>>> Cc: Subversion Development
>>> Subject: Re: Error during 'svn export' over http with serf 1.3.1
>>>
>>> On Tue, Sep 10, 2013 at 5:36 AM, Curt Sellmer <sellmerfud_at_gmail.com>
>>> wrote:
>>> > On Sun, Aug 25, 2013 at 1:41 AM, Lieven Govaerts
>>> > <[hidden email]> wrote:
>>> >
>>> >> On Sun, Aug 25, 2013 at 1:36 AM, Johan Corveleyn <[hidden email]>
>>> wrote:
>>> >>> On Sun, Aug 25, 2013 at 1:25 AM, Lieven Govaerts
>>> >>> <[hidden email]> 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/cmdlin
>>> e/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 <[hidden email]>
>>> wrote:
>>> >>>>> I get an error when exporting
>>> >>>>> http://svn.apache.org/repos/asf/subversion/tags/1.8.3, with
>>> trunk_at_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.
>>> > ... [show rest of quote]
>>> >
>>> >> 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
>>> >
>>> > I came across this error message today as well. I recently upgraded
>>> > my svn server to 1.8.1. I have been dumping my repos and loading them
>>> > into new repos.
>>> > On one particular repo, I get this error when doing the following
>> command:
>>> >
>>> > svn log -l 4 http://server/repo/branches
>>> >
>>> > I get the error about 50% of the time. Interestingly when I run the
>>> > same command against http://server/repo/trunk I never get the error.
>>> >
>>> > I tried disabling compression with --config-option
>>> > servers:global:http-compression=off and when I do this about 50% of
>>> > the time I get only the first two log entries. But no error is
>>> > reported.
>>> >
>>> > So far I've only noticed the problem on one repo. I even did the
>>> > dump/load a second time an the results are the same.
>>>
>>> What's your client version? Can you show the output of svn --version
>>> of the client?
>>
>> Yesterday I accidentally found out that I was able to reproduce this problem
>> on my PC. I spend more than a bit of time on debugging and eventually found
>> a way to selectively enable and disable the problem:
>>
>> * I can reproduce the problem if I compile ZLIB using the x86 or x64
>> optimized assembly code.
>> * I can't reproduce it using the normal C code that is used when no ML is
>> found.
>>
>> Tomorrow I will spend some time in an attempt to reproduce this problem
>> using static data and just zlib, in an attempt to prove that this is the
>> reason we see this problem.
>> (Disabling the optimizations also changes the timings of course... so it
>> might just be a side effect.)
>>
>>
>> Ivan Zhakov notes that the assembly files are stored in the 'contrib'
>> directory of the ZLib project, so might not be formally part of zlib itself.
>> But from what I read on the zlib development list even their public
>> distributed zlib1.dll is compiled with these optimizations enabled.
>>
>> Note that the subversion build scripts since at least Subversion 1.2.0
>> enable this optimization when a compatible ML is found via gen-make.py.
>> (That is when build_zlib.bat was introduced. I haven't checked how things
>> were handled before)
> Bert,
>
> I've checked gen_win.py and gen_win_dependencies.py both on trunk and
> 1.8.x and they search for ML only if '--enable-ml' option is
> specified. Otherwise Subversion doesn't use assembler for zlib if it
> installed on the machine. Did I miss something?
>

I've lost track of the status of this issue. Does anyone know where it
stands currently?

Was an issue reported to zlib for the problem with the optimized assembly code?

Was there anything else that could have been done (or has already been
done) on the serf or svn side?

Is it now recommended to turn off --enable-ml when building for
Windows? Should this be enforced by the build scripts, as a workaround
until the optimized zlib is fixed?

-- 
Johan
Received on 2013-10-21 09:47:09 CEST

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