?  search:
summary | log | graphiclog1 | graphiclog2 | commit | commitdiff | tree | refs | edit | fork
blame | history | raw | HEAD
[core] consolidate duplicated read-to-close code
[lighttpd.git] / src / mod_accesslog.c
blob84ef2597d31d2eb267f56e8e37b1997bb3f8c477
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 FORMAT_NOTE
62 } type;
63 } format_mapping;
64
65 /**
66 *
67 *
68 * "%h %l %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-Agent}i\""
69 *
70 */
71
72 static const format_mapping fmap[] =
73 {
74 { '%', FORMAT_PERCENT },
75 { 'h', FORMAT_REMOTE_HOST },
76 { 'l', FORMAT_REMOTE_IDENT },
77 { 'u', FORMAT_REMOTE_USER },
78 { 't', FORMAT_TIMESTAMP },
79 { 'r', FORMAT_REQUEST_LINE },
80 { 's', FORMAT_STATUS },
81 { 'b', FORMAT_BYTES_OUT_NO_HEADER },
82 { 'i', FORMAT_HEADER },
83
84 { 'a', FORMAT_REMOTE_ADDR },
85 { 'A', FORMAT_LOCAL_ADDR },
86 { 'B', FORMAT_BYTES_OUT_NO_HEADER },
87 { 'C', FORMAT_COOKIE },
88 { 'D', FORMAT_TIME_USED_US },
89 { 'e', FORMAT_ENV },
90 { 'f', FORMAT_FILENAME },
91 { 'H', FORMAT_REQUEST_PROTOCOL },
92 { 'k', FORMAT_KEEPALIVE_COUNT },
93 { 'm', FORMAT_REQUEST_METHOD },
94 { 'n', FORMAT_NOTE },
95 { 'p', FORMAT_SERVER_PORT },
96 { 'P', FORMAT_UNSUPPORTED }, /* we are only one process */
97 { 'q', FORMAT_QUERY_STRING },
98 { 'T', FORMAT_TIME_USED },
99 { 'U', FORMAT_URL }, /* w/o querystring */
100 { 'v', FORMAT_SERVER_NAME },
101 { 'V', FORMAT_HTTP_HOST },
102 { 'X', FORMAT_CONNECTION_STATUS },
103 { 'I', FORMAT_BYTES_IN },
104 { 'O', FORMAT_BYTES_OUT },
105
106 { 'o', FORMAT_RESPONSE_HEADER },
107
108 { '\0', FORMAT_UNSET }
109 };
110
111
112 enum e_optflags_time {
113 /* format string is passed to strftime unless other format optflags set
114 * (besides FORMAT_FLAG_TIME_BEGIN or FORMAT_FLAG_TIME_END) */
115 FORMAT_FLAG_TIME_END = 0x00,/* use request end time (default) */
116 FORMAT_FLAG_TIME_BEGIN = 0x01,/* use request start time */
117 FORMAT_FLAG_TIME_SEC = 0x02,/* request time as num sec since epoch */
118 FORMAT_FLAG_TIME_MSEC = 0x04,/* request time as num msec since epoch */
119 FORMAT_FLAG_TIME_USEC = 0x08,/* request time as num usec since epoch */
120 FORMAT_FLAG_TIME_NSEC = 0x10,/* request time as num nsec since epoch */
121 FORMAT_FLAG_TIME_MSEC_FRAC = 0x20,/* request time msec fraction */
122 FORMAT_FLAG_TIME_USEC_FRAC = 0x40,/* request time usec fraction */
123 FORMAT_FLAG_TIME_NSEC_FRAC = 0x80 /* request time nsec fraction */
124 };
125
126
127 typedef struct {
128 enum { FIELD_UNSET, FIELD_STRING, FIELD_FORMAT } type;
129
130 buffer *string;
131 int field;
132 int opt;
133 } format_field;
134
135 typedef struct {
136 format_field **ptr;
137
138 size_t used;
139 size_t size;
140 } format_fields;
141
142 typedef struct {
143 buffer *access_logfile;
144 int log_access_fd;
145 buffer *access_logbuffer; /* each logfile has a separate buffer */
146
147 unsigned short use_syslog; /* syslog has global buffer */
148 unsigned short syslog_level;
149
150 buffer *format;
151
152 time_t last_generated_accesslog_ts;
153 time_t *last_generated_accesslog_ts_ptr;
154
155 buffer *ts_accesslog_str;
156
157 format_fields *parsed_format;
158 } plugin_config;
159
160 typedef struct {
161 PLUGIN_DATA;
162
163 plugin_config **config_storage;
164 plugin_config conf;
165
166 buffer *syslog_logbuffer; /* syslog has global buffer. no caching, always written directly */
167 } plugin_data;
168
169 INIT_FUNC(mod_accesslog_init) {
170 plugin_data *p;
171
172 p = calloc(1, sizeof(*p));
173 p->syslog_logbuffer = buffer_init();
174
175 return p;
176 }
177
178 static void accesslog_write_all(server *srv, const buffer *filename, int fd, const void* buf, size_t count) {
179 if (-1 == write_all(fd, buf, count)) {
180 log_error_write(srv, __FILE__, __LINE__, "sbs",
181 "writing access log entry failed:", filename, strerror(errno));
182 }
183 }
184
185 static void accesslog_append_escaped(buffer *dest, buffer *str) {
186 char *ptr, *start, *end;
187
188 /* replaces non-printable chars with \xHH where HH is the hex representation of the byte */
189 /* exceptions: " => \", \ => \\, whitespace chars => \n \t etc. */
190 if (buffer_string_is_empty(str)) return;
191 buffer_string_prepare_append(dest, buffer_string_length(str));
192
193 for (ptr = start = str->ptr, end = str->ptr + buffer_string_length(str); ptr < end; ptr++) {
194 unsigned char const c = (unsigned char) *ptr;
195 if (c >= ' ' && c <= '~' && c != '"' && c != '\\') {
196 /* nothing to change, add later as one block */
197 } else {
198 /* copy previous part */
199 if (start < ptr) {
200 buffer_append_string_len(dest, start, ptr - start);
201 }
202 start = ptr + 1;
203
204 switch (c) {
205 case '"':
206 BUFFER_APPEND_STRING_CONST(dest, "\\\"");
207 break;
208 case '\\':
209 BUFFER_APPEND_STRING_CONST(dest, "\\\\");
210 break;
211 case '\b':
212 BUFFER_APPEND_STRING_CONST(dest, "\\b");
213 break;
214 case '\n':
215 BUFFER_APPEND_STRING_CONST(dest, "\\n");
216 break;
217 case '\r':
218 BUFFER_APPEND_STRING_CONST(dest, "\\r");
219 break;
220 case '\t':
221 BUFFER_APPEND_STRING_CONST(dest, "\\t");
222 break;
223 case '\v':
224 BUFFER_APPEND_STRING_CONST(dest, "\\v");
225 break;
226 default: {
227 /* non printable char => \xHH */
228 char hh[5] = {'\\','x',0,0,0};
229 char h = c / 16;
230 hh[2] = (h > 9) ? (h - 10 + 'A') : (h + '0');
231 h = c % 16;
232 hh[3] = (h > 9) ? (h - 10 + 'A') : (h + '0');
233 buffer_append_string_len(dest, &hh[0], 4);
234 }
235 break;
236 }
237 }
238 }
239
240 if (start < end) {
241 buffer_append_string_len(dest, start, end - start);
242 }
243 }
244
245 static int accesslog_parse_format(server *srv, format_fields *fields, buffer *format) {
246 size_t i, j, k = 0, start = 0;
247
248 if (buffer_is_empty(format)) return -1;
249
250 for (i = 0; i < buffer_string_length(format); i++) {
251 switch(format->ptr[i]) {
252 case '%':
253 if (i > 0 && start != i) {
254 /* copy the string before this % */
255 if (fields->size == 0) {
256 fields->size = 16;
257 fields->used = 0;
258 fields->ptr = malloc(fields->size * sizeof(format_field * ));
259 } else if (fields->used == fields->size) {
260 fields->size += 16;
261 fields->ptr = realloc(fields->ptr, fields->size * sizeof(format_field * ));
262 }
263
264 fields->ptr[fields->used] = malloc(sizeof(format_field));
265 fields->ptr[fields->used]->type = FIELD_STRING;
266 fields->ptr[fields->used]->string = buffer_init();
267
268 buffer_copy_string_len(fields->ptr[fields->used]->string, format->ptr + start, i - start);
269
270 fields->used++;
271 }
272
273 /* we need a new field */
274
275 if (fields->size == 0) {
276 fields->size = 16;
277 fields->used = 0;
278 fields->ptr = malloc(fields->size * sizeof(format_field * ));
279 } else if (fields->used == fields->size) {
280 fields->size += 16;
281 fields->ptr = realloc(fields->ptr, fields->size * sizeof(format_field * ));
282 }
283
284 /* search for the terminating command */
285 switch (format->ptr[i+1]) {
286 case '>':
287 case '<':
288 /* after the } has to be a character */
289 if (format->ptr[i+2] == '\0') {
290 log_error_write(srv, __FILE__, __LINE__, "s", "%< and %> have to be followed by a format-specifier");
291 return -1;
292 }
293
294
295 for (j = 0; fmap[j].key != '\0'; j++) {
296 if (fmap[j].key != format->ptr[i+2]) continue;
297
298 /* found key */
299
300 fields->ptr[fields->used] = malloc(sizeof(format_field));
301 fields->ptr[fields->used]->type = FIELD_FORMAT;
302 fields->ptr[fields->used]->field = fmap[j].type;
303 fields->ptr[fields->used]->string = NULL;
304 fields->ptr[fields->used]->opt = 0;
305
306 fields->used++;
307
308 break;
309 }
310
311 if (fmap[j].key == '\0') {
312 log_error_write(srv, __FILE__, __LINE__, "s", "%< and %> have to be followed by a valid format-specifier");
313 return -1;
314 }
315
316 start = i + 3;
317 i = start - 1; /* skip the string */
318
319 break;
320 case '{':
321 /* go forward to } */
322
323 for (k = i+2; k < buffer_string_length(format); k++) {
324 if (format->ptr[k] == '}') break;
325 }
326
327 if (k == buffer_string_length(format)) {
328 log_error_write(srv, __FILE__, __LINE__, "s", "%{ has to be terminated by a }");
329 return -1;
330 }
331
332 /* after the } has to be a character */
333 if (format->ptr[k+1] == '\0') {
334 log_error_write(srv, __FILE__, __LINE__, "s", "%{...} has to be followed by a format-specifier");
335 return -1;
336 }
337
338 if (k == i + 2) {
339 log_error_write(srv, __FILE__, __LINE__, "s", "%{...} has to be contain a string");
340 return -1;
341 }
342
343 for (j = 0; fmap[j].key != '\0'; j++) {
344 if (fmap[j].key != format->ptr[k+1]) continue;
345
346 /* found key */
347
348 fields->ptr[fields->used] = malloc(sizeof(format_field));
349 fields->ptr[fields->used]->type = FIELD_FORMAT;
350 fields->ptr[fields->used]->field = fmap[j].type;
351 fields->ptr[fields->used]->string = buffer_init();
352 fields->ptr[fields->used]->opt = 0;
353
354 buffer_copy_string_len(fields->ptr[fields->used]->string, format->ptr + i + 2, k - (i + 2));
355
356 fields->used++;
357
358 break;
359 }
360
361 if (fmap[j].key == '\0') {
362 log_error_write(srv, __FILE__, __LINE__, "s", "%{...} has to be followed by a valid format-specifier");
363 return -1;
364 }
365
366 start = k + 2;
367 i = start - 1; /* skip the string */
368
369 break;
370 default:
371 /* after the % has to be a character */
372 if (format->ptr[i+1] == '\0') {
373 log_error_write(srv, __FILE__, __LINE__, "s", "% has to be followed by a format-specifier");
374 return -1;
375 }
376
377 for (j = 0; fmap[j].key != '\0'; j++) {
378 if (fmap[j].key != format->ptr[i+1]) continue;
379
380 /* found key */
381
382 fields->ptr[fields->used] = malloc(sizeof(format_field));
383 fields->ptr[fields->used]->type = FIELD_FORMAT;
384 fields->ptr[fields->used]->field = fmap[j].type;
385 fields->ptr[fields->used]->string = NULL;
386 fields->ptr[fields->used]->opt = 0;
387
388 fields->used++;
389
390 break;
391 }
392
393 if (fmap[j].key == '\0') {
394 log_error_write(srv, __FILE__, __LINE__, "s", "% has to be followed by a valid format-specifier");
395 return -1;
396 }
397
398 start = i + 2;
399 i = start - 1; /* skip the string */
400
401 break;
402 }
403
404 break;
405 }
406 }
407
408 if (start < i) {
409 /* copy the string */
410 if (fields->size == 0) {
411 fields->size = 16;
412 fields->used = 0;
413 fields->ptr = malloc(fields->size * sizeof(format_field * ));
414 } else if (fields->used == fields->size) {
415 fields->size += 16;
416 fields->ptr = realloc(fields->ptr, fields->size * sizeof(format_field * ));
417 }
418
419 fields->ptr[fields->used] = malloc(sizeof(format_field));
420 fields->ptr[fields->used]->type = FIELD_STRING;
421 fields->ptr[fields->used]->string = buffer_init();
422
423 buffer_copy_string_len(fields->ptr[fields->used]->string, format->ptr + start, i - start);
424
425 fields->used++;
426 }
427
428 return 0;
429 }
430
431 FREE_FUNC(mod_accesslog_free) {
432 plugin_data *p = p_d;
433 size_t i;
434
435 if (!p) return HANDLER_GO_ON;
436
437 if (p->config_storage) {
438
439 for (i = 0; i < srv->config_context->used; i++) {
440 plugin_config *s = p->config_storage[i];
441
442 if (NULL == s) continue;
443
444 if (!buffer_string_is_empty(s->access_logbuffer)) {
445 if (s->log_access_fd != -1) {
446 accesslog_write_all(srv, s->access_logfile, s->log_access_fd, CONST_BUF_LEN(s->access_logbuffer));
447 }
448 }
449
450 if (s->log_access_fd != -1) close(s->log_access_fd);
451
452 buffer_free(s->ts_accesslog_str);
453 buffer_free(s->access_logbuffer);
454 buffer_free(s->format);
455 buffer_free(s->access_logfile);
456
457 if (s->parsed_format) {
458 size_t j;
459 for (j = 0; j < s->parsed_format->used; j++) {
460 if (s->parsed_format->ptr[j]->string) buffer_free(s->parsed_format->ptr[j]->string);
461 free(s->parsed_format->ptr[j]);
462 }
463 free(s->parsed_format->ptr);
464 free(s->parsed_format);
465 }
466
467 free(s);
468 }
469
470 free(p->config_storage);
471 }
472
473 if (p->syslog_logbuffer) buffer_free(p->syslog_logbuffer);
474 free(p);
475
476 return HANDLER_GO_ON;
477 }
478
479 SETDEFAULTS_FUNC(log_access_open) {
480 plugin_data *p = p_d;
481 size_t i = 0;
482
483 config_values_t cv[] = {
484 { "accesslog.filename", NULL, T_CONFIG_STRING, T_CONFIG_SCOPE_CONNECTION },
485 { "accesslog.use-syslog", NULL, T_CONFIG_BOOLEAN, T_CONFIG_SCOPE_CONNECTION },
486 { "accesslog.format", NULL, T_CONFIG_STRING, T_CONFIG_SCOPE_CONNECTION },
487 { "accesslog.syslog-level", NULL, T_CONFIG_SHORT, T_CONFIG_SCOPE_CONNECTION },
488 { NULL, NULL, T_CONFIG_UNSET, T_CONFIG_SCOPE_UNSET }
489 };
490
491 if (!p) return HANDLER_ERROR;
492
493 p->config_storage = calloc(1, srv->config_context->used * sizeof(plugin_config *));
494
495 for (i = 0; i < srv->config_context->used; i++) {
496 data_config const* config = (data_config const*)srv->config_context->data[i];
497 plugin_config *s;
498
499 s = calloc(1, sizeof(plugin_config));
500 s->access_logfile = buffer_init();
501 s->format = buffer_init();
502 s->access_logbuffer = buffer_init();
503 s->ts_accesslog_str = buffer_init();
504 s->log_access_fd = -1;
505 s->last_generated_accesslog_ts = 0;
506 s->last_generated_accesslog_ts_ptr = &(s->last_generated_accesslog_ts);
507 s->syslog_level = LOG_INFO;
508
509
510 cv[0].destination = s->access_logfile;
511 cv[1].destination = &(s->use_syslog);
512 cv[2].destination = s->format;
513 cv[3].destination = &(s->syslog_level);
514
515 p->config_storage[i] = s;
516
517 if (0 != config_insert_values_global(srv, config->value, cv, i == 0 ? T_CONFIG_SCOPE_SERVER : T_CONFIG_SCOPE_CONNECTION)) {
518 return HANDLER_ERROR;
519 }
520
521 if (i == 0 && buffer_string_is_empty(s->format)) {
522 /* set a default logfile string */
523
524 buffer_copy_string_len(s->format, CONST_STR_LEN("%h %V %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-Agent}i\""));
525 }
526
527 /* parse */
528
529 if (!buffer_is_empty(s->format)) {
530 size_t j, tcount = 0;
531
532 s->parsed_format = calloc(1, sizeof(*(s->parsed_format)));
533
534 if (-1 == accesslog_parse_format(srv, s->parsed_format, s->format)) {
535
536 log_error_write(srv, __FILE__, __LINE__, "sb",
537 "parsing accesslog-definition failed:", s->format);
538
539 return HANDLER_ERROR;
540 }
541
542 for (j = 0; j < s->parsed_format->used; ++j) {
543 format_field * const f = s->parsed_format->ptr[j];
544 if (FIELD_FORMAT != f->type) continue;
545 if (FORMAT_TIMESTAMP == f->field) {
546 if (!buffer_string_is_empty(f->string)) {
547 const char *ptr = f->string->ptr;
548 if (0 == strncmp(ptr, "begin:", sizeof("begin:")-1)) {
549 f->opt |= FORMAT_FLAG_TIME_BEGIN;
550 ptr += sizeof("begin:")-1;
551 } else if (0 == strncmp(ptr, "end:", sizeof("end:")-1)) {
552 f->opt |= FORMAT_FLAG_TIME_END;
553 ptr += sizeof("end:")-1;
554 }
555 if (0 == strcmp(ptr, "sec")) f->opt |= FORMAT_FLAG_TIME_SEC;
556 else if (0 == strcmp(ptr, "msec")) f->opt |= FORMAT_FLAG_TIME_MSEC;
557 else if (0 == strcmp(ptr, "usec")) f->opt |= FORMAT_FLAG_TIME_USEC;
558 else if (0 == strcmp(ptr, "nsec")) f->opt |= FORMAT_FLAG_TIME_NSEC;
559 else if (0 == strcmp(ptr, "msec_frac")) f->opt |= FORMAT_FLAG_TIME_MSEC_FRAC;
560 else if (0 == strcmp(ptr, "usec_frac")) f->opt |= FORMAT_FLAG_TIME_USEC_FRAC;
561 else if (0 == strcmp(ptr, "nsec_frac")) f->opt |= FORMAT_FLAG_TIME_NSEC_FRAC;
562 else if (NULL == strchr(ptr, '%')) {
563 log_error_write(srv, __FILE__, __LINE__, "sb",
564 "constant string for time format (misspelled token? or missing '%'):", s->format);
565
566 return HANDLER_ERROR;
567 }
568 }
569
570 /* make sure they didn't try to send the timestamp in twice
571 * (would invalidate s->ts_accesslog_str cache of timestamp str) */
572 if (!(f->opt & ~(FORMAT_FLAG_TIME_BEGIN|FORMAT_FLAG_TIME_END|FORMAT_FLAG_TIME_SEC)) && ++tcount > 1) {
573 log_error_write(srv, __FILE__, __LINE__, "sb",
574 "you may not use strftime timestamp format %{}t twice in the same access log:", s->format);
575
576 return HANDLER_ERROR;
577 }
578
579 if (f->opt & FORMAT_FLAG_TIME_BEGIN) srv->srvconf.high_precision_timestamps = 1;
580 } else if (FORMAT_TIME_USED_US == f->field) {
581 f->opt |= FORMAT_FLAG_TIME_USEC;
582 srv->srvconf.high_precision_timestamps = 1;
583 } else if (FORMAT_TIME_USED == f->field) {
584 if (f->opt & ~(FORMAT_FLAG_TIME_SEC)) srv->srvconf.high_precision_timestamps = 1;
585
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 } else if (FORMAT_COOKIE == f->field) {
602 if (buffer_string_is_empty(f->string)) f->type = FIELD_STRING; /*(blank)*/
603 }
604 }
605
606 #if 0
607 /* debugging */
608 for (j = 0; j < s->parsed_format->used; j++) {
609 switch (s->parsed_format->ptr[j]->type) {
610 case FIELD_FORMAT:
611 log_error_write(srv, __FILE__, __LINE__, "ssds",
612 "config:", "format", s->parsed_format->ptr[j]->field,
613 s->parsed_format->ptr[j]->string ?
614 s->parsed_format->ptr[j]->string->ptr : "" );
615 break;
616 case FIELD_STRING:
617 log_error_write(srv, __FILE__, __LINE__, "ssbs", "config:", "string '", s->parsed_format->ptr[j]->string, "'");
618 break;
619 default:
620 break;
621 }
622 }
623 #endif
624 }
625
626 if (s->use_syslog) {
627 /* ignore the next checks */
628 continue;
629 }
630
631 if (buffer_string_is_empty(s->access_logfile)) continue;
632
633 if (srv->srvconf.preflight_check) continue;
634
635 if (-1 == (s->log_access_fd = open_logfile_or_pipe(srv, s->access_logfile->ptr)))
636 return HANDLER_ERROR;
637
638 }
639
640 return HANDLER_GO_ON;
641 }
642
643 SIGHUP_FUNC(log_access_cycle) {
644 plugin_data *p = p_d;
645 size_t i;
646
647 if (!p->config_storage) return HANDLER_GO_ON;
648
649 for (i = 0; i < srv->config_context->used; i++) {
650 plugin_config *s = p->config_storage[i];
651
652 if (!buffer_string_is_empty(s->access_logbuffer)) {
653 if (s->log_access_fd != -1) {
654 accesslog_write_all(srv, s->access_logfile, s->log_access_fd, CONST_BUF_LEN(s->access_logbuffer));
655 }
656
657 buffer_reset(s->access_logbuffer);
658 }
659
660 if (s->use_syslog == 0
661 && !buffer_string_is_empty(s->access_logfile)
662 && s->access_logfile->ptr[0] != '|') {
663
664 if (-1 != s->log_access_fd) close(s->log_access_fd);
665
666 if (-1 == (s->log_access_fd =
667 fdevent_open_cloexec(s->access_logfile->ptr, O_APPEND | O_WRONLY | O_CREAT | O_LARGEFILE, 0644))) {
668
669 log_error_write(srv, __FILE__, __LINE__, "ss", "cycling access-log failed:", strerror(errno));
670
671 return HANDLER_ERROR;
672 }
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 case FORMAT_NOTE:
947 if (NULL != (ds = (data_string *)array_get_element(con->environment, f->string->ptr))) {
948 accesslog_append_escaped(b, ds->value);
949 } else {
950 buffer_append_string_len(b, CONST_STR_LEN("-"));
951 }
952 break;
953 case FORMAT_FILENAME:
954 if (!buffer_string_is_empty(con->physical.path)) {
955 buffer_append_string_buffer(b, con->physical.path);
956 } else {
957 buffer_append_string_len(b, CONST_STR_LEN("-"));
958 }
959 break;
960 case FORMAT_BYTES_OUT:
961 if (con->bytes_written > 0) {
962 buffer_append_int(b, con->bytes_written);
963 } else {
964 buffer_append_string_len(b, CONST_STR_LEN("-"));
965 }
966 break;
967 case FORMAT_BYTES_IN:
968 if (con->bytes_read > 0) {
969 buffer_append_int(b, con->bytes_read);
970 } else {
971 buffer_append_string_len(b, CONST_STR_LEN("-"));
972 }
973 break;
974 case FORMAT_SERVER_NAME:
975 if (!buffer_string_is_empty(con->server_name)) {
976 buffer_append_string_buffer(b, con->server_name);
977 } else {
978 buffer_append_string_len(b, CONST_STR_LEN("-"));
979 }
980 break;
981 case FORMAT_HTTP_HOST:
982 if (!buffer_string_is_empty(con->uri.authority)) {
983 accesslog_append_escaped(b, con->uri.authority);
984 } else {
985 buffer_append_string_len(b, CONST_STR_LEN("-"));
986 }
987 break;
988 case FORMAT_REQUEST_PROTOCOL:
989 buffer_append_string_len(b,
990 con->request.http_version == HTTP_VERSION_1_1 ? "HTTP/1.1" : "HTTP/1.0", 8);
991 break;
992 case FORMAT_REQUEST_METHOD:
993 buffer_append_string(b, get_http_method_name(con->request.http_method));
994 break;
995 case FORMAT_PERCENT:
996 buffer_append_string_len(b, CONST_STR_LEN("%"));
997 break;
998 case FORMAT_LOCAL_ADDR:
999 {
1000 /* (perf: not using getsockname() and inet_ntop_cache_get_ip())
1001 * (still useful if admin has configured explicit listen IPs) */
1002 const char *colon;
1003 buffer *srvtoken = con->srv_socket->srv_token;
1004 if (srvtoken->ptr[0] == '[') {
1005 colon = strstr(srvtoken->ptr, "]:");
1006 } else {
1007 colon = strchr(srvtoken->ptr, ':');
1008 }
1009 if (colon) {
1010 buffer_append_string_len(b, srvtoken->ptr, (size_t)(colon - srvtoken->ptr));
1011 } else {
1012 buffer_append_string_buffer(b, srvtoken);
1013 }
1014 }
1015 break;
1016 case FORMAT_SERVER_PORT:
1017 {
1018 const char *colon;
1019 buffer *srvtoken = ((server_socket*)(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(b, colon+1);
1027 } else {
1028 buffer_append_int(b, srv->srvconf.port);
1029 }
1030 }
1031 break;
1032 case FORMAT_QUERY_STRING:
1033 accesslog_append_escaped(b, con->uri.query);
1034 break;
1035 case FORMAT_URL:
1036 accesslog_append_escaped(b, con->uri.path_raw);
1037 break;
1038 case FORMAT_CONNECTION_STATUS:
1039 if (con->state == CON_STATE_RESPONSE_END) {
1040 if (0 == con->keep_alive) {
1041 buffer_append_string_len(b, CONST_STR_LEN("-"));
1042 } else {
1043 buffer_append_string_len(b, CONST_STR_LEN("+"));
1044 }
1045 } else { /* CON_STATE_ERROR */
1046 buffer_append_string_len(b, CONST_STR_LEN("X"));
1047 }
1048 break;
1049 case FORMAT_KEEPALIVE_COUNT:
1050 if (con->request_count > 1) {
1051 buffer_append_int(b, (intmax_t)(con->request_count-1));
1052 } else {
1053 buffer_append_string_len(b, CONST_STR_LEN("0"));
1054 }
1055 break;
1056 case FORMAT_COOKIE:
1057 if (NULL != (ds = (data_string *)array_get_element(con->request.headers, "Cookie"))) {
1058 char *str = ds->value->ptr;
1059 size_t len = buffer_string_length(f->string);
1060 do {
1061 while (*str == ' ' || *str == '\t') ++str;
1062 if (0 == strncmp(str, f->string->ptr, len) && str[len] == '=') {
1063 char *v = str+len+1;
1064 buffer *bstr;
1065 for (str = v; *str != '\0' && *str != ';'; ++str) ;
1066 if (str == v) break;
1067 do { --str; } while (str > v && (*str == ' ' || *str == '\t'));
1068 bstr = buffer_init();
1069 buffer_copy_string_len(bstr, v, str - v + 1);
1070 accesslog_append_escaped(b, bstr);
1071 buffer_free(bstr);
1072 break;
1073 } else {
1074 do { ++str; } while (*str != ' ' && *str != '\t' && *str != '\0');
1075 }
1076 while (*str == ' ' || *str == '\t') ++str;
1077 } while (*str++ == ';');
1078 }
1079 break;
1080 default:
1081 break;
1082 }
1083 break;
1084 default:
1085 break;
1086 }
1087 }
1088
1089 if (p->conf.use_syslog) { /* syslog doesn't cache */
1090 #ifdef HAVE_SYSLOG_H
1091 if (!buffer_string_is_empty(b)) {
1092 /*(syslog appends a \n on its own)*/
1093 syslog(p->conf.syslog_level, "%s", b->ptr);
1094 buffer_reset(b);
1095 }
1096 #endif
1097 return HANDLER_GO_ON;
1098 }
1099
1100 buffer_append_string_len(b, CONST_STR_LEN("\n"));
1101
1102 if ((!buffer_string_is_empty(p->conf.access_logfile) && p->conf.access_logfile->ptr[0] == '|') || /* pipes don't cache */
1103 newts ||
1104 buffer_string_length(b) >= BUFFER_MAX_REUSE_SIZE) {
1105 if (p->conf.log_access_fd >= 0) {
1106 accesslog_write_all(srv, p->conf.access_logfile, p->conf.log_access_fd, CONST_BUF_LEN(b));
1107 }
1108 buffer_reset(b);
1109 }
1110
1111 return HANDLER_GO_ON;
1112 }
1113
1114
1115 int mod_accesslog_plugin_init(plugin *p);
1116 int mod_accesslog_plugin_init(plugin *p) {
1117 p->version = LIGHTTPD_VERSION_ID;
1118 p->name = buffer_init_string("accesslog");
1119
1120 p->init = mod_accesslog_init;
1121 p->set_defaults= log_access_open;
1122 p->cleanup = mod_accesslog_free;
1123
1124 p->handle_request_done = log_access_write;
1125 p->handle_sighup = log_access_cycle;
1126
1127 p->data = NULL;
1128
1129 return 0;
1130 }
A fast webserver with minimal memory-footprint (lighttpd)