[PATCH jk/pkt-line-cleanup] t5700-clone-reference: send trace to fd 2, not 3, to please Windows git

From: Johannes Sixt <redacted>

Two tests use GIT_TRACE=3 to dump debugging information of git. On
Windows, however, bash is unable to set up file descriptor 3 correctly
for its child process, so that git reports "Bad file descriptor" on
every trace attempt. The 'git clone' test succeeds nevertheless because
an empty trace file remains, and there is only a check for the
absence of a particular line. But the 'git fetch' process ultimately
hangs (the dynamics that lead to this surprising result have not been
investigated).

Since we do not otherwise use stderr in the test cases, divert the
trace dump to stderr.

Signed-off-by: Johannes Sixt <redacted>
---
 This fixes a regression introduced in 

 t/t5700-clone-reference.sh | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/t/t5700-clone-reference.sh b/t/t5700-clone-reference.sh
index 9cd3b4d..8b5c58e 100755
--- a/t/t5700-clone-reference.sh
+++ b/t/t5700-clone-reference.sh

@@ -55,7 +55,7 @@ cd "$base_dir"
 rm -f "$U.D"
 
 test_expect_success 'cloning with reference (no -l -s)' \
-'GIT_TRACE_PACKET=3 git clone --reference B "file://$(pwd)/A" D 3>"$U.D"'
+'GIT_TRACE_PACKET=2 git clone --reference B "file://$(pwd)/A" D 2>"$U.D"'
 
 test_expect_success 'fetched no objects' \
 '! grep " want" "$U.D"'

@@ -173,7 +173,7 @@ test_expect_success 'fetch with incomplete alternates' '
 	(
 		cd K &&
 		git remote add J "file://$base_dir/J" &&
-		GIT_TRACE_PACKET=3 git fetch J 3>"$U.K"
+		GIT_TRACE_PACKET=2 git fetch J 2>"$U.K"
 	) &&
 	master_object=$(cd A && git for-each-ref --format="%(objectname)" refs/heads/master) &&
 	! grep " want $master_object" "$U.K" &&

-- 
1.8.2.1298.g2825a8e

On Wed, Mar 20, 2013 at 09:24:44AM +0100, Johannes Sixt wrote:

From: Johannes Sixt <redacted>

Two tests use GIT_TRACE=3 to dump debugging information of git. On
Windows, however, bash is unable to set up file descriptor 3 correctly
for its child process, so that git reports "Bad file descriptor" on
every trace attempt. The 'git clone' test succeeds nevertheless because
an empty trace file remains, and there is only a check for the
absence of a particular line. But the 'git fetch' process ultimately
hangs (the dynamics that lead to this surprising result have not been
investigated).

Since we do not otherwise use stderr in the test cases, divert the
trace dump to stderr.

I think that is OK, but I'm curious why this is a problem _now_, and not
with the code prior to 97a83fa8. The old GIT_DEBUG_SEND_PACK was also
just calling write() to descriptor 3.

Signed-off-by: Johannes Sixt <redacted>
---
 This fixes a regression introduced in 

...in 97a83fa8, I assume.

-Peff

Am 3/20/2013 10:33, schrieb Jeff King:

On Wed, Mar 20, 2013 at 09:24:44AM +0100, Johannes Sixt wrote:

quoted

From: Johannes Sixt <redacted>

Two tests use GIT_TRACE=3 to dump debugging information of git. On
Windows, however, bash is unable to set up file descriptor 3 correctly
for its child process, so that git reports "Bad file descriptor" on
every trace attempt. The 'git clone' test succeeds nevertheless because
an empty trace file remains, and there is only a check for the
absence of a particular line. But the 'git fetch' process ultimately
hangs (the dynamics that lead to this surprising result have not been
investigated).

Since we do not otherwise use stderr in the test cases, divert the
trace dump to stderr.

I think that is OK, but I'm curious why this is a problem _now_, and not
with the code prior to 97a83fa8. The old GIT_DEBUG_SEND_PACK was also
just calling write() to descriptor 3.

Before this change, both affected commands completed and the trace file
was empty. Notice that in both test cases we only check for the absence of
certain lines, which is naturally true for an empty file, so that the
tests pass.

With the updated code, 'git fetch' hung, which is how I noticed the
problem. As I said, I didn't investigate where and why this happens.

quoted

 This fixes a regression introduced in 

