From 0bc6a66a7a0624e63edcd2499f91b227cdb77f47 Mon Sep 17 00:00:00 2001 From: Jakub Zelenka Date: Sun, 9 Feb 2020 19:40:25 +0000 Subject: [PATCH] Fix bug #77653 (operator displayed instead of the real error message) --- NEWS | 4 + sapi/fpm/fpm/fpm_main.c | 3 + sapi/fpm/fpm/fpm_request.c | 2 - sapi/fpm/fpm/fpm_stdio.c | 90 ++++++++++--------- sapi/fpm/fpm/zlog.c | 8 +- sapi/fpm/tests/log-bm-in-shutdown-fn.phpt | 49 ++++++++++ .../log-bwp-msg-flush-split-fallback.phpt | 49 ++++++++++ .../tests/log-bwp-msg-flush-split-real.phpt | 46 ++++++++++ 8 files changed, 202 insertions(+), 49 deletions(-) create mode 100644 sapi/fpm/tests/log-bm-in-shutdown-fn.phpt create mode 100644 sapi/fpm/tests/log-bwp-msg-flush-split-fallback.phpt create mode 100644 sapi/fpm/tests/log-bwp-msg-flush-split-real.phpt diff --git a/NEWS b/NEWS index 56d1b12f93..7a1fdd32b9 100644 --- a/NEWS +++ b/NEWS @@ -22,6 +22,10 @@ PHP NEWS cmb) . Fixed bug #79271 (DOMDocumentType::$childNodes is NULL). (cmb) +- FPM: + . Fixed bug #77653 (operator displayed instead of the real error message). + (Jakub Zelenka) + - PCRE: . Fixed bug #79188 (Memory corruption in preg_replace/preg_replace_callback and unicode). (Nikita) diff --git a/sapi/fpm/fpm/fpm_main.c b/sapi/fpm/fpm/fpm_main.c index bc3c145ca0..b4daa4e4ca 100644 --- a/sapi/fpm/fpm/fpm_main.c +++ b/sapi/fpm/fpm/fpm_main.c @@ -87,6 +87,7 @@ int __riscosify_control = __RISCOSIFY_STRICT_UNIX_SPECS; #include "fpm_request.h" #include "fpm_status.h" #include "fpm_signals.h" +#include "fpm_stdio.h" #include "fpm_conf.h" #include "fpm_php.h" #include "fpm_log.h" @@ -1968,6 +1969,8 @@ fastcgi_request_done: php_request_shutdown((void *) 0); + fpm_stdio_flush_child(); + requests++; if (UNEXPECTED(max_requests && (requests == max_requests))) { fcgi_request_set_keep(request, 0); diff --git a/sapi/fpm/fpm/fpm_request.c b/sapi/fpm/fpm/fpm_request.c index e480256a01..c80aa14462 100644 --- a/sapi/fpm/fpm/fpm_request.c +++ b/sapi/fpm/fpm/fpm_request.c @@ -16,7 +16,6 @@ #include "fpm_children.h" #include "fpm_scoreboard.h" #include "fpm_status.h" -#include "fpm_stdio.h" #include "fpm_request.h" #include "fpm_log.h" @@ -200,7 +199,6 @@ void fpm_request_end(void) /* {{{ */ #endif proc->memory = memory; fpm_scoreboard_proc_release(proc); - fpm_stdio_flush_child(); } /* }}} */ diff --git a/sapi/fpm/fpm/fpm_stdio.c b/sapi/fpm/fpm/fpm_stdio.c index fde9c9144c..ddedfb48c7 100644 --- a/sapi/fpm/fpm/fpm_stdio.c +++ b/sapi/fpm/fpm/fpm_stdio.c @@ -106,9 +106,11 @@ int fpm_stdio_init_child(struct fpm_worker_pool_s *wp) /* {{{ */ } /* }}} */ +#define FPM_STDIO_CMD_FLUSH "\0fscf" + int fpm_stdio_flush_child() /* {{{ */ { - return write(STDERR_FILENO, "\0", 1); + return write(STDERR_FILENO, FPM_STDIO_CMD_FLUSH, sizeof(FPM_STDIO_CMD_FLUSH)); } /* }}} */ @@ -120,10 +122,8 @@ static void fpm_stdio_child_said(struct fpm_event_s *ev, short which, void *arg) struct fpm_child_s *child; int is_stdout; struct fpm_event_s *event; - int fifo_in = 1, fifo_out = 1; - int in_buf = 0; - int read_fail = 0, finish_log_stream = 0, create_log_stream; - int res; + int in_buf = 0, cmd_pos = 0, pos, start; + int read_fail = 0, create_log_stream; struct zlog_stream *log_stream; if (!arg) { @@ -162,49 +162,53 @@ static void fpm_stdio_child_said(struct fpm_event_s *ev, short which, void *arg) } } - 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)) { - /* pipe is closed or error */ - read_fail = (res < 0) ? res : 1; - } - } else { - in_buf += res; - /* if buffer ends with \0, then the stream will be finished */ - if (!buf[in_buf - 1]) { - finish_log_stream = 1; - in_buf--; - } + while (1) { +stdio_read: + in_buf = read(fd, buf, max_buf_size - 1); + if (in_buf <= 0) { /* no data */ + if (in_buf == 0 || (errno != EAGAIN && errno != EWOULDBLOCK)) { + /* pipe is closed or error */ + read_fail = (in_buf < 0) ? in_buf : 1; } + break; } - - if (fifo_out) { - if (in_buf == 0) { - fifo_out = 0; + start = 0; + if (cmd_pos > 0) { + if ((sizeof(FPM_STDIO_CMD_FLUSH) - cmd_pos) <= in_buf && + !memcmp(buf, &FPM_STDIO_CMD_FLUSH[cmd_pos], sizeof(FPM_STDIO_CMD_FLUSH) - cmd_pos)) { + zlog_stream_finish(log_stream); + start = cmd_pos; } else { - char *nl; - - nl = memchr(buf, '\n', in_buf); - if (nl) { - /* we should print each new line int the new message */ - int out_len = nl - buf; - zlog_stream_str(log_stream, buf, out_len); + zlog_stream_str(log_stream, &FPM_STDIO_CMD_FLUSH[0], cmd_pos); + } + cmd_pos = 0; + } + for (pos = start; pos < in_buf; pos++) { + switch (buf[pos]) { + case '\n': + zlog_stream_str(log_stream, buf + start, pos - start); zlog_stream_finish(log_stream); - /* skip new line */ - out_len++; - /* move data in the buffer */ - memmove(buf, buf + out_len, in_buf - out_len); - in_buf -= out_len; - } else if (in_buf == max_buf_size - 1 || !fifo_in) { - /* we should print if no more space in the buffer or no more data to come */ - zlog_stream_str(log_stream, buf, in_buf); - in_buf = 0; - } + start = pos + 1; + break; + case '\0': + if (pos + sizeof(FPM_STDIO_CMD_FLUSH) <= in_buf) { + if (!memcmp(buf + pos, FPM_STDIO_CMD_FLUSH, sizeof(FPM_STDIO_CMD_FLUSH))) { + zlog_stream_str(log_stream, buf + start, pos - start); + zlog_stream_finish(log_stream); + start = pos + sizeof(FPM_STDIO_CMD_FLUSH); + pos = start - 1; + } + } else if (!memcmp(buf + pos, FPM_STDIO_CMD_FLUSH, in_buf - pos)) { + cmd_pos = in_buf - pos; + zlog_stream_str(log_stream, buf + start, pos - start); + goto stdio_read; + } + break; } } + if (start < pos) { + zlog_stream_str(log_stream, buf + start, pos - start); + } } if (read_fail) { @@ -225,8 +229,6 @@ static void fpm_stdio_child_said(struct fpm_event_s *ev, short which, void *arg) close(child->fd_stderr); child->fd_stderr = -1; } - } else if (finish_log_stream) { - zlog_stream_finish(log_stream); } } /* }}} */ diff --git a/sapi/fpm/fpm/zlog.c b/sapi/fpm/fpm/zlog.c index ddfed2aef9..db2f0db447 100644 --- a/sapi/fpm/fpm/zlog.c +++ b/sapi/fpm/fpm/zlog.c @@ -734,14 +734,16 @@ ssize_t zlog_stream_format(struct zlog_stream *stream, const char *fmt, ...) /* ssize_t zlog_stream_str(struct zlog_stream *stream, const char *str, size_t str_len) /* {{{ */ { + /* do not write anything if the stream is full or str is empty */ + if (str_len == 0 || stream->full) { + return 0; + } + /* reset stream if it is finished */ if (stream->finished) { stream->finished = 0; stream->len = 0; stream->full = 0; - } else if (stream->full) { - /* do not write anything if the stream is full */ - return 0; } if (stream->use_buffer) { diff --git a/sapi/fpm/tests/log-bm-in-shutdown-fn.phpt b/sapi/fpm/tests/log-bm-in-shutdown-fn.phpt new file mode 100644 index 0000000000..f968bf9f08 --- /dev/null +++ b/sapi/fpm/tests/log-bm-in-shutdown-fn.phpt @@ -0,0 +1,49 @@ +--TEST-- +FPM: Log message in shutdown function +--SKIPIF-- + +--FILE-- +start(); +$tester->expectLogStartNotices(); +$tester->request()->expectEmptyBody(); +$tester->terminate(); +$tester->expectFastCGIErrorMessage('e', 1050, 80); +$tester->expectLogMessage('NOTICE: PHP message: ' . str_repeat('e', 80), 1050); +$tester->close(); + +?> +Done +--EXPECT-- +Done +--CLEAN-- + diff --git a/sapi/fpm/tests/log-bwp-msg-flush-split-fallback.phpt b/sapi/fpm/tests/log-bwp-msg-flush-split-fallback.phpt new file mode 100644 index 0000000000..0c152619a9 --- /dev/null +++ b/sapi/fpm/tests/log-bwp-msg-flush-split-fallback.phpt @@ -0,0 +1,49 @@ +--TEST-- +FPM: Buffered worker output plain log with msg with flush split in buffer +--SKIPIF-- + +--FILE-- +start(); +$tester->expectLogStartNotices(); +$tester->request()->expectEmptyBody(); +$tester->terminate(); +$lines = $tester->getLogLines(2); +var_dump($lines[0] === str_repeat('a', 1021) . "\0f\n"); +var_dump($lines[1] === "abc\n"); +$tester->close(); + +?> +Done +--EXPECT-- +bool(true) +bool(true) +Done +--CLEAN-- + diff --git a/sapi/fpm/tests/log-bwp-msg-flush-split-real.phpt b/sapi/fpm/tests/log-bwp-msg-flush-split-real.phpt new file mode 100644 index 0000000000..63b2555de7 --- /dev/null +++ b/sapi/fpm/tests/log-bwp-msg-flush-split-real.phpt @@ -0,0 +1,46 @@ +--TEST-- +FPM: Buffered worker output plain log with msg with flush split in buffer +--SKIPIF-- + +--FILE-- +start(); +$tester->expectLogStartNotices(); +$tester->request()->expectEmptyBody(); +$tester->terminate(); +var_dump($tester->getLastLogLine() === str_repeat('a', 1022) . "\n"); +$tester->close(); + +?> +Done +--EXPECT-- +bool(true) +Done +--CLEAN-- + -- 2.49.0