error.c

   1 /* source: error.c */
   2 /* Copyright Gerhard Rieger and contributors (see file CHANGES) */
   3 /* Published under the GNU General Public License V.2, see file COPYING */
   4
   5 /* the logging subsystem */
   6
   7 #include "config.h"
   8 #include "sysincludes.h"
   9
  10 #include "mytypes.h"
  11 #include "compat.h"
  12 #include "utils.h"
  13 #include "vsnprintf_r.h"
  14 #include "snprinterr.h"
  15
  16 #include "error.h"
  17 #include "sycls.h"
  18
  19
  20 /* translate MSG level to SYSLOG level */
  21 int syslevel[] = {
  22    LOG_DEBUG,
  23    LOG_INFO,
  24    LOG_NOTICE,
  25    LOG_WARNING,
  26    LOG_ERR,
  27    LOG_CRIT };
  28
  29 struct diag_opts {
  30    const char *progname;
  31    int msglevel;
  32    int shutup;          /* decrease msglevel by this value */
  33    int exitlevel;
  34    int syslog;
  35    FILE *logfile;
  36    int logfacility;
  37    bool micros;
  38    int exitstatus;      /* pass signal number to error exit */
  39    bool withhostname;   /* in custom logs add hostname */
  40    char *hostname;
  41    bool signalsafe;
  42 } ;
  43
  44
  45 static void _diag_exit(int status);
  46
  47
  48 struct diag_opts diagopts =
  49    { NULL, E_WARN, 0, E_ERROR, 0, NULL, LOG_DAEMON, false, 0, false, NULL, true } ;
  50
  51 static void msg2(
  52 #if HAVE_CLOCK_GETTIME
  53                  struct timespec *now,
  54 #elif HAVE_PROTOTYPE_LIB_gettimeofday
  55                  struct timeval *now,
  56 #else
  57                  time_t *now,
  58 #endif
  59                  int level, int exitcode, int handler, const char *text);
  60 static void _msg(int level, const char *buff, const char *syslp);
  61
  62 volatile sig_atomic_t diag_in_handler;  /* !=0 indicates to msg() that in signal handler */
  63 volatile sig_atomic_t diag_immediate_msg;       /* !=0 prints messages even from within signal handler instead of deferring them */
  64 volatile sig_atomic_t diag_immediate_exit;      /* !=0 calls exit() from diag_exit() even when in signal handler. For system() */
  65
  66 static struct wordent facilitynames[] = {
  67    {"auth",     (void *)LOG_AUTH},
  68 #ifdef LOG_AUTHPRIV
  69    {"authpriv", (void *)LOG_AUTHPRIV},
  70 #endif
  71 #ifdef LOG_CONSOLE
  72    {"console",  (void *)LOG_CONSOLE},
  73 #endif
  74    {"cron",     (void *)LOG_CRON},
  75    {"daemon",   (void *)LOG_DAEMON},
  76 #ifdef LOG_FTP
  77    {"ftp",      (void *)LOG_FTP},
  78 #endif
  79    {"kern",     (void *)LOG_KERN},
  80    {"local0",   (void *)LOG_LOCAL0},
  81    {"local1",   (void *)LOG_LOCAL1},
  82    {"local2",   (void *)LOG_LOCAL2},
  83    {"local3",   (void *)LOG_LOCAL3},
  84    {"local4",   (void *)LOG_LOCAL4},
  85    {"local5",   (void *)LOG_LOCAL5},
  86    {"local6",   (void *)LOG_LOCAL6},
  87    {"local7",   (void *)LOG_LOCAL7},
  88    {"lpr",      (void *)LOG_LPR},
  89    {"mail",     (void *)LOG_MAIL},
  90    {"news",     (void *)LOG_NEWS},
  91 #ifdef LOG_SECURITY
  92    {"security", (void *)LOG_SECURITY},
  93 #endif
  94    {"syslog",   (void *)LOG_SYSLOG},
  95    {"user",     (void *)LOG_USER},
  96    {"uucp",     (void *)LOG_UUCP}
  97 } ;
  98
  99 /* serialize message for sending from signal handlers */
 100 struct sermsg {
 101    int severity;
 102 #if HAVE_CLOCK_GETTIME
 103    struct timespec ts;
 104 #else
 105    struct timeval tv;
 106 #endif
 107 } ;
 108
 109 static int diaginitialized;
 110 static int diag_sock_send = -1;
 111 static int diag_sock_recv = -1;
 112 static volatile sig_atomic_t diag_msg_avail = 0;        /* !=0: messages from within signal handler may be waiting */
 113
 114
 115 static int diag_sock_pair(void) {
 116    int handlersocks[2];
 117
 118    if (socketpair(AF_UNIX, SOCK_DGRAM, 0, handlersocks) < 0) {
 119       diag_sock_send = -1;
 120       diag_sock_recv = -1;
 121       return -1;
 122    }
 123    fcntl(handlersocks[0], F_SETFD, FD_CLOEXEC);
 124    fcntl(handlersocks[1], F_SETFD, FD_CLOEXEC);
 125    diag_sock_send = handlersocks[1];
 126    diag_sock_recv = handlersocks[0];
 127 #if !defined(MSG_DONTWAIT)
 128    fcntl(diag_sock_send, F_SETFL, O_NONBLOCK);
 129    fcntl(diag_sock_recv, F_SETFL, O_NONBLOCK);
 130 #endif
 131    fcntl(diag_sock_send, F_SETFD, FD_CLOEXEC);
 132    fcntl(diag_sock_recv, F_SETFD, FD_CLOEXEC);
 133    return 0;
 134 }
 135
 136 static int diag_init(void) {
 137    if (diaginitialized) {
 138       return 0;
 139    }
 140    diaginitialized = 1;
 141    /* gcc with GNU libc refuses to set this in the initializer */
 142    diagopts.logfile = stderr;
 143    if (diagopts.signalsafe) {
 144       if (diag_sock_pair() < 0) {
 145          return -1;
 146       }
 147    }
 148    return 0;
 149 }
 150 #define DIAG_INIT ((void)(diaginitialized || diag_init()))
 151
 152
 153 void diag_set(char what, const char *arg) {
 154    switch (what) {
 155    case 'I':
 156       if (diagopts.signalsafe) {
 157          if (diag_sock_send >= 0) { Close(diag_sock_send); diag_sock_send = -1; }
 158          if (diag_sock_recv >= 0) { Close(diag_sock_recv); diag_sock_recv = -1; }
 159       }
 160       diagopts.signalsafe = false;
 161       return;
 162    }
 163
 164    DIAG_INIT;
 165    switch (what) {
 166       const struct wordent *keywd;
 167
 168    case 'y': diagopts.syslog = true;
 169       if (arg && arg[0]) {
 170          if ((keywd =
 171               keyw(facilitynames, arg,
 172                    sizeof(facilitynames)/sizeof(struct wordent))) == NULL) {
 173             Error1("unknown syslog facility \"%s\"", arg);
 174          } else {
 175             diagopts.logfacility = (int)(size_t)keywd->desc;
 176          }
 177       }
 178       openlog(diagopts.progname, LOG_PID, diagopts.logfacility);
 179       if (diagopts.logfile != NULL && diagopts.logfile != stderr) {
 180          fclose(diagopts.logfile);
 181       }
 182       diagopts.logfile = NULL;
 183       break;
 184    case 'f':
 185       if (diagopts.logfile != NULL && diagopts.logfile != stderr) {
 186          fclose(diagopts.logfile);
 187       }
 188       if ((diagopts.logfile = fopen(arg, "a")) == NULL) {
 189           Error2("cannot open log file \"%s\": %s", arg, strerror(errno));
 190       }
 191       break;
 192    case 's':
 193       if (diagopts.logfile != NULL && diagopts.logfile != stderr) {
 194          fclose(diagopts.logfile);
 195       }
 196       diagopts.logfile = stderr; break; /* logging to stderr is default */
 197    case 'p': diagopts.progname = arg;
 198       openlog(diagopts.progname, LOG_PID, diagopts.logfacility);
 199       break;
 200    case 'u': diagopts.micros = true; break;
 201    default: msg(E_ERROR, "unknown diagnostic option %c", what);
 202    }
 203 }
 204
 205 void diag_set_int(char what, int arg) {
 206    DIAG_INIT;
 207    switch (what) {
 208    case 'D': diagopts.msglevel = arg; break;
 209    case 'e': diagopts.exitlevel = arg; break;
 210    case 'x': diagopts.exitstatus = arg; break;
 211    case 'd':
 212       diagopts.msglevel = arg;
 213       break;
 214    case 'h': diagopts.withhostname = arg;
 215       if ((diagopts.hostname = getenv("HOSTNAME")) == NULL) {
 216          struct utsname ubuf;
 217          uname(&ubuf);
 218          diagopts.hostname = strdup(ubuf.nodename);
 219       }
 220       break;
 221    case 'u':
 222       diagopts.shutup = arg;
 223       diagopts.exitlevel -= arg;
 224       break;
 225    default: msg(E_ERROR, "unknown diagnostic option %c", what);
 226    }
 227 }
 228
 229 int diag_get_int(char what) {
 230    DIAG_INIT;
 231    switch (what) {
 232    case 'y': return diagopts.syslog;
 233    case 's': return diagopts.logfile == stderr;
 234    case 'd': case 'D': return diagopts.msglevel;
 235    case 'e': return diagopts.exitlevel;
 236    }
 237    return -1;
 238 }
 239
 240 const char *diag_get_string(char what) {
 241    DIAG_INIT;
 242    switch (what) {
 243    case 'p': return diagopts.progname;
 244    }
 245    return NULL;
 246 }
 247
 248 /* make sure that the diag_sock fds do not have this num */
 249 int diag_reserve_fd(int fd) {
 250    DIAG_INIT;
 251    if (diag_sock_send == fd) {
 252       diag_sock_send = Dup(fd);
 253       Close(fd);
 254    }
 255    if (diag_sock_recv == fd) {
 256       diag_sock_recv = Dup(fd);
 257       Close(fd);
 258    }
 259    return 0;
 260 }
 261
 262 /* call this after a fork() from the child process to separate master/parent
 263    sockets from child sockets */
 264 int diag_fork() {
 265    Close(diag_sock_send);
 266    Close(diag_sock_recv);
 267    if (diagopts.signalsafe) {
 268       return diag_sock_pair();
 269    }
 270    return 0;
 271 }
 272
 273 /* Linux and AIX syslog format:
 274 Oct  4 17:10:37 hostname socat[52798]: D signal(13, 1)
 275 */
 276 void msg(int level, const char *format, ...) {
 277    struct diag_dgram diag_dgram;
 278    va_list ap;
 279
 280    /* does not perform a system call if nothing todo, thanks diag_msg_avail */
 281
 282    diag_dgram._errno = errno;   /* keep for passing from signal handler to sock.
 283                                    reason is that strerror is definitely not
 284                                    async-signal-safe */
 285    DIAG_INIT;
 286
 287    /* in normal program flow (not in signal handler) */
 288    /* first flush the queue of datagrams from the socket */
 289    if (diag_msg_avail && !diag_in_handler) {
 290       diag_flush();
 291    }
 292
 293    level -= diagopts.shutup;    /* decrease severity of messages? */
 294
 295    /* Just ignore this call when level too low for both logging and exiting */
 296    if (level < diagopts.msglevel && level < diagopts.exitlevel)
 297       return;
 298
 299    va_start(ap, format);
 300
 301    /* we do only a minimum in the outer parts which may run in a signal handler
 302       these are: get actual time, level, serialized message  and write them to socket
 303    */
 304    diag_dgram.op = DIAG_OP_MSG;
 305 #if HAVE_CLOCK_GETTIME
 306    clock_gettime(CLOCK_REALTIME, &diag_dgram.now);
 307 #elif HAVE_PROTOTYPE_LIB_gettimeofday
 308    gettimeofday(&diag_dgram.now, NULL);
 309 #else
 310    diag_dgram.now = time(NULL);
 311 #endif
 312    diag_dgram.level = level;
 313    diag_dgram.exitcode = diagopts.exitstatus;
 314    if (level >= diagopts.msglevel)
 315       vsnprintf_r(diag_dgram.text, sizeof(diag_dgram.text), format, ap);
 316    else
 317       diag_dgram.text[0] = '\0';
 318    if (diagopts.signalsafe && diag_in_handler && !diag_immediate_msg) {
 319       send(diag_sock_send, &diag_dgram, sizeof(diag_dgram)-TEXTLEN + strlen(diag_dgram.text)+1,
 320            0    /* for canonical reasons */
 321 #ifdef MSG_DONTWAIT
 322            |MSG_DONTWAIT
 323 #endif
 324 #ifdef MSG_NOSIGNAL
 325            |MSG_NOSIGNAL
 326 #endif
 327            );
 328       diag_msg_avail = 1;
 329       va_end(ap);
 330       return;
 331    }
 332
 333    msg2(&diag_dgram.now, diag_dgram.level, diagopts.exitstatus, 0, diag_dgram.text);
 334    va_end(ap); return;
 335 }
 336
 337 void msg2(
 338 #if HAVE_CLOCK_GETTIME
 339           struct timespec *now,
 340 #elif HAVE_PROTOTYPE_LIB_gettimeofday
 341           struct timeval *now,
 342 #else
 343           time_t *now,
 344 #endif
 345           int level,            /* E_INFO... */
 346           int exitcode,         /* on exit use this exit code */
 347           int handler,          /* message comes from signal handler */
 348           const char *text) {
 349    time_t epoch;
 350    unsigned long micros;
 351 #if HAVE_STRFTIME
 352    struct tm struct_tm;
 353 #endif
 354 #define MSGLEN 512
 355    char buff[MSGLEN+2], *bufp = buff, *syslp = NULL;
 356    size_t bytes;
 357
 358    if (text[0] != '\0') {
 359 #if HAVE_CLOCK_GETTIME
 360    epoch = now->tv_sec;
 361 #elif HAVE_PROTOTYPE_LIB_gettimeofday
 362    epoch = now->tv_sec;
 363 #else
 364    epoch = *now;
 365 #endif
 366    /*! consider caching instead of recalculating many times per second */
 367 #if HAVE_STRFTIME
 368    bytes = strftime(bufp, 20, "%Y/%m/%d %H:%M:%S", localtime_r(&epoch, &struct_tm));
 369 #else
 370    bytes = snprintf(bufp, 11, F_time, epoch);
 371 #endif
 372    bufp += bytes;
 373    *bufp = '\0';
 374    if (diagopts.micros) {
 375 #if HAVE_CLOCK_GETTIME
 376       micros = now->tv_nsec/1000;
 377 #elif HAVE_PROTOTYPE_LIB_gettimeofday
 378       micros = now->tv_usec;
 379 #else
 380       micros = 0;
 381 #endif
 382       bufp += sprintf(bufp, ".%06lu ", micros);
 383    } else {
 384       *bufp++ = ' ';
 385       *bufp = '\0';
 386    }
 387
 388    if (diagopts.withhostname) {
 389       bytes = snprintf(bufp, MSGLEN-(bufp-buff), "%s ", diagopts.hostname);
 390       if (bytes >= MSGLEN-(bufp-buff))
 391          bytes = MSGLEN-(bufp-buff)-1;
 392       bufp += bytes;
 393    }
 394    bytes = snprintf(bufp, MSGLEN-(bufp-buff), "%s["F_pid"] ", diagopts.progname, getpid());
 395    if (bytes >= MSGLEN-(bufp-buff))
 396       bytes = MSGLEN-(bufp-buff)-1;
 397    bufp += bytes;
 398    syslp = bufp;        /* syslog prefixes with time etc.itself */
 399    if (bufp < buff+MSGLEN)
 400       *bufp++ = "DINWEF"[level];
 401 #if 0 /* only for debugging socat */
 402    if (handler)  bufp[-1] = tolower((unsigned char)bufp[-1]); /* for debugging, low chars indicate messages from signal handlers */
 403 #endif
 404    if (bufp < buff+MSGLEN)
 405       *bufp++ = ' ';
 406    strncpy(bufp, text, MSGLEN-(bufp-buff));
 407    bufp[MSGLEN-(bufp-buff)] = 0;
 408    bufp = strchr(bufp, '\0');
 409    strcpy(bufp, "\n");
 410    _msg(level, buff, syslp);
 411   }
 412    if (level >= diagopts.exitlevel) {
 413       if (E_NOTICE >= diagopts.msglevel && text[0] != '\0') {
 414          if ((syslp - buff) + 16 > MSGLEN+1)
 415             syslp = buff + MSGLEN - 15;
 416          snprintf_r(syslp, 16, "N exit(%d)\n", exitcode?exitcode:(diagopts.exitstatus?diagopts.exitstatus:1));
 417          _msg(E_NOTICE, buff, syslp);
 418       }
 419       exit(exitcode?exitcode:(diagopts.exitstatus?diagopts.exitstatus:1));
 420    }
 421 }
 422
 423
 424 static void _msg(int level, const char *buff, const char *syslp) {
 425    if (diagopts.syslog) {
 426       /* prevent format string attacks (thanks to CoKi) */
 427       syslog(syslevel[level], "%s", syslp);
 428    }
 429    if (diagopts.logfile) {
 430       fputs(buff, diagopts.logfile); fflush(diagopts.logfile);
 431    }
 432 }
 433
 434
 435 /* handle the messages in the queue */
 436 void diag_flush(void) {
 437    struct diag_dgram recv_dgram;
 438    char exitmsg[20];
 439
 440    if (diag_msg_avail == 0) {
 441       return;
 442    }
 443    diag_msg_avail = 0;
 444
 445    if (!diagopts.signalsafe) {
 446       return;
 447    }
 448
 449    while (recv(diag_sock_recv, &recv_dgram, sizeof(recv_dgram)-1,
 450                0        /* for canonical reasons */
 451 #ifdef MSG_DONTWAIT
 452                |MSG_DONTWAIT
 453 #endif
 454                ) > 0) {
 455       recv_dgram.text[TEXTLEN-1] = '\0';
 456       switch (recv_dgram.op) {
 457       case DIAG_OP_EXIT:
 458          /* we want the actual time, not when this dgram was sent */
 459 #if HAVE_CLOCK_GETTIME
 460          clock_gettime(CLOCK_REALTIME, &recv_dgram.now);
 461 #elif HAVE_PROTOTYPE_LIB_gettimeofday
 462          gettimeofday(&recv_dgram.now, NULL);
 463 #else
 464          recv_dgram.now = time(NULL);
 465 #endif
 466          if (E_NOTICE >= diagopts.msglevel) {
 467             snprintf_r(exitmsg, sizeof(exitmsg), "exit(%d)", recv_dgram.exitcode?recv_dgram.exitcode:1);
 468             msg2(&recv_dgram.now, E_NOTICE, recv_dgram.exitcode?recv_dgram.exitcode:1, 1, exitmsg);
 469          }
 470          exit(recv_dgram.exitcode?recv_dgram.exitcode:1);
 471       case DIAG_OP_MSG:
 472          if (recv_dgram._errno) {
 473             /* there might be a %m control in the string (glibc compatible,
 474                replace with strerror(...errno) ) */
 475             char text[TEXTLEN];
 476             errno = recv_dgram._errno;
 477             snprinterr(text, TEXTLEN, recv_dgram.text);
 478             msg2(&recv_dgram.now, recv_dgram.level, recv_dgram.exitcode, 1, text);
 479          } else {
 480             msg2(&recv_dgram.now, recv_dgram.level, recv_dgram.exitcode, 1, recv_dgram.text);
 481          }
 482          break;
 483       }
 484    }
 485 }
 486
 487
 488 /* use a new log output file descriptor that is dup'ed from the current one.
 489    this is useful when socat logs to stderr but fd 2 should be redirected to
 490    serve other purposes */
 491 int diag_dup(void) {
 492    int newfd;
 493
 494    DIAG_INIT;
 495    if (diagopts.logfile == NULL) {
 496       return -1;
 497    }
 498    newfd = dup(fileno(diagopts.logfile));
 499    Fcntl_l(newfd, F_SETFD, FD_CLOEXEC);
 500    if (diagopts.logfile != stderr) {
 501       fclose(diagopts.logfile);
 502    }
 503    if (newfd >= 0) {
 504       diagopts.logfile = fdopen(newfd, "w");
 505    }
 506    return newfd;
 507 }
 508
 509
 510 /* this function is kind of async-signal-safe exit(). When invoked from signal
 511    handler it defers exit. */
 512 void diag_exit(int status) {
 513    struct diag_dgram diag_dgram;
 514
 515    if (diag_in_handler && !diag_immediate_exit) {
 516       diag_dgram.op = DIAG_OP_EXIT;
 517       diag_dgram.exitcode = status;
 518       send(diag_sock_send, &diag_dgram, sizeof(diag_dgram)-TEXTLEN,
 519            0    /* for canonical reasons */
 520 #ifdef MSG_DONTWAIT
 521            |MSG_DONTWAIT
 522 #endif
 523 #ifdef MSG_NOSIGNAL
 524            |MSG_NOSIGNAL
 525 #endif
 526            );
 527       diag_msg_avail = 1;
 528       return;
 529    }
 530    _diag_exit(status);
 531 }
 532
 533 static void _diag_exit(int status) {
 534    Exit(status);
 535 }
 536
 537
 538 /* a function that appears to the application like select() but that also
 539    monitors the diag socket diag_sock_recv and processes its messages.
 540    Do not call from within a signal handler. */
 541 int diag_select(int nfds, fd_set *readfds, fd_set *writefds,
 542                  fd_set *exceptfds, struct timeval *timeout) {
 543    int result;
 544    fd_set save_readfds, save_writefds, save_exceptfds;
 545
 546    if (readfds)   { memcpy(&save_readfds,   readfds,   sizeof(*readfds)); }
 547    if (writefds)  { memcpy(&save_writefds,  writefds,  sizeof(*writefds)); }
 548    if (exceptfds) { memcpy(&save_exceptfds, exceptfds, sizeof(*exceptfds)); }
 549
 550    while (1) {
 551       FD_SET(diag_sock_recv, readfds);
 552       result = Select(nfds, readfds, writefds,
 553                        exceptfds, timeout);
 554      if (!FD_ISSET(diag_sock_recv, readfds)) {
 555          /* select terminated not due to diag_sock_recv, normalt continuation */
 556          break;
 557       }
 558       diag_flush();
 559       if (readfds)   { memcpy(readfds,   &save_readfds,   sizeof(*readfds)); }
 560       if (writefds)  { memcpy(writefds,  &save_writefds,  sizeof(*writefds)); }
 561       if (exceptfds) { memcpy(exceptfds, &save_exceptfds, sizeof(*exceptfds)); }
 562    }
 563    return result;
 564 }
 565