Anyone know why git ls-remote output might be corrupted?

Anyone know why git ls-remote output might be corrupted?

[Paul Smith]

I have some scripting on my CI/CD servers that invokes git ls-remote
and parses the output.  The scripting is in Python.  Sometimes, but not
always, the output of this command is corrupted.  I've enhanced the
error handling and I see this:

>> git ls-remote --heads origin
*** INTERNAL: remote branch lookup failed:
Output:
-----
8431d80571dea5cc8e6d0848f27124f66346dcc4        refs/heads/foo1
aaec1feb1167cf3fbd39a36cdd7736679a9f4fae        refs/heads/foo2
6167c73fbaded389ff54d52a01878975f4a6d5e5        refs/heads/foo3
   ...
3a2e8036a6f6605d4dd14c72bd395298bff9d80e        refs/heads/xxx1
3a2e8036a6f6605d4dd14c72bd395298bff9d80e        refs/heads/xxx2
795d2ff669041fc91341cf5bf820aibab79dc92bd741e77a7dcf71d94285a6ae494dc0        refs/heads/yyy1
1496ea0ddab29ae3935754fced4bd5858cff7940        refs/heads/yyy2
1496ea0ddab29ae3935754fced4bd5858cff7940        refs/heads/yyy3
-----

Also a bunch of the heads are missing.  It's pretty clear that right in
the middle of printing one of the SHAs we suddenly lost a bunch of
output, and started printing stuff from later (in the last instance 66
out of 131 heads were missing).  Breaking down the output above you can
see:

  3a2e8036a6f6605d4dd14c72bd395298bff9d80e        refs/heads/xxx2
  795d2ff669041fc91341cf5bf820aibab79dc92bd741e77a7dcf71d94285a6ae494dc0        refs/heads/yyy1
                               ^

where the "795d2ff669041fc91341cf5bf820a" before the "i" char is a
valid start of a SHA for a head (not shown), then the "i", then a fully
valid SHA for heads/yyy1 which is 66 heads later.

I've seen this happen with different versions of Git on the client side
and on different OS's (Windows and Linux).  The only real constant here
is the Git server.

Is it feasible that this is an error on the server side?  Does the
server return formatted output for ls-remote?  I would naively have
expected it to return a binary representation of the heads, and the
formatting be done by the client.  But maybe not.

I should point out that subsequent runs in the same client work fine,
and when I log into the CI/CD client and run the command by hand I
can't reproduce it.  It's random.  I also can't find any errors printed
anywhere on either the server (we are using ssh access only for client
connections, managed via gitolite) or the client, except for the above.

Help, this is causing a few spurious failures in my CI/CD system per
day!

Re: Anyone know why git ls-remote output might be corrupted?

[Paul Smith]

On Fri, 2023-06-02 at 14:59 -0400, Paul Smith wrote:
> Also a bunch of the heads are missing.  It's pretty clear that right
> in the middle of printing one of the SHAs we suddenly lost a bunch of
> output, and started printing stuff from later (in the last instance
> 66 out of 131 heads were missing).

I forgot to mention: git ls-remote does not exit with an error code. 
The exit code is 0 (success).

The reason I get this failure is that as I parse the output I notice
that the SHA is invalid (contains a non-hex character "i") and it
throws this error.

RE: Anyone know why git ls-remote output might be corrupted?

[rsbecker]

On Friday, June 2, 2023 3:13 PM, Paul Smith wrote:
>On Fri, 2023-06-02 at 14:59 -0400, Paul Smith wrote:
>> Also a bunch of the heads are missing.  It's pretty clear that right
>> in the middle of printing one of the SHAs we suddenly lost a bunch of
>> output, and started printing stuff from later (in the last instance
>> 66 out of 131 heads were missing).
>
>I forgot to mention: git ls-remote does not exit with an error code.
>The exit code is 0 (success).
>
>The reason I get this failure is that as I parse the output I notice that the SHA is invalid
>(contains a non-hex character "i") and it throws this error.

Does your CI/CD system use sparse checkout or depth=1 or some other partial clone?

Re: Anyone know why git ls-remote output might be corrupted?

[Paul Smith]

