[core] restart piped loggers if they exit (fixes #1393)

x-ref:
  "access log pipe writer should restart child process if it exits"
  https://redmine.lighttpd.net/issues/1393

4 files changed, 157 insertions, 18 deletions

diff --git a/src/fdevent.c b/src/fdevent.c
index b73a08b3..28b07234 100644
--- a/src/fdevent.c
+++ b/src/fdevent.c
@@ -6,6 +6,7 @@
 #include "log.h"
 
 #include <sys/types.h>
+#include <sys/wait.h>
 #include "sys-socket.h"
 
 #include <unistd.h>
@@ -13,6 +14,7 @@
 #include <string.h>
 #include <errno.h>
 #include <fcntl.h>
+#include <time.h>
 
 #ifdef SOCK_CLOEXEC
 static int use_sock_cloexec;
@@ -538,10 +540,24 @@ pid_t fdevent_fork_execve(const char *name, char *argv[], char *envp[], int fdin
 }
 
 
-static int fdevent_open_logger_pipe(const char *logger) {
-    /* create write pipe and spawn process */
+typedef struct fdevent_cmd_pipe {
+    pid_t pid;
+    int fds[2];
+    const char *cmd;
+    time_t start;
+} fdevent_cmd_pipe;
+
+typedef struct fdevent_cmd_pipes {
+    fdevent_cmd_pipe *ptr;
+    size_t used;
+    size_t size;
+} fdevent_cmd_pipes;
+
+static fdevent_cmd_pipes cmd_pipes;
+
+
+static pid_t fdevent_open_logger_pipe_spawn(const char *logger, int rfd) {
     char *args[4];
-    int to_log_fds[2];
     int devnull = fdevent_open_devnull();
     pid_t pid;
 
@@ -549,31 +565,129 @@ static int fdevent_open_logger_pipe(const char *logger) {
         return -1;
     }
 
-    if (pipe(to_log_fds)) {
-        close(devnull);
-        return -1;
-    }
-    fdevent_setfd_cloexec(to_log_fds[0]);
-    fdevent_setfd_cloexec(to_log_fds[1]);
-
     *(const char **)&args[0] = "/bin/sh";
     *(const char **)&args[1] = "-c";
     *(const char **)&args[2] = logger;
     args[3] = NULL;
 
-    pid = fdevent_fork_execve(args[0], args, NULL, to_log_fds[0], devnull, devnull, -1);
+    pid = fdevent_fork_execve(args[0], args, NULL, rfd, devnull, devnull, -1);
 
     if (pid > 0) {
-        /*(future: save pipe fds, pid, and command line to restart if child exits)*/
         close(devnull);
-        close(to_log_fds[0]);
-        return to_log_fds[1];
     }
     else {
         int errnum = errno;
         close(devnull);
-        close(to_log_fds[0]);
-        close(to_log_fds[1]);
+        errno = errnum;
+    }
+    return pid;
+}
+
+
+static void fdevent_waitpid_logger_pipe(fdevent_cmd_pipe *fcp, time_t ts) {
+    pid_t pid = fcp->pid;
+    if (pid > 0) {
+        switch (waitpid(pid, NULL, WNOHANG)) {
+          case 0:  return;
+          case -1: if (errno == EINTR) return; /* fall through */
+          default: break;
+        }
+        fcp->pid = -1;
+    }
+    if (fcp->start + 5 < ts) { /* limit restart to once every 5 sec */
+        /* restart child process using existing pipe fds */
+        fcp->start = ts;
+        fcp->pid = fdevent_open_logger_pipe_spawn(fcp->cmd, fcp->fds[0]);
+    }
+}
+
+
+void fdevent_waitpid_logger_pipes(time_t ts) {
+    for (size_t i = 0; i < cmd_pipes.used; ++i) {
+        fdevent_waitpid_logger_pipe(cmd_pipes.ptr+i, ts);
+    }
+}
+
+
+int fdevent_reaped_logger_pipe(pid_t pid) {
+    for (size_t i = 0; i < cmd_pipes.used; ++i) {
+        fdevent_cmd_pipe *fcp = cmd_pipes.ptr+i;
+        if (fcp->pid == pid) {
+            time_t ts = time(NULL);
+            if (fcp->start + 5 < ts) { /* limit restart to once every 5 sec */
+                fcp->start = ts;
+                fcp->pid = fdevent_open_logger_pipe_spawn(fcp->cmd,fcp->fds[0]);
+                return 1;
+            }
+            else {
+                fcp->pid = -1;
+                return -1;
+            }
+        }
+    }
+    return 0;
+}
+
+
+void fdevent_close_logger_pipes(void) {
+    for (size_t i = 0; i < cmd_pipes.used; ++i) {
+        fdevent_cmd_pipe *fcp = cmd_pipes.ptr+i;
+        close(fcp->fds[0]);
+        if (fcp->fds[1] != STDERR_FILENO) close(fcp->fds[1]);
+    }
+    free(cmd_pipes.ptr);
+    cmd_pipes.ptr = NULL;
+    cmd_pipes.used = 0;
+    cmd_pipes.size = 0;
+}
+
+
+void fdevent_breakagelog_logger_pipe(int fd) {
+    for (size_t i = 0; i < cmd_pipes.used; ++i) {
+        fdevent_cmd_pipe *fcp = cmd_pipes.ptr+i;
+        if (fcp->fds[1] != fd) continue;
+        fcp->fds[1] = STDERR_FILENO;
+        break;
+    }
+}
+
+
+static void fdevent_init_logger_pipe(const char *cmd, int fds[2], pid_t pid) {
+    fdevent_cmd_pipe *fcp;
+    if (cmd_pipes.used == cmd_pipes.size) {
+        cmd_pipes.size += 4;
+        cmd_pipes.ptr =
+          realloc(cmd_pipes.ptr, cmd_pipes.size * sizeof(fdevent_cmd_pipe));
+        force_assert(cmd_pipes.ptr);
+    }
+    fcp = cmd_pipes.ptr + cmd_pipes.used++;
+    fcp->cmd = cmd; /* note: cmd must persist in memory (or else copy here) */
+    fcp->fds[0] = fds[0];
+    fcp->fds[1] = fds[1];
+    fcp->pid = pid;
+    fcp->start = time(NULL);
+}
+
+
+static int fdevent_open_logger_pipe(const char *logger) {
+    int fds[2];
+    pid_t pid;
+    if (pipe(fds)) {
+        return -1;
+    }
+    fdevent_setfd_cloexec(fds[0]);
+    fdevent_setfd_cloexec(fds[1]);
+
+    pid = fdevent_open_logger_pipe_spawn(logger, fds[0]);
+
+    if (pid > 0) {
+        fdevent_init_logger_pipe(logger, fds, pid);
+        return fds[1];
+    }
+    else {
+        int errnum = errno;
+        close(fds[0]);
+        close(fds[1]);
         errno = errnum;
         return -1;
     }
diff --git a/src/fdevent.h b/src/fdevent.h
index bf9ba7c9..4caef9d9 100644
--- a/src/fdevent.h
+++ b/src/fdevent.h
@@ -225,6 +225,10 @@ int fdevent_set_stdin_stdout_stderr(int fdin, int fdout, int fderr);
 pid_t fdevent_fork_execve(const char *name, char *argv[], char *envp[], int fdin, int fdout, int fderr, int dfd);
 int fdevent_open_logger(const char *logger);
 int fdevent_cycle_logger(const char *logger, int *curfd);
+int fdevent_reaped_logger_pipe(pid_t pid);
+void fdevent_waitpid_logger_pipes(time_t ts);
+void fdevent_close_logger_pipes(void);
+void fdevent_breakagelog_logger_pipe(int fd);
 
 int fdevent_select_init(fdevents *ev);
 int fdevent_poll_init(fdevents *ev);
diff --git a/src/mod_accesslog.c b/src/mod_accesslog.c
index 309579ed..9e299397 100644
--- a/src/mod_accesslog.c
+++ b/src/mod_accesslog.c
@@ -445,7 +445,11 @@ FREE_FUNC(mod_accesslog_free) {
 				}
 			}
 
-			if (s->log_access_fd != -1) close(s->log_access_fd);
+			if (s->log_access_fd != -1) {
+				if (buffer_string_is_empty(s->access_logfile) || *s->access_logfile->ptr != '|') {
+					close(s->log_access_fd);
+				} /*(else piped loggers closed in fdevent_close_logger_pipes())*/
+			}
 
 			buffer_free(s->ts_accesslog_str);
 			buffer_free(s->access_logbuffer);
diff --git a/src/server.c b/src/server.c
index 18a71e4f..bad0b49d 100644
--- a/src/server.c
+++ b/src/server.c
@@ -843,6 +843,8 @@ static int log_error_open(server *srv) {
                             "' failed: ", strerror(errno));
             return -1;
         }
+
+        if (*logfile == '|') fdevent_breakagelog_logger_pipe(errfd);
     }
     else if (!srv->srvconf.dont_daemonize) {
         /* move STDERR_FILENO to /dev/null */
@@ -900,8 +902,11 @@ static int log_error_close(server *srv) {
     case ERRORLOG_FD:
         if (-1 != srv->errorlog_fd) {
             /* don't close STDERR */
-            if (STDERR_FILENO != srv->errorlog_fd)
+            /* fdevent_close_logger_pipes() closes ERRORLOG_PIPE */
+            if (STDERR_FILENO != srv->errorlog_fd
+                && srv->errorlog_mode != ERRORLOG_PIPE) {
                 close(srv->errorlog_fd);
+            }
             srv->errorlog_fd = -1;
         }
         break;
@@ -1598,6 +1603,11 @@ static int server_main (server * const srv, int argc, char **argv) {
 				int status;
 
 				if (-1 != (pid = wait(&status))) {
+					switch (fdevent_reaped_logger_pipe(pid)) {
+					  default: break;
+					  case -1: alarm(5); /* fall through */
+					  case  1: continue;
+					}
 					/** 
 					 * check if one of our workers went away
 					 */
@@ -1630,6 +1640,10 @@ static int server_main (server * const srv, int argc, char **argv) {
 								kill(0, SIGHUP);
 							}
 						}
+						if (handle_sig_alarm) {
+							handle_sig_alarm = 0;
+							fdevent_waitpid_logger_pipes(time(NULL));
+						}
 						break;
 					default:
 						break;
@@ -1844,6 +1858,8 @@ static int server_main (server * const srv, int argc, char **argv) {
 				for (i = 0; i < srv->config_context->used; ++i) {
 					srv->config_storage[i]->global_bytes_per_second_cnt = 0;
 				}
+				/* check piped-loggers and restart, unless shutting down */
+				if (!graceful_shutdown && !srv_shutdown && 0 == srv->srvconf.max_worker) fdevent_waitpid_logger_pipes(min_ts);
 				/* if graceful_shutdown, accelerate cleanup of recently completed request/responses */
 				if (graceful_shutdown && !srv_shutdown) server_graceful_shutdown_maint(srv);
 				/**
@@ -2095,6 +2111,7 @@ int main (int argc, char **argv) {
         /* clean-up */
         remove_pid_file(srv);
         log_error_close(srv);
+        fdevent_close_logger_pipes();
         if (graceful_restart)
             server_sockets_save(srv);
         else