threads / discuss / 9152

Test #7 in t9200-git-cvsexportcommit fails

Subject: Test #7 in t9200-git-cvsexportcommit fails

## tl;dr

21 messages between Jul 22, 2007 and Jul 25, 2007.

replies: 20people: 8as markdown or json

Jason Sewall· Jul 22, 2007, 19:41 UTC · lore

This test fails for me on the current head (pulled just now) and where the test was introduced (e86ad71fe).

All other tests pass.

I know almost nothing about how CVS works internally, so I don't have any insight as to the cause of this problem - all I can see is that the contents of CVS/Entries has the 'with spaces' files at 1.1 instead of the expect 1.2.

I'm happy to provide more information if you can tell me how to get it. In particular, I'd like to tell you about my version of perl-cvs (or whatever it's called) but I have no idea how to do that...

Jason

P.S. I don't use this part of git at all, so this is not a priority for me. I am using Fedora 7, which is definitely a mainstream distro, so I imagine others might have this problem too.

Alex Riesen· Jul 22, 2007, 20:21 UTC · re: Jason Sewall · lore

Re: Test #7 in t9200-git-cvsexportcommit fails

Jason Sewall, Sun, Jul 22, 2007 21:41:53 +0200:
> This test fails for me on the current head (pulled just now) and where
> the test was introduced (e86ad71fe).

Aahh, the test where CVS failed to commit sub-second changes... It never really succeeded.

> P.S. I don't use this part of git at all, so this is not a priority
> for me. I am using Fedora 7, which is definitely a mainstream distro,
> so I imagine others might have this problem too.
Just disable it:
    $ echo "export GIT_SKIP_TESTS = t9200" >>config.mak

It'll never work, cvs does not commit changes made during one second, as they have the same timestamp.

If you feel interested, try investigating the test by running it with "-d -v", like this:

    $ cd t
    $ ./t9200-git-cvsexportcommit.sh -d -v -i

You'll have to run it multiple times, probably: the problem is sometimes timing dependent and changed output conditions may make it go away for a while. Just continue trying.

Jason Sewall· Jul 22, 2007, 20:49 UTC · re: Alex Riesen · lore

Re: Test #7 in t9200-git-cvsexportcommit fails

> It'll never work, cvs does not commit changes made during one second,
> as they have the same timestamp.
Why not add a delay in there, like this:
id=$(git rev-list --max-count=1 HEAD) && sleep 2
It makes the test work for me.
Jason
Alex Riesen· Jul 22, 2007, 21:42 UTC · re: Jason Sewall · lore

Re: Test #7 in t9200-git-cvsexportcommit fails

Jason Sewall, Sun, Jul 22, 2007 22:49:19 +0200:
Show 8 quoted lines
> >It'll never work, cvs does not commit changes made during one second,
> >as they have the same timestamp.
> 
> Why not add a delay in there, like this:
> 
> id=$(git rev-list --max-count=1 HEAD) && sleep 2
> 
> It makes the test work for me.

It looks just like another reason to disable it. It is not like the _git_ functionality which is used by git-cvsexportcommit is not already tested elsewhere.

Note that I do _NOT_ suggest disabling it by default, but a bit of warning would probably do some good:

diff --git a/t/t9200-git-cvsexportcommit.sh b/t/t9200-git-cvsexportcommit.sh
index 4efa0c9..e5e9e36 100755
--- a/t/t9200-git-cvsexportcommit.sh
+++ b/t/t9200-git-cvsexportcommit.sh
@@ -6,6 +6,12 @@ test_description='CVS export comit. '
 
 . ./test-lib.sh
 
+echo >&2
+echo >&2 "This test is very timing dependent and may fail."
+echo >&2 "If you don't need git-cvsexportcommit you're better off"
+echo >&2 "disabling it: make test GIT_SKIP_TESTS=t9200"
+echo >&2
+
 cvs >/dev/null 2>&1
 if test $? -ne 1
 then
Junio C Hamano· Jul 22, 2007, 22:19 UTC · re: Jason Sewall · lore

Re: Test #7 in t9200-git-cvsexportcommit fails

"Jason Sewall" <jasonsewall@gmail.com> writes:
>> It'll never work, cvs does not commit changes made during one second,
>> as they have the same timestamp.
Heh, racy CVS?
Show 5 quoted lines
> Why not add a delay in there, like this:
>
> id=$(git rev-list --max-count=1 HEAD) && sleep 2
>
> It makes the test work for me.

Sounds like an acceptable workaround. Care to send in a tested signed patch?

Jason Sewall· Jul 23, 2007, 03:59 UTC · re: Junio C Hamano · lore

[PATCH] Add a 1-second sleep to git-cvsexportcommit test

Test #7 of t9200 isn't likely to succeed because tests are executed too fast for cvs; add a delay to give it a chance to succeed.
---
 I think I didn't send this through the proper server, so here it is finally.
 t/t9200-git-cvsexportcommit.sh |    1 +
 1 files changed, 1 insertions(+), 0 deletions(-)
diff --git a/t/t9200-git-cvsexportcommit.sh b/t/t9200-git-cvsexportcommit.sh
index 4efa0c9..2096e59 100755
--- a/t/t9200-git-cvsexportcommit.sh
+++ b/t/t9200-git-cvsexportcommit.sh
@@ -164,6 +164,7 @@ test_expect_success \
       git add "G g/with spaces.png" &&
       git commit -a -m "Update with spaces" &&
       id=$(git rev-list --max-count=1 HEAD) &&
+      sleep 1 &&
       (cd "$CVSWORK" &&
       git-cvsexportcommit -c $id
       test "$(echo $(sort "G g/CVS/Entries"|cut -d/ -f2,3,5))" = "with spaces.png/1.2/-kb with spaces.txt/1.2/"
--
1.5.3.rc2.4.g726f9
Junio C Hamano· Jul 23, 2007, 04:32 UTC · re: Jason Sewall · lore

Re: [PATCH] Add a 1-second sleep to git-cvsexportcommit test

Jason Sewall <jasonsewall@gmail.com> writes:
Show 18 quoted lines
> Test #7 of t9200 isn't likely to succeed because tests are executed too fast for cvs; add a delay to give it a chance to succeed.
> ---
>  I think I didn't send this through the proper server, so here it is finally.
>  t/t9200-git-cvsexportcommit.sh |    1 +
>  1 files changed, 1 insertions(+), 0 deletions(-)
>
> diff --git a/t/t9200-git-cvsexportcommit.sh b/t/t9200-git-cvsexportcommit.sh
> index 4efa0c9..2096e59 100755
> --- a/t/t9200-git-cvsexportcommit.sh
> +++ b/t/t9200-git-cvsexportcommit.sh
> @@ -164,6 +164,7 @@ test_expect_success \
>        git add "G g/with spaces.png" &&
>        git commit -a -m "Update with spaces" &&
>        id=$(git rev-list --max-count=1 HEAD) &&
> +      sleep 1 &&
>        (cd "$CVSWORK" &&
>        git-cvsexportcommit -c $id
>        test "$(echo $(sort "G g/CVS/Entries"|cut -d/ -f2,3,5))" = "with spaces.png/1.2/-kb with spaces.txt/1.2/"
Thanks.

But this makes one wonder why only this test and nothing else is affected. Maybe our machines are not fast enough for other tests to execute inside a second, but in 6 months others start to become problem and we would need a similar fix again?

I am tempted to do this instead, although it would make it much slower.

It may be that we may want to fix this inside cvsexportcommit itself, instead of working it around in the tests. If somebody tries to push more than one commit from git using two cvsexportcommit in a row, he would need to make sure that the second run happens one or more seconds after the first run, otherwise he will see the exact corruption in real life.

Anybody else have better ideas?  
---
 t/t9200-git-cvsexportcommit.sh |   29 ++++++++++++++++++-----------
 1 files changed, 18 insertions(+), 11 deletions(-)
diff --git a/t/t9200-git-cvsexportcommit.sh b/t/t9200-git-cvsexportcommit.sh
index 4efa0c9..28c7dfa 100755
--- a/t/t9200-git-cvsexportcommit.sh
+++ b/t/t9200-git-cvsexportcommit.sh
@@ -28,6 +28,13 @@ git add empty &&
 git commit -q -a -m "Initial" 2>/dev/null ||
 exit 1
 
+git_cvsexportcommit () {
+	# CVS does not even look at files whose timestamps
+	# match the ones recorded in CVS/Entries
+	sleep 2 &&
+	git cvsexportcommit "$@"
+}
+
 test_expect_success \
     'New file' \
     'mkdir A B C D E F &&
@@ -42,7 +49,7 @@ test_expect_success \
      git commit -a -m "Test: New file" &&
      id=$(git rev-list --max-count=1 HEAD) &&
      (cd "$CVSWORK" &&
-     git cvsexportcommit -c $id &&
+     git_cvsexportcommit -c $id &&
      test "$(echo $(sort A/CVS/Entries|cut -d/ -f2,3,5))" = "newfile1.txt/1.1/" &&
      test "$(echo $(sort B/CVS/Entries|cut -d/ -f2,3,5))" = "newfile2.txt/1.1/" &&
      test "$(echo $(sort C/CVS/Entries|cut -d/ -f2,3,5))" = "newfile3.png/1.1/-kb" &&
@@ -66,7 +73,7 @@ test_expect_success \
      git commit -a -m "Test: Remove, add and update" &&
      id=$(git rev-list --max-count=1 HEAD) &&
      (cd "$CVSWORK" &&
-     git cvsexportcommit -c $id &&
+     git_cvsexportcommit -c $id &&
      test "$(echo $(sort A/CVS/Entries|cut -d/ -f2,3,5))" = "newfile1.txt/1.2/" &&
      test "$(echo $(sort B/CVS/Entries|cut -d/ -f2,3,5))" = "" &&
      test "$(echo $(sort C/CVS/Entries|cut -d/ -f2,3,5))" = "" &&
@@ -88,7 +95,7 @@ test_expect_success \
      git commit -a -m "generation 2" &&
      id=$(git rev-list --max-count=1 HEAD) &&
      (cd "$CVSWORK" &&
-     ! git cvsexportcommit -c $id
+     ! git_cvsexportcommit -c $id
      )'
 
 #test_expect_success \
@@ -100,7 +107,7 @@ test_expect_success \
 #     git commit -a -m "generation 3" &&
 #     id=$(git rev-list --max-count=1 HEAD) &&
 #     (cd "$CVSWORK" &&
-#     ! git cvsexportcommit -c $id
+#     ! git_cvsexportcommit -c $id
 #     )'
 
 # We reuse the state from two tests back here
@@ -114,7 +121,7 @@ test_expect_success \
      git commit -a -m "test: remove only a binary file" &&
      id=$(git rev-list --max-count=1 HEAD) &&
      (cd "$CVSWORK" &&
-     git cvsexportcommit -c $id &&
+     git_cvsexportcommit -c $id &&
      test "$(echo $(sort A/CVS/Entries|cut -d/ -f2,3,5))" = "newfile1.txt/1.2/" &&
      test "$(echo $(sort B/CVS/Entries|cut -d/ -f2,3,5))" = "" &&
      test "$(echo $(sort C/CVS/Entries|cut -d/ -f2,3,5))" = "" &&
@@ -132,7 +139,7 @@ test_expect_success \
      git commit -a -m "test: remove only a binary file" &&
      id=$(git rev-list --max-count=1 HEAD) &&
      (cd "$CVSWORK" &&
-     git cvsexportcommit -c $id &&
+     git_cvsexportcommit -c $id &&
      test "$(echo $(sort A/CVS/Entries|cut -d/ -f2,3,5))" = "" &&
      test "$(echo $(sort B/CVS/Entries|cut -d/ -f2,3,5))" = "" &&
      test "$(echo $(sort C/CVS/Entries|cut -d/ -f2,3,5))" = "" &&
@@ -153,7 +160,7 @@ test_expect_success \
       git commit -a -m "With spaces" &&
       id=$(git rev-list --max-count=1 HEAD) &&
       (cd "$CVSWORK" &&
-      git-cvsexportcommit -c $id &&
+      git_cvsexportcommit -c $id &&
       test "$(echo $(sort "G g/CVS/Entries"|cut -d/ -f2,3,5))" = "with spaces.png/1.1/-kb with spaces.txt/1.1/"
       )'
 
@@ -165,7 +172,7 @@ test_expect_success \
       git commit -a -m "Update with spaces" &&
       id=$(git rev-list --max-count=1 HEAD) &&
       (cd "$CVSWORK" &&
-      git-cvsexportcommit -c $id
+      git_cvsexportcommit -c $id
       test "$(echo $(sort "G g/CVS/Entries"|cut -d/ -f2,3,5))" = "with spaces.png/1.2/-kb with spaces.txt/1.2/"
       )'
 
@@ -190,7 +197,7 @@ test_expect_success \
       git commit -a -m "Går det så går det" && \
       id=$(git rev-list --max-count=1 HEAD) &&
       (cd "$CVSWORK" &&
-      git-cvsexportcommit -v -c $id &&
+      git_cvsexportcommit -v -c $id &&
       test "$(echo $(sort Å/goo/a/b/c/d/e/f/g/h/i/j/k/l/m/n/o/p/q/r/s/t/u/v/w/x/y/z/å/ä/ö/CVS/Entries|cut -d/ -f2,3,5))" = "gårdetsågårdet.png/1.1/-kb gårdetsågårdet.txt/1.1/"
       )'
 
@@ -208,7 +215,7 @@ test_expect_success \
       git commit -a -m "Update two" &&
       id=$(git rev-list --max-count=1 HEAD) &&
       (cd "$CVSWORK" &&
-      ! git-cvsexportcommit -c $id
+      ! git_cvsexportcommit -c $id
       )'
 
 case "$(git repo-config --bool core.filemode)" in
@@ -225,7 +232,7 @@ test_expect_success \
       git add G/off &&
       git commit -a -m "Execute test" &&
       (cd "$CVSWORK" &&
-      git-cvsexportcommit -c HEAD
+      git_cvsexportcommit -c HEAD
       test -x G/on &&
       ! test -x G/off
       )'
Simon 'corecode' Schubert· Jul 23, 2007, 07:55 UTC · re: Junio C Hamano · lore

Re: [PATCH] Add a 1-second sleep to git-cvsexportcommit test

Junio C Hamano wrote:
Show 6 quoted lines
> It may be that we may want to fix this inside cvsexportcommit
> itself, instead of working it around in the tests.  If somebody
> tries to push more than one commit from git using two
> cvsexportcommit in a row, he would need to make sure that the
> second run happens one or more seconds after the first run,
> otherwise he will see the exact corruption in real life.
Ah, now I see the problem.  The timestamp in the CVS/Entries is the same (because it only has second granularity), so cvs commit won't consider it as changed.
That's the reason why CVS usually waits until the second turns after a "update" (obviously not after a "commit").  So we could either turn back the timestamp in the Entries file (ugly) or simply wait until the second turns.  Given the overall cvs performance, this won't be a big issue, I guess.
cheers
  simon
-- 
Serve - BSD     +++  RENT this banner advert  +++    ASCII Ribbon   /"\
Work - Mac      +++  space for low €€€ NOW!1  +++      Campaign     \ /
Party Enjoy Relax   |   http://dragonflybsd.org      Against  HTML   \
Dude 2c 2 the max   !   http://golden-apple.biz       Mail + News   / \
Robin Rosenberg· Jul 24, 2007, 00:23 UTC · re: Simon 'corecode' Schubert · lore

Re: [PATCH] Add a 1-second sleep to git-cvsexportcommit test

måndag 23 juli 2007 skrev Simon 'corecode' Schubert:
Show 18 quoted lines
> Junio C Hamano wrote:
> > It may be that we may want to fix this inside cvsexportcommit
> > itself, instead of working it around in the tests.  If somebody
> > tries to push more than one commit from git using two
> > cvsexportcommit in a row, he would need to make sure that the
> > second run happens one or more seconds after the first run,
> > otherwise he will see the exact corruption in real life.
> 
> Ah, now I see the problem.  The timestamp in the CVS/Entries is the same (because it only has second granularity), 
> so cvs commit won't consider it as changed. 
> 
> That's the reason why CVS usually waits until the second turns after a "update" (obviously not after a "commit"). 
> So we could either turn back the timestamp in the Entries file (ugly) or simply wait until the second turns.  Given 
> the overall cvs performance, this won't be a big issue, I guess. 
> 
> cheers
>   simon
>

CVS sleeps after commit here. Can we bisect it? I have 1.12.3 (mandriva). The patch below I think would work around the problem, rather than trying to fix the test. but I'd like to have the last CVS revision where it does not work for the patch comment

Since the sleep is per invocation of cvsexportcommit it won't hurt too much since it is rarely invoked on a huge number of git commits.

-- robin
diff --git a/git-cvsexportcommit.perl b/git-cvsexportcommit.perl
index d6ae99b..6377408 100755
--- a/git-cvsexportcommit.perl
+++ b/git-cvsexportcommit.perl
@@ -277,6 +277,10 @@ if ($opt_c) {
 # clean up
 unlink(".cvsexportcommit.diff");

+# timestamp problems. Invoking this command on a machine that is too fast may result in
+# CVS not recognizing changed because the timestamp is unchanged
+sleep(1);
+
 sub usage {
        print STDERR <<END;
 Usage: GIT_DIR=/path/to/.git ${\basename $0} [-h] [-p] [-v] [-c] [-f] [-m msgprefix] [ parent ] commit
Simon 'corecode' Schubert· Jul 24, 2007, 08:11 UTC · re: Robin Rosenberg · lore

Re: [PATCH] Add a 1-second sleep to git-cvsexportcommit test

Robin Rosenberg wrote:
Show 17 quoted lines
>>> It may be that we may want to fix this inside cvsexportcommit
>>> itself, instead of working it around in the tests.  If somebody
>>> tries to push more than one commit from git using two
>>> cvsexportcommit in a row, he would need to make sure that the
>>> second run happens one or more seconds after the first run,
>>> otherwise he will see the exact corruption in real life.
>> Ah, now I see the problem.  The timestamp in the CVS/Entries is the same (because it only has second granularity), 
>> so cvs commit won't consider it as changed. 
>>
>> That's the reason why CVS usually waits until the second turns after a "update" (obviously not after a "commit"). 
>> So we could either turn back the timestamp in the Entries file (ugly) or simply wait until the second turns.  Given 
>> the overall cvs performance, this won't be a big issue, I guess. 
> 
> CVS sleeps after commit here. Can we bisect it? I have 1.12.3
> (mandriva). The patch below I think would work around the problem,
> rather than trying to fix the test. but I'd like to have the last CVS
>  revision where it does not work for the patch comment
This is a strange thing.  CVS has this in their commit code since 1996.  So I wonder why this is getting triggered.
> Since the sleep is per invocation of cvsexportcommit it won't hurt
> too much since it is rarely invoked on a huge number of git commits.
The question also is, why does this happen on two sequential invocations of cvsexportcommit, but not on two cvs commits done by cvsexportcommit?  This should look the same to cvs, no?
cheers
  simon
-- 
Serve - BSD     +++  RENT this banner advert  +++    ASCII Ribbon   /"\
Work - Mac      +++  space for low €€€ NOW!1  +++      Campaign     \ /
Party Enjoy Relax   |   http://dragonflybsd.org      Against  HTML   \
Dude 2c 2 the max   !   http://golden-apple.biz       Mail + News   / \
Robin Rosenberg· Jul 24, 2007, 08:33 UTC · re: Simon 'corecode' Schubert · lore

Re: [PATCH] Add a 1-second sleep to git-cvsexportcommit test

tisdag 24 juli 2007 skrev Simon 'corecode' Schubert:
Show 25 quoted lines
> Robin Rosenberg wrote:
> >>> It may be that we may want to fix this inside cvsexportcommit
> >>> itself, instead of working it around in the tests.  If somebody
> >>> tries to push more than one commit from git using two
> >>> cvsexportcommit in a row, he would need to make sure that the
> >>> second run happens one or more seconds after the first run,
> >>> otherwise he will see the exact corruption in real life.
> >> Ah, now I see the problem.  The timestamp in the CVS/Entries is the same (because it only has second granularity), 
> >> so cvs commit won't consider it as changed. 
> >>
> >> That's the reason why CVS usually waits until the second turns after a "update" (obviously not after a "commit"). 
> >> So we could either turn back the timestamp in the Entries file (ugly) or simply wait until the second turns.  Given 
> >> the overall cvs performance, this won't be a big issue, I guess. 
> > 
> > CVS sleeps after commit here. Can we bisect it? I have 1.12.3
> > (mandriva). The patch below I think would work around the problem,
> > rather than trying to fix the test. but I'd like to have the last CVS
> >  revision where it does not work for the patch comment
> 
> This is a strange thing.  CVS has this in their commit code since 1996.  So I wonder why this is getting triggered.
> 
> > Since the sleep is per invocation of cvsexportcommit it won't hurt
> > too much since it is rarely invoked on a huge number of git commits.
> 
> The question also is, why does this happen on two sequential invocations of cvsexportcommit, but not on two cvs commits done by cvsexportcommit?  This should look the same to cvs, no?
I reread my post here...  My last sentence was a comment to the patch and not the sleep in CVS.
-- robin
Simon 'corecode' Schubert· Jul 24, 2007, 08:38 UTC · re: Robin Rosenberg · lore

Re: [PATCH] Add a 1-second sleep to git-cvsexportcommit test

Robin Rosenberg wrote:
Show 6 quoted lines
>>> Since the sleep is per invocation of cvsexportcommit it won't hurt
>>> too much since it is rarely invoked on a huge number of git commits.
>> The question also is, why does this happen on two sequential invocations of cvsexportcommit, but not on two cvs commits done by cvsexportcommit?  This should look the same to cvs, no?
> 
> I reread my post here... My last sentence was a comment to the patch
> and not the sleep in CVS.
Yes, I realize this.  Still, I wonder the same:  why is this needed *per invocation of cvsexportcommit* and not *per invocation of cvs*?  Seems unintuitive to me, or I didn't read the patch good enough.
cheers
  simon
-- 
Serve - BSD     +++  RENT this banner advert  +++    ASCII Ribbon   /"\
Work - Mac      +++  space for low €€€ NOW!1  +++      Campaign     \ /
Party Enjoy Relax   |   http://dragonflybsd.org      Against  HTML   \
Dude 2c 2 the max   !   http://golden-apple.biz       Mail + News   / \
Robin Rosenberg· Jul 24, 2007, 09:34 UTC · re: Simon 'corecode' Schubert · lore

Re: [PATCH] Add a 1-second sleep to git-cvsexportcommit test

tisdag 24 juli 2007 skrev Simon 'corecode' Schubert:
Show 13 quoted lines
> Robin Rosenberg wrote:
> >>> Since the sleep is per invocation of cvsexportcommit it won't hurt
> >>> too much since it is rarely invoked on a huge number of git commits.
> >> The question also is, why does this happen on two sequential invocations 
> >> of cvsexportcommit, but not on two cvs commits done by cvsexportcommit?  
> >> This should look the same to cvs, no?  
> > 
> > I reread my post here... My last sentence was a comment to the patch
> > and not the sleep in CVS.
> 
> Yes, I realize this.  Still, I wonder the same:  why is this needed *per
> invocation of cvsexportcommit* and not *per invocation of cvs*?  Seems
> unintuitive to me, or I didn't read the patch good enough.

Besides the potential update and status commands cvs is only invoked once per invocation of cvsexportcommit so there is no difference between a sleep per CVS invokation vs a sleep per cvsexportcommit invocation. The sleep is needed to make sure file modification times resulting from git-apply are different.

The sleep in CVS fixes that on my machine so I do not have a problem (and cannot really verify that the patch I made fixes the problem).

This debug patch reveals the sleep in CVS. CVS does the sleep differently for different platforms.
diff --git a/t/t9200-git-cvsexportcommit.sh b/t/t9200-git-cvsexportcommit.sh
index 4efa0c9..9a1e998 100755
--- a/t/t9200-git-cvsexportcommit.sh
+++ b/t/t9200-git-cvsexportcommit.sh
@@ -153,7 +153,7 @@ test_expect_success \
       git commit -a -m "With spaces" &&
       id=$(git rev-list --max-count=1 HEAD) &&
       (cd "$CVSWORK" &&
-      git-cvsexportcommit -c $id &&
+      strace -fF -o a git-cvsexportcommit -c $id &&
       test "$(echo $(sort "G g/CVS/Entries"|cut -d/ -f2,3,5))" = "with spaces.png/1.1/-kb with spaces.txt/1.1/"
       )'
 
@@ -165,7 +165,7 @@ test_expect_success \
       git commit -a -m "Update with spaces" &&
       id=$(git rev-list --max-count=1 HEAD) &&
       (cd "$CVSWORK" &&
-      git-cvsexportcommit -c $id
+      strace -fF -o b git-cvsexportcommit -c $id
       test "$(echo $(sort "G g/CVS/Entries"|cut -d/ -f2,3,5))" = "with spaces.png/1.2/-kb with spaces.txt/1.2/"
       )'

Tail of the first cvsexportcommit invocation (trash/cvswork/a) from the place where it writes the last file
into the CVS repo.
 
27778 write(7, "/with spaces.png/1.1/Tue Jul 24 "..., 99) = 99
27778 close(7)                          = 0
27778 munmap(0xb7f15000, 4096)          = 0
27778 rename("CVS/Entries.Backup", "CVS/Entries") = 0
27778 unlink("CVS/Entries.Log")         = 0
27778 fchdir(6)                         = 0
27778 close(6)                          = 0
27778 rt_sigprocmask(SIG_SETMASK, ~[RTMIN RT_1], [], 8) = 0
27778 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
27778 rt_sigprocmask(SIG_SETMASK, ~[RTMIN RT_1], [], 8) = 0
27778 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
27778 rt_sigprocmask(SIG_SETMASK, ~[RTMIN RT_1], [], 8) = 0
27778 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
27778 rt_sigprocmask(SIG_SETMASK, ~[RTMIN RT_1], [], 8) = 0
27778 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
27778 rt_sigprocmask(SIG_SETMASK, ~[RTMIN RT_1], [], 8) = 0
27778 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
27778 rt_sigprocmask(SIG_SETMASK, ~[RTMIN RT_1], [], 8) = 0
27778 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
27778 time(NULL)                        = 1185268822
27778 gettimeofday({1185268822, 953340}, NULL) = 0

Here CVS sleeps. The amount varies between invocations since it
only sleeps enough for the seconds to wrap.

27778 nanosleep({0, 46660000}, NULL)    = 0
27778 time(NULL)                        = 1185268823
27778 rt_sigprocmask(SIG_SETMASK, ~[RTMIN RT_1], [], 8) = 0
27778 close(1 <unfinished ...>
27766 <... read resumed> "", 4096)      = 0
27778 <... close resumed> )             = 0
27766 close(6 <unfinished ...>
27778 munmap(0xb7f14000, 4096 <unfinished ...>
27766 <... close resumed> )             = 0
27778 <... munmap resumed> )            = 0

Back into git-cvsexportcommit
27766 rt_sigaction(SIGHUP, {SIG_IGN},  <unfinished ...>
27778 exit_group(0)                     = ?
27766 <... rt_sigaction resumed> {SIG_DFL}, 8) = 0
27766 --- SIGCHLD (Child exited) @ 0 (0) ---
27766 rt_sigaction(SIGINT, {SIG_IGN}, {SIG_DFL}, 8) = 0
27766 rt_sigaction(SIGQUIT, {SIG_IGN}, {SIG_DFL}, 8) = 0
27766 waitpid(27778, [{WIFEXITED(s) && WEXITSTATUS(s) == 0}], 0) = 27778
27766 rt_sigaction(SIGHUP, {SIG_DFL}, NULL, 8) = 0
27766 rt_sigaction(SIGINT, {SIG_DFL}, NULL, 8) = 0
27766 rt_sigaction(SIGQUIT, {SIG_DFL}, NULL, 8) = 0
27766 unlink(".msg")                    = 0
27766 unlink(".cvsexportcommit.diff")   = 0
27766 stat64("/home/me/tmp/git-cvsapplycommit-55ADfh", {st_mode=S_IFDIR|0700, st_size=6, ...}) = 0
27766 lstat64("/home/me/tmp/git-cvsapplycommit-55ADfh", {st_mode=S_IFDIR|0700, st_size=6, ...}) = 0
27766 chmod("/home/me/tmp/git-cvsapplycommit-55ADfh", 0700) = 0
27766 open("/home/me/tmp/git-cvsapplycommit-55ADfh", O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_DIRECTORY) = 6
27766 fstat64(6, {st_mode=S_IFDIR|0700, st_size=6, ...}) = 0
27766 fcntl64(6, F_SETFD, FD_CLOEXEC)   = 0
27766 getdents64(6, /* 2 entries */, 4096) = 48
27766 getdents64(6, /* 0 entries */, 4096) = 0
27766 close(6)                          = 0
27766 rmdir("/home/me/tmp/git-cvsapplycommit-55ADfh") = 0
27766 write(1, "/home/me/SW/GIT/t/trash/cvsroot/"..., 234) = 234
27766 exit_group(0)                     = ?

-- robin
Junio C Hamano· Jul 24, 2007, 10:14 UTC · re: Robin Rosenberg · lore

Re: [PATCH] Add a 1-second sleep to git-cvsexportcommit test

Robin Rosenberg <robin.rosenberg.lists@dewire.com> writes:
Show 17 quoted lines
> Tail of the first cvsexportcommit invocation (trash/cvswork/a) from the place where it writes the last file
> into the CVS repo.
>  
> 27778 write(7, "/with spaces.png/1.1/Tue Jul 24 "..., 99) = 99
> 27778 close(7)                          = 0
> 27778 munmap(0xb7f15000, 4096)          = 0
> 27778 rename("CVS/Entries.Backup", "CVS/Entries") = 0
> 27778 unlink("CVS/Entries.Log")         = 0
> 27778 fchdir(6)                         = 0
> 27778 close(6)                          = 0
> ...
> 27778 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
> 27778 time(NULL)                        = 1185268822
> 27778 gettimeofday({1185268822, 953340}, NULL) = 0
>
> Here CVS sleeps. The amount varies between invocations since it
> only sleeps enough for the seconds to wrap.

Makes one wonder what it would do if you are on a filesystem with coarser-than-a-second timestamp resolution.

Robin Rosenberg· Jul 24, 2007, 12:57 UTC · re: Junio C Hamano · lore

Re: [PATCH] Add a 1-second sleep to git-cvsexportcommit test

tisdag 24 juli 2007 skrev Junio C Hamano:
Show 5 quoted lines
> > Here CVS sleeps. The amount varies between invocations since it
> > only sleeps enough for the seconds to wrap.
> 
> Makes one wonder what it would do if you are on a filesystem
> with coarser-than-a-second timestamp resolution.

Like fat, but then the last test fails on FAT, which wasn't the case. Any other reasonable file systems that comes to your mind?

Jason, could you provide us with some more information on OS, fs, cvs version etc.
Whether timestamp granularity is larger than a second or not can be checked with this line, I think:
	touch a && ls --full-time a && sleep 1 && touch a && ls --full-time a

Sample output where the timestamps are roughly one second apart. -rw-r--r-- 1 me me 0 2007-07-24 14:15:47.330927250 +0200 a -rw-r--r-- 1 me me 0 2007-07-24 14:15:48.338990250 +0200 a

-- robin
Jason Sewall· Jul 24, 2007, 15:31 UTC · re: Robin Rosenberg · lore

Re: [PATCH] Add a 1-second sleep to git-cvsexportcommit test

Fedora 7 Kernel 2.6.22 (SMP) CVS 1.11.22 ext3 (unsure of version or how to discover version)

As one would expect from the above, the 'granularity' test you gave my reveals 1-second granularity.

On 7/24/07, Robin Rosenberg <robin.rosenberg.lists@dewire.com> wrote:
Show 22 quoted lines
> tisdag 24 juli 2007 skrev Junio C Hamano:
> > > Here CVS sleeps. The amount varies between invocations since it
> > > only sleeps enough for the seconds to wrap.
> >
> > Makes one wonder what it would do if you are on a filesystem
> > with coarser-than-a-second timestamp resolution.
>
> Like fat, but then the last test fails on FAT, which wasn't the case. Any other reasonable file
> systems that comes to your mind?
>
> Jason, could you provide us with some more information on OS, fs, cvs version etc.
>
> Whether timestamp granularity is larger than a second or not can be checked with this line, I think:
>
>         touch a && ls --full-time a && sleep 1 && touch a && ls --full-time a
>
> Sample output where the timestamps are roughly one second apart.
> -rw-r--r-- 1 me me 0 2007-07-24 14:15:47.330927250 +0200 a
> -rw-r--r-- 1 me me 0 2007-07-24 14:15:48.338990250 +0200 a
>
> -- robin
>
Linus Torvalds· Jul 24, 2007, 19:02 UTC · re: Robin Rosenberg · lore

Re: [PATCH] Add a 1-second sleep to git-cvsexportcommit test

On Tue, 24 Jul 2007, Robin Rosenberg wrote:
Show 9 quoted lines
>
> 27778 time(NULL)                        = 1185268822
> 27778 gettimeofday({1185268822, 953340}, NULL) = 0
> 
> Here CVS sleeps. The amount varies between invocations since it
> only sleeps enough for the seconds to wrap.
> 
> 27778 nanosleep({0, 46660000}, NULL)    = 0
> 27778 time(NULL)                        = 1185268823
Btw, this is *really* dangerous and buggy.

The reason? The CPU real-time clock is very different from whatever clock the filesystems may use.

Filesystems generally do not use the same clock as the CPU does. That's obviously true for things like networked filesystems, but it's actually true even for local filesystems (even on UP) because the CPU "realtime" clock rather expensive and much too exact for them. It does all the fancy NTP date correction etc, and it has all the complex code to actually make sure you don't get any time jumps etc.

So you should basically assume that all filesystems will use a clock that is *close*, but not synchronized with the real-time clock. You have NFS issues, but even locally you'd generally expect the local filesystem to be based on a simply clock that is updated by the timer tick, and is "close enough" to the realtime clock that you get with gettimeofday(). But *not* identical.

So if you sleep for one second, the filesystem times will update by one second, but if you try to *synchronize* to exactly one second, it's not at all certain that the *filesystem* clock will be synchronized to the same second! Time skew is simply a fact of life.

A really obvious example of this is NFS. Anybody who thinks that the NFS times are synchronized to the client real-time clock is just seriously mistaken. They may be close, but they won't be identical.

So I think CVS is simply buggy here. It assumes that "filesystem time" is the same as "CPU time", and while that sounds like an obvious assumption to make, if you think about it for even five seconds (the NFS case above), you realize that it's a totally *buggy* assumption.

In other words: if you want the timestamps on two files to be one second apart, you have to sleep one second in between writing them (or you have to set the time explicitly with "utimes()" or similar). Doing the "optimized sleep" simply DOES NOT WORK.

So CVS is buggy. Big surprise. Film at 11.

Btw, if anybody can think of a similar scenario in git, please holler. We shouldn't have those kinds of bugs.

So the things you generally can depend on:
 - *within* a single filesystem, the clocks should be comparable (ie you 
   can do "stat()" on two files, and compare the date-stamps between the 
   files).
 - the clocks should obviously be "close" to the local realtime. Time skew 
   is a fact of life, but if time skews by more than a big fraction of a 
   second, something is wrong. It's certainly still very possible (NFS 
   with clients not running NTP), but at least at that point a program can 
   validly say "badly maintained network, it's the users problem".
but depending on exact time syncronization is a really really bad idea.
		Linus
Robin Rosenberg· Jul 24, 2007, 22:56 UTC · re: Linus Torvalds · lore

Re: [PATCH] Add a 1-second sleep to git-cvsexportcommit test

tisdag 24 juli 2007 skrev Linus Torvalds:
Show 23 quoted lines
> 
> On Tue, 24 Jul 2007, Robin Rosenberg wrote:
> >
> > 27778 time(NULL)                        = 1185268822
> > 27778 gettimeofday({1185268822, 953340}, NULL) = 0
> > 
> > Here CVS sleeps. The amount varies between invocations since it
> > only sleeps enough for the seconds to wrap.
> > 
> > 27778 nanosleep({0, 46660000}, NULL)    = 0
> > 27778 time(NULL)                        = 1185268823
> 
> Btw, this is *really* dangerous and buggy.
> 
> The reason? The CPU real-time clock is very different from whatever clock 
> the filesystems may use.
> 
> Filesystems generally do not use the same clock as the CPU does. That's 
> obviously true for things like networked filesystems, but it's actually 
> true even for local filesystems (even on UP) because the CPU "realtime" 
> clock rather expensive and much too exact for them. It does all the fancy 
> NTP date correction etc, and it has all the complex code to actually make 
> sure you don't get any time jumps etc.

Having our mind enlightened, I propose this or nothing as a workaround. Since cvsexportcommit is really a CVS workaround we might work around some bugs in CVS itself while we're at it.

-- robin
From: Robin Rosenberg <robin.rosenberg@dewire.com>
Date: Wed, 25 Jul 2007 00:53:24 +0200
Subject: [PATCH] Sleep in git-cvsexportcommit

If git cvsexportcommit is executed fast enough in sequence, the CVS timestamps could end up being the same. CVS tries to fix this by sleeping until the CPU clock changes seconds. Unfortunately, the CPU clock and the file system clock are not necessarily the same, so the timestamps could be the same anyway. When that happens CVS may not recognize changed files and cvs will forget to commit some files.

Signed-off-by: Robin Rosenberg <robin.rosenberg@dewire.com>
---
 git-cvsexportcommit.perl |    5 +++++
 1 files changed, 5 insertions(+), 0 deletions(-)
diff --git a/git-cvsexportcommit.perl b/git-cvsexportcommit.perl
index d6ae99b..f6366be 100755
--- a/git-cvsexportcommit.perl
+++ b/git-cvsexportcommit.perl
@@ -277,6 +277,11 @@ if ($opt_c) {
 # clean up
 unlink(".cvsexportcommit.diff");
 
+# CVS version 1.11.x and 1.12.x sleeps the wrong way to ensure the timestamp 
+# used by CVS and the one set by subsequence file modifications are different.
+# If they are not different CVS will not detect changes.
+sleep(1);
+
 sub usage {
 	print STDERR <<END;
 Usage: GIT_DIR=/path/to/.git ${\basename $0} [-h] [-p] [-v] [-c] [-f] [-m msgprefix] [ parent ] commit

-- 
1.5.2.3
Linus Torvalds· Jul 24, 2007, 23:19 UTC · re: Robin Rosenberg · lore

Re: [PATCH] Add a 1-second sleep to git-cvsexportcommit test

On Wed, 25 Jul 2007, Robin Rosenberg wrote:
> 
> Having our mind enlightened, I propose this or nothing as a workaround. Since
> cvsexportcommit is really a CVS workaround we might work around some bugs
> in CVS itself while we're at it.

Side note: I think the reason it came up now is that with CONFIG_NO_HZ the Linux filesystem clock will easily be off by half a second even for local filesystems.

With CONFIG_NO_HZ, we don't update the time as religiously, and as a result, people who look at the low-resolution time (like filesystems) will get a noticeable skew.

Quite frankly, that's a Linux kernel bug, and we'll fix it. But it doesn't really invalidate the argument: applications really shouldn't depend on the "filesystem time" being in sync with the "CPU time", and it may be that the kernel bug was the one that ended up exposing this mis-feature of CVS.

Normally, Linux (and probably most other systems) will keep the local filesystems synchronized to within at least one clock-tick of the real-time clock, so the clock skew between filesystems and CPU is at most in the "few millisecond" range.

That's also the kind of range that NTP will largely guarantee, so generally, in most circumstances, while you cannot (and shouldn't) expect filesystem times to be "accurate", in most good situations you'll never see skews over a few milliseconds.

(But on the other hand, search for "kerberos" and "time skew" on google, and you see discussions about allowing five *minutes* of skew etc, so clearly the model of "everybody runs NTP" isn't exactly all of it ;)

So I suspect that the CVS code is (a) buggy and (b) hard to show the bug actually triggering on a well-maintained machine, and that it may well be the case that the only reason it shows up as a bug now is that Jason is running a recent kernel with CONFIG_NO_HZ. I have no idea what the default Fedora 7 kernel does.

		Linus
Andy Parkins· Jul 25, 2007, 07:35 UTC · re: Linus Torvalds · lore

Re: [PATCH] Add a 1-second sleep to git-cvsexportcommit test

On Tuesday 2007 July 24, Linus Torvalds wrote:
> So if you sleep for one second, the filesystem times will update by one
> second, but if you try to *synchronize* to exactly one second, it's not at
> all certain that the *filesystem* clock will be synchronized to the same
> second! Time skew is simply a fact of life.

I think it's even worse; if memory serves one of the Windows file systems (spit) only stores times to a two-second resolution. So half the time, waiting for one second won't change the time stamp _at all_.

Andy
-- 
Dr Andy Parkins, M Eng (hons), MIET
andyparkins@gmail.com
Marius Storm-Olsen· Jul 25, 2007, 07:43 UTC · re: Andy Parkins · lore

Re: [PATCH] Add a 1-second sleep to git-cvsexportcommit test

Andy Parkins said the following on 25.07.2007 09:35:
Show 10 quoted lines
> On Tuesday 2007 July 24, Linus Torvalds wrote:
> 
>> So if you sleep for one second, the filesystem times will update by one
>> second, but if you try to *synchronize* to exactly one second, it's not at
>> all certain that the *filesystem* clock will be synchronized to the same
>> second! Time skew is simply a fact of life.
> 
> I think it's even worse; if memory serves one of the Windows file systems 
> (spit) only stores times to a two-second resolution.  So half the time, 
> waiting for one second won't change the time stamp _at all_.

"File time stamps on FAT drives are rounded to the nearest two seconds (even number) when the file is written to the drive. The file time stamps on NTFS drives are rounded to the nearest 100 nanoseconds when the file is written to the drive."

http://support.microsoft.com/kb/127830
-- 
.marius

← back to recent threads