[svn.haxx.se] · SVN Dev · SVN Users · SVN Org · TSVN Dev · TSVN Users · Subclipse Dev · Subclipse Users · this month's index

Strange failure of log_tests.py#7 -- missing commit in guarantee_repos_and_wc ?

From: Johan Corveleyn <jcorvel_at_gmail.com>
Date: Mon, 3 Jun 2013 01:29:46 +0200

Running the testsuite on 1.8.0-rc2, I ran into a test failure of
log_tests.py#7. I'm pretty sure it will prove to be non-reproducible
... it'll be gone when I rerun the test (and I didn't see this when I
tested trunk today). Still, I'm getting a bit nervous lately with
unexplained test failures ...

The test fails with:

[[[
W: =============================================================
Expected 'log_tests-7' and actual 'log_tests-7' in status tree are different!
=============================================================
EXPECTED NODE TO BE:
=============================================================
 * Node name: log_tests-7
    Path: svn-test-work\working_copies\log_tests-7
    Contents: None
    Properties: {}
    Attributes: {'status': ' ', 'wc_rev': '9'}
    Children: None (node is probably a file)
=============================================================
ACTUAL NODE FOUND:
=============================================================
 * Node name: log_tests-7
    Path: svn-test-work\working_copies\log_tests-7
    Contents: None
    Properties: {}
    Attributes: {'status': ' ', 'wc_rev': '8'}
    Children: None (node is probably a file)

W: ACTUAL STATUS TREE:
svntest.wc.State(wc_dir, {
  '' : Item(status=' ', wc_rev='8'),
  'A' : Item(status=' ', wc_rev='8'),
  'A/B' : Item(status=' ', wc_rev='8'),
  'A/B/F' : Item(status=' ', wc_rev='8'),
  'A/B/E' : Item(status=' ', wc_rev='8'),
  'A/B/E/beta' : Item(status=' ', wc_rev='8'),
  'A/B/lambda' : Item(status=' ', wc_rev='8'),
  'A/C' : Item(status=' ', wc_rev='8'),
  'A/C/epsilon' : Item(status=' ', wc_rev='8'),
  'A/D' : Item(status=' ', wc_rev='8'),
  'A/D/gamma' : Item(status=' ', wc_rev='8'),
  'A/D/G' : Item(status=' ', wc_rev='8'),
  'A/D/G/tau' : Item(status=' ', wc_rev='8'),
  'A/D/G/pi' : Item(status=' ', wc_rev='8'),
  'A/D/G/rho' : Item(status=' ', wc_rev='8'),
  'A/D/H' : Item(status=' ', wc_rev='8'),
  'A/D/H/psi' : Item(status=' ', wc_rev='8'),
  'A/D/H/omega' : Item(status=' ', wc_rev='8'),
  'A/D/H/chi' : Item(status=' ', wc_rev='8'),
  'A/mu' : Item(status=' ', wc_rev='8'),
  'iota' : Item(status=' ', wc_rev='8'),
})
W: CWD: R:\test\subversion\tests\cmdline
W: EXCEPTION: SVNTreeUnequal
Traceback (most recent call last):
  File "C:\research\svn\client_build\subversion-1.8.0-rc2\subversion\tests\cmdline\svntest\main.py",
line 1550, in run
    rc = self.pred.run(sandbox)
  File "C:\research\svn\client_build\subversion-1.8.0-rc2\subversion\tests\cmdline\svntest\testcase.py",
line 176, in run
    return self.func(sandbox)
  File "C:\research\svn\client_build\subversion-1.8.0-rc2\subversion\tests\cmdline\log_tests.py",
line 828, in log_wc_with_peg_revision
    guarantee_repos_and_wc(sbox)
  File "C:\research\svn\client_build\subversion-1.8.0-rc2\subversion\tests\cmdline\log_tests.py",
line 216, in guarantee_repos_and_wc
    svntest.actions.run_and_verify_status(wc_path, expected_status)
  File "C:\research\svn\client_build\subversion-1.8.0-rc2\subversion\tests\cmdline\svntest\actions.py",
line 1479, in run_and_verify_status
    status_tree.compare_and_display('status', actual_status)
  File "C:\research\svn\client_build\subversion-1.8.0-rc2\subversion\tests\cmdline\svntest\wc.py",
line 344, in compare_and_display
    raise svntest.tree.SVNTreeUnequal
SVNTreeUnequal
FAIL: log_tests.py 7: 'svn log wc_target_at_N'
]]]

Now, what's strange about this is that the failure happens in
guarantee_repos_and_wc (which seems to set up the test fixture for the
test), but this function already ran successfully for the preceding
tests (tests 1, 5 and 6 also call this).

When I look at the actual 'svn log' of this working copy (or the
repository), it gets even stranger: the commit for revision 2 is
missing:

[[[
R:\test\subversion\tests\cmdline\svn-test-work\working_copies\log_tests-7>svn
log
------------------------------------------------------------------------
r8 | jrandom | 2013-06-03 00:23:04 +0200 (Mon, 03 Jun 2013) | 1 line

Log message for revision 9
------------------------------------------------------------------------
r7 | jrandom | 2013-06-03 00:23:03 +0200 (Mon, 03 Jun 2013) | 3 lines

 Log message for revision 8
  but with multiple lines
  to test the code
------------------------------------------------------------------------
r6 | jrandom | 2013-06-03 00:23:03 +0200 (Mon, 03 Jun 2013) | 1 line

Log message for revision 7
------------------------------------------------------------------------
r5 | jrandom | 2013-06-03 00:23:02 +0200 (Mon, 03 Jun 2013) | 3 lines

 Log message for revision 6
  but with multiple lines
  to test the code
------------------------------------------------------------------------
r4 | jrandom | 2013-06-03 00:23:02 +0200 (Mon, 03 Jun 2013) | 1 line

Log message for revision 5
------------------------------------------------------------------------
r3 | jrandom | 2013-06-03 00:23:01 +0200 (Mon, 03 Jun 2013) | 3 lines

 Log message for revision 4
  but with multiple lines
  to test the code
------------------------------------------------------------------------
r2 | jrandom | 2013-06-03 00:23:00 +0200 (Mon, 03 Jun 2013) | 1 line

Log message for revision 3
------------------------------------------------------------------------
r1 | jrandom | 2013-06-03 00:22:36 +0200 (Mon, 03 Jun 2013) | 1 line

Log message for revision 1.
------------------------------------------------------------------------
]]]

Looking at guarantee_repos_and_wc, revision 2 should have been this:

  # Revision 2: edit iota
  msg=""" Log message for revision 2
  but with multiple lines
  to test the code"""
  svntest.main.file_write(msg_file, msg)
  svntest.main.file_append(iota_path, "2")
  svntest.main.run_svn(None,
                       'ci', '-F', msg_file)
  svntest.main.run_svn(None,
                       'up')

When I look at iota, that edit was done ("2" is there), so apparently
that commit wasn't performed.

Can anyone explain this? Any ideas?

Can it be a timestamp issue? sleep_for_timestamp ... which reminds me
... it's almost 1:30 am ... time to stamp some sleep.

But even if the timestamp after the edit is precisely the same as
after the checkout, I don't understand how that can lead to 'commit'
not seeing that the file is modified: the edit changed the filesize,
and I thought both timestamp and filesize were considered to check for
modified files ...

Confused,

--
Johan
Received on 2013-06-03 01:30:39 CEST

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

This site is subject to the Apache Privacy Policy and the Apache Public Forum Archive Policy.