int fpm_status_handle_request(TSRMLS_D) /* {{{ */ { struct fpm_scoreboard_s scoreboard, *scoreboard_p; struct fpm_scoreboard_proc_s proc; char *buffer, *time_format, time_buffer[64]; time_t now_epoch; int full, encode; char *short_syntax, *short_post; char *full_pre, *full_syntax, *full_post, *full_separator; zend_string *_GET_str; if (!SG(request_info).request_uri) { return 0; } /* PING */ if (fpm_status_ping_uri && fpm_status_ping_response && !strcmp(fpm_status_ping_uri, SG(request_info).request_uri)) { fpm_request_executing(); sapi_add_header_ex(ZEND_STRL("Content-Type: text/plain"), 1, 1 TSRMLS_CC); sapi_add_header_ex(ZEND_STRL("Expires: Thu, 01 Jan 1970 00:00:00 GMT"), 1, 1 TSRMLS_CC); sapi_add_header_ex(ZEND_STRL("Cache-Control: no-cache, no-store, must-revalidate, max-age=0"), 1, 1 TSRMLS_CC); SG(sapi_headers).http_response_code = 200; /* handle HEAD */ if (SG(request_info).headers_only) { return 1; } PUTS(fpm_status_ping_response); return 1; } /* STATUS */ if (fpm_status_uri && !strcmp(fpm_status_uri, SG(request_info).request_uri)) { fpm_request_executing(); scoreboard_p = fpm_scoreboard_get(); if (!scoreboard_p) { zlog(ZLOG_ERROR, "status: unable to find or access status shared memory"); SG(sapi_headers).http_response_code = 500; sapi_add_header_ex(ZEND_STRL("Content-Type: text/plain"), 1, 1 TSRMLS_CC); sapi_add_header_ex(ZEND_STRL("Expires: Thu, 01 Jan 1970 00:00:00 GMT"), 1, 1 TSRMLS_CC); sapi_add_header_ex(ZEND_STRL("Cache-Control: no-cache, no-store, must-revalidate, max-age=0"), 1, 1 TSRMLS_CC); PUTS("Internal error. Please review log file for errors."); return 1; } if (!fpm_spinlock(&scoreboard_p->lock, 1)) { zlog(ZLOG_NOTICE, "[pool %s] status: scoreboard already in used.", scoreboard_p->pool); SG(sapi_headers).http_response_code = 503; sapi_add_header_ex(ZEND_STRL("Content-Type: text/plain"), 1, 1 TSRMLS_CC); sapi_add_header_ex(ZEND_STRL("Expires: Thu, 01 Jan 1970 00:00:00 GMT"), 1, 1 TSRMLS_CC); sapi_add_header_ex(ZEND_STRL("Cache-Control: no-cache, no-store, must-revalidate, max-age=0"), 1, 1 TSRMLS_CC); PUTS("Server busy. Please try again later."); return 1; } /* copy the scoreboard not to bother other processes */ scoreboard = *scoreboard_p; fpm_unlock(scoreboard_p->lock); if (scoreboard.idle < 0 || scoreboard.active < 0) { zlog(ZLOG_ERROR, "[pool %s] invalid status values", scoreboard.pool); SG(sapi_headers).http_response_code = 500; sapi_add_header_ex(ZEND_STRL("Content-Type: text/plain"), 1, 1 TSRMLS_CC); sapi_add_header_ex(ZEND_STRL("Expires: Thu, 01 Jan 1970 00:00:00 GMT"), 1, 1 TSRMLS_CC); sapi_add_header_ex(ZEND_STRL("Cache-Control: no-cache, no-store, must-revalidate, max-age=0"), 1, 1 TSRMLS_CC); PUTS("Internal error. Please review log file for errors."); return 1; } /* send common headers */ sapi_add_header_ex(ZEND_STRL("Expires: Thu, 01 Jan 1970 00:00:00 GMT"), 1, 1 TSRMLS_CC); sapi_add_header_ex(ZEND_STRL("Cache-Control: no-cache, no-store, must-revalidate, max-age=0"), 1, 1 TSRMLS_CC); SG(sapi_headers).http_response_code = 200; /* handle HEAD */ if (SG(request_info).headers_only) { return 1; } /* full status ? */ _GET_str = STR_INIT("_GET", sizeof("_GET")-1, 0); full = (fpm_php_get_string_from_table(_GET_str, "full" TSRMLS_CC) != NULL); short_syntax = short_post = NULL; full_separator = full_pre = full_syntax = full_post = NULL; encode = 0; /* HTML */ if (fpm_php_get_string_from_table(_GET_str, "html" TSRMLS_CC)) { sapi_add_header_ex(ZEND_STRL("Content-Type: text/html"), 1, 1 TSRMLS_CC); time_format = "%d/%b/%Y:%H:%M:%S %z"; encode = 1; short_syntax = "<!DOCTYPE html PUBLIC \"-//W3C//DTD XHTML 1.0 Strict//EN\" \"http://www.w3.org/TR/xhtml1/DTD/xhtml1-strict.dtd\">\n" "<html xmlns=\"http://www.w3.org/1999/xhtml\" xml:lang=\"en\" lang=\"en\">\n" "<head><title>PHP-FPM Status Page</title></head>\n" "<body>\n" "<table>\n" "<tr><th>pool</th><td>%s</td></tr>\n" "<tr><th>process manager</th><td>%s</td></tr>\n" "<tr><th>start time</th><td>%s</td></tr>\n" "<tr><th>start since</th><td>%lu</td></tr>\n" "<tr><th>accepted conn</th><td>%lu</td></tr>\n" #ifdef HAVE_FPM_LQ "<tr><th>listen queue</th><td>%u</td></tr>\n" "<tr><th>max listen queue</th><td>%u</td></tr>\n" "<tr><th>listen queue len</th><td>%d</td></tr>\n" #endif "<tr><th>idle processes</th><td>%d</td></tr>\n" "<tr><th>active processes</th><td>%d</td></tr>\n" "<tr><th>total processes</th><td>%d</td></tr>\n" "<tr><th>max active processes</th><td>%d</td></tr>\n" "<tr><th>max children reached</th><td>%u</td></tr>\n" "<tr><th>slow requests</th><td>%lu</td></tr>\n" "</table>\n"; if (!full) { short_post = "</body></html>"; } else { full_pre = "<table border=\"1\">\n" "<tr>" "<th>pid</th>" "<th>state</th>" "<th>start time</th>" "<th>start since</th>" "<th>requests</th>" "<th>request duration</th>" "<th>request method</th>" "<th>request uri</th>" "<th>content length</th>" "<th>user</th>" "<th>script</th>" #ifdef HAVE_FPM_LQ "<th>last request cpu</th>" #endif "<th>last request memory</th>" "</tr>\n"; full_syntax = "<tr>" "<td>%d</td>" "<td>%s</td>" "<td>%s</td>" "<td>%lu</td>" "<td>%lu</td>" "<td>%lu</td>" "<td>%s</td>" "<td>%s%s%s</td>" "<td>%zu</td>" "<td>%s</td>" "<td>%s</td>" #ifdef HAVE_FPM_LQ "<td>%.2f</td>" #endif "<td>%zu</td>" "</tr>\n"; full_post = "</table></body></html>"; } /* XML */ } else if (fpm_php_get_string_from_table(_GET_str, "xml" TSRMLS_CC)) { sapi_add_header_ex(ZEND_STRL("Content-Type: text/xml"), 1, 1 TSRMLS_CC); time_format = "%s"; encode = 1; short_syntax = "<?xml version=\"1.0\" ?>\n" "<status>\n" "<pool>%s</pool>\n" "<process-manager>%s</process-manager>\n" "<start-time>%s</start-time>\n" "<start-since>%lu</start-since>\n" "<accepted-conn>%lu</accepted-conn>\n" #ifdef HAVE_FPM_LQ "<listen-queue>%u</listen-queue>\n" "<max-listen-queue>%u</max-listen-queue>\n" "<listen-queue-len>%d</listen-queue-len>\n" #endif "<idle-processes>%d</idle-processes>\n" "<active-processes>%d</active-processes>\n" "<total-processes>%d</total-processes>\n" "<max-active-processes>%d</max-active-processes>\n" "<max-children-reached>%u</max-children-reached>\n" "<slow-requests>%lu</slow-requests>\n"; if (!full) { short_post = "</status>"; } else { full_pre = "<processes>\n"; full_syntax = "<process>" "<pid>%d</pid>" "<state>%s</state>" "<start-time>%s</start-time>" "<start-since>%lu</start-since>" "<requests>%lu</requests>" "<request-duration>%lu</request-duration>" "<request-method>%s</request-method>" "<request-uri>%s%s%s</request-uri>" "<content-length>%zu</content-length>" "<user>%s</user>" "<script>%s</script>" #ifdef HAVE_FPM_LQ "<last-request-cpu>%.2f</last-request-cpu>" #endif "<last-request-memory>%zu</last-request-memory>" "</process>\n" ; full_post = "</processes>\n</status>"; } /* JSON */ } else if (fpm_php_get_string_from_table(_GET_str, "json" TSRMLS_CC)) { sapi_add_header_ex(ZEND_STRL("Content-Type: application/json"), 1, 1 TSRMLS_CC); time_format = "%s"; short_syntax = "{" "\"pool\":\"%s\"," "\"process manager\":\"%s\"," "\"start time\":%s," "\"start since\":%lu," "\"accepted conn\":%lu," #ifdef HAVE_FPM_LQ "\"listen queue\":%u," "\"max listen queue\":%u," "\"listen queue len\":%d," #endif "\"idle processes\":%d," "\"active processes\":%d," "\"total processes\":%d," "\"max active processes\":%d," "\"max children reached\":%u," "\"slow requests\":%lu"; if (!full) { short_post = "}"; } else { full_separator = ","; full_pre = ", \"processes\":["; full_syntax = "{" "\"pid\":%d," "\"state\":\"%s\"," "\"start time\":%s," "\"start since\":%lu," "\"requests\":%lu," "\"request duration\":%lu," "\"request method\":\"%s\"," "\"request uri\":\"%s%s%s\"," "\"content length\":%zu," "\"user\":\"%s\"," "\"script\":\"%s\"," #ifdef HAVE_FPM_LQ "\"last request cpu\":%.2f," #endif "\"last request memory\":%zu" "}"; full_post = "]}"; } /* TEXT */ } else { sapi_add_header_ex(ZEND_STRL("Content-Type: text/plain"), 1, 1 TSRMLS_CC); time_format = "%d/%b/%Y:%H:%M:%S %z"; short_syntax = "pool: %s\n" "process manager: %s\n" "start time: %s\n" "start since: %lu\n" "accepted conn: %lu\n" #ifdef HAVE_FPM_LQ "listen queue: %u\n" "max listen queue: %u\n" "listen queue len: %d\n" #endif "idle processes: %d\n" "active processes: %d\n" "total processes: %d\n" "max active processes: %d\n" "max children reached: %u\n" "slow requests: %lu\n"; if (full) { full_syntax = "\n" "************************\n" "pid: %d\n" "state: %s\n" "start time: %s\n" "start since: %lu\n" "requests: %lu\n" "request duration: %lu\n" "request method: %s\n" "request URI: %s%s%s\n" "content length: %zu\n" "user: %s\n" "script: %s\n" #ifdef HAVE_FPM_LQ "last request cpu: %.2f\n" #endif "last request memory: %zu\n"; } } strftime(time_buffer, sizeof(time_buffer) - 1, time_format, localtime(&scoreboard.start_epoch)); now_epoch = time(NULL); spprintf(&buffer, 0, short_syntax, scoreboard.pool, PM2STR(scoreboard.pm), time_buffer, now_epoch - scoreboard.start_epoch, scoreboard.requests, #ifdef HAVE_FPM_LQ scoreboard.lq, scoreboard.lq_max, scoreboard.lq_len, #endif scoreboard.idle, scoreboard.active, scoreboard.idle + scoreboard.active, scoreboard.active_max, scoreboard.max_children_reached, scoreboard.slow_rq); PUTS(buffer); efree(buffer); STR_RELEASE(_GET_str); if (short_post) { PUTS(short_post); } /* no need to test the var 'full' */ if (full_syntax) { int i, first; zend_string *tmp_query_string; char *query_string; struct timeval duration, now; #ifdef HAVE_FPM_LQ float cpu; #endif fpm_clock_get(&now); if (full_pre) { PUTS(full_pre); } first = 1; for (i=0; i<scoreboard_p->nprocs; i++) { if (!scoreboard_p->procs[i] || !scoreboard_p->procs[i]->used) { continue; } proc = *scoreboard_p->procs[i]; if (first) { first = 0; } else { if (full_separator) { PUTS(full_separator); } } query_string = NULL; tmp_query_string = NULL; if (proc.query_string[0] != '\0') { if (!encode) { query_string = proc.query_string; } else { tmp_query_string = php_escape_html_entities_ex((unsigned char *)proc.query_string, strlen(proc.query_string), 1, ENT_HTML_IGNORE_ERRORS & ENT_COMPAT, NULL, 1 TSRMLS_CC); query_string = tmp_query_string->val; } } #ifdef HAVE_FPM_LQ /* prevent NaN */ if (proc.cpu_duration.tv_sec == 0 && proc.cpu_duration.tv_usec == 0) { cpu = 0.; } else { cpu = (proc.last_request_cpu.tms_utime + proc.last_request_cpu.tms_stime + proc.last_request_cpu.tms_cutime + proc.last_request_cpu.tms_cstime) / fpm_scoreboard_get_tick() / (proc.cpu_duration.tv_sec + proc.cpu_duration.tv_usec / 1000000.) * 100.; } #endif if (proc.request_stage == FPM_REQUEST_ACCEPTING) { duration = proc.duration; } else { timersub(&now, &proc.accepted, &duration); } strftime(time_buffer, sizeof(time_buffer) - 1, time_format, localtime(&proc.start_epoch)); spprintf(&buffer, 0, full_syntax, proc.pid, fpm_request_get_stage_name(proc.request_stage), time_buffer, now_epoch - proc.start_epoch, proc.requests, duration.tv_sec * 1000000UL + duration.tv_usec, proc.request_method[0] != '\0' ? proc.request_method : "-", proc.request_uri[0] != '\0' ? proc.request_uri : "-", query_string ? "?" : "", query_string ? query_string : "", proc.content_length, proc.auth_user[0] != '\0' ? proc.auth_user : "******", proc.script_filename[0] != '\0' ? proc.script_filename : "-", #ifdef HAVE_FPM_LQ proc.request_stage == FPM_REQUEST_ACCEPTING ? cpu : 0., #endif proc.request_stage == FPM_REQUEST_ACCEPTING ? proc.memory : 0); PUTS(buffer); efree(buffer); if (tmp_query_string) { STR_FREE(tmp_query_string); } } if (full_post) { PUTS(full_post); } } return 1; } return 0; }
int fpm_log_write(char *log_format) /* {{{ */ { char *s, *b; char buffer[FPM_LOG_BUFFER+1]; int token, test; size_t len, len2; struct fpm_scoreboard_proc_s proc, *proc_p; struct fpm_scoreboard_s *scoreboard; 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; } now_epoch = time(NULL); if (!test) { scoreboard = fpm_scoreboard_get(); if (!scoreboard) { zlog(ZLOG_WARNING, "unable to get scoreboard while preparing the access log"); return -1; } proc_p = fpm_scoreboard_proc_acquire(NULL, -1, 0); if (!proc_p) { zlog(ZLOG_WARNING, "[pool %s] Unable to acquire shm slot while preparing the access log", scoreboard->pool); return -1; } proc = *proc_p; fpm_scoreboard_proc_release(proc_p); } token = 0; memset(buffer, '\0', sizeof(buffer)); b = buffer; len = 0; s = log_format; while (*s != '\0') { /* Test is we have place for 1 more char. */ if (len >= FPM_LOG_BUFFER) { zlog(ZLOG_NOTICE, "the log buffer is full (%d). The access log request has been truncated.", FPM_LOG_BUFFER); len = FPM_LOG_BUFFER; 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 = proc.last_request_cpu.tms_utime + proc.last_request_cpu.tms_stime + proc.last_request_cpu.tms_cutime + proc.last_request_cpu.tms_cstime; } } else if (!strcasecmp(format, "user")) { if (!test) { tms_total = proc.last_request_cpu.tms_utime + proc.last_request_cpu.tms_cutime; } } else if (!strcasecmp(format, "system")) { if (!test) { tms_total = proc.last_request_cpu.tms_stime + proc.last_request_cpu.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 / fpm_scoreboard_get_tick() / (proc.cpu_duration.tv_sec + proc.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", proc.duration.tv_sec + proc.duration.tv_usec / 1000000.); } /* miliseconds */ } else if (!strcasecmp(format, "miliseconds") || !strcasecmp(format, "mili")) { if (!test) { len2 = snprintf(b, FPM_LOG_BUFFER - len, "%.3f", proc.duration.tv_sec * 1000. + proc.duration.tv_usec / 1000.); } /* microseconds */ } else if (!strcasecmp(format, "microseconds") || !strcasecmp(format, "micro")) { if (!test) { len2 = snprintf(b, FPM_LOG_BUFFER - len, "%lu", proc.duration.tv_sec * 1000000UL + proc.duration.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", *proc.script_filename ? proc.script_filename : "-"); } break; case 'l': /* content length */ if (!test) { len2 = snprintf(b, FPM_LOG_BUFFER - len, "%zu", proc.content_length); } break; case 'm': /* method */ if (!test) { len2 = snprintf(b, FPM_LOG_BUFFER - len, "%s", *proc.request_method ? proc.request_method : "-"); } break; case 'M': /* memory */ /* seconds */ if (format[0] == '\0' || !strcasecmp(format, "bytes")) { if (!test) { len2 = snprintf(b, FPM_LOG_BUFFER - len, "%zu", proc.memory); } /* kilobytes */ } else if (!strcasecmp(format, "kilobytes") || !strcasecmp(format, "kilo")) { if (!test) { len2 = snprintf(b, FPM_LOG_BUFFER - len, "%lu", proc.memory / 1024); } /* megabytes */ } else if (!strcasecmp(format, "megabytes") || !strcasecmp(format, "mega")) { if (!test) { len2 = snprintf(b, FPM_LOG_BUFFER - len, "%lu", proc.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", scoreboard->pool[0] ? scoreboard->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", proc.query_string); } break; case 'Q': /* '?' */ if (!test) { len2 = snprintf(b, FPM_LOG_BUFFER - len, "%s", *proc.query_string ? "?" : ""); } break; case 'r': /* request URI */ if (!test) { len2 = snprintf(b, FPM_LOG_BUFFER - len, "%s", proc.request_uri); } break; case 'R': /* remote IP address */ if (!test) { const 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 = &proc.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", proc.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; }