Re: git-bisect failure

bix:/usr/src/git26> git bisect bad
Bisecting:      55 revisions left to test after this

At this point, you marked 4c139862b8831261d57de02716b92f82e5fb463b
"[PATCH] xtensa: delete accidental file" is already bad.  And the last
known good commit is b749bfcd1be72f8cb8310e1cac12825bda029432 "[PATCH]
ppc64: update xmon helptext".  The commit between these is just a
straight sequence (no branches), so running "git bisect visualize"
gives me a nice single strand of pearls.

bix:/usr/src/git26> git bisect bad
Bisecting:      28 revisions left to test after this

With this, you marked "[PATCH] i386 boottime for_each_cpu broken" is
bad.  "Reread references" in the running gitk shows me that the range
between bad and good halved.

bix:/usr/src/git26> git bisect good
Bisecting:      14 revisions left to test after this

Marked "[PATCH] mips: remove timex.h for vr41xx" good.

bix:/usr/src/git26> git bisect good
Bisecting:       7 revisions left to test after this

Marked "[PATCH] i386: cleanup serialize msr" good.

bix:/usr/src/git26> git bisect good
Bisecting:       3 revisions left to test after this

Marked "[PATCH] x86: privilege cleanup" good.

bix:/usr/src/git26> git bisect bad 
Bisecting:       2 revisions left to test after this

Marked "[PATCH] x86: introduce a write acessor for updating the
current LDT" bad.

Just after you marked "[PATCH] x86: privilege cleanup" as good, the
list of suspects looked like this (time flows bottom to top):

bad  [PATCH] i386 boottime for_each_cpu broken
     [PATCH] i386: encapsulate copying of pgd entries
     [PATCH] x86 NMI: better support for debuggers
???  [PATCH] x86: introduce a write acessor for updating the current LDT
     [PATCH] x86: remove redundant TSS clearing
     [PATCH] x86: make IOPL explicit
good [PATCH] x86: privilege cleanup

and you said the middle one is already bad here.  We are tracking
regression, so "privilege cleanup" was good and in the course of
somewhere from there to "i386 boottime for_each_cpu broken" which is
bad, a breakage happened.  You marked the "updating the current LDT"
one as bad, which to me looks like it was already broken at that point.

After that, you say:
bix:/usr/src/git26> git bisect good

to mark "[PATCH] x86: remove redundant TSS clearing" as good,
which means "redundant TSS" was good and "current LDT" was bad,
and they are back to back, so it looks like the bug was
introduced by the "LDT", which is what you got.  So it _might_
be possible that you said "current LDT" was bad when it was
actually good.  That is one possible explanation.

Another possibility is that the symptom you were tracking was
not a single regression that was introduced with a single patch.
Could it be possible that "the current LDT" did not pass your
test but from different bug, which was fixed by either "x86 NMI"
or "encapsulate copying pgd"?  Sorry I am not a kernel developer
so I cannot judge if the above is plausible or not.

In any case, there is one caveat about bisection bug search.  It
assumes that you are tracking a single regression that was
introduced, and there is no funny interaction of bugs hiding
each other -- this may not hold true in the real life.  IOW,
something like this could be possible:

BAD  [PATCH] i386 boottime for_each_cpu broken
good [PATCH] i386: encapsulate copying of pgd entries
bad  [PATCH] x86 NMI: better support for debuggers
BAD  [PATCH] x86: introduce a write acessor for updating the current LDT
good [PATCH] x86: remove redundant TSS clearing
good [PATCH] x86: make IOPL explicit
GOOD [PATCH] x86: privilege cleanup

I marked the ones bisect told you to test in Capital letters, and a
good/bad which was never tested in lowercase.  If the bug pattern is
not "up to here everything is good but after that things start to
break", then bisect, by its nature of skipping the check to narrow the
range down fast, would miss the real transition from good to bad.

Junio C Hamano [off-list ref] wrote:

So it _might_
 be possible that you said "current LDT" was bad when it was
 actually good.  That is one possible explanation.

I agree.  Mea culpa.  Sorry.

On Sat, 10 Sep 2005, Andrew Morton wrote:

Junio C Hamano [off-list ref] wrote:

quoted

So it _might_
 be possible that you said "current LDT" was bad when it was
 actually good.  That is one possible explanation.

I agree.  Mea culpa.  Sorry.

Well, this was actually something I hit when testign bisection too: it 
_is_ very unforgiving of mistakes.

