Intermittent Failures in t1450-fsck

Intermittent Failures in t1450-fsck

[Brian Gernhardt]

t1450-fsck fails in test 10 "tag pointing to something else than its type", but only if I run it as part of the full test suite (with either `make test` or `make prove`).  If I run the test separately, it passes.

The output from running with GIT_TEST_OPTS="-v" is:

expecting success: 
	sha=$(echo blob | git hash-object -w --stdin) &&
	test_when_finished "remove_object $sha" &&
	cat >wrong-tag <<-EOF &&
	object $sha
	type commit
	tag wrong
	tagger T A Gger <tagger@example.com> 1234567890 -0000

	This is an invalid tag.
	EOF

	tag=$(git hash-object -t tag -w --stdin <wrong-tag) &&
	test_when_finished "remove_object $tag" &&
	echo $tag >.git/refs/tags/wrong &&
	test_when_finished "git update-ref -d refs/tags/wrong" &&
	test_must_fail git fsck --tags 2>out &&
	cat out &&
	grep "error in tag.*broken links" out

tagged commit 63499e4ea8e096b831515ceb1d5a7593e4d87ae5 (wrong) in 66f6581d549f70e05ca586bc2df5c15a95662c36
missing commit 63499e4ea8e096b831515ceb1d5a7593e4d87ae5
error: Object 63499e4ea8e096b831515ceb1d5a7593e4d87ae5 is a commit, not a blob
error: 63499e4ea8e096b831515ceb1d5a7593e4d87ae5: object corrupt or missing
not ok - 10 tag pointing to something else than its type

Re: Intermittent Failures in t1450-fsck (Bisected)

[Brian Gernhardt]

I finally managed to pin down what triggers the bug and bisect it to its beginning.

I see this failure only when the test suite is run in parallel.  (make -j or -j in GIT_PROVE_OPTS)

The bug starts happening in "e96c19c: config: support values longer than 1023 bytes".

I have no idea why this commit causes failures in a test for fsck, but commits before it were merged work and commits after do not.  (Its direct ancestors work as well.)  Even more telling, reverting it on top of next causes the test to pass again.

~~ Brian

On Apr 13, 2011, at 1:11 PM, Brian Gernhardt wrote:

> t1450-fsck fails in test 10 "tag pointing to something else than its type", but only if I run it as part of the full test suite (with either `make test` or `make prove`).  If I run the test separately, it passes.
> 
> The output from running with GIT_TEST_OPTS="-v" is:
> 
> expecting success: 
> 	sha=$(echo blob | git hash-object -w --stdin) &&
> 	test_when_finished "remove_object $sha" &&
> 	cat >wrong-tag <<-EOF &&
> 	object $sha
> 	type commit
> 	tag wrong
> 	tagger T A Gger <tagger@example.com> 1234567890 -0000
> 
> 	This is an invalid tag.
> 	EOF
> 
> 	tag=$(git hash-object -t tag -w --stdin <wrong-tag) &&
> 	test_when_finished "remove_object $tag" &&
> 	echo $tag >.git/refs/tags/wrong &&
> 	test_when_finished "git update-ref -d refs/tags/wrong" &&
> 	test_must_fail git fsck --tags 2>out &&
> 	cat out &&
> 	grep "error in tag.*broken links" out
> 
> tagged commit 63499e4ea8e096b831515ceb1d5a7593e4d87ae5 (wrong) in 66f6581d549f70e05ca586bc2df5c15a95662c36
> missing commit 63499e4ea8e096b831515ceb1d5a7593e4d87ae5
> error: Object 63499e4ea8e096b831515ceb1d5a7593e4d87ae5 is a commit, not a blob
> error: 63499e4ea8e096b831515ceb1d5a7593e4d87ae5: object corrupt or missing
> not ok - 10 tag pointing to something else than its type
> 
> --
> To unsubscribe from this list: send the line "unsubscribe git" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: Intermittent Failures in t1450-fsck (Bisected)