...in 97a83fa8, I assume.

Yes, correct. (Sorry, I got distracted while I looked up the commit.)

-- Hannes

On Wed, Mar 20, 2013 at 12:30:47PM +0100, Johannes Sixt wrote:

quoted

I think that is OK, but I'm curious why this is a problem _now_, and not
with the code prior to 97a83fa8. The old GIT_DEBUG_SEND_PACK was also
just calling write() to descriptor 3.

Before this change, both affected commands completed and the trace file
was empty. Notice that in both test cases we only check for the absence of
certain lines, which is naturally true for an empty file, so that the
tests pass.

Hmm. The code in t5503 is similar, but before my patch used to actually
use "test -s" to make sure that some trace output was written. Did it
fail before 97a83fa8 (and does it pass now)?

We should probably be adjusting t5503, too. And possibly adding back in
the "test -s" checks (which I removed as redundant, but I guess the
double-checking might have caught a platform error in this case).

Also, though I think your use of stderr is probably OK, might it be a
little more robust against future output changes to use:

  GIT_TRACE_PACKET=$PWD/$U.D git clone ...

to write directly to the file. The original GIT_DEBUG_SEND_PACK did not
support such niceties, but GIT_TRACE gives them to us for free.

With the updated code, 'git fetch' hung, which is how I noticed the
problem. As I said, I didn't investigate where and why this happens.

Thinking on it more, almost certainly what is happening is that fd 3 is
being used for the actual protocol, and we are jamming random bytes over
it. Since we have changed the bytes, the code is reacting in a different
way (but the actual reaction doesn't matter; we should stop the cause,
not worry about the symptom).

-Peff

On Wed, Mar 20, 2013 at 01:06:07PM -0400, Jeff King wrote:

On Wed, Mar 20, 2013 at 12:30:47PM +0100, Johannes Sixt wrote:

quoted

quoted

I think that is OK, but I'm curious why this is a problem _now_, and not
with the code prior to 97a83fa8. The old GIT_DEBUG_SEND_PACK was also
just calling write() to descriptor 3.

Before this change, both affected commands completed and the trace file
was empty. Notice that in both test cases we only check for the absence of
certain lines, which is naturally true for an empty file, so that the
tests pass.

Hmm. The code in t5503 is similar, but before my patch used to actually
use "test -s" to make sure that some trace output was written. Did it
fail before 97a83fa8 (and does it pass now)?

Ah, I see. It did fail, and it was marked with NOT_MINGW. I think we can
fix that now. Patch coming in a moment.

-Peff

Some test scripts use the GIT_TRACE mechanism to dump
debugging information to descriptor 3 (and point it to a
file using the shell). On Windows, however, bash is unable
to set up descriptor 3. We do not write our trace to the
file, and worse, we may interfere with other operations
happening on descriptor 3, causing tests to fail or other
even behave inconsistently.

Prior to commit 97a83fa (upload-pack: remove packet debugging
harness), these tests used GIT_DEBUG_SEND_PACK, which only
supported output to a descriptor. The tests in t5503 were
always broken on Windows, and were marked to be skipped via
the NOT_MINGW prerequisite. In t5700, the tests used to pass
prior to 97a83fa, but only because they were not careful
enough; because we only grepped the trace file, an empty
file looked successful to us. But post-97a83fa, the writing
to descriptor 3 causes "git fetch" to hang (presumably
because we are throwing random bytes into the middle of the
protocol).

Now that we are using the GIT_TRACE mechanism, we can
improve both scripts by asking git to write directly to a
file rather than a descriptor. That fixes the hang in t5700,
and should allow t5503 to successfully run on Windows.

In both cases we now also use "test -s" to double-check that
our trace file actually contains output, which should reduce
the possibility of an erroneously passing test.

Signed-off-by: Jeff King <redacted>
---
On top of jk/pkt-line-cleanup.

This works for me on Linux, but I do not have a mingw system to test
t5503 on. If my reasoning is right, it should, but one never knows. :)

Johannes, can you report whether it fixes the problem?

 t/t5503-tagfollow.sh       | 38 ++++++++++++++++++--------------------
 t/t5700-clone-reference.sh | 14 +++++++++-----
 2 files changed, 27 insertions(+), 25 deletions(-)

