Error "fatal: cannot pread pack file: Success"

Error "fatal: cannot pread pack file: Success"

[Bill Lear]

Using 1.5.0.1.  Can't see what is wrong with this clone...

% df -h .
Filesystem            Size  Used Avail Use% Mounted on
store:/storage/disk1
                      682G  113G  535G  18% /austin

% git clone --bare ~/devel/project
Initialized empty Git repository in /austin/users/rael/repos/git/project/
remote: Generating pack...
remote: Done counting 4589 objects.
remote: Deltifying 4589 objects.
 100% (4589/4589) done89) done
Indexing 4589 objects.
remote: Total 4589 (delta 2209), reused 4589 (delta 2209)
 100% (4589/4589) done
Resolving 2209 deltas.
fatal: cannot pread pack file: Success
fatal: index-pack died with error code 128
fetch-pack from '/home/rael/devel/project/.git' failed.

% mkdir project
% touch project/foo
% ls -l project/foo
-rw-r--r--  1 rael software 0 Feb 27 21:44 project/foo
% rm -rf project

% cd ~/devel
% df -h .
Filesystem            Size  Used Avail Use% Mounted on
/dev/sda5             186G   82G   95G  47% /home
% mkdir test
% cd test

% git clone --bare ~/devel/project
Initialized empty Git repository in /home/rael/test/project/
remote: Generating pack...
remote: Done counting 4589 objects.
remote: Deltifying 4589 objects.
  7Indexing 4589 objects. done
 100% (4589/4589) done89) done4589) done
remote: Total 4589 (delta 2209), reused 4589 (delta 2209)
 100% (4589/4589) done
Resolving 2209 deltas.
 100% (2209/2209) done

This happens repeatedly.  git fsck of my repo shows no problems.

Anything else I can check?


Bill

Re: Error "fatal: cannot pread pack file: Success"

[Shawn O. Pearce]

Bill Lear <rael@zopyra.com> wrote:
> Using 1.5.0.1.  Can't see what is wrong with this clone...
...
> Indexing 4589 objects.
> remote: Total 4589 (delta 2209), reused 4589 (delta 2209)
>  100% (4589/4589) done
> Resolving 2209 deltas.
> fatal: cannot pread pack file: Success
> fatal: index-pack died with error code 128
> fetch-pack from '/home/rael/devel/project/.git' failed.

What platform is this?  index-pack failed to read using pread(),
but the error code in errno was 0 (success)?  Huh?

It turns out this is steaming from a short read; we asked for some
length of bytes but did not get that exact value.  That sounds like
the packfile is truncated.

Ohh - is this repository on NFS, or some other sort of network
filesystem?  Maybe the FS couldn't give us the entire pread request
in one shot...

I think the pread() in get_data_from_pack of index-pack is wrong,
it really should be looping until we fill the buffer in case the
OS doesn't fully satisfy our read request the first time.

-- 
Shawn.

Re: Error "fatal: cannot pread pack file: Success"

[Shawn O. Pearce]

"Shawn O. Pearce" <spearce@spearce.org> wrote:
> Bill Lear <rael@zopyra.com> wrote:
> > Using 1.5.0.1.  Can't see what is wrong with this clone...
> ...
> > Indexing 4589 objects.
> > remote: Total 4589 (delta 2209), reused 4589 (delta 2209)
> >  100% (4589/4589) done
> > Resolving 2209 deltas.
> > fatal: cannot pread pack file: Success
> > fatal: index-pack died with error code 128
> > fetch-pack from '/home/rael/devel/project/.git' failed.
> 
> I think the pread() in get_data_from_pack of index-pack is wrong,
> it really should be looping until we fill the buffer in case the
> OS doesn't fully satisfy our read request the first time.

Does this fix your problem?

-->8--
[PATCH] index-pack: Loop over pread until data loading is complete.

A filesystem might not be able to completely supply our pread
request in one system call, such as if we are reading data from a
network file system and the requested length is just simply huge.

Signed-off-by: Shawn O. Pearce <spearce@spearce.org>
---
 index-pack.c |   10 ++++++++--
 1 files changed, 8 insertions(+), 2 deletions(-)