[Jeff King]

On Thu, May 05, 2011 at 02:46:52AM -0400, Brian Gernhardt wrote:

> I finally managed to pin down what triggers the bug and bisect it to
> its beginning.
> 
> I see this failure only when the test suite is run in parallel.  (make
> -j or -j in GIT_PROVE_OPTS)
> 
> The bug starts happening in "e96c19c: config: support values longer than 1023 bytes".

I'm slightly confused. Commit e96c19c predates the test that you
reported as failing here:

> > t1450-fsck fails in test 10 "tag pointing to something else than its type", but only if I run it as part of the full test suite (with either `make test` or `make prove`).  If I run the test separately, it passes.
> > 
> > The output from running with GIT_TEST_OPTS="-v" is:
> > 
> > expecting success: 
> > 	sha=$(echo blob | git hash-object -w --stdin) &&
> > 	test_when_finished "remove_object $sha" &&
> > 	cat >wrong-tag <<-EOF &&
> > 	object $sha
> > 	type commit
> > 	tag wrong
> > 	tagger T A Gger <tagger@example.com> 1234567890 -0000
> > 
> > 	This is an invalid tag.
> > 	EOF
> > 
> > 	tag=$(git hash-object -t tag -w --stdin <wrong-tag) &&
> > 	test_when_finished "remove_object $tag" &&
> > 	echo $tag >.git/refs/tags/wrong &&
> > 	test_when_finished "git update-ref -d refs/tags/wrong" &&
> > 	test_must_fail git fsck --tags 2>out &&
> > 	cat out &&
> > 	grep "error in tag.*broken links" out
> > 
> > tagged commit 63499e4ea8e096b831515ceb1d5a7593e4d87ae5 (wrong) in 66f6581d549f70e05ca586bc2df5c15a95662c36
> > missing commit 63499e4ea8e096b831515ceb1d5a7593e4d87ae5
> > error: Object 63499e4ea8e096b831515ceb1d5a7593e4d87ae5 is a commit, not a blob
> > error: 63499e4ea8e096b831515ceb1d5a7593e4d87ae5: object corrupt or missing
> > not ok - 10 tag pointing to something else than its type

So how did you bisect down to it? You said reverting e96c19c fixes it,
which does seem like strong evidence, but what I am wondering is if a
_different_ test in t1450 fails at e96c19c. That would point to
something else funny going on.

Double weird is that my output for t1450.10 is totally different from
that.  Which commit are you testing on?

Given that the problem seems racy and intermittent, have you tried
running under valgrind?

-Peff

Re: Intermittent Failures in t1450-fsck (Bisected)

[Brian Gernhardt]

On May 5, 2011, at 5:32 AM, Jeff King wrote:

> On Thu, May 05, 2011 at 02:46:52AM -0400, Brian Gernhardt wrote:
>>> t1450-fsck fails in test 10 "tag pointing to something else than its type", but only if I run it as part of the full test suite (with either `make test` or `make prove`).  If I run the test separately, it passes.
>>> 
>>> The output from running with GIT_TEST_OPTS="-v" is:
>>> 
>>> expecting success: 
>>> 	sha=$(echo blob | git hash-object -w --stdin) &&
>>> 	test_when_finished "remove_object $sha" &&
>>> 	cat >wrong-tag <<-EOF &&
>>> 	object $sha
>>> 	type commit
>>> 	tag wrong
>>> 	tagger T A Gger <tagger@example.com> 1234567890 -0000
>>> 
>>> 	This is an invalid tag.
>>> 	EOF
>>> 
>>> 	tag=$(git hash-object -t tag -w --stdin <wrong-tag) &&
>>> 	test_when_finished "remove_object $tag" &&
>>> 	echo $tag >.git/refs/tags/wrong &&
>>> 	test_when_finished "git update-ref -d refs/tags/wrong" &&
>>> 	test_must_fail git fsck --tags 2>out &&
>>> 	cat out &&
>>> 	grep "error in tag.*broken links" out
>>> 
>>> tagged commit 63499e4ea8e096b831515ceb1d5a7593e4d87ae5 (wrong) in 66f6581d549f70e05ca586bc2df5c15a95662c36
>>> missing commit 63499e4ea8e096b831515ceb1d5a7593e4d87ae5
>>> error: Object 63499e4ea8e096b831515ceb1d5a7593e4d87ae5 is a commit, not a blob
>>> error: 63499e4ea8e096b831515ceb1d5a7593e4d87ae5: object corrupt or missing
>>> not ok - 10 tag pointing to something else than its type
> 
> So how did you bisect down to it? You said reverting e96c19c fixes it,
> which does seem like strong evidence, but what I am wondering is if a
> _different_ test in t1450 fails at e96c19c. That would point to
> something else funny going on.