On Fri, 2023-06-02 at 15:34 -0400, rsbecker@nexbridge.com wrote:
> On Friday, June 2, 2023 3:13 PM, Paul Smith wrote:
> > On Fri, 2023-06-02 at 14:59 -0400, Paul Smith wrote:
> > > Also a bunch of the heads are missing.  It's pretty clear that
> > > right in the middle of printing one of the SHAs we suddenly lost
> > > a bunch of output, and started printing stuff from later (in the
> > > last instance 66 out of 131 heads were missing).
> > 
> > I forgot to mention: git ls-remote does not exit with an error
> > code.  The exit code is 0 (success).
> > 
> > The reason I get this failure is that as I parse the output I
> > notice that the SHA is invalid (contains a non-hex character "i")
> > and it throws this error.
> 
> Does your CI/CD system use sparse checkout or depth=1 or some other
> partial clone?

Yes, the local copy of the repo is a sparse checkout.

I'm surprised that matters to ls-remote... I would have expected that
the "sparseness" of the local repo is irrelevant when listing the state
of the remote's heads?  Is that the reason for the issue I'm seeing?

RE: Anyone know why git ls-remote output might be corrupted?

[rsbecker]

On Friday, June 2, 2023 3:53 PM, Paul Smith wrote:
>On Fri, 2023-06-02 at 15:34 -0400, rsbecker@nexbridge.com wrote:
>> On Friday, June 2, 2023 3:13 PM, Paul Smith wrote:
>> > On Fri, 2023-06-02 at 14:59 -0400, Paul Smith wrote:
>> > > Also a bunch of the heads are missing.  It's pretty clear that
>> > > right in the middle of printing one of the SHAs we suddenly lost a
>> > > bunch of output, and started printing stuff from later (in the
>> > > last instance 66 out of 131 heads were missing).
>> >
>> > I forgot to mention: git ls-remote does not exit with an error code.
>> > The exit code is 0 (success).
>> >
>> > The reason I get this failure is that as I parse the output I notice
>> > that the SHA is invalid (contains a non-hex character "i") and it
>> > throws this error.
>>
>> Does your CI/CD system use sparse checkout or depth=1 or some other
>> partial clone?
>
>Yes, the local copy of the repo is a sparse checkout.
>
>I'm surprised that matters to ls-remote... I would have expected that the "sparseness"
>of the local repo is irrelevant when listing the state of the remote's heads?  Is that
>the reason for the issue I'm seeing?

I'm just wondering whether this might be an impact somehow and adding info to help the team diagnose. I have seen other commands have some issues in the past with --depth=n
--Randall

Re: Anyone know why git ls-remote output might be corrupted?

[Paul Smith]

On Fri, 2023-06-02 at 16:02 -0400, rsbecker@nexbridge.com wrote:
> > > Does your CI/CD system use sparse checkout or depth=1 or some
> > > other partial clone?
> > 
> > Yes, the local copy of the repo is a sparse checkout.
> > 
> > I'm surprised that matters to ls-remote... I would have expected
> > that the "sparseness" of the local repo is irrelevant when listing
> > the state of the remote's heads?
> 
> I'm just wondering whether this might be an impact somehow and adding
> info to help the team diagnose. I have seen other commands have some
> issues in the past with --depth=n

I see.  Well I can try changing my call to avoid the local repo in any
way, and run 'git ls-remote --heads user@server:reponame' from a
temporary directory outside of any repo, rather than using "origin".

I would be surprised if it makes a difference but the behavior is sure
strange enough that I wouldn't be THAT surprised :)

Re: Anyone know why git ls-remote output might be corrupted?

[Elijah Newren]

On Fri, Jun 2, 2023 at 1:26 PM <rsbecker@nexbridge.com> wrote:
>
> On Friday, June 2, 2023 3:53 PM, Paul Smith wrote:
> >On Fri, 2023-06-02 at 15:34 -0400, rsbecker@nexbridge.com wrote:
> >> On Friday, June 2, 2023 3:13 PM, Paul Smith wrote:
> >> > On Fri, 2023-06-02 at 14:59 -0400, Paul Smith wrote:
> >> > > Also a bunch of the heads are missing.  It's pretty clear that
> >> > > right in the middle of printing one of the SHAs we suddenly lost a
> >> > > bunch of output, and started printing stuff from later (in the
> >> > > last instance 66 out of 131 heads were missing).
> >> >
> >> > I forgot to mention: git ls-remote does not exit with an error code.
> >> > The exit code is 0 (success).
> >> >
> >> > The reason I get this failure is that as I parse the output I notice
> >> > that the SHA is invalid (contains a non-hex character "i") and it
> >> > throws this error.
> >>
> >> Does your CI/CD system use sparse checkout or depth=1 or some other
> >> partial clone?
> >
> >Yes, the local copy of the repo is a sparse checkout.
> >
> >I'm surprised that matters to ls-remote... I would have expected that the "sparseness"
> >of the local repo is irrelevant when listing the state of the remote's heads?  Is that
> >the reason for the issue I'm seeing?
>
> I'm just wondering whether this might be an impact somehow and adding info to help the team diagnose. I have seen other commands have some issues in the past with --depth=n
> --Randall

