?  search:
summary | log | graphiclog1 | graphiclog2 | commit | commitdiff | tree | refs | edit | fork
blame | history | raw | HEAD
[mod_cgi] quiet trace if mod_cgi sends SIGTERM (fixes #2838)
[lighttpd.git] / src / mod_accesslog.c
blob3fc1503a12625028765232e6ef48124deddcf80c
1 #include "first.h"
2
3 #include "base.h"
4 #include "fdevent.h"
5 #include "log.h"
6 #include "buffer.h"
7
8 #include "plugin.h"
9
10 #include <sys/types.h>
11 #include <sys/stat.h>
12
13 #include <stdlib.h>
14 #include <string.h>
15 #include <fcntl.h>
16 #include <unistd.h>
17 #include <errno.h>
18 #include <time.h>
19
20 #ifdef HAVE_SYSLOG_H
21 # include <syslog.h>
22 #endif
23
24 typedef struct {
25 char key;
26 enum {
27 FORMAT_UNSET,
28 FORMAT_UNSUPPORTED,
29 FORMAT_PERCENT,
30 FORMAT_REMOTE_HOST,
31 FORMAT_REMOTE_IDENT,
32 FORMAT_REMOTE_USER,
33 FORMAT_TIMESTAMP,
34 FORMAT_REQUEST_LINE,
35 FORMAT_STATUS,
36 FORMAT_BYTES_OUT_NO_HEADER,
37 FORMAT_HEADER,
38
39 FORMAT_REMOTE_ADDR,
40 FORMAT_LOCAL_ADDR,
41 FORMAT_COOKIE,
42 FORMAT_TIME_USED_US,
43 FORMAT_ENV,
44 FORMAT_FILENAME,
45 FORMAT_REQUEST_PROTOCOL,
46 FORMAT_REQUEST_METHOD,
47 FORMAT_SERVER_PORT,
48 FORMAT_QUERY_STRING,
49 FORMAT_TIME_USED,
50 FORMAT_URL,
51 FORMAT_SERVER_NAME,
52 FORMAT_HTTP_HOST,
53 FORMAT_CONNECTION_STATUS,
54 FORMAT_BYTES_IN,
55 FORMAT_BYTES_OUT,
56
57 FORMAT_KEEPALIVE_COUNT,
58 FORMAT_RESPONSE_HEADER,
59 FORMAT_NOTE
60 } type;
61 } format_mapping;
62
63 /**
64 *
65 *
66 * "%h %l %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-Agent}i\""
67 *
68 */
69
70 static const format_mapping fmap[] =
71 {
72 { '%', FORMAT_PERCENT },
73 { 'h', FORMAT_REMOTE_HOST },
74 { 'l', FORMAT_REMOTE_IDENT },
75 { 'u', FORMAT_REMOTE_USER },
76 { 't', FORMAT_TIMESTAMP },
77 { 'r', FORMAT_REQUEST_LINE },
78 { 's', FORMAT_STATUS },
79 { 'b', FORMAT_BYTES_OUT_NO_HEADER },
80 { 'i', FORMAT_HEADER },
81
82 { 'a', FORMAT_REMOTE_ADDR },
83 { 'A', FORMAT_LOCAL_ADDR },
84 { 'B', FORMAT_BYTES_OUT_NO_HEADER },
85 { 'C', FORMAT_COOKIE },
86 { 'D', FORMAT_TIME_USED_US },
87 { 'e', FORMAT_ENV },
88 { 'f', FORMAT_FILENAME },
89 { 'H', FORMAT_REQUEST_PROTOCOL },
90 { 'k', FORMAT_KEEPALIVE_COUNT },
91 { 'm', FORMAT_REQUEST_METHOD },
92 { 'n', FORMAT_NOTE },
93 { 'p', FORMAT_SERVER_PORT },
94 { 'P', FORMAT_UNSUPPORTED }, /* we are only one process */
95 { 'q', FORMAT_QUERY_STRING },
96 { 'T', FORMAT_TIME_USED },
97 { 'U', FORMAT_URL }, /* w/o querystring */
98 { 'v', FORMAT_SERVER_NAME },
99 { 'V', FORMAT_HTTP_HOST },
100 { 'X', FORMAT_CONNECTION_STATUS },
101 { 'I', FORMAT_BYTES_IN },
102 { 'O', FORMAT_BYTES_OUT },
103
104 { 'o', FORMAT_RESPONSE_HEADER },
105
106 { '\0', FORMAT_UNSET }
107 };
108
109
110 enum e_optflags_time {
111 /* format string is passed to strftime unless other format optflags set
112 * (besides FORMAT_FLAG_TIME_BEGIN or FORMAT_FLAG_TIME_END) */
113 FORMAT_FLAG_TIME_END = 0x00,/* use request end time (default) */
114 FORMAT_FLAG_TIME_BEGIN = 0x01,/* use request start time */
115 FORMAT_FLAG_TIME_SEC = 0x02,/* request time as num sec since epoch */
116 FORMAT_FLAG_TIME_MSEC = 0x04,/* request time as num msec since epoch */
117 FORMAT_FLAG_TIME_USEC = 0x08,/* request time as num usec since epoch */
118 FORMAT_FLAG_TIME_NSEC = 0x10,/* request time as num nsec since epoch */
119 FORMAT_FLAG_TIME_MSEC_FRAC = 0x20,/* request time msec fraction */
120 FORMAT_FLAG_TIME_USEC_FRAC = 0x40,/* request time usec fraction */
121 FORMAT_FLAG_TIME_NSEC_FRAC = 0x80 /* request time nsec fraction */
122 };
123
124
125 typedef struct {
126 enum { FIELD_UNSET, FIELD_STRING, FIELD_FORMAT } type;
127
128 buffer *string;
129 int field;
130 int opt;
131 } format_field;
132
133 typedef struct {
134 format_field **ptr;
135
136 size_t used;
137 size_t size;
138 } format_fields;
139
140 typedef struct {
141 buffer *access_logfile;
142 int log_access_fd;
143 buffer *access_logbuffer; /* each logfile has a separate buffer */
144
145 unsigned short use_syslog; /* syslog has global buffer */
146 unsigned short syslog_level;
147
148 buffer *format;
149
150 time_t last_generated_accesslog_ts;
151 time_t *last_generated_accesslog_ts_ptr;
152
153 buffer *ts_accesslog_str;
154
155 format_fields *parsed_format;
156 } plugin_config;
157
158 typedef struct {
159 PLUGIN_DATA;
160
161 plugin_config **config_storage;
162 plugin_config conf;
163
164 buffer *syslog_logbuffer; /* syslog has global buffer. no caching, always written directly */
165 } plugin_data;
166
167 INIT_FUNC(mod_accesslog_init) {
168 plugin_data *p;
169
170 p = calloc(1, sizeof(*p));
171 p->syslog_logbuffer = buffer_init();
172
173 return p;
174 }
175
176 static void accesslog_write_all(server *srv, const buffer *filename, int fd, const void* buf, size_t count) {
177 if (-1 == write_all(fd, buf, count)) {
178 log_error_write(srv, __FILE__, __LINE__, "sbs",
179 "writing access log entry failed:", filename, strerror(errno));
180 }
181 }
182
183 static void accesslog_append_escaped(buffer *dest, buffer *str) {
184 char *ptr, *start, *end;
185
186 /* replaces non-printable chars with \xHH where HH is the hex representation of the byte */
187 /* exceptions: " => \", \ => \\, whitespace chars => \n \t etc. */
188 if (buffer_string_is_empty(str)) return;
189 buffer_string_prepare_append(dest, buffer_string_length(str));
190
191 for (ptr = start = str->ptr, end = str->ptr + buffer_string_length(str); ptr < end; ptr++) {
192 unsigned char const c = (unsigned char) *ptr;
193 if (c >= ' ' && c <= '~' && c != '"' && c != '\\') {
194 /* nothing to change, add later as one block */
195 } else {
196 /* copy previous part */
197 if (start < ptr) {
198 buffer_append_string_len(dest, start, ptr - start);
199 }
200 start = ptr + 1;
201
202 switch (c) {
203 case '"':
204 BUFFER_APPEND_STRING_CONST(dest, "\\\"");
205 break;
206 case '\\':
207 BUFFER_APPEND_STRING_CONST(dest, "\\\\");
208 break;
209 case '\b':
210 BUFFER_APPEND_STRING_CONST(dest, "\\b");
211 break;
212 case '\n':
213 BUFFER_APPEND_STRING_CONST(dest, "\\n");
214 break;
215 case '\r':
216 BUFFER_APPEND_STRING_CONST(dest, "\\r");
217 break;
218 case '\t':
219 BUFFER_APPEND_STRING_CONST(dest, "\\t");
220 break;
221 case '\v':
222 BUFFER_APPEND_STRING_CONST(dest, "\\v");
223 break;
224 default: {
225 /* non printable char => \xHH */
226 char hh[5] = {'\\','x',0,0,0};
227 char h = c / 16;
228 hh[2] = (h > 9) ? (h - 10 + 'A') : (h + '0');
229 h = c % 16;
230 hh[3] = (h > 9) ? (h - 10 + 'A') : (h + '0');
231 buffer_append_string_len(dest, &hh[0], 4);
232 }
233 break;
234 }
235 }
236 }
237
238 if (start < end) {
239 buffer_append_string_len(dest, start, end - start);
240 }
241 }
242
243 static int accesslog_parse_format(server *srv, format_fields *fields, buffer *format) {
244 size_t i, j, k = 0, start = 0;
245
246 if (buffer_is_empty(format)) return -1;
247
248 for (i = 0; i < buffer_string_length(format); i++) {
249 switch(format->ptr[i]) {
250 case '%':
251 if (i > 0 && start != i) {
252 /* copy the string before this % */
253 if (fields->size == 0) {
254 fields->size = 16;
255 fields->used = 0;
256 fields->ptr = malloc(fields->size * sizeof(format_field * ));
257 } else if (fields->used == fields->size) {
258 fields->size += 16;
259 fields->ptr = realloc(fields->ptr, fields->size * sizeof(format_field * ));
260 }
261
262 fields->ptr[fields->used] = malloc(sizeof(format_field));
263 fields->ptr[fields->used]->type = FIELD_STRING;
264 fields->ptr[fields->used]->string = buffer_init();
265
266 buffer_copy_string_len(fields->ptr[fields->used]->string, format->ptr + start, i - start);
267
268 fields->used++;
269 }
270
271 /* we need a new field */
272
273 if (fields->size == 0) {
274 fields->size = 16;
275 fields->used = 0;
276 fields->ptr = malloc(fields->size * sizeof(format_field * ));
277 } else if (fields->used == fields->size) {
278 fields->size += 16;
279 fields->ptr = realloc(fields->ptr, fields->size * sizeof(format_field * ));
280 }
281
282 /* search for the terminating command */
283 switch (format->ptr[i+1]) {
284 case '>':
285 case '<':
286 /* after the } has to be a character */
287 if (format->ptr[i+2] == '\0') {
288 log_error_write(srv, __FILE__, __LINE__, "s", "%< and %> have to be followed by a format-specifier");
289 return -1;
290 }
291
292
293 for (j = 0; fmap[j].key != '\0'; j++) {
294 if (fmap[j].key != format->ptr[i+2]) continue;
295
296 /* found key */
297
298 fields->ptr[fields->used] = malloc(sizeof(format_field));
299 fields->ptr[fields->used]->type = FIELD_FORMAT;
300 fields->ptr[fields->used]->field = fmap[j].type;
301 fields->ptr[fields->used]->string = NULL;
302 fields->ptr[fields->used]->opt = 0;
303
304 fields->used++;
305
306 break;
307 }
308
309 if (fmap[j].key == '\0') {
310 log_error_write(srv, __FILE__, __LINE__, "s", "%< and %> have to be followed by a valid format-specifier");
311 return -1;
312 }
313
314 start = i + 3;
315 i = start - 1; /* skip the string */
316
317 break;
318 case '{':
319 /* go forward to } */
320
321 for (k = i+2; k < buffer_string_length(format); k++) {
322 if (format->ptr[k] == '}') break;
323 }
324
325 if (k == buffer_string_length(format)) {
326 log_error_write(srv, __FILE__, __LINE__, "s", "%{ has to be terminated by a }");
327 return -1;
328 }
329
330 /* after the } has to be a character */
331 if (format->ptr[k+1] == '\0') {
332 log_error_write(srv, __FILE__, __LINE__, "s", "%{...} has to be followed by a format-specifier");
333 return -1;
334 }
335
336 if (k == i + 2) {
337 log_error_write(srv, __FILE__, __LINE__, "s", "%{...} has to be contain a string");
338 return -1;
339 }
340
341 for (j = 0; fmap[j].key != '\0'; j++) {
342 if (fmap[j].key != format->ptr[k+1]) continue;
343
344 /* found key */
345
346 fields->ptr[fields->used] = malloc(sizeof(format_field));
347 fields->ptr[fields->used]->type = FIELD_FORMAT;
348 fields->ptr[fields->used]->field = fmap[j].type;
349 fields->ptr[fields->used]->string = buffer_init();
350 fields->ptr[fields->used]->opt = 0;
351
352 buffer_copy_string_len(fields->ptr[fields->used]->string, format->ptr + i + 2, k - (i + 2));
353
354 fields->used++;
355
356 break;
357 }
358
359 if (fmap[j].key == '\0') {
360 log_error_write(srv, __FILE__, __LINE__, "s", "%{...} has to be followed by a valid format-specifier");
361 return -1;
362 }
363
364 start = k + 2;
365 i = start - 1; /* skip the string */
366
367 break;
368 default:
369 /* after the % has to be a character */
370 if (format->ptr[i+1] == '\0') {
371 log_error_write(srv, __FILE__, __LINE__, "s", "% has to be followed by a format-specifier");
372 return -1;
373 }
374
375 for (j = 0; fmap[j].key != '\0'; j++) {
376 if (fmap[j].key != format->ptr[i+1]) continue;
377
378 /* found key */
379
380 fields->ptr[fields->used] = malloc(sizeof(format_field));
381 fields->ptr[fields->used]->type = FIELD_FORMAT;
382 fields->ptr[fields->used]->field = fmap[j].type;
383 fields->ptr[fields->used]->string = NULL;
384 fields->ptr[fields->used]->opt = 0;
385
386 fields->used++;
387
388 break;
389 }
390
391 if (fmap[j].key == '\0') {
392 log_error_write(srv, __FILE__, __LINE__, "s", "% has to be followed by a valid format-specifier");
393 return -1;
394 }
395
396 start = i + 2;
397 i = start - 1; /* skip the string */
398
399 break;
400 }
401
402 break;
403 }
404 }
405
406 if (start < i) {
407 /* copy the string */
408 if (fields->size == 0) {
409 fields->size = 16;
410 fields->used = 0;
411 fields->ptr = malloc(fields->size * sizeof(format_field * ));
412 } else if (fields->used == fields->size) {
413 fields->size += 16;
414 fields->ptr = realloc(fields->ptr, fields->size * sizeof(format_field * ));
415 }
416
417 fields->ptr[fields->used] = malloc(sizeof(format_field));
418 fields->ptr[fields->used]->type = FIELD_STRING;
419 fields->ptr[fields->used]->string = buffer_init();
420
421 buffer_copy_string_len(fields->ptr[fields->used]->string, format->ptr + start, i - start);
422
423 fields->used++;
424 }
425
426 return 0;
427 }
428
429 FREE_FUNC(mod_accesslog_free) {
430 plugin_data *p = p_d;
431 size_t i;
432
433 if (!p) return HANDLER_GO_ON;
434
435 if (p->config_storage) {
436
437 for (i = 0; i < srv->config_context->used; i++) {
438 plugin_config *s = p->config_storage[i];
439
440 if (NULL == s) continue;
441
442 if (!buffer_string_is_empty(s->access_logbuffer)) {
443 if (s->log_access_fd != -1) {
444 accesslog_write_all(srv, s->access_logfile, s->log_access_fd, CONST_BUF_LEN(s->access_logbuffer));
445 }
446 }
447
448 if (s->log_access_fd != -1) {
449 if (buffer_string_is_empty(s->access_logfile) || *s->access_logfile->ptr != '|') {
450 close(s->log_access_fd);
451 } /*(else piped loggers closed in fdevent_close_logger_pipes())*/
452 }
453
454 buffer_free(s->ts_accesslog_str);
455 buffer_free(s->access_logbuffer);
456 buffer_free(s->format);
457 buffer_free(s->access_logfile);
458
459 if (s->parsed_format) {
460 size_t j;
461 for (j = 0; j < s->parsed_format->used; j++) {
462 if (s->parsed_format->ptr[j]->string) buffer_free(s->parsed_format->ptr[j]->string);
463 free(s->parsed_format->ptr[j]);
464 }
465 free(s->parsed_format->ptr);
466 free(s->parsed_format);
467 }
468
469 free(s);
470 }
471
472 free(p->config_storage);
473 }
474
475 if (p->syslog_logbuffer) buffer_free(p->syslog_logbuffer);
476 free(p);
477
478 return HANDLER_GO_ON;
479 }
480
481 SETDEFAULTS_FUNC(log_access_open) {
482 plugin_data *p = p_d;
483 size_t i = 0;
484
485 config_values_t cv[] = {
486 { "accesslog.filename", NULL, T_CONFIG_STRING, T_CONFIG_SCOPE_CONNECTION },
487 { "accesslog.use-syslog", NULL, T_CONFIG_BOOLEAN, T_CONFIG_SCOPE_CONNECTION },
488 { "accesslog.format", NULL, T_CONFIG_STRING, T_CONFIG_SCOPE_CONNECTION },
489 { "accesslog.syslog-level", NULL, T_CONFIG_SHORT, T_CONFIG_SCOPE_CONNECTION },
490 { NULL, NULL, T_CONFIG_UNSET, T_CONFIG_SCOPE_UNSET }
491 };
492
493 if (!p) return HANDLER_ERROR;
494
495 p->config_storage = calloc(1, srv->config_context->used * sizeof(plugin_config *));
496
497 for (i = 0; i < srv->config_context->used; i++) {
498 data_config const* config = (data_config const*)srv->config_context->data[i];
499 plugin_config *s;
500
501 s = calloc(1, sizeof(plugin_config));
502 s->access_logfile = buffer_init();
503 s->format = buffer_init();
504 s->access_logbuffer = buffer_init();
505 s->ts_accesslog_str = buffer_init();
506 s->log_access_fd = -1;
507 s->last_generated_accesslog_ts = 0;
508 s->last_generated_accesslog_ts_ptr = &(s->last_generated_accesslog_ts);
509 s->syslog_level = LOG_INFO;
510
511
512 cv[0].destination = s->access_logfile;
513 cv[1].destination = &(s->use_syslog);
514 cv[2].destination = s->format;
515 cv[3].destination = &(s->syslog_level);
516
517 p->config_storage[i] = s;
518
519 if (0 != config_insert_values_global(srv, config->value, cv, i == 0 ? T_CONFIG_SCOPE_SERVER : T_CONFIG_SCOPE_CONNECTION)) {
520 return HANDLER_ERROR;
521 }
522
523 if (i == 0 && buffer_string_is_empty(s->format)) {
524 /* set a default logfile string */
525
526 buffer_copy_string_len(s->format, CONST_STR_LEN("%h %V %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-Agent}i\""));
527 }
528
529 /* parse */
530
531 if (!buffer_is_empty(s->format)) {
532 size_t j, tcount = 0;
533
534 s->parsed_format = calloc(1, sizeof(*(s->parsed_format)));
535
536 if (-1 == accesslog_parse_format(srv, s->parsed_format, s->format)) {
537
538 log_error_write(srv, __FILE__, __LINE__, "sb",
539 "parsing accesslog-definition failed:", s->format);
540
541 return HANDLER_ERROR;
542 }
543
544 for (j = 0; j < s->parsed_format->used; ++j) {
545 format_field * const f = s->parsed_format->ptr[j];
546 if (FIELD_FORMAT != f->type) continue;
547 if (FORMAT_TIMESTAMP == f->field) {
548 if (!buffer_string_is_empty(f->string)) {
549 const char *ptr = f->string->ptr;
550 if (0 == strncmp(ptr, "begin:", sizeof("begin:")-1)) {
551 f->opt |= FORMAT_FLAG_TIME_BEGIN;
552 ptr += sizeof("begin:")-1;
553 } else if (0 == strncmp(ptr, "end:", sizeof("end:")-1)) {
554 f->opt |= FORMAT_FLAG_TIME_END;
555 ptr += sizeof("end:")-1;
556 }
557 if (0 == strcmp(ptr, "sec")) f->opt |= FORMAT_FLAG_TIME_SEC;
558 else if (0 == strcmp(ptr, "msec")) f->opt |= FORMAT_FLAG_TIME_MSEC;
559 else if (0 == strcmp(ptr, "usec")) f->opt |= FORMAT_FLAG_TIME_USEC;
560 else if (0 == strcmp(ptr, "nsec")) f->opt |= FORMAT_FLAG_TIME_NSEC;
561 else if (0 == strcmp(ptr, "msec_frac")) f->opt |= FORMAT_FLAG_TIME_MSEC_FRAC;
562 else if (0 == strcmp(ptr, "usec_frac")) f->opt |= FORMAT_FLAG_TIME_USEC_FRAC;
563 else if (0 == strcmp(ptr, "nsec_frac")) f->opt |= FORMAT_FLAG_TIME_NSEC_FRAC;
564 else if (NULL == strchr(ptr, '%')) {
565 log_error_write(srv, __FILE__, __LINE__, "sb",
566 "constant string for time format (misspelled token? or missing '%'):", s->format);
567
568 return HANDLER_ERROR;
569 }
570 }
571
572 /* make sure they didn't try to send the timestamp in twice
573 * (would invalidate s->ts_accesslog_str cache of timestamp str) */
574 if (!(f->opt & ~(FORMAT_FLAG_TIME_BEGIN|FORMAT_FLAG_TIME_END|FORMAT_FLAG_TIME_SEC)) && ++tcount > 1) {
575 log_error_write(srv, __FILE__, __LINE__, "sb",
576 "you may not use strftime timestamp format %{}t twice in the same access log:", s->format);
577
578 return HANDLER_ERROR;
579 }
580
581 if (f->opt & FORMAT_FLAG_TIME_BEGIN) srv->srvconf.high_precision_timestamps = 1;
582 } else if (FORMAT_TIME_USED_US == f->field) {
583 f->opt |= FORMAT_FLAG_TIME_USEC;
584 srv->srvconf.high_precision_timestamps = 1;
585 } else if (FORMAT_TIME_USED == f->field) {
586 if (buffer_string_is_empty(f->string)
587 || buffer_is_equal_string(f->string, CONST_STR_LEN("s"))
588 || buffer_is_equal_string(f->string, CONST_STR_LEN("sec"))) f->opt |= FORMAT_FLAG_TIME_SEC;
589 else if (buffer_is_equal_string(f->string, CONST_STR_LEN("ms"))
590 || buffer_is_equal_string(f->string, CONST_STR_LEN("msec"))) f->opt |= FORMAT_FLAG_TIME_MSEC;
591 else if (buffer_is_equal_string(f->string, CONST_STR_LEN("us"))
592 || buffer_is_equal_string(f->string, CONST_STR_LEN("usec"))) f->opt |= FORMAT_FLAG_TIME_USEC;
593 else if (buffer_is_equal_string(f->string, CONST_STR_LEN("ns"))
594 || buffer_is_equal_string(f->string, CONST_STR_LEN("nsec"))) f->opt |= FORMAT_FLAG_TIME_NSEC;
595 else {
596 log_error_write(srv, __FILE__, __LINE__, "sb",
597 "invalid time unit in %{UNIT}T:", s->format);
598
599 return HANDLER_ERROR;
600 }
601
602 if (f->opt & ~(FORMAT_FLAG_TIME_SEC)) srv->srvconf.high_precision_timestamps = 1;
603 } else if (FORMAT_COOKIE == f->field) {
604 if (buffer_string_is_empty(f->string)) f->type = FIELD_STRING; /*(blank)*/
605 }
606 }
607
608 #if 0
609 /* debugging */
610 for (j = 0; j < s->parsed_format->used; j++) {
611 switch (s->parsed_format->ptr[j]->type) {
612 case FIELD_FORMAT:
613 log_error_write(srv, __FILE__, __LINE__, "ssds",
614 "config:", "format", s->parsed_format->ptr[j]->field,
615 s->parsed_format->ptr[j]->string ?
616 s->parsed_format->ptr[j]->string->ptr : "" );
617 break;
618 case FIELD_STRING:
619 log_error_write(srv, __FILE__, __LINE__, "ssbs", "config:", "string '", s->parsed_format->ptr[j]->string, "'");
620 break;
621 default:
622 break;
623 }
624 }
625 #endif
626 }
627
628 if (s->use_syslog) {
629 /* ignore the next checks */
630 continue;
631 }
632
633 if (buffer_string_is_empty(s->access_logfile)) continue;
634
635 if (srv->srvconf.preflight_check) continue;
636
637 if (-1 == (s->log_access_fd = fdevent_open_logger(s->access_logfile->ptr))) {
638 log_error_write(srv, __FILE__, __LINE__, "SBSS",
639 "opening log '", s->access_logfile,
640 "' failed: ", strerror(errno));
641 return HANDLER_ERROR;
642 }
643 }
644
645 return HANDLER_GO_ON;
646 }
647
648 static void log_access_flush(server *srv, void *p_d) {
649 plugin_data *p = p_d;
650 size_t i;
651
652 for (i = 0; i < srv->config_context->used; i++) {
653 plugin_config *s = p->config_storage[i];
654
655 if (!buffer_string_is_empty(s->access_logbuffer)) {
656 if (s->log_access_fd != -1) {
657 accesslog_write_all(srv, s->access_logfile, s->log_access_fd, CONST_BUF_LEN(s->access_logbuffer));
658 }
659
660 buffer_reset(s->access_logbuffer);
661 }
662 }
663 }
664
665 TRIGGER_FUNC(log_access_periodic_flush) {
666 /* flush buffered access logs every 4 seconds */
667 if (0 == (srv->cur_ts & 3)) log_access_flush(srv, p_d);
668 return HANDLER_GO_ON;
669 }
670
671 SIGHUP_FUNC(log_access_cycle) {
672 plugin_data *p = p_d;
673 size_t i;
674
675 if (!p->config_storage) return HANDLER_GO_ON;
676
677 log_access_flush(srv, p);
678
679 for (i = 0; i < srv->config_context->used; i++) {
680 plugin_config *s = p->config_storage[i];
681 if (s->use_syslog == 0
682 && !buffer_string_is_empty(s->access_logfile)
683 && s->access_logfile->ptr[0] != '|') {
684
685 if (-1 == fdevent_cycle_logger(s->access_logfile->ptr, &s->log_access_fd)) {
686 log_error_write(srv, __FILE__, __LINE__, "ss", "cycling access-log failed:", strerror(errno));
687 return HANDLER_ERROR;
688 }
689 }
690 }
691
692 return HANDLER_GO_ON;
693 }
694
695 #define PATCH(x) \
696 p->conf.x = s->x;
697 static int mod_accesslog_patch_connection(server *srv, connection *con, plugin_data *p) {
698 size_t i, j;
699 plugin_config *s = p->config_storage[0];
700
701 PATCH(access_logfile);
702 PATCH(log_access_fd);
703 PATCH(last_generated_accesslog_ts_ptr);
704 PATCH(access_logbuffer);
705 PATCH(ts_accesslog_str);
706 PATCH(parsed_format);
707 PATCH(use_syslog);
708 PATCH(syslog_level);
709
710 /* skip the first, the global context */
711 for (i = 1; i < srv->config_context->used; i++) {
712 data_config *dc = (data_config *)srv->config_context->data[i];
713 s = p->config_storage[i];
714
715 /* condition didn't match */
716 if (!config_check_cond(srv, con, dc)) continue;
717
718 /* merge config */
719 for (j = 0; j < dc->value->used; j++) {
720 data_unset *du = dc->value->data[j];
721
722 if (buffer_is_equal_string(du->key, CONST_STR_LEN("accesslog.filename"))) {
723 PATCH(access_logfile);
724 PATCH(log_access_fd);
725 PATCH(access_logbuffer);
726 } else if (buffer_is_equal_string(du->key, CONST_STR_LEN("accesslog.format"))) {
727 PATCH(parsed_format);
728 PATCH(last_generated_accesslog_ts_ptr);
729 PATCH(ts_accesslog_str);
730 } else if (buffer_is_equal_string(du->key, CONST_STR_LEN("accesslog.use-syslog"))) {
731 PATCH(use_syslog);
732 } else if (buffer_is_equal_string(du->key, CONST_STR_LEN("accesslog.syslog-level"))) {
733 PATCH(syslog_level);
734 }
735 }
736 }
737
738 return 0;
739 }
740 #undef PATCH
741
742 REQUESTDONE_FUNC(log_access_write) {
743 plugin_data *p = p_d;
744 buffer *b;
745 size_t j;
746
747 int newts = 0;
748 data_string *ds;
749 struct timespec ts = { 0, 0 };
750
751 mod_accesslog_patch_connection(srv, con, p);
752
753 /* No output device, nothing to do */
754 if (!p->conf.use_syslog && p->conf.log_access_fd == -1) return HANDLER_GO_ON;
755
756 if (p->conf.use_syslog) {
757 b = p->syslog_logbuffer;
758 } else {
759 b = p->conf.access_logbuffer;
760 }
761
762 if (buffer_is_empty(b)) {
763 buffer_string_set_length(b, 0);
764 }
765
766 for (j = 0; j < p->conf.parsed_format->used; j++) {
767 const format_field * const f = p->conf.parsed_format->ptr[j];
768 switch(f->type) {
769 case FIELD_STRING:
770 buffer_append_string_buffer(b, f->string);
771 break;
772 case FIELD_FORMAT:
773 switch(f->field) {
774 case FORMAT_TIMESTAMP:
775
776 if (f->opt & ~(FORMAT_FLAG_TIME_BEGIN|FORMAT_FLAG_TIME_END)) {
777 if (f->opt & FORMAT_FLAG_TIME_SEC) {
778 time_t t = (!(f->opt & FORMAT_FLAG_TIME_BEGIN)) ? srv->cur_ts : con->request_start;
779 buffer_append_int(b, (intmax_t)t);
780 } else if (f->opt & (FORMAT_FLAG_TIME_MSEC|FORMAT_FLAG_TIME_USEC|FORMAT_FLAG_TIME_NSEC)) {
781 off_t t; /*(expected to be 64-bit since large file support enabled)*/
782 long ns;
783 if (!(f->opt & FORMAT_FLAG_TIME_BEGIN)) {
784 if (0 == ts.tv_sec) log_clock_gettime_realtime(&ts);
785 t = (off_t)ts.tv_sec;
786 ns = ts.tv_nsec;
787 } else {
788 t = (off_t)con->request_start_hp.tv_sec;
789 ns = con->request_start_hp.tv_nsec;
790 }
791 if (f->opt & FORMAT_FLAG_TIME_MSEC) {
792 t *= 1000;
793 t += (ns + 999999) / 1000000; /* ceil */
794 } else if (f->opt & FORMAT_FLAG_TIME_USEC) {
795 t *= 1000000;
796 t += (ns + 999) / 1000; /* ceil */
797 } else {/*(f->opt & FORMAT_FLAG_TIME_NSEC)*/
798 t *= 1000000000;
799 t += ns;
800 }
801 buffer_append_int(b, (intmax_t)t);
802 } else { /*(FORMAT_FLAG_TIME_MSEC_FRAC|FORMAT_FLAG_TIME_USEC_FRAC|FORMAT_FLAG_TIME_NSEC_FRAC)*/
803 long ns;
804 char *ptr;
805 if (!(f->opt & FORMAT_FLAG_TIME_BEGIN)) {
806 if (0 == ts.tv_sec) log_clock_gettime_realtime(&ts);
807 ns = ts.tv_nsec;
808 } else {
809 ns = con->request_start_hp.tv_nsec;
810 }
811 /*assert(t < 1000000000);*/
812 if (f->opt & FORMAT_FLAG_TIME_MSEC_FRAC) {
813 ns += 999999; /* ceil */
814 ns /= 1000000;
815 buffer_append_string_len(b, CONST_STR_LEN("000"));
816 } else if (f->opt & FORMAT_FLAG_TIME_USEC_FRAC) {
817 ns += 999; /* ceil */
818 ns /= 1000;
819 buffer_append_string_len(b, CONST_STR_LEN("000000"));
820 } else {/*(f->opt & FORMAT_FLAG_TIME_NSEC_FRAC)*/
821 buffer_append_string_len(b, CONST_STR_LEN("000000000"));
822 }
823 for (ptr = b->ptr + buffer_string_length(b); ns > 0; ns /= 10)
824 *--ptr = (ns % 10) + '0';
825 }
826 } else if (!(f->opt & FORMAT_FLAG_TIME_BEGIN) && srv->cur_ts == *(p->conf.last_generated_accesslog_ts_ptr)) {
827 buffer_append_string_buffer(b, p->conf.ts_accesslog_str);
828 } else {
829 /* cache the generated timestamp (only if ! FORMAT_FLAG_TIME_BEGIN) */
830 struct tm *tmptr;
831 time_t t;
832 #if defined(HAVE_STRUCT_TM_GMTOFF)
833 # ifdef HAVE_LOCALTIME_R
834 struct tm tm;
835 # endif /* HAVE_LOCALTIME_R */
836 #else /* HAVE_STRUCT_TM_GMTOFF */
837 # ifdef HAVE_GMTIME_R
838 struct tm tm;
839 # endif /* HAVE_GMTIME_R */
840 #endif /* HAVE_STRUCT_TM_GMTOFF */
841
842 if (!(f->opt & FORMAT_FLAG_TIME_BEGIN)) {
843 t = *(p->conf.last_generated_accesslog_ts_ptr) = srv->cur_ts;
844 newts = 1;
845 } else {
846 t = con->request_start;
847 }
848
849 #if defined(HAVE_STRUCT_TM_GMTOFF)
850 # ifdef HAVE_LOCALTIME_R
851 tmptr = localtime_r(&t, &tm);
852 # else /* HAVE_LOCALTIME_R */
853 tmptr = localtime(&t);
854 # endif /* HAVE_LOCALTIME_R */
855 #else /* HAVE_STRUCT_TM_GMTOFF */
856 # ifdef HAVE_GMTIME_R
857 tmptr = gmtime_r(&t, &tm);
858 # else /* HAVE_GMTIME_R */
859 tmptr = gmtime(&t);
860 # endif /* HAVE_GMTIME_R */
861 #endif /* HAVE_STRUCT_TM_GMTOFF */
862
863 buffer_string_prepare_copy(p->conf.ts_accesslog_str, 255);
864
865 if (buffer_string_is_empty(f->string)) {
866 #if defined(HAVE_STRUCT_TM_GMTOFF)
867 long scd, hrs, min;
868 buffer_append_strftime(p->conf.ts_accesslog_str, "[%d/%b/%Y:%H:%M:%S ", tmptr);
869 buffer_append_string_len(p->conf.ts_accesslog_str, tmptr->tm_gmtoff >= 0 ? "+" : "-", 1);
870
871 scd = labs(tmptr->tm_gmtoff);
872 hrs = scd / 3600;
873 min = (scd % 3600) / 60;
874
875 /* hours */
876 if (hrs < 10) buffer_append_string_len(p->conf.ts_accesslog_str, CONST_STR_LEN("0"));
877 buffer_append_int(p->conf.ts_accesslog_str, hrs);
878
879 if (min < 10) buffer_append_string_len(p->conf.ts_accesslog_str, CONST_STR_LEN("0"));
880 buffer_append_int(p->conf.ts_accesslog_str, min);
881 buffer_append_string_len(p->conf.ts_accesslog_str, CONST_STR_LEN("]"));
882 #else
883 buffer_append_strftime(p->conf.ts_accesslog_str, "[%d/%b/%Y:%H:%M:%S +0000]", tmptr);
884 #endif /* HAVE_STRUCT_TM_GMTOFF */
885 } else {
886 buffer_append_strftime(p->conf.ts_accesslog_str, f->string->ptr, tmptr);
887 }
888
889 buffer_append_string_buffer(b, p->conf.ts_accesslog_str);
890 }
891 break;
892 case FORMAT_TIME_USED:
893 case FORMAT_TIME_USED_US:
894 if (f->opt & FORMAT_FLAG_TIME_SEC) {
895 buffer_append_int(b, srv->cur_ts - con->request_start);
896 } else {
897 const struct timespec * const bs = &con->request_start_hp;
898 off_t tdiff; /*(expected to be 64-bit since large file support enabled)*/
899 if (0 == ts.tv_sec) log_clock_gettime_realtime(&ts);
900 tdiff = (off_t)(ts.tv_sec - bs->tv_sec)*1000000000 + (ts.tv_nsec - bs->tv_nsec);
901 if (tdiff <= 0) {
902 /* sanity check for time moving backwards
903 * (daylight savings adjustment or leap seconds or ?) */
904 tdiff = -1;
905 } else if (f->opt & FORMAT_FLAG_TIME_MSEC) {
906 tdiff += 999999; /* ceil */
907 tdiff /= 1000000;
908 } else if (f->opt & FORMAT_FLAG_TIME_USEC) {
909 tdiff += 999; /* ceil */
910 tdiff /= 1000;
911 } /* else (f->opt & FORMAT_FLAG_TIME_NSEC) */
912 buffer_append_int(b, (intmax_t)tdiff);
913 }
914 break;
915 case FORMAT_REMOTE_ADDR:
916 case FORMAT_REMOTE_HOST:
917 buffer_append_string_buffer(b, con->dst_addr_buf);
918 break;
919 case FORMAT_REMOTE_IDENT:
920 /* ident */
921 buffer_append_string_len(b, CONST_STR_LEN("-"));
922 break;
923 case FORMAT_REMOTE_USER:
924 if (NULL != (ds = (data_string *)array_get_element(con->environment, "REMOTE_USER")) && !buffer_string_is_empty(ds->value)) {
925 accesslog_append_escaped(b, ds->value);
926 } else {
927 buffer_append_string_len(b, CONST_STR_LEN("-"));
928 }
929 break;
930 case FORMAT_REQUEST_LINE:
931 if (!buffer_string_is_empty(con->request.request_line)) {
932 accesslog_append_escaped(b, con->request.request_line);
933 }
934 break;
935 case FORMAT_STATUS:
936 buffer_append_int(b, con->http_status);
937 break;
938
939 case FORMAT_BYTES_OUT_NO_HEADER:
940 if (con->bytes_written > 0) {
941 buffer_append_int(b,
942 con->bytes_written - con->bytes_header <= 0 ? 0 : con->bytes_written - con->bytes_header);
943 } else {
944 buffer_append_string_len(b, CONST_STR_LEN("-"));
945 }
946 break;
947 case FORMAT_HEADER:
948 if (NULL != (ds = (data_string *)array_get_element_klen(con->request.headers, CONST_BUF_LEN(f->string)))) {
949 accesslog_append_escaped(b, ds->value);
950 } else {
951 buffer_append_string_len(b, CONST_STR_LEN("-"));
952 }
953 break;
954 case FORMAT_RESPONSE_HEADER:
955 if (NULL != (ds = (data_string *)array_get_element_klen(con->response.headers, CONST_BUF_LEN(f->string)))) {
956 accesslog_append_escaped(b, ds->value);
957 } else {
958 buffer_append_string_len(b, CONST_STR_LEN("-"));
959 }
960 break;
961 case FORMAT_ENV:
962 case FORMAT_NOTE:
963 if (NULL != (ds = (data_string *)array_get_element_klen(con->environment, CONST_BUF_LEN(f->string)))) {
964 accesslog_append_escaped(b, ds->value);
965 } else {
966 buffer_append_string_len(b, CONST_STR_LEN("-"));
967 }
968 break;
969 case FORMAT_FILENAME:
970 if (!buffer_string_is_empty(con->physical.path)) {
971 buffer_append_string_buffer(b, con->physical.path);
972 } else {
973 buffer_append_string_len(b, CONST_STR_LEN("-"));
974 }
975 break;
976 case FORMAT_BYTES_OUT:
977 if (con->bytes_written > 0) {
978 buffer_append_int(b, con->bytes_written);
979 } else {
980 buffer_append_string_len(b, CONST_STR_LEN("-"));
981 }
982 break;
983 case FORMAT_BYTES_IN:
984 if (con->bytes_read > 0) {
985 buffer_append_int(b, con->bytes_read);
986 } else {
987 buffer_append_string_len(b, CONST_STR_LEN("-"));
988 }
989 break;
990 case FORMAT_SERVER_NAME:
991 if (!buffer_string_is_empty(con->server_name)) {
992 buffer_append_string_buffer(b, con->server_name);
993 } else {
994 buffer_append_string_len(b, CONST_STR_LEN("-"));
995 }
996 break;
997 case FORMAT_HTTP_HOST:
998 if (!buffer_string_is_empty(con->uri.authority)) {
999 accesslog_append_escaped(b, con->uri.authority);
1000 } else {
1001 buffer_append_string_len(b, CONST_STR_LEN("-"));
1002 }
1003 break;
1004 case FORMAT_REQUEST_PROTOCOL:
1005 buffer_append_string_len(b,
1006 con->request.http_version == HTTP_VERSION_1_1 ? "HTTP/1.1" : "HTTP/1.0", 8);
1007 break;
1008 case FORMAT_REQUEST_METHOD:
1009 buffer_append_string(b, get_http_method_name(con->request.http_method));
1010 break;
1011 case FORMAT_PERCENT:
1012 buffer_append_string_len(b, CONST_STR_LEN("%"));
1013 break;
1014 case FORMAT_LOCAL_ADDR:
1015 {
1016 /* (perf: not using getsockname() and inet_ntop_cache_get_ip())
1017 * (still useful if admin has configured explicit listen IPs) */
1018 const char *colon;
1019 buffer *srvtoken = con->srv_socket->srv_token;
1020 if (srvtoken->ptr[0] == '[') {
1021 colon = strstr(srvtoken->ptr, "]:");
1022 } else {
1023 colon = strchr(srvtoken->ptr, ':');
1024 }
1025 if (colon) {
1026 buffer_append_string_len(b, srvtoken->ptr, (size_t)(colon - srvtoken->ptr));
1027 } else {
1028 buffer_append_string_buffer(b, srvtoken);
1029 }
1030 }
1031 break;
1032 case FORMAT_SERVER_PORT:
1033 {
1034 const char *colon;
1035 buffer *srvtoken = ((server_socket*)(con->srv_socket))->srv_token;
1036 if (srvtoken->ptr[0] == '[') {
1037 colon = strstr(srvtoken->ptr, "]:");
1038 } else {
1039 colon = strchr(srvtoken->ptr, ':');
1040 }
1041 if (colon) {
1042 buffer_append_string(b, colon+1);
1043 } else {
1044 buffer_append_int(b, srv->srvconf.port);
1045 }
1046 }
1047 break;
1048 case FORMAT_QUERY_STRING:
1049 accesslog_append_escaped(b, con->uri.query);
1050 break;
1051 case FORMAT_URL:
1052 accesslog_append_escaped(b, con->uri.path_raw);
1053 break;
1054 case FORMAT_CONNECTION_STATUS:
1055 if (con->state == CON_STATE_RESPONSE_END) {
1056 if (0 == con->keep_alive) {
1057 buffer_append_string_len(b, CONST_STR_LEN("-"));
1058 } else {
1059 buffer_append_string_len(b, CONST_STR_LEN("+"));
1060 }
1061 } else { /* CON_STATE_ERROR */
1062 buffer_append_string_len(b, CONST_STR_LEN("X"));
1063 }
1064 break;
1065 case FORMAT_KEEPALIVE_COUNT:
1066 if (con->request_count > 1) {
1067 buffer_append_int(b, (intmax_t)(con->request_count-1));
1068 } else {
1069 buffer_append_string_len(b, CONST_STR_LEN("0"));
1070 }
1071 break;
1072 case FORMAT_COOKIE:
1073 if (NULL != (ds = (data_string *)array_get_element(con->request.headers, "Cookie"))) {
1074 char *str = ds->value->ptr;
1075 size_t len = buffer_string_length(f->string);
1076 do {
1077 while (*str == ' ' || *str == '\t') ++str;
1078 if (0 == strncmp(str, f->string->ptr, len) && str[len] == '=') {
1079 char *v = str+len+1;
1080 buffer *bstr;
1081 for (str = v; *str != '\0' && *str != ';'; ++str) ;
1082 if (str == v) break;
1083 do { --str; } while (str > v && (*str == ' ' || *str == '\t'));
1084 bstr = buffer_init();
1085 buffer_copy_string_len(bstr, v, str - v + 1);
1086 accesslog_append_escaped(b, bstr);
1087 buffer_free(bstr);
1088 break;
1089 } else {
1090 do { ++str; } while (*str != ' ' && *str != '\t' && *str != '\0');
1091 }
1092 while (*str == ' ' || *str == '\t') ++str;
1093 } while (*str++ == ';');
1094 }
1095 break;
1096 default:
1097 break;
1098 }
1099 break;
1100 default:
1101 break;
1102 }
1103 }
1104
1105 if (p->conf.use_syslog) { /* syslog doesn't cache */
1106 #ifdef HAVE_SYSLOG_H
1107 if (!buffer_string_is_empty(b)) {
1108 /*(syslog appends a \n on its own)*/
1109 syslog(p->conf.syslog_level, "%s", b->ptr);
1110 buffer_reset(b);
1111 }
1112 #endif
1113 return HANDLER_GO_ON;
1114 }
1115
1116 buffer_append_string_len(b, CONST_STR_LEN("\n"));
1117
1118 if ((!buffer_string_is_empty(p->conf.access_logfile) && p->conf.access_logfile->ptr[0] == '|') || /* pipes don't cache */
1119 newts ||
1120 buffer_string_length(b) >= BUFFER_MAX_REUSE_SIZE) {
1121 if (p->conf.log_access_fd >= 0) {
1122 accesslog_write_all(srv, p->conf.access_logfile, p->conf.log_access_fd, CONST_BUF_LEN(b));
1123 }
1124 buffer_reset(b);
1125 }
1126
1127 return HANDLER_GO_ON;
1128 }
1129
1130
1131 int mod_accesslog_plugin_init(plugin *p);
1132 int mod_accesslog_plugin_init(plugin *p) {
1133 p->version = LIGHTTPD_VERSION_ID;
1134 p->name = buffer_init_string("accesslog");
1135
1136 p->init = mod_accesslog_init;
1137 p->set_defaults= log_access_open;
1138 p->cleanup = mod_accesslog_free;
1139
1140 p->handle_request_done = log_access_write;
1141 p->handle_trigger = log_access_periodic_flush;
1142 p->handle_sighup = log_access_cycle;
1143
1144 p->data = NULL;
1145
1146 return 0;
1147 }
A fast webserver with minimal memory-footprint (lighttpd)