I actually bisected the test failure to "c5a5f12e: Merge branch 'ef/maint-strbuf-init'", and then rebased e96c19c on top of 2a2dbd2 to see what actually caused the error.  I re-ran it like this again today and got the exact same error.

> Double weird is that my output for t1450.10 is totally different from
> that.  Which commit are you testing on?

The original e-mail was from next at that point.  The output from the rebased version and current next (76e37e2) is identical.

> Given that the problem seems racy and intermittent, have you tried
> running under valgrind?

This is on my OS X laptop and last I knew valgrind was very buggy on OS X, so I've never tried it.  I'll install it now and see if I can get anything useful out of it.

~~ Brian

Re: Intermittent Failures in t1450-fsck (Bisected)

[Jeff King]

On Thu, May 05, 2011 at 04:04:33PM -0400, Brian Gernhardt wrote:

> The original e-mail was from next at that point.  The output from the
> rebased version and current next (76e37e2) is identical.

Thanks. The weird thing is that running t1450 on 76e37e2 gives me this
output:

broken link from     tag 66f6581d549f70e05ca586bc2df5c15a95662c36
broken link from unknown unknown
dangling blob 63499e4ea8e096b831515ceb1d5a7593e4d87ae5
error: Object 63499e4ea8e096b831515ceb1d5a7593e4d87ae5 is a blob, not a commit
error in tag 66f6581d549f70e05ca586bc2df5c15a95662c36: broken links
error in tag 66f6581d549f70e05ca586bc2df5c15a95662c36: could not load tagged object
error in tag 66f6581d549f70e05ca586bc2df5c15a95662c36: broken links

whereas from your original email, you had:

> >>> tagged commit 63499e4ea8e096b831515ceb1d5a7593e4d87ae5 (wrong) in 66f6581d549f70e05ca586bc2df5c15a95662c36
> >>> missing commit 63499e4ea8e096b831515ceb1d5a7593e4d87ae5
> >>> error: Object 63499e4ea8e096b831515ceb1d5a7593e4d87ae5 is a commit, not a blob
> >>> error: 63499e4ea8e096b831515ceb1d5a7593e4d87ae5: object corrupt or missing

which is weird. We do call "remove_object $sha", but only inside
test_when_finished. I wonder if there is some bug with
test_when_finished on your platform. Have you tried instrumenting the
remove_object function to print a message when it is run? That might
give us a clue if it is accidentally being run early.

> This is on my OS X laptop and last I knew valgrind was very buggy on
> OS X, so I've never tried it.  I'll install it now and see if I can
> get anything useful out of it.

I've tried but been unable to reproduce on Linux, so it seems like
something OS X specific.

-Peff

Re: Intermittent Failures in t1450-fsck (Bisected)

[Brian Gernhardt]

On May 5, 2011, at 5:03 PM, Jeff King wrote:

