[Updated PATCH 0/2] Improve remote helpers exec error reporting

[Updated PATCH 0/2] Improve remote helpers exec error reporting

[Ilari Liusvaara]

This reroll fixes the following from previous round:
- Split loop-trying-to-close to its own inline function.
- Don't rely on pipe(2) preserving fd array in case of failure.
- Don't try to use partially received error codes.
- Don't send error about partial write as it would go to who knows where.
- Add a testcase (ENOENT is detected correctly).

Ilari Liusvaara (2):
  Report exec errors from run-command
  Improve transport helper exec failure reporting

 Makefile               |    1 +
 run-command.c          |   79 ++++++++++++++++++++++++++++++++++++++++++++++--
 t/t0061-run-command.sh |   13 ++++++++
 test-run-command.c     |   35 +++++++++++++++++++++
 transport-helper.c     |   14 ++++++--
 5 files changed, 135 insertions(+), 7 deletions(-)
 create mode 100755 t/t0061-run-command.sh
 create mode 100644 test-run-command.c

[Updated PATCH 1/2] Report exec errors from run-command

[Ilari Liusvaara]

Previously run-command was unable to report errors happening in exec
call. Change it to pass errno from failed exec to errno value at
return.

The errno value passing can be done by opening close-on-exec pipe and
piping the error code through in case of failure. In case of success,
close-on-exec closes the pipe on successful exec and parent process
gets end of file on read.

Signed-off-by: Ilari Liusvaara <ilari.liusvaara@elisanet.fi>
---
 Makefile               |    1 +
 run-command.c          |   79 ++++++++++++++++++++++++++++++++++++++++++++++--
 t/t0061-run-command.sh |   13 ++++++++
 test-run-command.c     |   35 +++++++++++++++++++++
 4 files changed, 125 insertions(+), 3 deletions(-)
 create mode 100755 t/t0061-run-command.sh
 create mode 100644 test-run-command.c

diff --git a/Makefile b/Makefile
index 4a1e5bc..452ad50 100644
--- a/Makefile
+++ b/Makefile
@@ -1725,6 +1725,7 @@ TEST_PROGRAMS += test-parse-options$X
 TEST_PROGRAMS += test-path-utils$X
 TEST_PROGRAMS += test-sha1$X
 TEST_PROGRAMS += test-sigchain$X
+TEST_PROGRAMS += test-run-command$X
 
 all:: $(TEST_PROGRAMS)
 
diff --git a/run-command.c b/run-command.c
index cf2d8f7..34e5af4 100644
--- a/run-command.c
+++ b/run-command.c
@@ -15,6 +15,12 @@ static inline void dup_devnull(int to)
 	close(fd);
 }
 
