git quietly fails on https:// URL, https errors are never reported to user

git quietly fails on https:// URL, https errors are never reported to user

[Yuri]

On one of my FreeBSD systems I can't clone github through https URL.
It only says "Cloning into 'MyProject'...", writes some files, but then 
deletes everything, without printing anything else at all. Exit code is 128.

Replacing https:// with git:// makes it work fine.

While debugging, I find that remove_junk() deletes all directories from 
under __cxa_finalize.
Before this, exit(128) is called from recvline_fh ("Debug: Remote helper 
quit.) And this function in turn is called from under
refs = transport_get_remote_refs(transport);

I think you need to make sure that any https errors (in this and other 
locations) are reported to the user, and git never quits on error 
without saying what the error is.

git-1.8.5.2

Yuri

Re: git quietly fails on https:// URL, https errors are never reported to user

[Jeff King]

On Thu, Jan 16, 2014 at 04:27:03AM -0800, Yuri wrote:

> While debugging, I find that remove_junk() deletes all directories
> from under __cxa_finalize.
> Before this, exit(128) is called from recvline_fh ("Debug: Remote
> helper quit.) And this function in turn is called from under
> refs = transport_get_remote_refs(transport);
> 
> I think you need to make sure that any https errors (in this and
> other locations) are reported to the user, and git never quits on
> error without saying what the error is.

We used to print "Reading from helper 'git-remote-https' failed" in this
instance. But in the majority of cases, remote-https has printed a
useful message already to stderr, and the extra line just confused
people. The downside, as you noticed, is that when the helper dies
without printing an error, the user is left with no message.

Unfortunately, detecting whether the helper printed a useful message is
non-trivial. It's possible we could do more detection based on the
helper's death (e.g., if it died by signal, print a message) and at
least say _something_.

But even if we do so, the message isn't going to tell you what went
wrong, only that something unexpected happened.  It is up to the helper
to print something useful, and if it didn't, it should be fixed.  So the
most important bug to fix here, IMHO, is figuring out why
git-remote-https died without printing an error message.

Is it possible to strace (or truss) the helper process? What it was
doing when it died may be helpful. Rather than picking through "strace
-f" output, you can use this hack to trace just the helper process:

  cat >/in/your/$PATH/git-remote-strace <<\EOF
  #!/bin/sh
  protocol=$(echo "$2" | cut -d: -f1)
  exec strace git-remote-$protocol "$@"
  EOF

  git clone strace::https://github.com/your/repo.git

-Peff

Re: git quietly fails on https:// URL, https errors are never reported to user

[Yuri]

On 01/16/2014 10:03, Jeff King wrote:
> We used to print "Reading from helper 'git-remote-https' failed" in this
> instance. But in the majority of cases, remote-https has printed a
> useful message already to stderr, and the extra line just confused
> people. The downside, as you noticed, is that when the helper dies
> without printing an error, the user is left with no message.

In my case it was some random misconfiguration of the libraries handling 
https that caused them to fail in some way silently. Full update of the 
supporting libraries fixed this. But previous forced git update didn't 
fix it.

I think your should bring back this printout. Errors only happen in a 
very low percentage of cases, and printing some more would be very 
helpful for troubleshooting. I am not sure what happened in 
git-remote-https, stream may have looked legit to it, or maybe it got 
some error from the supporting libraries and didn't report it. I can't 
tell now because I updated and the problem is gone.

Yuri

Re: git quietly fails on https:// URL, https errors are never reported to user

[Yuri]

On 01/16/2014 10:03, Jeff King wrote:
> We used to print "Reading from helper 'git-remote-https' failed" in this
> instance. But in the majority of cases, remote-https has printed a
> useful message already to stderr, and the extra line just confused
> people. The downside, as you noticed, is that when the helper dies
> without printing an error, the user is left with no message.

I would like to suggest to return this printout, see patch below. This 
would be a revert of this commit:
commit 266f1fdfa99f5d29ca7ce455966e7960c00a82e4
Author: Jeff King <peff@peff.net>
Date:   Fri Jun 21 03:05:39 2013 -0400

I think that in a rare case of error this extra-printout wouldn't hurt. 
I also made this message more user friendly, without mentioning the term 
"helper".

Yuri

diff --git a/transport-helper.c b/transport-helper.c
index 2010674..5ea2831 100644
--- a/transport-helper.c
+++ b/transport-helper.c
@@ -58,7 +58,7 @@ static int recvline_fh(FILE *helper, struct strbuf 
*buffer, const char *name)
         if (strbuf_getline(buffer, helper, '\n') == EOF) {
                 if (debug)
                         fprintf(stderr, "Debug: Remote helper quit.\n");
-               exit(128);
+               die("Failure in '%s' protocol reader", name);
         }

         if (debug)

Re: git quietly fails on https:// URL, https errors are never reported to user

