htparser: Use bufio instead of stdio for greater responsiveness.
[ashd.git] / src / accesslog.c
CommitLineData
048ac115
FT
1/*
2 ashd - A Sane HTTP Daemon
3 Copyright (C) 2008 Fredrik Tolf <fredrik@dolda2000.com>
4
5 This program is free software: you can redistribute it and/or modify
6 it under the terms of the GNU General Public License as published by
7 the Free Software Foundation, either version 3 of the License, or
8 (at your option) any later version.
9
10 This program is distributed in the hope that it will be useful,
11 but WITHOUT ANY WARRANTY; without even the implied warranty of
12 MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
13 GNU General Public License for more details.
14
15 You should have received a copy of the GNU General Public License
16 along with this program. If not, see <http://www.gnu.org/licenses/>.
17*/
18
19#include <stdlib.h>
20#include <stdio.h>
21#include <unistd.h>
22#include <string.h>
23#include <errno.h>
24#include <sys/poll.h>
25#include <time.h>
26#include <sys/time.h>
f99bcc64 27#include <signal.h>
472abd3c 28#include <fcntl.h>
5c805444 29#include <stdint.h>
ca170d77 30#include <sys/stat.h>
5c805444 31#include <sys/socket.h>
048ac115
FT
32
33#ifdef HAVE_CONFIG_H
34#include <config.h>
35#endif
36#include <utils.h>
37#include <log.h>
38#include <req.h>
39#include <proc.h>
5c805444
FT
40#include <mt.h>
41#include <mtio.h>
b97cd36b 42#include <bufio.h>
048ac115
FT
43
44#define DEFFORMAT "%{%Y-%m-%d %H:%M:%S}t %m %u %A \"%G\""
45
5c805444
FT
46static struct logdata {
47 struct hthead *req, *resp;
48 struct timeval start, end;
49 off_t bytesin, bytesout;
50} defdata = {
51 .bytesin = -1,
52 .bytesout = -1,
53};
54
55static int ch, filter;
f99bcc64 56static char *outname = NULL;
048ac115 57static FILE *out;
ca170d77 58static int flush = 1, locklog = 1;
048ac115 59static char *format;
f99bcc64 60static volatile int reopen = 0;
048ac115 61
39522714 62static void qputs(char *sp, FILE *o)
048ac115 63{
39522714
FT
64 unsigned char *s = (unsigned char *)sp;
65
048ac115
FT
66 for(; *s; s++) {
67 if(*s == '\"') {
68 fputs("\\\"", o);
69 } else if(*s == '\\') {
70 fputs("\\\\", o);
71 } else if(*s == '\n') {
72 fputs("\\n", o);
73 } else if(*s == '\t') {
74 fputs("\\t", o);
75 } else if((*s < 32) || (*s >= 128)) {
39522714 76 fprintf(o, "\\x%02x", (int)*s);
048ac115
FT
77 } else {
78 fputc(*s, o);
79 }
80 }
81}
82
5c805444 83static void logitem(struct logdata *data, char o, char *d)
048ac115
FT
84{
85 char *h, *p;
86 char buf[1024];
048ac115
FT
87
88 switch(o) {
89 case '%':
90 putc('%', out);
91 break;
92 case 'h':
5c805444 93 if((h = getheader(data->req, d)) == NULL) {
048ac115
FT
94 putc('-', out);
95 } else {
96 qputs(h, out);
97 }
98 break;
99 case 'u':
5c805444 100 qputs(data->req->url, out);
048ac115
FT
101 break;
102 case 'U':
5c805444
FT
103 strncpy(buf, data->req->url, sizeof(buf));
104 buf[sizeof(buf) - 1] = 0;
048ac115
FT
105 if((p = strchr(buf, '?')) != NULL)
106 *p = 0;
107 qputs(buf, out);
108 break;
109 case 'm':
5c805444 110 qputs(data->req->method, out);
048ac115
FT
111 break;
112 case 'r':
5c805444 113 qputs(data->req->rest, out);
048ac115
FT
114 break;
115 case 'v':
5c805444 116 qputs(data->req->ver, out);
048ac115
FT
117 break;
118 case 't':
119 if(!*d)
120 d = "%a, %d %b %Y %H:%M:%S %z";
5c805444 121 strftime(buf, sizeof(buf), d, localtime(&data->start.tv_sec));
048ac115
FT
122 qputs(buf, out);
123 break;
124 case 'T':
125 if(!*d)
126 d = "%a, %d %b %Y %H:%M:%S %z";
5c805444 127 strftime(buf, sizeof(buf), d, gmtime(&data->start.tv_sec));
048ac115
FT
128 qputs(buf, out);
129 break;
130 case 's':
5c805444
FT
131 fprintf(out, "%06i", (int)data->start.tv_usec);
132 break;
133 case 'c':
134 if(!data->resp)
135 putc('-', out);
136 else
137 fprintf(out, "%i", data->resp->code);
138 break;
139 case 'i':
140 if(data->bytesin < 0)
141 putc('-', out);
142 else
143 fprintf(out, "%ji", (intmax_t)data->bytesin);
144 break;
145 case 'o':
146 if(data->bytesout < 0)
147 putc('-', out);
148 else
149 fprintf(out, "%ji", (intmax_t)data->bytesout);
150 break;
151 case 'd':
152 if((data->end.tv_sec == 0) && (data->end.tv_usec == 0))
153 fputc('-', out);
154 else
155 fprintf(out, "%.6f", (data->end.tv_sec - data->start.tv_sec) + ((data->end.tv_usec - data->start.tv_usec) / 1000000.0));
048ac115
FT
156 break;
157 case 'A':
5c805444 158 logitem(data, 'h', "X-Ash-Address");
048ac115
FT
159 break;
160 case 'H':
5c805444 161 logitem(data, 'h', "Host");
048ac115
FT
162 break;
163 case 'R':
5c805444 164 logitem(data, 'h', "Referer");
048ac115
FT
165 break;
166 case 'G':
5c805444 167 logitem(data, 'h', "User-Agent");
048ac115
FT
168 break;
169 }
170}
171
5c805444 172static void logreq(struct logdata *data)
048ac115
FT
173{
174 char *p, *p2;
175 char d[strlen(format)];
176 char o;
177
178 p = format;
179 while(*p) {
180 if(*p == '%') {
181 p++;
182 if(*p == '{') {
183 p++;
184 if((p2 = strchr(p, '}')) == NULL)
185 continue;
186 memcpy(d, p, p2 - p);
187 d[p2 - p] = 0;
188 p = p2 + 1;
189 } else {
190 d[0] = 0;
191 }
192 o = *p++;
193 if(o == 0)
194 break;
5c805444 195 logitem(data, o, d);
048ac115
FT
196 } else {
197 fputc(*p++, out);
198 }
199 }
200 fputc('\n', out);
201 if(flush)
202 fflush(out);
203}
204
205static void serve(struct hthead *req, int fd)
206{
5c805444
FT
207 struct logdata data;
208
209 data = defdata;
210 data.req = req;
211 gettimeofday(&data.start, NULL);
048ac115
FT
212 if(sendreq(ch, req, fd)) {
213 flog(LOG_ERR, "accesslog: could not pass request to child: %s", strerror(errno));
214 exit(1);
215 }
5c805444
FT
216 logreq(&data);
217}
218
b97cd36b 219static int passdata(struct bufio *in, struct bufio *out, off_t *passed)
5c805444 220{
b97cd36b 221 ssize_t read;
5c805444 222 off_t total;
5c805444
FT
223
224 total = 0;
b97cd36b
FT
225 while(!bioeof(in)) {
226 if((read = biocopysome(out, in)) < 0)
5c805444
FT
227 return(-1);
228 total += read;
b97cd36b
FT
229 if(biorspace(in) && (biofillsome(in) < 0))
230 return(-1);
5c805444
FT
231 }
232 if(passed)
233 *passed = total;
234 return(0);
235}
236
237static void filterreq(struct muth *mt, va_list args)
238{
239 vavar(struct hthead *, req);
240 vavar(int, fd);
241 int pfds[2];
242 struct hthead *resp;
b97cd36b 243 struct bufio *cl, *hd;
5c805444
FT
244 struct logdata data;
245
246 hd = NULL;
247 resp = NULL;
248 data = defdata;
249 data.req = req;
250 gettimeofday(&data.start, NULL);
b97cd36b 251 cl = mtbioopen(fd, 1, 600, "r+", NULL);
5c805444
FT
252 if(socketpair(PF_UNIX, SOCK_STREAM, 0, pfds))
253 goto out;
b97cd36b 254 hd = mtbioopen(pfds[1], 1, 600, "r+", NULL);
5c805444
FT
255 if(sendreq(ch, req, pfds[0])) {
256 close(pfds[0]);
257 goto out;
258 }
259 close(pfds[0]);
260
261 if(passdata(cl, hd, &data.bytesin))
262 goto out;
b97cd36b 263 if(bioflush(hd))
ff28e3a5 264 goto out;
5c805444 265 shutdown(pfds[1], SHUT_WR);
b97cd36b 266 if((resp = parseresponseb(hd)) == NULL)
5c805444
FT
267 goto out;
268 data.resp = resp;
b97cd36b
FT
269 writerespb(cl, resp);
270 bioprintf(cl, "\r\n");
5c805444
FT
271 if(passdata(hd, cl, &data.bytesout))
272 goto out;
273 gettimeofday(&data.end, NULL);
274
275out:
276 logreq(&data);
277
278 freehthead(req);
279 if(resp != NULL)
280 freehthead(resp);
b97cd36b 281 bioclose(cl);
5c805444 282 if(hd != NULL)
b97cd36b 283 bioclose(hd);
048ac115
FT
284}
285
f99bcc64
FT
286static void sighandler(int sig)
287{
5c805444
FT
288 if(sig == SIGHUP) {
289 if(filter)
290 exitioloop(2);
291 else
292 reopen = 1;
293 }
f99bcc64
FT
294}
295
ca170d77
FT
296static int lockfile(FILE *file)
297{
298 struct flock ld;
299
300 memset(&ld, 0, sizeof(ld));
301 ld.l_type = F_WRLCK;
302 ld.l_whence = SEEK_SET;
303 ld.l_start = 0;
304 ld.l_len = 0;
305 return(fcntl(fileno(file), F_SETLK, &ld));
306}
307
308static void fetchpid(char *filename)
309{
310 int fd, ret;
311 struct flock ld;
312
313 if((fd = open(filename, O_WRONLY)) < 0) {
314 fprintf(stderr, "accesslog: %s: %s\n", filename, strerror(errno));
315 exit(1);
316 }
317 memset(&ld, 0, sizeof(ld));
318 ld.l_type = F_WRLCK;
319 ld.l_whence = SEEK_SET;
320 ld.l_start = 0;
321 ld.l_len = 0;
322 ret = fcntl(fd, F_GETLK, &ld);
323 close(fd);
324 if(ret) {
325 fprintf(stderr, "accesslog: %s: %s\n", filename, strerror(errno));
326 exit(1);
327 }
328 if(ld.l_type == F_UNLCK) {
329 fprintf(stderr, "accesslog: %s: not locked\n", filename);
330 exit(1);
331 }
332 printf("%i\n", (int)ld.l_pid);
333}
334
f99bcc64
FT
335static void reopenlog(void)
336{
337 FILE *new;
ca170d77 338 struct stat olds, news;
f99bcc64
FT
339
340 if(outname == NULL) {
341 flog(LOG_WARNING, "accesslog: received SIGHUP but logging to stdout, so ignoring");
342 return;
343 }
ca170d77
FT
344 if(locklog) {
345 if(fstat(fileno(out), &olds)) {
346 flog(LOG_ERR, "accesslog: could not stat current logfile(?!): %s", strerror(errno));
347 return;
348 }
349 if(!stat(outname, &news)) {
350 if((olds.st_dev == news.st_dev) && (olds.st_ino == news.st_ino)) {
351 /*
352 * This needs to be ignored, because if the same logfile
353 * is opened and then closed, the lock is lost. To quote
354 * the Linux fcntl(2) manpage: "This is bad." No kidding.
355 *
356 * Technically, there is a race condition here when the
357 * file has been stat'ed but not yet opened, where the old
358 * log file, having been previously renamed, changes name
359 * back to the name accesslog knows and is thus reopened
360 * regardlessly, but I think that might fit under the
361 * idiom "pathological case". It should, at least, not be
362 * a security problem.
363 */
364 flog(LOG_INFO, "accesslog: received SIGHUP, but logfile has not changed, so ignoring");
365 return;
366 }
367 }
368 }
f99bcc64
FT
369 if((new = fopen(outname, "a")) == NULL) {
370 flog(LOG_WARNING, "accesslog: could not reopen log file `%s' on SIGHUP: %s", outname, strerror(errno));
371 return;
372 }
e09f3227 373 fcntl(fileno(new), F_SETFD, FD_CLOEXEC);
ca170d77
FT
374 if(locklog) {
375 if(lockfile(new)) {
376 if((errno == EAGAIN) || (errno == EACCES)) {
377 flog(LOG_ERR, "accesslog: logfile is already locked; reverting to current log", strerror(errno));
378 fclose(new);
379 return;
380 } else {
381 flog(LOG_WARNING, "accesslog: could not lock logfile, so no lock will be held: %s", strerror(errno));
382 }
383 }
384 }
f99bcc64
FT
385 fclose(out);
386 out = new;
387}
388
5c805444
FT
389static void listenloop(struct muth *mt, va_list args)
390{
391 vavar(int, lfd);
392 int fd;
393 struct hthead *req;
394
395 while(1) {
396 block(lfd, EV_READ, 0);
397 if((fd = recvreq(lfd, &req)) < 0) {
398 if(errno != 0)
399 flog(LOG_ERR, "accesslog: error in recvreq: %s", strerror(errno));
400 exit(1);
401 }
402 mustart(filterreq, req, fd);
403 }
404}
405
406static void chwatch(struct muth *mt, va_list args)
407{
408 vavar(int, cfd);
409
410 block(cfd, EV_READ, 0);
411 exitioloop(1);
412}
413
414static void floop(void)
415{
416 mustart(listenloop, 0);
417 mustart(chwatch, ch);
418 while(1) {
419 switch(ioloop()) {
420 case 0:
421 case 1:
422 return;
423 case 2:
424 reopenlog();
425 break;
426 }
427 }
428}
429
430static void sloop(void)
431{
432 int fd, ret;
433 struct hthead *req;
434 struct pollfd pfd[2];
435
436 while(1) {
437 if(reopen) {
438 reopenlog();
439 reopen = 0;
440 }
441 memset(pfd, 0, sizeof(pfd));
442 pfd[0].fd = 0;
443 pfd[0].events = POLLIN;
444 pfd[1].fd = ch;
445 pfd[1].events = POLLHUP;
446 if((ret = poll(pfd, 2, -1)) < 0) {
447 if(errno != EINTR) {
448 flog(LOG_ERR, "accesslog: error in poll: %s", strerror(errno));
449 exit(1);
450 }
451 }
452 if(pfd[0].revents) {
453 if((fd = recvreq(0, &req)) < 0) {
454 if(errno == 0)
455 return;
456 flog(LOG_ERR, "accesslog: error in recvreq: %s", strerror(errno));
457 exit(1);
458 }
459 serve(req, fd);
460 freehthead(req);
461 close(fd);
462 }
463 if(pfd[1].revents & POLLHUP)
464 return;
465 }
466}
467
048ac115
FT
468static void usage(FILE *out)
469{
ca170d77 470 fprintf(out, "usage: accesslog [-hFaL] [-f FORMAT] [-p PIDFILE] OUTFILE CHILD [ARGS...]\n");
e51483a1 471 fprintf(out, " accesslog -P LOGFILE\n");
048ac115
FT
472}
473
474int main(int argc, char **argv)
475{
5c805444 476 int c;
472abd3c
FT
477 char *pidfile;
478 FILE *pidout;
048ac115 479
472abd3c 480 pidfile = NULL;
5c805444 481 while((c = getopt(argc, argv, "+hFaeLf:p:P:")) >= 0) {
048ac115
FT
482 switch(c) {
483 case 'h':
484 usage(stdout);
485 exit(0);
048ac115
FT
486 case 'F':
487 flush = 0;
488 break;
ca170d77
FT
489 case 'L':
490 locklog = 0;
491 break;
5c805444
FT
492 case 'e':
493 filter = 1;
494 break;
048ac115
FT
495 case 'f':
496 format = optarg;
497 break;
ca170d77
FT
498 case 'P':
499 fetchpid(optarg);
500 exit(0);
472abd3c
FT
501 case 'p':
502 pidfile = optarg;
503 break;
048ac115 504 case 'a':
5c805444 505 format = "%A - - [%{%d/%b/%Y:%H:%M:%S %z}t] \"%m %u %v\" %c %o \"%R\" \"%G\"";
048ac115
FT
506 break;
507 default:
508 usage(stderr);
509 exit(1);
510 }
511 }
9701afc5 512 if(argc - optind < 2) {
048ac115
FT
513 usage(stderr);
514 exit(1);
515 }
516 if(format == NULL)
517 format = DEFFORMAT;
f99bcc64
FT
518 if(!strcmp(argv[optind], "-"))
519 outname = NULL;
520 else
521 outname = argv[optind];
522 if(outname == NULL) {
9701afc5 523 out = stdout;
e09f3227 524 locklog = 0;
9701afc5
FT
525 } else {
526 if((out = fopen(argv[optind], "a")) == NULL) {
527 flog(LOG_ERR, "accesslog: could not open %s for logging: %s", argv[optind], strerror(errno));
048ac115
FT
528 exit(1);
529 }
e09f3227 530 fcntl(fileno(out), F_SETFD, FD_CLOEXEC);
048ac115 531 }
ca170d77
FT
532 if(locklog) {
533 if(lockfile(out)) {
534 if((errno == EAGAIN) || (errno == EACCES)) {
535 flog(LOG_ERR, "accesslog: logfile is already locked", strerror(errno));
536 exit(1);
537 } else {
538 flog(LOG_WARNING, "accesslog: could not lock logfile: %s", strerror(errno));
539 }
540 }
541 }
9701afc5 542 if((ch = stdmkchild(argv + optind + 1, NULL, NULL)) < 0) {
e3f12675 543 flog(LOG_ERR, "accesslog: could not fork child: %s", strerror(errno));
048ac115
FT
544 exit(1);
545 }
f99bcc64 546 signal(SIGHUP, sighandler);
472abd3c
FT
547 if(pidfile) {
548 if(!strcmp(pidfile, "-")) {
549 if(!outname) {
550 flog(LOG_ERR, "accesslog: cannot derive PID file name without an output file");
551 exit(1);
552 }
553 pidfile = sprintf2("%s.pid", outname);
554 }
555 if((pidout = fopen(pidfile, "w")) == NULL) {
556 flog(LOG_ERR, "accesslog: could not open PID file %s for writing: %s", pidfile);
557 exit(1);
558 }
559 fprintf(pidout, "%i\n", (int)getpid());
560 fclose(pidout);
561 }
5c805444
FT
562 if(filter)
563 floop();
564 else
565 sloop();
f95bc205 566 fclose(out);
472abd3c
FT
567 if(pidfile != NULL)
568 unlink(pidfile);
048ac115
FT
569 return(0);
570}