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: }
FreeBSD-CVSweb <freebsd-cvsweb@FreeBSD.org>
![[BACK]](/icons/cvsweb/back.gif){kind=icon}
Return to mod_accesslog.c CVS log ![[TXT]](/icons/cvsweb/text.gif){kind=icon}
![[DIR]](/icons/cvsweb/dir.gif){kind=icon}
Up to [ELWIX - Embedded LightWeight unIX -] / embedaddon / lighttpd / src