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
set_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)
 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) {
 322         if (have_logfile) {
 323             return pcmk_rc_ok;
 324         }
 325         filename = DEFAULT_LOG_FILE;
 326     }
 327 
 328     // If the user doesn't want logging, we're done
 329     if (logfile_disabled(filename)) {
 330         return pcmk_rc_ok;
 331     }
 332 
 333     // If the caller wants the default and we already have it, we're done
 334     is_default = pcmk__str_eq(filename, DEFAULT_LOG_FILE, pcmk__str_none);
 335     if (is_default && (default_fd >= 0)) {
 336         return pcmk_rc_ok;
 337     }
 338 
 339     // Check whether we have write access to the file
 340     logfile = fopen(filename, "a");
 341     if (logfile == NULL) {
 342         rc = errno;
 343         crm_warn("Logging to '%s' is disabled: %s " CRM_XS " uid=%u gid=%u",
 344                  filename, strerror(rc), geteuid(), getegid());
 345         return rc;
 346     }
 347 
 348     rc = set_logfile_permissions(filename, logfile);
 349     if (rc != pcmk_rc_ok) {
 350         crm_warn("Logging to '%s' is disabled: %s " CRM_XS " permissions",
 351                  filename, strerror(rc));
 352         fclose(logfile);
 353         return rc;
 354     }
 355 
 356     // Close and reopen as libqb logging target
 357     fclose(logfile);
 358     fd = qb_log_file_open(filename);
 359     if (fd < 0) {
 360         crm_warn("Logging to '%s' is disabled: %s " CRM_XS " qb_log_file_open",
 361                  filename, strerror(-fd));
 362         return -fd; // == +errno
 363     }
 364 
 365     if (is_default) {
 366         default_fd = fd;
 367         setenv_logfile(filename);
 368 
 369     } else if (default_fd >= 0) {
 370         crm_notice("Switching logging to %s", filename);
 371         disable_logfile(default_fd);
 372     }
 373 
 374     crm_notice("Additional logging available in %s", filename);
 375     enable_logfile(fd);
 376     have_logfile = true;
 377     return pcmk_rc_ok;
 378 }
 379 
 380 static int blackbox_trigger = 0;
 381 static volatile char *blackbox_file_prefix = NULL;
 382 
 383 static void
 384 blackbox_logger(int32_t t, struct qb_log_callsite *cs, log_time_t timestamp,
     /*  */
 385                 const char *msg)
 386 {
 387     if(cs && cs->priority < LOG_ERR) {
 388         crm_write_blackbox(SIGTRAP, cs); /* Bypass the over-dumping logic */
 389     } else {
 390         crm_write_blackbox(0, cs);
 391     }
 392 }
 393 
 394 static void
 395 crm_control_blackbox(int nsig, bool enable)
     /*  */
 396 {
 397     int lpc = 0;
 398 
 399     if (blackbox_file_prefix == NULL) {
 400         pid_t pid = getpid();
 401 
 402         blackbox_file_prefix = crm_strdup_printf("%s/%s-%lu",
 403                                                  CRM_BLACKBOX_DIR,
 404                                                  crm_system_name,
 405                                                  (unsigned long) pid);
 406     }
 407 
 408     if (enable && qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_STATE_GET, 0) != QB_LOG_STATE_ENABLED) {
 409         qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_SIZE, 5 * 1024 * 1024); /* Any size change drops existing entries */
 410         qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_ENABLED, QB_TRUE);      /* Setting the size seems to disable it */
 411 
 412         /* Enable synchronous logging */
 413         for (lpc = QB_LOG_BLACKBOX; lpc < QB_LOG_TARGET_MAX; lpc++) {
 414             qb_log_ctl(lpc, QB_LOG_CONF_FILE_SYNC, QB_TRUE);
 415         }
 416 
 417         crm_notice("Initiated blackbox recorder: %s", blackbox_file_prefix);
 418 
 419         /* Save to disk on abnormal termination */
 420         crm_signal_handler(SIGSEGV, crm_trigger_blackbox);
 421         crm_signal_handler(SIGABRT, crm_trigger_blackbox);
 422         crm_signal_handler(SIGILL,  crm_trigger_blackbox);
 423         crm_signal_handler(SIGBUS,  crm_trigger_blackbox);
 424         crm_signal_handler(SIGFPE,  crm_trigger_blackbox);
 425 
 426         crm_update_callsites();
 427 
 428         blackbox_trigger = qb_log_custom_open(blackbox_logger, NULL, NULL, NULL);
 429         qb_log_ctl(blackbox_trigger, QB_LOG_CONF_ENABLED, QB_TRUE);
 430         crm_trace("Trigger: %d is %d %d", blackbox_trigger,
 431                   qb_log_ctl(blackbox_trigger, QB_LOG_CONF_STATE_GET, 0), QB_LOG_STATE_ENABLED);
 432 
 433         crm_update_callsites();
 434 
 435     } else if (!enable && qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_STATE_GET, 0) == QB_LOG_STATE_ENABLED) {
 436         qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_ENABLED, QB_FALSE);
 437 
 438         /* Disable synchronous logging again when the blackbox is disabled */
 439         for (lpc = QB_LOG_BLACKBOX; lpc < QB_LOG_TARGET_MAX; lpc++) {
 440             qb_log_ctl(lpc, QB_LOG_CONF_FILE_SYNC, QB_FALSE);
 441         }
 442     }
 443 }
 444 
 445 void
 446 crm_enable_blackbox(int nsig)
     /*  */
 447 {
 448     crm_control_blackbox(nsig, TRUE);
 449 }
 450 
 451 void
 452 crm_disable_blackbox(int nsig)
     /*  */
 453 {
 454     crm_control_blackbox(nsig, FALSE);
 455 }
 456 
 457 /*!
 458  * \internal
 459  * \brief Write out a blackbox, if blackboxes are enabled
 460  *
 461  * \param[in] nsig  Signal that was received
 462  * \param[in] cs    libqb callsite
 463  *
 464  * \note This may be called via a true signal handler and so must be async-safe.
 465  * @TODO actually make this async-safe
 466  */
 467 void
 468 crm_write_blackbox(int nsig, struct qb_log_callsite *cs)
     /*  */
 469 {
 470     static volatile int counter = 1;
 471     static volatile time_t last = 0;
 472 
 473     char buffer[NAME_MAX];
 474     time_t now = time(NULL);
 475 
 476     if (blackbox_file_prefix == NULL) {
 477         return;
 478     }
 479 
 480     switch (nsig) {
 481         case 0:
 482         case SIGTRAP:
 483             /* The graceful case - such as assertion failure or user request */
 484 
 485             if (nsig == 0 && now == last) {
 486                 /* Prevent over-dumping */
 487                 return;
 488             }
 489 
 490             snprintf(buffer, NAME_MAX, "%s.%d", blackbox_file_prefix, counter++);
 491             if (nsig == SIGTRAP) {
 492                 crm_notice("Blackbox dump requested, please see %s for contents", buffer);
 493 
 494             } else if (cs) {
 495                 syslog(LOG_NOTICE,
 496                        "Problem detected at %s:%d (%s), please see %s for additional details",
 497                        cs->function, cs->lineno, cs->filename, buffer);
 498             } else {
 499                 crm_notice("Problem detected, please see %s for additional details", buffer);
 500             }
 501 
 502             last = now;
 503             qb_log_blackbox_write_to_file(buffer);
 504 
 505             /* Flush the existing contents
 506              * A size change would also work
 507              */
 508             qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_ENABLED, QB_FALSE);
 509             qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_ENABLED, QB_TRUE);
 510             break;
 511 
 512         default:
 513             /* Do as little as possible, just try to get what we have out
 514              * We logged the filename when the blackbox was enabled
 515              */
 516             crm_signal_handler(nsig, SIG_DFL);
 517             qb_log_blackbox_write_to_file((const char *)blackbox_file_prefix);
 518             qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_ENABLED, QB_FALSE);
 519             raise(nsig);
 520             break;
 521     }
 522 }
 523 
 524 static const char *
 525 crm_quark_to_string(uint32_t tag)
     /*  */
 526 {
 527     const char *text = g_quark_to_string(tag);
 528 
 529     if (text) {
 530         return text;
 531     }
 532     return "";
 533 }
 534 
 535 static void
 536 crm_log_filter_source(int source, const char *trace_files, const char *trace_fns,
     /*  */
 537                       const char *trace_fmts, const char *trace_tags, const char *trace_blackbox,
 538                       struct qb_log_callsite *cs)
 539 {
 540     if (qb_log_ctl(source, QB_LOG_CONF_STATE_GET, 0) != QB_LOG_STATE_ENABLED) {
 541         return;
 542     } else if (cs->tags != crm_trace_nonlog && source == QB_LOG_BLACKBOX) {
 543         /* Blackbox gets everything if enabled */
 544         qb_bit_set(cs->targets, source);
 545 
 546     } else if (source == blackbox_trigger && blackbox_trigger > 0) {
 547         /* Should this log message result in the blackbox being dumped */
 548         if (cs->priority <= LOG_ERR) {
 549             qb_bit_set(cs->targets, source);
 550 
 551         } else if (trace_blackbox) {
 552             char *key = crm_strdup_printf("%s:%d", cs->function, cs->lineno);
 553 
 554             if (strstr(trace_blackbox, key) != NULL) {
 555                 qb_bit_set(cs->targets, source);
 556             }
 557             free(key);
 558         }
 559 
 560     } else if (source == QB_LOG_SYSLOG) {       /* No tracing to syslog */
 561         if (cs->priority <= crm_log_priority && cs->priority <= crm_log_level) {
 562             qb_bit_set(cs->targets, source);
 563         }
 564         /* Log file tracing options... */
 565     } else if (cs->priority <= crm_log_level) {
 566         qb_bit_set(cs->targets, source);
 567     } else if (trace_files && strstr(trace_files, cs->filename) != NULL) {
 568         qb_bit_set(cs->targets, source);
 569     } else if (trace_fns && strstr(trace_fns, cs->function) != NULL) {
 570         qb_bit_set(cs->targets, source);
 571     } else if (trace_fmts && strstr(trace_fmts, cs->format) != NULL) {
 572         qb_bit_set(cs->targets, source);
 573     } else if (trace_tags
 574                && cs->tags != 0
 575                && cs->tags != crm_trace_nonlog && g_quark_to_string(cs->tags) != NULL) {
 576         qb_bit_set(cs->targets, source);
 577     }
 578 }
 579 
 580 static void
 581 crm_log_filter(struct qb_log_callsite *cs)
     /*  */
 582 {
 583     int lpc = 0;
 584     static int need_init = 1;
 585     static const char *trace_fns = NULL;
 586     static const char *trace_tags = NULL;
 587     static const char *trace_fmts = NULL;
 588     static const char *trace_files = NULL;
 589     static const char *trace_blackbox = NULL;
 590 
 591     if (need_init) {
 592         need_init = 0;
 593         trace_fns = getenv("PCMK_trace_functions");
 594         trace_fmts = getenv("PCMK_trace_formats");
 595         trace_tags = getenv("PCMK_trace_tags");
 596         trace_files = getenv("PCMK_trace_files");
 597         trace_blackbox = getenv("PCMK_trace_blackbox");
 598 
 599         if (trace_tags != NULL) {
 600             uint32_t tag;
 601             char token[500];
 602             const char *offset = NULL;
 603             const char *next = trace_tags;
 604 
 605             do {
 606                 offset = next;
 607                 next = strchrnul(offset, ',');
 608                 snprintf(token, sizeof(token), "%.*s", (int)(next - offset), offset);
 609 
 610                 tag = g_quark_from_string(token);
 611                 crm_info("Created GQuark %u from token '%s' in '%s'", tag, token, trace_tags);
 612 
 613                 if (next[0] != 0) {
 614                     next++;
 615                 }
 616 
 617             } while (next != NULL && next[0] != 0);
 618         }
 619     }
 620 
 621     cs->targets = 0;            /* Reset then find targets to enable */
 622     for (lpc = QB_LOG_SYSLOG; lpc < QB_LOG_TARGET_MAX; lpc++) {
 623         crm_log_filter_source(lpc, trace_files, trace_fns, trace_fmts, trace_tags, trace_blackbox,
 624                               cs);
 625     }
 626 }
 627 
 628 gboolean
 629 crm_is_callsite_active(struct qb_log_callsite *cs, uint8_t level, uint32_t tags)
     /*  */
 630 {
 631     gboolean refilter = FALSE;
 632 
 633     if (cs == NULL) {
 634         return FALSE;
 635     }
 636 
 637     if (cs->priority != level) {
 638         cs->priority = level;
 639         refilter = TRUE;
 640     }
 641 
 642     if (cs->tags != tags) {
 643         cs->tags = tags;
 644         refilter = TRUE;
 645     }
 646 
 647     if (refilter) {
 648         crm_log_filter(cs);
 649     }
 650 
 651     if (cs->targets == 0) {
 652         return FALSE;
 653     }
 654     return TRUE;
 655 }
 656 
 657 void
 658 crm_update_callsites(void)
     /*  */
 659 {
 660     static gboolean log = TRUE;
 661 
 662     if (log) {
 663         log = FALSE;
 664         crm_debug
 665             ("Enabling callsites based on priority=%d, files=%s, functions=%s, formats=%s, tags=%s",
 666              crm_log_level, getenv("PCMK_trace_files"), getenv("PCMK_trace_functions"),
 667              getenv("PCMK_trace_formats"), getenv("PCMK_trace_tags"));
 668     }
 669     qb_log_filter_fn_set(crm_log_filter);
 670 }
 671 
 672 static gboolean
 673 crm_tracing_enabled(void)
     /*  */
 674 {
 675     if (crm_log_level == LOG_TRACE) {
 676         return TRUE;
 677     } else if (getenv("PCMK_trace_files") || getenv("PCMK_trace_functions")
 678                || getenv("PCMK_trace_formats") || getenv("PCMK_trace_tags")) {
 679         return TRUE;
 680     }
 681     return FALSE;
 682 }
 683 
 684 static int
 685 crm_priority2int(const char *name)
     /*  */
 686 {
 687     struct syslog_names {
 688         const char *name;
 689         int priority;
 690     };
 691     static struct syslog_names p_names[] = {
 692         {"emerg", LOG_EMERG},
 693         {"alert", LOG_ALERT},
 694         {"crit", LOG_CRIT},
 695         {"error", LOG_ERR},
 696         {"warning", LOG_WARNING},
 697         {"notice", LOG_NOTICE},
 698         {"info", LOG_INFO},
 699         {"debug", LOG_DEBUG},
 700         {NULL, -1}
 701     };
 702     int lpc;
 703 
 704     for (lpc = 0; name != NULL && p_names[lpc].name != NULL; lpc++) {
 705         if (pcmk__str_eq(p_names[lpc].name, name, pcmk__str_none)) {
 706             return p_names[lpc].priority;
 707         }
 708     }
 709     return crm_log_priority;
 710 }
 711 
 712 
 713 static void
 714 set_identity(const char *entity, int argc, char **argv)
     /*  */
 715 {
 716     if (crm_system_name != NULL) {
 717         return; // Already set, don't overwrite
 718     }
 719 
 720     if (entity != NULL) {
 721         crm_system_name = strdup(entity);
 722 
 723     } else if ((argc > 0) && (argv != NULL)) {
 724         char *mutable = strdup(argv[0]);
 725         char *modified = basename(mutable);
 726 
 727         if (strstr(modified, "lt-") == modified) {
 728             modified += 3;
 729         }
 730         crm_system_name = strdup(modified);
 731         free(mutable);
 732 
 733     } else {
 734         crm_system_name = strdup("Unknown");
 735     }
 736 
 737     CRM_ASSERT(crm_system_name != NULL);
 738 
 739     setenv("PCMK_service", crm_system_name, 1);
 740 }
 741 
 742 void
 743 crm_log_preinit(const char *entity, int argc, char **argv)
     /*  */
 744 {
 745     /* Configure libqb logging with nothing turned on */
 746 
 747     int lpc = 0;
 748     int32_t qb_facility = 0;
 749 
 750     static bool have_logging = FALSE;
 751 
 752     if(have_logging == FALSE) {
 753         have_logging = TRUE;
 754 
 755         crm_xml_init(); /* Sets buffer allocation strategy */
 756 
 757         if (crm_trace_nonlog == 0) {
 758             crm_trace_nonlog = g_quark_from_static_string("Pacemaker non-logging tracepoint");
 759         }
 760 
 761         umask(S_IWGRP | S_IWOTH | S_IROTH);
 762 
 763         /* Redirect messages from glib functions to our handler */
 764         glib_log_default = g_log_set_default_handler(crm_glib_handler, NULL);
 765 
 766         /* and for good measure... - this enum is a bit field (!) */
 767         g_log_set_always_fatal((GLogLevelFlags) 0); /*value out of range */
 768 
 769         /* Set crm_system_name, which is used as the logging name. It may also
 770          * be used for other purposes such as an IPC client name.
 771          */
 772         set_identity(entity, argc, argv);
 773 
 774         qb_facility = qb_log_facility2int("local0");
 775         qb_log_init(crm_system_name, qb_facility, LOG_ERR);
 776         crm_log_level = LOG_CRIT;
 777 
 778         /* Nuke any syslog activity until it's asked for */
 779         qb_log_ctl(QB_LOG_SYSLOG, QB_LOG_CONF_ENABLED, QB_FALSE);
 780 #ifdef HAVE_qb_log_conf_QB_LOG_CONF_MAX_LINE_LEN
 781         // Shorter than default, generous for what we *should* send to syslog
 782         qb_log_ctl(QB_LOG_SYSLOG, QB_LOG_CONF_MAX_LINE_LEN, 256);
 783 #endif
 784 
 785         /* Set format strings and disable threading
 786          * Pacemaker and threads do not mix well (due to the amount of forking)
 787          */
 788         qb_log_tags_stringify_fn_set(crm_quark_to_string);
 789         for (lpc = QB_LOG_SYSLOG; lpc < QB_LOG_TARGET_MAX; lpc++) {
 790             qb_log_ctl(lpc, QB_LOG_CONF_THREADED, QB_FALSE);
 791 #ifdef HAVE_qb_log_conf_QB_LOG_CONF_ELLIPSIS
 792             // End truncated lines with '...'
 793             qb_log_ctl(lpc, QB_LOG_CONF_ELLIPSIS, QB_TRUE);
 794 #endif
 795             set_format_string(lpc, crm_system_name);
 796         }
 797     }
 798 }
 799 
 800 gboolean
 801 crm_log_init(const char *entity, uint8_t level, gboolean daemon, gboolean to_stderr,
     /*  */
 802              int argc, char **argv, gboolean quiet)
 803 {
 804     const char *syslog_priority = NULL;
 805     const char *facility = pcmk__env_option("logfacility");
 806     const char *f_copy = facility;
 807 
 808     pcmk__is_daemon = daemon;
 809     crm_log_preinit(entity, argc, argv);
 810 
 811     if (level > LOG_TRACE) {
 812         level = LOG_TRACE;
 813     }
 814     if(level > crm_log_level) {
 815         crm_log_level = level;
 816     }
 817 
 818     /* Should we log to syslog */
 819     if (facility == NULL) {
 820         if (pcmk__is_daemon) {
 821             facility = "daemon";
 822         } else {
 823             facility = "none";
 824         }
 825         pcmk__set_env_option("logfacility", facility);
 826     }
 827 
 828     if (pcmk__str_eq(facility, "none", pcmk__str_casei)) {
 829         quiet = TRUE;
 830 
 831 
 832     } else {
 833         qb_log_ctl(QB_LOG_SYSLOG, QB_LOG_CONF_FACILITY, qb_log_facility2int(facility));
 834     }
 835 
 836     if (pcmk__env_option_enabled(crm_system_name, "debug")) {
 837         /* Override the default setting */
 838         crm_log_level = LOG_DEBUG;
 839     }
 840 
 841     /* What lower threshold do we have for sending to syslog */
 842     syslog_priority = pcmk__env_option("logpriority");
 843     if (syslog_priority) {
 844         crm_log_priority = crm_priority2int(syslog_priority);
 845     }
 846     qb_log_filter_ctl(QB_LOG_SYSLOG, QB_LOG_FILTER_ADD, QB_LOG_FILTER_FILE, "*",
 847                       crm_log_priority);
 848 
 849     // Log to syslog unless requested to be quiet
 850     if (!quiet) {
 851         qb_log_ctl(QB_LOG_SYSLOG, QB_LOG_CONF_ENABLED, QB_TRUE);
 852     }
 853 
 854     /* Should we log to stderr */ 
 855     if (pcmk__env_option_enabled(crm_system_name, "stderr")) {
 856         /* Override the default setting */
 857         to_stderr = TRUE;
 858     }
 859     crm_enable_stderr(to_stderr);
 860 
 861     // Log to a file if we're a daemon or user asked for one
 862     {
 863         const char *logfile = pcmk__env_option("logfile");
 864 
 865         if (!pcmk__str_eq("none", logfile, pcmk__str_casei)
 866             && (pcmk__is_daemon || (logfile != NULL))) {
 867             // Daemons always get a log file, unless explicitly set to "none"
 868             pcmk__add_logfile(logfile);
 869         }
 870     }
 871 
 872     if (pcmk__is_daemon
 873         && pcmk__env_option_enabled(crm_system_name, "blackbox")) {
 874         crm_enable_blackbox(0);
 875     }
 876 
 877     /* Summary */
 878     crm_trace("Quiet: %d, facility %s", quiet, f_copy);
 879     pcmk__env_option("logfile");
 880     pcmk__env_option("logfacility");
 881 
 882     crm_update_callsites();
 883 
 884     /* Ok, now we can start logging... */
 885 
 886     // Disable daemon request if user isn't root or Pacemaker daemon user
 887     if (pcmk__is_daemon) {
 888         const char *user = getenv("USER");
 889 
 890         if (user != NULL && !pcmk__strcase_any_of(user, "root", CRM_DAEMON_USER, NULL)) {
 891             crm_trace("Not switching to corefile directory for %s", user);
 892             pcmk__is_daemon = false;
 893         }
 894     }
 895 
 896     if (pcmk__is_daemon) {
 897         int user = getuid();
 898         const char *base = CRM_CORE_DIR;
 899         struct passwd *pwent = getpwuid(user);
 900 
 901         if (pwent == NULL) {
 902             crm_perror(LOG_ERR, "Cannot get name for uid: %d", user);
 903 
 904         } else if (!pcmk__strcase_any_of(pwent->pw_name, "root", CRM_DAEMON_USER, NULL)) {
 905             crm_trace("Don't change active directory for regular user: %s", pwent->pw_name);
 906 
 907         } else if (chdir(base) < 0) {
 908             crm_perror(LOG_INFO, "Cannot change active directory to %s", base);
 909 
 910         } else {
 911             crm_info("Changed active directory to %s", base);
 912 #if 0
 913             {
 914                 char path[512];
 915 
 916                 snprintf(path, 512, "%s-%lu", crm_system_name, (unsigned long) getpid());
 917                 mkdir(path, 0750);
 918                 chdir(path);
 919                 crm_info("Changed active directory to %s/%s/%s", base, pwent->pw_name, path);
 920             }
 921 #endif
 922         }
 923 
 924         /* Original meanings from signal(7)
 925          *
 926          * Signal       Value     Action   Comment
 927          * SIGTRAP        5        Core    Trace/breakpoint trap
 928          * SIGUSR1     30,10,16    Term    User-defined signal 1
 929          * SIGUSR2     31,12,17    Term    User-defined signal 2
 930          *
 931          * Our usage is as similar as possible
 932          */
 933         mainloop_add_signal(SIGUSR1, crm_enable_blackbox);
 934         mainloop_add_signal(SIGUSR2, crm_disable_blackbox);
 935         mainloop_add_signal(SIGTRAP, crm_trigger_blackbox);
 936 
 937     } else if (!quiet) {
 938         crm_log_args(argc, argv);
 939     }
 940 
 941     return TRUE;
 942 }
 943 
 944 /* returns the old value */
 945 unsigned int
 946 set_crm_log_level(unsigned int level)
     /*  */
 947 {
 948     unsigned int old = crm_log_level;
 949 
 950     if (level > LOG_TRACE) {
 951         level = LOG_TRACE;
 952     }
 953     crm_log_level = level;
 954     crm_update_callsites();
 955     crm_trace("New log level: %d", level);
 956     return old;
 957 }
 958 
 959 void
 960 crm_enable_stderr(int enable)
     /*  */
 961 {
 962     if (enable && qb_log_ctl(QB_LOG_STDERR, QB_LOG_CONF_STATE_GET, 0) != QB_LOG_STATE_ENABLED) {
 963         qb_log_ctl(QB_LOG_STDERR, QB_LOG_CONF_ENABLED, QB_TRUE);
 964         crm_update_callsites();
 965 
 966     } else if (enable == FALSE) {
 967         qb_log_ctl(QB_LOG_STDERR, QB_LOG_CONF_ENABLED, QB_FALSE);
 968     }
 969 }
 970 
 971 /*!
 972  * \brief Make logging more verbose
 973  *
 974  * If logging to stderr is not already enabled when this function is called,
 975  * enable it. Otherwise, increase the log level by 1.
 976  *
 977  * \param[in] argc  Ignored
 978  * \param[in] argv  Ignored
 979  */
 980 void
 981 crm_bump_log_level(int argc, char **argv)
     /*  */
 982 {
 983     if (qb_log_ctl(QB_LOG_STDERR, QB_LOG_CONF_STATE_GET, 0)
 984         != QB_LOG_STATE_ENABLED) {
 985         crm_enable_stderr(TRUE);
 986     } else {
 987         set_crm_log_level(crm_log_level + 1);
 988     }
 989 }
 990 
 991 unsigned int
 992 get_crm_log_level(void)
     /*  */
 993 {
 994     return crm_log_level;
 995 }
 996 
 997 /*!
 998  * \brief Log the command line (once)
 999  *
1000  * \param[in]  Number of values in \p argv
1001  * \param[in]  Command-line arguments (including command name)
1002  *
1003  * \note This function will only log once, even if called with different
1004  *       arguments.
1005  */
1006 void
1007 crm_log_args(int argc, char **argv)
     /*  */
