You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@subversion.apache.org by Johan Corveleyn <jc...@gmail.com> on 2013/06/03 01:29:46 UTC

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

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@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

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

Posted by Markus Schaber <m....@codesys.com>.
Hi, Johan,

Von: Johan Corveleyn [mailto:jcorvel@gmail.com]
> [Problems with the test suite when the disk gets full]
>
> Or do we have to worry about the failure modes of svn (or of the
> testsuite) when the disk is full?

I think we don't need to worry about the failure modes of the testsuite in that case.

However, at least SVN itself should try to ensure that the repository (and maybe also working copies) cannot be damaged by disk full scenarios.



Best regards

Markus Schaber

CODESYS(r) a trademark of 3S-Smart Software Solutions GmbH

Inspiring Automation Solutions

3S-Smart Software Solutions GmbH
Dipl.-Inf. Markus Schaber | Product Development Core Technology
Memminger Str. 151 | 87439 Kempten | Germany
Tel. +49-831-54031-979 | Fax +49-831-54031-50

E-Mail: m.schaber@codesys.com | Web: http://www.codesys.com | CODESYS store: http://store.codesys.com
CODESYS forum: http://forum.codesys.com

Managing Directors: Dipl.Inf. Dieter Hess, Dipl.Inf. Manfred Werner | Trade register: Kempten HRB 6186 | Tax ID No.: DE 167014915


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

Posted by Johan Corveleyn <jc...@gmail.com>.
On Thu, Jun 6, 2013 at 10:50 AM, Ben Reser <be...@reser.org> wrote:
> On Thu, Jun 6, 2013 at 9:27 AM, Johan Corveleyn <jc...@gmail.com> wrote:

>> Or do we have to worry about the failure modes of svn (or of the
>> testsuite) when the disk is full?
>
> I don't think we have any problematic failure modes when the disk is
> full.  However, I can't imagine there's any sane way that the test
> suite can know that the disk filled since the disk can fill in so many
> places when running the test (between various calls inside the tests
> or even between tests).
>
> So I'm not sure there's any great way to resolve strange looking test
> failures from disk space issues.

Okay, no problem. Case closed then. At least this case is now
documented in the archives :-).

--
Johan

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

Posted by Ben Reser <be...@reser.org>.
On Thu, Jun 6, 2013 at 9:27 AM, Johan Corveleyn <jc...@gmail.com> wrote:
> With my old WinXP laptop I can't really spare 1 GB of ram :-) (I only
> have 3.3 available).

Yeah I'm spoiled, I do my testing on VMs hosted on a machine with
32GBs of RAM. :D

> But, increasing it to 256MB (and using cleanup) did help: started the
> testsuite yesterday evening, and haven't seen any failures (this
> morning, the ra_serf tests were still running, but ra_local and ra_svn
> were finished ... no failures).
>
> Problem solved it seems.
>
> Or do we have to worry about the failure modes of svn (or of the
> testsuite) when the disk is full?

I don't think we have any problematic failure modes when the disk is
full.  However, I can't imagine there's any sane way that the test
suite can know that the disk filled since the disk can fill in so many
places when running the test (between various calls inside the tests
or even between tests).

So I'm not sure there's any great way to resolve strange looking test
failures from disk space issues.

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

Posted by Johan Corveleyn <jc...@gmail.com>.
On Thu, Jun 6, 2013 at 9:08 AM, Ben Reser <be...@reser.org> wrote:
> On Thu, Jun 6, 2013 at 2:01 AM, Johan Corveleyn <jc...@gmail.com> wrote:
>> However, I'm wondering now if perhaps there's an issue with the size
>> of the ramdisk (and increased need for disk space during the tests).
>> My ramdisk is only 128 MB large, which has sufficed until now. Perhaps
>> I now need to enlarge it. I'll try increasing it to 256 MB, and
>> rerunning the testsuite a couple of times.
>>
>> @Bert: you made some commits recently related to disk usage of the
>> test-suite. Can you summarize a bit what kinds of failures you got,
>> and what changes you made for this? And are these in 1.8.0-rc2, or
>> will they be in rc3?
>>
>> In one of your commit messages you specifically said that it should be
>> possible to run the test-suite in parallel on a 256 MB ramdisk. I
>> don't run the tests in parallel, but perhaps 128 MB has become too
>> small, even for non-parallellized test runs.
>>
>> All that said: if these spurious failures turn out to be
>> diskspace-related, I'm still a bit worried: how come I didn't see a
>> big glaring error message in the test log? But first, let's try to
>> check this hypothesis by rerunning the tests on a larger ramdisk.
>
> I usually use a 1GB ramdisk to test but don't use CLEANUP=1 since I
> have the memory and the cleanup just slows things down.  It usually
> fills up around 760MB.

