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