Skip to content

Commit e41347c

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

File tree

6 files changed

+255
-11
lines changed

6 files changed

+255
-11
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: 51 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 (fpm_access_log_suppress(&proc) == 1) {
154+
return -1;
155+
}
139156
}
140157

141158
token = 0;
@@ -474,3 +491,36 @@ 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 && *proc->query_string != '\0') {
499+
return -1;
500+
}
501+
// Never suppress if request method is not GET or HEAD
502+
if (
503+
strcmp(proc->request_method, "GET") != 0
504+
&& strcmp(proc->request_method, "HEAD") != 0
505+
) {
506+
return -2;
507+
}
508+
// Never suppress when response code is not 200
509+
if (SG(sapi_headers).http_response_code != 200) {
510+
return -3;
511+
}
512+
// Never suppress when a body has been sent
513+
if (SG(request_info).content_length > 0) {
514+
return -4;
515+
}
516+
struct key_value_s *kv;
517+
// Suppress when request URI is an exact match for one of our entries
518+
for (kv = fpm_access_suppress_paths; kv; kv = kv->next) {
519+
if (kv->value && strcmp(kv->value, proc->request_uri) == 0) {
520+
return 1;
521+
}
522+
}
523+
// TODO: Is there something we can set in SG(request_info / sapi_headers) to
524+
// flag that the script doesn't want to be logged?
525+
return -5;
526+
}

‎sapi/fpm/tests/log-exclude-paths.phpt