With my old WinXP laptop I can't really spare 1 GB of ram :-) (I only
have 3.3 available).

But, increasing it to 256MB (and using cleanup) did help: started the
testsuite yesterday evening, and haven't seen any failures (this
morning, the ra_serf tests were still running, but ra_local and ra_svn
were finished ... no failures).

Problem solved it seems.

Or do we have to worry about the failure modes of svn (or of the
testsuite) when the disk is full?

--
Johan

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

Posted by Ben Reser <be...@reser.org>.
On Thu, Jun 6, 2013 at 2:01 AM, Johan Corveleyn <jc...@gmail.com> wrote:
> However, I'm wondering now if perhaps there's an issue with the size
> of the ramdisk (and increased need for disk space during the tests).
> My ramdisk is only 128 MB large, which has sufficed until now. Perhaps
> I now need to enlarge it. I'll try increasing it to 256 MB, and
> rerunning the testsuite a couple of times.
>
> @Bert: you made some commits recently related to disk usage of the
> test-suite. Can you summarize a bit what kinds of failures you got,
> and what changes you made for this? And are these in 1.8.0-rc2, or
> will they be in rc3?
>
> In one of your commit messages you specifically said that it should be
> possible to run the test-suite in parallel on a 256 MB ramdisk. I
> don't run the tests in parallel, but perhaps 128 MB has become too
> small, even for non-parallellized test runs.
>
> All that said: if these spurious failures turn out to be
> diskspace-related, I'm still a bit worried: how come I didn't see a
> big glaring error message in the test log? But first, let's try to
> check this hypothesis by rerunning the tests on a larger ramdisk.

I usually use a 1GB ramdisk to test but don't use CLEANUP=1 since I
have the memory and the cleanup just slows things down.  It usually
fills up around 760MB.

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

Posted by Tobias Bading <tb...@web.de>.
On 06.06.2013 13:04, Ben Reser wrote:
> [...]
>> I think coming up with a safer implementation of
>> svn_io_sleep_for_timestamps would be a better long-term solution. The chance
>> of encountering such a failure increases as CPUs become faster and faster,
>> but the accuracy of file modification timestamps stays the same. Even on
>> 'good' Linux kernels, this accuracy seems to be only 0.01 or 0.004 seconds.
>> I almost feel the itch to rebuild Subversion 1.8 RC2 with SQLITE_NO_SYNC
>> #define'd to see whether more tests fail due to faster operations without
>> SQLite's fsync calls.
> Clearly svn_io_sleep_for_timestamps() needs some more thought.  There
> was some discussions between Julian, Philip and myself about this a
> while back.  svn_io_sleep_for_timestamps() can actually make things
> worse if we're using commit times as the timestamps.
>
> As far as how good the timestamp accuracy is, I was under the
> impression that ext4 had nanosecond timestamp resolution.

Yes, ext4 has nanosecond resolution, but the Linux kernels I've tested 
so far, which includes the newest mainline 3.9.4 kernel, aren't able to 
produce more than 250 unique file modification timestamps per second. 
Some generate only 100 per second, and the really 'bad ones' (at least 
Ubuntu 2.6.32-4[567]) only *two*. There obviously is some sort of 
timestamp caching involved, for performance reasons would be my guess. 
If https://bugs.launchpad.net/ubuntu/+source/linux/+bug/1185730 doesn't 
lead to an explanation, maybe reporting this directly to the mainline 
Linux gurus might help, because the bug is not caused by Ubuntu kernel 
modifications.

Tobias


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

Posted by Ben Reser <be...@reser.org>.
On Thu, Jun 6, 2013 at 10:47 AM, Tobias Bading <tb...@web.de> wrote:
> One could try to insert lines like this (already present in diff_tests.py in
> one test)
>
>   # sleep to guarantee timestamp change
>   time.sleep(1.1)
>
> at the proper places. But what are the proper places? Potentially every
> merge or commit may 'fail' if the content of a file is changed, but
> timestamp and size aren't.

And to what end?  Doing that just would hide timestamp sleep issues.
In the interest of test speed we turn sleep for timestamps off when
running tests and avoid changing files in ways that don't change the
file size already.

