You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@subversion.apache.org by Philip Martin <ph...@codematters.co.uk> on 2001/12/16 19:30:06 UTC

make check failing on log_tests.py

Hi

'make check' is failing while running log_tests.py, all the commits for
revisions 4 to 9 fail with 'Transaction is out of date'

Does anyone else see this?

-- 
Philip

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

Re: make check failing on log_tests.py

Posted by Philip Martin <ph...@codematters.co.uk>.
Kevin Pilch-Bisson <ke...@pilch-bisson.net> writes:

> I hate to bring it up again, but if you use shared libs, did you remove them 
> before rebuilding with the new svn and apr sources.

I don't have the shared library location in my /etc/ld.so.conf or
LD_LIBRARY_PATH, or any other environment variable, so the linker won't
look there. But I just tried removing the libraries and rebuilding and
it makes no difference.

-- 
Philip

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

Re: make check failing on log_tests.py

Posted by Kevin Pilch-Bisson <ke...@pilch-bisson.net>.
I hate to bring it up again, but if you use shared libs, did you remove them 
before rebuilding with the new svn and apr sources.

On Sun, Dec 16, 2001 at 11:39:00PM +0000, Philip Martin wrote:
> Philip Martin <ph...@codematters.co.uk> writes:
> 
> > Ben Collins-Sussman <su...@collab.net> writes:
> > 
> > > Philip Martin <ph...@codematters.co.uk> writes:
> > > 
> > > > Hi
> > > > 
> > > > 'make check' is failing while running log_tests.py, all the commits for
> > > > revisions 4 to 9 fail with 'Transaction is out of date'
> > > > 
> > > > Does anyone else see this?
> > > 
> > > This was happening to me this morning on my FreeBSD box, until I:
> > > 
> > >   * updated -both- svn and APR to head
> > > 
> > >   * re-ran autogen, configure, make clean && make.
> > > 
> > > 'make check' passes perfectly for me now.  Might have something to do
> > > with the new pool implementation in both apr and svn.
> > 
> > Doesn't work for me. I have even tried checking out a new subversion
> > and apr tree (within the last half-hour), and building from scratch,
> > but log_tests.py still fails.
> 
> It's failing in open_file() in commit_editor.c line 488. It's
> comparing base_revision against cr_rev:
> 
>   SVN_ERR (svn_fs_node_created_rev (&cr_rev, eb->txn_root,
>                                     path->data, new_fb->subpool));
>   
>   /* If the node our caller has has an older revision number than the
>      one in our transaction, return an out-of-dateness error. */
>   if (base_revision < cr_rev)
>     return out_of_date (path->data, eb->txn_name, subpool);
>   
> gdb shows that base_revision=3 and cr_rev=25. Now 3 is the head
> revision in the repository and the current revision in the working
> copy, and 25 is the txn as shown by svnadmin:
> 
> Txn 25:
> Created: Sun 16 Dec 2001 23:21:16.158898 (day 350, dst 0, gmt_off 000000)
> Author: pm
> Log (0 bytes):
> 
> ==========================================
>  A/ <1.3>
>   mu <19.1> [22]
>   B/ <2.2>
>    lambda <7.1> [26]
>    E/ <3.2>
>     alpha <5.2> [26]
>     beta <4.1> [24]
>    F/ <6.1>
>   C/ <8.2>
>    epsilon  D/ <9.2>
>    gamma <18.1> [25]
>    G/ <10.2>
>     rho <12.2> [24]
>     pi <11.2> [23]
>     tau <13.1> [23]
>    H/ <14.2>
>     chi <15.1> [23]
>     omega <17.2> [26]
>     psi <16.1> [23]
>  iota <20.2> [25]
> 
> The name parameter to open_file() is "iota" which also has 25 in the
> txn, but I don't really know what these numbers all mean.
> 
> Anyone know what's going on?
> 
> -- 
> Philip
> 
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe@subversion.tigris.org
> For additional commands, e-mail: dev-help@subversion.tigris.org
> 

-- 
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Kevin Pilch-Bisson                    http://www.pilch-bisson.net
     "Historically speaking, the presences of wheels in Unix
     has never precluded their reinvention." - Larry Wall
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

