Re: t0027 racy?

[Jeff King]

On Thu, Aug 11, 2016 at 06:58:12PM +, Torsten Bögershausen wrote:

> commit 3754404d3d1ea4a0cbbed4986cc4ac1b5fe6b66e
> Author: Torsten Bögershausen 
> Date:   Thu Aug 11 18:47:29 2016 +0200
> 
> t0027: Correct raciness in NNO test
> 
> When a non-reversible CRLF conversion is done in "git add",
> a warning is printed on stderr.
> 
> The commit_chk_wrnNNO() function  in t0027 was written to test this,
> but did the wrong thing: Instead of looking at the warning
> from "git add", it looked at the warning from "git commit".

Maybe add:

  This is racy because "git commit" may not have to do CRLF conversion
  at all if it can use the sha1 value from the index (which depends on
  whether "add" and "commit" run in a single second).

> Thanks to Jeff King  for analizing t0027.
> Reporyed-By: Johannes Schindelin 

s/analizing/analyzing/; s/Reporyed/Reported/

> diff --git a/t/t0027-auto-crlf.sh b/t/t0027-auto-crlf.sh
> index 2860d2d..6e44382 100755
> --- a/t/t0027-auto-crlf.sh
> +++ b/t/t0027-auto-crlf.sh
> @@ -119,8 +119,7 @@ commit_chk_wrnNNO () {
>   fname=${pfx}_$f.txt &&
>   cp $f $fname &&
>   printf Z >>"$fname" &&
> - git -c core.autocrlf=$crlf add $fname 2>/dev/null &&
> - git -c core.autocrlf=$crlf commit -m "commit_$fname" $fname 
> >"${pfx}_$f.err" 2>&1
> + git -c core.autocrlf=$crlf add $fname 2>"${pfx}_$f.err"
>   done

So this is the meat of the fix.

> @@ -394,11 +393,10 @@ test_expect_success 'commit files attr=crlf' '
>  
>  # attrLFCRLF  CRLFmixLF   
> LF_mix_CR   CRLFNUL
>  commit_chk_wrnNNO ""  ""  false   """"""  "" 
>  ""
> -commit_chk_wrnNNO ""  ""  trueLF_CRLF   """"  "" 
>  ""
> +commit_chk_wrnNNO ""  ""  true""""""  "" 
>  ""
>  commit_chk_wrnNNO ""  ""  input   """"""  "" 
>  ""
> -
> -commit_chk_wrnNNO "auto"  ""  false   "$WILC"   """"  "" 
>  ""
> -commit_chk_wrnNNO "auto"  ""  trueLF_CRLF   """"  "" 
>  ""
> +commit_chk_wrnNNO "auto"  ""  false   """"""  "" 
>  ""
> +commit_chk_wrnNNO "auto"  ""  true""""""  "" 
>  ""
>  commit_chk_wrnNNO "auto"  ""  input   """"""  "" 
>  ""

I am not sure I understand why this reordering is necessary, but I guess
it's to group like things together in a single commit? Might be worth a
mention in the commit message.

-Peff
--
To unsubscribe from this list: send the line "unsubscribe git" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: t0027 racy?

[Junio C Hamano]

Torsten Bögershausen  writes:

> Good ideas, I will work on a series that fixes bugs first, and then we
> can see if there is room for optimization.
>
> What do you think about this as a starting point, more things will
> follow.
> I like to here comments about the commit msg first ;-)

Throughout t0027 there is no mention on what NNO stands for.  Are
they about operations that result in un-normalized index entries?

> commit 3754404d3d1ea4a0cbbed4986cc4ac1b5fe6b66e
> Author: Torsten Bögershausen 
> Date:   Thu Aug 11 18:47:29 2016 +0200
>
> t0027: Correct raciness in NNO test
> 
> When a non-reversible CRLF conversion is done in "git add",
> a warning is printed on stderr.
> 
> The commit_chk_wrnNNO() function  in t0027 was written to test this,
> but did the wrong thing: Instead of looking at the warning
> from "git add", it looked at the warning from "git commit".
> 
> Correct this and replace the commit for each and every file with a commit
> of all files in one go.
> 
> The function commit_chk_wrnNNO() will to be renamed in a separate commit.
> Thanks to Jeff King  for analizing t0027.
> Reporyed-By: Johannes Schindelin 

Reporyed?  

An obligatory "comments-about-the-commit-msg";-)
--
To unsubscribe from this list: send the line "unsubscribe git" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: t0027 racy?

[Torsten Bögershausen]

[]
> FWIW I would strongly prefer to use the warning of `git add` and not even
> bother with `git commit`. What we are interested in is the warning
> message, generated by convert_to_git(). 
The commit is needed, because we check the content of the commit later.
> Not using the first one and
[]
> 
> On that matter, I wonder whether there would be a chance to revamp t0027
> in a major way, with the following goals:
> 
> - to make it very obvious to the casual reader what is being tested
> 
> - to combine Git invocations when possible, e.g. running one big `git add`
>   on a couple of files and then verify the relevant parts of the output
> 
> - dramatically decreasing the time required to run the test, without
>   sacrificing correctness (I would wager a bet that not only a few of
>   those 1388 test cases essentially exercise identical code paths)
Good ideas, I will work on a series that fixes bugs first, and then we
can see if there is room for optimization.

What do you think about this as a starting point,
more things will follow.
I like to here comments about the commit msg first ;-)

commit 3754404d3d1ea4a0cbbed4986cc4ac1b5fe6b66e
Author: Torsten Bögershausen 
Date:   Thu Aug 11 18:47:29 2016 +0200

t0027: Correct raciness in NNO test

When a non-reversible CRLF conversion is done in "git add",
a warning is printed on stderr.

The commit_chk_wrnNNO() function  in t0027 was written to test this,
but did the wrong thing: Instead of looking at the warning
from "git add", it looked at the warning from "git commit".

Correct this and replace the commit for each and every file with a commit
of all files in one go.

The function commit_chk_wrnNNO() will to be renamed in a separate commit.
Thanks to Jeff King  for analizing t0027.
Reporyed-By: Johannes Schindelin 

diff --git a/t/t0027-auto-crlf.sh b/t/t0027-auto-crlf.sh
index 2860d2d..6e44382 100755
--- a/t/t0027-auto-crlf.sh
+++ b/t/t0027-auto-crlf.sh
@@ -119,8 +119,7 @@ commit_chk_wrnNNO () {
fname=${pfx}_$f.txt &&
cp $f $fname &&
printf Z >>"$fname" &&
-   git -c core.autocrlf=$crlf add $fname 2>/dev/null &&
-   git -c core.autocrlf=$crlf commit -m "commit_$fname" $fname 
>"${pfx}_$f.err" 2>&1
+   git -c core.autocrlf=$crlf add $fname 2>"${pfx}_$f.err"
done
 
test_expect_success "commit NNO files crlf=$crlf attr=$attr LF" '
@@ -394,11 +393,10 @@ test_expect_success 'commit files attr=crlf' '
 
 # attrLFCRLF  CRLFmixLF   
LF_mix_CR   CRLFNUL
 commit_chk_wrnNNO ""  ""  false   """"""  ""   
   ""
-commit_chk_wrnNNO ""  ""  trueLF_CRLF   """"  ""   
   ""
+commit_chk_wrnNNO ""  ""  true""""""  ""   
   ""
 commit_chk_wrnNNO ""  ""  input   """"""  ""   
   ""
-
-commit_chk_wrnNNO "auto"  ""  false   "$WILC"   """"  ""   
   ""
-commit_chk_wrnNNO "auto"  ""  trueLF_CRLF   """"  ""   
   ""
+commit_chk_wrnNNO "auto"  ""  false   """"""  ""   
   ""
+commit_chk_wrnNNO "auto"  ""  true""""""  ""   
   ""
 commit_chk_wrnNNO "auto"  ""  input   """"""  ""   
   ""
 for crlf in true false input
 do
@@ -408,7 +406,7 @@ do
commit_chk_wrnNNO ""lf  $crlf   ""   CRLF_LFCRLF_LF 
 "" CRLF_LF
commit_chk_wrnNNO ""crlf$crlf   LF_CRLF   ""LF_CRLF 
LF_CRLF ""
commit_chk_wrnNNO auto  lf  $crlf   """"""  
""  ""
-   commit_chk_wrnNNO auto  crlf$crlf   LF_CRLF   """"  
""  ""
+   commit_chk_wrnNNO auto  crlf$crlf   """"""  
""  ""
commit_chk_wrnNNO text  lf  $crlf   ""   CRLF_LFCRLF_LF 
""  CRLF_LF
commit_chk_wrnNNO text  crlf$crlf   LF_CRLF   ""LF_CRLF 
LF_CRLF ""
 done
@@ -417,7 +415,8 @@ commit_chk_wrnNNO "text"  ""  false   "$WILC"   "$WICL" 
  "$WAMIX""$WILC
 commit_chk_wrnNNO "text"  ""  trueLF_CRLF   ""LF_CRLF 
LF_CRLF ""
 commit_chk_wrnNNO "text"  ""  input   ""CRLF_LF   CRLF_LF ""   
   CRLF_LF
 
-test_expect_success 'create files cleanup' '
+test_expect_success 'commit NNO and cleanup' '
+   git commit -m "commit files on top of NNO" &&
rm -f *.txt &&
git -c core.autocrlf=false reset --hard
 '
--
To unsubscribe from this list: send the line "unsubscribe git" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: t0027 racy?

[Johannes Schindelin]

Hi Torsten,

On Tue, 9 Aug 2016, Torsten Bögershausen wrote:

> >   git -c core.autocrlf=$crlf add $fname >"${pfx}_$f.err" 2>&1
> > 
> > would make more sense. We _know_ that we have to do convert_to_git() in
> > that step because the content is changed. And then you can ignore the
> > warnings from "git commit" (which are racy), or you can simply commit as
> > a whole later, as some other loops do.
> > 
> > But like Dscho, I do not actually understand what this test is checking.
> > The function is called commit_chk_wrnNNO(), so perhaps you really are
> > interested in what "commit" has to say. But IMHO that is not an
> > interesting test. We know that if it has to read the content from disk,
> > it will call convert_to_git(), which is the exact same code path used by
> > "git add". So I do not understand what it is accomplishing to make a
> > commit at all here.
> 
> It seems as if the test has been written without understanding the raciness.
> It should commit files with different line endings on top of
> a file with mixed line endings.
> The warning should be checked (and here "git add" can be used,
> or the file can be commited directly).
> I'm not sure why the test ended up in doing both.
> 
> However, doing it the right way triggers a bug in convert.c,
> (some warnings are missing, so I need some days to come up
> with a proper patch)

FWIW I would strongly prefer to use the warning of `git add` and not even
bother with `git commit`. What we are interested in is the warning
message, generated by convert_to_git(). Not using the first one and
triggering a second one merely adds unnecessary churn that increases the
CO2 budget of running the test.

On that matter, I wonder whether there would be a chance to revamp t0027
in a major way, with the following goals:

- to make it very obvious to the casual reader what is being tested

- to combine Git invocations when possible, e.g. running one big `git add`
  on a couple of files and then verify the relevant parts of the output

- dramatically decreasing the time required to run the test, without
  sacrificing correctness (I would wager a bet that not only a few of
  those 1388 test cases essentially exercise identical code paths)

Ciao,
Dscho

Re: t0027 racy?

[Torsten Bögershausen]

>   git -c core.autocrlf=$crlf add $fname >"${pfx}_$f.err" 2>&1
> 
> would make more sense. We _know_ that we have to do convert_to_git() in
> that step because the content is changed. And then you can ignore the
> warnings from "git commit" (which are racy), or you can simply commit as
> a whole later, as some other loops do.
> 
> But like Dscho, I do not actually understand what this test is checking.
> The function is called commit_chk_wrnNNO(), so perhaps you really are
> interested in what "commit" has to say. But IMHO that is not an
> interesting test. We know that if it has to read the content from disk,
> it will call convert_to_git(), which is the exact same code path used by
> "git add". So I do not understand what it is accomplishing to make a
> commit at all here.

It seems as if the test has been written without understanding the raciness.
It should commit files with different line endings on top of
a file with mixed line endings.
The warning should be checked (and here "git add" can be used,
or the file can be commited directly).
I'm not sure why the test ended up in doing both.

However, doing it the right way triggers a bug in convert.c,
(some warnings are missing, so I need some days to come up
with a proper patch)

Thanks for reporting & digging.
--
To unsubscribe from this list: send the line "unsubscribe git" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: t0027 racy?

[Jeff King]

On Tue, Aug 09, 2016 at 12:59:58PM +, Torsten Bögershausen wrote:

> Thanks for the explanation, so there are 2 chances for a race.
> 
> I assume that the suggested "touch" will fix race#2 in most cases.
> In my understanding, the change of the file size will be more reliable:
>  
> 
> diff --git a/t/t0027-auto-crlf.sh b/t/t0027-auto-crlf.sh
> index 2860d2d..9933a9b 100755
> --- a/t/t0027-auto-crlf.sh
> +++ b/t/t0027-auto-crlf.sh
> @@ -120,6 +120,7 @@ commit_chk_wrnNNO () {
> cp $f $fname &&
> printf Z >>"$fname" &&
> git -c core.autocrlf=$crlf add $fname 2>/dev/null &&
> +   printf Z >>"$fname" &&
> git -c core.autocrlf=$crlf commit -m "commit_$fname" $fname 
> >"${pfx}_$f.err" 2>&1
> done
> ---
> Does anybody agree ?

I think the mtime change is reliable. We know that the mtime on the file
will be greater than or equal to the index mtime (because it happened
afterwards), so git will always look at the on-disk contents.

With your change, "git commit" will also always re-read the file from
disk, because it actually has new content (and you provide the filename
on the command line, so it is stage-and-commit, not just
"commit-the-index").

So either is fine.

> And, by the way, the convert warning may be issued twice, once in
> "git add" and once in "git commit".

Yes, but you only save it from "git commit", so we can ignore what
happens from "add" here. But that's why I wondered if:

  git -c core.autocrlf=$crlf add $fname >"${pfx}_$f.err" 2>&1

would make more sense. We _know_ that we have to do convert_to_git() in
that step because the content is changed. And then you can ignore the
warnings from "git commit" (which are racy), or you can simply commit as
a whole later, as some other loops do.

But like Dscho, I do not actually understand what this test is checking.
The function is called commit_chk_wrnNNO(), so perhaps you really are
interested in what "commit" has to say. But IMHO that is not an
interesting test. We know that if it has to read the content from disk,
it will call convert_to_git(), which is the exact same code path used by
"git add". So I do not understand what it is accomplishing to make a
commit at all here.

-Peff
--
To unsubscribe from this list: send the line "unsubscribe git" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: t0027 racy?

[Torsten Bögershausen]

On Tue, Aug 09, 2016 at 07:49:38AM -0400, Jeff King wrote:
> On Tue, Aug 09, 2016 at 11:33:37AM +, Torsten Bögershausen wrote:
> 
> > > The second one seems plausible, given the history of issues with
> > > changing CRLF settings for an existing checkout. I'm not sure if it
> > > would be feasible to reset the index completely before each tested
> > > command, but that would probably solve it.
> > The content of the file has been changed (we appended the letter 'Z' to it,
> > so even if mtime is the same, st.st_size should differ.
> > And it seems as if the commit is triggered, see below.
> 
> I don't think I made myself clear. It's not a question of whether there
> is something to commit. It's that when git asks the index "what is the
> sha1 of the content at this path?", the index may be able to answer
> directly (the file is up-to-date, so we return the index value), or it
> may have to go to the filesystem and read the file content. It is this
> latter which triggers convert_to_git(), which is what generates the
> message in question.
> 
> For a more stripped-down example, try:
> 
>   git add foo
>   git commit -m msg
> 
> versus:
> 
>   git add foo
>   sleep 1
>   git commit -m msg
> 
> In the latter case, we should not generally need convert_to_git() in the
> "commit" step. It was already done by "git add", and we reuse the cached
> result.
> 
> Whereas in the first one, we may run into the racy-index problem and
> have to re-read the file to be on the safe side.
> 
> -Peff

Thanks for the explanation, so there are 2 chances for a race.

I assume that the suggested "touch" will fix race#2 in most cases.
In my understanding, the change of the file size will be more reliable:
 

diff --git a/t/t0027-auto-crlf.sh b/t/t0027-auto-crlf.sh
index 2860d2d..9933a9b 100755
--- a/t/t0027-auto-crlf.sh
+++ b/t/t0027-auto-crlf.sh
@@ -120,6 +120,7 @@ commit_chk_wrnNNO () {
cp $f $fname &&
printf Z >>"$fname" &&
git -c core.autocrlf=$crlf add $fname 2>/dev/null &&
+   printf Z >>"$fname" &&
git -c core.autocrlf=$crlf commit -m "commit_$fname" $fname 
>"${pfx}_$f.err" 2>&1
done
---
Does anybody agree ?
And, by the way, the convert warning may be issued twice, once in
"git add" and once in "git commit".
--
To unsubscribe from this list: send the line "unsubscribe git" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: t0027 racy?

[Jeff King]

On Tue, Aug 09, 2016 at 11:33:37AM +, Torsten Bögershausen wrote:

> > The second one seems plausible, given the history of issues with
> > changing CRLF settings for an existing checkout. I'm not sure if it
> > would be feasible to reset the index completely before each tested
> > command, but that would probably solve it.
> The content of the file has been changed (we appended the letter 'Z' to it,
> so even if mtime is the same, st.st_size should differ.
> And it seems as if the commit is triggered, see below.

I don't think I made myself clear. It's not a question of whether there
is something to commit. It's that when git asks the index "what is the
sha1 of the content at this path?", the index may be able to answer
directly (the file is up-to-date, so we return the index value), or it
may have to go to the filesystem and read the file content. It is this
latter which triggers convert_to_git(), which is what generates the
message in question.

For a more stripped-down example, try:

  git add foo
  git commit -m msg

versus:

  git add foo
  sleep 1
  git commit -m msg

In the latter case, we should not generally need convert_to_git() in the
"commit" step. It was already done by "git add", and we reuse the cached
result.

Whereas in the first one, we may run into the racy-index problem and
have to re-read the file to be on the safe side.

-Peff
--
To unsubscribe from this list: send the line "unsubscribe git" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: t0027 racy?

[Jeff King]

On Tue, Aug 09, 2016 at 01:33:04PM +0200, Johannes Schindelin wrote:

> On Mon, 8 Aug 2016, Jeff King wrote:
> 
> > I got failure within about 30 seconds on t0027 (though 5 minutes? Yeesh.
> > It runs in 9s on my laptop. I weep for you).
> 
> Yep. That is the price I (and all other Git for Windows developers) pay
> for the decision to implement Git's entire test suite in Shell script,
> including expensive tests with over a 1,000 test cases such as t0027.

To be fair, it does not run unless you set GIT_TEST_LONG. Even _I_ don't
do that by default.

-Peff
--
To unsubscribe from this list: send the line "unsubscribe git" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: t0027 racy?

[Johannes Schindelin]

Hi Peff,

On Mon, 8 Aug 2016, Jeff King wrote:

> I got failure within about 30 seconds on t0027 (though 5 minutes? Yeesh.
> It runs in 9s on my laptop. I weep for you).

Yep. That is the price I (and all other Git for Windows developers) pay
for the decision to implement Git's entire test suite in Shell script,
including expensive tests with over a 1,000 test cases such as t0027.

Ciao,
Dscho
--
To unsubscribe from this list: send the line "unsubscribe git" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: t0027 racy?

[Torsten Bögershausen]

On Tue, Aug 09, 2016 at 02:51:10AM -0400, Jeff King wrote:
> On Mon, Aug 08, 2016 at 08:32:24PM +, Torsten Bögershausen wrote:
> 
> > > The verbose output is not very exciting, though:
> > > 
> > >   expecting success: 
> > >   check_warning "$lfwarn" ${pfx}_LF.err
> > > 
> > >   --- NNO_attr_auto_aeol_crlf_false_LF.err.expect 2016-08-08 
> > > 15:26:37.061701392 +
> > >   +++ NNO_attr_auto_aeol_crlf_false_LF.err.actual 2016-08-08 
> > > 15:26:37.061701392 +
> > >   @@ -1 +0,0 @@
> > >   -warning: LF will be replaced by CRLF
> > >   not ok 114 - commit NNO files crlf=false attr=auto LF
> > [...]
> > The warning is missing, but should be there:
> > 
> > The file has LF, and after commit and a new checkout these LF will
> > be convertet into CRLF.
> > 
> > So why isn't the warning there (but here on my oldish machines)
> 
> To be clear, the warning _is_ there when I just run t0027 by itself, and
> the test passes.  It's only under heavy load that it isn't. So it's a
> race condition either in the test script or in git itself.
> 
> Usually race conditions like these are due to one of:
> 
>   - git dying from SIGPIPE before it has a chance to output the command.
> But I don't see any pipes being used in the test script.
> 
>   - index raciness causing us to avoid reading file content. For
> example, if you do:
> 
>   echo foo >bar
>   git add bar
> 
> Then _usually_ "bar" and the index will have the same mtime. And
> therefore subsequent commands that need to refresh the index will
> re-read the content of "bar", because they cannot tell from the stat
> information if we have the latest version of "bar" in the index or
> not (it could have been written after the index update, but in the
> same second).
> 
> But on a slow or heavily loaded system (or if you simply get unlucky
> in crossing the boundary to a new second), they'll have different
> mtimes. And therefore git knows it can skip reading the content from
> the filesystem.
> 
> So if your test relies on git actually re-converting the file
> content, it would sometimes randomly fail.
> 
> The second one seems plausible, given the history of issues with
> changing CRLF settings for an existing checkout. I'm not sure if it
> would be feasible to reset the index completely before each tested
> command, but that would probably solve it.
The content of the file has been changed (we appended the letter 'Z' to it,
so even if mtime is the same, st.st_size should differ.
And it seems as if the commit is triggered, see below.
> 

(I got the stress script working; no I can reproduce it nicely)

Is it possible to vote for a 3rd option ?
I added some more warnings, to have always some output in stderr. 

This is the good case, this test case passed:
cat NNO_attr_auto_aeol_crlf_true_LF.err 

warning: check_safe_crlf in NNO_attr_auto_aeol_crlf_true_LF.txt 2
warning: LF was here in NNO_attr_auto_aeol_crlf_true_LF.txt..
warning: LF will be replaced by CRLF in NNO_attr_auto_aeol_crlf_true_LF.txt.
The file will have its original line endings in your working directory.
warning: check_safe_crlf in NNO_attr__aeol_crlf_true_CRLF.txt 0
warning: check_safe_crlf in NNO_attr__aeol_crlf_true_CRLF_mix_LF.txt 0
warning: check_safe_crlf in NNO_attr__aeol_crlf_true_LF.txt 0
warning: check_safe_crlf in NNO_attr__aeol_lf_true_CRLF.txt 0
warning: check_safe_crlf in NNO_attr__aeol_lf_true_CRLF_mix_LF.txt 0
warning: check_safe_crlf in NNO_attr__aeol_lf_true_LF.txt 0
warning: check_safe_crlf in NNO_attr_auto_aeol_lf_true_LF.txt 0
[master 2decee0] commit_NNO_attr_auto_aeol_crlf_true_LF.txt
 Author: A U Thor 
 1 file changed, 2 insertions(+), 2 deletions(-)
---
And this one failed, the same code base, but a different file:
cat commit_NNO_attr_auto_aeol_crlf_input_LF.

[master ce2045a] commit_NNO_attr_auto_aeol_crlf_input_LF.txt
 Author: A U Thor 
 1 file changed, 2 insertions(+), 2 deletions(-)

---
Both had been generated with a patched convert.c:
git diff convert.c
index 67d69b5..ae64a58 100644
--- a/convert.c
+++ b/convert.c
@@ -191,6 +191,7 @@ static enum eol output_eol(enum crlf_action crlf_action)
 static void check_safe_crlf(const char *path, enum crlf_action crlf_action,
 struct text_stat *stats, enum safe_crlf checksafe)
 {
+   warning("check_safe_crlf in %s %d", path, (int)checksafe);
if (!checksafe)
return;
 
@@ -210,6 +211,7 @@ static void check_safe_crlf(const char *path, enum 
crlf_action crlf_action,
 * CRLFs would be added by checkout:
 * check if we have "naked" LFs
 */
+   warning("LF was here in %s..", path);
if (stats->lonelf) {
if (checksafe == SAFE_CRLF_WARN)
warning("LF will be replaced by CRLF in %s.\nThe

Re: t0027 racy?

[Johannes Schindelin]

Hi Peff,

On Tue, 9 Aug 2016, Jeff King wrote:

> And indeed, this seems to fix it for me (at least it has been running in
> a 16-way loop for 5 minutes, whereas before it died after 30 seconds or
> so):
> 
> diff --git a/t/t0027-auto-crlf.sh b/t/t0027-auto-crlf.sh
> index 2860d2d..9f057ff 100755
> --- a/t/t0027-auto-crlf.sh
> +++ b/t/t0027-auto-crlf.sh
> @@ -120,6 +120,7 @@ commit_chk_wrnNNO () {
>   cp $f $fname &&
>   printf Z >>"$fname" &&
>   git -c core.autocrlf=$crlf add $fname 2>/dev/null &&
> + touch $fname && # ensure index raciness
>   git -c core.autocrlf=$crlf commit -m "commit_$fname" $fname 
> >"${pfx}_$f.err" 2>&1
>   done

I will test this patch as soon as my poor machine has less work.

> I'm not sure if there is a more elegant solution, though (for instance,
> why not collect the output from "git add", which should have the same
> warning, I would think).

That should work, too. I am a bit overwhelmed with t0027, though, I do not
really understand what is going on. It tests *so many* things, and in no
test case is it clear to me what it tests and what it expects let alone
why those expectations make sense.

Ciao,
Dscho
--
To unsubscribe from this list: send the line "unsubscribe git" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: t0027 racy?

[Johannes Schindelin]

Hi Torsten,

On Mon, 8 Aug 2016, Torsten Bögershausen wrote:

> On 2016-08-08 17.05, Johannes Schindelin wrote:
> > 
> > I remember that you did a ton of work on t0027. Now I see problems,
> > and not only that the entire script now takes a whopping 4 minutes 20
> > seconds to run on my high-end Windows machine.
> > 
> > It appears that t0027 fails randomly for me, in seemingly random
> > places.  Sometimes all 1388 cases pass. Sometimes "29 - commit NNO
> > files crlf=true attr=auto LF" fails. Sometimes it is "24 - commit NNO
> > files crlf=false attr=auto LF". Sometimes it is "114 - commit NNO
> > files crlf=false attr=auto LF", and sometimes "111 - commit NNO files
> > attr=auto aeol=lf crlf=false CRLF_mix_LF".
> > 
> > When I run it with -i -v -x --tee, it passes every single time (taking
> > over 5 minutes, just to make things worse)...
> > 
> > Any idea about any possible races?
>
> Just to double-check: I assume that you have this
> commit ded2444ad8ab8128cae2b91b8efa57ea2dd8c7a5
> Author: Torsten Bögershausen 
> Date:   Mon Apr 25 18:56:27 2016 +0200
> 
> t0027: make commit_chk_wrnNNO() reliable
> in your tree ?

I tested this with multiple branches, but yes, the one I tested most was
the shears/pu branch of git-for-windows/git (which has all
Windows-specific patches of our master branch rebased on top of pu). I
also tested with the pu branch as of yesterday.

> Is there a special pattern ?

No. Just "make -j15 DEVELOPER=1 -k test".

> Did you
> a) Update the machine ?

Yep, it's up-to-date. Windows 10 Anniversary Update.

> b) Update Git code base ?

As I said, several.

> Is it only the NNO tests that fail ?

As I said, the failures are random, I just picked the 4 most recent ones.

> Did they ever pass ?

As I said, if I run with -i -v -x --tee, everything passes.

> I see only "commit NNO files" in you report, they belong to
> check_warning(), which is called around line 126 in t0027.

I believe this is true. Some race, probably, leading to the commit *not*
refreshing the files. Or some such, this is just a guess on my side.

> How reproducible is the problem ?

Not very. That is, about half of the time t0027 passes even *without* -i
-v -x --tee. And when it fails, it is anybody's guess which case fails.

> If you add
> exit 0
> After the last "commit_chk_wrnNNO" line (line 418),
> does
> ls -l crlf*.err
> give you any hint ?

No. It simply does not contain that warning that is expected.

Ciao,
Dscho

Re: t0027 racy?

[Jeff King]

On Tue, Aug 09, 2016 at 02:51:10AM -0400, Jeff King wrote:

>   - index raciness causing us to avoid reading file content. For
> example, if you do:
> 
>   echo foo >bar
>   git add bar
> 
> Then _usually_ "bar" and the index will have the same mtime. And
> therefore subsequent commands that need to refresh the index will
> re-read the content of "bar", because they cannot tell from the stat
> information if we have the latest version of "bar" in the index or
> not (it could have been written after the index update, but in the
> same second).
> 
> But on a slow or heavily loaded system (or if you simply get unlucky
> in crossing the boundary to a new second), they'll have different
> mtimes. And therefore git knows it can skip reading the content from
> the filesystem.
> 
> So if your test relies on git actually re-converting the file
> content, it would sometimes randomly fail.
> 
> The second one seems plausible, given the history of issues with
> changing CRLF settings for an existing checkout. I'm not sure if it
> would be feasible to reset the index completely before each tested
> command, but that would probably solve it.

And indeed, this seems to fix it for me (at least it has been running in
a 16-way loop for 5 minutes, whereas before it died after 30 seconds or
so):

diff --git a/t/t0027-auto-crlf.sh b/t/t0027-auto-crlf.sh
index 2860d2d..9f057ff 100755
--- a/t/t0027-auto-crlf.sh
+++ b/t/t0027-auto-crlf.sh
@@ -120,6 +120,7 @@ commit_chk_wrnNNO () {
cp $f $fname &&
printf Z >>"$fname" &&
git -c core.autocrlf=$crlf add $fname 2>/dev/null &&
+   touch $fname && # ensure index raciness
git -c core.autocrlf=$crlf commit -m "commit_$fname" $fname 
>"${pfx}_$f.err" 2>&1
done
 

I'm not sure if there is a more elegant solution, though (for instance,
why not collect the output from "git add", which should have the same
warning, I would think).

-Peff
--
To unsubscribe from this list: send the line "unsubscribe git" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: t0027 racy?

[Jeff King]

On Mon, Aug 08, 2016 at 08:32:24PM +, Torsten Bögershausen wrote:

> > The verbose output is not very exciting, though:
> > 
> > expecting success: 
> > check_warning "$lfwarn" ${pfx}_LF.err
> > 
> > --- NNO_attr_auto_aeol_crlf_false_LF.err.expect 2016-08-08 
> > 15:26:37.061701392 +
> > +++ NNO_attr_auto_aeol_crlf_false_LF.err.actual 2016-08-08 
> > 15:26:37.061701392 +
> > @@ -1 +0,0 @@
> > -warning: LF will be replaced by CRLF
> > not ok 114 - commit NNO files crlf=false attr=auto LF
> [...]
> The warning is missing, but should be there:
> 
> The file has LF, and after commit and a new checkout these LF will
> be convertet into CRLF.
> 
> So why isn't the warning there (but here on my oldish machines)

To be clear, the warning _is_ there when I just run t0027 by itself, and
the test passes.  It's only under heavy load that it isn't. So it's a
race condition either in the test script or in git itself.

Usually race conditions like these are due to one of:

  - git dying from SIGPIPE before it has a chance to output the command.
But I don't see any pipes being used in the test script.

  - index raciness causing us to avoid reading file content. For
example, if you do:

  echo foo >bar
  git add bar

Then _usually_ "bar" and the index will have the same mtime. And
therefore subsequent commands that need to refresh the index will
re-read the content of "bar", because they cannot tell from the stat
information if we have the latest version of "bar" in the index or
not (it could have been written after the index update, but in the
same second).

But on a slow or heavily loaded system (or if you simply get unlucky
in crossing the boundary to a new second), they'll have different
mtimes. And therefore git knows it can skip reading the content from
the filesystem.

So if your test relies on git actually re-converting the file
content, it would sometimes randomly fail.

The second one seems plausible, given the history of issues with
changing CRLF settings for an existing checkout. I'm not sure if it
would be feasible to reset the index completely before each tested
command, but that would probably solve it.

-Peff
--
To unsubscribe from this list: send the line "unsubscribe git" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: t0027 racy?

[Torsten Bögershausen]

On Mon, Aug 08, 2016 at 11:29:26AM -0400, Jeff King wrote:
> On Mon, Aug 08, 2016 at 05:05:07PM +0200, Johannes Schindelin wrote:
> 
> > I remember that you did a ton of work on t0027. Now I see problems, and
> > not only that the entire script now takes a whopping 4 minutes 20 seconds
> > to run on my high-end Windows machine.
> > 
> > It appears that t0027 fails randomly for me, in seemingly random places.
> > Sometimes all 1388 cases pass. Sometimes "29 - commit NNO files crlf=true
> > attr=auto LF" fails. Sometimes it is "24 - commit NNO files crlf=false
> > attr=auto LF". Sometimes it is "114 - commit NNO files crlf=false
> > attr=auto LF", and sometimes "111 - commit NNO files attr=auto aeol=lf
> > crlf=false CRLF_mix_LF".
> > 
> > When I run it with -i -v -x --tee, it passes every single time (taking
> > over 5 minutes, just to make things worse)...
> > 
> > Any idea about any possible races?
> 
> Try:
> 
>   https://github.com/peff/git/blob/meta/stress
> 
> which you can run as "sh /path/to/stress t0027" in the top-level of your
> git repository. I got failure within about 30 seconds on t0027 (though 5
> minutes? Yeesh. It runs in 9s on my laptop. I weep for you).
> 
> The verbose output is not very exciting, though:
> 
>   expecting success: 
>   check_warning "$lfwarn" ${pfx}_LF.err
> 
>   --- NNO_attr_auto_aeol_crlf_false_LF.err.expect 2016-08-08 
> 15:26:37.061701392 +
>   +++ NNO_attr_auto_aeol_crlf_false_LF.err.actual 2016-08-08 
> 15:26:37.061701392 +
>   @@ -1 +0,0 @@
>   -warning: LF will be replaced by CRLF
>   not ok 114 - commit NNO files crlf=false attr=auto LF

(I realized that t0027 is not yet self-explaining, I have it on my list)

NNO_attr_auto_aeol_crlf_false_LF means:

NNO:   "Not NOrmalized" A file had been commited with CRLF in the repo
attr_auto: .gitattributes has "* text=auto"
aeol_eol   .gitattributes has "eol=crlf"
crlf_false git config core.autocrlf = false
LF We commit a file with LF line endings.

This should happend:
- The file is commited "as is", with LF line endings.
- While commiting, git should print the warning
- "warning: LF will be replaced by CRLF" to stderr
- stderr is piped (redirected) into NNO_attr_auto_aeol_crlf_false_LF.err
- we grep for "will be replaced by" in xx.err and pipe it into xx.err.actual

The rest is test_cmp, this is what you see.
The warning is missing, but should be there:

The file has LF, and after commit and a new checkout these LF will
be convertet into CRLF.

So why isn't the warning there (but here on my oldish machines)
--
To unsubscribe from this list: send the line "unsubscribe git" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: t0027 racy?

[Torsten Bögershausen]

On 2016-08-08 17.05, Johannes Schindelin wrote:
> Hi Torsten,
> 
> I remember that you did a ton of work on t0027. Now I see problems, and
> not only that the entire script now takes a whopping 4 minutes 20 seconds
> to run on my high-end Windows machine.
> 
> It appears that t0027 fails randomly for me, in seemingly random places.
> Sometimes all 1388 cases pass. Sometimes "29 - commit NNO files crlf=true
> attr=auto LF" fails. Sometimes it is "24 - commit NNO files crlf=false
> attr=auto LF". Sometimes it is "114 - commit NNO files crlf=false
> attr=auto LF", and sometimes "111 - commit NNO files attr=auto aeol=lf
> crlf=false CRLF_mix_LF".
> 
> When I run it with -i -v -x --tee, it passes every single time (taking
> over 5 minutes, just to make things worse)...
> 
> Any idea about any possible races?
Just to double-check: I assume that you have this
commit ded2444ad8ab8128cae2b91b8efa57ea2dd8c7a5
Author: Torsten Bögershausen 
Date:   Mon Apr 25 18:56:27 2016 +0200

t0027: make commit_chk_wrnNNO() reliable
in your tree ?


Is there a special pattern ?
Did you
a) Update the machine ?
b) Update Git code base ?
or both ?
(Yes, I know that this may be stupid questions)

Is it only the NNO tests that fail ?
Did they ever pass ?
(I think I run them some time ago on a Virtual machine running Windows 7)

I see only "commit NNO files" in you report, they belong to
check_warning(), which is called around line 126 in t0027.


check_warning() does a grep on a file which has been re-directed from stderr.

How reproducible is the problem ?
If you add
exit 0
After the last "commit_chk_wrnNNO" line (line 418),
does
ls -l crlf*.err
give you any hint ?




--
To unsubscribe from this list: send the line "unsubscribe git" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: t0027 racy?

[Jeff King]

On Mon, Aug 08, 2016 at 05:05:07PM +0200, Johannes Schindelin wrote:

> I remember that you did a ton of work on t0027. Now I see problems, and
> not only that the entire script now takes a whopping 4 minutes 20 seconds
> to run on my high-end Windows machine.
> 
> It appears that t0027 fails randomly for me, in seemingly random places.
> Sometimes all 1388 cases pass. Sometimes "29 - commit NNO files crlf=true
> attr=auto LF" fails. Sometimes it is "24 - commit NNO files crlf=false
> attr=auto LF". Sometimes it is "114 - commit NNO files crlf=false
> attr=auto LF", and sometimes "111 - commit NNO files attr=auto aeol=lf
> crlf=false CRLF_mix_LF".
> 
> When I run it with -i -v -x --tee, it passes every single time (taking
> over 5 minutes, just to make things worse)...
> 
> Any idea about any possible races?

Try:

  https://github.com/peff/git/blob/meta/stress

which you can run as "sh /path/to/stress t0027" in the top-level of your
git repository. I got failure within about 30 seconds on t0027 (though 5
minutes? Yeesh. It runs in 9s on my laptop. I weep for you).

The verbose output is not very exciting, though:

expecting success: 
check_warning "$lfwarn" ${pfx}_LF.err

--- NNO_attr_auto_aeol_crlf_false_LF.err.expect 2016-08-08 
15:26:37.061701392 +
+++ NNO_attr_auto_aeol_crlf_false_LF.err.actual 2016-08-08 
15:26:37.061701392 +
@@ -1 +0,0 @@
-warning: LF will be replaced by CRLF
not ok 114 - commit NNO files crlf=false attr=auto LF

-Peff
--
To unsubscribe from this list: send the line "unsubscribe git" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

t0027 racy?

[Johannes Schindelin]

Hi Torsten,

I remember that you did a ton of work on t0027. Now I see problems, and
not only that the entire script now takes a whopping 4 minutes 20 seconds
to run on my high-end Windows machine.

It appears that t0027 fails randomly for me, in seemingly random places.
Sometimes all 1388 cases pass. Sometimes "29 - commit NNO files crlf=true
attr=auto LF" fails. Sometimes it is "24 - commit NNO files crlf=false
attr=auto LF". Sometimes it is "114 - commit NNO files crlf=false
attr=auto LF", and sometimes "111 - commit NNO files attr=auto aeol=lf
crlf=false CRLF_mix_LF".

When I run it with -i -v -x --tee, it passes every single time (taking
over 5 minutes, just to make things worse)...

Any idea about any possible races?

Ciao,
Dscho
--
To unsubscribe from this list: send the line "unsubscribe git" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html