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