You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@subversion.apache.org by kf...@collab.net on 2004/07/06 02:37:17 UTC

'svn log' failure

I run this command just about every day:

   $ svn log http://svn.collab.net/repos/svn/ trunk branches > log.out.tmp

Sometime today, it started failing (with very recent svn):

   $ svn log http://svn.collab.net/repos/svn/ trunk branches > log.out.tmp
   subversion/libsvn_ra_dav/util.c:670: (apr_err=175002)
   svn: REPORT request failed on '/repos/svn/!svn/bc/10146'
   subversion/libsvn_ra_dav/util.c:656: (apr_err=175002)
   svn: The REPORT request returned invalid XML in the response: \
        XML parse error at line 151235: Extra content at the end \
        of the document
   . (/repos/svn/!svn/bc/10146)
   $ 

The log it produces is *almost* complete: it contains r10146 (HEAD) to
r33.  The separator line after r33 is missing, as is r32 -> r1.  Most
disturbingly, it appears that some of the logs that *are* present are
corrupted slightly (more on that below).

I can reproduce this reliably as long as I don't disable the
'http-compression' option in my ~/.subversion/servers file.  Of
course, http-compression is not explicitly enabled by default, it's
just commented out, but that apparently means the default is "yes".

The ethereal trace of the erroring command is here:

   http://www.red-bean.com/kfogel/svn-log-ethereal-trace-with-gzip.out

It's using gzip encoding, naturally, so large swaths of it look like
mush.

Next, I tried disabling http-compression, here's exactly how:

   --- .subversion/servers~     2003-12-21 08:26:57.000000000 -0600
   +++ .subversion/servers      2004-07-05 15:42:36.000000000 -0500
   @@ -63,13 +63,13 @@
    ### each pointing to a PEM-encoded Certificate Authority (CA) 
    ### SSL certificate.  See details above for overriding security 
    ### due to SSL.
   -# [global]
   +[global]
    # http-proxy-exceptions = *.exception.com, www.internal-site.org
    # http-proxy-host = defaultproxy.whatever.com
    # http-proxy-port = 7000
    # http-proxy-username = defaultusername
    # http-proxy-password = defaultpassword
   -# http-compression = yes
   +http-compression = no
    # No http-timeout, so just use the builtin default.
    # No neon-debug-mask, so neon debugging is disabled.
    # ssl-authority-files = /path/to/CAcert.pem;/path/to/CAcert2.pem

When I ran the command again, it seemed to work:

   $ mv log.out.tmp log-with-gzip.out
   $ svn log http://svn.collab.net/repos/svn/ trunk branches > log-no-gzip.out
   $ 

No obvious errors here (but see below), and the log contains revisions
from r10146 (HEAD) to r1 this time.  The ethereal log for the no-gzip
run is at:

   http://www.red-bean.com/kfogel/svn-log-ethereal-trace-no-gzip.out

