[Bill Lear: I'm resending this to the git list --- I did not want to
publicize my trace output, so I have trimmed that. Below are Linus's
words.]
Ok, thanks. I'm going to be away for the next 24 hours, so won't be able
to look at it any closer, but hopefully nico or shawn will have found it
by then, or it will have resolved to a real NFS bug.
I did a very *quick* thing (the pread that fails is in process 28635, so I
looked at just that one), and the IO patterns are:
28635 open("/austin/users/blear/repos/git/fusion/objects/pack_pYGHgc", O_RDWR|O_CREAT|O_EXCL, 0600 <unfinished ...>
28635 <... open resumed> ) = 3
28635 read(0, <unfinished ...>
28635 <... read resumed> "PACK\0\0\0\2\0\0\21\362\236\17x\332\235\313AjC!\20\200"..., 4096) = 4096
28635 write(3, "PACK\0\0\0\2\0\0\21\362\236\17x\332\235\313AjC!\20\200"..., 4096 <unfinished ...>
28635 <... write resumed> ) = 4096
28635 read(0, <unfinished ...>
28635 <... read resumed> "\300\355i\31\204\330\343\205\365\365m\177\277\232\1\352"..., 4096) = 4096
28635 write(3, "\300\355i\31\204\330\343\205\365\365m\177\277\232\1\352"..., 4096 <unfinished ...>
28635 <... write resumed> ) = 4096
28635 read(0, <unfinished ...>
28635 <... read resumed> "\247h\264\217\23\23\232,\242a\202\1\317\276\354M\335\361"..., 4096) = 4096
28635 write(3, "\247h\264\217\23\23\232,\242a\202\1\317\276\354M\335\361"..., 4096) = 4096
...
(so yes, it seems to write the whole pack-file).
The only odd part is at the end of that sequence:
...
28635 read(0, <unfinished ...>
28635 <... read resumed> "\324/\356{Jc\277\251\20\f\375\210\347\271{m\222D\203S\t"..., 4096) = 3492
28635 write(3, "\324/\356{Jc\277\251\20\f\375\210\347\271{m\222D\203S\t"..., 3492 <unfinished ...>
28635 <... write resumed> ) = 3492
28635 read(0, <unfinished ...>
28635 <... read resumed> "\0349[:\')\30\352O\325\244\244[\17\342\251hL\233m", 4096) = 20
28635 write(3, "\34", 1 <unfinished ...>
28635 <... write resumed> ) = 1
(I skipped the writes to fd 2, which are just the "99% (4549/4594) done"
kind of messages). The strange thing here is that I think the last 20
bytes we read from fd 0 is the SHA1 of the whole pack-file, but then the
last *write* to the output pack-file is just a single-byte (\34), which is
just the first byte of the SHA1 we got. Maybe.
Regardless, we did a *lot* of writes to fd 3, yet then we get:
...
28635 pread(3, <unfinished ...>
28635 <... pread resumed> "", 207, 39395) = 0
28635 --- SIGALRM (Alarm clock) @ 0 (0) ---
28635 rt_sigreturn(0xe) = 0
28635 lseek(3, 0, SEEK_END) = 0
28635 write(2, "fatal: ", 7) = 7
28635 write(2, "cannot pread pack file: Success "..., 59) = 59
28635 write(2, "\n", 1) = 1
which really *does* seem like a NFS bug: the pread() seems to return 0,
and yes there is a SIGALRM going off that may be the cause of that return.
HOWEVER, the
lseek(3, 0, SEEK_END) = 0
also seems to indicate that somehow all the writes to fd 3 were dropped or
ignored, which makes me wonder whether the SIGALRM was involved after all
(because it shouldn't have affected the end result of the lseek anyway).
I'm confused. But I need to go now, so I can't look at it any more.
Linus
-
To unsubscribe from this list: send the line "unsubscribe git" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html