bisect gives strange answer

bisect gives strange answer

[Sanjoy Mahajan]

I have been having lots of fun using 'git bisect' to find the commit
that broke S3 wake on my laptop.  But in its last step it gives an
answer that cannot be right.  I had not used git until now, so I may be
missing something obvious: Corrections will be gratefully received.  I'm
using git from git-2005-08-03.tar.gz on i386 (TP 600X, Debian testing).

Before using git bisect, I had tested enough to know that 2.6.13-rc1 was
fine and 2.6.13-rc2-git1 was not (it would sleep but waking up would
hang).  So I compiled all the 2.6.13-rc1-git* snapshots and found that
2.6.13-rc1-git7 was the last one that worked, and 2.6.13-rc2-git1 was
the first to fail (see <http://bugzilla.kernel.org/show_bug.cgi?id=4989>
if you are curious about the bug itself).

Time to use 'git bisect' to find where in between the S3 wake got
broken.  I'll give all the commands I did so you can (hopefully!)
reproduce the problem.

I began by following the useful directions at
<http://linux.yyz.us/git-howto.html> to download the 2.6 repository:

repo=rsync://rsync.kernel.org/pub/scm/linux/kernel/git/torvalds/linux-2.6.git
git clone $repo linux-2.6
cd linux-2.6                  
rsync -a --verbose --stats --progress $repo/ .git/

Then I binary searched, compiling and testing, until bisect told me I
was done.  Here's the output of a script (run with #!/bin/bash -x) that
reproduces the problem in the clean archive made above.

======================================================================
+ git checkout
+ git bisect reset
+ git bisect start
+ git bisect good 17af691cd19765b782d891fc50c1568d0f1276b3  # 2.6.13-rc1-git7
+ git bisect bad c101f3136cc98a003d0d16be6fab7d0d950581a6   # 2.6.13-rc2-git1
Bisecting: 42 revisions left to test after this
+ cat .git/HEAD
b2f571026594884e7a2a3f8bc6ad5c92e0703330
+ git bisect good
Bisecting: 30 revisions left to test after this
+ cat .git/HEAD
450008b5a62bb09445ae05c4d01d510386c9435d
+ git bisect good
Bisecting: 15 revisions left to test after this
+ cat .git/HEAD
a9df3597fec5472d0840fbfdc2a3fac5268f7d08
+ git bisect bad
Bisecting: 8 revisions left to test after this
+ cat .git/HEAD
28e8c3ad9464de54a632f00ab3df88fa5f4652d1
+ git bisect bad
Bisecting: 4 revisions left to test after this
+ cat .git/HEAD
c774e93e2152d0be2612739418689e6e6400f4eb
+ git bisect bad
Bisecting: 2 revisions left to test after this
+ cat .git/HEAD
b4634484815e1879512a23e4f59eef648135c30a
+ git bisect bad
b4634484815e1879512a23e4f59eef648135c30a is first bad commit
diff-tree b4634484815e1879512a23e4f59eef648135c30a (from 3d3c2ae1101c1f2dff7e2f9d514769779dbd2737)
Author: Greg KH <greg@kroah.com>
Date:   Wed Jul 6 08:51:03 2005 -0700

    [PATCH] Fix bt87x.c build problem
    
    Missing forward declaration
    
    Signed-off-by: Greg Kroah-Hartman <gregkh@suse.de>
    Signed-off-by: Linus Torvalds <torvalds@osdl.org>

:040000 040000 5717e17e384b0b40e409966403e2b8dfdab615a9 4ba0c028e80bf81c5c782e9047bd484a1eeadca4 M	sound
======================================================================

The answer makes no sense since my .config doesn't use the bt87x driver
(the TP600X uses a snd-cs46xx).  To be sure, I checked the diff with

  git diff 3d3c2ae1101c1f2dff7e2f9d514769779dbd2737..b4634484815e1879512a23e4f59eef648135c30a

The commit changed only sound/pci/bt87x.c

I do believe this line at the end of the bisection:

  b4634484815e1879512a23e4f59eef648135c30a is first bad commit