I diff'd the two logfiles, expecting exactly one hunk of all "+"
lines, since the no-gzip log contains r32 -> r1 and the with-gzip log
doesn't.  I got that hunk, but I also got some other stuff:

   $ diff -u log-with-gzip.out log-no-gzip.out
   --- log-with-gzip.out  2004-07-05 15:31:20.000000000 -0500
   +++ log-no-gzip.out         2004-07-05 15:44:08.000000000 -0500
   @@ -95604,7 +95604,7 @@
      (notify): Be more conservative about registering a change.
    
    ------------------------------------------------------------------------
   -r2283 | kfogel | 2002-06-19 12:34:53 -0500 (Wed, 19 Jun 2002) | 56 lines
   +r2283 | kfogel | 2002-06-19 12:34:53 -0500 (Wed, 19 Jun 2002) | 57 lines
    
    Change commit/copy/import over to the new notification system.  Now
    only "svn merge" notification remains to be done.  This resolves
   @@ -95652,6 +95652,7 @@
    * subversion/clients/cmdline/copy-cmd.c
      (svn_cl__copy): Handle notification the new way.
    
   +
    * subversion/clients/cmdline/commit-cmd.c
      (svn_cl__commit): Same.
    
   @@ -112345,7 +112346,7 @@
    callback baton, but just passed directly to the callback.
    
    ------------------------------------------------------------------------
   -r1391 | gstein | 2002-03-01 03:58:04 -0600 (Fri, 01 Mar 2002) | 37 lines
   +r1391 | gstein | 2002-03-01 03:58:04 -0600 (Fri, 01 Mar 2002) | 38 lines
    
    Fix up the log functionality to properly deal with provided paths.
    
   @@ -112371,6 +112372,7 @@
    
    * libsvn_repos/log.c (svn_repos_get_logs): Make use of newly modified
        svn_fs_revisions_changed. We pass it the paths passed to us (if
   +
        any). The returned array of revs is then used to trim down the
        logs to just those that the caller is interested in.
    
   @@ -122981,7 +122983,7 @@
      Svn::RubyEditor#deleteEntry and Svn::CommitEditor#deleteEntry.
    
    ------------------------------------------------------------------------
   -r661 | cmpilato | 2001-12-17 20:51:39 -0600 (Mon, 17 Dec 2001) | 212 lines
   +r661 | cmpilato | 2001-12-17 20:51:39 -0600 (Mon, 17 Dec 2001) | 211 lines
    
    Major migration of repository creation/opening code into libsvn_repos
    from libsvn_fs (Issue #428).  For consistency, the rest of the public
   @@ -123129,7 +123131,6 @@
      (svn_ra_local__split_URL): Use the repos API instead of the FS api
      for opening repositories.
    
   -
    * subversion/mod_dav_svn/dav_svn.h
    
      (dav_svn_repos): Add repos field.
   @@ -128659,7 +128660,7 @@
      for fetching properties.
    
    ------------------------------------------------------------------------
   -r280 | cmpilato | 2001-10-22 15:04:14 -0500 (Mon, 22 Oct 2001) | 113 lines
   +r280 | cmpilato | 2001-10-22 15:04:14 -0500 (Mon, 22 Oct 2001) | 114 lines
    
    Patches very similar to those submitted by Mark Benedetto King
    <bk...@answerfriend.com> (I started writing this code on the train
   @@ -128734,6 +128735,7 @@
    * doc/.svnignore
    * doc/programmer/design/.svnignore
    * doc/user/manual/.svnignore
   +
    * doc/user/svn_for_cvs_users/.svnignore
    * expat-lite/.svnignore
    * subversion/bindings/guile/.svnignore
   @@ -132097,3 +132099,234 @@
      
      Add revision number to the subject line (and make an error statement
      a little nicer).
   +------------------------------------------------------------------------
   +r32 | kevin | 2001-09-04 10:28:26 -0500 (Tue, 04 Sep 2001) | 34 lines
   +
   +Make build system work if Berkeley DB is not present.
   +
   [...]

(Everything from that point on is just r32->r1 "+" lines, so I've
omitted them.)

Notice how the difference seems to be the addition or deletion of
newlines, and what's really weird is that mistakes happen both with
and without gzip, even though only with-gzip produced a user-visible
error.

   - In r2283, there is an extra newline in the no-gzip log.  
     I have confirmed that the line break is really not there in
     the repository by logging into svn.collab.net and running
     'svnlook log -r2283' directly.  

     Twilight Zone Extra: This extra newline does *not* seem to be
     present in the no-gzip ethereal trace!

   - In r1937, the with-gzip log has the error -- the addition of a
     spurious line break, which is not present in the no-gzip log.
     (Again, confirmed by direct 'svnlook' on the server.)

   - In r1391, we're back to having a problem in the no-gzip log: that
     newline isn't supposed to be there.  (Same svnlook deal.)

   - In r661, the with-gzip log incorrectly adds an extra newline, but
     no-gzip gets it right.  (svnlook again)

   - In r280, the no-gzip log adds the incorrect newline, in the
     middle of a file list.  (you know what I'm going to say about
     svnlook, so I won't bother this time)

Weird, huh?  Those are all unusually long log messages, more than 30
lines each.  But there are many, many other logs over 30 lines that
did not seem to have any problems (or, uh, if they did, they got the
same exact problem with and without gzip, 'cause they didn't show up
in the diff.  I've also checked a few of them by hand, just for
sanity, and they seem okay.)

I didn't see any recent changes that looked suspicious, at least from
looking over my [only mildly broken] logs.

Can anyone else reproduce this?

-Karl

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@subversion.tigris.org
For additional commands, e-mail: dev-help@subversion.tigris.org

Re: 'svn log' failure

Posted by kf...@collab.net.
"Peter N. Lundblad" <pe...@famlundblad.se> writes:
> I think this is related to issue 1941 about failing big
> updates/checkouts/switches. Nice that it shows up in more places now...:-)

It could be, but I'm tempted to doubt it, since there are problems
both with and without gzip...  Don't know for sure, of course.


---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@subversion.tigris.org
For additional commands, e-mail: dev-help@subversion.tigris.org

Re: 'svn log' failure

Posted by Joe Orton <jo...@manyfish.co.uk>.
On Tue, Jul 06, 2004 at 12:01:24PM +0200, Peter N. Lundblad wrote:
> On Mon, 5 Jul 2004 kfogel@collab.net wrote:
> > I can reproduce this reliably as long as I don't disable the
> > 'http-compression' option in my ~/.subversion/servers file.  Of
> > course, http-compression is not explicitly enabled by default, it's
> > just commented out, but that apparently means the default is "yes".
> >
> I think this is related to issue 1941 about failing big
> updates/checkouts/switches. Nice that it shows up in more places now...:-)

Yes, good call.  That issue should be fixed by using neon 0.24.7, it's
very likely to be caused by the second of the three ne_compress.c bugs.

joe

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@subversion.tigris.org
For additional commands, e-mail: dev-help@subversion.tigris.org

Re: 'svn log' failure

Posted by "Peter N. Lundblad" <pe...@famlundblad.se>.
On Mon, 5 Jul 2004 kfogel@collab.net wrote:

> I run this command just about every day:
>
>    $ svn log http://svn.collab.net/repos/svn/ trunk branches > log.out.tmp
>
> Sometime today, it started failing (with very recent svn):
>
>    $ svn log http://svn.collab.net/repos/svn/ trunk branches > log.out.tmp
>    subversion/libsvn_ra_dav/util.c:670: (apr_err=175002)
>    svn: REPORT request failed on '/repos/svn/!svn/bc/10146'
>    subversion/libsvn_ra_dav/util.c:656: (apr_err=175002)
>    svn: The REPORT request returned invalid XML in the response: \
>         XML parse error at line 151235: Extra content at the end \
>         of the document
>    . (/repos/svn/!svn/bc/10146)
>    $
>
> The log it produces is *almost* complete: it contains r10146 (HEAD) to
> r33.  The separator line after r33 is missing, as is r32 -> r1.  Most
> disturbingly, it appears that some of the logs that *are* present are
> corrupted slightly (more on that below).
>
> I can reproduce this reliably as long as I don't disable the
> 'http-compression' option in my ~/.subversion/servers file.  Of
> course, http-compression is not explicitly enabled by default, it's
> just commented out, but that apparently means the default is "yes".
>
I think this is related to issue 1941 about failing big
updates/checkouts/switches. Nice that it shows up in more places now...:-)

