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         /* coverity[leaked_handle : FALSE] */
 102         return (tmpfd != -1) ? 0 : -1;
 103 }
 104
 105 int open_logfile_or_pipe(server *srv, const char* logfile) {
 106         int fd;
 107
 108         if (logfile[0] == '|') {
 109 #ifdef HAVE_FORK
 110                 /* create write pipe and spawn process */
 111
 112                 int to_log_fds[2];
 113
 114                 if (pipe(to_log_fds)) {
 115                         log_error_write(srv, __FILE__, __LINE__, "ss", "pipe failed: ", strerror(errno));
 116                         return -1;
 117                 }
 118
 119                 /* fork, execve */
 120                 switch (fork()) {
 121                 case 0:
 122                         /* child */
 123                         close(STDIN_FILENO);
 124
 125                         /* dup the filehandle to STDIN */
 126                         if (to_log_fds[0] != STDIN_FILENO) {
 127                                 if (STDIN_FILENO != dup2(to_log_fds[0], STDIN_FILENO)) {
 128                                         log_error_write(srv, __FILE__, __LINE__, "ss",
 129                                                 "dup2 failed: ", strerror(errno));
 130                                         exit(-1);
 131                                 }
 132                                 close(to_log_fds[0]);
 133                         }
 134                         close(to_log_fds[1]);
 135
 136 #ifndef FD_CLOEXEC
 137                         {
 138                                 int i;
 139                                 /* we don't need the client socket */
 140                                 for (i = 3; i < 256; i++) {
 141                                         close(i);
 142                                 }
 143                         }
 144 #endif
 145
 146                         /* close old stderr */
 147                         openDevNull(STDERR_FILENO);
 148
 149                         /* exec the log-process (skip the | ) */
 150                         execl("/bin/sh", "sh", "-c", logfile + 1, NULL);
 151                         log_error_write(srv, __FILE__, __LINE__, "sss",
 152                                         "spawning log process failed: ", strerror(errno),
 153                                         logfile + 1);
 154
 155                         exit(-1);
 156                         break;
 157                 case -1:
 158                         /* error */
 159                         log_error_write(srv, __FILE__, __LINE__, "ss", "fork failed: ", strerror(errno));
 160                         return -1;
 161                 default:
 162                         close(to_log_fds[0]);
 163                         fd = to_log_fds[1];
 164                         break;
 165                 }
 166
 167 #else
 168                 return -1;
 169 #endif
 170         } else if (-1 == (fd = open(logfile, O_APPEND | O_WRONLY | O_CREAT | O_LARGEFILE, 0644))) {
 171                 log_error_write(srv, __FILE__, __LINE__, "SSSS",
 172                                 "opening errorlog '", logfile,
 173                                 "' failed: ", strerror(errno));
 174
 175                 return -1;
 176         }
 177
 178         fd_close_on_exec(fd);
 179
 180         return fd;
 181 }
 182
 183
 184 /**
 185  * open the errorlog
 186  *
 187  * we have 4 possibilities:
 188  * - stderr (default)
 189  * - syslog
 190  * - logfile
 191  * - pipe
 192  *
 193  * if the open failed, report to the user and die
 194  *
 195  */
 196
 197 int log_error_open(server *srv) {
 198 #ifdef HAVE_SYSLOG_H
 199         /* perhaps someone wants to use syslog() */
 200         openlog("lighttpd", LOG_CONS | LOG_PID, LOG_DAEMON);
 201 #endif
 202
 203         srv->errorlog_mode = ERRORLOG_FD;
 204         srv->errorlog_fd = STDERR_FILENO;
 205
 206         if (srv->srvconf.errorlog_use_syslog) {
 207                 srv->errorlog_mode = ERRORLOG_SYSLOG;
 208         } else if (!buffer_string_is_empty(srv->srvconf.errorlog_file)) {
 209                 const char *logfile = srv->srvconf.errorlog_file->ptr;
 210
 211                 if (-1 == (srv->errorlog_fd = open_logfile_or_pipe(srv, logfile))) {
 212                         return -1;
 213                 }
 214                 srv->errorlog_mode = (logfile[0] == '|') ? ERRORLOG_PIPE : ERRORLOG_FILE;
 215         }
 216
 217         log_error_write(srv, __FILE__, __LINE__, "s", "server started");
 218
 219         if (srv->errorlog_mode == ERRORLOG_FD && !srv->srvconf.dont_daemonize) {
 220                 /* We can only log to stderr in dont-daemonize mode;
 221                  * if we do daemonize and no errorlog file is specified, we log into /dev/null
 222                  */
 223                 srv->errorlog_fd = -1;
 224         }
 225
 226         if (!buffer_string_is_empty(srv->srvconf.breakagelog_file)) {
 227                 int breakage_fd;
 228                 const char *logfile = srv->srvconf.breakagelog_file->ptr;
 229
 230                 if (srv->errorlog_mode == ERRORLOG_FD) {
 231                         srv->errorlog_fd = dup(STDERR_FILENO);
 232                         fd_close_on_exec(srv->errorlog_fd);
 233                 }
 234
 235                 if (-1 == (breakage_fd = open_logfile_or_pipe(srv, logfile))) {
 236                         return -1;
 237                 }
 238
 239                 if (STDERR_FILENO != breakage_fd) {
 240                         dup2(breakage_fd, STDERR_FILENO);
 241                         close(breakage_fd);
 242                 }
 243         } else if (!srv->srvconf.dont_daemonize) {
 244                 /* move stderr to /dev/null */
 245                 openDevNull(STDERR_FILENO);
 246         }
 247         return 0;
 248 }
 249
 250 /**
 251  * open the errorlog
 252  *
 253  * if the open failed, report to the user and die
 254  * if no filename is given, use syslog instead
 255  *
 256  */
 257
 258 int log_error_cycle(server *srv) {
 259         /* only cycle if the error log is a file */
 260
 261         if (srv->errorlog_mode == ERRORLOG_FILE) {
 262                 const char *logfile = srv->srvconf.errorlog_file->ptr;
 263                 /* already check of opening time */
 264
 265                 int new_fd;
 266
 267                 if (-1 == (new_fd = open_logfile_or_pipe(srv, logfile))) {
 268                         /* write to old log */
 269                         log_error_write(srv, __FILE__, __LINE__, "SSSSS",
 270                                         "cycling errorlog '", logfile,
 271                                         "' failed: ", strerror(errno),
 272                                         ", falling back to syslog()");
 273
 274                         close(srv->errorlog_fd);
 275                         srv->errorlog_fd = -1;
 276 #ifdef HAVE_SYSLOG_H
 277                         srv->errorlog_mode = ERRORLOG_SYSLOG;
 278 #endif
 279                 } else {
 280                         /* ok, new log is open, close the old one */
 281                         close(srv->errorlog_fd);
 282                         srv->errorlog_fd = new_fd;
 283                         fd_close_on_exec(srv->errorlog_fd);
 284                 }
 285         }
 286
 287         return 0;
 288 }
 289
 290 int log_error_close(server *srv) {
 291         switch(srv->errorlog_mode) {
 292         case ERRORLOG_PIPE:
 293         case ERRORLOG_FILE:
 294         case ERRORLOG_FD:
 295                 if (-1 != srv->errorlog_fd) {
 296                         /* don't close STDERR */
 297                         if (STDERR_FILENO != srv->errorlog_fd)
 298                                 close(srv->errorlog_fd);
 299                         srv->errorlog_fd = -1;
 300                 }
 301                 break;
 302         case ERRORLOG_SYSLOG:
 303 #ifdef HAVE_SYSLOG_H
 304                 closelog();
 305 #endif
 306                 break;
 307         }
 308
 309         return 0;
 310 }
 311
 312 /* lowercase: append space, uppercase: don't */
 313 static void log_buffer_append_printf(buffer *out, const char *fmt, va_list ap) {
 314         for(; *fmt; fmt++) {
 315                 int d;
 316                 char *s;
 317                 buffer *b;
 318                 off_t o;
 319
 320                 switch(*fmt) {
 321                 case 's':           /* string */
 322                         s = va_arg(ap, char *);
 323                         buffer_append_string_c_escaped(out, s, (NULL != s) ? strlen(s) : 0);
 324                         buffer_append_string_len(out, CONST_STR_LEN(" "));
 325                         break;
 326                 case 'b':           /* buffer */
 327                         b = va_arg(ap, buffer *);
 328                         buffer_append_string_c_escaped(out, CONST_BUF_LEN(b));
 329                         buffer_append_string_len(out, CONST_STR_LEN(" "));
 330                         break;
 331                 case 'd':           /* int */
 332                         d = va_arg(ap, int);
 333                         buffer_append_int(out, d);
 334                         buffer_append_string_len(out, CONST_STR_LEN(" "));
 335                         break;
 336                 case 'o':           /* off_t */
 337                         o = va_arg(ap, off_t);
 338                         buffer_append_int(out, o);
 339                         buffer_append_string_len(out, CONST_STR_LEN(" "));
 340                         break;
 341                 case 'x':           /* int (hex) */
 342                         d = va_arg(ap, int);
 343                         buffer_append_string_len(out, CONST_STR_LEN("0x"));
 344                         buffer_append_uint_hex(out, d);
 345                         buffer_append_string_len(out, CONST_STR_LEN(" "));
 346                         break;
 347                 case 'S':           /* string */
 348                         s = va_arg(ap, char *);
 349                         buffer_append_string_c_escaped(out, s, (NULL != s) ? strlen(s) : 0);
 350                         break;
 351                 case 'B':           /* buffer */
 352                         b = va_arg(ap, buffer *);
 353                         buffer_append_string_c_escaped(out, CONST_BUF_LEN(b));
 354                         break;
 355                 case 'D':           /* int */
 356                         d = va_arg(ap, int);
 357                         buffer_append_int(out, d);
 358                         break;
 359                 case 'O':           /* off_t */
 360                         o = va_arg(ap, off_t);
 361                         buffer_append_int(out, o);
 362                         break;
 363                 case 'X':           /* int (hex) */
 364                         d = va_arg(ap, int);
 365                         buffer_append_string_len(out, CONST_STR_LEN("0x"));
 366                         buffer_append_uint_hex(out, d);
 367                         break;
 368                 case '(':
 369                 case ')':
 370                 case '<':
 371                 case '>':
 372                 case ',':
 373                 case ' ':
 374                         buffer_append_string_len(out, fmt, 1);
 375                         break;
 376                 }
 377         }
 378 }
 379
 380 static int log_buffer_prepare(buffer *b, server *srv, const char *filename, unsigned int line) {
 381         switch(srv->errorlog_mode) {
 382         case ERRORLOG_PIPE:
 383         case ERRORLOG_FILE:
 384         case ERRORLOG_FD:
 385                 if (-1 == srv->errorlog_fd) return -1;
 386                 /* cache the generated timestamp */
 387                 if (srv->cur_ts != srv->last_generated_debug_ts) {
 388                         buffer_string_prepare_copy(srv->ts_debug_str, 255);
 389                         buffer_append_strftime(srv->ts_debug_str, "%Y-%m-%d %H:%M:%S", localtime(&(srv->cur_ts)));
 390
 391                         srv->last_generated_debug_ts = srv->cur_ts;
 392                 }
 393
 394                 buffer_copy_buffer(b, srv->ts_debug_str);
 395                 buffer_append_string_len(b, CONST_STR_LEN(": ("));
 396                 break;
 397         case ERRORLOG_SYSLOG:
 398                 /* syslog is generating its own timestamps */
 399                 buffer_copy_string_len(b, CONST_STR_LEN("("));
 400                 break;
 401         }
 402
 403         buffer_append_string(b, filename);
 404         buffer_append_string_len(b, CONST_STR_LEN("."));
 405         buffer_append_int(b, line);
 406         buffer_append_string_len(b, CONST_STR_LEN(") "));
 407
 408         return 0;
 409 }
 410
 411 static void log_write(server *srv, buffer *b) {
 412         switch(srv->errorlog_mode) {
 413         case ERRORLOG_PIPE:
 414         case ERRORLOG_FILE:
 415         case ERRORLOG_FD:
 416                 buffer_append_string_len(b, CONST_STR_LEN("\n"));
 417                 write_all(srv->errorlog_fd, CONST_BUF_LEN(b));
 418                 break;
 419         case ERRORLOG_SYSLOG:
 420                 syslog(LOG_ERR, "%s", b->ptr);
 421                 break;
 422         }
 423 }
 424
 425 int log_error_write(server *srv, const char *filename, unsigned int line, const char *fmt, ...) {
 426         va_list ap;
 427
 428         if (-1 == log_buffer_prepare(srv->errorlog_buf, srv, filename, line)) return 0;
 429
 430         va_start(ap, fmt);
 431         log_buffer_append_printf(srv->errorlog_buf, fmt, ap);
 432         va_end(ap);
 433
 434         log_write(srv, srv->errorlog_buf);
 435
 436         return 0;
 437 }
 438
 439 int log_error_write_multiline_buffer(server *srv, const char *filename, unsigned int line, buffer *multiline, const char *fmt, ...) {
 440         va_list ap;
 441         size_t prefix_len;
 442         buffer *b = srv->errorlog_buf;
 443         char *pos, *end, *current_line;
 444
 445         if (buffer_string_is_empty(multiline)) return 0;
 446
 447         if (-1 == log_buffer_prepare(b, srv, filename, line)) return 0;
 448
 449         va_start(ap, fmt);
 450         log_buffer_append_printf(b, fmt, ap);
 451         va_end(ap);
 452
 453         prefix_len = buffer_string_length(b);
 454
 455         current_line = pos = multiline->ptr;
 456         end = multiline->ptr + buffer_string_length(multiline);
 457
 458         for ( ; pos <= end ; ++pos) {
 459                 switch (*pos) {
 460                 case '\n':
 461                 case '\r':
 462                 case '\0': /* handles end of string */
 463                         if (current_line < pos) {
 464                                 /* truncate to prefix */
 465                                 buffer_string_set_length(b, prefix_len);
 466
 467                                 buffer_append_string_len(b, current_line, pos - current_line);
 468                                 log_write(srv, b);
 469                         }
 470                         current_line = pos + 1;
 471                         break;
 472                 default:
 473                         break;
 474                 }
 475         }
 476
 477         return 0;
 478 }