+static inline void force_close(int fd)
+{
+	while (close(fd) < 0 && errno != EBADF)
+		; /* No-op */
+}
+
 int start_command(struct child_process *cmd)
 {
 	int need_in, need_out, need_err;
@@ -76,9 +82,64 @@ fail_pipe:
 	trace_argv_printf(cmd->argv, "trace: run_command:");
 
 #ifndef WIN32
+{
+	int report_pipe[2] = {-1, -1};
+
+	if (pipe(report_pipe) < 0) {
+		report_pipe[0] = -1;
+		report_pipe[1] = -1;
+		warning("Can't open pipe for exec status report: %s\n",
+			strerror(errno));
+	}
+
 	fflush(NULL);
 	cmd->pid = fork();
-	if (!cmd->pid) {
+	if (cmd->pid > 0) {
+		int r = 0, ret;
+		force_close(report_pipe[1]);
+read_again:
+		if (report_pipe[0] > 0)
+			r = read(report_pipe[0], &ret, sizeof(ret));
+		if (r < 0 && (errno == EAGAIN || errno == EINTR ||
+			errno == EWOULDBLOCK))
+			goto read_again;
+		else if (r < 0)
+			warning("Can't read exec status report: %s\n",
+				strerror(errno));
+		else if (r == 0)
+			;
+		else if (r < sizeof(ret)) {
+			warning("Received incomplete exec status report.\n");
+			errno = EBADMSG;
+		} else {
+			failed_errno = ret;
+			/*
+			 * Clean up the process that did the failed execution
+			 * so no zombies remain.
+			 */
+wait_again:
+			r = waitpid(cmd->pid, &ret, 0);
+			if (r < 0 && errno != ECHILD)
+				goto wait_again;
+			cmd->pid = -1;
+		}
+	} else if (!cmd->pid) {
+		int r = 0;
+		int flags;
+		force_close(report_pipe[0]);
+
+		flags = fcntl(report_pipe[1], F_GETFD);
+		if (flags < 0)
+			r = -1;
+		flags |= FD_CLOEXEC;
+		r = (r || fcntl(report_pipe[1], F_SETFD, flags));
+		if (r) {
+			warning("Can't FD_CLOEXEC pipe for exec status "
+				"report: %s\n", strerror(errno));
+			force_close(report_pipe[1]);
+			report_pipe[1] = -1;
+		}
+
 		if (cmd->no_stdin)
 			dup_devnull(0);
 		else if (need_in) {
@@ -126,13 +187,25 @@ fail_pipe:
 		} else {
 			execvp(cmd->argv[0], (char *const*) cmd->argv);
 		}
+		failed_errno = errno;
+
 		trace_printf("trace: exec '%s' failed: %s\n", cmd->argv[0],
 				strerror(errno));
+
+		r = 0;
+write_again:
+		if (report_pipe[1] >= 0)
+			r = write(report_pipe[1], &failed_errno,
+				sizeof(failed_errno));
+		if (r < 0 && (errno == EAGAIN || errno == EINTR ||
+			errno == EWOULDBLOCK))
+			goto write_again;
+
 		exit(127);
-	}
-	if (cmd->pid < 0)
+	} else if (cmd->pid < 0)
 		error("cannot fork() for %s: %s", cmd->argv[0],
 			strerror(failed_errno = errno));
+}
 #else
 {
 	int s0 = -1, s1 = -1, s2 = -1;	/* backups of stdin, stdout, stderr */
diff --git a/t/t0061-run-command.sh b/t/t0061-run-command.sh
new file mode 100755
index 0000000..1d9e82a
--- /dev/null
+++ b/t/t0061-run-command.sh
@@ -0,0 +1,13 @@
+#!/bin/sh
+#
+# Copyright (c) 2009 Ilari Liusvaara
+#
+
+test_description='Test run command'
+
+. ./test-lib.sh
+
+test_expect_success "reporting ENOENT" \
+"test-run-command 1"
+
+test_done
diff --git a/test-run-command.c b/test-run-command.c
new file mode 100644
index 0000000..6297785
--- /dev/null
+++ b/test-run-command.c
@@ -0,0 +1,35 @@
+/*
+ * test-run-command.c: test run command API.
+ *
+ * (C) 2009 Ilari Liusvaara <ilari.liusvaara@elisanet.fi>
+ *
+ * This code is free software; you can redistribute it and/or modify
+ * it under the terms of the GNU General Public License version 2 as
+ * published by the Free Software Foundation.
+ */
+
+#include "git-compat-util.h"
+#include "run-command.h"
+#include <string.h>
+#include <errno.h>
+
+int main(int argc, char **argv)
+{
+	char* procs[2];
+	struct child_process proc;
+	memset(&proc, 0, sizeof(proc));
+
+	if(argc < 2)
+		return 1;
+
+	if (argv[1][1] == '1')
+		procs[0] = "does-not-exist-62896869286";
+	procs[1] = NULL;
+	proc.argv = (const char **)procs;
+
+	if (!run_command(&proc))
+		return 1;
+	if (errno != ENOENT)
+		return 1;
+	return 0;
+}
-- 
1.6.6.3.gaa2e1

Re: [Updated PATCH 1/2] Report exec errors from run-command

[Erik Faye-Lund]

On Wed, Dec 30, 2009 at 11:52 AM, Ilari Liusvaara
<ilari.liusvaara@elisanet.fi> wrote:
> +static inline void force_close(int fd)
> +{
> +       while (close(fd) < 0 && errno != EBADF)
> +               ; /* No-op */
> +}
> +

According to http://linux.die.net/man/2/close, close can set errno to
EBADF, EINTR, or EIO. Currently, you're retrying on EINTR and EIO.
When we get EIO, are you sure it makes sense to retry? I'd imagine
that error would most likely just repeat itself, leading to an
infinite loop. How about "while (close(fd) < 0 && errno == EINTR)"
instead? I've seen other functions (like xread in wrapper.c) only
retry on those errors that it expects. In xreads case, it's not
retrying on EIO.

Perhaps it's OK still, since force_close() is only used on pipes. I
don't know if closing a pipe can generate EIO or not.

-- 
Erik "kusma" Faye-Lund

Re: [Updated PATCH 1/2] Report exec errors from run-command

[Tarmigan]

On Wed, Dec 30, 2009 at 5:52 AM, Ilari Liusvaara
<ilari.liusvaara@elisanet.fi> wrote:
> Previously run-command was unable to report errors happening in exec
> call. Change it to pass errno from failed exec to errno value at
> return.
>
> The errno value passing can be done by opening close-on-exec pipe and
> piping the error code through in case of failure. In case of success,
> close-on-exec closes the pipe on successful exec and parent process
> gets end of file on read.

I was testing pu and 'git diff' and 'git log' would hang forever.

Bisecting pointed to v1 of this patch.  But seeing that v2 was out, I
tried v2 of the patch, but the issue remains.

Tried on OSX and linux with the same results.

Here's a gdb backtrace on OSX at the point where I interrupted it:
(gdb) bt
#0  0x9923dbfe in read$UNIX2003 ()
#1  0x000b399b in start_command (cmd=0x10b300) at run-command.c:110
#2  0x00099452 in setup_pager () at pager.c:94
#3  0x0002196b in cmd_diff (argc=1, argv=0xbffff42c, prefix=0x0) at
builtin-diff.c:316
#4  0x00002a2a in run_builtin [inlined] () at git.c:257
#5  0x00002a2a in handle_internal_command (argc=1, argv=0xbffff42c) at git.c:401
#6  0x00002cab in main (argc=1, argv=0xbffff42c) at git.c:443

and on linux:
(gdb) bt
#0  0x0000003530a0d590 in __read_nocancel () from /lib64/libpthread.so.0
#1  0x0000000000494858 in start_command (cmd=0x71ed60) at run-command.c:93
#2  0x000000000047daf8 in setup_pager () at pager.c:94
#3  0x000000000041d83f in cmd_diff (argc=1, argv=0x7fff256f9fe0, prefix=0x0)
    at builtin-diff.c:316
#4  0x0000000000403ced in handle_internal_command (argc=1, argv=0x7fff256f9fe0)
    at git.c:257
#5  0x0000000000403f26 in main (argc=1, argv=0x7fff256f9fe0) at git.c:445

Thanks,
Tarmigan

Re: [Updated PATCH 1/2] Report exec errors from run-command

[Ilari Liusvaara]

On Thu, Dec 31, 2009 at 12:26:48AM -0500, Tarmigan wrote:
> On Wed, Dec 30, 2009 at 5:52 AM, Ilari Liusvaara
> <ilari.liusvaara@elisanet.fi> wrote:
> 
> I was testing pu and 'git diff' and 'git log' would hang forever.
 
V3 just sent to list. Should fix this issue.

-Ilari

Re: [Updated PATCH 1/2] Report exec errors from run-command

[Tarmigan]

On Thu, Dec 31, 2009 at 5:48 AM, Ilari Liusvaara
<ilari.liusvaara@elisanet.fi> wrote:
> On Thu, Dec 31, 2009 at 12:26:48AM -0500, Tarmigan wrote:
>> On Wed, Dec 30, 2009 at 5:52 AM, Ilari Liusvaara
>> <ilari.liusvaara@elisanet.fi> wrote:
>>
>> I was testing pu and 'git diff' and 'git log' would hang forever.
>
> V3 just sent to list. Should fix this issue.

Yep, that fixed it.

Thanks,
Tarmigan

[Updated PATCH 2/2] Improve transport helper exec failure reporting

[Ilari Liusvaara]

Previously transport-helper exec failure error reporting was pretty
much useless as it didn't report errors from execve, only from pipe
and fork. Now that run-command passes errno from exec, use the
improved support to actually print useful errors if execution fails.

Signed-off-by: Ilari Liusvaara <ilari.liusvaara@elisanet.fi>
---
 transport-helper.c |   14 ++++++++++----
 1 files changed, 10 insertions(+), 4 deletions(-)

diff --git a/transport-helper.c b/transport-helper.c
index 5078c71..0965c9b 100644
--- a/transport-helper.c
+++ b/transport-helper.c
@@ -31,13 +31,19 @@ static struct child_process *get_helper(struct transport *transport)
 	helper->out = -1;
 	helper->err = 0;
 	helper->argv = xcalloc(4, sizeof(*helper->argv));
-	strbuf_addf(&buf, "remote-%s", data->name);
+	strbuf_addf(&buf, "git-remote-%s", data->name);
 	helper->argv[0] = strbuf_detach(&buf, NULL);
 	helper->argv[1] = transport->remote->name;
 	helper->argv[2] = transport->url;
-	helper->git_cmd = 1;
-	if (start_command(helper))
-		die("Unable to run helper: git %s", helper->argv[0]);
+	helper->git_cmd = 0;
+	if (start_command(helper)) {
+		if (errno == ENOENT)
+			die("Unable to find remote helper for \"%s\"",
+				data->name);
+		else
+			die("Unable to run helper %s: %s", helper->argv[0],
+				strerror(errno));
+	}
 	data->helper = helper;
 
 	write_str_in_full(helper->in, "capabilities\n");
-- 
1.6.6.3.gaa2e1

Re: [Updated PATCH 2/2] Improve transport helper exec failure reporting

[Johannes Sixt]

Ilari Liusvaara schrieb:
> @@ -31,13 +31,19 @@ static struct child_process *get_helper(struct transport *transport)
>  	helper->out = -1;
>  	helper->err = 0;
>  	helper->argv = xcalloc(4, sizeof(*helper->argv));
> -	strbuf_addf(&buf, "remote-%s", data->name);
> +	strbuf_addf(&buf, "git-remote-%s", data->name);
>  	helper->argv[0] = strbuf_detach(&buf, NULL);
>  	helper->argv[1] = transport->remote->name;
>  	helper->argv[2] = transport->url;
> -	helper->git_cmd = 1;
> -	if (start_command(helper))
> -		die("Unable to run helper: git %s", helper->argv[0]);
> +	helper->git_cmd = 0;
> +	if (start_command(helper)) {
> +		if (errno == ENOENT)
> +			die("Unable to find remote helper for \"%s\"",
> +				data->name);

You should set helper->silent_exec_failure = 1 when you give your own 
error message for the ENOENT case.

BTW, which error message do you see without your change in this case? You 
only say "pretty much useless", but do not give an example.

> +		else
> +			die("Unable to run helper %s: %s", helper->argv[0],
> +				strerror(errno));

You shouldn't write an error message here because start_command has 
already reported the error.

-- Hannes

Re: [Updated PATCH 2/2] Improve transport helper exec failure reporting

[Ilari Liusvaara]

On Thu, Dec 31, 2009 at 04:44:37PM +0100, Johannes Sixt wrote:
> Ilari Liusvaara schrieb:
> >@@ -31,13 +31,19 @@ static struct child_process *get_helper(struct transport *transport)
> 
> You should set helper->silent_exec_failure = 1 when you give your
> own error message for the ENOENT case.

Ah yeah, might matter for Win32.

> BTW, which error message do you see without your change in this
> case? You only say "pretty much useless", but do not give an
> example.

git: 'remote-foo' is not a git-command. See 'git --help'.

And as first line of output, such thing is utterly confusing.

> >+		else
> >+			die("Unable to run helper %s: %s", helper->argv[0],
> >+				strerror(errno));
> 
> You shouldn't write an error message here because start_command has
> already reported the error.

Its not printed on Unix.

-Ilari

Re: [Updated PATCH 2/2] Improve transport helper exec failure reporting

[Johannes Sixt]

Ilari Liusvaara schrieb:
> On Thu, Dec 31, 2009 at 04:44:37PM +0100, Johannes Sixt wrote:
>> Ilari Liusvaara schrieb:
>>> @@ -31,13 +31,19 @@ static struct child_process *get_helper(struct transport *transport)
>> You should set helper->silent_exec_failure = 1 when you give your
>> own error message for the ENOENT case.
> 
> Ah yeah, might matter for Win32.

Actually, no. I forgot to mention that your modified start_command should 
treat ENOENT differently by looking at cmd->silent_exec_failure. But see 
below.

>> BTW, which error message do you see without your change in this
>> case? You only say "pretty much useless", but do not give an
>> example.
> 
> git: 'remote-foo' is not a git-command. See 'git --help'.
> 
> And as first line of output, such thing is utterly confusing.

And you change this by treating the helper command not as a git command, 
but as a normal command that happens to start with 'git-'. Whether this 
interpretation is suitable for the transport layer, I do not want to 
decide and I will certainly not object. :-)

An alternative solution would be to forward the silent_exec_failure flag 
to exec_git_cmd() to unify the treatment of the error condition with the 
non-git-command error path.

>>> +		else
>>> +			die("Unable to run helper %s: %s", helper->argv[0],
>>> +				strerror(errno));
>> You shouldn't write an error message here because start_command has
>> already reported the error.
> 
> Its not printed on Unix.

I see.

Documentation/technical/api-run-command.txt documents the error behavior. 
There are three error cases:

1. system call failures
2. exec failure due to ENOENT
3. non-zero exit of the child and death through signal

Your patch makes all exec failures into category 1, but IMO, these are 
actually category 3 (except for the ENOENT case).

In case 3, it is expected that the child process prints a suitable error 
message. Therefore, you should start with merely replacing the unconditional

	exit(127);
by
	if (errno == ENOENT)
		exit(127);
	else
		die_errno("Cannot exec %s", cmd->argv[0]);

And then you can think about how you support the ENOENT case better. My 
proposal for this was to do the PATH lookup manually before the fork(), 
and then the above conditional would melt down to simply:

	die_errno("Cannot exec %s", cmd->argv[0]);

-- Hannes

Re: [Updated PATCH 2/2] Improve transport helper exec failure reporting

[Ilari Liusvaara]

On Thu, Dec 31, 2009 at 06:48:02PM +0100, Johannes Sixt wrote:
> Ilari Liusvaara schrieb:
> >On Thu, Dec 31, 2009 at 04:44:37PM +0100, Johannes Sixt wrote:
> >>Ilari Liusvaara schrieb:
 
> And you change this by treating the helper command not as a git
> command, but as a normal command that happens to start with 'git-'.
> Whether this interpretation is suitable for the transport layer, I
> do not want to decide and I will certainly not object. :-)

The transport helpers are special: they shouldn't be built-in.

> An alternative solution would be to forward the silent_exec_failure
> flag to exec_git_cmd() to unify the treatment of the error condition
> with the non-git-command error path.

Won't work. The error in git command case would be noted in another memory
image. And passing that back would be nasty to say the least.
 
> In case 3, it is expected that the child process prints a suitable
> error message. Therefore, you should start with merely replacing the
> unconditional
> 
> 	exit(127);
> by
> 	if (errno == ENOENT)
> 		exit(127);
> 	else
> 		die_errno("Cannot exec %s", cmd->argv[0]);
> 
> And then you can think about how you support the ENOENT case better.
> My proposal for this was to do the PATH lookup manually before the
> fork(), and then the above conditional would melt down to simply:
> 
> 	die_errno("Cannot exec %s", cmd->argv[0]);
> 

The child process can't sanely print anything. Stderr would go to
who knows where. Parent process should have much better idea what to
do with errors.


-Ilari

Re: [Updated PATCH 2/2] Improve transport helper exec failure reporting

[Johannes Sixt]

Ilari Liusvaara schrieb:
> On Thu, Dec 31, 2009 at 06:48:02PM +0100, Johannes Sixt wrote:
>> In case 3, it is expected that the child process prints a suitable
>> error message. Therefore, you should start with merely replacing the
>> unconditional
>>
>> 	exit(127);
>> by
>> 	if (errno == ENOENT)
>> 		exit(127);
>> 	else
>> 		die_errno("Cannot exec %s", cmd->argv[0]);
>>
>> And then you can think about how you support the ENOENT case better.
>> My proposal for this was to do the PATH lookup manually before the
>> fork(), and then the above conditional would melt down to simply:
>>
>> 	die_errno("Cannot exec %s", cmd->argv[0]);
>>
> 
> The child process can't sanely print anything. Stderr would go to
> who knows where.

Wrong - because:

> Parent process should have much better idea what to
> do with errors.

Very correct. For this reason, the parent process assigns a stderr channel 
to the child (or does not do so to inherit its own stderr), and the child 
is expected to use it. Errors due to execvp failures are no exception, IMO 
(except ENOENT, as always).

-- Hannes

Re: [Updated PATCH 2/2] Improve transport helper exec failure reporting

[Johannes Sixt]

On Donnerstag, 31. Dezember 2009, Johannes Sixt wrote:
> Ilari Liusvaara schrieb:
> > The child process can't sanely print anything. Stderr would go to
> > who knows where.
>
> Wrong - because:
> > Parent process should have much better idea what to
> > do with errors.
>
> Very correct. For this reason, the parent process assigns a stderr channel
> to the child (or does not do so to inherit its own stderr), and the child
> is expected to use it. Errors due to execvp failures are no exception, IMO
> (except ENOENT, as always).

Actually, I changed my mind: execvp failures should go to the parent's stderr,
just as all errors before the exec happens.

How about this patch for a starter? Take it with a grain of salt - I coded it
after the New Year celebration ;) I was unable to find a case quickly that
exercises die_child().