diff --git a/t/t5503-tagfollow.sh b/t/t5503-tagfollow.sh
index d181c96..f30c038 100755
--- a/t/t5503-tagfollow.sh
+++ b/t/t5503-tagfollow.sh

@@ -4,10 +4,6 @@ test_description='test automatic tag following'
 
 . ./test-lib.sh
 
-if ! test_have_prereq NOT_MINGW; then
-	say "GIT_TRACE_PACKET not supported - skipping tests"
-fi
-
 # End state of the repository:
 #
 #         T - tag1          S - tag2

@@ -17,7 +13,7 @@ fi
 #     \   C - origin/cat    \
 #      origin/master         master
 
-test_expect_success NOT_MINGW setup '
+test_expect_success setup '
 	test_tick &&
 	echo ichi >file &&
 	git add file &&

@@ -39,33 +35,35 @@ test_expect_success NOT_MINGW 'fetch A (new commit : 1 connection)' '
 '
 
 U=UPLOAD_LOG
+UPATH="$(pwd)/$U"
 
-test_expect_success NOT_MINGW 'setup expect' '
+test_expect_success 'setup expect' '
 cat - <<EOF >expect
 want $A
 EOF
 '
 
 get_needs () {
+	test -s "$1" &&
 	perl -alne '
 		next unless $F[1] eq "upload-pack<";
 		last if $F[2] eq "0000";
 		print $F[2], " ", $F[3];
-	' "$@"
+	' "$1"
 }
 
-test_expect_success NOT_MINGW 'fetch A (new commit : 1 connection)' '
+test_expect_success 'fetch A (new commit : 1 connection)' '
 	rm -f $U &&
 	(
 		cd cloned &&
-		GIT_TRACE_PACKET=3 git fetch 3>../$U &&
+		GIT_TRACE_PACKET=$UPATH git fetch &&
 		test $A = $(git rev-parse --verify origin/master)
 	) &&
 	get_needs $U >actual &&
 	test_cmp expect actual
 '
 
-test_expect_success NOT_MINGW "create tag T on A, create C on branch cat" '
+test_expect_success "create tag T on A, create C on branch cat" '
 	git tag -a -m tag1 tag1 $A &&
 	T=$(git rev-parse --verify tag1) &&
 

@@ -77,18 +75,18 @@ test_expect_success NOT_MINGW 'fetch C, T (new branch, tag : 1 connection)' '
 	git checkout master
 '
 
-test_expect_success NOT_MINGW 'setup expect' '
+test_expect_success 'setup expect' '
 cat - <<EOF >expect
 want $C
 want $T
 EOF
 '
 
