[PATCH] daemon: send stderr of service programs to the syslog

If git-daemon is run with --detach or --inetd, then stderr is explicitly
redirected to /dev/null. But notice that the service programs were spawned
via execl_git_cmd(), in particular, the stderr channel is inherited from
the daemon. This means that errors that the programs wrote to stderr (for
example, via die()), went to /dev/null.

This patch arranges that the daemon does not merely exec the service
program, but forks it and monitors stderr of the child; it writes the
errors that it produces to the daemons log via logerror().

A consequence is that the daemon process remains in memory for the full
duration of the service program, but this cannot be avoided.

Signed-off-by: Johannes Sixt <redacted>
---
 I don't know whether service programs like upload-archive or upload-pack
 write progress report to stderr or not, for example, if a client does not
 support side-bands. In this case this patch is probably not enough since
 this would fill the log with unneeded progress information. Any hints
 are appreciated.

 I intend to follow-up this patch with another one that integrates
 run_service_command() in execute() in order to streamline how the
 'incoming' fd is inherited to the service programs. But I haven't
 even begun this change, yet, because I'd like to know first how this
 one is received.

 -- Hannes

 daemon.c |   57 ++++++++++++++++++++++++++++++++++++++++++++++++---------
 1 files changed, 48 insertions(+), 9 deletions(-)

diff --git a/daemon.c b/daemon.c
index d7ceca4..3e1a354 100644
--- a/daemon.c
+++ b/daemon.c

@@ -1,6 +1,7 @@
 #include "cache.h"
 #include "pkt-line.h"
-#include "exec_cmd.h"
+#include "run-command.h"
+#include "strbuf.h"
 
 #include <syslog.h>
 

@@ -343,28 +344,66 @@ static int run_service(char *dir, const struct daemon_service *service)
 	return service->fn();
 }
 
+static void copy_to_log(int fd)
+{
+	struct strbuf line = STRBUF_INIT;
+	FILE *fp;
+
+	fp = fdopen(fd, "r");
+	if (fp == NULL) {
+		logerror("fdopen of error channel failed");
+		close(fd);
+		return;
+	}
+
+	while (strbuf_getline(&line, fp, '\n') != EOF) {
+		logerror("%s", line.buf);
+		strbuf_setlen(&line, 0);
+	}
+	
+	strbuf_release(&line);
+	fclose(fp);
+}
+
+static int run_service_command(const char **argv)
+{
+	struct child_process cld;
+
+	memset(&cld, 0, sizeof(cld));
+	cld.argv = argv;
+	cld.git_cmd = 1;
+	cld.err = -1;
+	if (start_command(&cld))
+		return -1;
+
+	close(0);
+	close(1);
+
+	copy_to_log(cld.err);
+
+	return finish_command(&cld);
+}
+
 static int upload_pack(void)
 {
 	/* Timeout as string */
 	char timeout_buf[64];
+	const char *argv[] = { "upload-pack", "--strict", timeout_buf, ".", NULL };
 
 	snprintf(timeout_buf, sizeof timeout_buf, "--timeout=%u", timeout);
-
-	/* git-upload-pack only ever reads stuff, so this is safe */
-	execl_git_cmd("upload-pack", "--strict", timeout_buf, ".", NULL);
-	return -1;
+	return run_service_command(argv);
 }
 
 static int upload_archive(void)
 {
-	execl_git_cmd("upload-archive", ".", NULL);
-	return -1;
+	static const char *argv[] = { "upload-archive", ".", NULL };
+	return run_service_command(argv);
 }
 
 static int receive_pack(void)
 {
-	execl_git_cmd("receive-pack", ".", NULL);
-	return -1;
+	static const char *argv[] = { "receive-pack", ".", NULL };
+	return run_service_command(argv);
 }
 
 static struct daemon_service daemon_service[] = {

-- 
1.6.3.17.g1665f

Johannes Sixt [off-list ref] wrote:

If git-daemon is run with --detach or --inetd, then stderr is explicitly
redirected to /dev/null. But notice that the service programs were spawned
via execl_git_cmd(), in particular, the stderr channel is inherited from
the daemon. This means that errors that the programs wrote to stderr (for
example, via die()), went to /dev/null.

This patch arranges that the daemon does not merely exec the service
program, but forks it and monitors stderr of the child; it writes the
errors that it produces to the daemons log via logerror().

A consequence is that the daemon process remains in memory for the full
duration of the service program, but this cannot be avoided.

Signed-off-by: Johannes Sixt <redacted>
---
 I don't know whether service programs like upload-archive or upload-pack
 write progress report to stderr or not, for example, if a client does not
 support side-bands. In this case this patch is probably not enough since
 this would fill the log with unneeded progress information. Any hints
 are appreciated.

They could, if they were broken.  :-)

