| 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> |
| 27 | #include <signal.h> |
| 28 | #include <fcntl.h> |
| 29 | #include <stdint.h> |
| 30 | #include <sys/stat.h> |
| 31 | #include <sys/socket.h> |
| 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> |
| 40 | #include <mt.h> |
| 41 | #include <mtio.h> |
| 42 | #include <bufio.h> |
| 43 | |
| 44 | #define DEFFORMAT "%{%Y-%m-%d %H:%M:%S}t %m %u %A \"%G\"" |
| 45 | |
| 46 | static 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 | |
| 55 | static int ch, filter; |
| 56 | static char *outname = NULL; |
| 57 | static FILE *out; |
| 58 | static int flush = 1, locklog = 1; |
| 59 | static char *format; |
| 60 | static volatile int reopen = 0; |
| 61 | |
| 62 | static void qputs(char *sp, FILE *o) |
| 63 | { |
| 64 | unsigned char *s = (unsigned char *)sp; |
| 65 | |
| 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)) { |
| 76 | fprintf(o, "\\x%02x", (int)*s); |
| 77 | } else { |
| 78 | fputc(*s, o); |
| 79 | } |
| 80 | } |
| 81 | } |
| 82 | |
| 83 | static void logitem(struct logdata *data, char o, char *d) |
| 84 | { |
| 85 | char *h, *p; |
| 86 | char buf[1024]; |
| 87 | |
| 88 | switch(o) { |
| 89 | case '%': |
| 90 | putc('%', out); |
| 91 | break; |
| 92 | case 'h': |
| 93 | if((h = getheader(data->req, d)) == NULL) { |
| 94 | putc('-', out); |
| 95 | } else { |
| 96 | qputs(h, out); |
| 97 | } |
| 98 | break; |
| 99 | case 'u': |
| 100 | qputs(data->req->url, out); |
| 101 | break; |
| 102 | case 'U': |
| 103 | strncpy(buf, data->req->url, sizeof(buf)); |
| 104 | buf[sizeof(buf) - 1] = 0; |
| 105 | if((p = strchr(buf, '?')) != NULL) |
| 106 | *p = 0; |
| 107 | qputs(buf, out); |
| 108 | break; |
| 109 | case 'm': |
| 110 | qputs(data->req->method, out); |
| 111 | break; |
| 112 | case 'r': |
| 113 | qputs(data->req->rest, out); |
| 114 | break; |
| 115 | case 'v': |
| 116 | qputs(data->req->ver, out); |
| 117 | break; |
| 118 | case 't': |
| 119 | if(!*d) |
| 120 | d = "%a, %d %b %Y %H:%M:%S %z"; |
| 121 | strftime(buf, sizeof(buf), d, localtime(&data->start.tv_sec)); |
| 122 | qputs(buf, out); |
| 123 | break; |
| 124 | case 'T': |
| 125 | if(!*d) |
| 126 | d = "%a, %d %b %Y %H:%M:%S %z"; |
| 127 | strftime(buf, sizeof(buf), d, gmtime(&data->start.tv_sec)); |
| 128 | qputs(buf, out); |
| 129 | break; |
| 130 | case 's': |
| 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)); |
| 156 | break; |
| 157 | case 'A': |
| 158 | logitem(data, 'h', "X-Ash-Address"); |
| 159 | break; |
| 160 | case 'H': |
| 161 | logitem(data, 'h', "Host"); |
| 162 | break; |
| 163 | case 'R': |
| 164 | logitem(data, 'h', "Referer"); |
| 165 | break; |
| 166 | case 'G': |
| 167 | logitem(data, 'h', "User-Agent"); |
| 168 | break; |
| 169 | } |
| 170 | } |
| 171 | |
| 172 | static void logreq(struct logdata *data) |
| 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; |
| 195 | logitem(data, o, d); |
| 196 | } else { |
| 197 | fputc(*p++, out); |
| 198 | } |
| 199 | } |
| 200 | fputc('\n', out); |
| 201 | if(flush) |
| 202 | fflush(out); |
| 203 | } |
| 204 | |
| 205 | static void serve(struct hthead *req, int fd) |
| 206 | { |
| 207 | struct logdata data; |
| 208 | |
| 209 | data = defdata; |
| 210 | data.req = req; |
| 211 | gettimeofday(&data.start, NULL); |
| 212 | if(sendreq(ch, req, fd)) { |
| 213 | flog(LOG_ERR, "accesslog: could not pass request to child: %s", strerror(errno)); |
| 214 | exit(1); |
| 215 | } |
| 216 | logreq(&data); |
| 217 | } |
| 218 | |
| 219 | static int passdata(struct bufio *in, struct bufio *out, off_t *passed) |
| 220 | { |
| 221 | ssize_t read; |
| 222 | off_t total; |
| 223 | |
| 224 | total = 0; |
| 225 | while(!bioeof(in)) { |
| 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 | } |
| 232 | if(biorspace(in) && (biofillsome(in) < 0)) |
| 233 | return(-1); |
| 234 | } |
| 235 | if(passed) |
| 236 | *passed = total; |
| 237 | return(0); |
| 238 | } |
| 239 | |
| 240 | static 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; |
| 246 | struct bufio *cl, *hd; |
| 247 | struct stdiofd *cli, *hdi; |
| 248 | struct logdata data; |
| 249 | |
| 250 | hd = NULL; |
| 251 | resp = NULL; |
| 252 | data = defdata; |
| 253 | data.req = req; |
| 254 | gettimeofday(&data.start, NULL); |
| 255 | cl = mtbioopen(fd, 1, 600, "r+", &cli); |
| 256 | if(socketpair(PF_UNIX, SOCK_STREAM, 0, pfds)) |
| 257 | goto out; |
| 258 | hd = mtbioopen(pfds[1], 1, 600, "r+", &hdi); |
| 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; |
| 267 | if(bioflush(hd)) |
| 268 | goto out; |
| 269 | shutdown(pfds[1], SHUT_WR); |
| 270 | if((resp = parseresponseb(hd)) == NULL) |
| 271 | goto out; |
| 272 | cli->sendrights = hdi->rights; |
| 273 | hdi->rights = -1; |
| 274 | data.resp = resp; |
| 275 | writerespb(cl, resp); |
| 276 | bioprintf(cl, "\r\n"); |
| 277 | if(passdata(hd, cl, &data.bytesout)) |
| 278 | goto out; |
| 279 | gettimeofday(&data.end, NULL); |
| 280 | |
| 281 | out: |
| 282 | logreq(&data); |
| 283 | |
| 284 | freehthead(req); |
| 285 | if(resp != NULL) |
| 286 | freehthead(resp); |
| 287 | bioclose(cl); |
| 288 | if(hd != NULL) |
| 289 | bioclose(hd); |
| 290 | } |
| 291 | |
| 292 | static void sighandler(int sig) |
| 293 | { |
| 294 | if(sig == SIGHUP) { |
| 295 | if(filter) |
| 296 | exitioloop(2); |
| 297 | else |
| 298 | reopen = 1; |
| 299 | } |
| 300 | } |
| 301 | |
| 302 | static 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 | |
| 314 | static 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 | |
| 341 | static void reopenlog(void) |
| 342 | { |
| 343 | FILE *new; |
| 344 | struct stat olds, news; |
| 345 | |
| 346 | if(outname == NULL) { |
| 347 | flog(LOG_WARNING, "accesslog: received SIGHUP but logging to stdout, so ignoring"); |
| 348 | return; |
| 349 | } |
| 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 | } |
| 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 | } |
| 379 | fcntl(fileno(new), F_SETFD, FD_CLOEXEC); |
| 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 | } |
| 391 | fclose(out); |
| 392 | out = new; |
| 393 | } |
| 394 | |
| 395 | static 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 | |
| 412 | static 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 | |
| 420 | static 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 | |
| 436 | static 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 | |
| 474 | static void usage(FILE *out) |
| 475 | { |
| 476 | fprintf(out, "usage: accesslog [-hFaL] [-f FORMAT] [-p PIDFILE] OUTFILE CHILD [ARGS...]\n"); |
| 477 | fprintf(out, " accesslog -P LOGFILE\n"); |
| 478 | } |
| 479 | |
| 480 | int main(int argc, char **argv) |
| 481 | { |
| 482 | int c; |
| 483 | char *pidfile; |
| 484 | FILE *pidout; |
| 485 | |
| 486 | pidfile = NULL; |
| 487 | while((c = getopt(argc, argv, "+hFaeLf:p:P:")) >= 0) { |
| 488 | switch(c) { |
| 489 | case 'h': |
| 490 | usage(stdout); |
| 491 | exit(0); |
| 492 | case 'F': |
| 493 | flush = 0; |
| 494 | break; |
| 495 | case 'L': |
| 496 | locklog = 0; |
| 497 | break; |
| 498 | case 'e': |
| 499 | filter = 1; |
| 500 | break; |
| 501 | case 'f': |
| 502 | format = optarg; |
| 503 | break; |
| 504 | case 'P': |
| 505 | fetchpid(optarg); |
| 506 | exit(0); |
| 507 | case 'p': |
| 508 | pidfile = optarg; |
| 509 | break; |
| 510 | case 'a': |
| 511 | format = "%A - - [%{%d/%b/%Y:%H:%M:%S %z}t] \"%m %u %v\" %c %o \"%R\" \"%G\""; |
| 512 | break; |
| 513 | default: |
| 514 | usage(stderr); |
| 515 | exit(1); |
| 516 | } |
| 517 | } |
| 518 | if(argc - optind < 2) { |
| 519 | usage(stderr); |
| 520 | exit(1); |
| 521 | } |
| 522 | if(format == NULL) |
| 523 | format = DEFFORMAT; |
| 524 | if(!strcmp(argv[optind], "-")) |
| 525 | outname = NULL; |
| 526 | else |
| 527 | outname = argv[optind]; |
| 528 | if(outname == NULL) { |
| 529 | out = stdout; |
| 530 | locklog = 0; |
| 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)); |
| 534 | exit(1); |
| 535 | } |
| 536 | fcntl(fileno(out), F_SETFD, FD_CLOEXEC); |
| 537 | } |
| 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 | } |
| 548 | if((ch = stdmkchild(argv + optind + 1, NULL, NULL)) < 0) { |
| 549 | flog(LOG_ERR, "accesslog: could not fork child: %s", strerror(errno)); |
| 550 | exit(1); |
| 551 | } |
| 552 | signal(SIGHUP, sighandler); |
| 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 | } |
| 568 | if(filter) |
| 569 | floop(); |
| 570 | else |
| 571 | sloop(); |
| 572 | fclose(out); |
| 573 | if(pidfile != NULL) |
| 574 | unlink(pidfile); |
| 575 | return(0); |
| 576 | } |