> On Thu, May 05, 2011 at 04:04:33PM -0400, Brian Gernhardt wrote:
> 
>> The original e-mail was from next at that point.  The output from the
>> rebased version and current next (76e37e2) is identical.
> 
> Thanks. The weird thing is that running t1450 on 76e37e2 gives me this
> output:
> 
> broken link from     tag 66f6581d549f70e05ca586bc2df5c15a95662c36
> broken link from unknown unknown
> dangling blob 63499e4ea8e096b831515ceb1d5a7593e4d87ae5
> error: Object 63499e4ea8e096b831515ceb1d5a7593e4d87ae5 is a blob, not a commit
> error in tag 66f6581d549f70e05ca586bc2df5c15a95662c36: broken links
> error in tag 66f6581d549f70e05ca586bc2df5c15a95662c36: could not load tagged object
> error in tag 66f6581d549f70e05ca586bc2df5c15a95662c36: broken links
> 
> whereas from your original email, you had:
> 
>>>>> tagged commit 63499e4ea8e096b831515ceb1d5a7593e4d87ae5 (wrong) in 66f6581d549f70e05ca586bc2df5c15a95662c36
>>>>> missing commit 63499e4ea8e096b831515ceb1d5a7593e4d87ae5
>>>>> error: Object 63499e4ea8e096b831515ceb1d5a7593e4d87ae5 is a commit, not a blob
>>>>> error: 63499e4ea8e096b831515ceb1d5a7593e4d87ae5: object corrupt or missing
> 
> which is weird. We do call "remove_object $sha", but only inside
> test_when_finished. I wonder if there is some bug with
> test_when_finished on your platform. Have you tried instrumenting the
> remove_object function to print a message when it is run? That might
> give us a clue if it is accidentally being run early.

I've done so, and the output is at the end of the e-mail.  I also added calls to `git show` to see if the objects could still be read.

>> This is on my OS X laptop and last I knew valgrind was very buggy on
>> OS X, so I've never tried it.  I'll install it now and see if I can
>> get anything useful out of it.
> 
> I've tried but been unable to reproduce on Linux, so it seems like
> something OS X specific.

Quite possibly.  My /bin/sh is GNU bash 3.2.48(1), so I don't know if that makes a difference.

I've actually nailed it down to something even more specific than "OS X".  It's failing when I run it on a ramdisk.

git/t$ dev=`hdiutil attach -nomount ram://512000`
git/t$ diskutil erasevolume HFS+ Git_Test $dev
Started erase on disk1
Unmounting disk
Erasing
Initialized /dev/rdisk1 as a 250 MB HFS Plus volume
Mounting disk
Finished erase on disk1 Git_Test
git/t$ ./t1450-fsck.sh -v --root=/Volumes/Git_Test  # Fails

~~ Brian

expecting success: 
	sha=$(echo blob | git hash-object -w --stdin) &&
	test_when_finished "remove_object $sha" &&
	cat >wrong-tag <<-EOF &&
	object $sha
	type commit
	tag wrong
	tagger T A Gger <tagger@example.com> 1234567890 -0000

	This is an invalid tag.
	EOF

	tag=$(git hash-object -t tag -w --stdin <wrong-tag) &&
	test_when_finished "remove_object $tag" &&
	echo $tag >.git/refs/tags/wrong &&
	git show $blob &&
	git show $tag &&
	test_when_finished "git update-ref -d refs/tags/wrong" &&
	test_must_fail git fsck --tags 2>out &&
	cat out &&
	grep "error in tag.*broken links" out

commit c9145d6720f85544cc4bb6009a2e541660aa156b
Author: A U Thor <author@example.com>
Date:   Thu Apr 7 15:14:13 2005 -0700

    B

diff --git a/fileB b/fileB
new file mode 100644
index 0000000..f719efd
--- /dev/null
+++ b/fileB
@@ -0,0 +1 @@
+two
tag wrong
Tagger: T A Gger <tagger@example.com>
Date:   Fri Feb 13 23:31:30 2009 +0000