--- 8< ---
From: Johannes Sixt <j6t@kdbg.org>
Date: Fri, 1 Jan 2010 01:22:05 +0100
Subject: [PATCH] start_command: report child process setup errors to the parent's stderr

When the child process's environment is set up in start_command(), error
messages were written to wherever the parent redirected the child's stderr
channel. However, even if the parent redirected the child's stderr, errors
during this setup process, including the exec itself, are usually an
indication of a problem in the parent's environment. Therefore, the error
messages should go to the parent's stderr.

Redirection of the child's error messages is usually only used to redirect
hook error messages during client-server exchanges such that stderr goes
to the client. In these cases, hook setup errors could be regarded as
information leak.

This patch makes a copy of stderr if necessary and uses a special
die routine that is used for all die() calls so that the errors are sent to
the parent's channel.

Signed-off-by: Johannes Sixt <j6t@kdbg.org>
---
 run-command.c |   39 ++++++++++++++++++++++++++++++++++++---
 1 files changed, 36 insertions(+), 3 deletions(-)

diff --git a/run-command.c b/run-command.c
index cf2d8f7..2480a8c 100644
--- a/run-command.c
+++ b/run-command.c
@@ -15,6 +15,23 @@ static inline void dup_devnull(int to)
 	close(fd);
 }
 