[Junio C Hamano]

Yuri <yuri@rawbw.com> writes:

> I think that in a rare case of error this extra-printout wouldn't
> hurt.

If the "error is rare, extra verbiage does not hurt" were a valid
attitude, "error is rare, non-zero exit is enough" would be equally
valid ;-)

Also that statement contradicts with the rationale given by 266f1fdf
(transport-helper: be quiet on read errors from helpers,
2013-06-21), no?

    However, this makes a much more common case worse: when a helper
    does die with a useful message, we print the extra "Reading from
    'git-remote-foo failed" message. This can also end up confusing
    users, as they may not even know what remote helpers are (e.g.,
    the fact that http support comes through git-remote-https is
    purely an implementation detail that most users do not know or
    care about).
    
Your change is not an exact revert and rewords the message to read

	Failure in 'http' protocol reader.

instead of

	Reading from helper 'git-remote-http' failed.

which avoids the "helper" word and replacing it with "protocol
reader" [*1*] in an attempt to make it less likely to "end up
confusing users", but I am not sure if "protocol reader" is good
enough for those who get confused with "helper" in the first place.
They will ask their resident guru or favourite search engine about
the message and will be told that your http connection did not go
well either way, but not many people have seen this new message.

If we were to reinstate the extra final line in the error message, I
think we would be off doing a straight revert without any rewording
that introduces yet another word "protocol reader" that is not found
anywhere in our glossary.

I think I am OK with adding one more line after "Reading from
... failed" that explains a more detailed error message might be
there above that line, but I am not sure what the good phrasing
would be.


[Footnote]

*1* It may introduce a new confusion "was it 'read' that failed, or
'write'?", though ;-)

Re: git quietly fails on https:// URL, https errors are never reported to user

[Jeff King]

On Fri, Jan 17, 2014 at 11:43:35AM -0800, Junio C Hamano wrote:

> Yuri <yuri@rawbw.com> writes:
> 
> > I think that in a rare case of error this extra-printout wouldn't
> > hurt.
> 
> If the "error is rare, extra verbiage does not hurt" were a valid
> attitude, "error is rare, non-zero exit is enough" would be equally
> valid ;-)

I think the problem is that error is _not_ rare. For years, we did not
print the extra verbiage, and nobody complained. Then, within days of us
making a release that included the extra line, somebody complained[1].

The real issue is that the remote-helper hanging up _should_ be an
exceptional condition, but it's not. The remote-helper protocol sucks,
and has no way to signal failure of an operation besides just hanging
up. So you end up with junk like:

  $ git clone https://google.com/foo.git
  Cloning into 'foo'...
  fatal: repository 'https://google.com/foo.git/' not found
  fatal: Reading from helper 'git-remote-https' failed

That second line is not adding anything, and IMHO is making things
uglier and more confusing. We _expected_ the helper to hang up; that's
how it signals an error to us. It is not an unexpected condition at all.
The exit(128) we do is simply propagating the error report of the
helper.

That's the common error case: the message is redundant and annoying. The
_uncommon_ case is the one Yuri hit: some library misconfiguration that
causes the helper not to run at all.  Adding back any message is hurting
the common case to help the uncommon one.

> I think I am OK with adding one more line after "Reading from
> ... failed" that explains a more detailed error message might be
> there above that line, but I am not sure what the good phrasing
> would be.

I'd really rather not. Hopefully the explanation above makes it clear
why not.

The "most right" solution is to fix the helper protocol to allow error
reporting. That may be somewhat complicated to retain backward
compatibility (we have to introduce a capability, probe for it, handle
old helpers, etc).

We _may_ be able to do better by annotating certain commands with
whether we expect them to hangup. The big one, I think, would be the
initial "capabilities" command. Something like the patch below would
detect any startup problems in the helper. From Yuri's description, that
would catch his case or any similar ones.

Anything after startup should be the responsibility of the helper to
report. If it doesn't, that's a bug in the helper. The one exception may
be signals. We could waitpid() on the helper and report any signal
death (e.g., it obviously cannot report its own SIGKILL death, and I'd
guess that most do not report their own SIGPIPE death).

diff --git a/transport-helper.c b/transport-helper.c
index 2010674..af03f1a 100644
--- a/transport-helper.c
+++ b/transport-helper.c
@@ -50,7 +50,8 @@ static void sendline(struct helper_data *helper, struct strbuf *buffer)
 		die_errno("Full write to remote helper failed");
 }
 