This is an invalid tag.
error: Object 63499e4ea8e096b831515ceb1d5a7593e4d87ae5 is a commit, not a blob
error: Could not read object 63499e4ea8e096b831515ceb1d5a7593e4d87ae5
removing 66f6581d549f70e05ca586bc2df5c15a95662c36
removing 63499e4ea8e096b831515ceb1d5a7593e4d87ae5
not ok - 10 tag pointing to something else than its type
#	
#		sha=$(echo blob | git hash-object -w --stdin) &&
#		test_when_finished "remove_object $sha" &&
#		cat >wrong-tag <<-EOF &&
#		object $sha
#		type commit
#		tag wrong
#		tagger T A Gger <tagger@example.com> 1234567890 -0000
#	
#		This is an invalid tag.
#		EOF
#	
#		tag=$(git hash-object -t tag -w --stdin <wrong-tag) &&
#		test_when_finished "remove_object $tag" &&
#		echo $tag >.git/refs/tags/wrong &&
#		git show $blob &&
#		git show $tag &&
#		test_when_finished "git update-ref -d refs/tags/wrong" &&
#		test_must_fail git fsck --tags 2>out &&
#		cat out &&
#		grep "error in tag.*broken links" out
#	

expecting success: 
	git fsck >actual 2>&1 &&
	test_cmp empty actual

--- empty	2011-05-05 21:56:11.000000000 +0000
+++ actual	2011-05-05 21:56:12.000000000 +0000
@@ -0,0 +1 @@
+error: refs/tags/wrong does not point to a valid object!
not ok - 11 cleaned up
#	
#		git fsck >actual 2>&1 &&
#		test_cmp empty actual
#	

# failed 2 among 11 test(s)
1..11

Re: Intermittent Failures in t1450-fsck (Bisected)

[Brian Gernhardt]

On May 5, 2011, at 5:58 PM, Brian Gernhardt wrote:

> I've actually nailed it down to something even more specific than "OS X".  It's failing when I run it on a ramdisk.
>> 

I've tried to narrow it down even further.  I cut the test down to just the setup and failing test. Then I removed all "test_when_finished" and replaced the "test_must_fail" with "!" so I can directly copy/paste the test into a window.  When the test runs, it fails.  When I run it manually, even with using /bin/sh and eval, it succeeds.  Can anybody else think of what difference there might be between a shell and the test script that I should test?  (I did remember to set GIT_EXEC_PATH and my PATH to run the same version as the script is.)

There's some _very_ weird triggering condition involved here and I'm hoping to narrow it down so I can set some useful breakpoints in gdb and see what's going on inside.

Output follows:

t$ dev=`hdiutil attach -nomount ram://200000`
t$ diskutil erasevolume HFS+ Git_Test $dev
Started erase on disk1
Unmounting disk
Erasing
Initialized /dev/rdisk1 as a 100 MB HFS Plus volume
Mounting disk
Finished erase on disk1 Git_Test
t$ ./t1450-fsck.sh -i -v --root=/Volumes/Git_Test
Initialized empty Git repository in /Volumes/Git_Test/trash directory.t1450-fsck/.git/
expecting success: 
	git config gc.auto 0 &&
	git config i18n.commitencoding ISO-8859-1 &&
	test_commit A fileA one &&
	git config --unset i18n.commitencoding &&
	git checkout HEAD^0 &&
	test_commit B fileB two &&
	git tag -d A B &&
	git reflog expire --expire=now --all &&
	>empty

[master (root-commit) 1347563] A
 Author: A U Thor <author@example.com>
 1 files changed, 1 insertions(+), 0 deletions(-)
 create mode 100644 fileA
Note: checking out 'HEAD^0'.

You are in 'detached HEAD' state. You can look around, make experimental
changes and commit them, and you can discard any commits you make in this
state without impacting any branches by performing another checkout.

If you want to create a new branch to retain commits you create, you may
do so (now or later) by using -b with the checkout command again. Example:

  git checkout -b new_branch_name

