lib/common/logging.c

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

DEFINITIONS