But 
  diff-tree b4634484815e1879512a23e4f59eef648135c30a (from 3d3c2ae1101c1f2dff7e2f9d514769779dbd2737)

cannot be right.  Where did 3d3c2ae1101c1f2dff7e2f9d514769779dbd2737
come from?  The last good commit was
  450008b5a62bb09445ae05c4d01d510386c9435d 
so shouldn't bisect (if there's really only 1 commit in left now) say

  diff-tree b4634484815e1879512a23e4f59eef648135c30a (from 450008b5a62bb09445ae05c4d01d510386c9435d)

  $ git diff 450008b5a62bb09445ae05c4d01d510386c9435d \
              b4634484815e1879512a23e4f59eef648135c30a \
    | grep 'diff --git' | awk '{print $3}'

produces this list of changed files (I'm sure there's an easier way):

a/arch/arm/kernel/armksyms.c
a/arch/arm/mach-ixp4xx/common-pci.c
a/arch/arm/mach-ixp4xx/coyote-setup.c
a/arch/arm/mach-ixp4xx/ixdp425-setup.c
a/arch/arm/mm/proc-v6.S
a/drivers/pci/pci-driver.c
a/include/asm-arm/arch-ixp4xx/io.h
a/sound/pci/bt87x.c

I suspect that bisect jumped the gun at the end, and that there are a
few more revisions to test.  Maybe the revision tree structure gets a
bit complicated and breaks an implicit linearity assumption  in bisect?

Probably 3d3c2ae1101c1f2dff7e2f9d514769779dbd2737 is the commit just
before b4634484815e1879512a23e4f59eef648135c30a (the first one I know to
be bad), and I'm guessing that 3d3c2ae1101c1f2dff7e2f9d514769779dbd2737
is bad too.

The suspect change is probably to drivers/pci/pci-driver.c since all the
other changed files are the unused bt87x sound driver or are for the arm
architecture.  Here is that diff:

diff --git a/drivers/pci/pci-driver.c b/drivers/pci/pci-driver.c
--- a/drivers/pci/pci-driver.c
+++ b/drivers/pci/pci-driver.c
@@ -17,13 +17,13 @@
  * Dynamic device IDs are disabled for !CONFIG_HOTPLUG
  */
 
+#ifdef CONFIG_HOTPLUG
+
 struct pci_dynid {
 	struct list_head node;
 	struct pci_device_id id;
 };
 