That _may_ be something fundamental (hey, the point of bisection is that
you can get a lot of work done thanks to the log2(n) behaviour, but it
also means that a mistake ends up being easily multiplied). But on the 
other hand, maybe there could be nicer interfaces.

In particular, I suspect that we should save off the sequence of good/bad 
markers, so that it can be more easily re-created. Right now we only track 
the last "bad" marker, and we don't keep track of the order of the ones 
marked good. That's technically _sufficient_ for the job, but maybe we 
should have more of an audit trail.

With an audit trail, people could re-do the bisection if something goes 
wrong. Right now, if you by mistake mark something bad, and you 
immediately realize that it was a mistake, you can't undo it - because the 
old bad state was overwritten.

So the bisection algorithm may have done the right thing from a technical 
standpoint, but I suspect it could be made to be a bit more forgiving, or 
at least when somebody realizes that bisection didn't work right, we could 
have the trail of good/bad markings to try to debug what happened...

		Linus

Linus Torvalds [off-list ref] wrote:

On Sat, 10 Sep 2005, Andrew Morton wrote:
 >
 > Junio C Hamano [off-list ref] wrote:
 > >
 > > So it _might_
 > >  be possible that you said "current LDT" was bad when it was
 > >  actually good.  That is one possible explanation.
 > 
 > I agree.  Mea culpa.  Sorry.

 Well, this was actually something I hit when testign bisection too: it 
 _is_ very unforgiving of mistakes.

Yes.  That was my third attempt.  You basically _have_ to write down the
good/bad sequence as you go.  One slip and you've blown an hour's work.

 So the bisection algorithm may have done the right thing from a technical 
 standpoint, but I suspect it could be made to be a bit more forgiving, or 
 at least when somebody realizes that bisection didn't work right, we could 
 have the trail of good/bad markings to try to debug what happened...

Yup.  Simply keeping a little log file would suffice.

On Sat, 10 Sep 2005, Andrew Morton wrote:

Yup.  Simply keeping a little log file would suffice.

This is a _very_ cheesy and untested patch.

Oh, btw, it also fixes "git bisect reset" - we used to remove the file 
"refs/reads/bisect", not "refs/heads/bisect". 

Cheesy, cheesy, cheesy,

		Linus "not proud" Torvalds

---
Subject: Keep bisect event log

This keeps an event log in refs/bisect/log, which tracks what bisections 
have been done. We could eventually have a "git bisect replay" or 
somethign similar that actually uses it - for now we just have a command 
to show the log: "git bisect log".

Signed-off-by: Linus Torvalds <torvalds@osdl.org>
---

diff --git a/git-bisect.sh b/git-bisect.sh
--- a/git-bisect.sh
+++ b/git-bisect.sh

@@ -8,7 +8,8 @@ git bisect bad [<rev>]		mark <rev> a kno
 git bisect good [<rev>...]	mark <rev>... known-good revisions.
 git bisect next			find next bisection to test and check it out.
 git bisect reset [<branch>]	finish bisection search and go back to branch.
-git bisect visualize            show bisect status in gitk.'
+git bisect visualize            show bisect status in gitk.
+git bisect log                  show bisect log.'
     exit 1
 }
 

@@ -67,6 +68,7 @@ bisect_bad() {
 		usage ;;
 	esac || exit
 	echo "$rev" > "$GIT_DIR/refs/bisect/bad"
+	echo "bad $rev" >> "$GIT_DIR/refs/bisect/log"
 	bisect_auto_next
 }
 

@@ -81,6 +83,7 @@ bisect_good() {
 	do
 		rev=$(git-rev-parse --verify "$rev") || exit
 		echo "$rev" >"$GIT_DIR/refs/bisect/good-$rev"
+		echo "good $rev" >> "$GIT_DIR/refs/bisect/log"
 	done
 	bisect_auto_next
 }

@@ -149,7 +152,11 @@ bisect_reset() {
 	esac
 	git checkout "$branch" &&
 	rm -fr "$GIT_DIR/refs/bisect"
-	rm -f "$GIT_DIR/refs/reads/bisect"
+	rm -f "$GIT_DIR/refs/heads/bisect"
+}
+
+bisect_log() {
+	cat "$GIT_DIR/refs/bisect/log"
 }
 
 case "$#" in

@@ -172,6 +179,8 @@ case "$#" in
 	bisect_visualize "$@" ;;
     reset)
         bisect_reset "$@" ;;
+    log)
+        bisect_log "$@" ;;
     *)
         usage ;;
     esac