Skip to content

FPM logger refactoring #2458

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 1 commit into from
Jul 7, 2018
Merged

FPM logger refactoring #2458

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
16 changes: 16 additions & 0 deletions sapi/fpm/fpm/fpm_conf.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -80,6 +80,8 @@ struct fpm_global_config_s fpm_global_config = {
.systemd_watchdog = 0,
.systemd_interval = -1, /* -1 means not set */
#endif
.log_buffering = ZLOG_DEFAULT_BUFFERING,
.log_limit = ZLOG_DEFAULT_LIMIT
};
static struct fpm_worker_pool_s *current_wp = NULL;
static int ini_recursion = 0;
Expand All @@ -97,7 +99,9 @@ static struct ini_value_parser_s ini_fpm_global_options[] = {
{ "syslog.ident", &fpm_conf_set_string, GO(syslog_ident) },
{ "syslog.facility", &fpm_conf_set_syslog_facility, GO(syslog_facility) },
#endif
{ "log_buffering", &fpm_conf_set_boolean, GO(log_buffering) },
{ "log_level", &fpm_conf_set_log_level, GO(log_level) },
{ "log_limit", &fpm_conf_set_integer, GO(log_limit) },
{ "emergency_restart_threshold", &fpm_conf_set_integer, GO(emergency_restart_threshold) },
{ "emergency_restart_interval", &fpm_conf_set_time, GO(emergency_restart_interval) },
{ "process_control_timeout", &fpm_conf_set_time, GO(process_control_timeout) },
Expand Down Expand Up @@ -153,6 +157,7 @@ static struct ini_value_parser_s ini_fpm_pool_options[] = {
{ "chroot", &fpm_conf_set_string, WPO(chroot) },
{ "chdir", &fpm_conf_set_string, WPO(chdir) },
{ "catch_workers_output", &fpm_conf_set_boolean, WPO(catch_workers_output) },
{ "decorate_workers_output", &fpm_conf_set_boolean, WPO(decorate_workers_output) },
{ "clear_env", &fpm_conf_set_boolean, WPO(clear_env) },
{ "security.limit_extensions", &fpm_conf_set_string, WPO(security_limit_extensions) },
#ifdef HAVE_APPARMOR
Expand Down Expand Up @@ -616,6 +621,7 @@ static void *fpm_worker_pool_config_alloc() /* {{{ */
wp->config->process_priority = 64; /* 64 means unset */
wp->config->process_dumpable = 0;
wp->config->clear_env = 1;
wp->config->decorate_workers_output = 1;

if (!fpm_worker_all_pools) {
fpm_worker_all_pools = wp;
Expand Down Expand Up @@ -1192,6 +1198,12 @@ static int fpm_conf_post_process(int force_daemon) /* {{{ */

fpm_globals.log_level = fpm_global_config.log_level;
zlog_set_level(fpm_globals.log_level);
if (fpm_global_config.log_limit < ZLOG_MIN_LIMIT) {
zlog(ZLOG_ERROR, "log_limit must be greater than %d", ZLOG_MIN_LIMIT);
return -1;
}
zlog_set_limit(fpm_global_config.log_limit);
zlog_set_buffering(fpm_global_config.log_buffering);

if (fpm_global_config.process_max < 0) {
zlog(ZLOG_ERROR, "process_max can't be negative");
Expand Down Expand Up @@ -1265,6 +1277,7 @@ static void fpm_conf_cleanup(int which, void *arg) /* {{{ */
free(fpm_global_config.events_mechanism);
fpm_global_config.pid_file = 0;
fpm_global_config.error_log = 0;
fpm_global_config.log_limit = ZLOG_DEFAULT_LIMIT;
#ifdef HAVE_SYSLOG_H
free(fpm_global_config.syslog_ident);
fpm_global_config.syslog_ident = 0;
Expand Down Expand Up @@ -1606,7 +1619,9 @@ static void fpm_conf_dump() /* {{{ */
zlog(ZLOG_NOTICE, "\tsyslog.ident = %s", STR2STR(fpm_global_config.syslog_ident));
zlog(ZLOG_NOTICE, "\tsyslog.facility = %d", fpm_global_config.syslog_facility); /* FIXME: convert to string */
#endif
zlog(ZLOG_NOTICE, "\tlog_buffering = %s", BOOL2STR(fpm_global_config.log_buffering));
zlog(ZLOG_NOTICE, "\tlog_level = %s", zlog_get_level_name(fpm_globals.log_level));
zlog(ZLOG_NOTICE, "\tlog_limit = %d", fpm_global_config.log_limit);
zlog(ZLOG_NOTICE, "\temergency_restart_interval = %ds", fpm_global_config.emergency_restart_interval);
zlog(ZLOG_NOTICE, "\temergency_restart_threshold = %d", fpm_global_config.emergency_restart_threshold);
zlog(ZLOG_NOTICE, "\tprocess_control_timeout = %ds", fpm_global_config.process_control_timeout);
Expand Down Expand Up @@ -1669,6 +1684,7 @@ static void fpm_conf_dump() /* {{{ */
zlog(ZLOG_NOTICE, "\tchroot = %s", STR2STR(wp->config->chroot));
zlog(ZLOG_NOTICE, "\tchdir = %s", STR2STR(wp->config->chdir));
zlog(ZLOG_NOTICE, "\tcatch_workers_output = %s", BOOL2STR(wp->config->catch_workers_output));
zlog(ZLOG_NOTICE, "\tdecorate_workers_output = %s", BOOL2STR(wp->config->decorate_workers_output));
zlog(ZLOG_NOTICE, "\tclear_env = %s", BOOL2STR(wp->config->clear_env));
zlog(ZLOG_NOTICE, "\tsecurity.limit_extensions = %s", wp->config->security_limit_extensions);

Expand Down
3 changes: 3 additions & 0 deletions sapi/fpm/fpm/fpm_conf.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -30,6 +30,8 @@ struct fpm_global_config_s {
int syslog_facility;
#endif
int log_level;
int log_limit;
int log_buffering;
int emergency_restart_threshold;
int emergency_restart_interval;
int process_control_timeout;
Expand Down Expand Up @@ -85,6 +87,7 @@ struct fpm_worker_pool_config_s {
char *chroot;
char *chdir;
int catch_workers_output;
int decorate_workers_output;
int clear_env;
char *security_limit_extensions;
struct key_value_s *env;
Expand Down
20 changes: 7 additions & 13 deletions sapi/fpm/fpm/fpm_main.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -637,21 +637,15 @@ void sapi_cgi_log_fastcgi(int level, char *message, size_t len)

fcgi_request *request = (fcgi_request*) SG(server_context);

/* ensure we want:
* - to log (fastcgi.logging in php.ini)
/* message is written to FCGI_STDERR if following conditions are met:
* - logging is enabled (fastcgi.logging in php.ini)
* - we are currently dealing with a request
* - the message is not empty
* - the fcgi_write did not fail
*/
if (CGIG(fcgi_logging) && request && message && len > 0) {
ssize_t ret;
char *buf = malloc(len + 2);
memcpy(buf, message, len);
memcpy(buf + len, "\n", sizeof("\n"));
ret = fcgi_write(request, FCGI_STDERR, buf, len + 1);
free(buf);
if (ret < 0) {
php_handle_aborted_connection();
}
if (CGIG(fcgi_logging) && request && message && len > 0
&& fcgi_write(request, FCGI_STDERR, message, len) < 0) {
php_handle_aborted_connection();
}
}
/* }}} */
Expand All @@ -660,7 +654,7 @@ void sapi_cgi_log_fastcgi(int level, char *message, size_t len)
*/
static void sapi_cgi_log_message(char *message, int syslog_type_int)
{
zlog(ZLOG_NOTICE, "PHP message: %s", message);
zlog_msg(ZLOG_NOTICE, "PHP message: ", message);
}
/* }}} */

Expand Down
69 changes: 36 additions & 33 deletions sapi/fpm/fpm/fpm_stdio.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -14,6 +14,7 @@

#include "fpm.h"
#include "fpm_children.h"
#include "fpm_cleanup.h"
#include "fpm_events.h"
#include "fpm_sockets.h"
#include "fpm_stdio.h"
Expand All @@ -22,6 +23,12 @@
static int fd_stdout[2];
static int fd_stderr[2];

static void fpm_stdio_cleanup(int which, void *arg) /* {{{ */
{
zlog_cleanup();
}
/* }}} */

int fpm_stdio_init_main() /* {{{ */
{
int fd = open("/dev/null", O_RDWR);
Expand All @@ -30,6 +37,9 @@ int fpm_stdio_init_main() /* {{{ */
zlog(ZLOG_SYSERROR, "failed to init stdio: open(\"/dev/null\")");
return -1;
}
if (0 > fpm_cleanup_add(FPM_CLEANUP_PARENT, fpm_stdio_cleanup, 0)) {
return -1;
}

if (0 > dup2(fd, STDIN_FILENO) || 0 > dup2(fd, STDOUT_FILENO)) {
zlog(ZLOG_SYSERROR, "failed to init stdio: dup2()");
Expand Down Expand Up @@ -115,21 +125,30 @@ static void fpm_stdio_child_said(struct fpm_event_s *ev, short which, void *arg)
int is_stdout;
struct fpm_event_s *event;
int fifo_in = 1, fifo_out = 1;
int is_last_message = 0;
int in_buf = 0;
int res;
struct zlog_stream stream;

if (!arg) {
return;
}
child = (struct fpm_child_s *)arg;

is_stdout = (fd == child->fd_stdout);
if (is_stdout) {
event = &child->ev_stdout;
} else {
event = &child->ev_stderr;
}

zlog_stream_init_ex(&stream, ZLOG_WARNING, STDERR_FILENO);
zlog_stream_set_decorating(&stream, child->wp->config->decorate_workers_output);
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);
Expand All @@ -144,7 +163,6 @@ static void fpm_stdio_child_said(struct fpm_event_s *ev, short which, void *arg)
}

fpm_event_del(event);
is_last_message = 1;

if (is_stdout) {
close(child->fd_stdout);
Expand All @@ -164,42 +182,27 @@ static void fpm_stdio_child_said(struct fpm_event_s *ev, short which, void *arg)
fifo_out = 0;
} else {
char *nl;
int should_print = 0;
buf[in_buf] = '\0';

/* FIXME: there might be binary data */

/* we should print if no more space in the buffer */
if (in_buf == max_buf_size - 1) {
should_print = 1;
}

/* we should print if no more data to come */
if (!fifo_in) {
should_print = 1;
}

nl = strchr(buf, '\n');
if (nl || should_print) {

if (nl) {
*nl = '\0';
}

zlog(ZLOG_WARNING, "[pool %s] child %d said into %s: \"%s\"%s", child->wp->config->name,
(int) child->pid, is_stdout ? "stdout" : "stderr", buf, is_last_message ? ", pipe is closed" : "");

if (nl) {
int out_buf = 1 + nl - buf;
memmove(buf, buf + out_buf, in_buf - out_buf);
in_buf -= out_buf;
} else {
in_buf = 0;
}
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(&stream, buf, out_len);
zlog_stream_finish(&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(&stream, buf, in_buf);
in_buf = 0;
}
}
}
}
zlog_stream_close(&stream);
}
/* }}} */

Expand Down
Loading