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