-#ifdef CONFIG_HOTPLUG
-
 /**
  * store_new_id
  *


But whether moving back the CONFIG_HOTPLUG fixes my S3 wake is another
story, one for the acpi-devel list (once I do the experiment).

Re: bisect gives strange answer

[Junio C Hamano]

Sanjoy Mahajan <sanjoy@mrao.cam.ac.uk> writes:

> + git bisect bad
> Bisecting: 2 revisions left to test after this
> + cat .git/HEAD
> b4634484815e1879512a23e4f59eef648135c30a
> + git bisect bad
> b4634484815e1879512a23e4f59eef648135c30a is first bad commit
> diff-tree b4634484815e1879512a23e4f59eef648135c30a (from 3d3c2ae1101c1f2dff7e2f9d514769779dbd2737)
> The answer makes no sense since my .config doesn't use the bt87x driver
> (the TP600X uses a snd-cs46xx).  To be sure, I checked the diff with
>
>   git diff 3d3c2ae1101c1f2dff7e2f9d514769779dbd2737..b4634484815e1879512a23e4f59eef648135c30a
>
> The commit changed only sound/pci/bt87x.c
>
> I do believe this line at the end of the bisection:
>
>   b4634484815e1879512a23e4f59eef648135c30a is first bad commit
>...
> I suspect that bisect jumped the gun at the end, and that there are a
> few more revisions to test.

Thank you for a very useful reproduction recipe.  I think this
is my bug.  Could you try this please?

------------
diff --git a/git-bisect-script b/git-bisect-script
--- a/git-bisect-script
+++ b/git-bisect-script
@@ -107,8 +107,8 @@ bisect_next() {
 	rev=$(eval "git-rev-list --bisect $good $bad") || exit
 	nr=$(eval "git-rev-list $rev $good" | wc -l) || exit
 	if [ "$nr" -le "1" ]; then
-	    echo "$bad is first bad commit"
-	    git-diff-tree --pretty $bad
+	    echo "$rev is first bad commit"
+	    git-diff-tree --pretty $rev
 	    exit 0
 	fi
 	echo "Bisecting: $nr revisions left to test after this"

Re: bisect gives strange answer

[Sanjoy Mahajan]

> Could you try this please?

Thanks, it now finishes with the diff that I expected:

3d3c2ae1101c1f2dff7e2f9d514769779dbd2737 is first bad commit
diff-tree 3d3c2ae1101c1f2dff7e2f9d514769779dbd2737 (from a18bcb7450840f07a772a45229de4811d930f461)
Author: Greg KH <gregkh@suse.de>
Date:   Wed Jul 6 09:09:38 2005 -0700

    [PATCH] PCI: fix !CONFIG_HOTPLUG pci build problem
    
    Here's a patch to fix the build issue when CONFIG_HOTPLUG is not enabled
    in 2.6.13-rc2.
    
    Signed-off-by: Greg Kroah-Hartman <gregkh@suse.de>
    Signed-off-by: Linus Torvalds <torvalds@osdl.org>

:040000 040000 93e93c4d8e88d6e05e815261f96ab38376c92809 b9cbda6dd88aeca51031d36e00f396e7091fd54c M	drivers


The full run is included below.

-Sanjoy

`A society of sheep must in time beget a government of wolves.'
   - Bertrand de Jouvenal


+ git bisect reset
+ git bisect start
+ git bisect good 17af691cd19765b782d891fc50c1568d0f1276b3
+ git bisect bad c101f3136cc98a003d0d16be6fab7d0d950581a6
Bisecting: 42 revisions left to test after this
+ cat .git/HEAD
b2f571026594884e7a2a3f8bc6ad5c92e0703330
+ git bisect good
Bisecting: 30 revisions left to test after this
+ cat .git/HEAD
450008b5a62bb09445ae05c4d01d510386c9435d
+ git bisect good
Bisecting: 15 revisions left to test after this
+ cat .git/HEAD
a9df3597fec5472d0840fbfdc2a3fac5268f7d08
+ git bisect bad
Bisecting: 8 revisions left to test after this
+ cat .git/HEAD
28e8c3ad9464de54a632f00ab3df88fa5f4652d1
+ git bisect bad
Bisecting: 4 revisions left to test after this
+ cat .git/HEAD
c774e93e2152d0be2612739418689e6e6400f4eb
+ git bisect bad
Bisecting: 2 revisions left to test after this
+ cat .git/HEAD
b4634484815e1879512a23e4f59eef648135c30a
+ git bisect bad
3d3c2ae1101c1f2dff7e2f9d514769779dbd2737 is first bad commit
diff-tree 3d3c2ae1101c1f2dff7e2f9d514769779dbd2737 (from a18bcb7450840f07a772a45229de4811d930f461)
Author: Greg KH <gregkh@suse.de>
Date:   Wed Jul 6 09:09:38 2005 -0700

    [PATCH] PCI: fix !CONFIG_HOTPLUG pci build problem
    
    Here's a patch to fix the build issue when CONFIG_HOTPLUG is not enabled
    in 2.6.13-rc2.
    
    Signed-off-by: Greg Kroah-Hartman <gregkh@suse.de>
    Signed-off-by: Linus Torvalds <torvalds@osdl.org>

:040000 040000 93e93c4d8e88d6e05e815261f96ab38376c92809 b9cbda6dd88aeca51031d36e00f396e7091fd54c M	drivers

Re: bisect gives strange answer

[Greg KH]

On Thu, Aug 04, 2005 at 03:23:28AM -0400, Sanjoy Mahajan wrote:
> > Could you try this please?
> 
> Thanks, it now finishes with the diff that I expected:
> 
> 3d3c2ae1101c1f2dff7e2f9d514769779dbd2737 is first bad commit
> diff-tree 3d3c2ae1101c1f2dff7e2f9d514769779dbd2737 (from a18bcb7450840f07a772a45229de4811d930f461)
> Author: Greg KH <gregkh@suse.de>
> Date:   Wed Jul 6 09:09:38 2005 -0700
> 
>     [PATCH] PCI: fix !CONFIG_HOTPLUG pci build problem
>     
>     Here's a patch to fix the build issue when CONFIG_HOTPLUG is not enabled
>     in 2.6.13-rc2.
>     
>     Signed-off-by: Greg Kroah-Hartman <gregkh@suse.de>
>     Signed-off-by: Linus Torvalds <torvalds@osdl.org>

By any chance, is this patch causing you problems?

Just curious :)

greg k-h

Re: bisect gives strange answer

[Sanjoy Mahajan]

> By any chance, is this patch causing you problems?

No, sadly.  But I had hopes!  As I think about it more, there's no way
it could, since I have CONFIG_HOTPLUG=y, so moving the CONFIG_HOTPLUG
would not change anything (for those who don't know the patch, it is
appended below).  

My latest theory is that I fed bisect incorrect good/bad data.
Perhaps If I had checked out and compiled those intermediate versions
from scratch, each version in a separate directory, then I would have
got different answers.  Two possible reasons:

1. The kernel Makefiles ar do not understand every subtle dependency.
   So they might get confused by updating to different tree states (as
   the bisect progresses) because those updates change Makefiles and
   include files.  In other words, I should have done 'make clean' or
   'make mrproper' before each kernel compile.

2. git-bisect-script doesn't use -f when it does 'git checkout', so
   files that should be updated are not.  Right now I'm in the middle
   of recollecting the data with git-bisect-script using -f in all
   uses of git checkout (unless that is a really silly idea).

-Sanjoy


git diff a18bcb7450840f07a772..3d3c2ae1101c1f2dff7e2f9d514769779dbd2737
diff --git a/drivers/pci/pci-driver.c b/drivers/pci/pci-driver.c
--- a/drivers/pci/pci-driver.c
+++ b/drivers/pci/pci-driver.c
@@ -17,13 +17,13 @@
  * Dynamic device IDs are disabled for !CONFIG_HOTPLUG
  */
 
