Пример #1
0
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;
}
Пример #2
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;
}