Solaris test t5500 race condition

Solaris test t5500 race condition

[Peter Eriksen]

Hello,

I've found a race in t5500-fetch-pack.sh.  The problem is the way the
number of unpacked objects are counted:

    pack_count=$(grep Unpacking log.txt|tr -dc "0-9")

It just concatenates all the digits on the line with "Unpacking" in it. 
This is the output I get on Solaris:

    Generating pack...
    Done counting 3 objects.
    Deltifying 3 objects.
      33% (1/3) done^M  66% (2/3) done^M 100% (3/3) done
    Total 3Unpacking , written 33 objects          <------------
     (delta 0), reused 0 (delta 0)
    11fa2f0cb58ed7f02dbd5ac75ed82a53fae62a7b refs/heads/A

The marked line is written as a joyful duet between these
two functions:

    unpack-objects.c:   fprintf(stderr, "Unpacking %d objects\n",
                                nr_objects);

    pack-objects.c:     fprintf(stderr, "Total %d, written %d 
                                (delta %d), reused %d (delta %d)\n",

I can't think of a good solution right now.

Regards,

Peter

Re: Solaris test t5500 race condition

[Jason Riedy]

And "Peter Eriksen" writes:
 - I've found a race in t5500-fetch-pack.sh.

Crap.  I ran into this on AIX a while ago; I was hoping no
other systems would see it.  There are no guarantees that 
the two processes' outputs will be mutually line buffered.
Luckily, it's just a cosmetic problem, but it does cause 
that test case to fail.

I know how to fix it (imho), but have no time to implement
it.  There needs to be a separate communication stage after 
negotiating the objects and before dumping the pack.  During
that stage, upload-pack would just send progress notices to 
the caller.  Only the caller would communicate to the terminal.
Some other ideas are in
  http://marc.theaimsgroup.com/?l=git&m=114357528512063&w=2

Jason

Re: Solaris test t5500 race condition

[Junio C Hamano]

"Peter Eriksen" <s022018@student.dtu.dk> writes:

>     Generating pack...
>     Done counting 3 objects.
>     Deltifying 3 objects.
>       33% (1/3) done^M  66% (2/3) done^M 100% (3/3) done
>     Total 3Unpacking , written 33 objects          <------------
>      (delta 0), reused 0 (delta 0)
>     11fa2f0cb58ed7f02dbd5ac75ed82a53fae62a7b refs/heads/A

Hmph.  Not good.  Before the writer managed to flush the report
the reader has already decoded the header and reports the number
of objects it is going to unpack.

Unfortunately the Solaris box I have access to is perhaps
sufficiently slow that this is not an issue X-<.

I think test based on the eye-candy is fragile anyway.  We would
want to probably _count_ before and after to see if the command
did what we expected.

There is a subtle difficulty doing so, however.  The test is
trying to see if fetch-pack vs upload-pack negotiations result
in minimal transfer, but if it is not, unpack side would just
happily say "I received this one, oh, I already have it".

We could do "fetch-pack -k" to keep the result packed, count the
number of objects in the resulting pack.

How about doing something like this instead?

-- >8 --
[PATCH] t5500: test fix

Relying on eye-candy progress bar was fragile to begin with.
Run fetch-pack with -k option, and count the objects that are in
the pack that were transferred from the other end.

Signed-off-by: Junio C Hamano <junkio@cox.net>

---

 t/t5500-fetch-pack.sh |   33 ++++++++++++++-------------------
 1 files changed, 14 insertions(+), 19 deletions(-)

7f732c632ff7a1adc2309257becdc0c1fe76b514
diff --git a/t/t5500-fetch-pack.sh b/t/t5500-fetch-pack.sh
index e15e14f..92f12d9 100755
--- a/t/t5500-fetch-pack.sh
+++ b/t/t5500-fetch-pack.sh
@@ -12,11 +12,6 @@ # Test fetch-pack/upload-pack pair.
 
 # Some convenience functions
 
-function show_count () {
-	commit_count=$(($commit_count+1))
-	printf "      %d\r" $commit_count
-}
-
 function add () {
 	local name=$1
 	local text="$@"
@@ -55,13 +50,6 @@ function test_expect_object_count () {
 		"test $count = $output"
 }
 
-function test_repack () {
-	local rep=$1
-
-	test_expect_success "repack && prune-packed in $rep" \
-		'(git-repack && git-prune-packed)2>>log.txt'
-}
-
 function pull_to_client () {
 	local number=$1
 	local heads=$2
@@ -70,13 +58,23 @@ function pull_to_client () {
 
 	cd client
 	test_expect_success "$number pull" \
-		"git-fetch-pack -v .. $heads > log.txt 2>&1"
+		"git-fetch-pack -k -v .. $heads"
 	case "$heads" in *A*) echo $ATIP > .git/refs/heads/A;; esac
 	case "$heads" in *B*) echo $BTIP > .git/refs/heads/B;; esac
 	git-symbolic-ref HEAD refs/heads/${heads:0:1}
+
 	test_expect_success "fsck" 'git-fsck-objects --full > fsck.txt 2>&1'
-	test_expect_object_count "after $number pull" $count
-	pack_count=$(grep Unpacking log.txt|tr -dc "0-9")
+
+	test_expect_success 'check downloaded results' \
+	'mv .git/objects/pack/pack-* . &&
+	 p=`ls -1 pack-*.pack` &&
+	 git-unpack-objects <$p &&
+	 git-fsck-objects --full'
+
+	test_expect_success "new object count after $number pull" \
+	'idx=`echo pack-*.idx` &&
+	 pack_count=`git-show-index <$idx | wc -l` &&
+	 test $pack_count = $count'
 	test -z "$pack_count" && pack_count=0
 	if [ -z "$no_strict_count_check" ]; then
 		test_expect_success "minimal count" "test $count = $pack_count"
@@ -84,6 +82,7 @@ function pull_to_client () {
 		test $count != $pack_count && \
 			echo "WARNING: $pack_count objects transmitted, only $count of which were needed"
 	fi
+	rm -f pack-*
 	cd ..
 }
 
@@ -117,8 +116,6 @@ git-symbolic-ref HEAD refs/heads/B
 
 pull_to_client 1st "B A" $((11*3))
 
-(cd client; test_repack client)
-
 add A11 $A10
 
 prev=1; cur=2; while [ $cur -le 65 ]; do
@@ -129,8 +126,6 @@ done
 
 pull_to_client 2nd "B" $((64*3))
 
-(cd client; test_repack client)
-
 pull_to_client 3rd "A" $((1*3)) # old fails
 
 test_done
-- 
1.3.0.rc3.g9306

Re: Solaris test t5500 race condition

[Peter Eriksen]

On Thu, Apr 13, 2006 at 10:34:05PM -0700, Junio C Hamano wrote:
> "Peter Eriksen" <s022018@student.dtu.dk> writes:
> 
> >     Generating pack...
> >     Done counting 3 objects.
> >     Deltifying 3 objects.
> >       33% (1/3) done^M  66% (2/3) done^M 100% (3/3) done
> >     Total 3Unpacking , written 33 objects          <------------
> >      (delta 0), reused 0 (delta 0)
> >     11fa2f0cb58ed7f02dbd5ac75ed82a53fae62a7b refs/heads/A
> 
> Hmph.  Not good.  Before the writer managed to flush the report
> the reader has already decoded the header and reports the number
> of objects it is going to unpack.
...
> -- >8 --
> [PATCH] t5500: test fix

With the patch it doesn't complain anymore.  There are many other 
problems with the tests on Solaris though.

Peter

Re: Solaris test t5500 race condition

[Jason Riedy]

And "Peter Eriksen" writes:
 - > -- >8 --
 - > [PATCH] t5500: test fix
 - 
 - With the patch it doesn't complain anymore.  There are many other 
 - problems with the tests on Solaris though.

I just ran next branch's tests on 5.8 with no problems.  Could 
you be a bit more specific?

Jason