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