Test #7 in t9200-git-cvsexportcommit fails

Test #7 in t9200-git-cvsexportcommit fails

[Jason Sewall]

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.

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

[Alex Riesen]

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.

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

[Jason Sewall]

> 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

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

[Alex Riesen]

Jason Sewall, Sun, Jul 22, 2007 22:49:19 +0200:
> >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

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

[Junio C Hamano]

"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?

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

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

[Jason Sewall]

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

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

[Junio C Hamano]

Jason Sewall <jasonsewall@gmail.com> writes:

> 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
       )'

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

[Simon 'corecode' Schubert]

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

-- 
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   / \

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

[Robin Rosenberg]

måndag 23 juli 2007 skrev Simon 'corecode' Schubert:
> 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

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

[Simon 'corecode' Schubert]

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?

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   / \

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

[Robin Rosenberg]

tisdag 24 juli 2007 skrev Simon 'corecode' Schubert:
> 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

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

[Simon 'corecode' Schubert]

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.

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   / \

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

[Robin Rosenberg]

tisdag 24 juli 2007 skrev Simon 'corecode' Schubert:
> 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

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

[Junio C Hamano]

Robin Rosenberg <robin.rosenberg.lists@dewire.com> writes:

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

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

[Robin Rosenberg]

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

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

[Jason Sewall]

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

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

[Linus Torvalds]

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.

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

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

[Robin Rosenberg]

tisdag 24 juli 2007 skrev Linus Torvalds:
> 
> 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

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

[Linus Torvalds]

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

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

[Andy Parkins]

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

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

[Marius Storm-Olsen]

[-- Attachment #1: Type: text/plain, Size: 922 bytes --]

Andy Parkins said the following on 25.07.2007 09:35:
> 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


[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 187 bytes --]