-test_expect_success NOT_MINGW 'fetch C, T (new branch, tag : 1 connection)' '
+test_expect_success 'fetch C, T (new branch, tag : 1 connection)' '
 	rm -f $U &&
 	(
 		cd cloned &&
-		GIT_TRACE_PACKET=3 git fetch 3>../$U &&
+		GIT_TRACE_PACKET=$UPATH git fetch &&
 		test $C = $(git rev-parse --verify origin/cat) &&
 		test $T = $(git rev-parse --verify tag1) &&
 		test $A = $(git rev-parse --verify tag1^0)

@@ -97,7 +95,7 @@ test_expect_success NOT_MINGW 'fetch C, T (new branch, tag : 1 connection)' '
 	test_cmp expect actual
 '
 
-test_expect_success NOT_MINGW "create commits O, B, tag S on B" '
+test_expect_success "create commits O, B, tag S on B" '
 	test_tick &&
 	echo O >file &&
 	git add file &&

@@ -113,18 +111,18 @@ test_expect_success NOT_MINGW 'fetch B, S (commit and tag : 1 connection)' '
 	S=$(git rev-parse --verify tag2)
 '
 
-test_expect_success NOT_MINGW 'setup expect' '
+test_expect_success 'setup expect' '
 cat - <<EOF >expect
 want $B
 want $S
 EOF
 '
 
-test_expect_success NOT_MINGW 'fetch B, S (commit and tag : 1 connection)' '
+test_expect_success 'fetch B, S (commit and tag : 1 connection)' '
 	rm -f $U &&
 	(
 		cd cloned &&
-		GIT_TRACE_PACKET=3 git fetch 3>../$U &&
+		GIT_TRACE_PACKET=$UPATH git fetch &&
 		test $B = $(git rev-parse --verify origin/master) &&
 		test $B = $(git rev-parse --verify tag2^0) &&
 		test $S = $(git rev-parse --verify tag2)

@@ -133,14 +131,14 @@ EOF
 	test_cmp expect actual
 '
 
-test_expect_success NOT_MINGW 'setup expect' '
+test_expect_success 'setup expect' '
 cat - <<EOF >expect
 want $B
 want $S
 EOF
 '
 
-test_expect_success NOT_MINGW 'new clone fetch master and tags' '
+test_expect_success 'new clone fetch master and tags' '
 	git branch -D cat
 	rm -f $U
 	(

@@ -148,7 +146,7 @@ test_expect_success NOT_MINGW 'new clone fetch master and tags' '
 		cd clone2 &&
 		git init &&
 		git remote add origin .. &&
-		GIT_TRACE_PACKET=3 git fetch 3>../$U &&
+		GIT_TRACE_PACKET=$UPATH git fetch &&
 		test $B = $(git rev-parse --verify origin/master) &&
 		test $S = $(git rev-parse --verify tag2) &&
 		test $B = $(git rev-parse --verify tag2^0) &&

diff --git a/t/t5700-clone-reference.sh b/t/t5700-clone-reference.sh
index 9cd3b4d..60f1552 100755
--- a/t/t5700-clone-reference.sh
+++ b/t/t5700-clone-reference.sh

@@ -54,11 +54,14 @@ test_expect_success 'cloning with reference (no -l -s)' \
 
 rm -f "$U.D"
 
-test_expect_success 'cloning with reference (no -l -s)' \
-'GIT_TRACE_PACKET=3 git clone --reference B "file://$(pwd)/A" D 3>"$U.D"'
+test_expect_success 'cloning with reference (no -l -s)' '
+	GIT_TRACE_PACKET=$U.D git clone --reference B "file://$(pwd)/A" D
+'
 
-test_expect_success 'fetched no objects' \
-'! grep " want" "$U.D"'
+test_expect_success 'fetched no objects' '
+	test -s "$U.D" &&
+	! grep " want" "$U.D"
+'
 
 cd "$base_dir"
 

@@ -173,9 +176,10 @@ test_expect_success 'fetch with incomplete alternates' '
 	(
 		cd K &&
 		git remote add J "file://$base_dir/J" &&
-		GIT_TRACE_PACKET=3 git fetch J 3>"$U.K"
+		GIT_TRACE_PACKET=$U.K git fetch J
 	) &&
 	master_object=$(cd A && git for-each-ref --format="%(objectname)" refs/heads/master) &&
+	test -s "$U.K" &&
 	! grep " want $master_object" "$U.K" &&
 	tag_object=$(cd A && git for-each-ref --format="%(objectname)" refs/tags/HEAD) &&
 	! grep " want $tag_object" "$U.K"

-- 
1.8.2.22.g1efe1a3

On Wed, Mar 20, 2013 at 1:43 PM, Jeff King [off-list ref] wrote:

Some test scripts use the GIT_TRACE mechanism to dump
debugging information to descriptor 3 (and point it to a
file using the shell). On Windows, however, bash is unable
to set up descriptor 3. We do not write our trace to the
file, and worse, we may interfere with other operations
happening on descriptor 3, causing tests to fail or other
even behave inconsistently.

s/other even/even/

On Wed, Mar 20, 2013 at 04:29:40PM -0400, Eric Sunshine wrote:

On Wed, Mar 20, 2013 at 1:43 PM, Jeff King [off-list ref] wrote:

quoted

Some test scripts use the GIT_TRACE mechanism to dump
debugging information to descriptor 3 (and point it to a
file using the shell). On Windows, however, bash is unable
to set up descriptor 3. We do not write our trace to the
file, and worse, we may interfere with other operations
happening on descriptor 3, causing tests to fail or other
even behave inconsistently.

s/other even/even/

Urgh, I should probably add another proofreading pass to my commit
messages. Thanks.

-Peff

Am 3/20/2013 18:43, schrieb Jeff King:

Now that we are using the GIT_TRACE mechanism, we can
improve both scripts by asking git to write directly to a
file rather than a descriptor. That fixes the hang in t5700,
and should allow t5503 to successfully run on Windows.

Well spotted, and, right, both tests pass with this patch.

Tested-by: Johannes Sixt <redacted>

Thanks,
-- Hannes