HEAD is now at 1347563... A
[detached HEAD c9145d6] B
 Author: A U Thor <author@example.com>
 1 files changed, 1 insertions(+), 0 deletions(-)
 create mode 100644 fileB
Deleted tag 'A' (was 1347563)
Deleted tag 'B' (was c9145d6)
ok 1 - setup

expecting success: 
	sha1_file() {
		echo "$*" | sed "s#..#.git/objects/&/#"
	} &&

	remove_object() {
		file=$(sha1_file "$*") &&
		test -e "$file" &&
		rm -f "$file"
	}

ok 2 - setup: helpers for corruption tests

expecting success: 
	sha=$(echo blob | git hash-object -w --stdin) &&
	cat >wrong-tag <<-EOF &&
	object $sha
	type commit
	tag wrong
	tagger T A Gger <tagger@example.com> 1234567890 -0000

	This is an invalid tag.
	EOF

	tag=$(git hash-object -t tag -w --stdin <wrong-tag) &&
	echo $tag >.git/refs/tags/wrong &&
	! git fsck --tags 2>out &&
	cat out &&
	grep "error in tag.*broken links" out

tagged commit 63499e4ea8e096b831515ceb1d5a7593e4d87ae5 (wrong) in 66f6581d549f70e05ca586bc2df5c15a95662c36
missing commit 63499e4ea8e096b831515ceb1d5a7593e4d87ae5
error: Object 63499e4ea8e096b831515ceb1d5a7593e4d87ae5 is a commit, not a blob
error: 63499e4ea8e096b831515ceb1d5a7593e4d87ae5: object corrupt or missing
not ok - 3 tag pointing to something else than its type
#	
#		sha=$(echo blob | git hash-object -w --stdin) &&
#		cat >wrong-tag <<-EOF &&
#		object $sha
#		type commit
#		tag wrong
#		tagger T A Gger <tagger@example.com> 1234567890 -0000
#	
#		This is an invalid tag.
#		EOF
#	
#		tag=$(git hash-object -t tag -w --stdin <wrong-tag) &&
#		echo $tag >.git/refs/tags/wrong &&
#		! git fsck --tags 2>out &&
#		cat out &&
#		grep "error in tag.*broken links" out
#	
t$ /bin/sh
sh-3.2$ cd /Volumes/Git_Test/trash\ directory.t1450-fsck
sh-3.2$ rm .git/objects/63/499e4ea8e096b831515ceb1d5a7593e4d87ae5 .git/objects/66/f6581d549f70e05ca586bc2df5c15a95662c36 
override r--r--r--  brian/brian for .git/objects/63/499e4ea8e096b831515ceb1d5a7593e4d87ae5? y
override r--r--r--  brian/brian for .git/objects/66/f6581d549f70e05ca586bc2df5c15a95662c36? y
sh-3.2$ export GIT_EXEC_PATH=$HOME/dev/git
sh-3.2$ export PATH=$HOME/dev/git:$PATH
sh-3.2$ eval '
> sha=$(echo blob | git hash-object -w --stdin) &&
> cat >wrong-tag <<-EOF &&
> object $sha
> type commit
> tag wrong
> tagger T A Gger <tagger@example.com> 1234567890 -0000
> 
> This is an invalid tag.
> EOF
> 
> tag=$(git hash-object -t tag -w --stdin <wrong-tag) &&
> echo $tag >.git/refs/tags/wrong &&
> ! $HOME/dev/git/git fsck --tags 2>out &&
> cat out &&
> grep "error in tag.*broken links" out
> '
broken link from     tag 66f6581d549f70e05ca586bc2df5c15a95662c36
broken link from unknown unknown
dangling blob 63499e4ea8e096b831515ceb1d5a7593e4d87ae5
error: Object 63499e4ea8e096b831515ceb1d5a7593e4d87ae5 is a blob, not a commit
error in tag 66f6581d549f70e05ca586bc2df5c15a95662c36: broken links
error in tag 66f6581d549f70e05ca586bc2df5c15a95662c36: could not load tagged object
error in tag 66f6581d549f70e05ca586bc2df5c15a95662c36: broken links
sh-3.2$ 

