- Added custom access log (also added per request %CPU and memory mesurement)

This commit is contained in:
Jérôme Loyet 2011-06-23 08:03:52 +00:00
parent 12081f5659
commit bbe8518456
23 changed files with 746 additions and 12 deletions

2
NEWS
View File

@ -178,6 +178,8 @@ PHP NEWS
. Added master rlimit_files and rlimit_core in the global configuration
settings. (fat)
. Removed pid in debug logs written by chrildren processes. (fat)
. Added custom access log (also added per request %CPU and memory
mesurement). (fat)
- Reflection extension:
. Fixed bug #54347 (reflection_extension does not lowercase module function

View File

@ -340,6 +340,33 @@ AC_DEFUN([AC_FPM_LQ],
])
dnl }}}
AC_DEFUN([AC_FPM_SYSCONF],
[
AC_MSG_CHECKING([for sysconf])
AC_TRY_COMPILE([ #include <unistd.h> ], [sysconf(_SC_CLK_TCK);], [
AC_DEFINE([HAVE_SYSCONF], 1, [do we have sysconf?])
AC_MSG_RESULT([yes])
], [
AC_MSG_RESULT([no])
])
])
dnl }}}
AC_DEFUN([AC_FPM_TIMES],
[
AC_MSG_CHECKING([for times])
AC_TRY_COMPILE([ #include <sys/times.h> ], [struct tms t; times(&t);], [
AC_DEFINE([HAVE_TIMES], 1, [do we have times?])
AC_MSG_RESULT([yes])
], [
AC_MSG_RESULT([no])
])
])
dnl }}}
AC_MSG_CHECKING(for FPM build)
if test "$PHP_FPM" != "no"; then
AC_MSG_RESULT($PHP_FPM)
@ -350,6 +377,8 @@ if test "$PHP_FPM" != "no"; then
AC_FPM_TRACE
AC_FPM_BUILTIN_ATOMIC
AC_FPM_LQ
AC_FPM_SYSCONF
AC_FPM_TIMES
PHP_ARG_WITH(fpm-user,,
[ --with-fpm-user[=USER] Set the user for php-fpm to run as. (default: nobody)], nobody, no)
@ -403,6 +432,7 @@ if test "$PHP_FPM" != "no"; then
fpm/fpm_conf.c \
fpm/fpm_env.c \
fpm/fpm_events.c \
fpm/fpm_log.c \
fpm/fpm_main.c \
fpm/fpm_php.c \
fpm/fpm_php_trace.c \

View File