IIRC only upload-pack produces progress (from pack-objects).
It does so by using a pipe on fd 2, and either copying it down
to the client via side-band, or discarding it.  So progress data
shouldn't ever appear on upload-pack's own fd 2, which means you
won't get it in this syslog thing.

But I have to wonder, why are we doing this?  Why can't we teach the
individual server program to record its error to the syslog before
it aborts?  Are we looking for SIGSEGV or something?  Its only the
daemon program staying around in memory, but that's a lot of little
daemons doing nothing waiting for their children to terminate.
Seems like a waste to me.
 
-- 
Shawn.

On Mon, 15 Jun 2009, Shawn O. Pearce wrote:

But I have to wonder, why are we doing this?  Why can't we teach the
individual server program to record its error to the syslog before
it aborts?  Are we looking for SIGSEGV or something?  Its only the
daemon program staying around in memory, but that's a lot of little
daemons doing nothing waiting for their children to terminate.

Those daemons certainly have very little in terms of private data memory 
usage, so all of them will share the same memory pages in practice. And 
it is certainly best to have only one location to deal with syslog usage 
than having each server programs to do it, after figuring out if they 
are actually invoked in a context that requires syslog instead of 
stderr.  Having the git daemon deal with syslog, and log any abnormal 
exit code from the programs it spawn is IMHO a pretty logical thing to 
do.


Nicolas

Shawn O. Pearce wrote:

They could, if they were broken.  :-)

IIRC only upload-pack produces progress (from pack-objects).
It does so by using a pipe on fd 2, and either copying it down
to the client via side-band, or discarding it.  So progress data
shouldn't ever appear on upload-pack's own fd 2, which means you
won't get it in this syslog thing.

But I have to wonder, why are we doing this?  Why can't we teach the
individual server program to record its error to the syslog before
it aborts?  Are we looking for SIGSEGV or something?  Its only the
daemon program staying around in memory, but that's a lot of little
daemons doing nothing waiting for their children to terminate.
Seems like a waste to me.
 

Actually, even logging signals would be useful, so I think this makes
sense.  The daemon process is pretty trivial compared to the rest of the
stuff being spawned.

	-hpa

upload-pack runs pack-objects, which generates progress indicator output
on its stderr. If the client requests a sideband, this indicator is sent
to the client; but if it did not, then the progress is written to
upload-pack's own stderr.

Since the previous patch git-daemon monitors stderr of the service program,
such as upload-pack, and copies it to the syslog. This would now also copy
the progress indicator to the syslog. We avoid this by calling pack-objects
without --progress if there is no sideband channel to the client.

Signed-off-by: Johannes Sixt <redacted>
---
On Montag, 15. Juni 2009, Shawn O. Pearce wrote:

IIRC only upload-pack produces progress (from pack-objects).
It does so by using a pipe on fd 2, and either copying it down
to the client via side-band, or discarding it.  So progress data
shouldn't ever appear on upload-pack's own fd 2, which means you
won't get it in this syslog thing.

Unfortunately, upload-pack *does* write the progress to fd 2,
and this fixes it.

-- Hannes

 upload-pack.c |    9 +++++++++
 1 files changed, 9 insertions(+), 0 deletions(-)

diff --git a/upload-pack.c b/upload-pack.c
index edc7861..fef8be5 100644
--- a/upload-pack.c
+++ b/upload-pack.c

@@ -521,6 +521,15 @@ static void receive_needs(void)
 	}
 	if (debug_fd)
 		write_in_full(debug_fd, "#E\n", 3);