I think if shallowness or sparseness affected ls-remote output in any
way whatsoever, that would itself be a bug.  Granted, I don't know
much about the protocol side of things, but I'd be very surprised if
either of these conditions mattered.

Re: Anyone know why git ls-remote output might be corrupted?

[Elijah Newren]

On Fri, Jun 2, 2023 at 12:27 PM Paul Smith <paul@mad-scientist.net> wrote:
>
> I have some scripting on my CI/CD servers that invokes git ls-remote
> and parses the output.  The scripting is in Python.  Sometimes, but not
> always, the output of this command is corrupted.  I've enhanced the
> error handling and I see this:
>
> >> git ls-remote --heads origin
> *** INTERNAL: remote branch lookup failed:
> Output:
> -----
> 8431d80571dea5cc8e6d0848f27124f66346dcc4        refs/heads/foo1
> aaec1feb1167cf3fbd39a36cdd7736679a9f4fae        refs/heads/foo2
> 6167c73fbaded389ff54d52a01878975f4a6d5e5        refs/heads/foo3
>    ...
> 3a2e8036a6f6605d4dd14c72bd395298bff9d80e        refs/heads/xxx1
> 3a2e8036a6f6605d4dd14c72bd395298bff9d80e        refs/heads/xxx2
> 795d2ff669041fc91341cf5bf820aibab79dc92bd741e77a7dcf71d94285a6ae494dc0        refs/heads/yyy1
> 1496ea0ddab29ae3935754fced4bd5858cff7940        refs/heads/yyy2
> 1496ea0ddab29ae3935754fced4bd5858cff7940        refs/heads/yyy3
> -----

Can you trigger this problem with just `git ls-remote --heads origin`,
or do you only see it after processing by your python script?

If you can trigger with the former, what does
    GIT_TRACE_PACKET=1 git ls-remote --heads origin
report?

If the latter, can you find a way to minimize your python script or
find some equivalent shell commands with the same buggy behavior?

> Also a bunch of the heads are missing.  It's pretty clear that right in
> the middle of printing one of the SHAs we suddenly lost a bunch of
> output, and started printing stuff from later (in the last instance 66
> out of 131 heads were missing).  Breaking down the output above you can
> see:
>
>   3a2e8036a6f6605d4dd14c72bd395298bff9d80e        refs/heads/xxx2
>   795d2ff669041fc91341cf5bf820aibab79dc92bd741e77a7dcf71d94285a6ae494dc0        refs/heads/yyy1
>                                ^
>
> where the "795d2ff669041fc91341cf5bf820a" before the "i" char is a
> valid start of a SHA for a head (not shown), then the "i", then a fully
> valid SHA for heads/yyy1 which is 66 heads later.

Sounds kind of like
https://lore.kernel.org/git/6786526.72e2EbofS7@devpool47/ which also
triggered for some other tooling and then was reduced down to some
shell commands.  Unfortunately, the thread ended without a lot of
resolution other than "don't mix stdout and stderr" and "if we slow
down the network connection somehow, that'll avoid the problem".

Re: Anyone know why git ls-remote output might be corrupted?

[Jeff King]

On Fri, Jun 02, 2023 at 06:12:52PM -0700, Elijah Newren wrote:

> > Also a bunch of the heads are missing.  It's pretty clear that right in
> > the middle of printing one of the SHAs we suddenly lost a bunch of
> > output, and started printing stuff from later (in the last instance 66
> > out of 131 heads were missing).  Breaking down the output above you can
> > see:
> >
> >   3a2e8036a6f6605d4dd14c72bd395298bff9d80e        refs/heads/xxx2
> >   795d2ff669041fc91341cf5bf820aibab79dc92bd741e77a7dcf71d94285a6ae494dc0        refs/heads/yyy1
> >                                ^
> >
> > where the "795d2ff669041fc91341cf5bf820a" before the "i" char is a
> > valid start of a SHA for a head (not shown), then the "i", then a fully
> > valid SHA for heads/yyy1 which is 66 heads later.
> 
> Sounds kind of like
> https://lore.kernel.org/git/6786526.72e2EbofS7@devpool47/ which also
> triggered for some other tooling and then was reduced down to some
> shell commands.  Unfortunately, the thread ended without a lot of
> resolution other than "don't mix stdout and stderr" and "if we slow
> down the network connection somehow, that'll avoid the problem".

Thanks for digging up that thread. I had a vague memory of this coming
up before, but wasn't sure what to search for to find it. :)

From that thread, one theory that I think remains unexplored: could
ls-remote's stdout be opened in non-blocking mode?

The output of ls-remote is written with printf(). We don't bother
checking for errors from stdio, since typically a write error would
result in us getting EPIPE and being killed. But if stdout were
unexpectedly in non-blocking mode, we might get EAGAIN. I'm not sure how
libc would handle that.

Now, why the descriptor would be in non-blocking mode, I have no idea.
But maybe something funny going on in your python script.

I'd be curious if applying the patch from:

  https://lore.kernel.org/git/YUTo1BTp7BXOw6K9@coredump.intra.peff.net/

reports any problems. As well as whether the suggested "sleep" pipeline
there (triggered via your script in this case) shows the problem more
reliably.

-Peff

Re: Anyone know why git ls-remote output might be corrupted?

[Jeff King]

On Sun, Jun 04, 2023 at 02:00:48AM -0400, Jeff King wrote:

> Now, why the descriptor would be in non-blocking mode, I have no idea.
> But maybe something funny going on in your python script.
> 
> I'd be curious if applying the patch from:
> 
>   https://lore.kernel.org/git/YUTo1BTp7BXOw6K9@coredump.intra.peff.net/
> 
> reports any problems. As well as whether the suggested "sleep" pipeline
> there (triggered via your script in this case) shows the problem more
> reliably.

It does look like glibc's stdio will throw away buffer contents that get
EAGAIN. Doing:

  perl -MFcntl -e '
    fcntl(STDOUT, F_GETFL, $flags);
    $flags |= O_NONBLOCK;
    fcntl(STDOUT, F_SETFL, $flags);
    exec @ARGV;
  ' git ls-remote . | (sleep 1; tee output) | sha256sum

does result in some missing writes and broken input that looks like
what's going on in this thread (in this case, it's writing to my
terminal, which isn't fast enough to keep up; but you could also pipe to
something like "tee output | sha256sum" to see that the output changes
with each run). And naturally you'll need a big enough output from
ls-remote to fill the pipe buffer.

However, Git _does_ eventually produce a non-zero exit code in this
case, because we check ferror() after running any builtin. So it
eventually ends with:

  fatal: unknown write failure on standard output

So I dunno. Maybe this is not the same thing. I do think running
the problematic case under "strace -o foo.out" may yield more
information.

-Peff

Re: Anyone know why git ls-remote output might be corrupted?

[Jeff King]

On Sun, Jun 04, 2023 at 02:25:57AM -0400, Jeff King wrote:

> It does look like glibc's stdio will throw away buffer contents that get
> EAGAIN. Doing:
> 
>   perl -MFcntl -e '
>     fcntl(STDOUT, F_GETFL, $flags);
>     $flags |= O_NONBLOCK;
>     fcntl(STDOUT, F_SETFL, $flags);
>     exec @ARGV;
>   ' git ls-remote . | (sleep 1; tee output) | sha256sum
> 
> does result in some missing writes and broken input that looks like
> what's going on in this thread (in this case, it's writing to my
> terminal, which isn't fast enough to keep up; but you could also pipe to
> something like "tee output | sha256sum" to see that the output changes
> with each run). And naturally you'll need a big enough output from
> ls-remote to fill the pipe buffer.

Sorry for some slight confusion above. I edited my example command to
show piping to "sha256sum", but didn't modify the paragraph below it
(originally I was not piping anywhere, just sending to the terminal).

Adding the "sleep 1" means that the command will always fail (ls-remote
easily writes all of its output and hits EAGAIN before the other side
reads anything). But it means that the output is deterministic (the
first PIPE_BUF bytes make it through, and nothing else does). Removing
the sleep makes the output non-deterministic, but much more interesting
(you get missing chunks in the interior of the output).