@ -149,6 +149,8 @@ static int is_fastcgi = 0;
static int in_shutdown = 0;
static in_addr_t *allowed_clients = NULL;
static sa_t client_sa;
#ifdef _WIN32
static DWORD WINAPI fcgi_shutdown_thread(LPVOID arg)
@ -833,7 +835,9 @@ int fcgi_accept_request(fcgi_request *req)
FCGI_LOCK(req->listen_socket);
req->fd = accept(listen_socket, (struct sockaddr *)&sa, &len);
FCGI_UNLOCK(req->listen_socket);
if (req->fd >= 0 && allowed_clients) {
client_sa = sa;
if (sa.sa.sa_family == AF_INET && req->fd >= 0 && allowed_clients) {
int n = 0;
int allowed = 0;
@ -1118,6 +1122,14 @@ void fcgi_free_mgmt_var_cb(void * ptr)
pefree(*var, 1);
}
char *fcgi_get_last_client_ip() /* {{{ */
{
if (client_sa.sa.sa_family == AF_UNIX) {
return NULL;
}
return inet_ntoa(client_sa.sa_inet.sin_addr);
}
/* }}} */
/*
* Local variables:
* tab-width: 4

View File

@ -135,6 +135,8 @@ int fcgi_flush(fcgi_request *req, int close);
void fcgi_set_mgmt_var(const char * name, size_t name_len, const char * value, size_t value_len);
void fcgi_free_mgmt_var_cb(void * ptr);
char *fcgi_get_last_client_ip();
/*
* Local variables:
* tab-width: 4

View File

@ -19,6 +19,7 @@
#include "fpm_conf.h"
#include "fpm_worker_pool.h"
#include "fpm_stdio.h"
#include "fpm_log.h"
#include "zlog.h"
struct fpm_globals_s fpm_globals = {
@ -45,8 +46,9 @@ int fpm_init(int argc, char **argv, char *config, char *prefix, int test_conf) /
}
fpm_globals.prefix = prefix;
if (0 > fpm_php_init_main() ||
if (0 > fpm_php_init_main() ||
0 > fpm_stdio_init_main() ||
0 > fpm_log_init_main() ||
0 > fpm_conf_init_main(test_conf) ||
0 > fpm_unix_init_main() ||
0 > fpm_pctl_init_main() ||

View File

@ -27,6 +27,7 @@
#include "fpm_env.h"
#include "fpm_shm_slots.h"
#include "fpm_status.h"
#include "fpm_log.h"
#include "zlog.h"
@ -146,6 +147,7 @@ static void fpm_child_init(struct fpm_worker_pool_s *wp) /* {{{ */
fpm_globals.max_requests = wp->config->pm_max_requests;
if (0 > fpm_stdio_init_child(wp) ||
0 > fpm_log_init_child(wp) ||
0 > fpm_status_init_child(wp) ||
0 > fpm_unix_init_child(wp) ||
0 > fpm_signals_init_child() ||

View File

@ -41,6 +41,7 @@
#include "fpm_sockets.h"
#include "fpm_shm.h"
#include "fpm_status.h"
#include "fpm_log.h"
#include "zlog.h"
static int fpm_conf_load_ini_file(char *filename TSRMLS_DC);
@ -102,6 +103,8 @@ static struct ini_value_parser_s ini_fpm_pool_options[] = {
{ "pm.status_path", &fpm_conf_set_string, WPO(pm_status_path) },
{ "ping.path", &fpm_conf_set_string, WPO(ping_path) },
{ "ping.response", &fpm_conf_set_string, WPO(ping_response) },
{ "access.log", &fpm_conf_set_string, WPO(access_log) },
{ "access.format", &fpm_conf_set_string, WPO(access_format) },
{ 0, 0, 0 }
};
@ -414,6 +417,8 @@ int fpm_worker_pool_config_free(struct fpm_worker_pool_config_s *wpc) /* {{{ */
free(wpc->chdir);
free(wpc->slowlog);
free(wpc->prefix);
free(wpc->access_log);
free(wpc->access_format);
return 0;
}
@ -663,6 +668,13 @@ static int fpm_conf_process_all_pools() /* {{{ */
/* memset(&fpm_status.last_update, 0, sizeof(fpm_status.last_update)); */
}
if (wp->config->access_log && *wp->config->access_log) {
fpm_evaluate_full_path(&wp->config->access_log, wp, NULL, 0);
if (!wp->config->access_format) {
wp->config->access_format = strdup("%R - %u %t \"%m %r\" %s");
}
}
if (wp->config->chroot && *wp->config->chroot) {
fpm_evaluate_full_path(&wp->config->chroot, wp, NULL, 1);
@ -770,8 +782,10 @@ int fpm_conf_write_pid() /* {{{ */
}
/* }}} */
static int fpm_conf_post_process() /* {{{ */
static int fpm_conf_post_process(TSRMLS_D) /* {{{ */
{
struct fpm_worker_pool_s *wp;
if (fpm_global_config.pid_file) {
fpm_evaluate_full_path(&fpm_global_config.pid_file, NULL, PHP_LOCALSTATEDIR, 0);
}
@ -786,7 +800,25 @@ static int fpm_conf_post_process() /* {{{ */
return -1;
}
return fpm_conf_process_all_pools();
if (0 > fpm_log_open(0)) {
return -1;
}
if (0 > fpm_conf_process_all_pools()) {
return -1;
}
for (wp = fpm_worker_all_pools; wp; wp = wp->next) {
if (!wp->config->access_log || !*wp->config->access_log) {
continue;
}
if (0 > fpm_log_write(wp->config->access_format TSRMLS_CC)) {
zlog(ZLOG_ERROR, "[pool %s] wrong format for access.format '%s'", wp->config->name, wp->config->access_format);
return -1;
}
}
return 0;
}
/* }}} */
@ -1147,6 +1179,8 @@ static void fpm_conf_dump() /* {{{ */
zlog(ZLOG_NOTICE, "\tpm.status_path = %s", STR2STR(wp->config->pm_status_path));
zlog(ZLOG_NOTICE, "\tping.path = %s", STR2STR(wp->config->ping_path));
zlog(ZLOG_NOTICE, "\tping.response = %s", STR2STR(wp->config->ping_response));
zlog(ZLOG_NOTICE, "\taccess.log = %s", STR2STR(wp->config->access_log));
zlog(ZLOG_NOTICE, "\taccess.format = %s", STR2STR(wp->config->access_format));
zlog(ZLOG_NOTICE, "\tcatch_workers_output = %s", BOOL2STR(wp->config->catch_workers_output));
zlog(ZLOG_NOTICE, "\trequest_terminate_timeout = %ds", wp->config->request_terminate_timeout);
zlog(ZLOG_NOTICE, "\trequest_slowlog_timeout = %ds", wp->config->request_slowlog_timeout);
@ -1212,7 +1246,7 @@ int fpm_conf_init_main(int test_conf) /* {{{ */
return -1;
}
if (0 > fpm_conf_post_process()) {
if (0 > fpm_conf_post_process(TSRMLS_C)) {
zlog(ZLOG_ERROR, "failed to post process the configuration");
return -1;
}

View File

@ -57,6 +57,8 @@ struct fpm_worker_pool_config_s {
int pm_max_spare_servers;
char *ping_path;
char *ping_response;
char *access_log;
char *access_format;
char *listen_address;
int listen_backlog;
char *listen_owner;

View File

@ -21,6 +21,7 @@
#include "fpm_children.h"
#include "zlog.h"
#include "fpm_clock.h"
#include "fpm_log.h"
#define fpm_event_set_timeout(ev, now) timeradd(&(now), &(ev)->frequency, &(ev)->timeout);
@ -55,8 +56,8 @@ static void fpm_event_cleanup(int which, void *arg) /* {{{ */
static void fpm_got_signal(struct fpm_event_s *ev, short which, void *arg) /* {{{ */
{
char c;
int res;
int fd = ev->fd;;
int res, ret;
int fd = ev->fd;
do {
do {
@ -93,10 +94,19 @@ static void fpm_got_signal(struct fpm_event_s *ev, short which, void *arg) /* {{
case '1' : /* SIGUSR1 */
zlog(ZLOG_DEBUG, "received SIGUSR1");
if (0 == fpm_stdio_open_error_log(1)) {
zlog(ZLOG_NOTICE, "log file re-opened");
zlog(ZLOG_NOTICE, "error log file re-opened");
} else {
zlog(ZLOG_ERROR, "unable to re-opened log file");
zlog(ZLOG_ERROR, "unable to re-opened error log file");
}
ret = fpm_log_open(1);
if (ret == 0) {
zlog(ZLOG_NOTICE, "access log file re-opened");
} else if (ret == -1) {
zlog(ZLOG_ERROR, "unable to re-opened access log file");
}
/* else no access log are set */
break;
case '2' : /* SIGUSR2 */
zlog(ZLOG_DEBUG, "received SIGUSR2");

493
sapi/fpm/fpm/fpm_log.c Normal file
View File

@ -0,0 +1,493 @@
/* $Id: fpm_status.c 312262 2011-06-18 17:41:56Z felipe $ */
/* (c) 2009 Jerome Loyet */
#include "php.h"
#include "SAPI.h"
#include <stdio.h>
#include <unistd.h>
#include <fcntl.h>
#ifdef HAVE_TIMES
#include <sys/times.h>
#endif
#include "fpm_config.h"
#include "fpm_log.h"
#include "fpm_clock.h"
#include "fpm_process_ctl.h"
#include "fpm_signals.h"
#include "fpm_shm_slots.h"
#include "fastcgi.h"
#include "zlog.h"
#ifdef MAX_LINE_LENGTH
# define FPM_LOG_BUFFER MAX_LINE_LENGTH
#else
# define FPM_LOG_BUFFER 1024
#endif
static char *fpm_log_format = NULL;
static char *fpm_log_pool = NULL;
static int fpm_log_fd = -1;
#ifdef HAVE_TIMES
static float tick;
#endif
int fpm_log_open(int reopen) /* {{{ */
{
struct fpm_worker_pool_s *wp;
int ret = 1;
int fd;
for (wp = fpm_worker_all_pools; wp; wp = wp->next) {
if (!wp->config->access_log) {
continue;
}
ret = 0;
fd = open(wp->config->access_log, O_WRONLY | O_APPEND | O_CREAT, S_IRUSR | S_IWUSR);
if (0 > fd) {
zlog(ZLOG_SYSERROR, "open(\"%s\") failed", wp->config->access_log);
return -1;
}
if (reopen) {
dup2(fd, wp->log_fd);
close(fd);
fd = wp->log_fd;
fpm_pctl_kill_all(SIGQUIT);
} else {
wp->log_fd = fd;
}
fcntl(fd, F_SETFD, fcntl(fd, F_GETFD) | FD_CLOEXEC);
}
return ret;
}
/* }}} */
int fpm_log_init_main() /* {{{ */
{
#ifdef HAVE_TIMES
#if (defined(HAVE_SYSCONF) && defined(_SC_CLK_TCK))
tick = sysconf(_SC_CLK_TCK);
#else /* _SC_CLK_TCK */
#ifdef HZ
tick = HZ;
#else /* HZ */
tick = 100;
#endif /* HZ */
#endif /* _SC_CLK_TCK */
zlog(ZLOG_DEBUG, "got clock tick '%.0f'", tick);
#endif /* HAVE_TIMES */
return 0;
}
/* }}} */
/* }}} */
int fpm_log_init_child(struct fpm_worker_pool_s *wp) /* {{{ */
{
if (!wp || !wp->config) {
return -1;
}
if (wp->config->access_log && *wp->config->access_log) {
if (wp->config->access_format) {
fpm_log_format = strdup(wp->config->access_format);
}
}
if (wp->config->name) {
fpm_log_pool = strdup(wp->config->name);
}
if (fpm_log_fd == -1) {
fpm_log_fd = wp->log_fd;
}
for (wp = fpm_worker_all_pools; wp; wp = wp->next) {
if (wp->log_fd > -1 && wp->log_fd != fpm_log_fd) {
close(wp->log_fd);
wp->log_fd = -1;
}
}
return 0;
}
/* }}} */
int fpm_log_write(char *log_format TSRMLS_DC) /* {{{ */
{
char *s, *b;
char buffer[FPM_LOG_BUFFER];
int token, test;
size_t len, len2;
// fcgi_request *request = (fcgi_request*) SG(server_context);
struct fpm_shm_slot_s slot, *slot_p;
struct timeval uptime, now;
char tmp[129];
char format[129];
time_t now_epoch;
#ifdef HAVE_TIMES
clock_t tms_total;
#endif
if (!log_format && (!fpm_log_format || fpm_log_fd == -1)) {
return -1;
}
if (!log_format) {
log_format = fpm_log_format;
test = 0;
} else {
test = 1;
}
fpm_clock_get(&now);
now_epoch = time(NULL);
if (!test) {
slot_p = fpm_shm_slots_acquire(0, 0);
if (!slot_p) {
zlog(ZLOG_WARNING, "Unable to acquire shm slot");
return -1;
}
slot = *slot_p;
fpm_shm_slots_release(slot_p);
timersub(&now, &slot.accepted, &uptime);
}
token = 0;
memset(buffer, '\0', sizeof(buffer));
b = buffer;
len = 0;
s = log_format;
while (*s != '\0') {
if (len > FPM_LOG_BUFFER) {
zlog(ZLOG_NOTICE, "the log buffer is full (%d). The log request has been truncated.", FPM_LOG_BUFFER);
len = FPM_LOG_BUFFER - 1;
break;
}
if (!token && *s == '%') {
token = 1;
memset(format, '\0', sizeof(format)); /* reset format */
s++;
continue;
}
if (token) {
token = 0;
len2 = 0;
switch (*s) {
case '%': /* '%' */
*b = '%';
len2 = 1;
break;
#ifdef HAVE_TIMES
case 'C': /* %CPU */
if (format[0] == '\0' || !strcasecmp(format, "total")) {
if (!test) {
tms_total =
(slot.cpu_finished.tms_utime + slot.cpu_finished.tms_stime + slot.cpu_finished.tms_cutime + slot.cpu_finished.tms_cstime)
-
(slot.cpu_accepted.tms_utime + slot.cpu_accepted.tms_stime + slot.cpu_accepted.tms_cutime + slot.cpu_accepted.tms_cstime)
;
}
} else if (!strcasecmp(format, "user")) {
if (!test) {
tms_total = (slot.cpu_finished.tms_utime + slot.cpu_finished.tms_cutime) - (slot.cpu_accepted.tms_utime + slot.cpu_accepted.tms_cutime);
}
} else if (!strcasecmp(format, "system")) {
if (!test) {
tms_total = (slot.cpu_finished.tms_stime + slot.cpu_finished.tms_cstime) - (slot.cpu_accepted.tms_stime + slot.cpu_accepted.tms_cstime);
}
} else {
zlog(ZLOG_WARNING, "only 'total', 'user' or 'system' are allowed as a modifier for %%%c ('%s')", *s, format);
return -1;
}
format[0] = '\0';
if (!test) {
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%.2f", tms_total / tick / (slot.cpu_duration.tv_sec + slot.cpu_duration.tv_usec / 1000000.) * 100.);
}
break;
#endif
case 'd': /* duration µs */
/* seconds */
if (format[0] == '\0' || !strcasecmp(format, "seconds")) {
if (!test) {
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%.3f", uptime.tv_sec + uptime.tv_usec / 1000000.);
}
/* miliseconds */
} else if (!strcasecmp(format, "miliseconds") || !strcasecmp(format, "mili")) {
if (!test) {
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%.3f", uptime.tv_sec * 1000. + uptime.tv_usec / 1000.);
}
/* microseconds */
} else if (!strcasecmp(format, "microseconds") || !strcasecmp(format, "micro")) {
if (!test) {
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%lu", uptime.tv_sec * 1000000UL + uptime.tv_usec);
}
} else {
zlog(ZLOG_WARNING, "only 'seconds', 'mili', 'miliseconds', 'micro' or 'microseconds' are allowed as a modifier for %%%c ('%s')", *s, format);
return -1;
}
format[0] = '\0';
break;
case 'e': /* fastcgi env */
if (format[0] == '\0') {
zlog(ZLOG_WARNING, "the name of the environment variable must be set between embraces for %%%c", *s);
return -1;
}
if (!test) {
char *env = fcgi_getenv((fcgi_request*) SG(server_context), format, strlen(format));
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%s", env ? env : "-");
}
format[0] = '\0';
break;
case 'f': /* script */
if (!test) {
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%s", slot.script_filename && *slot.script_filename ? slot.script_filename : "-");
}
break;
case 'l': /* content length */
if (!test) {
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%zu", slot.content_length);
}
break;
case 'm': /* method */
if (!test) {
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%s", slot.request_method && *slot.request_method ? slot.request_method : "-");
}
break;
case 'M': /* memory */
/* seconds */
if (format[0] == '\0' || !strcasecmp(format, "bytes")) {
if (!test) {
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%zu", slot.memory);
}
/* kilobytes */
} else if (!strcasecmp(format, "kilobytes") || !strcasecmp(format, "kilo")) {
if (!test) {
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%lu", slot.memory / 1024);
}
/* megabytes */
} else if (!strcasecmp(format, "megabytes") || !strcasecmp(format, "mega")) {
if (!test) {
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%lu", slot.memory / 1024 / 1024);
}
} else {
zlog(ZLOG_WARNING, "only 'bytes', 'kilo', 'kilobytes', 'mega' or 'megabytes' are allowed as a modifier for %%%c ('%s')", *s, format);
return -1;
}
format[0] = '\0';
break;
case 'n': /* pool name */
if (!test) {
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%s", fpm_log_pool ? fpm_log_pool : "-");
}
break;
case 'o': /* header output */
if (format[0] == '\0') {
zlog(ZLOG_WARNING, "the name of the header must be set between embraces for %%%c", *s);
return -1;
}
if (!test) {
sapi_header_struct *h;
zend_llist_position pos;
sapi_headers_struct *sapi_headers = &SG(sapi_headers);
size_t format_len = strlen(format);
h = (sapi_header_struct*)zend_llist_get_first_ex(&sapi_headers->headers, &pos);
while (h) {
char *header;
if (!h->header_len) {
h = (sapi_header_struct*)zend_llist_get_next_ex(&sapi_headers->headers, &pos);
continue;
}
if (!strstr(h->header, format)) {
h = (sapi_header_struct*)zend_llist_get_next_ex(&sapi_headers->headers, &pos);
continue;
}
/* test if enought char after the header name + ': ' */
if (h->header_len <= format_len + 2) {
h = (sapi_header_struct*)zend_llist_get_next_ex(&sapi_headers->headers, &pos);
continue;
}
if (h->header[format_len] != ':' || h->header[format_len + 1] != ' ') {
h = (sapi_header_struct*)zend_llist_get_next_ex(&sapi_headers->headers, &pos);
continue;
}
header = h->header + format_len + 2;
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%s", header && *header ? header : "-");
/* found, done */
break;
}
if (!len2) {
len2 = 1;
*b = '-';
}
}
format[0] = '\0';
break;
case 'p': /* PID */
if (!test) {
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%ld", (long)getpid());
}
break;
case 'P': /* PID */
if (!test) {
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%ld", (long)getppid());
}
break;
case 'q': /* query_string */
if (!test) {
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%s", slot.query_string ? slot.query_string : "");
}
break;
case 'Q': /* '?' */
if (!test) {
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%s", slot.query_string && *slot.query_string ? "?" : "");
}
break;
case 'r': /* request URI */
if (!test) {
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%s", slot.request_uri ? slot.request_uri : "-");
}
break;
case 'R': /* remote IP address */
if (!test) {
char *tmp = fcgi_get_last_client_ip();
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%s", tmp ? tmp : "-");
}
break;
case 's': /* status */
if (!test) {
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%d", SG(sapi_headers).http_response_code);
}
break;
case 'T':
case 't': /* time */
if (!test) {
time_t *t;
if (*s == 't') {
t = &slot.accepted_epoch;
} else {
t = &now_epoch;
}
if (format[0] == '\0') {
strftime(tmp, sizeof(tmp) - 1, "%d/%b/%Y:%H:%M:%S %z", localtime(t));
} else {
strftime(tmp, sizeof(tmp) - 1, format, localtime(t));
}
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%s", tmp);
}
format[0] = '\0';
break;
case 'u': /* remote user */
if (!test) {
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%s", slot.auth_user ? slot.auth_user : "-");
}
break;
case '{': /* complex var */
token = 1;
{
char *start;
size_t l;
start = ++s;
while (*s != '\0') {
if (*s == '}') {
l = s - start;
if (l >= sizeof(format) - 1) {
l = sizeof(format) - 1;
}
memcpy(format, start, l);
format[l] = '\0';
break;
}
s++;
}
if (s[1] == '\0') {
zlog(ZLOG_WARNING, "missing closing embrace in the access.format");
return -1;
}
}
break;
default:
zlog(ZLOG_WARNING, "Invalid token in the access.format (%%%c)", *s);
return -1;
}
if (*s != '}' && format[0] != '\0') {
zlog(ZLOG_WARNING, "embrace is not allowed for modifier %%%c", *s);
return -1;
}
s++;
if (!test) {
b += len2;
len += len2;
}
continue;
}
if (!test) {
// push the normal char to the output buffer
*b = *s;
b++;
len++;
}
s++;
}
if (!test && strlen(buffer) > 0) {
buffer[len] = '\n';
write(fpm_log_fd, buffer, len + 1);
}
return 0;
}
/* }}} */

14
sapi/fpm/fpm/fpm_log.h Normal file
View File

@ -0,0 +1,14 @@
/* $Id: fpm_status.h 312263 2011-06-18 17:46:16Z felipe $ */
/* (c) 2009 Jerome Loyet */
#ifndef FPM_LOG_H
#define FPM_LOG_H 1
#include "fpm_worker_pool.h"
int fpm_log_init_main();
int fpm_log_init_child(struct fpm_worker_pool_s *wp);
int fpm_log_write(char *log_format TSRMLS_DC);
int fpm_log_open(int reopen);
#endif

View File

@ -109,6 +109,7 @@ int __riscosify_control = __RISCOSIFY_STRICT_UNIX_SPECS;
#include <fpm/fpm_status.h>
#include <fpm/fpm_conf.h>
#include <fpm/fpm_php.h>
#include <fpm/fpm_log.h>
#ifndef PHP_WIN32
/* XXX this will need to change later when threaded fastcgi is implemented. shane */
@ -1906,6 +1907,9 @@ fastcgi_request_done:
}
}
fpm_request_end(TSRMLS_C);
fpm_log_write(NULL TSRMLS_CC);
STR_FREE(SG(request_info).path_translated);
SG(request_info).path_translated = NULL;

View File

@ -172,6 +172,18 @@ char *fpm_php_request_method(TSRMLS_D) /* {{{ */
}
/* }}} */
char *fpm_php_query_string(TSRMLS_D) /* {{{ */
{
return SG(request_info).query_string;
}
/* }}} */
char *fpm_php_auth_user(TSRMLS_D) /* {{{ */
{
return SG(request_info).auth_user;
}
/* }}} */
size_t fpm_php_content_length(TSRMLS_D) /* {{{ */
{
return SG(request_info).content_length;

View File

@ -37,6 +37,8 @@ int fpm_php_init_child(struct fpm_worker_pool_s *wp);
char *fpm_php_script_filename(TSRMLS_D);
char *fpm_php_request_uri(TSRMLS_D);
char *fpm_php_request_method(TSRMLS_D);
char *fpm_php_query_string(TSRMLS_D);
char *fpm_php_auth_user(TSRMLS_D);
size_t fpm_php_content_length(TSRMLS_D);
void fpm_php_soft_quit();
int fpm_php_init_main();

View File

@ -143,7 +143,7 @@ int fpm_pctl_kill(pid_t pid, int how) /* {{{ */
}
/* }}} */
static void fpm_pctl_kill_all(int signo) /* {{{ */
void fpm_pctl_kill_all(int signo) /* {{{ */
{
struct fpm_worker_pool_s *wp;
int alive_children = 0;

View File

@ -19,6 +19,7 @@ struct fpm_child_s;
void fpm_pctl(int new_state, int action);
int fpm_pctl_can_spawn_children();
int fpm_pctl_kill(pid_t pid, int how);
void fpm_pctl_kill_all(int signo);
void fpm_pctl_heartbeat(struct fpm_event_s *ev, short which, void *arg);
void fpm_pctl_perform_idle_server_maintenance_heartbeat(struct fpm_event_s *ev, short which, void *arg);
int fpm_pctl_child_exited();

View File

@ -1,6 +1,9 @@
/* $Id: fpm_request.c,v 1.9.2.1 2008/11/15 00:57:24 anight Exp $ */
/* (c) 2007,2008 Andrei Nigmatulin */
#ifdef HAVE_TIMES
#include <sys/times.h>
#endif
#include "fpm_config.h"
@ -16,6 +19,7 @@
#include "fpm_shm_slots.h"
#include "fpm_status.h"
#include "fpm_request.h"
#include "fpm_log.h"
#include "zlog.h"
@ -42,6 +46,10 @@ void fpm_request_reading_headers() /* {{{ */
slot->request_stage = FPM_REQUEST_READING_HEADERS;
fpm_clock_get(&slot->tv);
slot->accepted = slot->tv;
slot->accepted_epoch = time(NULL);
#ifdef HAVE_TIMES
times(&slot->cpu_accepted);
#endif
fpm_shm_slots_release(slot);
fpm_status_increment_accepted_conn(fpm_status_shm);
@ -55,6 +63,8 @@ void fpm_request_info() /* {{{ */
char *request_uri = fpm_php_request_uri(TSRMLS_C);
char *request_method = fpm_php_request_method(TSRMLS_C);
char *script_filename = fpm_php_script_filename(TSRMLS_C);
char *query_string = fpm_php_query_string(TSRMLS_C);
char *auth_user = fpm_php_auth_user(TSRMLS_C);
slot = fpm_shm_slots_acquire(0, 0);
slot->request_stage = FPM_REQUEST_INFO;
@ -68,6 +78,14 @@ void fpm_request_info() /* {{{ */
strlcpy(slot->request_method, request_method, sizeof(slot->request_method));
}
if (query_string) {
strlcpy(slot->query_string, query_string, sizeof(slot->query_string));
}
if (auth_user) {
strlcpy(slot->auth_user, auth_user, sizeof(slot->auth_user));
}
slot->content_length = fpm_php_content_length(TSRMLS_C);
/* if cgi.fix_pathinfo is set to "1" and script cannot be found (404)
@ -91,6 +109,22 @@ void fpm_request_executing() /* {{{ */
}
/* }}} */
void fpm_request_end(TSRMLS_D) /* {{{ */
{
struct fpm_shm_slot_s *slot;
slot = fpm_shm_slots_acquire(0, 0);
slot->request_stage = FPM_REQUEST_FINISHED;
fpm_clock_get(&slot->tv);
#ifdef HAVE_TIMES
times(&slot->cpu_finished);
timersub(&slot->tv, &slot->accepted, &slot->cpu_duration);
#endif
slot->memory = zend_memory_peak_usage(1 TSRMLS_CC);
fpm_shm_slots_release(slot);
}
/* }}} */
void fpm_request_finished() /* {{{ */
{
struct fpm_shm_slot_s *slot;
@ -99,6 +133,7 @@ void fpm_request_finished() /* {{{ */
slot->request_stage = FPM_REQUEST_FINISHED;
fpm_clock_get(&slot->tv);
memset(&slot->accepted, 0, sizeof(slot->accepted));
slot->accepted_epoch = 0;
fpm_shm_slots_release(slot);
}
/* }}} */
@ -125,7 +160,7 @@ void fpm_request_check_timed_out(struct fpm_child_s *child, struct timeval *now,
}
#endif
if (slot_c.request_stage > FPM_REQUEST_ACCEPTING && slot_c.request_stage < FPM_REQUEST_FINISHED) {
if (slot_c.request_stage > FPM_REQUEST_ACCEPTING && slot_c.request_stage < FPM_REQUEST_END) {
char purified_script_filename[sizeof(slot_c.script_filename)];
struct timeval tv;

View File

@ -9,7 +9,8 @@ void fpm_request_accepting(); /* hanging in accept() */
void fpm_request_reading_headers(); /* start reading fastcgi request from very first byte */
void fpm_request_info(); /* not a stage really but a point in the php code, where all request params have become known to sapi */
void fpm_request_executing(); /* the script is executing */
void fpm_request_finished(); /* request processed: script response have been sent to web server */
void fpm_request_end(TSRMLS_D); /* request ended: script response have been sent to web server */
void fpm_request_finished(); /* request processed: cleaning current request */
struct fpm_child_s;
struct timeval;
@ -22,6 +23,7 @@ enum fpm_request_stage_e {
FPM_REQUEST_READING_HEADERS,
FPM_REQUEST_INFO,
FPM_REQUEST_EXECUTING,
FPM_REQUEST_END,
FPM_REQUEST_FINISHED
};

View File

@ -5,6 +5,10 @@
#ifndef FPM_SHM_SLOTS_H
#define FPM_SHM_SLOTS_H 1
#ifdef HAVE_TIMES
#include <sys/times.h>
#endif
#include "fpm_atomic.h"
#include "fpm_worker_pool.h"
#include "fpm_request.h"
@ -18,11 +22,20 @@ struct fpm_shm_slot_s {
};
enum fpm_request_stage_e request_stage;
struct timeval accepted;
time_t accepted_epoch;
struct timeval tv;
char request_uri[128];
char query_string[512];
char request_method[16];
size_t content_length; /* used with POST only */
char script_filename[256];
char auth_user[32];
#ifdef HAVE_TIMES
struct tms cpu_accepted;
struct tms cpu_finished;
struct timeval cpu_duration;
#endif
size_t memory;
};
struct fpm_shm_slot_ptr_s {

View File

@ -9,6 +9,7 @@
#include "fpm_config.h"
#include "fpm_status.h"
#include "fpm_clock.h"
#include "fpm_shm_slots.h"
#include "zlog.h"
struct fpm_shm_s *fpm_status_shm = NULL;

View File

@ -55,6 +55,7 @@ struct fpm_worker_pool_s *fpm_worker_pool_alloc() /* {{{ */
fpm_array_init(&ret->slots_used, sizeof(struct fpm_shm_slot_ptr_s), 50);
fpm_array_init(&ret->slots_free, sizeof(struct fpm_shm_slot_ptr_s), 50);
ret->idle_spawn_rate = 1;
ret->log_fd = -1;
return ret;
}
/* }}} */

View File

@ -39,6 +39,7 @@ struct fpm_worker_pool_s {
int idle_spawn_rate;
int warn_max_children;
struct fpm_shm_s *shm_status;
int log_fd;
};
struct fpm_worker_pool_s *fpm_worker_pool_alloc();

View File

@ -232,6 +232,65 @@ pm.max_children = 50
; response is formatted as text/plain with a 200 response code.
; Default Value: pong
;ping.response = pong
; The access log file
; Default: not set
;access.log = log/$pool.access.log
; The access log format.
; The following syntax is allowed
; %%: the '%' character
; %C: %CPU used by the request
; it can accept the following format:
; - %{user}C for user CPU only
; - %{system}C for system CPU only
; - %{total}C for user + system CPU (default)
; %d: time taken to serve the request
; it can accept the following format:
; - %{seconds}d (default)
; - %{miliseconds}d
; - %{mili}d
; - %{microseconds}d
; - %{micro}d
; %e: an environment variable (same as $_ENV or $_SERVER)
; it must be associated with embraces to specify the name of the env
; variable. Some exemples:
; - server specifics like: %{REQUEST_METHOD}e or %{SERVER_PROTOCOL}e
; - HTTP headers like: %{HTTP_HOST}e or %{HTTP_USER_AGENT}e
; %f: script filename
: %l: content-length of the request (for POST request only)
; %m: request method
; %M: peak of memory allocated by PHP
; it can accept the following format:
; - %{bytes}M (default)
; - %{kilobytes}M
; - %{kilo}M
; - %{megabytes}M
; - %{mega}M
; %n: pool name
; %o: ouput header
; it must be associated with embraces to specify the name of the header:
; - %{Content-Type}o
; - %{X-Powered-By}o
; - %{Transfert-Encoding}o
; - ....
; %p: PID of the child that serviced the request
; %P: PID of the parent of the child that serviced the request
; %q: the query string
; %Q: the '?' character if query string exists
; %r: the request URI (without the query string, see %q and %Q)
; %R: remote IP address
; %s: status (response code)
; %t: server time the request was received
; it can accept a strftime(3) format:
; %d/%b/%Y:%H:%M:%S %z (default)
; %T: time the log has been written (the request has finished)
; it can accept a strftime(3) format:
; %d/%b/%Y:%H:%M:%S %z (default)
; %u: remote user
;
; Default: "%R - %u %t \"%m %r\" %s"
;access.format = %R - %u %t "%m %r%Q%q" %s %f %{mili}d %{kilo}M %C%%
; The timeout for serving a single request after which the worker process will
; be killed. This option should be used when the 'max_execution_time' ini option