Re: make check failing on log_tests.py

Posted by cm...@collab.net.
Philip Martin <ph...@codematters.co.uk> writes:

> and the revison number comes out at 216. That might be memory
> corruption, but could it be that the correct revison is 2, and that
> there is a missing null terminator? The len field indcates 1 but
> atoi() won't use that.

Yeah, I noticed a little while ago that I had forgotten to pay
attention to the "len" skel_t field there.  Your findings confirm
mine.  Excellent, thanks.

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

Re: make check failing on log_tests.py

Posted by Philip Martin <ph...@codematters.co.uk>.
cmpilato@collab.net writes:

> This is the second hint I've gotten that something is wrong with the
> svn_fs_node_created_rev function.  The created revision as 25 looks
> very suspicious, given that you were looking at transaction 25.  I
> mean, I'm assuming that your tree is only a couple of revisions
> old...so there's no way you could have a node in it that was created
> in revision 25.  Bogosity.

In case this helps identify the problem. I have a working copy like:

$ svn st -u working_copies/log_tests/
A                0    working_copies/log_tests/A/C/epsilon
M                3    working_copies/log_tests/iota
Head revision:      3

When I run 'svn ci working_copies/log_tests' under gdb I see the
following

Breakpoint 3, svn_fs__dag_get_revision (rev=0xbffff5c0, node=0x807ba30, 
    trail=0x8079618) at subversion/libsvn_fs/dag.c:291
291       SVN_ERR (get_node_revision (&node_rev, node, trail));
(gdb) n
292       *rev = atoi ((SVN_FS__NR_HDR_REV (SVN_FS__NR_HEADER (node_rev)))->data);

(gdb) p node_rev[0].children[0].children[0].next[0]
$5 = {is_atom = 1, data = 0x807bb88 "216:03:2\001", len = 1, children = 0x0, 
  next = 0x0}

and the revison number comes out at 216. That might be memory
corruption, but could it be that the correct revison is 2, and that
there is a missing null terminator? The len field indcates 1 but
atoi() won't use that.

Using svnadmin I see the transaction

Txn 18:
Created: Mon 17 Dec 2001 16:05:20.808207 (day 351, dst 0, gmt_off 000000)
Author: pm
Log (0 bytes):

==========================================
 A/ <1.3>
  mu <19.1> [22]
  B/ <2.2>
   lambda <7.1> [26]
   E/ <3.2>
    alpha <5.2> [26]
    beta <4.1> [24]
   F/ <6.1>
  C/ <8.2>
   epsilon  D/ <9.2>
   gamma <18.1> [25]
   G/ <10.2>
    rho <12.2> [24]
    pi <11.2> [23]
    tau <13.1> [23]
   H/ <14.2>
    chi <15.1> [23]
    omega <17.2> [26]
    psi <16.1> [23]
 iota <20.2> [25]





-- 
Philip

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

Re: make check failing on log_tests.py

Posted by cm...@collab.net.
This is the second hint I've gotten that something is wrong with the
svn_fs_node_created_rev function.  The created revision as 25 looks
very suspicious, given that you were looking at transaction 25.  I
mean, I'm assuming that your tree is only a couple of revisions
old...so there's no way you could have a node in it that was created
in revision 25.  Bogosity.

I'll be writing a C-test for svn_fs_node_created_rev() today
... hopefully it will illuminate the problem.


Philip Martin <ph...@codematters.co.uk> writes:

