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?
--
Ivan Zhakov
CTO | VisualSVN | http://www.visualsvn.com
Received on 2013-09-13 18:05:32 CEST