> I think coming up with a safer implementation of
> svn_io_sleep_for_timestamps would be a better long-term solution. The chance
> of encountering such a failure increases as CPUs become faster and faster,
> but the accuracy of file modification timestamps stays the same. Even on
> 'good' Linux kernels, this accuracy seems to be only 0.01 or 0.004 seconds.
> I almost feel the itch to rebuild Subversion 1.8 RC2 with SQLITE_NO_SYNC
> #define'd to see whether more tests fail due to faster operations without
> SQLite's fsync calls.

Clearly svn_io_sleep_for_timestamps() needs some more thought.  There
was some discussions between Julian, Philip and myself about this a
while back.  svn_io_sleep_for_timestamps() can actually make things
worse if we're using commit times as the timestamps.

As far as how good the timestamp accuracy is, I was under the
impression that ext4 had nanosecond timestamp resolution.

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

Posted by Tobias Bading <tb...@web.de>.
On 06.06.2013 10:38, Bert Huijben wrote:
> [...]
>
>> Grrrr. The author of diff-test 60 has a nice sense of humor it seems
>> ;-). The merge in that test changes a lot of lines, but the size of file
>> 3449_spurious stays the same. I didn't realize this until now. BTW, with
>> the bad kernel, I've once seen special-test 21 (update_symlink) fail as
>> well. Same reason I guess, a symbolic link is supposed to be changed
>> from "link A/mu" to "link iota", so the file's size doesn't change and
>> commit does nothing at all.
> Can you provide a patch to these two tests that still make the tests check
> their original target, but not trigger the timestamp problem?
>
> I can probably fix this diff test, but fully testing the symlink scenarios
> is not possible when running on Windows.

One could try to insert lines like this (already present in 
diff_tests.py in one test)

   # sleep to guarantee timestamp change
   time.sleep(1.1)

at the proper places. But what are the proper places? Potentially every 
merge or commit may 'fail' if the content of a file is changed, but 
timestamp and size aren't. I think coming up with a safer implementation 
of svn_io_sleep_for_timestamps would be a better long-term solution. The 
chance of encountering such a failure increases as CPUs become faster 
and faster, but the accuracy of file modification timestamps stays the 
same. Even on 'good' Linux kernels, this accuracy seems to be only 0.01 
or 0.004 seconds. I almost feel the itch to rebuild Subversion 1.8 RC2 
with SQLITE_NO_SYNC #define'd to see whether more tests fail due to 
faster operations without SQLite's fsync calls.

Tobias


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

Posted by Bert Huijben <be...@qqmail.nl>.

> -----Original Message-----
> From: Tobias Bading [mailto:tbading@web.de]
> Sent: donderdag 6 juni 2013 09:16
> To: Subversion Development
> Cc: Johan Corveleyn; Philip Martin; Bert Huijben
> Subject: Re: Strange failure of log_tests.py#7 -- missing commit in
> guarantee_repos_and_wc ?
> 
> Hi *!
> 
> On 06.06.2013 03:01, Johan Corveleyn wrote:
> > [...]
> >>> 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 ...
> >> You are correct: both the timestamp and the filesize are checked (the
> >> code is in svn_wc__internal_file_modified_p).  The timestamp "problem"
> >> only causes modifications to be missed if those modifications don't
> >> change the filesize.  In this case the filesize should have changed.
> 
> Grrrr. The author of diff-test 60 has a nice sense of humor it seems
> ;-). The merge in that test changes a lot of lines, but the size of file
> 3449_spurious stays the same. I didn't realize this until now. BTW, with
> the bad kernel, I've once seen special-test 21 (update_symlink) fail as
> well. Same reason I guess, a symbolic link is supposed to be changed
> from "link A/mu" to "link iota", so the file's size doesn't change and
> commit does nothing at all.

Can you provide a patch to these two tests that still make the tests check
their original target, but not trigger the timestamp problem?

I can probably fix this diff test, but fully testing the symlink scenarios
is not possible when running on Windows.

	Bert



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

Posted by Tobias Bading <tb...@web.de>.
Hi *!

On 06.06.2013 03:01, Johan Corveleyn wrote:
> [...]
>>> 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 ...
>> You are correct: both the timestamp and the filesize are checked (the
>> code is in svn_wc__internal_file_modified_p).  The timestamp "problem"
>> only causes modifications to be missed if those modifications don't
>> change the filesize.  In this case the filesize should have changed.

Grrrr. The author of diff-test 60 has a nice sense of humor it seems 
;-). The merge in that test changes a lot of lines, but the size of file 
3449_spurious stays the same. I didn't realize this until now. BTW, with 
the bad kernel, I've once seen special-test 21 (update_symlink) fail as 
well. Same reason I guess, a symbolic link is supposed to be changed 
from "link A/mu" to "link iota", so the file's size doesn't change and 
commit does nothing at all.

