Skip to content

Commit cfb3e98

Browse files
bukkabukka
committed
FPM: Implement configurable access log limit
It sets the access log limit as configurable log_limit to allow larger log limit than the currently fixed limit of 1024 characters. Fixes phpGH-12302 Closes phpGH-18725
1 parent 35a4656 commit cfb3e98

File tree

7 files changed

+186
-89
lines changed

7 files changed

+186
-89
lines changed

‎NEWS‎

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -12,13 +12,15 @@ PHP NEWS
1212
. Add support for CURLINFO_QUEUE_TIME_T in curl_getinfo() (thecaliskan)
1313
. Add support for CURLOPT_SSL_SIGNATURE_ALGORITHMS. (Ayesh Karunaratne)
1414

15+
- FPM:
16+
. Make FPM access log limit configurable using log_limit. (Jakub Zelenka)
17+
1518
- GD:
1619
. Fix incorrect comparison with result of php_stream_can_cast(). (Girgias)
1720

1821
- Intl:
1922
. Fix return value on failure for resourcebundle count handler. (Girgias)
2023

21-
2224
- OPcache:
2325
. Disallow changing opcache.memory_consumption when SHM is already set up.
2426
(timwolla)

‎UPGRADING‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -298,6 +298,7 @@ PHP 8.5 UPGRADE NOTES
298298
- FPM:
299299
. FPM with httpd ProxyPass decodes the full script path. Added
300300
fastcgi.script_path_encoded INI setting to prevent this new behavior.
301+
. FPM access log limit now respects log_limit value.
301302

302303
========================================
303304
4. Deprecated Functionality

‎sapi/fpm/fpm/fpm_log.c‎

Lines changed: 49 additions & 63 deletions
Original file line numberDiff line numberDiff line change
@@ -24,6 +24,7 @@
2424
static char *fpm_log_format = NULL;
2525
static int fpm_log_fd = -1;
2626
static struct key_value_s *fpm_access_suppress_paths = NULL;
27+
static struct zlog_stream fpm_log_stream;
2728

2829
static int fpm_access_log_suppress(struct fpm_scoreboard_proc_s *proc);
2930

@@ -92,7 +93,8 @@ int fpm_log_init_child(struct fpm_worker_pool_s *wp) /* {{{ */
9293
if (fpm_log_fd == -1) {
9394
fpm_log_fd = wp->log_fd;
9495
}
95-
96+
zlog_stream_init_ex(&fpm_log_stream, ZLOG_ACCESS_LOG, fpm_log_fd);
97+
zlog_stream_set_wrapping(&fpm_log_stream, 0);
9698