Re: Intermittent Failures in t1450-fsck (Bisected)

[Jeff King]

On Sat, May 07, 2011 at 04:25:28PM -0400, Brian Gernhardt wrote:

> I've tried to narrow it down even further.  I cut the test down to
> just the setup and failing test. Then I removed all
> "test_when_finished" and replaced the "test_must_fail" with "!" so I
> can directly copy/paste the test into a window.  When the test runs,
> it fails.  When I run it manually, even with using /bin/sh and eval,
> it succeeds.  Can anybody else think of what difference there might be
> between a shell and the test script that I should test?  (I did
> remember to set GIT_EXEC_PATH and my PATH to run the same version as
> the script is.)

Could be something in the environment. You might want to try pulling the
environment variable setup from test-lib.sh into your interactive shell.

I would suspect earlier tests might have created some weird state, but
it looks in your output like you removed most of them and still see the
problem.

> expecting success: 
> 	sha=$(echo blob | git hash-object -w --stdin) &&
> 	cat >wrong-tag <<-EOF &&
> 	object $sha
> 	type commit
> 	tag wrong
> 	tagger T A Gger <tagger@example.com> 1234567890 -0000
> 
> 	This is an invalid tag.
> 	EOF
> 
> 	tag=$(git hash-object -t tag -w --stdin <wrong-tag) &&
> 	echo $tag >.git/refs/tags/wrong &&
> 	! git fsck --tags 2>out &&
> 	cat out &&
> 	grep "error in tag.*broken links" out
> 
> tagged commit 63499e4ea8e096b831515ceb1d5a7593e4d87ae5 (wrong) in 66f6581d549f70e05ca586bc2df5c15a95662c36
> missing commit 63499e4ea8e096b831515ceb1d5a7593e4d87ae5
> error: Object 63499e4ea8e096b831515ceb1d5a7593e4d87ae5 is a commit, not a blob
> error: 63499e4ea8e096b831515ceb1d5a7593e4d87ae5: object corrupt or missing
> not ok - 3 tag pointing to something else than its type

Thanks for narrowing it down more. One thing I'd try is to see what "git
cat-file -t $sha" and "git cat-file -p $sha" say right before the fsck
is run (they should both print "blob").

Beyond that I think I'd try gdb, with breakpoints near the places those
messages are generated (you can find them by grepping for "tagged %s %s"
and "is a %s, not a").

Other than that, I'm a bit stumped. The whole "it breaks on a ramdisk"
thing is just odd.

-Peff

Re: Intermittent Failures in t1450-fsck (Bisected)

[Brian Gernhardt]

On May 5, 2011, at 4:04 PM, Brian Gernhardt wrote:

> On May 5, 2011, at 5:32 AM, Jeff King wrote:
> 
>> Given that the problem seems racy and intermittent, have you tried
>> running under valgrind?
> 
> This is on my OS X laptop and last I knew valgrind was very buggy on OS X, so I've never tried it.  I'll install it now and see if I can get anything useful out of it.

I will note the test _reliably_ fails when run in parallel with other tests.

Under valgrind I get the following error.  I will note that attempting to run the full test suite with valgrind gives lots of similar errors in many tests.  (All conditional jump in deflate, allocated in write_loose_object.)

