| 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 'p': |
| 100 | if(!data->resp || ((h = getheader(data->resp, d)) == NULL)) { |
| 101 | putc('-', out); |
| 102 | } else { |
| 103 | qputs(h, out); |
| 104 | } |
| 105 | break; |
| 106 | case 'P': |
| 107 | logitem(data, 'p', sprintf3("X-Ash-%s", d)); |
| 108 | break; |
| 109 | case 'u': |
| 110 | qputs(data->req->url, out); |
| 111 | break; |
| 112 | case 'U': |
| 113 | strncpy(buf, data->req->url, sizeof(buf)); |
| 114 | buf[sizeof(buf) - 1] = 0; |
| 115 | if((p = strchr(buf, '?')) != NULL) |
| 116 | *p = 0; |
| 117 | qputs(buf, out); |
| 118 | break; |
| 119 | case 'm': |
| 120 | qputs(data->req->method, out); |
| 121 | break; |
| 122 | case 'r': |
| 123 | qputs(data->req->rest, out); |
| 124 | break; |
| 125 | case 'v': |
| 126 | qputs(data->req->ver, out); |
| 127 | break; |
| 128 | case 't': |
| 129 | if(!*d) |
| 130 | d = "%a, %d %b %Y %H:%M:%S %z"; |
| 131 | strftime(buf, sizeof(buf), d, localtime(&data->start.tv_sec)); |
| 132 | qputs(buf, out); |
| 133 | break; |
| 134 | case 'T': |
| 135 | if(!*d) |
| 136 | d = "%a, %d %b %Y %H:%M:%S %z"; |
| 137 | strftime(buf, sizeof(buf), d, gmtime(&data->start.tv_sec)); |
| 138 | qputs(buf, out); |
| 139 | break; |
| 140 | case 's': |
| 141 | fprintf(out, "%06i", (int)data->start.tv_usec); |
| 142 | break; |
| 143 | case 'c': |
| 144 | if(!data->resp) |
| 145 | putc('-', out); |
| 146 | else |
| 147 | fprintf(out, "%i", data->resp->code); |
| 148 | break; |
| 149 | case 'i': |
| 150 | if(data->bytesin < 0) |
| 151 | putc('-', out); |
| 152 | else |
| 153 | fprintf(out, "%ji", (intmax_t)data->bytesin); |
| 154 | break; |
| 155 | case 'o': |
| 156 | if(data->bytesout < 0) |
| 157 | putc('-', out); |
| 158 | else |
| 159 | fprintf(out, "%ji", (intmax_t)data->bytesout); |
| 160 | break; |
| 161 | case 'd': |
| 162 | if((data->end.tv_sec == 0) && (data->end.tv_usec == 0)) |
| 163 | fputc('-', out); |
| 164 | else |
| 165 | fprintf(out, "%.6f", (data->end.tv_sec - data->start.tv_sec) + ((data->end.tv_usec - data->start.tv_usec) / 1000000.0)); |
| 166 | break; |
| 167 | case 'A': |
| 168 | logitem(data, 'h', "X-Ash-Address"); |
| 169 | break; |
| 170 | case 'H': |
| 171 | logitem(data, 'h', "Host"); |
| 172 | break; |
| 173 | case 'R': |
| 174 | logitem(data, 'h', "Referer"); |
| 175 | break; |
| 176 | case 'G': |
| 177 | logitem(data, 'h', "User-Agent"); |
| 178 | break; |
| 179 | } |
| 180 | } |
| 181 | |
| 182 | static void logreq(struct logdata *data) |
| 183 | { |
| 184 | char *p, *p2; |
| 185 | char d[strlen(format)]; |
| 186 | char o; |
| 187 | |
| 188 | p = format; |
| 189 | while(*p) { |
| 190 | if(*p == '%') { |
| 191 | p++; |
| 192 | if(*p == '{') { |
| 193 | p++; |
| 194 | if((p2 = strchr(p, '}')) == NULL) |
| 195 | continue; |
| 196 | memcpy(d, p, p2 - p); |
| 197 | d[p2 - p] = 0; |
| 198 | p = p2 + 1; |
| 199 | } else { |
| 200 | d[0] = 0; |
| 201 | } |
| 202 | o = *p++; |
| 203 | if(o == 0) |
| 204 | break; |
| 205 | logitem(data, o, d); |
| 206 | } else { |
| 207 | fputc(*p++, out); |
| 208 | } |
| 209 | } |
| 210 | fputc('\n', out); |
| 211 | if(flush) |
| 212 | fflush(out); |
| 213 | } |
| 214 | |
| 215 | static void serve(struct hthead *req, int fd) |
| 216 | { |
| 217 | struct logdata data; |
| 218 | |
| 219 | data = defdata; |
| 220 | data.req = req; |
| 221 | gettimeofday(&data.start, NULL); |
| 222 | if(sendreq(ch, req, fd)) { |
| 223 | flog(LOG_ERR, "accesslog: could not pass request to child: %s", strerror(errno)); |
| 224 | exit(1); |
| 225 | } |
| 226 | logreq(&data); |
| 227 | } |
| 228 | |
| 229 | static int passdata(struct bufio *in, struct bufio *out, off_t *passed) |
| 230 | { |
| 231 | ssize_t read; |
| 232 | off_t total; |
| 233 | |
| 234 | total = 0; |
| 235 | while(!bioeof(in)) { |
| 236 | if((read = biordata(in)) > 0) { |
| 237 | if((read = biowritesome(out, in->rbuf.b + in->rh, read)) < 0) |
| 238 | return(-1); |
| 239 | in->rh += read; |
| 240 | total += read; |
| 241 | } |
| 242 | if(biorspace(in) && (biofillsome(in) < 0)) |
| 243 | return(-1); |
| 244 | } |
| 245 | if(passed) |
| 246 | *passed = total; |
| 247 | return(0); |
| 248 | } |
| 249 | |
| 250 | static void filterreq(struct muth *mt, va_list args) |
| 251 | { |
| 252 | vavar(struct hthead *, req); |
| 253 | vavar(int, fd); |
| 254 | int pfds[2]; |
| 255 | struct hthead *resp; |
| 256 | struct bufio *cl, *hd; |
| 257 | struct stdiofd *cli, *hdi; |
| 258 | struct logdata data; |
| 259 | |
| 260 | hd = NULL; |
| 261 | resp = NULL; |
| 262 | data = defdata; |
| 263 | data.req = req; |
| 264 | gettimeofday(&data.start, NULL); |
| 265 | cl = mtbioopen(fd, 1, 600, "r+", &cli); |
| 266 | if(socketpair(PF_UNIX, SOCK_STREAM, 0, pfds)) |
| 267 | goto out; |
| 268 | hd = mtbioopen(pfds[1], 1, 600, "r+", &hdi); |
| 269 | if(sendreq(ch, req, pfds[0])) { |
| 270 | close(pfds[0]); |
| 271 | goto out; |
| 272 | } |
| 273 | close(pfds[0]); |
| 274 | |
| 275 | if(passdata(cl, hd, &data.bytesin)) |
| 276 | goto out; |
| 277 | if(bioflush(hd)) |
| 278 | goto out; |
| 279 | shutdown(pfds[1], SHUT_WR); |
| 280 | if((resp = parseresponseb(hd)) == NULL) |
| 281 | goto out; |
| 282 | cli->sendrights = hdi->rights; |
| 283 | hdi->rights = -1; |
| 284 | data.resp = resp; |
| 285 | writerespb(cl, resp); |
| 286 | bioprintf(cl, "\r\n"); |
| 287 | if(passdata(hd, cl, &data.bytesout)) |
| 288 | goto out; |
| 289 | gettimeofday(&data.end, NULL); |
| 290 | |
| 291 | out: |
| 292 | logreq(&data); |
| 293 | |
| 294 | freehthead(req); |
| 295 | if(resp != NULL) |
| 296 | freehthead(resp); |
| 297 | bioclose(cl); |
| 298 | if(hd != NULL) |
| 299 | bioclose(hd); |
| 300 | } |
| 301 | |
| 302 | static void sighandler(int sig) |
| 303 | { |
| 304 | if(sig == SIGHUP) { |
| 305 | if(filter) |
| 306 | exitioloop(2); |
| 307 | else |
| 308 | reopen = 1; |
| 309 | } |
| 310 | } |
| 311 | |
| 312 | static int lockfile(FILE *file) |
| 313 | { |
| 314 | struct flock ld; |
| 315 | |
| 316 | memset(&ld, 0, sizeof(ld)); |
| 317 | ld.l_type = F_WRLCK; |
| 318 | ld.l_whence = SEEK_SET; |
| 319 | ld.l_start = 0; |
| 320 | ld.l_len = 0; |
| 321 | return(fcntl(fileno(file), F_SETLK, &ld)); |
| 322 | } |
| 323 | |
| 324 | static void fetchpid(char *filename) |
| 325 | { |
| 326 | int fd, ret; |
| 327 | struct flock ld; |
| 328 | |
| 329 | if((fd = open(filename, O_WRONLY)) < 0) { |
| 330 | fprintf(stderr, "accesslog: %s: %s\n", filename, strerror(errno)); |
| 331 | exit(1); |
| 332 | } |
| 333 | memset(&ld, 0, sizeof(ld)); |
| 334 | ld.l_type = F_WRLCK; |
| 335 | ld.l_whence = SEEK_SET; |
| 336 | ld.l_start = 0; |
| 337 | ld.l_len = 0; |
| 338 | ret = fcntl(fd, F_GETLK, &ld); |
| 339 | close(fd); |
| 340 | if(ret) { |
| 341 | fprintf(stderr, "accesslog: %s: %s\n", filename, strerror(errno)); |
| 342 | exit(1); |
| 343 | } |
| 344 | if(ld.l_type == F_UNLCK) { |
| 345 | fprintf(stderr, "accesslog: %s: not locked\n", filename); |
| 346 | exit(1); |
| 347 | } |
| 348 | printf("%i\n", (int)ld.l_pid); |
| 349 | } |
| 350 | |
| 351 | static void reopenlog(void) |
| 352 | { |
| 353 | FILE *new; |
| 354 | struct stat olds, news; |
| 355 | |
| 356 | if(outname == NULL) { |
| 357 | flog(LOG_WARNING, "accesslog: received SIGHUP but logging to stdout, so ignoring"); |
| 358 | return; |
| 359 | } |
| 360 | if(locklog) { |
| 361 | if(fstat(fileno(out), &olds)) { |
| 362 | flog(LOG_ERR, "accesslog: could not stat current logfile(?!): %s", strerror(errno)); |
| 363 | return; |
| 364 | } |
| 365 | if(!stat(outname, &news)) { |
| 366 | if((olds.st_dev == news.st_dev) && (olds.st_ino == news.st_ino)) { |
| 367 | /* |
| 368 | * This needs to be ignored, because if the same logfile |
| 369 | * is opened and then closed, the lock is lost. To quote |
| 370 | * the Linux fcntl(2) manpage: "This is bad." No kidding. |
| 371 | * |
| 372 | * Technically, there is a race condition here when the |
| 373 | * file has been stat'ed but not yet opened, where the old |
| 374 | * log file, having been previously renamed, changes name |
| 375 | * back to the name accesslog knows and is thus reopened |
| 376 | * regardlessly, but I think that might fit under the |
| 377 | * idiom "pathological case". It should, at least, not be |
| 378 | * a security problem. |
| 379 | */ |
| 380 | flog(LOG_INFO, "accesslog: received SIGHUP, but logfile has not changed, so ignoring"); |
| 381 | return; |
| 382 | } |
| 383 | } |
| 384 | } |
| 385 | if((new = fopen(outname, "a")) == NULL) { |
| 386 | flog(LOG_WARNING, "accesslog: could not reopen log file `%s' on SIGHUP: %s", outname, strerror(errno)); |
| 387 | return; |
| 388 | } |
| 389 | fcntl(fileno(new), F_SETFD, FD_CLOEXEC); |
| 390 | if(locklog) { |
| 391 | if(lockfile(new)) { |
| 392 | if((errno == EAGAIN) || (errno == EACCES)) { |
| 393 | flog(LOG_ERR, "accesslog: logfile is already locked; reverting to current log", strerror(errno)); |
| 394 | fclose(new); |
| 395 | return; |
| 396 | } else { |
| 397 | flog(LOG_WARNING, "accesslog: could not lock logfile, so no lock will be held: %s", strerror(errno)); |
| 398 | } |
| 399 | } |
| 400 | } |
| 401 | fclose(out); |
| 402 | out = new; |
| 403 | } |
| 404 | |
| 405 | static void listenloop(struct muth *mt, va_list args) |
| 406 | { |
| 407 | vavar(int, lfd); |
| 408 | int fd; |
| 409 | struct hthead *req; |
| 410 | |
| 411 | while(1) { |
| 412 | block(lfd, EV_READ, 0); |
| 413 | if((fd = recvreq(lfd, &req)) < 0) { |
| 414 | if(errno != 0) |
| 415 | flog(LOG_ERR, "accesslog: error in recvreq: %s", strerror(errno)); |
| 416 | exit(1); |
| 417 | } |
| 418 | mustart(filterreq, req, fd); |
| 419 | } |
| 420 | } |
| 421 | |
| 422 | static void chwatch(struct muth *mt, va_list args) |
| 423 | { |
| 424 | vavar(int, cfd); |
| 425 | |
| 426 | block(cfd, EV_READ, 0); |
| 427 | exitioloop(1); |
| 428 | } |
| 429 | |
| 430 | static void floop(void) |
| 431 | { |
| 432 | mustart(listenloop, 0); |
| 433 | mustart(chwatch, ch); |
| 434 | while(1) { |
| 435 | switch(ioloop()) { |
| 436 | case 0: |
| 437 | case 1: |
| 438 | return; |
| 439 | case 2: |
| 440 | reopenlog(); |
| 441 | break; |
| 442 | } |
| 443 | } |
| 444 | } |
| 445 | |
| 446 | static void sloop(void) |
| 447 | { |
| 448 | int fd, ret; |
| 449 | struct hthead *req; |
| 450 | struct pollfd pfd[2]; |
| 451 | |
| 452 | while(1) { |
| 453 | if(reopen) { |
| 454 | reopenlog(); |
| 455 | reopen = 0; |
| 456 | } |
| 457 | memset(pfd, 0, sizeof(pfd)); |
| 458 | pfd[0].fd = 0; |
| 459 | pfd[0].events = POLLIN; |
| 460 | pfd[1].fd = ch; |
| 461 | pfd[1].events = POLLHUP; |
| 462 | if((ret = poll(pfd, 2, -1)) < 0) { |
| 463 | if(errno != EINTR) { |
| 464 | flog(LOG_ERR, "accesslog: error in poll: %s", strerror(errno)); |
| 465 | exit(1); |
| 466 | } |
| 467 | } |
| 468 | if(pfd[0].revents) { |
| 469 | if((fd = recvreq(0, &req)) < 0) { |
| 470 | if(errno == 0) |
| 471 | return; |
| 472 | flog(LOG_ERR, "accesslog: error in recvreq: %s", strerror(errno)); |
| 473 | exit(1); |
| 474 | } |
| 475 | serve(req, fd); |
| 476 | freehthead(req); |
| 477 | close(fd); |
| 478 | } |
| 479 | if(pfd[1].revents & POLLHUP) |
| 480 | return; |
| 481 | } |
| 482 | } |
| 483 | |
| 484 | static void usage(FILE *out) |
| 485 | { |
| 486 | fprintf(out, "usage: accesslog [-hFaL] [-f FORMAT] [-p PIDFILE] OUTFILE CHILD [ARGS...]\n"); |
| 487 | fprintf(out, " accesslog -P LOGFILE\n"); |
| 488 | } |
| 489 | |
| 490 | int main(int argc, char **argv) |
| 491 | { |
| 492 | int c; |
| 493 | char *pidfile; |
| 494 | FILE *pidout; |
| 495 | |
| 496 | pidfile = NULL; |
| 497 | while((c = getopt(argc, argv, "+hFaeLf:p:P:")) >= 0) { |
| 498 | switch(c) { |
| 499 | case 'h': |
| 500 | usage(stdout); |
| 501 | exit(0); |
| 502 | case 'F': |
| 503 | flush = 0; |
| 504 | break; |
| 505 | case 'L': |
| 506 | locklog = 0; |
| 507 | break; |
| 508 | case 'e': |
| 509 | filter = 1; |
| 510 | break; |
| 511 | case 'f': |
| 512 | format = optarg; |
| 513 | break; |
| 514 | case 'P': |
| 515 | fetchpid(optarg); |
| 516 | exit(0); |
| 517 | case 'p': |
| 518 | pidfile = optarg; |
| 519 | break; |
| 520 | case 'a': |
| 521 | format = "%A - %{log-user}P [%{%d/%b/%Y:%H:%M:%S %z}t] \"%m %u %v\" %c %o \"%R\" \"%G\""; |
| 522 | break; |
| 523 | default: |
| 524 | usage(stderr); |
| 525 | exit(1); |
| 526 | } |
| 527 | } |
| 528 | if(argc - optind < 2) { |
| 529 | usage(stderr); |
| 530 | exit(1); |
| 531 | } |
| 532 | if(format == NULL) |
| 533 | format = DEFFORMAT; |
| 534 | if(!strcmp(argv[optind], "-")) |
| 535 | outname = NULL; |
| 536 | else |
| 537 | outname = argv[optind]; |
| 538 | if(outname == NULL) { |
| 539 | out = stdout; |
| 540 | locklog = 0; |
| 541 | } else { |
| 542 | if((out = fopen(argv[optind], "a")) == NULL) { |
| 543 | flog(LOG_ERR, "accesslog: could not open %s for logging: %s", argv[optind], strerror(errno)); |
| 544 | exit(1); |
| 545 | } |
| 546 | fcntl(fileno(out), F_SETFD, FD_CLOEXEC); |
| 547 | } |
| 548 | if(locklog) { |
| 549 | if(lockfile(out)) { |
| 550 | if((errno == EAGAIN) || (errno == EACCES)) { |
| 551 | flog(LOG_ERR, "accesslog: logfile is already locked", strerror(errno)); |
| 552 | exit(1); |
| 553 | } else { |
| 554 | flog(LOG_WARNING, "accesslog: could not lock logfile: %s", strerror(errno)); |
| 555 | } |
| 556 | } |
| 557 | } |
| 558 | if((ch = stdmkchild(argv + optind + 1, NULL, NULL)) < 0) { |
| 559 | flog(LOG_ERR, "accesslog: could not fork child: %s", strerror(errno)); |
| 560 | exit(1); |
| 561 | } |
| 562 | signal(SIGHUP, sighandler); |
| 563 | if(pidfile) { |
| 564 | if(!strcmp(pidfile, "-")) { |
| 565 | if(!outname) { |
| 566 | flog(LOG_ERR, "accesslog: cannot derive PID file name without an output file"); |
| 567 | exit(1); |
| 568 | } |
| 569 | pidfile = sprintf2("%s.pid", outname); |
| 570 | } |
| 571 | if((pidout = fopen(pidfile, "w")) == NULL) { |
| 572 | flog(LOG_ERR, "accesslog: could not open PID file %s for writing: %s", pidfile); |
| 573 | exit(1); |
| 574 | } |
| 575 | fprintf(pidout, "%i\n", (int)getpid()); |
| 576 | fclose(pidout); |
| 577 | } |
| 578 | if(filter) |
| 579 | floop(); |
| 580 | else |
| 581 | sloop(); |
| 582 | fclose(out); |
| 583 | if(pidfile != NULL) |
| 584 | unlink(pidfile); |
| 585 | return(0); |
| 586 | } |