Skip to content

Commit abfe22b

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 8b61c49 commit abfe22b

File tree

3 files changed

+122
-85
lines changed

3 files changed

+122
-85
lines changed

‎sapi/fpm/fpm/fpm_log.c‎

Lines changed: 48 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,7 @@ 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);
9697

9798
for (wp = fpm_worker_all_pools; wp; wp = wp->next) {
9899
if (wp->log_fd > -1 && wp->log_fd != fpm_log_fd) {
@@ -107,12 +108,11 @@ int fpm_log_init_child(struct fpm_worker_pool_s *wp) /* {{{ */
107108

108109
int fpm_log_write(char *log_format) /* {{{ */
109110
{
110-
char *s, *b;
111-
char buffer[FPM_LOG_BUFFER+1];
112-
int token, test;
113-
size_t len, len2;
111+
char *s;
112+
bool test, token = false;
114113
struct fpm_scoreboard_proc_s proc, *proc_p;
115114
struct fpm_scoreboard_s *scoreboard;
115+
struct zlog_stream *stream;
116116
char tmp[129];
117117
char format[129];
118118
time_t now_epoch;
@@ -126,9 +126,9 @@ int fpm_log_write(char *log_format) /* {{{ */
126126

127127
if (!log_format) {
128128
log_format = fpm_log_format;
129-
test = 0;
129+
test = false;
130130
} else {
131-
test = 1;
131+
test = true;
132132
}
133133

134134
now_epoch = time(NULL);
@@ -152,38 +152,25 @@ int fpm_log_write(char *log_format) /* {{{ */
152152
}
153153
}
154154

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

162156
s = log_format;
157+
stream = &fpm_log_stream;
158+
zlog_stream_start(stream);
163159

164160
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-
172161
if (!token && *s == '%') {
173-
token = 1;
162+
token = true;
174163
memset(format, '\0', sizeof(format)); /* reset format */
175164
s++;
176165
continue;
177166
}
178167

179168
if (token) {
180-
token = 0;
181-
len2 = 0;
169+
token = false;
182170
switch (*s) {
183171

184172
case '%': /* '%' */
185-
*b = '%';
186-
len2 = 1;
173+
zlog_stream_char(stream, '%');
187174
break;
188175

189176
#ifdef HAVE_TIMES
@@ -207,7 +194,7 @@ int fpm_log_write(char *log_format) /* {{{ */
207194

208195
format[0] = '\0';
209196
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.);
197+
zlog_stream_format(stream, "%.2f", tms_total / fpm_scoreboard_get_tick() / (proc.cpu_duration.tv_sec + proc.cpu_duration.tv_usec / 1000000.) * 100.);
211198
}
212199
break;
213200
#endif
@@ -216,7 +203,7 @@ int fpm_log_write(char *log_format) /* {{{ */
216203
/* seconds */
217204
if (format[0] == '\0' || !strcasecmp(format, "seconds")) {
218205
if (!test) {
219-
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%.3f", proc.duration.tv_sec + proc.duration.tv_usec / 1000000.);
206+
zlog_stream_format(stream, "%.3f", proc.duration.tv_sec + proc.duration.tv_usec / 1000000.);
220207
}
221208

222209
/* milliseconds */
@@ -225,13 +212,13 @@ int fpm_log_write(char *log_format) /* {{{ */
225212
!strcasecmp(format, "miliseconds") || !strcasecmp(format, "mili")
226213
) {
227214
if (!test) {
228-
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%.3f", proc.duration.tv_sec * 1000. + proc.duration.tv_usec / 1000.);
215+
zlog_stream_format(stream, "%.3f", proc.duration.tv_sec * 1000. + proc.duration.tv_usec / 1000.);
229216
}
230217

231218
/* microseconds */
232219
} else if (!strcasecmp(format, "microseconds") || !strcasecmp(format, "micro")) {
233220
if (!test) {
234-
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%lu", (unsigned long)(proc.duration.tv_sec * 1000000UL + proc.duration.tv_usec));
221+
zlog_stream_format(stream, "%lu", (unsigned long)(proc.duration.tv_sec * 1000000UL + proc.duration.tv_usec));
235222
}
236223

237224
} else {
@@ -249,46 +236,46 @@ int fpm_log_write(char *log_format) /* {{{ */
249236

250237
if (!test) {
251238
char *env = fcgi_getenv((fcgi_request*) SG(server_context), format, strlen(format));
252-
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%s", env ? env : "-");
239+
zlog_stream_cstr(stream, env ? env : "-");
253240
}
254241
format[0] = '\0';
255242
break;
256243

257244
case 'f': /* script */
258245
if (!test) {
259-
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%s", *proc.script_filename ? proc.script_filename : "-");
246+
zlog_stream_cstr(stream, *proc.script_filename ? proc.script_filename : "-");
260247
}
261248
break;
262249

263250
case 'l': /* content length */
264251
if (!test) {
265-
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%zu", proc.content_length);
252+
zlog_stream_format(stream, "%zu", proc.content_length);
266253
}
267254
break;
268255

269256
case 'm': /* method */
270257
if (!test) {
271-
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%s", *proc.request_method ? proc.request_method : "-");
258+
zlog_stream_cstr(stream, *proc.request_method ? proc.request_method : "-");
272259
}
273260
break;
274261

275262
case 'M': /* memory */
276263
/* seconds */
277264
if (format[0] == '\0' || !strcasecmp(format, "bytes")) {
278265
if (!test) {
279-
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%zu", proc.memory);
266+
zlog_stream_format(stream, "%zu", proc.memory);
280267
}
281268

282269
/* kilobytes */
283270
} else if (!strcasecmp(format, "kilobytes") || !strcasecmp(format, "kilo")) {
284271
if (!test) {
285-
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%zu", proc.memory / 1024);
272+
zlog_stream_format(stream, "%zu", proc.memory / 1024);
286273
}
287274

288275
/* megabytes */
289276
} else if (!strcasecmp(format, "megabytes") || !strcasecmp(format, "mega")) {
290277
if (!test) {
291-
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%zu", proc.memory / 1024 / 1024);
278+
zlog_stream_format(stream, "%zu", proc.memory / 1024 / 1024);
292279
}
293280

294281
} else {
@@ -300,7 +287,7 @@ int fpm_log_write(char *log_format) /* {{{ */
300287

301288
case 'n': /* pool name */
302289
if (!test) {
303-
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%s", scoreboard->pool[0] ? scoreboard->pool : "-");
290+
zlog_stream_cstr(stream, scoreboard->pool[0] ? scoreboard->pool : "-");
304291
}
305292
break;
306293

@@ -314,6 +301,7 @@ int fpm_log_write(char *log_format) /* {{{ */
314301
zend_llist_position pos;
315302
sapi_headers_struct *sapi_headers = &SG(sapi_headers);
316303
size_t format_len = strlen(format);
304+
ssize_t written = 0;
317305

318306
h = (sapi_header_struct*)zend_llist_get_first_ex(&sapi_headers->headers, &pos);
319307
while (h) {
@@ -339,59 +327,58 @@ int fpm_log_write(char *log_format) /* {{{ */
339327
}
340328

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

344332
/* found, done */
345333
break;
346334
}
347-
if (!len2) {
348-
len2 = 1;
349-
*b = '-';
335+
if (!written) {
336+
zlog_stream_char(stream, '-');
350337
}
351338
}
352339
format[0] = '\0';
353340
break;
354341

355342
case 'p': /* PID */
356343
if (!test) {
357-
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%ld", (long)getpid());
344+
zlog_stream_format(stream, "%ld", (long)getpid());
358345
}
359346
break;
360347

361348
case 'P': /* PID */
362349
if (!test) {
363-
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%ld", (long)getppid());
350+
zlog_stream_format(stream, "%ld", (long)getppid());
364351
}
365352
break;
366353

367354
case 'q': /* query_string */
368355
if (!test) {
369-
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%s", proc.query_string);
356+
zlog_stream_cstr(stream, proc.query_string);
370357
}
371358
break;
372359

373360
case 'Q': /* '?' */
374361
if (!test) {
375-
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%s", *proc.query_string ? "?" : "");
362+
zlog_stream_cstr(stream, *proc.query_string ? "?" : "");
376363
}
377364
break;
378365

379366
case 'r': /* request URI */
380367
if (!test) {
381-
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%s", proc.request_uri);
368+
zlog_stream_cstr(stream, proc.request_uri);
382369
}
383370
break;
384371

385372
case 'R': /* remote IP address */
386373
if (!test) {
387374
const char *tmp = fcgi_get_last_client_ip();
388-
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%s", tmp ? tmp : "-");
375+
zlog_stream_cstr(stream, tmp ? tmp : "-");
389376
}
390377
break;
391378

392379
case 's': /* status */
393380
if (!test) {
394-
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%d", SG(sapi_headers).http_response_code);
381+
zlog_stream_format(stream, "%d", SG(sapi_headers).http_response_code);
395382
}
396383
break;
397384

@@ -409,14 +396,14 @@ int fpm_log_write(char *log_format) /* {{{ */
409396
} else {
410397
strftime(tmp, sizeof(tmp) - 1, format, localtime(t));
411398
}
412-
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%s", tmp);
399+
zlog_stream_cstr(stream, tmp);
413400
}
414401
format[0] = '\0';
415402
break;
416403

417404
case 'u': /* remote user */
418405
if (!test) {
419-
len2 = snprintf(b, FPM_LOG_BUFFER - len, "%s", proc.auth_user);
406+
zlog_stream_cstr(stream, proc.auth_user);
420407
}
421408
break;
422409

@@ -459,30 +446,28 @@ int fpm_log_write(char *log_format) /* {{{ */
459446
return -1;
460447
}
461448
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;
449+
450+
if (zlog_stream_is_over_limit(stream)) {
451+
zlog(ZLOG_NOTICE, "the log buffer is over the configured limit. The access log request has been truncated.");
469452
break;
470453
}
471454
continue;
472455
}
473456

457+
if (zlog_stream_is_over_limit(stream)) {
458+
zlog(ZLOG_NOTICE, "the log buffer is over the configured limit. The access log request has been truncated.");
459+
break;
460+
}
461+
474462
if (!test) {
475463
// push the normal char to the output buffer
476-
*b = *s;
477-
b++;
478-
len++;
464+
zlog_stream_char(stream, *s);
479465
}
480466
s++;
481467
}
482468

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

488473
return 0;

0 commit comments

Comments
 (0)