Re: rebase: strange failures to apply patc 3-way

From: Max Horn <max@quendi.de>
Date: Mar 11, 2013, 21:10 UTC
Message-ID: <E042F4D9-79DF-4AEF-8EDE-41BA9E5FB9EC@quendi.de>
In-Reply-To: <CADgNjanQxMFrQG=7SqgAXv5PW8OEfG+1kZt_Mrq27OcP1uyGtA@mail.gmail.com>

On 11.03.2013, at 20:15, Andrew Wong wrote:

Show 19 quoted lines

> On 3/10/13, Max Horn <max@quendi.de> wrote:
>> I did run
>> 
>>  touch lib/*.* src/*.* && git update-index --refresh && git diff-files
>> 
>> a couple dozen times (the "problematic" files where in src/ and lib), but
>> nothing happened. I just re-checked, and the rebase still fails in the same
>> why...
>> 
>> Perhaps I should add some printfs into the git source to figure out what
>> exactly it thinks is not right about those files... i.e. how does it come to
>> the conclusion that I have local changes, exactly. I don't know how Git does
>> that -- does it take the mtime from (l)stat into account? Perhaps problems
>> with my machine's clock could be responsible?
> 
> Instead of using "touch", maybe it'd be better if you run "ls-files"
> and "stat" at the point where rebase failed. You should run the
> command as soon as rebase failed. Don't try to run any git commands,
> as they might change the index state.

So I tried this:

  git rebase branches/stable-4.6  # ... which leads to the error
  git ls-files -m

but got nothing. Perhaps you had something else in mind, though, but I am not quite sure what... sorry for being dense, but if you let me know what exactly you meant, I'll be happy to try that. As for the stat command:

Show 12 quoted lines

> 
> And yes, git does make use of mtime and ctime from lstat to some
> degree when detecting file changes. Inserting printf's to print the
> timestamp might help, but the output might be too overwhelming to make
> out useful information, especially during a rebase.
> 
> BTW, it looks like "stat" command on OS X only prints out timestamps
> in seconds, and doesn't show you the nanoseconds part, which may be
> significant in your situation. Instead of using the "stat" command,
> try using this python command to print out the nanoseconds parts:
> python -c "import sys;import os;s=os.stat(sys.argv[1]);print('%d, %f,
> %f' % (s.st_size, s.st_ctime, s.st_mtime))" file1

I can do that, but I am not quite sure what the output should tell me? BTW, I think OS X just does not provide the stat information on a nanosecond level, at least that python command doesn't seem to yield useful extra data... Here is what I got after I just triggered the failing rebase (today it's again a different file it fails on that yesterday...). For comparision, I run stat first on the file with "conflicts", and then on a file that is not being touched by the rebase:

  File: ‘BAD-FILE’
  Size: 21058     	Blocks: 48         IO Block: 4096   regular file
Device: e000004h/234881028d	Inode: 19108072    Links: 1
Access: (0644/-rw-r--r--)  Uid: (  502/   mhorn)   Gid: (   20/   staff)
Access: 2013-03-11 21:40:14.000000000 +0100
Modify: 2013-03-11 21:40:12.000000000 +0100
Change: 2013-03-11 21:40:14.000000000 +0100
 Birth: 2013-03-11 21:40:12.000000000 +0100
  File: ‘NEUTRAL-FILE’
  Size: 1425      	Blocks: 8          IO Block: 4096   regular file
Device: e000004h/234881028d	Inode: 18180450    Links: 1
Access: (0644/-rw-r--r--)  Uid: (  502/   mhorn)   Gid: (   20/   staff)
Access: 2013-03-11 17:58:30.000000000 +0100
Modify: 2013-03-10 14:20:39.000000000 +0100
Change: 2013-03-10 14:20:39.000000000 +0100
 Birth: 2013-02-27 16:18:57.000000000 +0100

Here is the output of the python script for the two files: 21058, 1363034414.000000, 1363034412.000000 1425, 1362921639.000000, 1362921639.000000

One thing I notice is that ctime equals atime and both are larger than mtime. But I have no clue if that has any significance... hmm

Show 5 quoted lines

> Perhaps you could hack git-am.sh a bit to get more debugging info too.
> Hm, maybe a good place to start is un-silencing the output of "git
> apply". Inside "git-am.sh", you should see a line like:
>    git apply $squelch
> Remove the $squelch, and see what output it generates.

error: BAD-FILE: does not match index

I inserted "git ls-files -m" before that but that didn't print anything nor had it any other effect.

Show 5 quoted lines

> 
> Also, since you're getting the 3-way merge, you could also insert the
> "ls-files" and "stat" right after "git-merge-recursive", but before
> "die".
>

Aha, so that was interesting: I inserted both a "stat" invocation, and also invoked the "md5" tool to be able to tell whether the file content matched what I thought it should match. Doing that caused the breaking commit to shift. So, I added a second stat / md5 pair on the new breaking file. After doing that, the rebase suddenly completed! I reset -- hard to the previous state, tried again, and again it worked. And this after consistently failing (albeit in differing places) in maybe a hundred or more tries before. Removing those two calls, it failed again. I tried inserting a "sleep 1", just in case it's a race, but with that it still failed.

I then re-added the stat / md5 calls, and -- it failed again, but this much earlier (in commit 8, not around commits 14-18).

So I added the new conflicting fail to the stat/md5 calls (for a total of three files), and it failed in commit 4. Despite adding the new file (number 4),  it got stuck in this very commit in several attempts. I then for a while did some other stuff (like reading through the "git ls-files" man page ;-). Trying the rebase once more, with the stat / md5 calls on four files, it went back to failing in the place it started out failing today (commit 16). Adding / remove the stat&md5 invocations didn't seem to have an effect at this point.

Thanks, Max