So perhaps:

  perl ... git ls-remote . | tee output | sha256sum

is the most interesting case, because you'll get one of several possible
broken outputs, which you can identify by the changing sha256 output
(and then see the actual breakage by peeking at the "output" file).

-Peff

Re: Anyone know why git ls-remote output might be corrupted?

[Paul Smith]

On Fri, 2023-06-02 at 18:12 -0700, Elijah Newren wrote:
> Sounds kind of like
> https://lore.kernel.org/git/6786526.72e2EbofS7@devpool47/ which also
> triggered for some other tooling and then was reduced down to some
> shell commands.  Unfortunately, the thread ended without a lot of
> resolution other than "don't mix stdout and stderr" and "if we slow
> down the network connection somehow, that'll avoid the problem".

As I was riding my bike home last week I had this exact same epiphany.
So, I examined my script and discovered that indeed, I was using
subprocess.PIPE for stderr, which is the Python equivalent of the
shell's 2>&1 operation.  So, both stdout and stderr are going to the
same place.

I also checked and indeed, the git ls-remote command does print to both
stdout and stderr as part of its "standard" behavior:

  $ git ls-remote --heads >/dev/null
  From git@git:myrepo

This is unexpected to me, although of course there's nothing inherently
wrong with it but usually you don't expect "regular" output to go to
stderr.  I suppose the idea is that people can run:

  $ git ls-remote --heads 2>/dev/null

if they want just the output without the header.

Anyway, I modified my scripting to keep stdout and stderr separate and
I haven't heard anything about things continuing to fail so I guess
that was the problem.

The mode of failure is very very bizarre to me: first why is it just
one "bogus" character embedded in the output?  Second why are 60 lines
just dropped?  Third where did the REST of the stderr output go?

And finally, why did this not fail 100% of the time on Linux?  I can
believe that Windows pipe behavior is not POSIX and maybe Python's
emulation of it is imperfect, but surely that is not the case on Linux
and we would ALWAYS get the full results of both stdout and stderr on
Linux, even if mixed together?!?!

The mysteries never end.

Thanks all; hopefully this helps someone else.

Re: Anyone know why git ls-remote output might be corrupted?

[Junio C Hamano]

Paul Smith <paul@mad-scientist.net> writes:

> I also checked and indeed, the git ls-remote command does print to both
> stdout and stderr as part of its "standard" behavior:
>
>   $ git ls-remote --heads >/dev/null
>   From git@git:myrepo
>
> This is unexpected to me, although of course there's nothing inherently
> wrong with it but usually you don't expect "regular" output to go to
> stderr.  I suppose the idea is that people can run:
>
>   $ git ls-remote --heads 2>/dev/null
>
> if they want just the output without the header.

The above sounds like a reasonable expectation; then the issue is
there are some fflush missing when the command writes to one stream
and switches to write to another stream?

Thanks.

Re: Anyone know why git ls-remote output might be corrupted?

[Paul Smith]

On Sat, 2023-06-10 at 03:58 +0900, Junio C Hamano wrote:
> Paul Smith <paul@mad-scientist.net> writes:
> 
> > I also checked and indeed, the git ls-remote command does print to
> > both stdout and stderr as part of its "standard" behavior:
> > 
> >    $ git ls-remote --heads >/dev/null
> >    From git@git:myrepo
> > 
> > This is unexpected to me, although of course there's nothing
> > inherently wrong with it but usually you don't expect "regular"
> > output to go to stderr.  I suppose the idea is that people can run:
> > 
> >    $ git ls-remote --heads 2>/dev/null
> > 
> > if they want just the output without the header.
> 
> The above sounds like a reasonable expectation; then the issue is
> there are some fflush missing when the command writes to one stream
> and switches to write to another stream?

It's not immediately clear to me which "above" you refer to as a
reasonable expectation (the reason for the stdout vs. stderr different
I suppose?)

But I agree that forcing flush would be a good idea (or perhaps forcing
line buffering?  Changing buffering can be annoying to do portably),
for situations in which the output is being sent to a non-TTY, because
the default in that situation is fully buffered output.

Maybe it would be sufficient to have any output to stderr run
fflush(stdout) before the output, and fflush(stderr) after the output.
Presumably output to stderr is relatively rare, and so this wouldn't be
very noticeable.