}
/* }}} */
+#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));
}
/* }}} */
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) {
}
}
- 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) {
close(child->fd_stderr);
child->fd_stderr = -1;
}
- } else if (finish_log_stream) {
- zlog_stream_finish(log_stream);
}
}
/* }}} */
--- /dev/null
+--TEST--
+FPM: Log message in shutdown function
+--SKIPIF--
+<?php include "skipif.inc"; ?>
+--FILE--
+<?php
+
+require_once "tester.inc";
+
+$cfg = <<<EOT
+[global]
+error_log = {{FILE:LOG}}
+log_limit = 1024
+log_buffering = yes
+[unconfined]
+listen = {{ADDR}}
+pm = dynamic
+pm.max_children = 5
+pm.start_servers = 1
+pm.min_spare_servers = 1
+pm.max_spare_servers = 3
+catch_workers_output = yes
+EOT;
+
+$code = <<<EOT
+<?php
+register_shutdown_function(function() {
+ error_log(str_repeat('e', 80));
+});
+EOT;
+
+$tester = new FPM\Tester($cfg, $code);
+$tester->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--
+<?php
+require_once "tester.inc";
+FPM\Tester::clean();
+?>
--- /dev/null
+--TEST--
+FPM: Buffered worker output plain log with msg with flush split in buffer
+--SKIPIF--
+<?php include "skipif.inc"; ?>
+--FILE--
+<?php
+
+require_once "tester.inc";
+
+$cfg = <<<EOT
+[global]
+error_log = {{FILE:LOG}}
+[unconfined]
+listen = {{ADDR}}
+pm = dynamic
+pm.max_children = 5
+pm.start_servers = 1
+pm.min_spare_servers = 1
+pm.max_spare_servers = 3
+catch_workers_output = yes
+decorate_workers_output = no
+EOT;
+
+$code = <<<EOT
+<?php
+file_put_contents('php://stderr', str_repeat('a', 1021) . "\0fabc");
+EOT;
+
+$tester = new FPM\Tester($cfg, $code);
+$tester->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--
+<?php
+require_once "tester.inc";
+FPM\Tester::clean();
+?>
--- /dev/null
+--TEST--
+FPM: Buffered worker output plain log with msg with flush split in buffer
+--SKIPIF--
+<?php include "skipif.inc"; ?>
+--FILE--
+<?php
+
+require_once "tester.inc";
+
+$cfg = <<<EOT
+[global]
+error_log = {{FILE:LOG}}
+[unconfined]
+listen = {{ADDR}}
+pm = dynamic
+pm.max_children = 5
+pm.start_servers = 1
+pm.min_spare_servers = 1
+pm.max_spare_servers = 3
+catch_workers_output = yes
+decorate_workers_output = no
+EOT;
+
+$code = <<<EOT
+<?php
+file_put_contents('php://stderr', str_repeat('a', 1022) . "\0fscf\0");
+EOT;
+
+$tester = new FPM\Tester($cfg, $code);
+$tester->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--
+<?php
+require_once "tester.inc";
+FPM\Tester::clean();
+?>