Lines changed: 146 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,146 @@
1+
--TEST--
2+
FPM: Test excluding URIs from access log
3+
--SKIPIF--
4+
<?php include "skipif.inc"; ?>
5+
--FILE--
6+
<?php
7+
8+
require_once "tester.inc";
9+
10+
$normalCode = <<<EOT
11+
<?php
12+
echo \$_REQUEST['test'] ?? "Hello world";
13+
EOT;
14+
15+
file_put_contents(__DIR__ . '/log_exclude_paths_normal.php', $normalCode);
16+
17+
$statusCode = <<<EOT
18+
<?php
19+
if (isset(\$_SERVER['X_ERROR'])) {
20+
echo "Not OK";
21+
http_response_code(500);
22+
exit;
23+
}
24+
echo "OK";
25+
EOT;
26+
27+
file_put_contents(__DIR__ . '/log_exclude_paths_status.php', $statusCode);
28+
29+
30+
$cfg = <<<EOT
31+
[global]
32+
error_log = {{RFILE:LOG:ERR}}
33+
pid = {{RFILE:PID}}
34+
[unconfined]
35+
listen = {{ADDR}}
36+
access.log = {{RFILE:LOG:ACC}}
37+
access.format = "%R \"%m %r%Q%q\" %s Output"
38+
slowlog = {{RFILE:LOG:SLOW}}
39+
request_slowlog_timeout = 1
40+
ping.path = /ping
41+
ping.response = pong
42+
pm = dynamic
43+
pm.max_children = 5
44+
pm.start_servers = 2
45+
pm.min_spare_servers = 1
46+
pm.max_spare_servers = 3
47+
EOT;
48+
49+
$prefix = __DIR__;
50+
$tester = new FPM\Tester($cfg);
51+
$tester->start(['--prefix', $prefix]);
52+
$tester->expectLogStartNotices();
53+
$tester->ping();
54+
$tester->request(scriptFilename: __DIR__ . '/log_exclude_paths_normal.php')->expectBody('Hello world');
55+
$tester->request(scriptFilename: __DIR__ . '/log_exclude_paths_status.php')->expectBody('OK');
56+
$tester->ping();
57+
$tester->request(scriptFilename: __DIR__ . '/log_exclude_paths_status.php')->expectBody('OK');
58+
$tester->request(query: 'test=output', scriptFilename: __DIR__ . '/log_exclude_paths_normal.php')->expectBody('output');
59+
$tester->ping();
60+
$tester->request(scriptFilename: __DIR__ . '/log_exclude_paths_status.php')->expectBody('OK');
61+
$tester->request(query: 'test=output', scriptFilename: __DIR__ . '/ping')->expectBody('pong', 'text/plain');
62+
$tester->request(headers: ['X_ERROR' => 1], scriptFilename: __DIR__ . '/log_exclude_paths_status.php')->expectBody('Not OK');
63+
$tester->request(scriptFilename: __DIR__ . '/log_exclude_paths_normal.php')->expectBody('Hello world');
64+
$tester->request(scriptFilename: __DIR__ . '/log_exclude_paths_status.php')->expectBody('OK');
65+
$tester->request(scriptFilename: __DIR__ . '/log_exclude_paths_normal.php')->expectBody('Hello world');
66+
$tester->request(query: 'test=output', scriptFilename: __DIR__ . '/ping')->expectBody('pong', 'text/plain');
67+
$tester->ping();
68+
69+
// Add health checks to ignore list
70+
$cfg = <<<EOT
71+
[global]
72+
error_log = {{RFILE:LOG:ERR}}
73+
pid = {{RFILE:PID}}
74+
[unconfined]
75+
listen = {{ADDR}}
76+
access.log = {{RFILE:LOG:ACC}}
77+
access.format = "%R \"%m %r%Q%q\" %s Ignore"
78+
access.suppress_path[] = /ping
79+
access.suppress_path[] = /log_exclude_paths_status.php
80+
slowlog = {{RFILE:LOG:SLOW}}
81+
request_slowlog_timeout = 1
82+
ping.path = /ping
83+
ping.response = pong
84+
pm = dynamic
85+
pm.max_children = 5
86+
pm.start_servers = 2
87+
pm.min_spare_servers = 1
88+
pm.max_spare_servers = 3
89+
EOT;
90+
$tester->reload($cfg);
91+
$tester->expectLogReloadingNotices();
92+
$tester->ping();
93+
$tester->request(scriptFilename: __DIR__ . '/log_exclude_paths_normal.php')->expectBody('Hello world');
94+
$tester->request(scriptFilename: __DIR__ . '/log_exclude_paths_status.php')->expectBody('OK');
95+
$tester->ping();
96+
$tester->request(scriptFilename: __DIR__ . '/log_exclude_paths_status.php')->expectBody('OK');
97+
$tester->request(query: 'test=output', scriptFilename: __DIR__ . '/log_exclude_paths_normal.php')->expectBody('output');
98+
$tester->ping();
99+
$tester->request(scriptFilename: __DIR__ . '/log_exclude_paths_status.php')->expectBody('OK');
100+
$tester->request(query: 'test=output', scriptFilename: __DIR__ . '/ping')->expectBody('pong', 'text/plain');
101+
$tester->request(headers: ['X_ERROR' => 1], scriptFilename: __DIR__ . '/log_exclude_paths_status.php')->expectBody('Not OK');
102+
$tester->request(scriptFilename: __DIR__ . '/log_exclude_paths_normal.php')->expectBody('Hello world');
103+
$tester->request(scriptFilename: __DIR__ . '/log_exclude_paths_status.php')->expectBody('OK');
104+
$tester->request(scriptFilename: __DIR__ . '/log_exclude_paths_normal.php')->expectBody('Hello world');
105+
$tester->request(query: 'test=output', scriptFilename: __DIR__ . '/ping')->expectBody('pong', 'text/plain');
106+
$tester->ping();
107+
$tester->terminate();
108+
$tester->expectLogTerminatingNotices();
109+
$tester->close();
110+
$tester->expectNoFile(FPM\Tester::FILE_EXT_PID, $prefix);
111+
$tester->printAccessLog();
112+
113+
unlink(__DIR__ . '/log_exclude_paths_normal.php');
114+
unlink(__DIR__ . '/log_exclude_paths_status.php');
115+
116+
?>
117+
Done
118+
--EXPECT--
119+
127.0.0.1 "GET /ping" 200 Output
120+
127.0.0.1 "GET /log_exclude_paths_normal.php" 200 Output
121+
127.0.0.1 "GET /log_exclude_paths_status.php" 200 Output
122+
127.0.0.1 "GET /ping" 200 Output
123+
127.0.0.1 "GET /log_exclude_paths_status.php" 200 Output
124+
127.0.0.1 "GET /log_exclude_paths_normal.php?test=output" 200 Output
125+
127.0.0.1 "GET /ping" 200 Output
126+
127.0.0.1 "GET /log_exclude_paths_status.php" 200 Output
127+
127.0.0.1 "GET /ping?test=output" 200 Output
128+
127.0.0.1 "GET /log_exclude_paths_status.php" 500 Output
129+
127.0.0.1 "GET /log_exclude_paths_normal.php" 200 Output
130+
127.0.0.1 "GET /log_exclude_paths_status.php" 200 Output
131+
127.0.0.1 "GET /log_exclude_paths_normal.php" 200 Output
132+
127.0.0.1 "GET /ping?test=output" 200 Output
133+
127.0.0.1 "GET /ping" 200 Output
134+
127.0.0.1 "GET /log_exclude_paths_normal.php" 200 Ignore
135+
127.0.0.1 "GET /log_exclude_paths_normal.php?test=output" 200 Ignore
136+
127.0.0.1 "GET /ping?test=output" 200 Ignore
137+
127.0.0.1 "GET /log_exclude_paths_status.php" 500 Ignore
138+
127.0.0.1 "GET /log_exclude_paths_normal.php" 200 Ignore
139+
127.0.0.1 "GET /log_exclude_paths_normal.php" 200 Ignore
140+
127.0.0.1 "GET /ping?test=output" 200 Ignore
141+
Done
142+
--CLEAN--
143+
<?php
144+
require_once "tester.inc";
145+
FPM\Tester::clean();
146+
?>

