lib/common/logging.c

/* */
This source file includes following definitions.
crm_glib_handler
crm_trigger_blackbox
crm_log_deinit
set_format_string
logfile_disabled
chown_logfile
chmod_logfile
set_logfile_permissions
enable_logfile
disable_logfile
setenv_logfile
pcmk__add_logfile
blackbox_logger
crm_control_blackbox
crm_enable_blackbox
crm_disable_blackbox
crm_write_blackbox
crm_quark_to_string
crm_log_filter_source
crm_log_filter
crm_is_callsite_active
crm_update_callsites
crm_tracing_enabled
crm_priority2int
crm_identity
crm_log_preinit
crm_log_init
set_crm_log_level
crm_enable_stderr
crm_bump_log_level
get_crm_log_level
crm_log_args
crm_log_output_fn
pcmk__cli_init_logging
crm_log_cli_init
crm_add_logfile
   1 /*
   2  * Copyright 2004-2021 the Pacemaker project contributors
   3  *
   4  * The version control history for this file may have further details.
   5  *
   6  * This source code is licensed under the GNU Lesser General Public License
   7  * version 2.1 or later (LGPLv2.1+) WITHOUT ANY WARRANTY.
   8  */
   9 
  10 #include <crm_internal.h>
  11 
  12 #include <sys/param.h>
  13 #include <sys/types.h>
  14 #include <sys/wait.h>
  15 #include <sys/stat.h>
  16 #include <sys/utsname.h>
  17 
  18 #include <stdio.h>
  19 #include <unistd.h>
  20 #include <string.h>
  21 #include <stdlib.h>
  22 #include <limits.h>
  23 #include <ctype.h>
  24 #include <pwd.h>
  25 #include <grp.h>
  26 #include <time.h>
  27 #include <libgen.h>
  28 #include <signal.h>
  29 #include <bzlib.h>
  30 
  31 #include <qb/qbdefs.h>
  32 
  33 #include <crm/crm.h>
  34 #include <crm/common/mainloop.h>
  35 
  36 // Use high-resolution (millisecond) timestamps if libqb supports them
  37 #ifdef QB_FEATURE_LOG_HIRES_TIMESTAMPS
  38 #define TIMESTAMP_FORMAT_SPEC "%%T"
  39 typedef struct timespec *log_time_t;
  40 #else
  41 #define TIMESTAMP_FORMAT_SPEC "%%t"
  42 typedef time_t log_time_t;
  43 #endif
  44 
  45 unsigned int crm_log_level = LOG_INFO;
  46 unsigned int crm_trace_nonlog = 0;
  47 bool pcmk__is_daemon = false;
  48 
  49 static unsigned int crm_log_priority = LOG_NOTICE;
  50 static GLogFunc glib_log_default = NULL;
  51 
  52 static gboolean crm_tracing_enabled(void);
  53 
  54 static void
  55 crm_glib_handler(const gchar * log_domain, GLogLevelFlags flags, const gchar * message,
     /*  */
  56                  gpointer user_data)
  57 {
  58     int log_level = LOG_WARNING;
  59     GLogLevelFlags msg_level = (flags & G_LOG_LEVEL_MASK);
  60     static struct qb_log_callsite *glib_cs = NULL;
  61 
  62     if (glib_cs == NULL) {
  63         glib_cs = qb_log_callsite_get(__func__, __FILE__, "glib-handler",
  64                                       LOG_DEBUG, __LINE__, crm_trace_nonlog);
  65     }
  66 
  67 
  68     switch (msg_level) {
  69         case G_LOG_LEVEL_CRITICAL:
  70             log_level = LOG_CRIT;
  71 
  72             if (crm_is_callsite_active(glib_cs, LOG_DEBUG, 0) == FALSE) {
  73                 /* log and record how we got here */
  74                 crm_abort(__FILE__, __func__, __LINE__, message, TRUE, TRUE);
  75             }
  76             break;
  77 
  78         case G_LOG_LEVEL_ERROR:
  79             log_level = LOG_ERR;
  80             break;
  81         case G_LOG_LEVEL_MESSAGE:
  82             log_level = LOG_NOTICE;
  83             break;
  84         case G_LOG_LEVEL_INFO:
  85             log_level = LOG_INFO;
  86             break;
  87         case G_LOG_LEVEL_DEBUG:
  88             log_level = LOG_DEBUG;
  89             break;
  90 
  91         case G_LOG_LEVEL_WARNING:
  92         case G_LOG_FLAG_RECURSION:
  93         case G_LOG_FLAG_FATAL:
  94         case G_LOG_LEVEL_MASK:
  95             log_level = LOG_WARNING;
  96             break;
  97     }
  98 
  99     do_crm_log(log_level, "%s: %s", log_domain, message);
 100 }
 101 
 102 #ifndef NAME_MAX
 103 #  define NAME_MAX 256
 104 #endif
 105 
 106 /*!
 107  * \internal
 108  * \brief Write out a blackbox (enabling blackboxes if needed)
 109  *
 110  * \param[in] nsig  Signal number that was received
 111  *
 112  * \note This is a true signal handler, and so must be async-safe.
 113  */
 114 static void
 115 crm_trigger_blackbox(int nsig)
     /*  */
 116 {
 117     if(nsig == SIGTRAP) {
 118         /* Turn it on if it wasn't already */
 119         crm_enable_blackbox(nsig);
 120     }
 121     crm_write_blackbox(nsig, NULL);
 122 }
 123 
 124 void
 125 crm_log_deinit(void)
     /*  */
 126 {
 127     if (glib_log_default != NULL) {
 128         g_log_set_default_handler(glib_log_default, NULL);
 129     }
 130 }
 131 
 132 #define FMT_MAX 256
 133 
 134 static void
 135 set_format_string(int method, const char *daemon)
     /*  */
 136 {
 137     if (method == QB_LOG_SYSLOG) {
 138         // The system log gets a simplified, user-friendly format
 139         crm_extended_logging(method, QB_FALSE);
 140         qb_log_format_set(method, "%g %p: %b");
 141 
 142     } else {
 143         // Everything else gets more detail, for advanced troubleshooting
 144 
 145         int offset = 0;
 146         char fmt[FMT_MAX];
 147 
 148         if (method > QB_LOG_STDERR) {
 149             struct utsname res;
 150             const char *nodename = "localhost";
 151 
 152             if (uname(&res) == 0) {
 153                 nodename = res.nodename;
 154             }
 155 
 156             // If logging to file, prefix with timestamp, node name, daemon ID
 157             offset += snprintf(fmt + offset, FMT_MAX - offset,
 158                                TIMESTAMP_FORMAT_SPEC " %s %-20s[%lu] ",
 159                                nodename, daemon, (unsigned long) getpid());
 160         }
 161 
 162         // Add function name (in parentheses)
 163         offset += snprintf(fmt + offset, FMT_MAX - offset, "(%%n");
 164         if (crm_tracing_enabled()) {
 165             // When tracing, add file and line number
 166             offset += snprintf(fmt + offset, FMT_MAX - offset, "@%%f:%%l");
 167         }
 168         offset += snprintf(fmt + offset, FMT_MAX - offset, ")");
 169 
 170         // Add tag (if any), severity, and actual message
 171         offset += snprintf(fmt + offset, FMT_MAX - offset, " %%g\t%%p: %%b");
 172 
 173         CRM_LOG_ASSERT(offset > 0);
 174         qb_log_format_set(method, fmt);
 175     }
 176 }
 177 
 178 #define DEFAULT_LOG_FILE CRM_LOG_DIR "/pacemaker.log"
 179 
 180 static bool
 181 logfile_disabled(const char *filename)
     /*  */
 182 {
 183     return pcmk__str_eq(filename, "none", pcmk__str_casei|pcmk__str_null_matches)
 184            || pcmk__str_eq(filename, "/dev/null", pcmk__str_none);
 185 }
 186 
 187 /*!
 188  * \internal
 189  * \brief Fix log file ownership if group is wrong or doesn't have access
 190  *
 191  * \param[in] filename  Log file name (for logging only)
 192  * \param[in] logfd     Log file descriptor
 193  *
 194  * \return Standard Pacemaker return code
 195  */
 196 static int
 197 chown_logfile(const char *filename, int logfd)
     /*  */
 198 {
 199     uid_t pcmk_uid = 0;
 200     gid_t pcmk_gid = 0;
 201     struct stat st;
 202     int rc;
 203 
 204     // Get the log file's current ownership and permissions
 205     if (fstat(logfd, &st) < 0) {
 206         return errno;
 207     }
 208 
 209     // Any other errors don't prevent file from being used as log
 210 
 211     rc = pcmk_daemon_user(&pcmk_uid, &pcmk_gid);
 212     if (rc != pcmk_ok) {
 213         rc = pcmk_legacy2rc(rc);
 214         crm_warn("Not changing '%s' ownership because user information "
 215                  "unavailable: %s", filename, pcmk_rc_str(rc));
 216         return pcmk_rc_ok;
 217     }
 218     if ((st.st_gid == pcmk_gid)
 219         && ((st.st_mode & S_IRWXG) == (S_IRGRP|S_IWGRP))) {
 220         return pcmk_rc_ok;
 221     }
 222     if (fchown(logfd, pcmk_uid, pcmk_gid) < 0) {
 223         crm_warn("Couldn't change '%s' ownership to user %s gid %d: %s",
 224              filename, CRM_DAEMON_USER, pcmk_gid, strerror(errno));
 225     }
 226     return pcmk_rc_ok;
 227 }
 228 
 229 // Reset log file permissions (using environment variable if set)
 230 static void
 231 chmod_logfile(const char *filename, int logfd)
     /*  */
 232 {
 233     const char *modestr = getenv("PCMK_logfile_mode");
 234     mode_t filemode = S_IRUSR | S_IWUSR | S_IRGRP | S_IWGRP;
 235 
 236     if (modestr != NULL) {
 237         long filemode_l = strtol(modestr, NULL, 8);
 238 
 239         if ((filemode_l != LONG_MIN) && (filemode_l != LONG_MAX)) {
 240             filemode = (mode_t) filemode_l;
 241         }
 242     }
 243     if ((filemode != 0) && (fchmod(logfd, filemode) < 0)) {
 244         crm_warn("Couldn't change '%s' mode to %04o: %s",
 245                  filename, filemode, strerror(errno));
 246     }
 247 }
 248 
 249 // If we're root, correct a log file's permissions if needed
 250 static int
 251 set_logfile_permissions(const char *filename, FILE *logfile)
     /*  */
 252 {
 253     if (geteuid() == 0) {
 254         int logfd = fileno(logfile);
 255         int rc = chown_logfile(filename, logfd);
 256 
 257         if (rc != pcmk_rc_ok) {
 258             return rc;
 259         }
 260         chmod_logfile(filename, logfd);
 261     }
 262     return pcmk_rc_ok;
 263 }
 264 
 265 // Enable libqb logging to a new log file
 266 static void
 267 enable_logfile(int fd)
     /*  */
 268 {
 269     qb_log_ctl(fd, QB_LOG_CONF_ENABLED, QB_TRUE);
 270 #if 0
 271     qb_log_ctl(fd, QB_LOG_CONF_FILE_SYNC, 1); // Turn on synchronous writes
 272 #endif
 273 
 274 #ifdef HAVE_qb_log_conf_QB_LOG_CONF_MAX_LINE_LEN
 275     // Longer than default, for logging long XML lines
 276     qb_log_ctl(fd, QB_LOG_CONF_MAX_LINE_LEN, 800);
 277 #endif
 278 
 279     crm_update_callsites();
 280 }
 281 
 282 static inline void
 283 disable_logfile(int fd)
     /*  */
 284 {
 285     qb_log_ctl(fd, QB_LOG_CONF_ENABLED, QB_FALSE);
 286 }
 287 
 288 static void
 289 setenv_logfile(const char *filename)
     /*  */
 290 {
 291     // Some resource agents will log only if environment variable is set
 292     if (pcmk__env_option("logfile") == NULL) {
 293         pcmk__set_env_option("logfile", filename);
 294     }
 295 }
 296 
 297 /*!
 298  * \brief Add a file to be used as a Pacemaker detail log
 299  *
 300  * \param[in] filename  Name of log file to use
 301  *
 302  * \return Standard Pacemaker return code
 303  */
 304 int
 305 pcmk__add_logfile(const char *filename)
     /*  */
 306 {
 307     /* No log messages from this function will be logged to the new log!
 308      * If another target such as syslog has already been added, the messages
 309      * should show up there.
 310      */
 311 
 312     int fd = 0;
 313     int rc = pcmk_rc_ok;
 314     FILE *logfile = NULL;
 315     bool is_default = false;
 316 
 317     static int default_fd = -1;
 318     static bool have_logfile = false;
 319 
 320     // Use default if caller didn't specify (and we don't already have one)
 321     if ((filename == NULL) && !have_logfile) {
 322         filename = DEFAULT_LOG_FILE;
 323     }
 324 
 325     // If the user doesn't want logging, we're done
 326     if (logfile_disabled(filename)) {
 327         return pcmk_rc_ok;
 328     }
 329 
 330     // If the caller wants the default and we already have it, we're done
 331     is_default = pcmk__str_eq(filename, DEFAULT_LOG_FILE, pcmk__str_none);
 332     if (is_default && (default_fd >= 0)) {
 333         return pcmk_rc_ok;
 334     }
 335 
 336     // Check whether we have write access to the file
 337     logfile = fopen(filename, "a");
 338     if (logfile == NULL) {
 339         rc = errno;
 340         crm_warn("Logging to '%s' is disabled: %s " CRM_XS " uid=%u gid=%u",
 341                  filename, strerror(rc), geteuid(), getegid());
 342         return rc;
 343     }
 344 
 345     rc = set_logfile_permissions(filename, logfile);
 346     if (rc != pcmk_rc_ok) {
 347         crm_warn("Logging to '%s' is disabled: %s " CRM_XS " permissions",
 348                  filename, strerror(rc));
 349         fclose(logfile);
 350         return rc;
 351     }
 352 
 353     // Close and reopen as libqb logging target
 354     fclose(logfile);
 355     fd = qb_log_file_open(filename);
 356     if (fd < 0) {
 357         crm_warn("Logging to '%s' is disabled: %s " CRM_XS " qb_log_file_open",
 358                  filename, strerror(-fd));
 359         return -fd; // == +errno
 360     }
 361 
 362     if (is_default) {
 363         default_fd = fd;
 364         setenv_logfile(filename);
 365 
 366     } else if (default_fd >= 0) {
 367         crm_notice("Switching logging to %s", filename);
 368         disable_logfile(default_fd);
 369     }
 370 
 371     crm_notice("Additional logging available in %s", filename);
 372     enable_logfile(fd);
 373     have_logfile = true;
 374     return pcmk_rc_ok;
 375 }
 376 
 377 static int blackbox_trigger = 0;
 378 static volatile char *blackbox_file_prefix = NULL;
 379 
 380 static void
 381 blackbox_logger(int32_t t, struct qb_log_callsite *cs, log_time_t timestamp,
     /*  */
 382                 const char *msg)
 383 {
 384     if(cs && cs->priority < LOG_ERR) {
 385         crm_write_blackbox(SIGTRAP, cs); /* Bypass the over-dumping logic */
 386     } else {
 387         crm_write_blackbox(0, cs);
 388     }
 389 }
 390 
 391 static void
 392 crm_control_blackbox(int nsig, bool enable)
     /*  */
 393 {
 394     int lpc = 0;
 395 
 396     if (blackbox_file_prefix == NULL) {
 397         pid_t pid = getpid();
 398 
 399         blackbox_file_prefix = crm_strdup_printf("%s/%s-%lu",
 400                                                  CRM_BLACKBOX_DIR,
 401                                                  crm_system_name,
 402                                                  (unsigned long) pid);
 403     }
 404 
 405     if (enable && qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_STATE_GET, 0) != QB_LOG_STATE_ENABLED) {
 406         qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_SIZE, 5 * 1024 * 1024); /* Any size change drops existing entries */
 407         qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_ENABLED, QB_TRUE);      /* Setting the size seems to disable it */
 408 
 409         /* Enable synchronous logging */
 410         for (lpc = QB_LOG_BLACKBOX; lpc < QB_LOG_TARGET_MAX; lpc++) {
 411             qb_log_ctl(lpc, QB_LOG_CONF_FILE_SYNC, QB_TRUE);
 412         }
 413 
 414         crm_notice("Initiated blackbox recorder: %s", blackbox_file_prefix);
 415 
 416         /* Save to disk on abnormal termination */
 417         crm_signal_handler(SIGSEGV, crm_trigger_blackbox);
 418         crm_signal_handler(SIGABRT, crm_trigger_blackbox);
 419         crm_signal_handler(SIGILL,  crm_trigger_blackbox);
 420         crm_signal_handler(SIGBUS,  crm_trigger_blackbox);
 421         crm_signal_handler(SIGFPE,  crm_trigger_blackbox);
 422 
 423         crm_update_callsites();
 424 
 425         blackbox_trigger = qb_log_custom_open(blackbox_logger, NULL, NULL, NULL);
 426         qb_log_ctl(blackbox_trigger, QB_LOG_CONF_ENABLED, QB_TRUE);
 427         crm_trace("Trigger: %d is %d %d", blackbox_trigger,
 428                   qb_log_ctl(blackbox_trigger, QB_LOG_CONF_STATE_GET, 0), QB_LOG_STATE_ENABLED);
 429 
 430         crm_update_callsites();
 431 
 432     } else if (!enable && qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_STATE_GET, 0) == QB_LOG_STATE_ENABLED) {
 433         qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_ENABLED, QB_FALSE);
 434 
 435         /* Disable synchronous logging again when the blackbox is disabled */
 436         for (lpc = QB_LOG_BLACKBOX; lpc < QB_LOG_TARGET_MAX; lpc++) {
 437             qb_log_ctl(lpc, QB_LOG_CONF_FILE_SYNC, QB_FALSE);
 438         }
 439     }
 440 }
 441 
 442 void
 443 crm_enable_blackbox(int nsig)
     /*  */
 444 {
 445     crm_control_blackbox(nsig, TRUE);
 446 }
 447 
 448 void
 449 crm_disable_blackbox(int nsig)
     /*  */
 450 {
 451     crm_control_blackbox(nsig, FALSE);
 452 }
 453 
 454 /*!
 455  * \internal
 456  * \brief Write out a blackbox, if blackboxes are enabled
 457  *
 458  * \param[in] nsig  Signal that was received
 459  * \param[in] cs    libqb callsite
 460  *
 461  * \note This may be called via a true signal handler and so must be async-safe.
 462  * @TODO actually make this async-safe
 463  */
 464 void
 465 crm_write_blackbox(int nsig, struct qb_log_callsite *cs)
     /*  */
 466 {
 467     static volatile int counter = 1;
 468     static volatile time_t last = 0;
 469 
 470     char buffer[NAME_MAX];
 471     time_t now = time(NULL);
 472 
 473     if (blackbox_file_prefix == NULL) {
 474         return;
 475     }
 476 
 477     switch (nsig) {
 478         case 0:
 479         case SIGTRAP:
 480             /* The graceful case - such as assertion failure or user request */
 481 
 482             if (nsig == 0 && now == last) {
 483                 /* Prevent over-dumping */
 484                 return;
 485             }
 486 
 487             snprintf(buffer, NAME_MAX, "%s.%d", blackbox_file_prefix, counter++);
 488             if (nsig == SIGTRAP) {
 489                 crm_notice("Blackbox dump requested, please see %s for contents", buffer);
 490 
 491             } else if (cs) {
 492                 syslog(LOG_NOTICE,
 493                        "Problem detected at %s:%d (%s), please see %s for additional details",
 494                        cs->function, cs->lineno, cs->filename, buffer);
 495             } else {
 496                 crm_notice("Problem detected, please see %s for additional details", buffer);
 497             }
 498 
 499             last = now;
 500             qb_log_blackbox_write_to_file(buffer);
 501 
 502             /* Flush the existing contents
 503              * A size change would also work
 504              */
 505             qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_ENABLED, QB_FALSE);
 506             qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_ENABLED, QB_TRUE);
 507             break;
 508 
 509         default:
 510             /* Do as little as possible, just try to get what we have out
 511              * We logged the filename when the blackbox was enabled
 512              */
 513             crm_signal_handler(nsig, SIG_DFL);
 514             qb_log_blackbox_write_to_file((const char *)blackbox_file_prefix);
 515             qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_ENABLED, QB_FALSE);
 516             raise(nsig);
 517             break;
 518     }
 519 }
 520 
 521 static const char *
 522 crm_quark_to_string(uint32_t tag)
     /*  */
 523 {
 524     const char *text = g_quark_to_string(tag);
 525 
 526     if (text) {
 527         return text;
 528     }
 529     return "";
 530 }
 531 
 532 static void
 533 crm_log_filter_source(int source, const char *trace_files, const char *trace_fns,
     /*  */
 534                       const char *trace_fmts, const char *trace_tags, const char *trace_blackbox,
 535                       struct qb_log_callsite *cs)
 536 {
 537     if (qb_log_ctl(source, QB_LOG_CONF_STATE_GET, 0) != QB_LOG_STATE_ENABLED) {
 538         return;
 539     } else if (cs->tags != crm_trace_nonlog && source == QB_LOG_BLACKBOX) {
 540         /* Blackbox gets everything if enabled */
 541         qb_bit_set(cs->targets, source);
 542 
 543     } else if (source == blackbox_trigger && blackbox_trigger > 0) {
 544         /* Should this log message result in the blackbox being dumped */
 545         if (cs->priority <= LOG_ERR) {
 546             qb_bit_set(cs->targets, source);
 547 
 548         } else if (trace_blackbox) {
 549             char *key = crm_strdup_printf("%s:%d", cs->function, cs->lineno);
 550 
 551             if (strstr(trace_blackbox, key) != NULL) {
 552                 qb_bit_set(cs->targets, source);
 553             }
 554             free(key);
 555         }
 556 
 557     } else if (source == QB_LOG_SYSLOG) {       /* No tracing to syslog */
 558         if (cs->priority <= crm_log_priority && cs->priority <= crm_log_level) {
 559             qb_bit_set(cs->targets, source);
 560         }
 561         /* Log file tracing options... */
 562     } else if (cs->priority <= crm_log_level) {
 563         qb_bit_set(cs->targets, source);
 564     } else if (trace_files && strstr(trace_files, cs->filename) != NULL) {
 565         qb_bit_set(cs->targets, source);
 566     } else if (trace_fns && strstr(trace_fns, cs->function) != NULL) {
 567         qb_bit_set(cs->targets, source);
 568     } else if (trace_fmts && strstr(trace_fmts, cs->format) != NULL) {
 569         qb_bit_set(cs->targets, source);
 570     } else if (trace_tags
 571                && cs->tags != 0
 572                && cs->tags != crm_trace_nonlog && g_quark_to_string(cs->tags) != NULL) {
 573         qb_bit_set(cs->targets, source);
 574     }
 575 }
 576 
 577 static void
 578 crm_log_filter(struct qb_log_callsite *cs)
     /*  */
 579 {
 580     int lpc = 0;
 581     static int need_init = 1;
 582     static const char *trace_fns = NULL;
 583     static const char *trace_tags = NULL;
 584     static const char *trace_fmts = NULL;
 585     static const char *trace_files = NULL;
 586     static const char *trace_blackbox = NULL;
 587 
 588     if (need_init) {
 589         need_init = 0;
 590         trace_fns = getenv("PCMK_trace_functions");
 591         trace_fmts = getenv("PCMK_trace_formats");
 592         trace_tags = getenv("PCMK_trace_tags");
 593         trace_files = getenv("PCMK_trace_files");
 594         trace_blackbox = getenv("PCMK_trace_blackbox");
 595 
 596         if (trace_tags != NULL) {
 597             uint32_t tag;
 598             char token[500];
 599             const char *offset = NULL;
 600             const char *next = trace_tags;
 601 
 602             do {
 603                 offset = next;
 604                 next = strchrnul(offset, ',');
 605                 snprintf(token, sizeof(token), "%.*s", (int)(next - offset), offset);
 606 
 607                 tag = g_quark_from_string(token);
 608                 crm_info("Created GQuark %u from token '%s' in '%s'", tag, token, trace_tags);
 609 
 610                 if (next[0] != 0) {
 611                     next++;
 612                 }
 613 
 614             } while (next != NULL && next[0] != 0);
 615         }
 616     }
 617 
 618     cs->targets = 0;            /* Reset then find targets to enable */
 619     for (lpc = QB_LOG_SYSLOG; lpc < QB_LOG_TARGET_MAX; lpc++) {
 620         crm_log_filter_source(lpc, trace_files, trace_fns, trace_fmts, trace_tags, trace_blackbox,
 621                               cs);
 622     }
 623 }
 624 
 625 gboolean
 626 crm_is_callsite_active(struct qb_log_callsite *cs, uint8_t level, uint32_t tags)
     /*  */
 627 {
 628     gboolean refilter = FALSE;
 629 
 630     if (cs == NULL) {
 631         return FALSE;
 632     }
 633 
 634     if (cs->priority != level) {
 635         cs->priority = level;
 636         refilter = TRUE;
 637     }
 638 
 639     if (cs->tags != tags) {
 640         cs->tags = tags;
 641         refilter = TRUE;
 642     }
 643 
 644     if (refilter) {
 645         crm_log_filter(cs);
 646     }
 647 
 648     if (cs->targets == 0) {
 649         return FALSE;
 650     }
 651     return TRUE;
 652 }
 653 
 654 void
 655 crm_update_callsites(void)
     /*  */
 656 {
 657     static gboolean log = TRUE;
 658 
 659     if (log) {
 660         log = FALSE;
 661         crm_debug
 662             ("Enabling callsites based on priority=%d, files=%s, functions=%s, formats=%s, tags=%s",
 663              crm_log_level, getenv("PCMK_trace_files"), getenv("PCMK_trace_functions"),
 664              getenv("PCMK_trace_formats"), getenv("PCMK_trace_tags"));
 665     }
 666     qb_log_filter_fn_set(crm_log_filter);
 667 }
 668 
 669 static gboolean
 670 crm_tracing_enabled(void)
     /*  */
 671 {
 672     if (crm_log_level == LOG_TRACE) {
 673         return TRUE;
 674     } else if (getenv("PCMK_trace_files") || getenv("PCMK_trace_functions")
 675                || getenv("PCMK_trace_formats") || getenv("PCMK_trace_tags")) {
 676         return TRUE;
 677     }
 678     return FALSE;
 679 }
 680 
 681 static int
 682 crm_priority2int(const char *name)
     /*  */
 683 {
 684     struct syslog_names {
 685         const char *name;
 686         int priority;
 687     };
 688     static struct syslog_names p_names[] = {
 689         {"emerg", LOG_EMERG},
 690         {"alert", LOG_ALERT},
 691         {"crit", LOG_CRIT},
 692         {"error", LOG_ERR},
 693         {"warning", LOG_WARNING},
 694         {"notice", LOG_NOTICE},
 695         {"info", LOG_INFO},
 696         {"debug", LOG_DEBUG},
 697         {NULL, -1}
 698     };
 699     int lpc;
 700 
 701     for (lpc = 0; name != NULL && p_names[lpc].name != NULL; lpc++) {
 702         if (pcmk__str_eq(p_names[lpc].name, name, pcmk__str_none)) {
 703             return p_names[lpc].priority;
 704         }
 705     }
 706     return crm_log_priority;
 707 }
 708 
 709 
 710 static void
 711 crm_identity(const char *entity, int argc, char **argv) 
     /*  */
 712 {
 713     if(crm_system_name != NULL) {
 714         /* Nothing to do */
 715 
 716     } else if (entity) {
 717         free(crm_system_name);
 718         crm_system_name = strdup(entity);
 719 
 720     } else if (argc > 0 && argv != NULL) {
 721         char *mutable = strdup(argv[0]);
 722         char *modified = basename(mutable);
 723 
 724         if (strstr(modified, "lt-") == modified) {
 725             modified += 3;
 726         }
 727 
 728         free(crm_system_name);
 729         crm_system_name = strdup(modified);
 730         free(mutable);
 731 
 732     } else if (crm_system_name == NULL) {
 733         crm_system_name = strdup("Unknown");
 734     }
 735 
 736     setenv("PCMK_service", crm_system_name, 1);
 737 }
 738 
 739 void
 740 crm_log_preinit(const char *entity, int argc, char **argv)
     /*  */
 741 {
 742     /* Configure libqb logging with nothing turned on */
 743 
 744     int lpc = 0;
 745     int32_t qb_facility = 0;
 746 
 747     static bool have_logging = FALSE;
 748 
 749     if(have_logging == FALSE) {
 750         have_logging = TRUE;
 751 
 752         crm_xml_init(); /* Sets buffer allocation strategy */
 753 
 754         if (crm_trace_nonlog == 0) {
 755             crm_trace_nonlog = g_quark_from_static_string("Pacemaker non-logging tracepoint");
 756         }
 757 
 758         umask(S_IWGRP | S_IWOTH | S_IROTH);
 759 
 760         /* Redirect messages from glib functions to our handler */
 761         glib_log_default = g_log_set_default_handler(crm_glib_handler, NULL);
 762 
 763         /* and for good measure... - this enum is a bit field (!) */
 764         g_log_set_always_fatal((GLogLevelFlags) 0); /*value out of range */
 765 
 766         /* Who do we log as */
 767         crm_identity(entity, argc, argv);
 768 
 769         qb_facility = qb_log_facility2int("local0");
 770         qb_log_init(crm_system_name, qb_facility, LOG_ERR);
 771         crm_log_level = LOG_CRIT;
 772 
 773         /* Nuke any syslog activity until it's asked for */
 774         qb_log_ctl(QB_LOG_SYSLOG, QB_LOG_CONF_ENABLED, QB_FALSE);
 775 #ifdef HAVE_qb_log_conf_QB_LOG_CONF_MAX_LINE_LEN
 776         // Shorter than default, generous for what we *should* send to syslog
 777         qb_log_ctl(QB_LOG_SYSLOG, QB_LOG_CONF_MAX_LINE_LEN, 256);
 778 #endif
 779 
 780         /* Set format strings and disable threading
 781          * Pacemaker and threads do not mix well (due to the amount of forking)
 782          */
 783         qb_log_tags_stringify_fn_set(crm_quark_to_string);
 784         for (lpc = QB_LOG_SYSLOG; lpc < QB_LOG_TARGET_MAX; lpc++) {
 785             qb_log_ctl(lpc, QB_LOG_CONF_THREADED, QB_FALSE);
 786 #ifdef HAVE_qb_log_conf_QB_LOG_CONF_ELLIPSIS
 787             // End truncated lines with '...'
 788             qb_log_ctl(lpc, QB_LOG_CONF_ELLIPSIS, QB_TRUE);
 789 #endif
 790             set_format_string(lpc, crm_system_name);
 791         }
 792     }
 793 }
 794 
 795 gboolean
 796 crm_log_init(const char *entity, uint8_t level, gboolean daemon, gboolean to_stderr,
     /*  */
 797              int argc, char **argv, gboolean quiet)
 798 {
 799     const char *syslog_priority = NULL;
 800     const char *facility = pcmk__env_option("logfacility");
 801     const char *f_copy = facility;
 802 
 803     pcmk__is_daemon = daemon;
 804     crm_log_preinit(entity, argc, argv);
 805 
 806     if (level > LOG_TRACE) {
 807         level = LOG_TRACE;
 808     }
 809     if(level > crm_log_level) {
 810         crm_log_level = level;
 811     }
 812 
 813     /* Should we log to syslog */
 814     if (facility == NULL) {
 815         if (pcmk__is_daemon) {
 816             facility = "daemon";
 817         } else {
 818             facility = "none";
 819         }
 820         pcmk__set_env_option("logfacility", facility);
 821     }
 822 
 823     if (pcmk__str_eq(facility, "none", pcmk__str_casei)) {
 824         quiet = TRUE;
 825 
 826 
 827     } else {
 828         qb_log_ctl(QB_LOG_SYSLOG, QB_LOG_CONF_FACILITY, qb_log_facility2int(facility));
 829     }
 830 
 831     if (pcmk__env_option_enabled(crm_system_name, "debug")) {
 832         /* Override the default setting */
 833         crm_log_level = LOG_DEBUG;
 834     }
 835 
 836     /* What lower threshold do we have for sending to syslog */
 837     syslog_priority = pcmk__env_option("logpriority");
 838     if (syslog_priority) {
 839         crm_log_priority = crm_priority2int(syslog_priority);
 840     }
 841     qb_log_filter_ctl(QB_LOG_SYSLOG, QB_LOG_FILTER_ADD, QB_LOG_FILTER_FILE, "*",
 842                       crm_log_priority);
 843 
 844     // Log to syslog unless requested to be quiet
 845     if (!quiet) {
 846         qb_log_ctl(QB_LOG_SYSLOG, QB_LOG_CONF_ENABLED, QB_TRUE);
 847     }
 848 
 849     /* Should we log to stderr */ 
 850     if (pcmk__env_option_enabled(crm_system_name, "stderr")) {
 851         /* Override the default setting */
 852         to_stderr = TRUE;
 853     }
 854     crm_enable_stderr(to_stderr);
 855 
 856     // Log to a file if we're a daemon or user asked for one
 857     {
 858         const char *logfile = pcmk__env_option("logfile");
 859 
 860         if (!pcmk__str_eq("none", logfile, pcmk__str_casei)
 861             && (pcmk__is_daemon || (logfile != NULL))) {
 862             // Daemons always get a log file, unless explicitly set to "none"
 863             pcmk__add_logfile(logfile);
 864         }
 865     }
 866 
 867     if (pcmk__is_daemon
 868         && pcmk__env_option_enabled(crm_system_name, "blackbox")) {
 869         crm_enable_blackbox(0);
 870     }
 871 
 872     /* Summary */
 873     crm_trace("Quiet: %d, facility %s", quiet, f_copy);
 874     pcmk__env_option("logfile");
 875     pcmk__env_option("logfacility");
 876 
 877     crm_update_callsites();
 878 
 879     /* Ok, now we can start logging... */
 880 
 881     // Disable daemon request if user isn't root or Pacemaker daemon user
 882     if (pcmk__is_daemon) {
 883         const char *user = getenv("USER");
 884 
 885         if (user != NULL && !pcmk__strcase_any_of(user, "root", CRM_DAEMON_USER, NULL)) {
 886             crm_trace("Not switching to corefile directory for %s", user);
 887             pcmk__is_daemon = false;
 888         }
 889     }
 890 
 891     if (pcmk__is_daemon) {
 892         int user = getuid();
 893         const char *base = CRM_CORE_DIR;
 894         struct passwd *pwent = getpwuid(user);
 895 
 896         if (pwent == NULL) {
 897             crm_perror(LOG_ERR, "Cannot get name for uid: %d", user);
 898 
 899         } else if (!pcmk__strcase_any_of(pwent->pw_name, "root", CRM_DAEMON_USER, NULL)) {
 900             crm_trace("Don't change active directory for regular user: %s", pwent->pw_name);
 901 
 902         } else if (chdir(base) < 0) {
 903             crm_perror(LOG_INFO, "Cannot change active directory to %s", base);
 904 
 905         } else {
 906             crm_info("Changed active directory to %s", base);
 907 #if 0
 908             {
 909                 char path[512];
 910 
 911                 snprintf(path, 512, "%s-%lu", crm_system_name, (unsigned long) getpid());
 912                 mkdir(path, 0750);
 913                 chdir(path);
 914                 crm_info("Changed active directory to %s/%s/%s", base, pwent->pw_name, path);
 915             }
 916 #endif
 917         }
 918 
 919         /* Original meanings from signal(7)
 920          *
 921          * Signal       Value     Action   Comment
 922          * SIGTRAP        5        Core    Trace/breakpoint trap
 923          * SIGUSR1     30,10,16    Term    User-defined signal 1
 924          * SIGUSR2     31,12,17    Term    User-defined signal 2
 925          *
 926          * Our usage is as similar as possible
 927          */
 928         mainloop_add_signal(SIGUSR1, crm_enable_blackbox);
 929         mainloop_add_signal(SIGUSR2, crm_disable_blackbox);
 930         mainloop_add_signal(SIGTRAP, crm_trigger_blackbox);
 931 
 932     } else if (!quiet) {
 933         crm_log_args(argc, argv);
 934     }
 935 
 936     return TRUE;
 937 }
 938 
 939 /* returns the old value */
 940 unsigned int
 941 set_crm_log_level(unsigned int level)
     /*  */
 942 {
 943     unsigned int old = crm_log_level;
 944 
 945     if (level > LOG_TRACE) {
 946         level = LOG_TRACE;
 947     }
 948     crm_log_level = level;
 949     crm_update_callsites();
 950     crm_trace("New log level: %d", level);
 951     return old;
 952 }
 953 
 954 void
 955 crm_enable_stderr(int enable)
     /*  */
 956 {
 957     if (enable && qb_log_ctl(QB_LOG_STDERR, QB_LOG_CONF_STATE_GET, 0) != QB_LOG_STATE_ENABLED) {
 958         qb_log_ctl(QB_LOG_STDERR, QB_LOG_CONF_ENABLED, QB_TRUE);
 959         crm_update_callsites();
 960 
 961     } else if (enable == FALSE) {
 962         qb_log_ctl(QB_LOG_STDERR, QB_LOG_CONF_ENABLED, QB_FALSE);
 963     }
 964 }
 965 
 966 /*!
 967  * \brief Make logging more verbose
 968  *
 969  * If logging to stderr is not already enabled when this function is called,
 970  * enable it. Otherwise, increase the log level by 1.
 971  *
 972  * \param[in] argc  Ignored
 973  * \param[in] argv  Ignored
 974  */
 975 void
 976 crm_bump_log_level(int argc, char **argv)
     /*  */
 977 {
 978     if (qb_log_ctl(QB_LOG_STDERR, QB_LOG_CONF_STATE_GET, 0)
 979         != QB_LOG_STATE_ENABLED) {
 980         crm_enable_stderr(TRUE);
 981     } else {
 982         set_crm_log_level(crm_log_level + 1);
 983     }
 984 }
 985 
 986 unsigned int
 987 get_crm_log_level(void)
     /*  */
 988 {
 989     return crm_log_level;
 990 }
 991 
 992 /*!
 993  * \brief Log the command line (once)
 994  *
 995  * \param[in]  Number of values in \p argv
 996  * \param[in]  Command-line arguments (including command name)
 997  *
 998  * \note This function will only log once, even if called with different
 999  *       arguments.
1000  */
1001 void
1002 crm_log_args(int argc, char **argv)
     /*  */