-#ifdef CONFIG_HOTPLUG
-
 struct pci_dynid {
	struct list_head node;
	struct pci_device_id id;
 };
 
+#ifdef CONFIG_HOTPLUG
+
 /**
  * store_new_id
  *

Re: bisect gives strange answer

[Dave Jones]

On Thu, Aug 04, 2005 at 06:41:41PM +0100, Sanjoy Mahajan wrote:
 > > By any chance, is this patch causing you problems?
 > 
 > No, sadly.  But I had hopes!  As I think about it more, there's no way
 > it could, since I have CONFIG_HOTPLUG=y, so moving the CONFIG_HOTPLUG
 > would not change anything (for those who don't know the patch, it is
 > appended below).  
 > 
 > My latest theory is that I fed bisect incorrect good/bad data.
 > Perhaps If I had checked out and compiled those intermediate versions
 > from scratch, each version in a separate directory, then I would have
 > got different answers.  Two possible reasons:

Errrrm, if you don't compile/test those intermediate versions,
how do you know whether to tag it good/bad ?

		Dave

Re: bisect gives strange answer

[Sanjoy Mahajan]

> Errrrm, if you don't compile/test those intermediate versions,
> how do you know whether to tag it good/bad ?

Sorry, I wrote this part carelessly: "If I had checked out and
compiled those intermediate versions from scratch..."

I meant to emphasize the 'from scratch'.  I did check out and compile
the versions, but I didn't compile from scratch. i.e. I just took
whatever directory tree I got after

  git bisect good
or
  git bisect bad

and then did 'make -j 4'.  Perhaps I should have done

  make clean 
  <restore .config>
  make -j 4

to be really sure that every file that needed recompilation got
recompiled.

-Sanjoy

Re: bisect gives strange answer

[Junio C Hamano]

Dave Jones <davej@redhat.com> writes:

> Errrrm, if you don't compile/test those intermediate versions,
> how do you know whether to tag it good/bad ?

I think Sanjoy is saying that they _were_ tested, and suspects
that bisect didn't leave the right versions of the files in the
work tree, so what was compiled and tested were not what bisect
wanted to get tested.  This is theory #2 in Sanjoy's post:

>> 2. git-bisect-script doesn't use -f when it does 'git checkout', so
>>    files that should be updated are not.  Right now I'm in the middle
>>    of recollecting the data with git-bisect-script using -f in all
>>    uses of git checkout (unless that is a really silly idea).

I find this explanation quite plausible, in case it is all my
fault and I apologize for wasting kernel developers' time.

Re: bisect gives strange answer

[Sam Ravnborg]

> 
> 1. The kernel Makefiles ar do not understand every subtle dependency.
>    So they might get confused by updating to different tree states (as
>    the bisect progresses) because those updates change Makefiles and
>    include files.  In other words, I should have done 'make clean' or
>    'make mrproper' before each kernel compile.

If you see any sort of evidence that this would hold true I really like
to know.
The current build system is only known to fail if a changed file gets a
timestamp that is not equal to 'now'. Some braindead SCM uses the
timestamp of the chekin.

There has been put a tremendous effort in tracking each and every subtle
dependeny - and if something is missing then it ought to be fixed.

	Sam

Re: bisect gives strange answer

[Sanjoy Mahajan]

> If you see any sort of evidence that this would hold true I really like
> to know.

I haven't found any evidence.  When I rebuilt the kernels from scratch
(exporting them into an empty directory using cg-export), I got
reliable data and bisected down to a patch that probably was a problem.

I will redo those tests but rebuilding in place after each bisection
(with -f added to all the git checkout uses in git-bisect-script) and
see whether I get the same results.  If I don't, it could be due to
git or git-bisect (but not so likely with the -f switch) or to the
build system.  Will keep you and Junio posted.

-Sanjoy

Re: bisect gives strange answer

[Junio C Hamano]

Sanjoy Mahajan <sanjoy@mrao.cam.ac.uk> writes:

> I will redo those tests but rebuilding in place after each bisection
> (with -f added to all the git checkout uses in git-bisect-script) and
> see whether I get the same results.  If I don't, it could be due to
> git or git-bisect (but not so likely with the -f switch) or to the
> build system.  Will keep you and Junio posted.

I thought the lack of '-f' was a plausible explanation, but here
is what I just did.  The same bisect sequence in your example,
making sure the state of working tree matches what the commit
being tested:

    $ git bisect start
    $ git bisect good 17af691cd19765b782d891fc50c1568d0f1276b3
    $ git bisect bad c101f3136cc98a003d0d16be6fab7d0d950581a6
    Bisecting: 42 revisions left to test after this
    $ cat .git/HEAD
    b2f571026594884e7a2a3f8bc6ad5c92e0703330
    $ git bisect good; cat .git/HEAD; git-diff-cache -r bisect
    Bisecting: 30 revisions left to test after this
    450008b5a62bb09445ae05c4d01d510386c9435d
    $ git bisect good; cat .git/HEAD; git-diff-cache -r bisect
    Bisecting: 15 revisions left to test after this
    a9df3597fec5472d0840fbfdc2a3fac5268f7d08
    $ git bisect bad; cat .git/HEAD; git-diff-cache -r bisect
    Bisecting: 8 revisions left to test after this
    28e8c3ad9464de54a632f00ab3df88fa5f4652d1
    $ git bisect bad; cat .git/HEAD; git-diff-cache -r bisect
    Bisecting: 4 revisions left to test after this
    c774e93e2152d0be2612739418689e6e6400f4eb
    $ git bisect bad; cat .git/HEAD; git-diff-cache -r bisect
    Bisecting: 2 revisions left to test after this
    b4634484815e1879512a23e4f59eef648135c30a

So it does not appear to me that lack of '-f' is a problem.
Without the flag, checkout does "read-tree -m -u" which means to
update the working tree to match the new tree being read (this
includes the removal of files from the working tree that were
registered in the original index file that are not in the next
tree).

Re: bisect gives strange answer

[Junio C Hamano]

Sanjoy Mahajan <sanjoy@mrao.cam.ac.uk> writes:

> I'm having doing a stupidity with git, but here's what is confusing me
> about using bisect:
>
> If I start with a clean directory except for a 2.6 .git/ (where master =
> d95a1b4818f2fe38a3cfc9a7d5817dc9a1a69329), then do
>
> $ cd linux-2.6
> $ ls
> $ cat .git/HEAD
> d95a1b4818f2fe38a3cfc9a7d5817dc9a1a69329
> $ git bisect start
> $ git bisect good 17af691cd19765b782d891fc50c1568d0f1276b3
> $ git bisect bad c101f3136cc98a003d0d16be6fab7d0d950581a6  
> Bisecting: 42 revisions left to test after this
> $ ls
> arch	 Documentation	include  kernel       Makefile	README	  sound
> CREDITS  drivers	init	 lib	      mm	scripts
> crypto	 fs		ipc	 MAINTAINERS  net	security
>
> What happened to, for example, COPYING?  Maybe I am doing something
> silly (which I did before so I didn't get the right kernel trees to
> compile?).  If I do 'git reset' first, then COPYING is there.

Although I think what you saw is pathological, I do not think it
is what you did that is wrong.  The same thing happens if you
have .git/HEAD pointing at some version, you have nothing
checked out, and "git pull" from the upstream which results in a
fast forward merge.  Only the files that have been changed
between ORIG_HEAD and FETCH_HEAD are checked out.

What is happening is that git-checkout-script, which uses
"git-read-tree -m -u", checks out only the files that have
changed between the "current suspect" version and "next suspect"
version, leaving other paths untouched.  This means that if
"other paths" were not in the working tree to begin with, they
are left not-checked-out.

This is because the 'git-read-tree -m A B' is designed to allow
two-tree fast-forward merge work safely in a working tree that
has local modifications.  The local modification in your case is
that "you removed all files".  This is further complicated by
that the low-level git design wants to work in a non-populated
tree and treats not having a file in the working tree a bit
differently from having a file that is modified in the working
tree.  read-tree.c::verify_uptodate() function says when you
removed a file that is recorded in the index, it does not
consider you have a local modification on that path.

The paths that were not checked out fall in the case 14 in the
Documentation/git-read-tree.txt "Two Tree Merge" table, and the
path is not marked for update in "keep index" cases.

Although I think what git-read-tree currently does is
defensible, I do not think what "git checkout" does is.  The
user is asking things to be checked out so it is not a "work
without files in working tree" case anymore.

Maybe we should check if the working tree is clean before using
git-read-tree -m -u and require --force if it is not, perhaps?

The following patch is not tested at all but I am throwing it
out in the open early, in case the approach I am taking is
totally going in the wrong direction.


---
cd /opt/packrat/playpen/public/in-place/git/git.junio/
jit-diff
# - pu: Debian packaging fixes.
# + (working tree)
diff --git a/git-checkout-script b/git-checkout-script
--- a/git-checkout-script
+++ b/git-checkout-script
@@ -56,7 +56,9 @@ then
     git-read-tree --reset $new &&
 	git-checkout-cache -q -f -u -a
 else
-    git-read-tree -m -u $old $new
+    git-update-cache --refresh &&
+    git-read-tree -m -u $old $new ||
+    	die "git checkout: your working tree is dirty"
 fi
 
 # 
diff --git a/read-tree.c b/read-tree.c
--- a/read-tree.c
+++ b/read-tree.c
@@ -86,7 +86,7 @@ static void verify_uptodate(struct cache
 			return;
 		errno = 0;
 	}
-	if (errno == ENOENT)
+	if (errno == ENOENT && !update)
 		return;
 	die("Entry '%s' not uptodate. Cannot merge.", ce->name);
 }