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 };
 243
 244 /* Format messages as per RFC3164
 245  *
 246  * It appears that some syslog daemon implementations do not allow a
 247  * hostname when messages are sent via a Unix domain socket, so omit
 248  * it.  Similarly, syslogd on FreeBSD does not understand the hostname
 249  * part of the header, even when logging via UDP.  Note that most
 250  * implementations will log messages against "localhost" when logging
 251  * via UDP.  A timestamp could be sent but rsyslogd on Linux limits
 252  * the timestamp logged to the precision that was received on
 253  * /dev/log.  It seems sane to send degenerate RFC3164 messages
 254  * without a header at all, so that the daemon will generate high
 255  * resolution timestamps if configured.
 256  */
 257 static int format_rfc3164(int dbglevel, struct syslog_log_state *state,
 258                           const char *str, char *buf, int bsize)
 259 {
 260         int pri;
 261         int len;
 262
 263         pri = LOG_DAEMON | debug_level_to_priority(dbglevel);
 264         len = snprintf(buf, bsize, "<%d>%s[%u]: %s",
 265                        pri, state->app_name, getpid(), str);
 266         buf[bsize-1] = '\0';
 267         len = MIN(len, bsize - 1);
 268
 269         return len;
 270 }
 271
 272 /* Format messages as per RFC5424
 273  *
 274  * <165>1 2003-08-24T05:14:15.000003-07:00 192.0.2.1
 275  *         myproc 8710 - - %% It's time to make the do-nuts.
 276  */
 277 static int format_rfc5424(int dbglevel, struct syslog_log_state *state,
 278                           const char *str, char *buf, int bsize)
 279 {
 280         int pri;
 281         struct timeval tv;
 282         struct timeval_buf tvbuf;
 283         int len, s;
 284
 285         /* Header */
 286         pri = LOG_DAEMON | debug_level_to_priority(dbglevel);
 287         GetTimeOfDay(&tv);
 288         len = snprintf(buf, bsize,
 289                        "<%d>1 %s %s %s %u - - ",
 290                        pri, timeval_str_buf(&tv, true, true, &tvbuf),
 291                        state->hostname, state->app_name, getpid());
 292         /* A truncated header is not useful... */
 293         if (len >= bsize) {
 294                 return -1;
 295         }
 296
 297         /* Message */
 298         s = snprintf(&buf[len], bsize - len, "%s", str);
 299         buf[bsize-1] = '\0';
 300         len = MIN(len + s, bsize - 1);
 301
 302         return len;
 303 }
 304
 305 static void syslog_log(void *private_data, int level, const char *msg)
 306 {
 307         syslog(debug_level_to_priority(level), "%s", msg);
 308 }
 309
 310 static void syslog_log_sock(void *private_data, int level, const char *msg)
 311 {
 312         struct syslog_log_state *state = talloc_get_type_abort(
 313                 private_data, struct syslog_log_state);
 314         int n;
 315
 316         n = state->format(level, state, msg, state->buffer,
 317                           sizeof(state->buffer));
 318         if (n == -1) {
 319                 return;
 320         }
 321
 322         sys_write_v(state->fd, state->buffer, n);
 323 }
 324
 325 static int syslog_log_setup_syslog(TALLOC_CTX *mem_ctx, const char *app_name)
 326 {
 327         openlog(app_name, LOG_PID, LOG_DAEMON);
 328
 329         debug_set_callback(NULL, syslog_log);
 330
 331         return 0;
 332 }
 333
 334 static int syslog_log_state_destructor(struct syslog_log_state *state)
 335 {
 336         if (state->fd != -1) {
 337                 close(state->fd);
 338                 state->fd = -1;
 339         }
 340         return 0;
 341 }
 342
 343 static int syslog_log_setup_common(TALLOC_CTX *mem_ctx, const char *app_name,
 344                                    struct syslog_log_state **result)
 345 {
 346         struct syslog_log_state *state;
 347
 348         state = talloc_zero(mem_ctx, struct syslog_log_state);
 349         if (state == NULL) {
 350                 return ENOMEM;
 351         }
 352
 353         state->fd = -1;
 354         state->app_name = app_name;
 355         talloc_set_destructor(state, syslog_log_state_destructor);
 356
 357         return 0;
 358 }
 359
 360 #ifdef _PATH_LOG
 361 static int syslog_log_setup_nonblocking(TALLOC_CTX *mem_ctx,
 362                                         const char *app_name)
 363 {
 364         struct syslog_log_state *state = NULL;
 365         struct sockaddr_un dest;
 366         int ret;
 367
 368         ret = syslog_log_setup_common(mem_ctx, app_name, &state);
 369         if (ret != 0) {
 370                 return ret;
 371         }
 372
 373         state->fd = socket(AF_UNIX, SOCK_DGRAM, 0);
 374         if (state->fd == -1) {
 375                 int save_errno = errno;
 376                 talloc_free(state);
 377                 return save_errno;
 378         }
 379
 380         dest.sun_family = AF_UNIX;
 381         strncpy(dest.sun_path, _PATH_LOG, sizeof(dest.sun_path)-1);
 382         ret = connect(state->fd,
 383                       (struct sockaddr *)&dest, sizeof(dest));
 384         if (ret == -1) {
 385                 int save_errno = errno;
 386                 talloc_free(state);
 387                 return save_errno;
 388         }
 389
 390         ret = set_blocking(state->fd, false);
 391         if (ret != 0) {
 392                 int save_errno = errno;
 393                 talloc_free(state);
 394                 return save_errno;
 395         }
 396
 397         if (! set_close_on_exec(state->fd)) {
 398                 int save_errno = errno;
 399                 talloc_free(state);
 400                 return save_errno;
 401         }
 402
 403         state->hostname = NULL; /* Make this explicit */
 404         state->format = format_rfc3164;
 405
 406         debug_set_callback(state, syslog_log_sock);
 407
 408         return 0;
 409 }
 410 #endif /* _PATH_LOG */
 411
 412 static int syslog_log_setup_udp(TALLOC_CTX *mem_ctx, const char *app_name,
 413                                 bool rfc5424)
 414 {
 415         struct syslog_log_state *state = NULL;
 416         struct sockaddr_in dest;
 417         int ret;
 418
 419         ret = syslog_log_setup_common(mem_ctx, app_name, &state);
 420         if (ret != 0) {
 421                 return ret;
 422         }
 423
 424         state->fd = socket(AF_INET, SOCK_DGRAM, IPPROTO_UDP);
 425         if (state->fd == -1) {
 426                 int save_errno = errno;
 427                 talloc_free(state);
 428                 return save_errno;
 429         }
 430
 431         dest.sin_family = AF_INET;
 432         dest.sin_port   = htons(514);
 433         dest.sin_addr.s_addr = htonl(INADDR_LOOPBACK);
 434         ret = connect(state->fd,
 435                       (struct sockaddr *)&dest, sizeof(dest));
 436         if (ret == -1) {
 437                 int save_errno = errno;
 438                 talloc_free(state);
 439                 return save_errno;
 440         }
 441
 442         if (! set_close_on_exec(state->fd)) {
 443                 int save_errno = errno;
 444                 talloc_free(state);
 445                 return save_errno;
 446         }
 447
 448         state->hostname = get_myname(state);
 449         if (state->hostname == NULL) {
 450                 /* Use a fallback instead of failing initialisation */
 451                 state->hostname = "localhost";
 452         }
 453         if (rfc5424) {
 454                 state->format = format_rfc5424;
 455         } else {
 456                 state->format = format_rfc3164;
 457         }
 458
 459         debug_set_callback(state, syslog_log_sock);
 460
 461         return 0;
 462 }
 463
 464 static int syslog_log_setup(TALLOC_CTX *mem_ctx, const char *option,
 465                             const char *app_name)
 466 {
 467         if (option == NULL) {
 468                 return syslog_log_setup_syslog(mem_ctx, app_name);
 469 #ifdef _PATH_LOG
 470         } else if (strcmp(option, "nonblocking") == 0) {
 471                 return syslog_log_setup_nonblocking(mem_ctx, app_name);
 472 #endif
 473         } else if (strcmp(option, "udp") == 0) {
 474                 return syslog_log_setup_udp(mem_ctx, app_name, false);
 475         } else if (strcmp(option, "udp-rfc5424") == 0) {
 476                 return syslog_log_setup_udp(mem_ctx, app_name, true);
 477         }
 478
 479         return EINVAL;
 480 }
 481
 482 /* Initialise logging */
 483 int logging_init(TALLOC_CTX *mem_ctx, const char *logging,
 484                  const char *debug_level, const char *app_name)
 485 {
 486         struct {
 487                 const char *name;
 488                 int (*setup)(TALLOC_CTX *mem_ctx, const char *option,
 489                              const char *app_name);
 490         } log_backend[] = {
 491                 {
 492                         .name = "file",
 493                         .setup = file_log_setup,
 494                 },
 495                 {
 496                         .name = "syslog",
 497                         .setup = syslog_log_setup,
 498                 },
 499         };
 500         int (*setup)(TALLOC_CTX *, const char *, const char *) = NULL;
 501         char *str, *name, *option;
 502         int ret, i;
 503
 504         if (debug_level == NULL) {
 505                 debug_level = getenv("CTDB_DEBUGLEVEL");
 506         }
 507         if (! debug_level_parse(debug_level, &DEBUGLEVEL)) {
 508                 return EINVAL;
 509         }
 510
 511         if (logging == NULL) {
 512                 logging = getenv("CTDB_LOGGING");
 513         }
 514         if (logging == NULL || logging[0] == '\0') {
 515                 return EINVAL;
 516         }
 517
 518         str = talloc_strdup(mem_ctx, logging);
 519         if (str == NULL) {
 520                 return ENOMEM;
 521         }
 522
 523         name = strtok(str, ":");
 524         if (name == NULL) {
 525                 talloc_free(str);
 526                 return EINVAL;
 527         }
 528         option = strtok(NULL, ":");
 529         /*
 530          * option can be NULL here, both setup()
 531          * backends handle this.
 532          */
 533
 534         for (i=0; i<ARRAY_SIZE(log_backend); i++) {
 535                 if (strcmp(log_backend[i].name, name) == 0) {
 536                         setup = log_backend[i].setup;
 537                 }
 538         }
 539
 540         if (setup == NULL) {
 541                 talloc_free(str);
 542                 fprintf(stderr, "Invalid logging option \'%s\'\n", logging);
 543                 return EINVAL;
 544         }
 545
 546         ret = setup(mem_ctx, option, app_name);
 547         talloc_free(str);
 548         return ret;
 549 }