1003 {
1004     static bool logged = false;
1005     gchar *arg_string = NULL;
1006 
1007     if ((argc == 0) || (argv == NULL) || logged) {
1008         return;
1009     }
1010     logged = true;
1011     arg_string = g_strjoinv(" ", argv);
1012     crm_notice("Invoked: %s", arg_string);
1013     g_free(arg_string);
1014 }
1015 
1016 void
1017 crm_log_output_fn(const char *file, const char *function, int line, int level, const char *prefix,
     /*  */
1018                   const char *output)
1019 {
1020     const char *next = NULL;
1021     const char *offset = NULL;
1022 
1023     if (level == LOG_NEVER) {
1024         return;
1025     }
1026 
1027     if (output == NULL) {
1028         if (level != LOG_STDOUT) {
1029             level = LOG_TRACE;
1030         }
1031         output = "-- empty --";
1032     }
1033 
1034     next = output;
1035     do {
1036         offset = next;
1037         next = strchrnul(offset, '\n');
1038         do_crm_log_alias(level, file, function, line, "%s [ %.*s ]", prefix,
1039                          (int)(next - offset), offset);
1040         if (next[0] != 0) {
1041             next++;
1042         }
1043 
1044     } while (next != NULL && next[0] != 0);
1045 }
1046 
1047 void
1048 pcmk__cli_init_logging(const char *name, unsigned int verbosity)
     /*  */
1049 {
1050     crm_log_init(name, LOG_ERR, FALSE, FALSE, 0, NULL, TRUE);
1051 
1052     for (int i = 0; i < verbosity; i++) {
1053         /* These arguments are ignored, so pass placeholders. */
1054         crm_bump_log_level(0, NULL);
1055     }
1056 }
1057 
1058 // Deprecated functions kept only for backward API compatibility
1059 
1060 #include <crm/common/logging_compat.h>
1061 
1062 gboolean
1063 crm_log_cli_init(const char *entity)
     /*  */
1064 {
1065     pcmk__cli_init_logging(entity, 0);
1066     return TRUE;
1067 }
1068 
1069 gboolean
1070 crm_add_logfile(const char *filename)
     /*  */
1071 {
1072     return pcmk__add_logfile(filename) == pcmk_rc_ok;
1073 }
1074 
1075 // End deprecated API
/* */
root/lib/common/logging.c

DEFINITIONS