> OK, thanks. So certainly something fishy happened here. Some more
> thoughts below.
>
> On Wed, Jun 5, 2013 at 1:15 PM, Tobias Bading<tb...@web.de>  wrote:
> ...
>> I had a similar timestamp related problem with diff-test 60. (See thread
>> http://mail-archives.apache.org/mod_mbox/subversion-users/201305.mbox/%3C519DDBE3.5040909%40web.de%3E
>> on the users list for details, if you're interested.)
> Thanks for jumping in here. Yes, I read that thread. But I don't think
> it's the same problem (see below).

I agree... until proven otherwise. ;-)


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

Posted by Bert Huijben <be...@qqmail.nl>.

> -----Original Message-----
> From: Johan Corveleyn [mailto:jcorvel@gmail.com]
> Sent: donderdag 6 juni 2013 03:02
> To: Philip Martin
> Cc: Subversion Development; Tobias Bading; Bert Huijben
> Subject: Re: Strange failure of log_tests.py#7 -- missing commit in
> guarantee_repos_and_wc ?
> 
> On Wed, Jun 5, 2013 at 2:43 PM, Philip Martin
> <ph...@wandisco.com> wrote:
> > Johan Corveleyn <jc...@gmail.com> writes:
> ...
> >> 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 ...
> >
> > You are correct: both the timestamp and the filesize are checked (the
> > code is in svn_wc__internal_file_modified_p).  The timestamp "problem"
> > only causes modifications to be missed if those modifications don't
> > change the filesize.  In this case the filesize should have changed.
> 
> OK, thanks. So certainly something fishy happened here. Some more
> thoughts below.
> 
> On Wed, Jun 5, 2013 at 1:15 PM, Tobias Bading <tb...@web.de> wrote:
> ...
> > I had a similar timestamp related problem with diff-test 60. (See thread
> > http://mail-archives.apache.org/mod_mbox/subversion-
> users/201305.mbox/%3C519DDBE3.5040909%40web.de%3E
> > on the users list for details, if you're interested.)
> 
> Thanks for jumping in here. Yes, I read that thread. But I don't think
> it's the same problem (see below).
> 
> > TL;DR version of that thead:
> > If a file's timestamp doesn't change, Subversion assumes that it is
> > unmodified. Besides, Subversion's svn_io_sleep_for_timestamps()
> > implementation is making assumptions that aren't valid in all cases. The
> > cause of my test failures was a bad Linux kernel (reported here:
> > https://bugs.launchpad.net/ubuntu/+source/linux/+bug/1185730)
> combined with
> > Subversion's assumption that taking a nap for one millisecond would be
> > enough to get a fresh timestamp afterwards.
> 
> In this case, the filesize has also changed, so Subversion should
> still see it, regardless of timestamp.
> 
> > The output you provided looks like you're using Windoze, so a bad Linux
> > kernel is probably not your problem ;-). Do you have a very fast machine
> and
> > use a SSD? What filesystem do you use? NTFS?
> 
> Yes, I'm using Windows, so it's definitely not a bad Linux kernel :-).
> It's also likely not a problem with the OS or filesystem in general,
> since I've not changed it in years, and have been using it already a
> long time to test svn releases.
> 
> I'm actually running the tests on a Ramdisk (with an NTFS filesystem).
> Also nothing new, been using it this way for years without any
> problems.
> 
> However, I'm wondering now if perhaps there's an issue with the size
> of the ramdisk (and increased need for disk space during the tests).
> My ramdisk is only 128 MB large, which has sufficed until now. Perhaps
> I now need to enlarge it. I'll try increasing it to 256 MB, and
> rerunning the testsuite a couple of times.
> 
> @Bert: you made some commits recently related to disk usage of the
> test-suite. Can you summarize a bit what kinds of failures you got,
> and what changes you made for this? And are these in 1.8.0-rc2, or
> will they be in rc3?

I made some fixes to the test runner to clean up more left overs from
running the BDB tests.

The result without this fixes is that some tests start failing and failed
tests always leave their work area... So everything after a few failures
fails as well.

	Bert


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

Posted by Johan Corveleyn <jc...@gmail.com>.
On Wed, Jun 5, 2013 at 2:43 PM, Philip Martin
<ph...@wandisco.com> wrote:
> Johan Corveleyn <jc...@gmail.com> writes:
...
>> 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 ...
>
> You are correct: both the timestamp and the filesize are checked (the
> code is in svn_wc__internal_file_modified_p).  The timestamp "problem"
> only causes modifications to be missed if those modifications don't
> change the filesize.  In this case the filesize should have changed.

