ctdb/common/logging.c

   1 /*
   2    Logging utilities
   3
   4    Copyright (C) Andrew Tridgell  2008
   5    Copyright (C) Martin Schwenke  2014
   6    Copyright (C) Amitay Isaacs  2015
   7
   8    This program is free software; you can redistribute it and/or modify
   9    it under the terms of the GNU General Public License as published by
  10    the Free Software Foundation; either version 3 of the License, or
  11    (at your option) any later version.
  12
  13    This program is distributed in the hope that it will be useful,
  14    but WITHOUT ANY WARRANTY; without even the implied warranty of
  15    MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
  16    GNU General Public License for more details.
  17
  18    You should have received a copy of the GNU General Public License
  19    along with this program; if not, see <http://www.gnu.org/licenses/>.
  20 */
  21
  22 #include "replace.h"
  23 #include "system/network.h"
  24 #include "system/locale.h"
  25 #include "system/time.h"
  26 #include "system/filesys.h"
  27 #include "system/syslog.h"
  28
  29 #include "lib/util/time_basic.h"
  30 #include "lib/util/sys_rw.h"
  31 #include "lib/util/debug.h"
  32 #include "lib/util/blocking.h"
  33 #include "lib/util/samba_util.h" /* get_myname() */
  34
  35 #include "common/logging.h"
  36
  37 struct {
  38         int log_level;
  39         const char *log_string;
  40 } log_string_map[] = {
  41         { DEBUG_ERR,     "ERROR" },
  42         { DEBUG_WARNING, "WARNING" },
  43         { 2,             "WARNING" },
  44         { DEBUG_NOTICE,  "NOTICE" },
  45         { 4,             "NOTICE" },
  46         { DEBUG_INFO,    "INFO" },
  47         { 6,             "INFO" },
  48         { 7,             "INFO" },
  49         { 8,             "INFO" },
  50         { 9,             "INFO" },
  51         { DEBUG_DEBUG,   "DEBUG" },
  52 };
  53
  54 bool debug_level_parse(const char *log_string, int *log_level)
  55 {
  56         int i;
  57
  58         if (log_string == NULL) {
  59                 return false;
  60         }
  61
  62         if (isdigit(log_string[0])) {
  63                 int level = atoi(log_string);
  64
  65                 if (level >= 0 && level < ARRAY_SIZE(log_string_map)) {
  66                         *log_level = level;
  67                         return true;
  68                 }
  69                 return false;
  70         }
  71
  72         for (i=0; i<ARRAY_SIZE(log_string_map); i++) {
  73                 if (strncasecmp(log_string_map[i].log_string,
  74                                 log_string, strlen(log_string)) == 0) {
  75                         *log_level = log_string_map[i].log_level;
  76                         return true;
  77                 }
  78         }
  79
  80         return false;
  81 }
  82
  83 const char *debug_level_to_string(int log_level)
  84 {
  85         int i;
  86
  87         for (i=0; ARRAY_SIZE(log_string_map); i++) {
  88                 if (log_string_map[i].log_level == log_level) {
  89                         return log_string_map[i].log_string;
  90                 }
  91         }
  92         return "UNKNOWN";
  93 }
  94
  95 int debug_level_from_string(const char *log_string)
  96 {
  97         bool found;
  98         int log_level;
  99
 100         found = debug_level_parse(log_string, &log_level);
 101         if (found) {
 102                 return log_level;
 103         }
 104
 105         /* Default debug level */
 106         return DEBUG_ERR;
 107 }
 108
 109 /*
 110  * file logging backend
 111  */
 112
 113 struct file_log_state {
 114         const char *app_name;
 115         int fd;
 116         char buffer[1024];
 117 };
 118
 119 static void file_log(void *private_data, int level, const char *msg)
 120 {
 121         struct file_log_state *state = talloc_get_type_abort(
 122                 private_data, struct file_log_state);
 123         struct timeval tv;
 124         struct timeval_buf tvbuf;
 125         int ret;
 126
 127         if (state->fd == STDERR_FILENO) {
 128                 ret = snprintf(state->buffer, sizeof(state->buffer),
 129                                "%s[%u]: %s\n",
 130                                state->app_name, (unsigned)getpid(), msg);
 131         } else {
 132                 GetTimeOfDay(&tv);
 133                 timeval_str_buf(&tv, false, true, &tvbuf);
 134
 135                 ret = snprintf(state->buffer, sizeof(state->buffer),
 136                                "%s %s[%u]: %s\n", tvbuf.buf,
 137                                state->app_name, (unsigned)getpid(), msg);
 138         }
 139         if (ret < 0) {
 140                 return;
 141         }
 142
 143         state->buffer[sizeof(state->buffer)-1] = '\0';
 144
 145         sys_write_v(state->fd, state->buffer, strlen(state->buffer));
 146 }
 147
 148 static int file_log_state_destructor(struct file_log_state *state)
 149 {
 150         if (state->fd != -1 && state->fd != STDERR_FILENO) {
 151                 close(state->fd);
 152                 state->fd = -1;
 153         }
 154         return 0;
 155 }
 156
 157 static int file_log_setup(TALLOC_CTX *mem_ctx, const char *option,
 158                           const char *app_name)
 159 {
 160         struct file_log_state *state;
 161
 162         state = talloc_zero(mem_ctx, struct file_log_state);
 163         if (state == NULL) {
 164                 return ENOMEM;
 165         }
 166
 167         state->app_name = app_name;
 168
 169         if (option == NULL || strcmp(option, "-") == 0) {
 170                 int ret;
 171
 172                 state->fd = STDERR_FILENO;
 173                 ret = dup2(STDERR_FILENO, STDOUT_FILENO);
 174                 if (ret == -1) {
 175                         int save_errno = errno;
 176                         talloc_free(state);
 177                         return save_errno;
 178                 }
 179
 180         } else {
 181                 state->fd = open(option, O_WRONLY|O_APPEND|O_CREAT, 0644);
 182                 if (state->fd == -1) {
 183                         int save_errno = errno;
 184                         talloc_free(state);
 185                         return save_errno;
 186                 }
 187
 188                 if (! set_close_on_exec(state->fd)) {
 189                         int save_errno = errno;
 190                         talloc_free(state);
 191                         return save_errno;
 192                 }
 193         }
 194
 195         talloc_set_destructor(state, file_log_state_destructor);
 196         debug_set_callback(state, file_log);
 197
 198         return 0;
 199 }
 200
 201 /*
 202  * syslog logging backend
 203  */
 204
 205 /* Copied from lib/util/debug.c */
 206 static int debug_level_to_priority(int level)
 207 {
 208         /*
 209          * map debug levels to syslog() priorities
 210          */
 211         static const int priority_map[] = {
 212                 LOG_ERR,     /* 0 */
 213                 LOG_WARNING, /* 1 */
 214                 LOG_NOTICE,  /* 2 */
 215                 LOG_NOTICE,  /* 3 */
 216                 LOG_NOTICE,  /* 4 */
 217                 LOG_NOTICE,  /* 5 */
 218                 LOG_INFO,    /* 6 */
 219                 LOG_INFO,    /* 7 */
 220                 LOG_INFO,    /* 8 */
 221                 LOG_INFO,    /* 9 */
 222         };
 223         int priority;
 224
 225         if( level >= ARRAY_SIZE(priority_map) || level < 0)
 226                 priority = LOG_DEBUG;
 227         else
 228                 priority = priority_map[level];
 229
 230         return priority;
 231 }
 232
 233 struct syslog_log_state {
 234         int fd;
 235         const char *app_name;
 236         const char *hostname;
 237         int (*format)(int dbglevel, struct syslog_log_state *state,
 238                       const char *str, char *buf, int bsize);
 239         /* RFC3164 says: The total length of the packet MUST be 1024
 240            bytes or less. */
 241         char buffer[1024];
 242         unsigned int dropped_count;
 243 };
 244
 245 /* Format messages as per RFC3164
 246  *
 247  * It appears that some syslog daemon implementations do not allow a
 248  * hostname when messages are sent via a Unix domain socket, so omit
 249  * it.  Similarly, syslogd on FreeBSD does not understand the hostname
 250  * part of the header, even when logging via UDP.  Note that most
 251  * implementations will log messages against "localhost" when logging
 252  * via UDP.  A timestamp could be sent but rsyslogd on Linux limits
 253  * the timestamp logged to the precision that was received on
 254  * /dev/log.  It seems sane to send degenerate RFC3164 messages
 255  * without a header at all, so that the daemon will generate high
 256  * resolution timestamps if configured.
 257  */
 258 static int format_rfc3164(int dbglevel, struct syslog_log_state *state,
 259                           const char *str, char *buf, int bsize)
 260 {
 261         int pri;
 262         int len;
 263
 264         pri = LOG_DAEMON | debug_level_to_priority(dbglevel);
 265         len = snprintf(buf, bsize, "<%d>%s[%u]: %s",
 266                        pri, state->app_name, getpid(), str);
 267         buf[bsize-1] = '\0';
 268         len = MIN(len, bsize - 1);
 269
 270         return len;
 271 }
 272
 273 /* Format messages as per RFC5424
 274  *
 275  * <165>1 2003-08-24T05:14:15.000003-07:00 192.0.2.1
 276  *         myproc 8710 - - %% It's time to make the do-nuts.
 277  */
 278 static int format_rfc5424(int dbglevel, struct syslog_log_state *state,
 279                           const char *str, char *buf, int bsize)
 280 {
 281         int pri;
 282         struct timeval tv;
 283         struct timeval_buf tvbuf;
 284         int len, s;
 285
 286         /* Header */
 287         pri = LOG_DAEMON | debug_level_to_priority(dbglevel);
 288         GetTimeOfDay(&tv);
 289         len = snprintf(buf, bsize,
 290                        "<%d>1 %s %s %s %u - - ",
 291                        pri, timeval_str_buf(&tv, true, true, &tvbuf),
 292                        state->hostname, state->app_name, getpid());
 293         /* A truncated header is not useful... */
 294         if (len >= bsize) {
 295                 return -1;
 296         }
 297
 298         /* Message */
 299         s = snprintf(&buf[len], bsize - len, "%s", str);
 300         buf[bsize-1] = '\0';
 301         len = MIN(len + s, bsize - 1);
 302
 303         return len;
 304 }
 305
 306 static void syslog_log(void *private_data, int level, const char *msg)
 307 {
 308         syslog(debug_level_to_priority(level), "%s", msg);
 309 }
 310
 311 static int syslog_log_sock_maybe(struct syslog_log_state *state,
 312                                  int level, const char *msg)
 313 {
 314         int n;
 315         ssize_t ret;
 316
 317         n = state->format(level, state, msg, state->buffer,
 318                           sizeof(state->buffer));
 319         if (n == -1) {
 320                 return E2BIG;
 321         }
 322
 323         do {
 324                 ret = write(state->fd, state->buffer, n);
 325         } while (ret == -1 && errno == EINTR);
 326
 327         if (ret == -1) {
 328                 return errno;
 329         }
 330
 331         return 0;
 332
 333 }
 334 static void syslog_log_sock(void *private_data, int level, const char *msg)
 335 {
 336         struct syslog_log_state *state = talloc_get_type_abort(
 337                 private_data, struct syslog_log_state);
 338         int ret;
 339
 340         if (state->dropped_count > 0) {
 341                 char t[64] = { 0 };
 342                 snprintf(t, sizeof(t),
 343                          "[Dropped %u log messages]\n",
 344                          state->dropped_count);
 345                 t[sizeof(t)-1] = '\0';
 346                 ret = syslog_log_sock_maybe(state, level, t);
 347                 if (ret == EAGAIN || ret == EWOULDBLOCK) {
 348                         state->dropped_count++;
 349                         /*
 350                          * If above failed then actually drop the
 351                          * message that would be logged below, since
 352                          * it would have been dropped anyway and it is
 353                          * also likely to fail.  Falling through and
 354                          * attempting to log the message also means
 355                          * that the dropped message count will be
 356                          * logged out of order.
 357                          */
 358                         return;
 359                 }
 360                 if (ret != 0) {
 361                         /* Silent failure on any other error */
 362                         return;
 363                 }
 364                 state->dropped_count = 0;
 365         }
 366
 367         ret = syslog_log_sock_maybe(state, level, msg);
 368         if (ret == EAGAIN || ret == EWOULDBLOCK) {
 369                 state->dropped_count++;
 370         }
 371 }
 372
 373 static int syslog_log_setup_syslog(TALLOC_CTX *mem_ctx, const char *app_name)
 374 {
 375         openlog(app_name, LOG_PID, LOG_DAEMON);
 376
 377         debug_set_callback(NULL, syslog_log);
 378
 379         return 0;
 380 }
 381
 382 static int syslog_log_state_destructor(struct syslog_log_state *state)
 383 {
 384         if (state->fd != -1) {
 385                 close(state->fd);
 386                 state->fd = -1;
 387         }
 388         return 0;
 389 }
 390
 391 static int syslog_log_setup_common(TALLOC_CTX *mem_ctx, const char *app_name,
 392                                    struct syslog_log_state **result)
 393 {
 394         struct syslog_log_state *state;
 395
 396         state = talloc_zero(mem_ctx, struct syslog_log_state);
 397         if (state == NULL) {
 398                 return ENOMEM;
 399         }
 400
 401         state->fd = -1;
 402         state->app_name = app_name;
 403         talloc_set_destructor(state, syslog_log_state_destructor);
 404
 405         *result = state;
 406         return 0;
 407 }
 408
 409 #ifdef _PATH_LOG
 410 static int syslog_log_setup_nonblocking(TALLOC_CTX *mem_ctx,
 411                                         const char *app_name)
 412 {
 413         struct syslog_log_state *state = NULL;
 414         struct sockaddr_un dest;
 415         int ret;
 416
 417         ret = syslog_log_setup_common(mem_ctx, app_name, &state);
 418         if (ret != 0) {
 419                 return ret;
 420         }
 421
 422         state->fd = socket(AF_UNIX, SOCK_DGRAM, 0);
 423         if (state->fd == -1) {
 424                 int save_errno = errno;
 425                 talloc_free(state);
 426                 return save_errno;
 427         }
 428
 429         dest.sun_family = AF_UNIX;
 430         strncpy(dest.sun_path, _PATH_LOG, sizeof(dest.sun_path)-1);
 431         ret = connect(state->fd,
 432                       (struct sockaddr *)&dest, sizeof(dest));
 433         if (ret == -1) {
 434                 int save_errno = errno;
 435                 talloc_free(state);
 436                 return save_errno;
 437         }
 438
 439         ret = set_blocking(state->fd, false);
 440         if (ret != 0) {
 441                 int save_errno = errno;
 442                 talloc_free(state);
 443                 return save_errno;
 444         }
 445
 446         if (! set_close_on_exec(state->fd)) {
 447                 int save_errno = errno;
 448                 talloc_free(state);
 449                 return save_errno;
 450         }
 451
 452         state->hostname = NULL; /* Make this explicit */
 453         state->format = format_rfc3164;
 454
 455         debug_set_callback(state, syslog_log_sock);
 456
 457         return 0;
 458 }
 459 #endif /* _PATH_LOG */
 460
 461 static int syslog_log_setup_udp(TALLOC_CTX *mem_ctx, const char *app_name,
 462                                 bool rfc5424)
 463 {
 464         struct syslog_log_state *state = NULL;
 465         struct sockaddr_in dest;
 466         int ret;
 467
 468         ret = syslog_log_setup_common(mem_ctx, app_name, &state);
 469         if (ret != 0) {
 470                 return ret;
 471         }
 472
 473         state->fd = socket(AF_INET, SOCK_DGRAM, IPPROTO_UDP);
 474         if (state->fd == -1) {
 475                 int save_errno = errno;
 476                 talloc_free(state);
 477                 return save_errno;
 478         }
 479
 480         dest.sin_family = AF_INET;
 481         dest.sin_port   = htons(514);
 482         dest.sin_addr.s_addr = htonl(INADDR_LOOPBACK);
 483         ret = connect(state->fd,
 484                       (struct sockaddr *)&dest, sizeof(dest));
 485         if (ret == -1) {
 486                 int save_errno = errno;
 487                 talloc_free(state);
 488                 return save_errno;
 489         }
 490
 491         if (! set_close_on_exec(state->fd)) {
 492                 int save_errno = errno;
 493                 talloc_free(state);
 494                 return save_errno;
 495         }
 496
 497         state->hostname = get_myname(state);
 498         if (state->hostname == NULL) {
 499                 /* Use a fallback instead of failing initialisation */
 500                 state->hostname = "localhost";
 501         }
 502         if (rfc5424) {
 503                 state->format = format_rfc5424;
 504         } else {
 505                 state->format = format_rfc3164;
 506         }
 507
 508         debug_set_callback(state, syslog_log_sock);
 509
 510         return 0;
 511 }
 512
 513 static int syslog_log_setup(TALLOC_CTX *mem_ctx, const char *option,
 514                             const char *app_name)
 515 {
 516         if (option == NULL) {
 517                 return syslog_log_setup_syslog(mem_ctx, app_name);
 518 #ifdef _PATH_LOG
 519         } else if (strcmp(option, "nonblocking") == 0) {
 520                 return syslog_log_setup_nonblocking(mem_ctx, app_name);
 521 #endif
 522         } else if (strcmp(option, "udp") == 0) {
 523                 return syslog_log_setup_udp(mem_ctx, app_name, false);
 524         } else if (strcmp(option, "udp-rfc5424") == 0) {
 525                 return syslog_log_setup_udp(mem_ctx, app_name, true);
 526         }
 527
 528         return EINVAL;
 529 }
 530
 531 /* Initialise logging */
 532 int logging_init(TALLOC_CTX *mem_ctx, const char *logging,
 533                  const char *debug_level, const char *app_name)
 534 {
 535         struct {
 536                 const char *name;
 537                 int (*setup)(TALLOC_CTX *mem_ctx, const char *option,
 538                              const char *app_name);
 539         } log_backend[] = {
 540                 {
 541                         .name = "file",
 542                         .setup = file_log_setup,
 543                 },
 544                 {
 545                         .name = "syslog",
 546                         .setup = syslog_log_setup,
 547                 },
 548         };
 549         int (*setup)(TALLOC_CTX *, const char *, const char *) = NULL;
 550         char *str, *name, *option;
 551         int ret, i;
 552
 553         setup_logging(app_name, DEBUG_STDERR);
 554
 555         if (debug_level == NULL) {
 556                 debug_level = getenv("CTDB_DEBUGLEVEL");
 557         }
 558         if (! debug_level_parse(debug_level, &DEBUGLEVEL)) {
 559                 return EINVAL;
 560         }
 561
 562         if (logging == NULL) {
 563                 logging = getenv("CTDB_LOGGING");
 564         }
 565         if (logging == NULL || logging[0] == '\0') {
 566                 return EINVAL;
 567         }
 568
 569         str = talloc_strdup(mem_ctx, logging);
 570         if (str == NULL) {
 571                 return ENOMEM;
 572         }
 573
 574         name = strtok(str, ":");
 575         if (name == NULL) {
 576                 talloc_free(str);
 577                 return EINVAL;
 578         }
 579         option = strtok(NULL, ":");
 580         /*
 581          * option can be NULL here, both setup()
 582          * backends handle this.
 583          */
 584
 585         for (i=0; i<ARRAY_SIZE(log_backend); i++) {
 586                 if (strcmp(log_backend[i].name, name) == 0) {
 587                         setup = log_backend[i].setup;
 588                 }
 589         }
 590
 591         if (setup == NULL) {
 592                 talloc_free(str);
 593                 fprintf(stderr, "Invalid logging option \'%s\'\n", logging);
 594                 return EINVAL;
 595         }
 596
 597         ret = setup(mem_ctx, option, app_name);
 598         talloc_free(str);
 599         return ret;
 600 }