I don't know if the latest neon release might fix it. At least, 1941 is
reproducable with old neons.

Regards,
//Peter

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@subversion.tigris.org
For additional commands, e-mail: dev-help@subversion.tigris.org

Re: 'svn log' failure

Posted by Ben Reser <be...@reser.org>.
On Tue, Jul 06, 2004 at 03:25:56PM +0100, Joe Orton wrote:
> The difference in "svn log" output seems to occur when a CRLF sequence
> happens to fall over a packet boundary, so when receiving two packets
> like:
> 
> packet 1: "foo\r"
> packet 2: "\nbar"
> 
> the log message gets printed as "foo\n\nbar"; otherwise it gets printed
> as the expected "foo\nbar".  I did some quick tests exercising ne_xml
> directly and can't trigger any XML parser bugs in whitespace handling
> like that, so maybe this an artifact of the EOL translation inside SVN.

Aren't our log messages supposed to be UTF8 with LF line endings?

-- 
Ben Reser <be...@reser.org>
http://ben.reser.org

"Conscience is the inner voice which warns us somebody may be looking."
- H.L. Mencken

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@subversion.tigris.org
For additional commands, e-mail: dev-help@subversion.tigris.org

Re: 'svn log' failure

Posted by Joe Orton <jo...@manyfish.co.uk>.
The difference in "svn log" output seems to occur when a CRLF sequence
happens to fall over a packet boundary, so when receiving two packets
like:

packet 1: "foo\r"
packet 2: "\nbar"

the log message gets printed as "foo\n\nbar"; otherwise it gets printed
as the expected "foo\nbar".  I did some quick tests exercising ne_xml
directly and can't trigger any XML parser bugs in whitespace handling
like that, so maybe this an artifact of the EOL translation inside SVN.

joe


---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@subversion.tigris.org
For additional commands, e-mail: dev-help@subversion.tigris.org

Re: 'svn log' failure

Posted by kf...@collab.net.
Joe Orton <jo...@manyfish.co.uk> writes:
> I can't reproduce the error message, but I do notice you're using
> libxml2.  If I build neon against libxml2 rather than expat I can
> reproduce the seemingly random insertion of newlines in the log messages
> (packet fragmentation affects the size of the blocks passed to XML
> parser so that could be the random factor).