9799
for (wp = fpm_worker_all_pools; wp; wp = wp->next) {
98100
if (wp->log_fd > -1 && wp->log_fd != fpm_log_fd) {
@@ -107,12 +109,11 @@ int fpm_log_init_child(struct fpm_worker_pool_s *wp) /* {{{ */
107109

108110
int fpm_log_write(char *log_format) /* {{{ */
109111
{
110-
char *s, *b;
111-
char buffer[FPM_LOG_BUFFER+1];
112-
int token, test;
113-
size_t len, len2;
112+
char *s;
113+
bool test, token = false;
114114
struct fpm_scoreboard_proc_s proc, *proc_p;
115115
struct fpm_scoreboard_s *scoreboard;
116+
struct zlog_stream *stream;
116117
char tmp[129];
117118
char format[129];
118119
time_t now_epoch;
@@ -126,9 +127,9 @@ int fpm_log_write(char *log_format) /* {{{ */
126127

127128
if (!log_format) {
128129
log_format = fpm_log_format;
129-
test = 0;
130+
test = false;
130131
} else {
131-
test = 1;
132+
test = true;
132133
}
133134

134135
now_epoch = time(NULL);
@@ -152,38 +153,25 @@ int fpm_log_write(char *log_format) /* {{{ */
152153
}
153154
}
154155

155-
token = 0;
156-
157-
memset(buffer, '\0', sizeof(buffer));
158-
b = buffer;
159-
len = 0;
160-
161156

162157
s = log_format;
158+
stream = &fpm_log_stream;
159+
zlog_stream_start(stream);
163160

164161
while (*s != '\0') {
165-
/* Test is we have place for 1 more char. */
166-
if (len >= FPM_LOG_BUFFER) {
167-
zlog(ZLOG_NOTICE, "the log buffer is full (%d). The access log request has been truncated.", FPM_LOG_BUFFER);
168-
len = FPM_LOG_BUFFER;
169-
break;
170-
}
171-
172162
if (!token && *s == '%') {
173-
token = 1;
163+
token = true;
174164
memset(format, '\0', sizeof(format)); /* reset format */
175165
s++;
176166
continue;
177167
}
178168

179169
if (token) {
180-
token = 0;
181-
len2 = 0;
170+
token = false;
182171
switch (*s) {
183172

184173
case '%': /* '%' */
185-
*b = '%';
186-
len2 = 1;
174+
zlog_stream_char(stream, '%');
187175
break;
188176

189177
#ifdef HAVE_TIMES
@@ -207,7 +195,7 @@ int fpm_log_write(char *log_format) /* {{{ */
207195

208196
format[0] = '\0';
209197
if (!test) {
210-
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.);
198+
zlog_stream_format(stream, "%.2f", tms_total / fpm_scoreboard_get_tick() / (proc.cpu_duration.tv_sec + proc.cpu_duration.tv_usec / 1000000.) * 100.);
211199
}
212200
break;
213201
#endif
@@ -216,7 +204,7 @@ int fpm_log_write(char *log_format) /* {{{ */
216204
/* seconds */
217205
if (format[0] == '\0' || !strcasecmp(format, "seconds")) {
218206
if (!test) {
219-
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%.3f", proc.duration.tv_sec + proc.duration.tv_usec / 1000000.);
207+
zlog_stream_format(stream, "%.3f", proc.duration.tv_sec + proc.duration.tv_usec / 1000000.);
220208
}
221209

222210
/* milliseconds */
@@ -225,13 +213,13 @@ int fpm_log_write(char *log_format) /* {{{ */
225213
!strcasecmp(format, "miliseconds") || !strcasecmp(format, "mili")
226214
) {
227215
if (!test) {
228-
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%.3f", proc.duration.tv_sec * 1000. + proc.duration.tv_usec / 1000.);
216+
zlog_stream_format(stream, "%.3f", proc.duration.tv_sec * 1000. + proc.duration.tv_usec / 1000.);
229217
}
230218

231219
/* microseconds */
232220
} else if (!strcasecmp(format, "microseconds") || !strcasecmp(format, "micro")) {
233221
if (!test) {
234-
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%lu", (unsigned long)(proc.duration.tv_sec * 1000000UL + proc.duration.tv_usec));
222+
zlog_stream_format(stream, "%lu", (unsigned long)(proc.duration.tv_sec * 1000000UL + proc.duration.tv_usec));
235223
}
236224

237225
} else {
@@ -249,46 +237,46 @@ int fpm_log_write(char *log_format) /* {{{ */
249237

250238
if (!test) {
251239
char *env = fcgi_getenv((fcgi_request*) SG(server_context), format, strlen(format));
252-
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%s", env ? env : "-");
240+
zlog_stream_cstr(stream, env ? env : "-");
253241
}
254242
format[0] = '\0';
255243
break;
256244

257245
case 'f': /* script */
258246
if (!test) {
259-
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%s", *proc.script_filename ? proc.script_filename : "-");
247+
zlog_stream_cstr(stream, *proc.script_filename ? proc.script_filename : "-");
260248
}
261249
break;
262250

263251
case 'l': /* content length */
264252
if (!test) {
265-
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%zu", proc.content_length);
253+
zlog_stream_format(stream, "%zu", proc.content_length);
266254
}
267255
break;
268256

269257
case 'm': /* method */
270258
if (!test) {
271-
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%s", *proc.request_method ? proc.request_method : "-");
259+
zlog_stream_cstr(stream, *proc.request_method ? proc.request_method : "-");
272260
}
273261
break;
274262

275263
case 'M': /* memory */
276264
/* seconds */
277265
if (format[0] == '\0' || !strcasecmp(format, "bytes")) {
278266
if (!test) {
279-
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%zu", proc.memory);
267+
zlog_stream_format(stream, "%zu", proc.memory);
280268
}
281269

282270
/* kilobytes */
283271
} else if (!strcasecmp(format, "kilobytes") || !strcasecmp(format, "kilo")) {
284272
if (!test) {
285-
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%zu", proc.memory / 1024);
273+
zlog_stream_format(stream, "%zu", proc.memory / 1024);
286274
}
287275

288276
/* megabytes */
289277
} else if (!strcasecmp(format, "megabytes") || !strcasecmp(format, "mega")) {
290278
if (!test) {
291-
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%zu", proc.memory / 1024 / 1024);
279+
zlog_stream_format(stream, "%zu", proc.memory / 1024 / 1024);
292280
}
293281

294282
} else {
@@ -300,7 +288,7 @@ int fpm_log_write(char *log_format) /* {{{ */
300288

301289
case 'n': /* pool name */
302290
if (!test) {
303-
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%s", scoreboard->pool[0] ? scoreboard->pool : "-");
291+
zlog_stream_cstr(stream, scoreboard->pool[0] ? scoreboard->pool : "-");
304292
}
305293
break;
306294

@@ -314,6 +302,7 @@ int fpm_log_write(char *log_format) /* {{{ */
314302
zend_llist_position pos;
315303
sapi_headers_struct *sapi_headers = &SG(sapi_headers);
316304
size_t format_len = strlen(format);
305+
ssize_t written = 0;
317306

318307
h = (sapi_header_struct*)zend_llist_get_first_ex(&sapi_headers->headers, &pos);
319308
while (h) {
@@ -339,59 +328,58 @@ int fpm_log_write(char *log_format) /* {{{ */
339328
}
340329

341330
header = h->header + format_len + 2;
342-
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%s", header && *header ? header : "-");
331+
written += zlog_stream_cstr(stream, header && *header ? header : "-");
343332

344333
/* found, done */
345334
break;
346335
}
347-
if (!len2) {
348-
len2 = 1;
349-
*b = '-';
336+
if (!written) {
337+
zlog_stream_char(stream, '-');
350338
}
351339
}
352340
format[0] = '\0';
353341
break;
354342

355343
case 'p': /* PID */
356344
if (!test) {
357-
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%ld", (long)getpid());
345+
zlog_stream_format(stream, "%ld", (long)getpid());
358346
}
359347
break;
360348

361349
case 'P': /* PID */
362350
if (!test) {
363-
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%ld", (long)getppid());
351+
zlog_stream_format(stream, "%ld", (long)getppid());
364352
}
365353
break;
366354

367355
case 'q': /* query_string */
368356
if (!test) {
369-
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%s", proc.query_string);
357+
zlog_stream_cstr(stream, proc.query_string);
370358
}
371359
break;
372360

373361
case 'Q': /* '?' */
374362
if (!test) {
375-
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%s", *proc.query_string ? "?" : "");
363+
zlog_stream_cstr(stream, *proc.query_string ? "?" : "");
376364
}
377365
break;
378366

379367
case 'r': /* request URI */
380368
if (!test) {
381-
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%s", proc.request_uri);
369+
zlog_stream_cstr(stream, proc.request_uri);
382370
}
383371
break;
384372

385373
case 'R': /* remote IP address */
386374
if (!test) {
387375
const char *tmp = fcgi_get_last_client_ip();
388-
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%s", tmp ? tmp : "-");
376+
zlog_stream_cstr(stream, tmp ? tmp : "-");
389377
}
390378
break;
391379

392380
case 's': /* status */
393381
if (!test) {
394-
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%d", SG(sapi_headers).http_response_code);
382+
zlog_stream_format(stream, "%d", SG(sapi_headers).http_response_code);
395383
}
396384
break;
397385

@@ -409,14 +397,14 @@ int fpm_log_write(char *log_format) /* {{{ */
409397
} else {
410398
strftime(tmp, sizeof(tmp) - 1, format, localtime(t));
411399
}
412-
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%s", tmp);
400+
zlog_stream_cstr(stream, tmp);
413401
}
414402
format[0] = '\0';
415403
break;
416404

417405
case 'u': /* remote user */
418406
if (!test) {
419-
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%s", proc.auth_user);
407+
zlog_stream_cstr(stream, proc.auth_user);
420408
}
421409
break;
422410

@@ -459,30 +447,28 @@ int fpm_log_write(char *log_format) /* {{{ */
459447
return -1;
460448
}
461449
s++;
462-
if (!test) {
463-
b += len2;
464-
len += len2;
465-
}
466-
if (len >= FPM_LOG_BUFFER) {
467-
zlog(ZLOG_NOTICE, "the log buffer is full (%d). The access log request has been truncated.", FPM_LOG_BUFFER);
468-
len = FPM_LOG_BUFFER;
450+
451+
if (zlog_stream_is_over_limit(stream)) {
452+
zlog(ZLOG_NOTICE, "the log buffer is over the configured limit. The access log request has been truncated.");
469453
break;
470454
}
471455
continue;
472456
}
473457

458+
if (zlog_stream_is_over_limit(stream)) {
459+
zlog(ZLOG_NOTICE, "the log buffer is over the configured limit. The access log request has been truncated.");
460+
break;
461+
}
462+
474463
if (!test) {
475464
// push the normal char to the output buffer
476-
*b = *s;
477-
b++;
478-
len++;
465+
zlog_stream_char(stream, *s);
479466
}
480467
s++;
481468
}
482469

483-
if (!test && strlen(buffer) > 0) {
484-
buffer[len] = '\n';
485-
zend_quiet_write(fpm_log_fd, buffer, len + 1);
470+
if (!test) {
471+
zlog_stream_finish(stream);
486472
}
487473

488474
return 0;

‎sapi/fpm/fpm/fpm_scoreboard.h‎

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -34,11 +34,11 @@ struct fpm_scoreboard_proc_s {
3434
struct timeval duration;
3535
time_t accepted_epoch;
3636
struct timeval tv;
37-
char request_uri[128];
38-
char query_string[512];
37+
char request_uri[512];
38+
char query_string[2048];
3939
char request_method[16];
4040
size_t content_length; /* used with POST only */
41-
char script_filename[256];
41+
char script_filename[512];
4242
char auth_user[32];
4343
#ifdef HAVE_TIMES
4444
struct tms cpu_accepted;

0 commit comments

Comments
 (0)