> It's failing in open_file() in commit_editor.c line 488. It's
> comparing base_revision against cr_rev:
> 
>   SVN_ERR (svn_fs_node_created_rev (&cr_rev, eb->txn_root,
>                                     path->data, new_fb->subpool));
>   
>   /* If the node our caller has has an older revision number than the
>      one in our transaction, return an out-of-dateness error. */
>   if (base_revision < cr_rev)
>     return out_of_date (path->data, eb->txn_name, subpool);
>   
> gdb shows that base_revision=3 and cr_rev=25. Now 3 is the head
> revision in the repository and the current revision in the working
> copy, and 25 is the txn as shown by svnadmin:
> 
> Txn 25:
> Created: Sun 16 Dec 2001 23:21:16.158898 (day 350, dst 0, gmt_off 000000)
> Author: pm
> Log (0 bytes):
> 
> ==========================================
>  A/ <1.3>
>   mu <19.1> [22]
>   B/ <2.2>
>    lambda <7.1> [26]
>    E/ <3.2>
>     alpha <5.2> [26]
>     beta <4.1> [24]
>    F/ <6.1>
>   C/ <8.2>
>    epsilon  D/ <9.2>
>    gamma <18.1> [25]
>    G/ <10.2>
>     rho <12.2> [24]
>     pi <11.2> [23]
>     tau <13.1> [23]
>    H/ <14.2>
>     chi <15.1> [23]
>     omega <17.2> [26]
>     psi <16.1> [23]
>  iota <20.2> [25]
> 
> The name parameter to open_file() is "iota" which also has 25 in the
> txn, but I don't really know what these numbers all mean.
> 
> Anyone know what's going on?
> 
> -- 
> Philip
> 
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe@subversion.tigris.org
> For additional commands, e-mail: dev-help@subversion.tigris.org

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

Re: make check failing on log_tests.py

Posted by Philip Martin <ph...@codematters.co.uk>.
Philip Martin <ph...@codematters.co.uk> writes:

> Ben Collins-Sussman <su...@collab.net> writes:
> 
> > Philip Martin <ph...@codematters.co.uk> writes:
> > 
> > > Hi
> > > 
> > > 'make check' is failing while running log_tests.py, all the commits for
> > > revisions 4 to 9 fail with 'Transaction is out of date'
> > > 
> > > Does anyone else see this?
> > 
> > This was happening to me this morning on my FreeBSD box, until I:
> > 
> >   * updated -both- svn and APR to head
> > 
> >   * re-ran autogen, configure, make clean && make.
> > 
> > 'make check' passes perfectly for me now.  Might have something to do
> > with the new pool implementation in both apr and svn.
> 
> Doesn't work for me. I have even tried checking out a new subversion
> and apr tree (within the last half-hour), and building from scratch,
> but log_tests.py still fails.

It's failing in open_file() in commit_editor.c line 488. It's
comparing base_revision against cr_rev:

  SVN_ERR (svn_fs_node_created_rev (&cr_rev, eb->txn_root,
                                    path->data, new_fb->subpool));
  
  /* If the node our caller has has an older revision number than the
     one in our transaction, return an out-of-dateness error. */
  if (base_revision < cr_rev)
    return out_of_date (path->data, eb->txn_name, subpool);
  
gdb shows that base_revision=3 and cr_rev=25. Now 3 is the head
revision in the repository and the current revision in the working
copy, and 25 is the txn as shown by svnadmin:

Txn 25:
Created: Sun 16 Dec 2001 23:21:16.158898 (day 350, dst 0, gmt_off 000000)
Author: pm
Log (0 bytes):

==========================================
 A/ <1.3>
  mu <19.1> [22]
  B/ <2.2>
   lambda <7.1> [26]
   E/ <3.2>
    alpha <5.2> [26]
    beta <4.1> [24]
   F/ <6.1>
  C/ <8.2>
   epsilon  D/ <9.2>
   gamma <18.1> [25]
   G/ <10.2>
    rho <12.2> [24]
    pi <11.2> [23]
    tau <13.1> [23]
   H/ <14.2>
    chi <15.1> [23]
    omega <17.2> [26]
    psi <16.1> [23]
 iota <20.2> [25]

The name parameter to open_file() is "iota" which also has 25 in the
txn, but I don't really know what these numbers all mean.

Anyone know what's going on?

-- 
Philip

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

Re: make check failing on log_tests.py

Posted by Philip Martin <ph...@codematters.co.uk>.
Ben Collins-Sussman <su...@collab.net> writes:

