Skip to content

Commit e850718

Browse files
maaarghkmaaarghk
committed
fpm: Implement access log filtering
Fixes GH-8174, #80428
1 parent d87ab75 commit e850718

File tree

7 files changed

+375
-10
lines changed

7 files changed

+375
-10
lines changed

‎sapi/fpm/fpm/fpm_conf.c

Lines changed: 38 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -557,11 +557,13 @@ static char *fpm_conf_set_array(zval *key, zval *value, void **config, int conve
557557
}
558558

559559
memset(kv, 0, sizeof(*kv));
560-
kv->key = strdup(Z_STRVAL_P(key));
560+
if (key) {
561+
kv->key = strdup(Z_STRVAL_P(key));
561562

562-
if (!kv->key) {
563-
free(kv);
564-
return "fpm_conf_set_array: strdup(key) failed";
563+
if (!kv->key) {
564+
free(kv);
565+
return "fpm_conf_set_array: strdup(key) failed";
566+
}
565567
}
566568

567569
if (convert_to_bool) {
@@ -663,6 +665,11 @@ int fpm_worker_pool_config_free(struct fpm_worker_pool_config_s *wpc) /* {{{ */
663665
free(wpc->apparmor_hat);
664666
#endif
665667

668+
for (kv = wpc->access_suppress_paths; kv; kv = kv_next) {
669+
kv_next = kv->next;
670+
free(kv->value);
671+
free(kv);
672+
}
666673
for (kv = wpc->php_values; kv; kv = kv_next) {
667674
kv_next = kv->next;
668675
free(kv->key);
@@ -1497,11 +1504,29 @@ static void fpm_conf_ini_parser_array(zval *name, zval *key, zval *value, void *
14971504
char *err = NULL;
14981505
void *config;
14991506

1500-
if (!Z_STRVAL_P(key) || !Z_STRVAL_P(value) || !*Z_STRVAL_P(key)) {
1501-
zlog(ZLOG_ERROR, "[%s:%d] Misspelled array ?", ini_filename, ini_lineno);
1507+
if (
1508+
!zend_string_equals_literal(Z_STR_P(name), "access.suppress_path")
1509+
&& (!Z_STRVAL_P(key) || !Z_STRVAL_P(value) || !*Z_STRVAL_P(key))
1510+
) {
1511+
zlog(ZLOG_ERROR, "[%s:%d] You must provide a key for field '%s'", ini_filename, ini_lineno, Z_STRVAL_P(name));
15021512
*error = 1;
15031513
return;
1514+
} else if (
1515+
zend_string_equals_literal(Z_STR_P(name), "access.suppress_path")
1516+
) {
1517+
if (!Z_STRVAL_P(key) || !(*Z_STRVAL_P(key) == '\0')) {
1518+
zlog(ZLOG_ERROR, "[%s:%d] Keys provided to field 'access.suppress_path' are ignored", ini_filename, ini_lineno);
1519+
*error = 1;
1520+
}
1521+
if (!Z_STRVAL_P(value) || !(*Z_STRVAL_P(value)) || (*Z_STRVAL_P(value) != '/')) {
1522+
zlog(ZLOG_ERROR, "[%s:%d] Values provided to field 'access.suppress_path' must begin with '/'", ini_filename, ini_lineno);
1523+
*error = 1;
1524+
}
1525+
if (*error) {
1526+
return;
1527+
}
15041528
}
1529+
15051530
if (!current_wp || !current_wp->config) {
15061531
zlog(ZLOG_ERROR, "[%s:%d] Array are not allowed in the global section", ini_filename, ini_lineno);
15071532
*error = 1;
@@ -1533,6 +1558,10 @@ static void fpm_conf_ini_parser_array(zval *name, zval *key, zval *value, void *
15331558
config = (char *)current_wp->config + WPO(php_admin_values);
15341559
err = fpm_conf_set_array(key, value, &config, 1);
15351560

1561+
} else if (zend_string_equals_literal(Z_STR_P(name), "access.suppress_path")) {
1562+
config = (char *)current_wp->config + WPO(access_suppress_paths);
1563+
err = fpm_conf_set_array(NULL, value, &config, 0);
1564+
15361565
} else {
15371566
zlog(ZLOG_ERROR, "[%s:%d] unknown directive '%s'", ini_filename, ini_lineno, Z_STRVAL_P(name));
15381567
*error = 1;
@@ -1735,6 +1764,9 @@ static void fpm_conf_dump(void) /* {{{ */
17351764
zlog(ZLOG_NOTICE, "\tping.response = %s", STR2STR(wp->config->ping_response));
17361765
zlog(ZLOG_NOTICE, "\taccess.log = %s", STR2STR(wp->config->access_log));
17371766
zlog(ZLOG_NOTICE, "\taccess.format = %s", STR2STR(wp->config->access_format));
1767+
for (kv = wp->config->access_suppress_paths; kv; kv = kv->next) {
1768+
zlog(ZLOG_NOTICE, "\taccess.suppress_path[] = %s", kv->value);
1769+
}
17381770
zlog(ZLOG_NOTICE, "\tslowlog = %s", STR2STR(wp->config->slowlog));
17391771
zlog(ZLOG_NOTICE, "\trequest_slowlog_timeout = %ds", wp->config->request_slowlog_timeout);
17401772
zlog(ZLOG_NOTICE, "\trequest_slowlog_trace_depth = %d", wp->config->request_slowlog_trace_depth);

‎sapi/fpm/fpm/fpm_conf.h

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -79,6 +79,7 @@ struct fpm_worker_pool_config_s {
7979
char *ping_response;
8080
char *access_log;
8181
char *access_format;
82+
struct key_value_s *access_suppress_paths;
8283
char *slowlog;
8384
int request_slowlog_timeout;
8485
int request_slowlog_trace_depth;

‎sapi/fpm/fpm/fpm_log.c

Lines changed: 54 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -27,6 +27,9 @@
2727

2828
static char *fpm_log_format = NULL;
2929
static int fpm_log_fd = -1;
30+
static struct key_value_s *fpm_access_suppress_paths = NULL;
31+
32+
static int fpm_access_log_suppress(struct fpm_scoreboard_proc_s *proc);
3033

3134
int fpm_log_open(int reopen) /* {{{ */
3235
{
@@ -79,6 +82,17 @@ int fpm_log_init_child(struct fpm_worker_pool_s *wp) /* {{{ */
7982
}
8083
}
8184

85+
for (struct key_value_s *kv = wp->config->access_suppress_paths; kv; kv = kv->next) {
86+
struct key_value_s *kvcopy = calloc(1, sizeof(*kvcopy));
87+
if (kvcopy == NULL) {
88+
zlog(ZLOG_ERROR, "unable to allocate memory while opening the access log");
89+
return -1;
90+
}
91+
kvcopy->value = strdup(kv->value);
92+
kvcopy->next = fpm_access_suppress_paths;
93+
fpm_access_suppress_paths = kvcopy;
94+
}
95+
8296
if (fpm_log_fd == -1) {
8397
fpm_log_fd = wp->log_fd;
8498
}
@@ -109,7 +123,6 @@ int fpm_log_write(char *log_format) /* {{{ */
109123
#ifdef HAVE_TIMES
110124
clock_t tms_total;
111125
#endif
112-
113126
if (!log_format && (!fpm_log_format || fpm_log_fd == -1)) {
114127
return -1;
115128
}
@@ -136,6 +149,10 @@ int fpm_log_write(char *log_format) /* {{{ */
136149
}
137150
proc = *proc_p;
138151
fpm_scoreboard_proc_release(proc_p);
152+
153+
if (UNEXPECTED(fpm_access_log_suppress(&proc) == 1)) {
154+
return -1;
155+
}
139156
}
140157

141158
token = 0;
@@ -474,3 +491,39 @@ int fpm_log_write(char *log_format) /* {{{ */
474491
return 0;
475492
}
476493
/* }}} */
494+
495+
static int fpm_access_log_suppress(struct fpm_scoreboard_proc_s *proc)
496+
{
497+
// Never suppress when query string is passed
498+
if (proc->query_string[0] != '\0') {
499+
return -1;
500+
}
501+
502+
// Never suppress if request method is not GET or HEAD
503+
if (
504+
strcmp(proc->request_method, "GET") != 0
505+
&& strcmp(proc->request_method, "HEAD") != 0
506+
) {
507+
return -2;
508+
}
509+
510+
// Never suppress when response code is not 200
511+
if (SG(sapi_headers).http_response_code != 200) {
512+
return -3;
513+
}
514+
515+
// Never suppress when a body has been sent
516+
if (SG(request_info).content_length > 0) {
517+
return -4;
518+
}
519+
520+
struct key_value_s *kv;
521+
// Suppress when request URI is an exact match for one of our entries
522+
for (kv = fpm_access_suppress_paths; kv; kv = kv->next) {
523+
if (kv->value && strcmp(kv->value, proc->request_uri) == 0) {
524+
return 1;
525+
}
526+
}
527+
528+
return -5;
529+
}

‎sapi/fpm/tests/log-suppress-output-request-body.phpt

Lines changed: 121 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,121 @@
1+
--TEST--
2+
FPM: Test URIs are not excluded from access log when there is a request body
3+
--SKIPIF--
4+
<?php include "skipif.inc"; ?>
5+
--FILE--
6+
<?php
7+
8+
require_once "tester.inc";
9+
10+
$testScript = <<<EOT
11+
<?php
12+
echo strlen(file_get_contents('php://input'));
13+
EOT;
14+
$s = __DIR__ . '/health_check.php';
15+
file_put_contents($s, $testScript);
16+
17+
$body = str_repeat('a', 100);
18+
19+
// Add health checks to ignore list
20+
$cfg = <<<EOT
21+
[global]
22+
error_log = {{FILE:LOG:ERR}}
23+
pid = {{FILE:PID}}
24+
[unconfined]
25+
listen = {{ADDR}}
26+
access.log = {{FILE:LOG:ACC}}
27+
access.format = "%R \"%m %r%Q%q\" %s"
28+
access.suppress_path[] = /ping
29+
access.suppress_path[] = /request-1
30+
access.suppress_path[] = /request-2
31+
access.suppress_path[] = /request-3
32+
access.suppress_path[] = /request-4
33+
access.suppress_path[] = /request-5
34+
access.suppress_path[] = /request-6
35+
slowlog = {{FILE:LOG:SLOW}}
36+
request_slowlog_timeout = 1
37+
ping.path = /ping
38+
ping.response = pong
39+
pm = dynamic
40+
pm.max_children = 5
41+
pm.start_servers = 2
42+
pm.min_spare_servers = 1
43+
pm.max_spare_servers = 3
44+
EOT;
45+
46+
$tester = new FPM\Tester($cfg);
47+
$tester->start();
48+
$tester->expectLogStartNotices();
49+
$tester->ping();
50+
51+
// Should not suppress POST with no body
52+
$tester->request(
53+
scriptFilename: $s,
54+
uri: '/request-1',
55+
headers: ['REQUEST_METHOD' => 'POST']
56+
)->expectBody('0');
57+
58+
// Should not suppress POST with body
59+
$tester->request(
60+
scriptFilename: $s,
61+
uri: '/request-2',
62+
stdin: $body
63+
)->expectBody('100');
64+
65+
// Should not suppress GET with body
66+
$tester->request(
67+
scriptFilename: $s,
68+
uri: '/request-3',
69+
headers: ['REQUEST_METHOD' => 'GET'],
70+
stdin: $body
71+
)->expectBody('100');
72+
73+
// Should suppress GET with no body
74+
$tester->request(
75+
scriptFilename: $s,
76+
uri: '/request-4'
77+
)->expectBody('0');
78+
79+
// Should not suppress GET with no body but incorrect content length
80+
$tester->request(
81+
scriptFilename: $s,
82+
uri: '/request-5',
83+
headers: ['REQUEST_METHOD' => 'GET', 'CONTENT_LENGTH' => 100]
84+
)->expectBody('0');
85+
86+
// Should suppress GET with body but 0 content length (no stdin readable)
87+
$tester->request(
88+
scriptFilename: $s,
89+
uri: '/request-6',
90+
headers: ['REQUEST_METHOD' => 'GET', 'CONTENT_LENGTH' => 0],
91+
stdin: $body
92+
)->expectBody('0');
93+
94+
// Should suppress GET with body but 0 content length (no stdin readable)
95+
$tester->request(
96+
scriptFilename: $s,
97+
uri: '/request-6',
98+
headers: ['REQUEST_METHOD' => 'GET', 'CONTENT_LENGTH' => 0],
99+
stdin: $body
100+
)->expectBody('0');
101+
102+
$tester->terminate();
103+
$tester->expectLogTerminatingNotices();
104+
$tester->close();
105+
$tester->expectNoFile(FPM\Tester::FILE_EXT_PID);
106+
$tester->printAccessLog();
107+
108+
?>
109+
Done
110+
--EXPECT--
111+
127.0.0.1 "POST /request-1" 200
112+
127.0.0.1 "POST /request-2" 200
113+
127.0.0.1 "GET /request-3" 200
114+
127.0.0.1 "GET /request-5" 200
115+
Done
116+
--CLEAN--
117+
<?php
118+
require_once "tester.inc";
119+
FPM\Tester::clean();
120+
unlink(__DIR__ . '/health_check.php');
121+
?>

0 commit comments

Comments
 (0)