accesslog: Fail as soon as possible on broken channels.
[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 225 while(!bioeof(in)) {
417b376e
FT
226 if((read = biordata(in)) > 0) {
227 if((read = biowritesome(out, in->rbuf.b + in->rh, read)) < 0)
228 return(-1);
229 in->rh += read;
230 total += read;
231 }
b97cd36b
FT
232 if(biorspace(in) && (biofillsome(in) < 0))
233 return(-1);
5c805444
FT
234 }
235 if(passed)
236 *passed = total;
237 return(0);
238}
239
240static void filterreq(struct muth *mt, va_list args)
241{
242 vavar(struct hthead *, req);
243 vavar(int, fd);
244 int pfds[2];
245 struct hthead *resp;
b97cd36b 246 struct bufio *cl, *hd;
5c805444
FT
247 struct logdata data;
248
249 hd = NULL;
250 resp = NULL;
251 data = defdata;
252 data.req = req;
253 gettimeofday(&data.start, NULL);
b97cd36b 254 cl = mtbioopen(fd, 1, 600, "r+", NULL);
5c805444
FT
255 if(socketpair(PF_UNIX, SOCK_STREAM, 0, pfds))
256 goto out;
b97cd36b 257 hd = mtbioopen(pfds[1], 1, 600, "r+", NULL);
5c805444
FT
258 if(sendreq(ch, req, pfds[0])) {
259 close(pfds[0]);
260 goto out;
261 }
262 close(pfds[0]);
263
264 if(passdata(cl, hd, &data.bytesin))
265 goto out;
b97cd36b 266 if(bioflush(hd))
ff28e3a5 267 goto out;
5c805444 268 shutdown(pfds[1], SHUT_WR);
b97cd36b 269 if((resp = parseresponseb(hd)) == NULL)
5c805444
FT
270 goto out;
271 data.resp = resp;
b97cd36b
FT
272 writerespb(cl, resp);
273 bioprintf(cl, "\r\n");
5c805444
FT
274 if(passdata(hd, cl, &data.bytesout))
275 goto out;
276 gettimeofday(&data.end, NULL);
277
278out:
279 logreq(&data);
280
281 freehthead(req);
282 if(resp != NULL)
283 freehthead(resp);
b97cd36b 284 bioclose(cl);
5c805444 285 if(hd != NULL)
b97cd36b 286 bioclose(hd);
048ac115
FT
287}
288
f99bcc64
FT
289static void sighandler(int sig)
290{
5c805444
FT
291 if(sig == SIGHUP) {
292 if(filter)
293 exitioloop(2);
294 else
295 reopen = 1;
296 }
f99bcc64
FT
297}
298
ca170d77
FT
299static int lockfile(FILE *file)
300{
301 struct flock ld;
302
303 memset(&ld, 0, sizeof(ld));
304 ld.l_type = F_WRLCK;
305 ld.l_whence = SEEK_SET;
306 ld.l_start = 0;
307 ld.l_len = 0;
308 return(fcntl(fileno(file), F_SETLK, &ld));
309}
310
311static void fetchpid(char *filename)
312{
313 int fd, ret;
314 struct flock ld;
315
316 if((fd = open(filename, O_WRONLY)) < 0) {
317 fprintf(stderr, "accesslog: %s: %s\n", filename, strerror(errno));
318 exit(1);
319 }
320 memset(&ld, 0, sizeof(ld));
321 ld.l_type = F_WRLCK;
322 ld.l_whence = SEEK_SET;
323 ld.l_start = 0;
324 ld.l_len = 0;
325 ret = fcntl(fd, F_GETLK, &ld);
326 close(fd);
327 if(ret) {
328 fprintf(stderr, "accesslog: %s: %s\n", filename, strerror(errno));
329 exit(1);
330 }
331 if(ld.l_type == F_UNLCK) {
332 fprintf(stderr, "accesslog: %s: not locked\n", filename);
333 exit(1);
334 }
335 printf("%i\n", (int)ld.l_pid);
336}
337
f99bcc64
FT
338static void reopenlog(void)
339{
340 FILE *new;
ca170d77 341 struct stat olds, news;
f99bcc64
FT
342
343 if(outname == NULL) {
344 flog(LOG_WARNING, "accesslog: received SIGHUP but logging to stdout, so ignoring");
345 return;
346 }
ca170d77
FT
347 if(locklog) {
348 if(fstat(fileno(out), &olds)) {
349 flog(LOG_ERR, "accesslog: could not stat current logfile(?!): %s", strerror(errno));
350 return;
351 }
352 if(!stat(outname, &news)) {
353 if((olds.st_dev == news.st_dev) && (olds.st_ino == news.st_ino)) {
354 /*
355 * This needs to be ignored, because if the same logfile
356 * is opened and then closed, the lock is lost. To quote
357 * the Linux fcntl(2) manpage: "This is bad." No kidding.
358 *
359 * Technically, there is a race condition here when the
360 * file has been stat'ed but not yet opened, where the old
361 * log file, having been previously renamed, changes name
362 * back to the name accesslog knows and is thus reopened
363 * regardlessly, but I think that might fit under the
364 * idiom "pathological case". It should, at least, not be
365 * a security problem.
366 */
367 flog(LOG_INFO, "accesslog: received SIGHUP, but logfile has not changed, so ignoring");
368 return;
369 }
370 }
371 }
f99bcc64
FT
372 if((new = fopen(outname, "a")) == NULL) {
373 flog(LOG_WARNING, "accesslog: could not reopen log file `%s' on SIGHUP: %s", outname, strerror(errno));
374 return;
375 }
e09f3227 376 fcntl(fileno(new), F_SETFD, FD_CLOEXEC);
ca170d77
FT
377 if(locklog) {
378 if(lockfile(new)) {
379 if((errno == EAGAIN) || (errno == EACCES)) {
380 flog(LOG_ERR, "accesslog: logfile is already locked; reverting to current log", strerror(errno));
381 fclose(new);
382 return;
383 } else {
384 flog(LOG_WARNING, "accesslog: could not lock logfile, so no lock will be held: %s", strerror(errno));
385 }
386 }
387 }
f99bcc64
FT
388 fclose(out);
389 out = new;
390}
391
5c805444
FT
392static void listenloop(struct muth *mt, va_list args)
393{
394 vavar(int, lfd);
395 int fd;
396 struct hthead *req;
397
398 while(1) {
399 block(lfd, EV_READ, 0);
400 if((fd = recvreq(lfd, &req)) < 0) {
401 if(errno != 0)
402 flog(LOG_ERR, "accesslog: error in recvreq: %s", strerror(errno));
403 exit(1);
404 }
405 mustart(filterreq, req, fd);
406 }
407}
408
409static void chwatch(struct muth *mt, va_list args)
410{
411 vavar(int, cfd);
412
413 block(cfd, EV_READ, 0);
414 exitioloop(1);
415}
416
417static void floop(void)
418{
419 mustart(listenloop, 0);
420 mustart(chwatch, ch);
421 while(1) {
422 switch(ioloop()) {
423 case 0:
424 case 1:
425 return;
426 case 2:
427 reopenlog();
428 break;
429 }
430 }
431}
432
433static void sloop(void)
434{
435 int fd, ret;
436 struct hthead *req;
437 struct pollfd pfd[2];
438
439 while(1) {
440 if(reopen) {
441 reopenlog();
442 reopen = 0;
443 }
444 memset(pfd, 0, sizeof(pfd));
445 pfd[0].fd = 0;
446 pfd[0].events = POLLIN;
447 pfd[1].fd = ch;
448 pfd[1].events = POLLHUP;
449 if((ret = poll(pfd, 2, -1)) < 0) {
450 if(errno != EINTR) {
451 flog(LOG_ERR, "accesslog: error in poll: %s", strerror(errno));
452 exit(1);
453 }
454 }
455 if(pfd[0].revents) {
456 if((fd = recvreq(0, &req)) < 0) {
457 if(errno == 0)
458 return;
459 flog(LOG_ERR, "accesslog: error in recvreq: %s", strerror(errno));
460 exit(1);
461 }
462 serve(req, fd);
463 freehthead(req);
464 close(fd);
465 }
466 if(pfd[1].revents & POLLHUP)
467 return;
468 }
469}
470
048ac115
FT
471static void usage(FILE *out)
472{
ca170d77 473 fprintf(out, "usage: accesslog [-hFaL] [-f FORMAT] [-p PIDFILE] OUTFILE CHILD [ARGS...]\n");
e51483a1 474 fprintf(out, " accesslog -P LOGFILE\n");
048ac115
FT
475}
476
477int main(int argc, char **argv)
478{
5c805444 479 int c;
472abd3c
FT
480 char *pidfile;
481 FILE *pidout;
048ac115 482
472abd3c 483 pidfile = NULL;
5c805444 484 while((c = getopt(argc, argv, "+hFaeLf:p:P:")) >= 0) {
048ac115
FT
485 switch(c) {
486 case 'h':
487 usage(stdout);
488 exit(0);
048ac115
FT
489 case 'F':
490 flush = 0;
491 break;
ca170d77
FT
492 case 'L':
493 locklog = 0;
494 break;
5c805444
FT
495 case 'e':
496 filter = 1;
497 break;
048ac115
FT
498 case 'f':
499 format = optarg;
500 break;
ca170d77
FT
501 case 'P':
502 fetchpid(optarg);
503 exit(0);
472abd3c
FT
504 case 'p':
505 pidfile = optarg;
506 break;
048ac115 507 case 'a':
5c805444 508 format = "%A - - [%{%d/%b/%Y:%H:%M:%S %z}t] \"%m %u %v\" %c %o \"%R\" \"%G\"";
048ac115
FT
509 break;
510 default:
511 usage(stderr);
512 exit(1);
513 }
514 }
9701afc5 515 if(argc - optind < 2) {
048ac115
FT
516 usage(stderr);
517 exit(1);
518 }
519 if(format == NULL)
520 format = DEFFORMAT;
f99bcc64
FT
521 if(!strcmp(argv[optind], "-"))
522 outname = NULL;
523 else
524 outname = argv[optind];
525 if(outname == NULL) {
9701afc5 526 out = stdout;
e09f3227 527 locklog = 0;
9701afc5
FT
528 } else {
529 if((out = fopen(argv[optind], "a")) == NULL) {
530 flog(LOG_ERR, "accesslog: could not open %s for logging: %s", argv[optind], strerror(errno));
048ac115
FT
531 exit(1);
532 }
e09f3227 533 fcntl(fileno(out), F_SETFD, FD_CLOEXEC);
048ac115 534 }
ca170d77
FT
535 if(locklog) {
536 if(lockfile(out)) {
537 if((errno == EAGAIN) || (errno == EACCES)) {
538 flog(LOG_ERR, "accesslog: logfile is already locked", strerror(errno));
539 exit(1);
540 } else {
541 flog(LOG_WARNING, "accesslog: could not lock logfile: %s", strerror(errno));
542 }
543 }
544 }
9701afc5 545 if((ch = stdmkchild(argv + optind + 1, NULL, NULL)) < 0) {
e3f12675 546 flog(LOG_ERR, "accesslog: could not fork child: %s", strerror(errno));
048ac115
FT
547 exit(1);
548 }
f99bcc64 549 signal(SIGHUP, sighandler);
472abd3c
FT
550 if(pidfile) {
551 if(!strcmp(pidfile, "-")) {
552 if(!outname) {
553 flog(LOG_ERR, "accesslog: cannot derive PID file name without an output file");
554 exit(1);
555 }
556 pidfile = sprintf2("%s.pid", outname);
557 }
558 if((pidout = fopen(pidfile, "w")) == NULL) {
559 flog(LOG_ERR, "accesslog: could not open PID file %s for writing: %s", pidfile);
560 exit(1);
561 }
562 fprintf(pidout, "%i\n", (int)getpid());
563 fclose(pidout);
564 }
5c805444
FT
565 if(filter)
566 floop();
567 else
568 sloop();
f95bc205 569 fclose(out);
472abd3c
FT
570 if(pidfile != NULL)
571 unlink(pidfile);
048ac115
FT
572 return(0);
573}