> Philip Martin <ph...@codematters.co.uk> writes:
> 
> > Hi
> > 
> > 'make check' is failing while running log_tests.py, all the commits for
> > revisions 4 to 9 fail with 'Transaction is out of date'
> > 
> > Does anyone else see this?
> 
> This was happening to me this morning on my FreeBSD box, until I:
> 
>   * updated -both- svn and APR to head
> 
>   * re-ran autogen, configure, make clean && make.
> 
> 'make check' passes perfectly for me now.  Might have something to do
> with the new pool implementation in both apr and svn.

Doesn't work for me. I have even tried checking out a new subversion
and apr tree (within the last half-hour), and building from scratch,
but log_tests.py still fails.

I am using:
- neon/db in in the source tree,
- ./configure --prefix=/usr/local/subversion-fallback
- gcc 2.95.2, glibc 2.1.3, x86, Linux 2.4.16

-- 
Philip

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

Re: make check failing on log_tests.py

Posted by Ben Collins-Sussman <su...@collab.net>.
Philip Martin <ph...@codematters.co.uk> writes:

> Hi
> 
> 'make check' is failing while running log_tests.py, all the commits for
> revisions 4 to 9 fail with 'Transaction is out of date'
> 
> Does anyone else see this?

This was happening to me this morning on my FreeBSD box, until I:

  * updated -both- svn and APR to head

  * re-ran autogen, configure, make clean && make.

'make check' passes perfectly for me now.  Might have something to do
with the new pool implementation in both apr and svn.



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

Re: The smoking gun? was: make check failing on log_tests.py

Posted by Karl Fogel <kf...@newton.ch.collab.net>.
Philip Martin <ph...@codematters.co.uk> writes:
> > Err, the latest apr (with new pools) doesn't play nice with the test
> > code before rev 647 of subversion.  You should be seeing segfaults,
> > just like cmpilato had before he fixed subversions pools.
> > Or are you using an old apr against the earlier revisions?
> 
> No, I am using apr checked out on Dec 16 at about 22:48 GMT in all
> tests, and it doesn't segfault. When I run log_tests.py with rev 632
> it makes three commits successfully and fails with "out of date" on
> the fourth, just like rev 652. When run with rev 631 log_tests.py
> completes successfully.

Philip, could Mike's soon-to-be-committed fixes for
svn_fs_created_rev() be related to this?

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

Re: The smoking gun? was: make check failing on log_tests.py

Posted by Philip Martin <ph...@codematters.co.uk>.
"Sander Striker" <st...@apache.org> writes:

> Err, the latest apr (with new pools) doesn't play nice with the test
> code before rev 647 of subversion.  You should be seeing segfaults,
> just like cmpilato had before he fixed subversions pools.
> Or are you using an old apr against the earlier revisions?

No, I am using apr checked out on Dec 16 at about 22:48 GMT in all
tests, and it doesn't segfault. When I run log_tests.py with rev 632
it makes three commits successfully and fails with "out of date" on
the fourth, just like rev 652. When run with rev 631 log_tests.py
completes successfully.

-- 
Philip

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

RE: The smoking gun? was: make check failing on log_tests.py

Posted by Sander Striker <st...@apache.org>.
> From: Philip Martin [mailto:philip@codematters.co.uk]
> Sent: 17 December 2001 13:37

> "Sander Striker" <st...@apache.org> writes:
> 
> > Ofcourse we tried to reproduce this behaviour (wanting to rule out the
> > pools bug).  I failed, Justin succeeded.
> 
> Revision 631 passes the log tests, revision 632 fails. Now this may be
> coincidence, it is possible that the memory overwrite is just moving
> around and also exists in rev 631. However rev 632 says
> 
> > Log:
> > Part III of the New Commit System - the conversion of ra_local.  More
> > to follow.
> 
> so it certainly affects the code that is failing.

Err, the latest apr (with new pools) doesn't play nice with the test
code before rev 647 of subversion.  You should be seeing segfaults,
just like cmpilato had before he fixed subversions pools.
Or are you using an old apr against the earlier revisions?
 
> -- 
> Philip

Sander

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

The smoking gun? was: make check failing on log_tests.py

Posted by Philip Martin <ph...@codematters.co.uk>.
"Sander Striker" <st...@apache.org> writes:

