Fix FPM logging when log pipe is closed

Author: bukka

sapi/fpm/fpm/fpm_stdio.c

@@ -126,6 +126,7 @@ static void fpm_stdio_child_said(struct fpm_event_s *ev, short which, void *arg)
 	struct fpm_event_s *event;
 	int fifo_in = 1, fifo_out = 1;
 	int in_buf = 0;
+	int read_fail = 0;
 	int res;
 	struct zlog_stream stream;
 
@@ -146,31 +147,16 @@ static void fpm_stdio_child_said(struct fpm_event_s *ev, short which, void *arg)
 	zlog_stream_set_wrapping(&stream, ZLOG_TRUE);
 	zlog_stream_set_msg_prefix(&stream, "[pool %s] child %d said into %s: ",
 			child->wp->config->name, (int) child->pid, is_stdout ? "stdout" : "stderr");
-	zlog_stream_set_msg_suffix(&stream, NULL, ", pipe is closed");
 	zlog_stream_set_msg_quoting(&stream, ZLOG_TRUE);
 
 	while (fifo_in || fifo_out) {
 		if (fifo_in) {
 			res = read(fd, buf + in_buf, max_buf_size - 1 - in_buf);
 			if (res <= 0) { /* no data */
 				fifo_in = 0;
-				if (res < 0 && (errno == EAGAIN || errno == EWOULDBLOCK)) {
-					/* just no more data ready */
-				} else { /* error or pipe is closed */
-
-					if (res < 0) { /* error */
-						zlog(ZLOG_SYSERROR, "unable to read what child say");
-					}
-
-					fpm_event_del(event);
-
-					if (is_stdout) {
-						close(child->fd_stdout);
-						child->fd_stdout = -1;
-					} else {
-						close(child->fd_stderr);
-						child->fd_stderr = -1;
-					}
+				if (res == 0 || (errno != EAGAIN && errno != EWOULDBLOCK)) {
+					/* pipe is closed or error */
+					read_fail = (res < 0) ? res : 1;
 				}
 			} else {
 				in_buf += res;
@@ -202,7 +188,26 @@ static void fpm_stdio_child_said(struct fpm_event_s *ev, short which, void *arg)
 			}
 		}
 	}
-	zlog_stream_close(&stream);
+
+	if (read_fail) {
+		zlog_stream_set_msg_suffix(&stream, NULL, ", pipe is closed");
+		zlog_stream_close(&stream);
+		if (read_fail < 0) {
+			zlog(ZLOG_SYSERROR, "unable to read what child say");
+		}
+
+		fpm_event_del(event);
+
+		if (is_stdout) {
+			close(child->fd_stdout);
+			child->fd_stdout = -1;
+		} else {
+			close(child->fd_stderr);
+			child->fd_stderr = -1;
+		}
+	} else {
+		zlog_stream_close(&stream);
+	}
 }
 /* }}} */
 
@@ -292,7 +297,7 @@ int fpm_stdio_open_error_log(int reopen) /* {{{ */
 
 #ifdef HAVE_SYSLOG_H
 	if (!strcasecmp(fpm_global_config.error_log, "syslog")) {
-		php_openlog(fpm_global_config.syslog_ident, LOG_PID | LOG_CONS, fpm_global_config.syslog_facility);
+		openlog(fpm_global_config.syslog_ident, LOG_PID | LOG_CONS, fpm_global_config.syslog_facility);
 		fpm_globals.error_log_fd = ZLOG_SYSLOG;
 		if (fpm_use_error_log()) {
 			zlog_set_fd(fpm_globals.error_log_fd);

sapi/fpm/fpm/zlog.c

@@ -633,6 +633,9 @@ zlog_bool zlog_stream_set_msg_suffix(
 		stream->msg_suffix_len = strlen(suffix);
 		stream->msg_final_suffix_len = strlen(final_suffix);
 		len = stream->msg_suffix_len + stream->msg_final_suffix_len + 2;
+		if (stream->msg_suffix != NULL) {
+			free(stream->msg_suffix);
+		}
 		stream->msg_suffix = malloc(len);
 		if (stream->msg_suffix == NULL) {
 			return ZLOG_FALSE;
@@ -646,6 +649,9 @@ zlog_bool zlog_stream_set_msg_suffix(
 		stream->msg_suffix_len = strlen(suffix);
 		len = stream->msg_suffix_len + 1;
 		stream->msg_suffix = malloc(len);
+		if (stream->msg_suffix != NULL) {
+			free(stream->msg_suffix);
+		}
 		if (stream->msg_suffix == NULL) {
 			return ZLOG_FALSE;
 		}
@@ -656,6 +662,9 @@ zlog_bool zlog_stream_set_msg_suffix(
 		stream->msg_final_suffix_len = strlen(final_suffix);
 		len = stream->msg_final_suffix_len + 1;
 		stream->msg_final_suffix = malloc(len);
+		if (stream->msg_final_suffix != NULL) {
+			free(stream->msg_suffix);
+		}
 		if (stream->msg_final_suffix == NULL) {
 			return ZLOG_FALSE;
 		}

sapi/fpm/tests/logtool.inc

@@ -43,6 +43,11 @@ class LogTool
      */
     private $error;
 
+    /**
+     * @var bool
+     */
+    private $pipeClosed = false;
+
     /**
      * @param string $message
      * @param int $limit
@@ -72,6 +77,14 @@ class LogTool
         return $this->level ?: 'WARNING';
     }
 
+    /**
+     * @param bool $pipeClosed
+     */
+    public function setPipeClosed(bool $pipeClosed)
+    {
+        $this->pipeClosed = $pipeClosed;
+    }
+
     /**
      * @param string $line
      * @return bool
@@ -205,13 +218,13 @@ class LogTool
         if ($rem !== $outLen)  {
             return $this->error("Printed more than the message len");
         }
-        if ($finalSuffix === null) {
+        if (!$this->pipeClosed || $finalSuffix === null) {
             return false;
         }
         if ($finalSuffix === false) {
             return $this->error("No final suffix");
         }
-        if (strpos(self::FINAL_SUFFIX, $finalSuffix) === false) {
+        if (empty($finalSuffix) || strpos(self::FINAL_SUFFIX, $finalSuffix) === false) {
             return $this->error("The final suffix has to be equal to ', pipe is closed'");
         }
         if (self::FINAL_SUFFIX !== $finalSuffix) {