==14187== Conditional jump or move depends on uninitialised value(s)
==14187==    at 0x100209B3B: deflateEnd (in /usr/lib/libz.1.2.3.dylib)
==14187==    by 0x10020ABF6: deflateSetDictionary (in /usr/lib/libz.1.2.3.dylib)
==14187==    by 0x10020B914: deflate (in /usr/lib/libz.1.2.3.dylib)
==14187==    by 0x1000FA631: write_loose_object (in /Users/brian/dev/git/t/valgrind/../../git)
==14187==    by 0x1000FA8C8: write_sha1_file (in /Users/brian/dev/git/t/valgrind/../../git)
==14187==    by 0x1000FACFB: index_mem (in /Users/brian/dev/git/t/valgrind/../../git)
==14187==    by 0x1000FAE95: index_fd (in /Users/brian/dev/git/t/valgrind/../../git)
==14187==    by 0x100038258: hash_fd (in /Users/brian/dev/git/t/valgrind/../../git)
==14187==    by 0x1000386AA: cmd_hash_object (in /Users/brian/dev/git/t/valgrind/../../git)
==14187==    by 0x1000016BC: run_builtin (in /Users/brian/dev/git/t/valgrind/../../git)
==14187==    by 0x10000186E: handle_internal_command (in /Users/brian/dev/git/t/valgrind/../../git)
==14187==    by 0x10000195F: run_argv (in /Users/brian/dev/git/t/valgrind/../../git)
==14187==  Uninitialised value was created by a heap allocation
==14187==    at 0x1001F5345: malloc (vg_replace_malloc.c:236)
==14187==    by 0x10020A0FB: deflateInit2_ (in /usr/lib/libz.1.2.3.dylib)
==14187==    by 0x10020A264: deflateInit_ (in /usr/lib/libz.1.2.3.dylib)
==14187==    by 0x1000FA588: write_loose_object (in /Users/brian/dev/git/t/valgrind/../../git)
==14187==    by 0x1000FA8C8: write_sha1_file (in /Users/brian/dev/git/t/valgrind/../../git)
==14187==    by 0x1000FACFB: index_mem (in /Users/brian/dev/git/t/valgrind/../../git)
==14187==    by 0x1000FAE95: index_fd (in /Users/brian/dev/git/t/valgrind/../../git)
==14187==    by 0x100038258: hash_fd (in /Users/brian/dev/git/t/valgrind/../../git)
==14187==    by 0x1000386AA: cmd_hash_object (in /Users/brian/dev/git/t/valgrind/../../git)
==14187==    by 0x1000016BC: run_builtin (in /Users/brian/dev/git/t/valgrind/../../git)
==14187==    by 0x10000186E: handle_internal_command (in /Users/brian/dev/git/t/valgrind/../../git)
==14187==    by 0x10000195F: run_argv (in /Users/brian/dev/git/t/valgrind/../../git)
==14187== 
{
   <insert_a_suppression_name_here>
   Memcheck:Cond
   fun:deflateEnd
   fun:deflateSetDictionary
   fun:deflate
   fun:write_loose_object
   fun:write_sha1_file
   fun:index_mem
   fun:index_fd
   fun:hash_fd
   fun:cmd_hash_object
   fun:run_builtin
   fun:handle_internal_command
   fun:run_argv
}

Re: Intermittent Failures in t1450-fsck (Bisected)

[Jeff King]

On Thu, May 05, 2011 at 05:07:54PM -0400, Brian Gernhardt wrote:

> On May 5, 2011, at 4:04 PM, Brian Gernhardt wrote:
> 
> > On May 5, 2011, at 5:32 AM, Jeff King wrote:
> > 
> >> Given that the problem seems racy and intermittent, have you tried
> >> running under valgrind?
> > 
> > This is on my OS X laptop and last I knew valgrind was very buggy on OS X, so I've never tried it.  I'll install it now and see if I can get anything useful out of it.
> 
> I will note the test _reliably_ fails when run in parallel with other tests.

It might be interference from another test, though in general they
should all be in their own little sandboxes. It could just be a race
condition that gets triggered more reliably when the system is under
load.

> Under valgrind I get the following error.  I will note that attempting
> to run the full test suite with valgrind gives lots of similar errors
> in many tests.  (All conditional jump in deflate, allocated in
> write_loose_object.)

This is probably a false positive. On Linux we see these in libz because
it has some weird optimized loop that can read past the end of the
buffer (though I have usually see it in the inflate code path, not
deflate).

-Peff