-static int recvline_fh(FILE *helper, struct strbuf *buffer, const char *name)
+static int recvline_fh(FILE *helper, struct strbuf *buffer, const char *name,
+		       int die_on_failure)
 {
 	strbuf_reset(buffer);
 	if (debug)
@@ -58,7 +59,9 @@ static int recvline_fh(FILE *helper, struct strbuf *buffer, const char *name)
 	if (strbuf_getline(buffer, helper, '\n') == EOF) {
 		if (debug)
 			fprintf(stderr, "Debug: Remote helper quit.\n");
-		exit(128);
+		if (die_on_failure)
+			exit(128);
+		return -1;
 	}
 
 	if (debug)
@@ -68,7 +71,7 @@ static int recvline_fh(FILE *helper, struct strbuf *buffer, const char *name)
 
 static int recvline(struct helper_data *helper, struct strbuf *buffer)
 {
-	return recvline_fh(helper->out, buffer, helper->name);
+	return recvline_fh(helper->out, buffer, helper->name, 1);
 }
 
 static void xchgline(struct helper_data *helper, struct strbuf *buffer)
@@ -163,7 +166,9 @@ static struct child_process *get_helper(struct transport *transport)
 	while (1) {
 		const char *capname;
 		int mandatory = 0;
-		recvline(data, &buf);
+
+		if (recvline_fh(data->out, &buf, data->name, 0) < 0)
+			die("remote helper '%s' aborted session", data->name);
 
 		if (!*buf.buf)
 			break;
@@ -557,7 +562,7 @@ static int process_connect_service(struct transport *transport,
 		goto exit;
 
 	sendline(data, &cmdbuf);
-	recvline_fh(input, &cmdbuf, name);
+	recvline_fh(input, &cmdbuf, name, 1);
 	if (!strcmp(cmdbuf.buf, "")) {
 		data->no_disconnect_req = 1;
 		if (debug)

Re: git quietly fails on https:// URL, https errors are never reported to user

[Jeff King]

On Fri, Jan 17, 2014 at 03:13:25PM -0500, Jeff King wrote:

> On Fri, Jan 17, 2014 at 11:43:35AM -0800, Junio C Hamano wrote:
> 
> > Yuri <yuri@rawbw.com> writes:
> > 
> > > I think that in a rare case of error this extra-printout wouldn't
> > > hurt.
> > 
> > If the "error is rare, extra verbiage does not hurt" were a valid
> > attitude, "error is rare, non-zero exit is enough" would be equally
> > valid ;-)
> 
> I think the problem is that error is _not_ rare. For years, we did not
> print the extra verbiage, and nobody complained. Then, within days of us
> making a release that included the extra line, somebody complained[1].

Forgot my footnote here, but it was:

  http://article.gmane.org/gmane.comp.version-control.git/228498

which led to 266f1fd (transport-helper: be quiet on read errors from
helpers, 2013-06-21).

-Peff

Re: git quietly fails on https:// URL, https errors are never reported to user

[Yuri]

On 01/17/2014 12:13, Jeff King wrote:
>    $ git clonehttps://google.com/foo.git
>    Cloning into 'foo'...
>    fatal: repository 'https://google.com/foo.git/' not found
>    fatal: Reading from helper 'git-remote-https' failed
>
> That second line is not adding anything, and IMHO is making things
> uglier and more confusing. We_expected_  the helper to hang up; that's
> how it signals an error to us. It is not an unexpected condition at all.
> The exit(128) we do is simply propagating the error report of the
> helper.
>
> That's the common error case: the message is redundant and annoying. The
> _uncommon_  case is the one Yuri hit: some library misconfiguration that
> causes the helper not to run at all.  Adding back any message is hurting
> the common case to help the uncommon one.

But you can use the error code value to convey the cause of the failure 
to git, and avoid an unnecessary message in git itself. Based on the 
error code value git could tell if the error has already been reported 
to user.

Yuri

Re: git quietly fails on https:// URL, https errors are never reported to user

[Jeff King]

On Fri, Jan 17, 2014 at 12:39:39PM -0800, Yuri wrote:

> >That second line is not adding anything, and IMHO is making things
> >uglier and more confusing. We_expected_  the helper to hang up; that's
> >how it signals an error to us. It is not an unexpected condition at all.
> >The exit(128) we do is simply propagating the error report of the
> >helper.
> >
> >That's the common error case: the message is redundant and annoying. The
> >_uncommon_  case is the one Yuri hit: some library misconfiguration that
> >causes the helper not to run at all.  Adding back any message is hurting
> >the common case to help the uncommon one.
> 
> But you can use the error code value to convey the cause of the
> failure to git, and avoid an unnecessary message in git itself. Based
> on the error code value git could tell if the error has already been
> reported to user.

Yes, we can, but that is in the same boat as a protocol change: you have
to teach every remote helper (some of which are written by third
parties) to communicate over this sideband channel.

It's should be slightly easier than a change to the protocol text,
because it's mostly backwards compatible (helpers should already be
returning a non-zero error code). I think there is some complication
with exit codes and remote-helpers, where you cannot expect just check
the exit code at any time. I _think_ from previous discussions that it
is safe to waitpid() on the helper after we have gotten EOF on the
reading pipe, though.

-Peff