+#ifndef WIN32
+static int child_err;
+
+static NORETURN void die_child(const char *err, va_list params)
+{
+	char msg[4096];
+	int len = vsnprintf(msg, sizeof(msg), err, params);
+	if (len > sizeof(msg))
+		len = sizeof(msg);
+
+	write(child_err, "fatal: ", 7);
+	write(child_err, msg, len);
+	write(child_err, "\n", 1);
+	exit(128);
+}
+#endif
+
 int start_command(struct child_process *cmd)
 {
 	int need_in, need_out, need_err;
@@ -79,6 +96,21 @@ fail_pipe:
 	fflush(NULL);
 	cmd->pid = fork();
 	if (!cmd->pid) {
+		/*
+		 * Redirect the channel to write syscall error messages to
+		 * before redirecting the process's stderr so that all die()
+		 * in subsequent call paths use the parent's stderr.
+		 */
+		if (cmd->no_stderr || need_err) {
+			int flags;
+			child_err = dup(2);
+			flags = fcntl(child_err, F_GETFL);
+			if (flags < 0)
+				flags = 0;
+			fcntl(child_err, F_SETFL, flags | FD_CLOEXEC);
+			set_die_routine(die_child);
+		}
+
 		if (cmd->no_stdin)
 			dup_devnull(0);
 		else if (need_in) {
@@ -126,9 +158,10 @@ fail_pipe:
 		} else {
 			execvp(cmd->argv[0], (char *const*) cmd->argv);
 		}
-		trace_printf("trace: exec '%s' failed: %s\n", cmd->argv[0],
-				strerror(errno));
-		exit(127);
+		if (errno == ENOENT)
+			exit(127);
+		else
+			die_errno("exec '%s'", cmd->argv[0]);
 	}
 	if (cmd->pid < 0)
 		error("cannot fork() for %s: %s", cmd->argv[0],
-- 
1.6.6.115.gd1ab3