> -----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)
In my builds this optimization has +- always been enabled for the last 5
years. (Except in a few cases when the x64 builds weren't possible with
these flags)
Bert
Received on 2013-09-11 21:55:08 CEST