OK, thanks. So certainly something fishy happened here. Some more
thoughts below.

On Wed, Jun 5, 2013 at 1:15 PM, Tobias Bading <tb...@web.de> wrote:
...
> I had a similar timestamp related problem with diff-test 60. (See thread
> http://mail-archives.apache.org/mod_mbox/subversion-users/201305.mbox/%3C519DDBE3.5040909%40web.de%3E
> on the users list for details, if you're interested.)

Thanks for jumping in here. Yes, I read that thread. But I don't think
it's the same problem (see below).

> TL;DR version of that thead:
> If a file's timestamp doesn't change, Subversion assumes that it is
> unmodified. Besides, Subversion's svn_io_sleep_for_timestamps()
> implementation is making assumptions that aren't valid in all cases. The
> cause of my test failures was a bad Linux kernel (reported here:
> https://bugs.launchpad.net/ubuntu/+source/linux/+bug/1185730) combined with
> Subversion's assumption that taking a nap for one millisecond would be
> enough to get a fresh timestamp afterwards.

In this case, the filesize has also changed, so Subversion should
still see it, regardless of timestamp.

> The output you provided looks like you're using Windoze, so a bad Linux
> kernel is probably not your problem ;-). Do you have a very fast machine and
> use a SSD? What filesystem do you use? NTFS?

Yes, I'm using Windows, so it's definitely not a bad Linux kernel :-).
It's also likely not a problem with the OS or filesystem in general,
since I've not changed it in years, and have been using it already a
long time to test svn releases.

I'm actually running the tests on a Ramdisk (with an NTFS filesystem).
Also nothing new, been using it this way for years without any
problems.

However, I'm wondering now if perhaps there's an issue with the size
of the ramdisk (and increased need for disk space during the tests).
My ramdisk is only 128 MB large, which has sufficed until now. Perhaps
I now need to enlarge it. I'll try increasing it to 256 MB, and
rerunning the testsuite a couple of times.

@Bert: you made some commits recently related to disk usage of the
test-suite. Can you summarize a bit what kinds of failures you got,
and what changes you made for this? And are these in 1.8.0-rc2, or
will they be in rc3?

In one of your commit messages you specifically said that it should be
possible to run the test-suite in parallel on a 256 MB ramdisk. I
don't run the tests in parallel, but perhaps 128 MB has become too
small, even for non-parallellized test runs.

All that said: if these spurious failures turn out to be
diskspace-related, I'm still a bit worried: how come I didn't see a
big glaring error message in the test log? But first, let's try to
check this hypothesis by rerunning the tests on a larger ramdisk.

--
Johan

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

Posted by Philip Martin <ph...@wandisco.com>.
Johan Corveleyn <jc...@gmail.com> writes:

> ------------------------------------------------------------------------
> 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 ...

You are correct: both the timestamp and the filesize are checked (the
code is in svn_wc__internal_file_modified_p).  The timestamp "problem"
only causes modifications to be missed if those modifications don't
change the filesize.  In this case the filesize should have changed.

-- 
Certified & Supported Apache Subversion Downloads:
http://www.wandisco.com/subversion/download

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

Posted by Tobias Bading <tb...@web.de>.
On 03.06.2013 01:29, Johan Corveleyn wrote:
> [...]
>
> 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:
>
> [...]
>
> 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

Welcome to the club, Johan. ;-)

I had a similar timestamp related problem with diff-test 60. (See thread 
http://mail-archives.apache.org/mod_mbox/subversion-users/201305.mbox/%3C519DDBE3.5040909%40web.de%3E 
on the users list for details, if you're interested.)

TL;DR version of that thead:
If a file's timestamp doesn't change, Subversion assumes that it is 
unmodified. Besides, Subversion's svn_io_sleep_for_timestamps() 
implementation is making assumptions that aren't valid in all cases. The 
cause of my test failures was a bad Linux kernel (reported here: 
https://bugs.launchpad.net/ubuntu/+source/linux/+bug/1185730) combined 
with Subversion's assumption that taking a nap for one millisecond would 
be enough to get a fresh timestamp afterwards.

The output you provided looks like you're using Windoze, so a bad Linux 
kernel is probably not your problem ;-). Do you have a very fast machine 
and use a SSD? What filesystem do you use? NTFS?

Kind regards,
Tobias

PS: Please put me on CC in replies. Thanks.