1008 {
1009     static bool logged = false;
1010     gchar *arg_string = NULL;
1011 
1012     if ((argc == 0) || (argv == NULL) || logged) {
1013         return;
1014     }
1015     logged = true;
1016     arg_string = g_strjoinv(" ", argv);
1017     crm_notice("Invoked: %s", arg_string);
1018     g_free(arg_string);
1019 }
1020 
1021 void
1022 crm_log_output_fn(const char *file, const char *function, int line, int level, const char *prefix,
     /*  */
1023                   const char *output)
1024 {
1025     const char *next = NULL;
1026     const char *offset = NULL;
1027 
1028     if (level == LOG_NEVER) {
1029         return;
1030     }
1031 
1032     if (output == NULL) {
1033         if (level != LOG_STDOUT) {
1034             level = LOG_TRACE;
1035         }
1036         output = "-- empty --";
1037     }
1038 
1039     next = output;
1040     do {
1041         offset = next;
1042         next = strchrnul(offset, '\n');
1043         do_crm_log_alias(level, file, function, line, "%s [ %.*s ]", prefix,
1044                          (int)(next - offset), offset);
1045         if (next[0] != 0) {
1046             next++;
1047         }
1048 
1049     } while (next != NULL && next[0] != 0);
1050 }
1051 
1052 void
1053 pcmk__cli_init_logging(const char *name, unsigned int verbosity)
     /*  */
1054 {
1055     crm_log_init(name, LOG_ERR, FALSE, FALSE, 0, NULL, TRUE);
1056 
1057     for (int i = 0; i < verbosity; i++) {
1058         /* These arguments are ignored, so pass placeholders. */
1059         crm_bump_log_level(0, NULL);
1060     }
1061 }
1062 
1063 // Deprecated functions kept only for backward API compatibility
1064 
1065 #include <crm/common/logging_compat.h>
1066 
1067 gboolean
1068 crm_log_cli_init(const char *entity)
     /*  */
1069 {
1070     pcmk__cli_init_logging(entity, 0);
1071     return TRUE;
1072 }
1073 
1074 gboolean
1075 crm_add_logfile(const char *filename)
     /*  */
1076 {
1077     return pcmk__add_logfile(filename) == pcmk_rc_ok;
1078 }
1079 
1080 // End deprecated API
/* */
root/lib/common/logging.c

DEFINITIONS