diff --git a/index-pack.c b/index-pack.c
index 859ec01..cf81a99 100644
--- a/index-pack.c
+++ b/index-pack.c
@@ -277,13 +277,19 @@ static void *get_data_from_pack(struct object_entry *obj)
 {
 	unsigned long from = obj[0].offset + obj[0].hdr_size;
 	unsigned long len = obj[1].offset - from;
+	unsigned long rdy = 0;
 	unsigned char *src, *data;
 	z_stream stream;
 	int st;
 
 	src = xmalloc(len);
-	if (pread(pack_fd, src, len, from) != len)
-		die("cannot pread pack file: %s", strerror(errno));
+	data = src;
+	do {
+		ssize_t n = pread(pack_fd, data + rdy, len - rdy, from + rdy);
+		if (n <= 0)
+			die("cannot pread pack file: %s", strerror(errno));
+		rdy += n;
+	} while (rdy < len);
 	data = xmalloc(obj->size);
 	memset(&stream, 0, sizeof(stream));
 	stream.next_out = data;
-- 
1.5.0.2.775.g1a500

-- 
Shawn.

Re: Error "fatal: cannot pread pack file: Success"

[Junio C Hamano]

"Shawn O. Pearce" <spearce@spearce.org> writes:

> "Shawn O. Pearce" <spearce@spearce.org> wrote:
>> Bill Lear <rael@zopyra.com> wrote:
>> > Using 1.5.0.1.  Can't see what is wrong with this clone...
>> ...
>> > Indexing 4589 objects.
>> > remote: Total 4589 (delta 2209), reused 4589 (delta 2209)
>> >  100% (4589/4589) done
>> > Resolving 2209 deltas.
>> > fatal: cannot pread pack file: Success
>> > fatal: index-pack died with error code 128
>> > fetch-pack from '/home/rael/devel/project/.git' failed.
>> 
>> I think the pread() in get_data_from_pack of index-pack is wrong,
>> it really should be looping until we fill the buffer in case the
>> OS doesn't fully satisfy our read request the first time.

The patch looks correct, even if this was not the problem Bill
is suffering from.

> [PATCH] index-pack: Loop over pread until data loading is complete.
>
> A filesystem might not be able to completely supply our pread
> request in one system call, such as if we are reading data from a
> network file system and the requested length is just simply huge.
>
> Signed-off-by: Shawn O. Pearce <spearce@spearce.org>
> ---
>  index-pack.c |   10 ++++++++--
>  1 files changed, 8 insertions(+), 2 deletions(-)
>
> diff --git a/index-pack.c b/index-pack.c
> index 859ec01..cf81a99 100644
> --- a/index-pack.c
> +++ b/index-pack.c
> @@ -277,13 +277,19 @@ static void *get_data_from_pack(struct object_entry *obj)
>  {
>  	unsigned long from = obj[0].offset + obj[0].hdr_size;
>  	unsigned long len = obj[1].offset - from;
> +	unsigned long rdy = 0;
>  	unsigned char *src, *data;
>  	z_stream stream;
>  	int st;
>  
>  	src = xmalloc(len);
> -	if (pread(pack_fd, src, len, from) != len)
> -		die("cannot pread pack file: %s", strerror(errno));
> +	data = src;
> +	do {
> +		ssize_t n = pread(pack_fd, data + rdy, len - rdy, from + rdy);
> +		if (n <= 0)
> +			die("cannot pread pack file: %s", strerror(errno));
> +		rdy += n;
> +	} while (rdy < len);
>  	data = xmalloc(obj->size);
>  	memset(&stream, 0, sizeof(stream));
>  	stream.next_out = data;
> -- 
> 1.5.0.2.775.g1a500
>
> -- 
> Shawn.

Re: Error "fatal: cannot pread pack file: Success"

[Bill Lear]

On Tuesday, February 27, 2007 at 23:47:19 (-0500) Shawn O. Pearce writes:
>"Shawn O. Pearce" <spearce@spearce.org> wrote:
>> Bill Lear <rael@zopyra.com> wrote:
>> > Using 1.5.0.1.  Can't see what is wrong with this clone...
>> ...
>> > Indexing 4589 objects.
>> > remote: Total 4589 (delta 2209), reused 4589 (delta 2209)
>> >  100% (4589/4589) done
>> > Resolving 2209 deltas.
>> > fatal: cannot pread pack file: Success
>> > fatal: index-pack died with error code 128
>> > fetch-pack from '/home/rael/devel/project/.git' failed.
>> 
>> I think the pread() in get_data_from_pack of index-pack is wrong,
>> it really should be looping until we fill the buffer in case the
>> OS doesn't fully satisfy our read request the first time.
>
>Does this fix your problem?

Just got back: I will try applying this patch and testing with it
and let you know.

Yes, this is a mounted filesystem --- I did post the 'df -h' to show
this because I suspected something awry with it being a mounted drive.

I'll let you know if this fixes it...


Bill

Re: Error "fatal: cannot pread pack file: Success"

[Linus Torvalds]

On Tue, 27 Feb 2007, Junio C Hamano wrote:

> "Shawn O. Pearce" <spearce@spearce.org> writes:
> >> 
> >> I think the pread() in get_data_from_pack of index-pack is wrong,
> >> it really should be looping until we fill the buffer in case the
> >> OS doesn't fully satisfy our read request the first time.
> 
> The patch looks correct, even if this was not the problem Bill
> is suffering from.

Ack. 

Although I would almost prefer it if we just did it like we do a lot of 
the other cases: call it "xpread()" instead, and have the loop there.

The reason I didn't do that in the first place is that a file access is 
supposed to be fully satisfied anyway, but yeah, NFS with an interruptible 
mount will break that posix guarantee, so the loop is definitely the right 
thing to do.

		Linus

Re: Error "fatal: cannot pread pack file: Success"

[Bill Lear]

On Wednesday, February 28, 2007 at 09:28:15 (-0600) Bill Lear writes:
>On Tuesday, February 27, 2007 at 23:47:19 (-0500) Shawn O. Pearce writes:
>>"Shawn O. Pearce" <spearce@spearce.org> wrote:
>>> Bill Lear <rael@zopyra.com> wrote:
>>> > Using 1.5.0.1.  Can't see what is wrong with this clone...
>>> ...
>>> > Indexing 4589 objects.
>>> > remote: Total 4589 (delta 2209), reused 4589 (delta 2209)
>>> >  100% (4589/4589) done
>>> > Resolving 2209 deltas.
>>> > fatal: cannot pread pack file: Success
>>> > fatal: index-pack died with error code 128
>>> > fetch-pack from '/home/rael/devel/project/.git' failed.
>>> 
>>> I think the pread() in get_data_from_pack of index-pack is wrong,
>>> it really should be looping until we fill the buffer in case the
>>> OS doesn't fully satisfy our read request the first time.
>>
>>Does this fix your problem?
>
>Just got back: I will try applying this patch and testing with it
>and let you know.

No, does not fix.  I added a bit more printout on the error:

% git clone --bare ~/devel/project
Initialized empty Git repository in /austin/users/rael/repos/git/project
remote: Generating pack...
remote: Done counting 4594 objects.
remote: Deltifying 4594 objects.
remote:  100% (4594/4594) done
Indexing 4594 objects.
remote: Total 4594 (delta 2210), reused 4591 (delta 2209)
 100% (4594/4594) done
Resolving 2210 deltas.
fatal: cannot pread pack file: Success [n=0; rdy=0; len=207]
fatal: index-pack died with error code 128
fetch-pack from '/home/rael/devel/fusion/.git' failed.


Bill

Re: Error "fatal: cannot pread pack file: Success"

[Shawn O. Pearce]

Bill Lear <rael@zopyra.com> wrote:
> fatal: cannot pread pack file: Success [n=0; rdy=0; len=207]
> fatal: index-pack died with error code 128
> fetch-pack from '/home/rael/devel/fusion/.git' failed.

Bwhat?!?  Can you print out the offset and the size of the packfile?
It looks like your pack has been truncated?  Or is this just your
filesystem saying "nahh, I'm not going to give you that data right
now, try again later and maybe I will"?

I fail to see how a pread with a length of 207 is getting an EOF
return unless the packfile is short.

-- 
Shawn.

Re: Error "fatal: cannot pread pack file: Success"

[Bill Lear]

On Wednesday, February 28, 2007 at 10:54:12 (-0500) Shawn O. Pearce writes:
>Bill Lear <rael@zopyra.com> wrote:
>> fatal: cannot pread pack file: Success [n=0; rdy=0; len=207]
>> fatal: index-pack died with error code 128
>> fetch-pack from '/home/rael/devel/project/.git' failed.
>
>Bwhat?!?  Can you print out the offset and the size of the packfile?
>It looks like your pack has been truncated?  Or is this just your
>filesystem saying "nahh, I'm not going to give you that data right
>now, try again later and maybe I will"?

The code has this:

        unsigned long from = obj[0].offset + obj[0].hdr_size;
        unsigned long len = obj[1].offset - from;

by "offset", do you want obj[0].offset and obj[1].offset?

How do I get the size of the packfile?  Is it obj->size?

Well, I went ahead and did that.  Here are the results:

% git clone --bare ~/devel/project
[...]
Resolving 2210 deltas.
fatal: cannot pread pack file: Success [obj[0].offset=39393; obj[1].offset=39602; n=305; obj->size=0; rdy=0; len=207]
fatal: index-pack died with error code 128

Let me know if that is not what you intended.


Bill

Re: Error "fatal: cannot pread pack file: Success"

[Bill Lear]

On Wednesday, February 28, 2007 at 10:12:50 (-0600) Bill Lear writes:
>On Wednesday, February 28, 2007 at 10:54:12 (-0500) Shawn O. Pearce writes:
>>Bill Lear <rael@zopyra.com> wrote:
>>> fatal: cannot pread pack file: Success [n=0; rdy=0; len=207]
>>> fatal: index-pack died with error code 128
>>> fetch-pack from '/home/rael/devel/project/.git' failed.
>>
>>Bwhat?!?  Can you print out the offset and the size of the packfile?
>>It looks like your pack has been truncated?  Or is this just your
>>filesystem saying "nahh, I'm not going to give you that data right
>>now, try again later and maybe I will"?
>
>The code has this:
>
>        unsigned long from = obj[0].offset + obj[0].hdr_size;
>        unsigned long len = obj[1].offset - from;
>
>by "offset", do you want obj[0].offset and obj[1].offset?
>
>How do I get the size of the packfile?  Is it obj->size?
>
>Well, I went ahead and did that.  Here are the results:
>
>% git clone --bare ~/devel/project
>[...]
>Resolving 2210 deltas.
>fatal: cannot pread pack file: Success [obj[0].offset=39393; obj[1].offset=39602; n=305; obj->size=0; rdy=0; len=207]
>fatal: index-pack died with error code 128

Above has n and obj->size switched, sorry.


Bill

Re: Error "fatal: cannot pread pack file: Success"

[Shawn O. Pearce]

Bill Lear <rael@zopyra.com> wrote:
> >The code has this:
> >
> >        unsigned long from = obj[0].offset + obj[0].hdr_size;
> >        unsigned long len = obj[1].offset - from;
> >
> >by "offset", do you want obj[0].offset and obj[1].offset?
> >
> >How do I get the size of the packfile?  Is it obj->size?

I meant something like this:

diff --git a/index-pack.c b/index-pack.c
index cf81a99..001aa46 100644
--- a/index-pack.c
+++ b/index-pack.c
@@ -287,7 +287,7 @@ static void *get_data_from_pack(struct object_entry *obj)
 	do {
 		ssize_t n = pread(pack_fd, data + rdy, len - rdy, from + rdy);
 		if (n <= 0)
-			die("cannot pread pack file: %s", strerror(errno));
+			die("cannot pread pack file: %s from=%lu, packfile size=%lu", strerror(errno), from, lseek(pack_fd, SEEK_END, 0));
 		rdy += n;
 	} while (rdy < len);
 	data = xmalloc(obj->size);

-- 
Shawn.

Re: Error "fatal: cannot pread pack file: Success"

[Linus Torvalds]

On Wed, 28 Feb 2007, Bill Lear wrote:
> 
> Well, I went ahead and did that.  Here are the results:
> 
> % git clone --bare ~/devel/project
> [...]
> Resolving 2210 deltas.
> fatal: cannot pread pack file: Success [obj[0].offset=39393; obj[1].offset=39602; n=305; obj->size=0; rdy=0; len=207]
> fatal: index-pack died with error code 128

What's "n"? Is that the return value from pread? Or was that "rdy"?

We expect the return value of pread() to be exactly the size we asked for, 
namely "len". Anything else would be an error, and we know you're not 
getting a negative return value (since strerror() says "success") unless 
your pread() is *really* buggered.

But getting a return value of 0 would indicate that your pack-file is 
seriously corrupt (in particular, it would likely be truncated). And 
getting a return value of 305 is also weird beyond belief, since we only 
asked for 207 bytes.

One thing to do (maybe you did already) is to just verify that what you're 
cloning looks fine:

	cd ~/devel/project
	git fsck --full

just to be safe.

		Linus

Re: Error "fatal: cannot pread pack file: Success"

[Bill Lear]

On Wednesday, February 28, 2007 at 08:34:18 (-0800) Linus Torvalds writes:
>On Wed, 28 Feb 2007, Bill Lear wrote:
>> Well, I went ahead and did that.  Here are the results:
>> 
>> % git clone --bare ~/devel/project
>> [...]
>> Resolving 2210 deltas.
>> fatal: cannot pread pack file: Success [obj[0].offset=39393; obj[1].offset=39602; n=305; obj->size=0; rdy=0; len=207]
>> fatal: index-pack died with error code 128
>
>What's "n"? Is that the return value from pread? Or was that "rdy"?

Yes, n is the value from pread.

This is on Linux, BTW:

% uname -a

Linux bl.zopyra.com 2.6.9-34.0.2.ELsmp #1 SMP Fri Jul 7 18:22:55 CDT 2006 x86_64 x86_64 x86_64 GNU/Linux

>One thing to do (maybe you did already) is to just verify that what you're 
>cloning looks fine:
>
>	cd ~/devel/project
>	git fsck --full

Did that, went fine.


Bill

Re: Error "fatal: cannot pread pack file: Success"

[Bill Lear]

On Wednesday, February 28, 2007 at 11:32:56 (-0500) Shawn O. Pearce writes:
>Bill Lear <rael@zopyra.com> wrote:
>> >The code has this:
>> >
>> >        unsigned long from = obj[0].offset + obj[0].hdr_size;
>> >        unsigned long len = obj[1].offset - from;
>> >
>> >by "offset", do you want obj[0].offset and obj[1].offset?
>> >
>> >How do I get the size of the packfile?  Is it obj->size?
>
>I meant something like this:
>...

% cd ~/devel/project
% git-fsck --full
% cd -
% git clone --bare ~/devel/project
[...]
fatal: cannot pread pack file: Success from=39395, packfile size=2
fatal: index-pack died with error code 128

And, again, this works fine on my non-mounted file system:

% cd ~/test
% git clone --bare ~/devel/project
Initialized empty Git repository in /home/blear/test/project/
remote: Generating pack...
remote: Done counting 4594 objects.
remote: Deltifying 4594 objects.
remote:  100% (4594/4594) done
Indexing 4594 objects.
remote: Total 4594 (delta 2210), reused 4591 (delta 2209)
 100% (4594/4594) done
Resolving 2210 deltas.
 100% (2210/2210) done


Bill

Re: Error "fatal: cannot pread pack file: Success"

[Morten Welinder]

> +                       die("cannot pread pack file: %s from=%lu, packfile size=%lu", strerror(errno), from, lseek(pack_fd, SEEK_END, 0));

That might give you the errno from the lseek call.

Morten

Re: Error "fatal: cannot pread pack file: Success"

[Linus Torvalds]

On Wed, 28 Feb 2007, Bill Lear wrote:

> On Wednesday, February 28, 2007 at 08:34:18 (-0800) Linus Torvalds writes:
> >> [...]
> >> Resolving 2210 deltas.
> >> fatal: cannot pread pack file: Success [obj[0].offset=39393; obj[1].offset=39602; n=305; obj->size=0; rdy=0; len=207]
> >> fatal: index-pack died with error code 128
> >
> >What's "n"? Is that the return value from pread? Or was that "rdy"?
> 
> Yes, n is the value from pread.

Ok, that's just ODD. 

Getting 305 bytes back when you asked for 207 is a bad bad bad thing. It's 
also really really odd and unexpected. 

What filesystem? And could you strace this and actually see the pread() 
system call?

(use "strace -f -o tracefile" to follow all forks and to put the end 
result in a trace file)

			Linus

Re: Error "fatal: cannot pread pack file: Success"

[Shawn O. Pearce]

Bill Lear <rael@zopyra.com> wrote:
> fatal: cannot pread pack file: Success from=39395, packfile size=2
> fatal: index-pack died with error code 128

Gahhh. I had the arguments to lseek reversed:

diff --git a/index-pack.c b/index-pack.c
index cf81a99..5629c23 100644
--- a/index-pack.c
+++ b/index-pack.c
@@ -287,7 +287,7 @@ static void *get_data_from_pack(struct object_entry *obj)
 	do {
 		ssize_t n = pread(pack_fd, data + rdy, len - rdy, from + rdy);
 		if (n <= 0)
-			die("cannot pread pack file: %s", strerror(errno));
+			die("cannot pread pack file: %s from=%lu, packfile size=%lu", strerror(errno), from, lseek(pack_fd, 0, SEEK_END));
 		rdy += n;
 	} while (rdy < len);
 	data = xmalloc(obj->size);


-- 
Shawn.

Re: Error "fatal: cannot pread pack file: Success"

[Shawn O. Pearce]

Morten Welinder <mwelinder@gmail.com> wrote:
> >+                       die("cannot pread pack file: %s from=%lu, packfile 
> >size=%lu", strerror(errno), from, lseek(pack_fd, SEEK_END, 0));
> 
> That might give you the errno from the lseek call.

Yes, and I don't care here.  We're dead either way, that pread is
returning bunk and we don't know why.

But it is also giving me SEEK_END, not the end of the file.  I got
the arguments backwards to lseek.  Whoops.  ;-)

-- 
Shawn.

Re: Error "fatal: cannot pread pack file: Success"

[Bill Lear]

On Wednesday, February 28, 2007 at 08:47:44 (-0800) Linus Torvalds writes:
>
>
>On Wed, 28 Feb 2007, Bill Lear wrote:
>
>> On Wednesday, February 28, 2007 at 08:34:18 (-0800) Linus Torvalds writes:
>> >> [...]
>> >> Resolving 2210 deltas.
>> >> fatal: cannot pread pack file: Success [obj[0].offset=39393; obj[1].offset=39602; n=305; obj->size=0; rdy=0; len=207]
>> >> fatal: index-pack died with error code 128
>> >
>> >What's "n"? Is that the return value from pread? Or was that "rdy"?
>> 
>> Yes, n is the value from pread.
>
>Ok, that's just ODD. 
>
>Getting 305 bytes back when you asked for 207 is a bad bad bad thing. It's 
>also really really odd and unexpected. 

You may have missed my admission that I screwed up the print: n is 0, obj->size
was 305.

>What filesystem? And could you strace this and actually see the pread() 
>system call?

How can I tell which filesystem?  It's Linux all around, as far as I
know.  Here is what mount tells me about this filesystem:

storage:/storage/disk1 on /austin type nfs (rw,addr=192.168.2.192)

>(use "strace -f -o tracefile" to follow all forks and to put the end 
>result in a trace file)

Will do ...


Bill

Re: Error "fatal: cannot pread pack file: Success"

[Bill Lear]

On Wednesday, February 28, 2007 at 11:49:22 (-0500) Shawn O. Pearce writes:
>Morten Welinder <mwelinder@gmail.com> wrote:
>> >+                       die("cannot pread pack file: %s from=%lu, packfile 
>> >size=%lu", strerror(errno), from, lseek(pack_fd, SEEK_END, 0));
>> 
>> That might give you the errno from the lseek call.
>
>Yes, and I don't care here.  We're dead either way, that pread is
>returning bunk and we don't know why.
>
>But it is also giving me SEEK_END, not the end of the file.  I got
>the arguments backwards to lseek.  Whoops.  ;-)

Ok, fixed that:

% strace -f -o tracefile git clone --bare ~/devel/project
[...]
fatal: cannot pread pack file: Success from=39395, packfile size=0
[...]
% grep pread tracefile
28635 pread(3,  <unfinished ...>
28635 <... pread resumed> "", 207, 39395) = 0
28635 write(2, "cannot pread pack file: Success "..., 59) = 59


Bill

Re: Error "fatal: cannot pread pack file: Success"

[Shawn O. Pearce]

Bill Lear <rael@zopyra.com> wrote:
> % strace -f -o tracefile git clone --bare ~/devel/project
> [...]
> fatal: cannot pread pack file: Success from=39395, packfile size=0
> [...]
> % grep pread tracefile
> 28635 pread(3,  <unfinished ...>
> 28635 <... pread resumed> "", 207, 39395) = 0
> 28635 write(2, "cannot pread pack file: Success "..., 59) = 59

Well, that answers that.  The packfile is 0 bytes long.  Why?
We downloaded the data and are trying to resolve deltas... but
when we go back into the packfile we thought we had, we find it is
nothing but an empty file.  NFS strikes again!

Have you been able to clone onto this drive before?  Maybe with a
different version of Git (1.4.x series, before this pread change
in index-pack)?  Clearly this operation should be working, but
its not, and I'm certainly at a loss for why the file would just
magically truncate itself.

-- 
Shawn.

Re: Error "fatal: cannot pread pack file: Success"

[Bill Lear]

On Wednesday, February 28, 2007 at 12:06:41 (-0500) Shawn O. Pearce writes:
>Bill Lear <rael@zopyra.com> wrote:
>> % strace -f -o tracefile git clone --bare ~/devel/project
>> [...]
>> fatal: cannot pread pack file: Success from=39395, packfile size=0
>> [...]
>> % grep pread tracefile
>> 28635 pread(3,  <unfinished ...>
>> 28635 <... pread resumed> "", 207, 39395) = 0
>> 28635 write(2, "cannot pread pack file: Success "..., 59) = 59
>
>Well, that answers that.  The packfile is 0 bytes long.  Why?
>We downloaded the data and are trying to resolve deltas... but
>when we go back into the packfile we thought we had, we find it is
>nothing but an empty file.  NFS strikes again!
>
>Have you been able to clone onto this drive before?  Maybe with a
>different version of Git (1.4.x series, before this pread change
>in index-pack)?  Clearly this operation should be working, but
>its not, and I'm certainly at a loss for why the file would just
>magically truncate itself.

Yes: 1.4.x worked fine.  This was actually my attempt to re-do the 1.4
clone I had laying around, as I wanted my backup done with 1.5.  I
still have the 1.4 cloned repo, just moved it out of the way...


Bill

Re: Error "fatal: cannot pread pack file: Success"

[Linus Torvalds]

On Wed, 28 Feb 2007, Bill Lear wrote:
> >
> >Getting 305 bytes back when you asked for 207 is a bad bad bad thing. It's 
> >also really really odd and unexpected. 
> 
> You may have missed my admission that I screwed up the print: n is 0, obj->size
> was 305.

Ahh, ok. 

That means you got 0 back. That in turn means that the file seems to be 
truncated for some reason - the only valid reason to get 0 back is if the 
length of the file is smaller than the offset you're asking for data from.

> >What filesystem? And could you strace this and actually see the pread() 
> >system call?
> 
> How can I tell which filesystem?  It's Linux all around, as far as I
> know.  Here is what mount tells me about this filesystem:
> 
> storage:/storage/disk1 on /austin type nfs (rw,addr=192.168.2.192)

Yes, that's how you get the filesystem type ;)

> >(use "strace -f -o tracefile" to follow all forks and to put the end 
> >result in a trace file)
> 
> Will do ...

Well, if the return value was 0, it wasn't as odd any more, and the reason 
seems to be a file truncate error. Shawn seems to be on that one.

(The "return 305 when asked for 207" seemed like a kernel bug, which was 
why I got really interested ;)

		Linus

Re: Error "fatal: cannot pread pack file: Success"

[Nicolas Pitre]

On Wed, 28 Feb 2007, Linus Torvalds wrote:

> One thing to do (maybe you did already) is to just verify that what you're 
> cloning looks fine:
> 
> 	cd ~/devel/project
> 	git fsck --full
> 
> just to be safe.

That won't tell anything.  git-index-pack works on a streamed pack and 
by the time it dies the pack is not complete yet and not moved to the 
final spot.


Nicolas

Re: Error "fatal: cannot pread pack file: Success"

[Shawn O. Pearce]

Bill Lear <rael@zopyra.com> wrote:
> Yes: 1.4.x worked fine.  This was actually my attempt to re-do the 1.4
> clone I had laying around, as I wanted my backup done with 1.5.  I
> still have the 1.4 cloned repo, just moved it out of the way...

OK, is ~/devel/project fully packed?  If it isn't can you repack
it (or a clone of it) so that it is?

Then take the packfile and try to feed it right into index-pack:

	mkdir /austin/users/rael/repos/git/project-test
	cd /austin/users/rael/repos/git/project-test
	git --bare init
	git --bare index-pack --stdin --fix-thin \
	  <~/devel/project/.git/objects/pack/pack-*.pack

Now while that is running it should be creating pack_XXXXXX as a
temporary file (where XXXXXX is replaced with the temp string).
Its this file that we are seeing magically truncate to 0 in the
middle of running.

But I fail to see anything in index-pack that would cause this,
and its the only program that knows about this file at this stage
of the clone.

-- 
Shawn.

Re: Error "fatal: cannot pread pack file: Success"

[Nicolas Pitre]

On Wed, 28 Feb 2007, Shawn O. Pearce wrote:

> Bill Lear <rael@zopyra.com> wrote:
> > Yes: 1.4.x worked fine.  This was actually my attempt to re-do the 1.4
> > clone I had laying around, as I wanted my backup done with 1.5.  I
> > still have the 1.4 cloned repo, just moved it out of the way...
> 
> OK, is ~/devel/project fully packed?  If it isn't can you repack
> it (or a clone of it) so that it is?
> 
> Then take the packfile and try to feed it right into index-pack:
> 
> 	mkdir /austin/users/rael/repos/git/project-test
> 	cd /austin/users/rael/repos/git/project-test
> 	git --bare init
> 	git --bare index-pack --stdin --fix-thin \
> 	  <~/devel/project/.git/objects/pack/pack-*.pack
> 
> Now while that is running it should be creating pack_XXXXXX as a
> temporary file (where XXXXXX is replaced with the temp string).
> Its this file that we are seeing magically truncate to 0 in the
> middle of running.
> 
> But I fail to see anything in index-pack that would cause this,
> and its the only program that knows about this file at this stage
> of the clone.

... and Bill already said that the same clone operation, when not 
performed on top of NFS, works fine.


Nicolas

Re: Error "fatal: cannot pread pack file: Success"

[Shawn O. Pearce]

Nicolas Pitre <nico@cam.org> wrote:
> On Wed, 28 Feb 2007, Shawn O. Pearce wrote:
> > Bill Lear <rael@zopyra.com> wrote:
> > > Yes: 1.4.x worked fine.  This was actually my attempt to re-do the 1.4
> > > clone I had laying around, as I wanted my backup done with 1.5.  I
> > > still have the 1.4 cloned repo, just moved it out of the way...
> > 
> > But I fail to see anything in index-pack that would cause this,
> > and its the only program that knows about this file at this stage
> > of the clone.
> 
> ... and Bill already said that the same clone operation, when not 
> performed on top of NFS, works fine.

Gah.  You're right.  And Bill also said the same clone works fine
on NFS, just so long as it is the Git 1.4.x series.  Which means
no pread/delta-resolving based index-pack.

Which leads me to believe something really horrible is happening in
the NFS server, like when we append to the packfile it truncates it.
Except during a clone we shouldn't append anything during the
delta resolution phase, as all delta bases should appear in that
one packfile.

Bill, are you sure someone isn't truncating your files on your NFS
server behind your back?  Is it an early April fool's joke from
a coworker?

-- 
Shawn.

Re: Error "fatal: cannot pread pack file: Success"

[Nicolas Pitre]

On Wed, 28 Feb 2007, Linus Torvalds wrote:

> Well, if the return value was 0, it wasn't as odd any more, and the reason 
> seems to be a file truncate error. Shawn seems to be on that one.
> 
> (The "return 305 when asked for 207" seemed like a kernel bug, which was 
> why I got really interested ;)

I wouldn't dismiss a kernel bug just yet.

Bill already said the same operation, when not performed over NFS, works 
just fine.

He also mentioned that version 1.4.4, which uses mmap() instead of 
pread(), works also fine even over NFS.


Nicolas

Re: Error "fatal: cannot pread pack file: Success"

[Linus Torvalds]

On Wed, 28 Feb 2007, Nicolas Pitre wrote:
>
> On Wed, 28 Feb 2007, Linus Torvalds wrote:
> 
> > Well, if the return value was 0, it wasn't as odd any more, and the reason 
> > seems to be a file truncate error. Shawn seems to be on that one.
> > 
> > (The "return 305 when asked for 207" seemed like a kernel bug, which was 
> > why I got really interested ;)
> 
> I wouldn't dismiss a kernel bug just yet.
> 
> Bill already said the same operation, when not performed over NFS, works 
> just fine.
> 
> He also mentioned that version 1.4.4, which uses mmap() instead of 
> pread(), works also fine even over NFS.

Hmm.. Good point. 

I'm addign Trond, Chuck and Neil to the list, just in case there might be 
some known problem where NFS might use f_pos instead of the passed-in 
position, causing problems with pread(). Not that I can imagine how that 
could even happen or not be noticed..

Guys, this is a oldish 2.6.x kernel: "2.6.9-34.0.2.ELsmp #1 SMP Fri Jul 
7", and for some reason we have a file that appears truncated to pread() 
(returns 0) but worked with mmap and the same test-case apparently works 
on non-NFS filesystems. Any ideas? Some known bug that got fixed since?

Bill, can you make the whole strace available somewhere?

			Linus

Re: Error "fatal: cannot pread pack file: Success"

[Bill Lear]

On Wednesday, February 28, 2007 at 12:43:39 (-0500) Shawn O. Pearce writes:
>Bill Lear <rael@zopyra.com> wrote:
>> Yes: 1.4.x worked fine.  This was actually my attempt to re-do the 1.4
>> clone I had laying around, as I wanted my backup done with 1.5.  I
>> still have the 1.4 cloned repo, just moved it out of the way...
>
>OK, is ~/devel/project fully packed?  If it isn't can you repack
>it (or a clone of it) so that it is?

I did a git gc on this before starting, so I assume it is fully packed.

I tried copying my backup 1.4 repo to my local drive and then cloning
it with 1.5 onto my nfs-mounted drive.  This failed like this:

% cp -rp project-/ ~/project-1.4
% git clone --bare ~/project-1.4
[...]
Resolving 1286 deltas.
fatal: cannot pread pack file: Success from=37269, packfile size=0
fatal: index-pack died with error code 128

Just to see what 1.4 will now do, I tried with 1.4, and it is now
failing also:

[Reset PATH]
% git --version
git version 1.4.4.1
% git clone --bare ~/project-1.4
[...]
Resolving 1286 deltas.
remote: Total 3165, written 3165 (delta 1286), reused 1840 (delta 488)
fatal: index-pack died of signal 7

>Then take the packfile and try to feed it right into index-pack:
>
>	mkdir /austin/users/rael/repos/git/project-test
>	cd /austin/users/rael/repos/git/project-test
>	git --bare init
>	git --bare index-pack --stdin --fix-thin \
>	  <~/devel/project/.git/objects/pack/pack-*.pack
>
>Now while that is running it should be creating pack_XXXXXX as a
>temporary file (where XXXXXX is replaced with the temp string).
>Its this file that we are seeing magically truncate to 0 in the
>middle of running.

Did that.  Still fails:

% git --bare index-pack --stdin --fix-thin < ~/devel/project/.git/objects/pack/pack-fe532a54e5d549f1cfc70a4ab2c5f4eaac8897a5.pack
fatal: cannot pread pack file: Success from=39215, packfile size=0

I do see this:

% ls -l objects
total 88088
drwxr-xr-x  2 rael  software     4096 Feb 28 13:05 info/
drwxr-xr-x  2 rael  software     4096 Feb 28 13:05 pack/
-rw-------  1 rael  software 90099505 Feb 28 13:06 pack_eZwOnG


Bill

Re: Error "fatal: cannot pread pack file: Success"

[Linus Torvalds]

[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

Re: Error "fatal: cannot pread pack file: Success"

[Bill Lear]

On Wednesday, February 28, 2007 at 13:18:08 (-0600) Bill Lear writes:
>
>% ls -l objects
>total 88088
>drwxr-xr-x  2 rael  software     4096 Feb 28 13:05 info/
>drwxr-xr-x  2 rael  software     4096 Feb 28 13:05 pack/
>-rw-------  1 rael  software 90099505 Feb 28 13:06 pack_eZwOnG

I should have added:

% ls -l ~/devel/fusion/.git/objects/pack/pack-fe532a54e5d549f1cfc70a4ab2c5f4eaac8897a5.pack
-r--r--r--  1 rael software 90099525 Feb 27 21:36 /home/rael/devel/project/.git/objects/pack/pack-fe532a54e5d549f1cfc70a4ab2c5f4eaac8897a5.pack

That's 20 bytes of difference.


Bill

Re: Error "fatal: cannot pread pack file: Success"

[Nicolas Pitre]

On Wed, 28 Feb 2007, Bill Lear wrote:

> On Wednesday, February 28, 2007 at 13:18:08 (-0600) Bill Lear writes:
> >
> >% ls -l objects
> >total 88088
> >drwxr-xr-x  2 rael  software     4096 Feb 28 13:05 info/
> >drwxr-xr-x  2 rael  software     4096 Feb 28 13:05 pack/
> >-rw-------  1 rael  software 90099505 Feb 28 13:06 pack_eZwOnG
> 
> I should have added:
> 
> % ls -l ~/devel/fusion/.git/objects/pack/pack-fe532a54e5d549f1cfc70a4ab2c5f4eaac8897a5.pack
> -r--r--r--  1 rael software 90099525 Feb 27 21:36 /home/rael/devel/project/.git/objects/pack/pack-fe532a54e5d549f1cfc70a4ab2c5f4eaac8897a5.pack
> 
> That's 20 bytes of difference.

That is actually OK.  This is the temporary pack file the fetch received 
but which final SHA1 has not been written yet.  Normally, after the 
delta resolution has finished (the part that requires the pread() calls) 
then the final SHA1 is written and the pack is moved to its final 
location under an appropriate name.  But in your case index-pack bailed 
out on the failing pread() and left its incomplete temporary pack there.


Nicolas

Re: Error "fatal: cannot pread pack file: Success"

[Bill Lear]

On Wednesday, February 28, 2007 at 14:40:25 (-0500) Nicolas Pitre writes:
>On Wed, 28 Feb 2007, Bill Lear wrote:
>
>> On Wednesday, February 28, 2007 at 13:18:08 (-0600) Bill Lear writes:
>> >
>> >% ls -l objects
>> >total 88088
>> >drwxr-xr-x  2 rael  software     4096 Feb 28 13:05 info/
>> >drwxr-xr-x  2 rael  software     4096 Feb 28 13:05 pack/
>> >-rw-------  1 rael  software 90099505 Feb 28 13:06 pack_eZwOnG
>> 
>> I should have added:
>> 
>> % ls -l ~/devel/fusion/.git/objects/pack/pack-fe532a54e5d549f1cfc70a4ab2c5f4eaac8897a5.pack
>> -r--r--r--  1 rael software 90099525 Feb 27 21:36 /home/rael/devel/project/.git/objects/pack/pack-fe532a54e5d549f1cfc70a4ab2c5f4eaac8897a5.pack
>> 
>> That's 20 bytes of difference.
>
>That is actually OK.  This is the temporary pack file the fetch received 
>but which final SHA1 has not been written yet.  Normally, after the 
>delta resolution has finished (the part that requires the pread() calls) 
>then the final SHA1 is written and the pack is moved to its final 
>location under an appropriate name.  But in your case index-pack bailed 
>out on the failing pread() and left its incomplete temporary pack there.

As follow-up: I installed git 1.5.0.1 on a box with a newer version of
Linux, tried the same operations and it worked fine.

% uname -a
Linux xiho.zopyra.com 2.6.15-1.2054_FC5smp #1 SMP Tue Mar 14 16:05:46 EST 2006 i686 i686 i386 GNU/Linux

% git clone --bare ~/project
Initialized empty Git repository in /austin/users/rael/repos/git/project/
remote: Generating pack...
remote: Done counting 4304 objects.
remote: Deltifying 4304 objects.
remote:  100% (4304/4304) done
Indexing 4304 objects.
remote: Total 4304 (delta 2031), reused 4293 (delta 2026)
 100% (4304/4304) done
Resolving 2031 deltas.
 100% (2031/2031) done

So, I guess we'll just have to upgrade our Linux boxes to get the
newer NFS client code that appears to be the cause of this...


Bill