+
+	/*
+	 * If upload-pack is run from the daemon and the client did not
+	 * request a sideband, the progress output produced by pack-objects
+	 * would go to the syslog. Squelch it.
+	 */
+	if (!use_sideband)
+		no_progress = 1;
+
 	if (depth == 0 && shallows.nr == 0)
 		return;
 	if (depth > 0) {

-- 
1.6.3.17.g1665f

On Sonntag, 14. Juni 2009, Johannes Sixt wrote:

 I don't know whether service programs like upload-archive or upload-pack
 write progress report to stderr or not, for example, if a client does not
 support side-bands. In this case this patch is probably not enough since
 this would fill the log with unneeded progress information. Any hints
 are appreciated.

The progress indicator can be helped . But there is now another anoyance: If 
the client terminates the connection early, this is now logged as:

fatal: unable to run 'git-upload-pack'

The reason for this is that upload-pack is run as 'git upload-pack', which 
itself spawns the external 'git-upload-pack'. The latter dies from a SIGPIPE, 
and the former, in execv_dashed_external(), dutyfully writes this down.

The easiest solution is perhaps to make upload-pack a builtin.

BUT... The motivation, of which this patch is actually a fall-out, is to clean 
up the messy error behavor of the start,finish,run_command family. To take 
care of this error message is just one more (hopefully small) point on my 
agenda.

 I intend to follow-up this patch with another one that integrates
 run_service_command() in execute() in order to streamline how the
 'incoming' fd is inherited to the service programs.

I'm not sure anymore whether the change I planned here is worth it. When I 
wrote this announcement, I had mis-remembered how daemon.c's handle() and 
execute() functions and --inetd mode interact.

-- Hannes

Johannes Sixt wrote:

On Sonntag, 14. Juni 2009, Johannes Sixt wrote:

quoted

 I don't know whether service programs like upload-archive or upload-pack
 write progress report to stderr or not, for example, if a client does not
 support side-bands. In this case this patch is probably not enough since
 this would fill the log with unneeded progress information. Any hints
 are appreciated.

The progress indicator can be helped . But there is now another anoyance: If 
the client terminates the connection early, this is now logged as:

fatal: unable to run 'git-upload-pack'

The reason for this is that upload-pack is run as 'git upload-pack', which 
itself spawns the external 'git-upload-pack'. The latter dies from a SIGPIPE, 
and the former, in execv_dashed_external(), dutyfully writes this down.

The easiest solution is perhaps to make upload-pack a builtin.

BUT... The motivation, of which this patch is actually a fall-out, is to clean 
up the messy error behavor of the start,finish,run_command family. To take 
care of this error message is just one more (hopefully small) point on my 
agenda.

We probably do want to log that the client has disconnected.

	-hpa

On Montag, 15. Juni 2009, H. Peter Anvin wrote:

Johannes Sixt wrote:

quoted

The progress indicator can be helped . But there is now another anoyance:
If the client terminates the connection early, this is now logged as:

fatal: unable to run 'git-upload-pack'

We probably do want to log that the client has disconnected.

Any client, or only clients that disconnect early? Is this useful besides 
debugging?

I think git-daemon's --verbose is intended to log all client connects and 
disconnects. This here is about a *new* message that would be logged 
without --verbose.

-- Hannes

Johannes Sixt wrote:

On Montag, 15. Juni 2009, H. Peter Anvin wrote:

quoted

Johannes Sixt wrote:

quoted

The progress indicator can be helped . But there is now another anoyance:
If the client terminates the connection early, this is now logged as:

fatal: unable to run 'git-upload-pack'

We probably do want to log that the client has disconnected.

Any client, or only clients that disconnect early? Is this useful besides 
debugging?

Clients that disconnect without completing the transaction.  This is
highly valuable to administrators when tracking down a problem (since it
generally implies a client or network problem, as opposed to a server
problem.)

	-hpa

Johannes Sixt [off-list ref] writes:

    CC daemon.o
cc1: warnings being treated as errors
daemon.c: In function 'main':
daemon.c:981: error: implicit declaration of function 'git_extract_argv0_path'
make: *** [daemon.o] Error 1

I'll add the include back in the meantime.

On Freitag, 19. Juni 2009, Junio C Hamano wrote:

Johannes Sixt [off-list ref] writes:

quoted

diff --git a/daemon.c b/daemon.c
index d7ceca4..3e1a354 100644
--- a/daemon.c
+++ b/daemon.c

@@ -1,6 +1,7 @@
 #include "cache.h"
 #include "pkt-line.h"
-#include "exec_cmd.h"
+#include "run-command.h"
+#include "strbuf.h"

    CC daemon.o
cc1: warnings being treated as errors
daemon.c: In function 'main':
daemon.c:981: error: implicit declaration of function
'git_extract_argv0_path' make: *** [daemon.o] Error 1

I'll add the include back in the meantime.

Oops, you are right! Thanks for noticing it. Silly me: I didn't have -Wall in 
my CFLAGS.

-- Hannes