‎sapi/fpm/tests/tester.inc

Lines changed: 9 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -342,11 +342,14 @@ class Tester
342342
* @return null|string
343343
* @throws \Exception
344344
*/
345-
public function testConfig()
345+
public function testConfig($returnRaw = false)
346346
{
347347
$configFile = $this->createConfig();
348-
$cmd = self::findExecutable() . ' -t -y ' . $configFile . ' 2>&1';
348+
$cmd = self::findExecutable() . ' -tt -y ' . $configFile . ' 2>&1';
349349
exec($cmd, $output, $code);
350+
if ($returnRaw) {
351+
return $output;
352+
}
350353
if ($code) {
351354
return preg_replace("/\[.+?\]/", "", $output[0]);
352355
}
@@ -537,7 +540,10 @@ class Tester
537540
string $scriptFilename = null
538541
) {
539542
if (is_null($uri)) {
540-
$uri = $this->makeSourceFile();
543+
if (is_null($scriptFilename)) {
544+
$scriptFilename = $this->makeSourceFile();
545+
}
546+
$uri = "/" . basename($scriptFilename);
541547
}
542548

543549
$params = array_merge(
@@ -1159,7 +1165,6 @@ class Tester
11591165
{
11601166
$filePath = $this->getFile($extension, $dir, $name);
11611167
file_put_contents($filePath, $content);
1162-
11631168
return $filePath;
11641169
}
11651170

‎sapi/fpm/www.conf.in

Lines changed: 10 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -343,6 +343,16 @@ pm.max_spare_servers = 3
343343
; Default: "%R - %u %t \"%m %r\" %s"
344344
;access.format = "%R - %u %t \"%m %r%Q%q\" %s %f %{milli}d %{kilo}M %C%%"
345345

346+
; A list of REQUEST_URI values which should be filtered from the access log.
347+
; As a security precuation, this setting will be ignored if:
348+
; - The request method is not GET or HEAD
349+
; - There is a request body
350+
; - There are query parameters
351+
; - The response code is not 200
352+
; Default Value: not set
353+
;access.suppress_path[] = /ping
354+
;access.suppress_path[] = /health_check.php
355+
346356
; The log file for slow requests
347357
; Default Value: not set
348358
; Note: slowlog is mandatory if request_slowlog_timeout is set

0 commit comments

Comments
 (0)