> Ofcourse we tried to reproduce this behaviour (wanting to rule out the
> pools bug).  I failed, Justin succeeded.

Revision 631 passes the log tests, revision 632 fails. Now this may be
coincidence, it is possible that the memory overwrite is just moving
around and also exists in rev 631. However rev 632 says

> Log:
> Part III of the New Commit System - the conversion of ra_local.  More
> to follow.

so it certainly affects the code that is failing.

-- 
Philip

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

RE: make check failing on log_tests.py

Posted by Sander Striker <st...@apache.org>.
Hi,

> From: Philip Martin [mailto:philip@codematters.co.uk]
> Sent: 17 December 2001 03:20
> Philip Martin <ph...@codematters.co.uk> writes:
> 
> > Hi
> > 
> > 'make check' is failing while running log_tests.py, all the commits for
> > revisions 4 to 9 fail with 'Transaction is out of date'
> > 
> > Does anyone else see this?
> 
> After log_tests.py fails if I try
> 
> $ cd subversion/tests/clients/cmdline
> $ svn ci working_copies/log_tests/
> 
> I get the same "out of date" error. However if I use the
> electric-fence malloc/free debugger the commit succeeds:
> 
> $ LD_PRELOAD=libefence.so.0.0 svn ci working_copies/log_tests/
> 
> Now since the memory pools reuse malloc'd memory without free'ing it
> (which is perfectly acceptable) they defeat much of electric-fence's
> checking. However electric-fence will cause the memory to be allocated
> differently, in particular it will use more and spread it more
> widely. This behaviour is with pristine subversion code, no local
> changes.
> 
> I conclude that the problem is not my configuration or build, but that
> there is a bug in the pool code, or a pool memory overwrite somewhere
> in the subversion code, and my setup just happens to trigger it.
> 
> -- 
> Philip

Ofcourse we tried to reproduce this behaviour (wanting to rule out the
pools bug).  I failed, Justin succeeded.

Justin encountered an interesting comment during investigation:

#  log_tests.py:  testing "svn log"
#
#  ######################################################################
#  ###                                                                ###
#  ###  YO!  THIS FILE DOESN'T WORK YET.  DON'T TRY TO RUN IT.  THIS  ###
#  ###  ISN'T A PROBLEM BECAUSE WE HAVEN'T ADDED IT TO THE TESTS LIST ###
#  ###  IN BUILD.CONF YET.                                            ###
#  ###                                                                ###
#  ######################################################################

This probably is an out of date comment.  If not, the
test slipped in unintentionally.

Anyhow, I updated to the latest APR and Subversion, autogen, configure,
make, make check and everything SUCCEEDs.  The only significant difference
between Justins and my reproduction effort is that he has two copies of
subversion on his machine; the new source one and an old installed one
(different --prefix location).  My machine only has _one_ copy of subversion.

I'm working on the pools debug version, so that efence will actually be
usefull.  I'm a bit swamped till wednesday, but will try to get something
in soon.

Sander


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

Re: make check failing on log_tests.py

Posted by Philip Martin <ph...@codematters.co.uk>.
Philip Martin <ph...@codematters.co.uk> writes:

> Hi
> 
> 'make check' is failing while running log_tests.py, all the commits for
> revisions 4 to 9 fail with 'Transaction is out of date'
> 
> Does anyone else see this?

After log_tests.py fails if I try

$ cd subversion/tests/clients/cmdline
$ svn ci working_copies/log_tests/

I get the same "out of date" error. However if I use the
electric-fence malloc/free debugger the commit succeeds:

$ LD_PRELOAD=libefence.so.0.0 svn ci working_copies/log_tests/

Now since the memory pools reuse malloc'd memory without free'ing it
(which is perfectly acceptable) they defeat much of electric-fence's
checking. However electric-fence will cause the memory to be allocated
differently, in particular it will use more and spread it more
widely. This behaviour is with pristine subversion code, no local
changes.

I conclude that the problem is not my configuration or build, but that
there is a bug in the pool code, or a pool memory overwrite somewhere
in the subversion code, and my setup just happens to trigger it.

-- 
Philip

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