src/log.c

   1 #include "first.h"
   2
   3 #include "base.h"
   4 #include "log.h"
   5 #include "array.h"
   6
   7 #include <sys/types.h>
   8
   9 #include <errno.h>
  10 #include <fcntl.h>
  11 #include <time.h>
  12 #include <unistd.h>
  13 #include <string.h>
  14 #include <stdlib.h>
  15
  16 #include <stdarg.h>
  17 #include <stdio.h>
  18
  19 #ifdef HAVE_SYSLOG_H
  20 # include <syslog.h>
  21 #endif
  22
  23 #ifdef HAVE_VALGRIND_VALGRIND_H
  24 # include <valgrind/valgrind.h>
  25 #endif
  26
  27 #ifndef O_LARGEFILE
  28 # define O_LARGEFILE 0
  29 #endif
  30
  31 #ifndef HAVE_CLOCK_GETTIME
  32 #ifdef HAVE_SYS_TIME_H
  33 # include <sys/time.h>  /* gettimeofday() */
  34 #endif
  35 #endif
  36
  37 int log_clock_gettime_realtime (struct timespec *ts) {
  38       #ifdef HAVE_CLOCK_GETTIME
  39         return clock_gettime(CLOCK_REALTIME, ts);
  40       #else
  41         /* Mac OSX does not provide clock_gettime()
  42          * e.g. defined(__APPLE__) && defined(__MACH__) */
  43         struct timeval tv;
  44         gettimeofday(&tv, NULL);
  45         ts->tv_sec  = tv.tv_sec;
  46         ts->tv_nsec = tv.tv_usec * 1000;
  47         return 0;
  48       #endif
  49 }
  50
  51 /* retry write on EINTR or when not all data was written */
  52 ssize_t write_all(int fd, const void* buf, size_t count) {
  53         ssize_t written = 0;
  54
  55         while (count > 0) {
  56                 ssize_t r = write(fd, buf, count);
  57                 if (r < 0) {
  58                         switch (errno) {
  59                         case EINTR:
  60                                 /* try again */
  61                                 break;
  62                         default:
  63                                 /* fail - repeating probably won't help */
  64                                 return -1;
  65                         }
  66                 } else if (0 == r) {
  67                         /* really shouldn't happen... */
  68                         errno = EIO;
  69                         return -1;
  70                 } else {
  71                         force_assert(r <= (ssize_t) count);
  72                         written += r;
  73                         buf = r + (char const*) buf;
  74                         count -= r;
  75                 }
  76         }
  77
  78         return written;
  79 }
  80
  81 /* Close fd and _try_ to get a /dev/null for it instead.
  82  * close() alone may trigger some bugs when a
  83  * process opens another file and gets fd = STDOUT_FILENO or STDERR_FILENO
  84  * and later tries to just print on stdout/stderr
  85  *
  86  * Returns 0 on success and -1 on failure (fd gets closed in all cases)
  87  */
  88 int openDevNull(int fd) {
  89         int tmpfd;
  90         close(fd);
  91 #if defined(__WIN32)
  92         /* Cygwin should work with /dev/null */
  93         tmpfd = open("nul", O_RDWR);
  94 #else
  95         tmpfd = open("/dev/null", O_RDWR);
  96 #endif
  97         if (tmpfd != -1 && tmpfd != fd) {
  98                 dup2(tmpfd, fd);
  99                 close(tmpfd);
 100         }
 101         return (tmpfd != -1) ? 0 : -1;
 102 }
 103
 104 int open_logfile_or_pipe(server *srv, const char* logfile) {
 105         int fd;
 106
 107         if (logfile[0] == '|') {
 108 #ifdef HAVE_FORK
 109                 /* create write pipe and spawn process */
 110
 111                 int to_log_fds[2];
 112
 113                 if (pipe(to_log_fds)) {
 114                         log_error_write(srv, __FILE__, __LINE__, "ss", "pipe failed: ", strerror(errno));
 115                         return -1;
 116                 }
 117
 118                 /* fork, execve */
 119                 switch (fork()) {
 120                 case 0:
 121                         /* child */
 122                         close(STDIN_FILENO);
 123
 124                         /* dup the filehandle to STDIN */
 125                         if (to_log_fds[0] != STDIN_FILENO) {
 126                                 if (STDIN_FILENO != dup2(to_log_fds[0], STDIN_FILENO)) {
 127                                         log_error_write(srv, __FILE__, __LINE__, "ss",
 128                                                 "dup2 failed: ", strerror(errno));
 129                                         exit(-1);
 130                                 }
 131                                 close(to_log_fds[0]);
 132                         }
 133                         close(to_log_fds[1]);
 134
 135 #ifndef FD_CLOEXEC
 136                         {
 137                                 int i;
 138                                 /* we don't need the client socket */
 139                                 for (i = 3; i < 256; i++) {
 140                                         close(i);
 141                                 }
 142                         }
 143 #endif
 144
 145                         /* close old stderr */
 146                         openDevNull(STDERR_FILENO);
 147
 148                         /* exec the log-process (skip the | ) */
 149                         execl("/bin/sh", "sh", "-c", logfile + 1, NULL);
 150                         log_error_write(srv, __FILE__, __LINE__, "sss",
 151                                         "spawning log process failed: ", strerror(errno),
 152                                         logfile + 1);
 153
 154                         exit(-1);
 155                         break;
 156                 case -1:
 157                         /* error */
 158                         log_error_write(srv, __FILE__, __LINE__, "ss", "fork failed: ", strerror(errno));
 159                         return -1;
 160                 default:
 161                         close(to_log_fds[0]);
 162                         fd = to_log_fds[1];
 163                         break;
 164                 }
 165
 166 #else
 167                 return -1;
 168 #endif
 169         } else if (-1 == (fd = open(logfile, O_APPEND | O_WRONLY | O_CREAT | O_LARGEFILE, 0644))) {
 170                 log_error_write(srv, __FILE__, __LINE__, "SSSS",
 171                                 "opening errorlog '", logfile,
 172                                 "' failed: ", strerror(errno));
 173
 174                 return -1;
 175         }
 176
 177         fd_close_on_exec(fd);
 178
 179         return fd;
 180 }
 181
 182
 183 /**
 184  * open the errorlog
 185  *
 186  * we have 4 possibilities:
 187  * - stderr (default)
 188  * - syslog
 189  * - logfile
 190  * - pipe
 191  *
 192  * if the open failed, report to the user and die
 193  *
 194  */
 195
 196 int log_error_open(server *srv) {
 197 #ifdef HAVE_SYSLOG_H
 198         /* perhaps someone wants to use syslog() */
 199         openlog("lighttpd", LOG_CONS | LOG_PID, LOG_DAEMON);
 200 #endif
 201
 202         srv->errorlog_mode = ERRORLOG_FD;
 203         srv->errorlog_fd = STDERR_FILENO;
 204
 205         if (srv->srvconf.errorlog_use_syslog) {
 206                 srv->errorlog_mode = ERRORLOG_SYSLOG;
 207         } else if (!buffer_string_is_empty(srv->srvconf.errorlog_file)) {
 208                 const char *logfile = srv->srvconf.errorlog_file->ptr;
 209
 210                 if (-1 == (srv->errorlog_fd = open_logfile_or_pipe(srv, logfile))) {
 211                         return -1;
 212                 }
 213                 srv->errorlog_mode = (logfile[0] == '|') ? ERRORLOG_PIPE : ERRORLOG_FILE;
 214         }
 215
 216         log_error_write(srv, __FILE__, __LINE__, "s", "server started");
 217
 218         if (srv->errorlog_mode == ERRORLOG_FD && !srv->srvconf.dont_daemonize) {
 219                 /* We can only log to stderr in dont-daemonize mode;
 220                  * if we do daemonize and no errorlog file is specified, we log into /dev/null
 221                  */
 222                 srv->errorlog_fd = -1;
 223         }
 224
 225         if (!buffer_string_is_empty(srv->srvconf.breakagelog_file)) {
 226                 int breakage_fd;
 227                 const char *logfile = srv->srvconf.breakagelog_file->ptr;
 228
 229                 if (srv->errorlog_mode == ERRORLOG_FD) {
 230                         srv->errorlog_fd = dup(STDERR_FILENO);
 231                         fd_close_on_exec(srv->errorlog_fd);
 232                 }
 233
 234                 if (-1 == (breakage_fd = open_logfile_or_pipe(srv, logfile))) {
 235                         return -1;
 236                 }
 237
 238                 if (STDERR_FILENO != breakage_fd) {
 239                         dup2(breakage_fd, STDERR_FILENO);
 240                         close(breakage_fd);
 241                 }
 242         } else if (!srv->srvconf.dont_daemonize) {
 243                 /* move stderr to /dev/null */
 244                 openDevNull(STDERR_FILENO);
 245         }
 246         return 0;
 247 }
 248
 249 /**
 250  * open the errorlog
 251  *
 252  * if the open failed, report to the user and die
 253  * if no filename is given, use syslog instead
 254  *
 255  */
 256
 257 int log_error_cycle(server *srv) {
 258         /* only cycle if the error log is a file */
 259
 260         if (srv->errorlog_mode == ERRORLOG_FILE) {
 261                 const char *logfile = srv->srvconf.errorlog_file->ptr;
 262                 /* already check of opening time */
 263
 264                 int new_fd;
 265
 266                 if (-1 == (new_fd = open_logfile_or_pipe(srv, logfile))) {
 267                         /* write to old log */
 268                         log_error_write(srv, __FILE__, __LINE__, "SSSSS",
 269                                         "cycling errorlog '", logfile,
 270                                         "' failed: ", strerror(errno),
 271                                         ", falling back to syslog()");
 272
 273                         close(srv->errorlog_fd);
 274                         srv->errorlog_fd = -1;
 275 #ifdef HAVE_SYSLOG_H
 276                         srv->errorlog_mode = ERRORLOG_SYSLOG;
 277 #endif
 278                 } else {
 279                         /* ok, new log is open, close the old one */
 280                         close(srv->errorlog_fd);
 281                         srv->errorlog_fd = new_fd;
 282                         fd_close_on_exec(srv->errorlog_fd);
 283                 }
 284         }
 285
 286         return 0;
 287 }
 288
 289 int log_error_close(server *srv) {
 290         switch(srv->errorlog_mode) {
 291         case ERRORLOG_PIPE:
 292         case ERRORLOG_FILE:
 293         case ERRORLOG_FD:
 294                 if (-1 != srv->errorlog_fd) {
 295                         /* don't close STDERR */
 296                         if (STDERR_FILENO != srv->errorlog_fd)
 297                                 close(srv->errorlog_fd);
 298                         srv->errorlog_fd = -1;
 299                 }
 300                 break;
 301         case ERRORLOG_SYSLOG:
 302 #ifdef HAVE_SYSLOG_H
 303                 closelog();
 304 #endif
 305                 break;
 306         }
 307
 308         return 0;
 309 }
 310
 311 /* lowercase: append space, uppercase: don't */
 312 static void log_buffer_append_printf(buffer *out, const char *fmt, va_list ap) {
 313         for(; *fmt; fmt++) {
 314                 int d;
 315                 char *s;
 316                 buffer *b;
 317                 off_t o;
 318
 319                 switch(*fmt) {
 320                 case 's':           /* string */
 321                         s = va_arg(ap, char *);
 322                         buffer_append_string_c_escaped(out, s, (NULL != s) ? strlen(s) : 0);
 323                         buffer_append_string_len(out, CONST_STR_LEN(" "));
 324                         break;
 325                 case 'b':           /* buffer */
 326                         b = va_arg(ap, buffer *);
 327                         buffer_append_string_c_escaped(out, CONST_BUF_LEN(b));
 328                         buffer_append_string_len(out, CONST_STR_LEN(" "));
 329                         break;
 330                 case 'd':           /* int */
 331                         d = va_arg(ap, int);
 332                         buffer_append_int(out, d);
 333                         buffer_append_string_len(out, CONST_STR_LEN(" "));
 334                         break;
 335                 case 'o':           /* off_t */
 336                         o = va_arg(ap, off_t);
 337                         buffer_append_int(out, o);
 338                         buffer_append_string_len(out, CONST_STR_LEN(" "));
 339                         break;
 340                 case 'x':           /* int (hex) */
 341                         d = va_arg(ap, int);
 342                         buffer_append_string_len(out, CONST_STR_LEN("0x"));
 343                         buffer_append_uint_hex(out, d);
 344                         buffer_append_string_len(out, CONST_STR_LEN(" "));
 345                         break;
 346                 case 'S':           /* string */
 347                         s = va_arg(ap, char *);
 348                         buffer_append_string_c_escaped(out, s, (NULL != s) ? strlen(s) : 0);
 349                         break;
 350                 case 'B':           /* buffer */
 351                         b = va_arg(ap, buffer *);
 352                         buffer_append_string_c_escaped(out, CONST_BUF_LEN(b));
 353                         break;
 354                 case 'D':           /* int */
 355                         d = va_arg(ap, int);
 356                         buffer_append_int(out, d);
 357                         break;
 358                 case 'O':           /* off_t */
 359                         o = va_arg(ap, off_t);
 360                         buffer_append_int(out, o);
 361                         break;
 362                 case 'X':           /* int (hex) */
 363                         d = va_arg(ap, int);
 364                         buffer_append_string_len(out, CONST_STR_LEN("0x"));
 365                         buffer_append_uint_hex(out, d);
 366                         break;
 367                 case '(':
 368                 case ')':
 369                 case '<':
 370                 case '>':
 371                 case ',':
 372                 case ' ':
 373                         buffer_append_string_len(out, fmt, 1);
 374                         break;
 375                 }
 376         }
 377 }
 378
 379 static int log_buffer_prepare(buffer *b, server *srv, const char *filename, unsigned int line) {
 380         switch(srv->errorlog_mode) {
 381         case ERRORLOG_PIPE:
 382         case ERRORLOG_FILE:
 383         case ERRORLOG_FD:
 384                 if (-1 == srv->errorlog_fd) return -1;
 385                 /* cache the generated timestamp */
 386                 if (srv->cur_ts != srv->last_generated_debug_ts) {
 387                         buffer_string_prepare_copy(srv->ts_debug_str, 255);
 388                         buffer_append_strftime(srv->ts_debug_str, "%Y-%m-%d %H:%M:%S", localtime(&(srv->cur_ts)));
 389
 390                         srv->last_generated_debug_ts = srv->cur_ts;
 391                 }
 392
 393                 buffer_copy_buffer(b, srv->ts_debug_str);
 394                 buffer_append_string_len(b, CONST_STR_LEN(": ("));
 395                 break;
 396         case ERRORLOG_SYSLOG:
 397                 /* syslog is generating its own timestamps */
 398                 buffer_copy_string_len(b, CONST_STR_LEN("("));
 399                 break;
 400         }
 401
 402         buffer_append_string(b, filename);
 403         buffer_append_string_len(b, CONST_STR_LEN("."));
 404         buffer_append_int(b, line);
 405         buffer_append_string_len(b, CONST_STR_LEN(") "));
 406
 407         return 0;
 408 }
 409
 410 static void log_write(server *srv, buffer *b) {
 411         switch(srv->errorlog_mode) {
 412         case ERRORLOG_PIPE:
 413         case ERRORLOG_FILE:
 414         case ERRORLOG_FD:
 415                 buffer_append_string_len(b, CONST_STR_LEN("\n"));
 416                 write_all(srv->errorlog_fd, CONST_BUF_LEN(b));
 417                 break;
 418         case ERRORLOG_SYSLOG:
 419                 syslog(LOG_ERR, "%s", b->ptr);
 420                 break;
 421         }
 422 }
 423
 424 int log_error_write(server *srv, const char *filename, unsigned int line, const char *fmt, ...) {
 425         va_list ap;
 426
 427         if (-1 == log_buffer_prepare(srv->errorlog_buf, srv, filename, line)) return 0;
 428
 429         va_start(ap, fmt);
 430         log_buffer_append_printf(srv->errorlog_buf, fmt, ap);
 431         va_end(ap);
 432
 433         log_write(srv, srv->errorlog_buf);
 434
 435         return 0;
 436 }
 437
 438 int log_error_write_multiline_buffer(server *srv, const char *filename, unsigned int line, buffer *multiline, const char *fmt, ...) {
 439         va_list ap;
 440         size_t prefix_len;
 441         buffer *b = srv->errorlog_buf;
 442         char *pos, *end, *current_line;
 443
 444         if (buffer_string_is_empty(multiline)) return 0;
 445
 446         if (-1 == log_buffer_prepare(b, srv, filename, line)) return 0;
 447
 448         va_start(ap, fmt);
 449         log_buffer_append_printf(b, fmt, ap);
 450         va_end(ap);
 451
 452         prefix_len = buffer_string_length(b);
 453
 454         current_line = pos = multiline->ptr;
 455         end = multiline->ptr + buffer_string_length(multiline);
 456
 457         for ( ; pos <= end ; ++pos) {
 458                 switch (*pos) {
 459                 case '\n':
 460                 case '\r':
 461                 case '\0': /* handles end of string */
 462                         if (current_line < pos) {
 463                                 /* truncate to prefix */
 464                                 buffer_string_set_length(b, prefix_len);
 465
 466                                 buffer_append_string_len(b, current_line, pos - current_line);
 467                                 log_write(srv, b);
 468                         }
 469                         current_line = pos + 1;
 470                         break;
 471                 default:
 472                         break;
 473                 }
 474         }
 475
 476         return 0;
 477 }