Interesting.  I wonder if I've been getting these extra bits all
along.  I've probably been building with libxml2 on that machine (my
home machine, a Debian GNU/Linux box) for a long time.

> With expat the log messages are identical every time, so there is
> probably a bug either in libxml2 or in how neon drives it.
> 
> Can you upload the neon debug log somewhere (with e.g. neon-debug-mask =
> 134) from a run which produces the error?

Now I cannot reproduce the error anymore, with Neon 0.24.6.  And the
logs produced don't seem to have content problems, either -- at least,
not in the revisions that had problems before.  I'm building with
0.24.7 now, will report results either way.

By the way, in an earlier mail I wrote a Neon version number as
"0.26", when I meant "0.24.6", of course.

-Karl

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@subversion.tigris.org
For additional commands, e-mail: dev-help@subversion.tigris.org

Re: 'svn log' failure

Posted by Joe Orton <jo...@manyfish.co.uk>.
On Mon, Jul 05, 2004 at 09:37:17PM -0500, Karl Fogel wrote:
> I run this command just about every day:
> 
>    $ svn log http://svn.collab.net/repos/svn/ trunk branches > log.out.tmp
> 
> Sometime today, it started failing (with very recent svn):
> 
>    $ svn log http://svn.collab.net/repos/svn/ trunk branches > log.out.tmp
>    subversion/libsvn_ra_dav/util.c:670: (apr_err=175002)
>    svn: REPORT request failed on '/repos/svn/!svn/bc/10146'
>    subversion/libsvn_ra_dav/util.c:656: (apr_err=175002)
>    svn: The REPORT request returned invalid XML in the response: \
>         XML parse error at line 151235: Extra content at the end \
>         of the document
>    . (/repos/svn/!svn/bc/10146)
>    $ 

I can't reproduce the error message, but I do notice you're using
libxml2.  If I build neon against libxml2 rather than expat I can
reproduce the seemingly random insertion of newlines in the log messages
(packet fragmentation affects the size of the blocks passed to XML
parser so that could be the random factor).

With expat the log messages are identical every time, so there is
probably a bug either in libxml2 or in how neon drives it.

Can you upload the neon debug log somewhere (with e.g. neon-debug-mask =
134) from a run which produces the error?

joe

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@subversion.tigris.org
For additional commands, e-mail: dev-help@subversion.tigris.org

Re: 'svn log' failure

Posted by "Peter N. Lundblad" <pe...@famlundblad.se>.
On Tue, 6 Jul 2004, Joe Orton wrote:

> On Tue, Jul 06, 2004 at 07:26:51AM -0500, Karl Fogel wrote:
> > Joe Orton <jo...@manyfish.co.uk> writes:
> > > Did you upgrade to neon 0.24.7 before it started failing?
> >
> > Nope, it was Neon 0.24.6.
>
> OK, upgrade to 0.24.7 and it should be fixed then.
>
Just for the record, I can confirm that the upgrade to neon 0.24.7 fixes
the broken checkouts of issue 1941. I checked out the 1.0 branch with
compression enabled and it worked. Cool! And thanks for fixing neon!

Regards,
//Peter

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@subversion.tigris.org
For additional commands, e-mail: dev-help@subversion.tigris.org

Re: 'svn log' failure

Posted by Joe Orton <jo...@manyfish.co.uk>.
On Tue, Jul 06, 2004 at 07:26:51AM -0500, Karl Fogel wrote:
> Joe Orton <jo...@manyfish.co.uk> writes:
> > Did you upgrade to neon 0.24.7 before it started failing?
> 
> Nope, it was Neon 0.24.6.

OK, upgrade to 0.24.7 and it should be fixed then.

joe

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@subversion.tigris.org
For additional commands, e-mail: dev-help@subversion.tigris.org

Re: 'svn log' failure

Posted by kf...@collab.net.
Joe Orton <jo...@manyfish.co.uk> writes:
> Did you upgrade to neon 0.24.7 before it started failing?

Nope, it was Neon 0.24.6.

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@subversion.tigris.org
For additional commands, e-mail: dev-help@subversion.tigris.org

Re: 'svn log' failure

Posted by Joe Orton <jo...@manyfish.co.uk>.
On Mon, Jul 05, 2004 at 09:37:17PM -0500, Karl Fogel wrote:
> I run this command just about every day:
> 
>    $ svn log http://svn.collab.net/repos/svn/ trunk branches > log.out.tmp
> 
> Sometime today, it started failing (with very recent svn):

Did you upgrade to neon 0.24.7 before it started failing?

joe

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@subversion.tigris.org
For additional commands, e-mail: dev-help@subversion.tigris.org