pacemaker  2.1.3-ea053b43a
Scalable High-Availability cluster resource manager
logging.c
Go to the documentation of this file.
1 /*
2  * Copyright 2004-2022 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 
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
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 
145 /* XXX __attribute__((nonnull)) for use_nodename parameter */
146 static void
147 set_format_string(int method, const char *daemon, pid_t use_pid,
148  const char *use_nodename)
149 {
150  if (method == QB_LOG_SYSLOG) {
151  // The system log gets a simplified, user-friendly format
152  crm_extended_logging(method, QB_FALSE);
153  qb_log_format_set(method, "%g %p: %b");
154 
155  } else {
156  // Everything else gets more detail, for advanced troubleshooting
157 
158  int offset = 0;
159  char fmt[FMT_MAX];
160 
161  if (method > QB_LOG_STDERR) {
162  // If logging to file, prefix with timestamp, node name, daemon ID
163  offset += snprintf(fmt + offset, FMT_MAX - offset,
164  TIMESTAMP_FORMAT_SPEC " %s %-20s[%lu] ",
165  use_nodename, daemon, (unsigned long) use_pid);
166  }
167 
168  // Add function name (in parentheses)
169  offset += snprintf(fmt + offset, FMT_MAX - offset, "(%%n");
170  if (crm_tracing_enabled()) {
171  // When tracing, add file and line number
172  offset += snprintf(fmt + offset, FMT_MAX - offset, "@%%f:%%l");
173  }
174  offset += snprintf(fmt + offset, FMT_MAX - offset, ")");
175 
176  // Add tag (if any), severity, and actual message
177  offset += snprintf(fmt + offset, FMT_MAX - offset, " %%g\t%%p: %%b");
178 
179  CRM_LOG_ASSERT(offset > 0);
180  qb_log_format_set(method, fmt);
181  }
182 }
183 
184 #define DEFAULT_LOG_FILE CRM_LOG_DIR "/pacemaker.log"
185 
186 static bool
187 logfile_disabled(const char *filename)
188 {
189  return pcmk__str_eq(filename, PCMK__VALUE_NONE, pcmk__str_casei)
190  || pcmk__str_eq(filename, "/dev/null", pcmk__str_none);
191 }
192 
202 static int
203 chown_logfile(const char *filename, int logfd)
204 {
205  uid_t pcmk_uid = 0;
206  gid_t pcmk_gid = 0;
207  struct stat st;
208  int rc;
209 
210  // Get the log file's current ownership and permissions
211  if (fstat(logfd, &st) < 0) {
212  return errno;
213  }
214 
215  // Any other errors don't prevent file from being used as log
216 
217  rc = pcmk_daemon_user(&pcmk_uid, &pcmk_gid);
218  if (rc != pcmk_ok) {
219  rc = pcmk_legacy2rc(rc);
220  crm_warn("Not changing '%s' ownership because user information "
221  "unavailable: %s", filename, pcmk_rc_str(rc));
222  return pcmk_rc_ok;
223  }
224  if ((st.st_gid == pcmk_gid)
225  && ((st.st_mode & S_IRWXG) == (S_IRGRP|S_IWGRP))) {
226  return pcmk_rc_ok;
227  }
228  if (fchown(logfd, pcmk_uid, pcmk_gid) < 0) {
229  crm_warn("Couldn't change '%s' ownership to user %s gid %d: %s",
230  filename, CRM_DAEMON_USER, pcmk_gid, strerror(errno));
231  }
232  return pcmk_rc_ok;
233 }
234 
235 // Reset log file permissions (using environment variable if set)
236 static void
237 chmod_logfile(const char *filename, int logfd)
238 {
239  const char *modestr = getenv("PCMK_logfile_mode");
240  mode_t filemode = S_IRUSR | S_IWUSR | S_IRGRP | S_IWGRP;
241 
242  if (modestr != NULL) {
243  long filemode_l = strtol(modestr, NULL, 8);
244 
245  if ((filemode_l != LONG_MIN) && (filemode_l != LONG_MAX)) {
246  filemode = (mode_t) filemode_l;
247  }
248  }
249  if ((filemode != 0) && (fchmod(logfd, filemode) < 0)) {
250  crm_warn("Couldn't change '%s' mode to %04o: %s",
251  filename, filemode, strerror(errno));
252  }
253 }
254 
255 // If we're root, correct a log file's permissions if needed
256 static int
257 set_logfile_permissions(const char *filename, FILE *logfile)
258 {
259  if (geteuid() == 0) {
260  int logfd = fileno(logfile);
261  int rc = chown_logfile(filename, logfd);
262 
263  if (rc != pcmk_rc_ok) {
264  return rc;
265  }
266  chmod_logfile(filename, logfd);
267  }
268  return pcmk_rc_ok;
269 }
270 
271 // Enable libqb logging to a new log file
272 static void
273 enable_logfile(int fd)
274 {
275  qb_log_ctl(fd, QB_LOG_CONF_ENABLED, QB_TRUE);
276 #if 0
277  qb_log_ctl(fd, QB_LOG_CONF_FILE_SYNC, 1); // Turn on synchronous writes
278 #endif
279 
280 #ifdef HAVE_qb_log_conf_QB_LOG_CONF_MAX_LINE_LEN
281  // Longer than default, for logging long XML lines
282  qb_log_ctl(fd, QB_LOG_CONF_MAX_LINE_LEN, 800);
283 #endif
284 
286 }
287 
288 static inline void
289 disable_logfile(int fd)
290 {
291  qb_log_ctl(fd, QB_LOG_CONF_ENABLED, QB_FALSE);
292 }
293 
294 static void
295 setenv_logfile(const char *filename)
296 {
297  // Some resource agents will log only if environment variable is set
298  if (pcmk__env_option(PCMK__ENV_LOGFILE) == NULL) {
300  }
301 }
302 
310 int
311 pcmk__add_logfile(const char *filename)
312 {
313  /* No log messages from this function will be logged to the new log!
314  * If another target such as syslog has already been added, the messages
315  * should show up there.
316  */
317 
318  int fd = 0;
319  int rc = pcmk_rc_ok;
320  FILE *logfile = NULL;
321  bool is_default = false;
322 
323  static int default_fd = -1;
324  static bool have_logfile = false;
325 
326  // Use default if caller didn't specify (and we don't already have one)
327  if (filename == NULL) {
328  if (have_logfile) {
329  return pcmk_rc_ok;
330  }
331  filename = DEFAULT_LOG_FILE;
332  }
333 
334  // If the user doesn't want logging, we're done
335  if (logfile_disabled(filename)) {
336  return pcmk_rc_ok;
337  }
338 
339  // If the caller wants the default and we already have it, we're done
340  is_default = pcmk__str_eq(filename, DEFAULT_LOG_FILE, pcmk__str_none);
341  if (is_default && (default_fd >= 0)) {
342  return pcmk_rc_ok;
343  }
344 
345  // Check whether we have write access to the file
346  logfile = fopen(filename, "a");
347  if (logfile == NULL) {
348  rc = errno;
349  crm_warn("Logging to '%s' is disabled: %s " CRM_XS " uid=%u gid=%u",
350  filename, strerror(rc), geteuid(), getegid());
351  return rc;
352  }
353 
354  rc = set_logfile_permissions(filename, logfile);
355  if (rc != pcmk_rc_ok) {
356  crm_warn("Logging to '%s' is disabled: %s " CRM_XS " permissions",
357  filename, strerror(rc));
358  fclose(logfile);
359  return rc;
360  }
361 
362  // Close and reopen as libqb logging target
363  fclose(logfile);
364  fd = qb_log_file_open(filename);
365  if (fd < 0) {
366  crm_warn("Logging to '%s' is disabled: %s " CRM_XS " qb_log_file_open",
367  filename, strerror(-fd));
368  return -fd; // == +errno
369  }
370 
371  if (is_default) {
372  default_fd = fd;
373  setenv_logfile(filename);
374 
375  } else if (default_fd >= 0) {
376  crm_notice("Switching logging to %s", filename);
377  disable_logfile(default_fd);
378  }
379 
380  crm_notice("Additional logging available in %s", filename);
381  enable_logfile(fd);
382  have_logfile = true;
383  return pcmk_rc_ok;
384 }
385 
386 static int blackbox_trigger = 0;
387 static volatile char *blackbox_file_prefix = NULL;
388 
389 static void
390 blackbox_logger(int32_t t, struct qb_log_callsite *cs, log_time_t timestamp,
391  const char *msg)
392 {
393  if(cs && cs->priority < LOG_ERR) {
394  crm_write_blackbox(SIGTRAP, cs); /* Bypass the over-dumping logic */
395  } else {
396  crm_write_blackbox(0, cs);
397  }
398 }
399 
400 static void
401 crm_control_blackbox(int nsig, bool enable)
402 {
403  int lpc = 0;
404 
405  if (blackbox_file_prefix == NULL) {
406  pid_t pid = getpid();
407 
408  blackbox_file_prefix = crm_strdup_printf("%s/%s-%lu",
411  (unsigned long) pid);
412  }
413 
414  if (enable && qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_STATE_GET, 0) != QB_LOG_STATE_ENABLED) {
415  qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_SIZE, 5 * 1024 * 1024); /* Any size change drops existing entries */
416  qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_ENABLED, QB_TRUE); /* Setting the size seems to disable it */
417 
418  /* Enable synchronous logging */
419  for (lpc = QB_LOG_BLACKBOX; lpc < QB_LOG_TARGET_MAX; lpc++) {
420  qb_log_ctl(lpc, QB_LOG_CONF_FILE_SYNC, QB_TRUE);
421  }
422 
423  crm_notice("Initiated blackbox recorder: %s", blackbox_file_prefix);
424 
425  /* Save to disk on abnormal termination */
426  crm_signal_handler(SIGSEGV, crm_trigger_blackbox);
427  crm_signal_handler(SIGABRT, crm_trigger_blackbox);
428  crm_signal_handler(SIGILL, crm_trigger_blackbox);
429  crm_signal_handler(SIGBUS, crm_trigger_blackbox);
430  crm_signal_handler(SIGFPE, crm_trigger_blackbox);
431 
433 
434  blackbox_trigger = qb_log_custom_open(blackbox_logger, NULL, NULL, NULL);
435  qb_log_ctl(blackbox_trigger, QB_LOG_CONF_ENABLED, QB_TRUE);
436  crm_trace("Trigger: %d is %d %d", blackbox_trigger,
437  qb_log_ctl(blackbox_trigger, QB_LOG_CONF_STATE_GET, 0), QB_LOG_STATE_ENABLED);
438 
440 
441  } else if (!enable && qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_STATE_GET, 0) == QB_LOG_STATE_ENABLED) {
442  qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_ENABLED, QB_FALSE);
443 
444  /* Disable synchronous logging again when the blackbox is disabled */
445  for (lpc = QB_LOG_BLACKBOX; lpc < QB_LOG_TARGET_MAX; lpc++) {
446  qb_log_ctl(lpc, QB_LOG_CONF_FILE_SYNC, QB_FALSE);
447  }
448  }
449 }
450 
451 void
453 {
454  crm_control_blackbox(nsig, TRUE);
455 }
456 
457 void
459 {
460  crm_control_blackbox(nsig, FALSE);
461 }
462 
473 void
474 crm_write_blackbox(int nsig, struct qb_log_callsite *cs)
475 {
476  static volatile int counter = 1;
477  static volatile time_t last = 0;
478 
479  char buffer[NAME_MAX];
480  time_t now = time(NULL);
481 
482  if (blackbox_file_prefix == NULL) {
483  return;
484  }
485 
486  switch (nsig) {
487  case 0:
488  case SIGTRAP:
489  /* The graceful case - such as assertion failure or user request */
490 
491  if (nsig == 0 && now == last) {
492  /* Prevent over-dumping */
493  return;
494  }
495 
496  snprintf(buffer, NAME_MAX, "%s.%d", blackbox_file_prefix, counter++);
497  if (nsig == SIGTRAP) {
498  crm_notice("Blackbox dump requested, please see %s for contents", buffer);
499 
500  } else if (cs) {
501  syslog(LOG_NOTICE,
502  "Problem detected at %s:%d (%s), please see %s for additional details",
503  cs->function, cs->lineno, cs->filename, buffer);
504  } else {
505  crm_notice("Problem detected, please see %s for additional details", buffer);
506  }
507 
508  last = now;
509  qb_log_blackbox_write_to_file(buffer);
510 
511  /* Flush the existing contents
512  * A size change would also work
513  */
514  qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_ENABLED, QB_FALSE);
515  qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_ENABLED, QB_TRUE);
516  break;
517 
518  default:
519  /* Do as little as possible, just try to get what we have out
520  * We logged the filename when the blackbox was enabled
521  */
522  crm_signal_handler(nsig, SIG_DFL);
523  qb_log_blackbox_write_to_file((const char *)blackbox_file_prefix);
524  qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_ENABLED, QB_FALSE);
525  raise(nsig);
526  break;
527  }
528 }
529 
530 static const char *
531 crm_quark_to_string(uint32_t tag)
532 {
533  const char *text = g_quark_to_string(tag);
534 
535  if (text) {
536  return text;
537  }
538  return "";
539 }
540 
541 static void
542 crm_log_filter_source(int source, const char *trace_files, const char *trace_fns,
543  const char *trace_fmts, const char *trace_tags, const char *trace_blackbox,
544  struct qb_log_callsite *cs)
545 {
546  if (qb_log_ctl(source, QB_LOG_CONF_STATE_GET, 0) != QB_LOG_STATE_ENABLED) {
547  return;
548  } else if (cs->tags != crm_trace_nonlog && source == QB_LOG_BLACKBOX) {
549  /* Blackbox gets everything if enabled */
550  qb_bit_set(cs->targets, source);
551 
552  } else if (source == blackbox_trigger && blackbox_trigger > 0) {
553  /* Should this log message result in the blackbox being dumped */
554  if (cs->priority <= LOG_ERR) {
555  qb_bit_set(cs->targets, source);
556 
557  } else if (trace_blackbox) {
558  char *key = crm_strdup_printf("%s:%d", cs->function, cs->lineno);
559 
560  if (strstr(trace_blackbox, key) != NULL) {
561  qb_bit_set(cs->targets, source);
562  }
563  free(key);
564  }
565 
566  } else if (source == QB_LOG_SYSLOG) { /* No tracing to syslog */
567  if (cs->priority <= crm_log_priority && cs->priority <= crm_log_level) {
568  qb_bit_set(cs->targets, source);
569  }
570  /* Log file tracing options... */
571  } else if (cs->priority <= crm_log_level) {
572  qb_bit_set(cs->targets, source);
573  } else if (trace_files && strstr(trace_files, cs->filename) != NULL) {
574  qb_bit_set(cs->targets, source);
575  } else if (trace_fns && strstr(trace_fns, cs->function) != NULL) {
576  qb_bit_set(cs->targets, source);
577  } else if (trace_fmts && strstr(trace_fmts, cs->format) != NULL) {
578  qb_bit_set(cs->targets, source);
579  } else if (trace_tags
580  && cs->tags != 0
581  && cs->tags != crm_trace_nonlog && g_quark_to_string(cs->tags) != NULL) {
582  qb_bit_set(cs->targets, source);
583  }
584 }
585 
586 static void
587 crm_log_filter(struct qb_log_callsite *cs)
588 {
589  int lpc = 0;
590  static int need_init = 1;
591  static const char *trace_fns = NULL;
592  static const char *trace_tags = NULL;
593  static const char *trace_fmts = NULL;
594  static const char *trace_files = NULL;
595  static const char *trace_blackbox = NULL;
596 
597  if (need_init) {
598  need_init = 0;
599  trace_fns = getenv("PCMK_trace_functions");
600  trace_fmts = getenv("PCMK_trace_formats");
601  trace_tags = getenv("PCMK_trace_tags");
602  trace_files = getenv("PCMK_trace_files");
603  trace_blackbox = getenv("PCMK_trace_blackbox");
604 
605  if (trace_tags != NULL) {
606  uint32_t tag;
607  char token[500];
608  const char *offset = NULL;
609  const char *next = trace_tags;
610 
611  do {
612  offset = next;
613  next = strchrnul(offset, ',');
614  snprintf(token, sizeof(token), "%.*s", (int)(next - offset), offset);
615 
616  tag = g_quark_from_string(token);
617  crm_info("Created GQuark %u from token '%s' in '%s'", tag, token, trace_tags);
618 
619  if (next[0] != 0) {
620  next++;
621  }
622 
623  } while (next != NULL && next[0] != 0);
624  }
625  }
626 
627  cs->targets = 0; /* Reset then find targets to enable */
628  for (lpc = QB_LOG_SYSLOG; lpc < QB_LOG_TARGET_MAX; lpc++) {
629  crm_log_filter_source(lpc, trace_files, trace_fns, trace_fmts, trace_tags, trace_blackbox,
630  cs);
631  }
632 }
633 
634 gboolean
635 crm_is_callsite_active(struct qb_log_callsite *cs, uint8_t level, uint32_t tags)
636 {
637  gboolean refilter = FALSE;
638 
639  if (cs == NULL) {
640  return FALSE;
641  }
642 
643  if (cs->priority != level) {
644  cs->priority = level;
645  refilter = TRUE;
646  }
647 
648  if (cs->tags != tags) {
649  cs->tags = tags;
650  refilter = TRUE;
651  }
652 
653  if (refilter) {
654  crm_log_filter(cs);
655  }
656 
657  if (cs->targets == 0) {
658  return FALSE;
659  }
660  return TRUE;
661 }
662 
663 void
665 {
666  static gboolean log = TRUE;
667 
668  if (log) {
669  log = FALSE;
670  crm_debug
671  ("Enabling callsites based on priority=%d, files=%s, functions=%s, formats=%s, tags=%s",
672  crm_log_level, getenv("PCMK_trace_files"), getenv("PCMK_trace_functions"),
673  getenv("PCMK_trace_formats"), getenv("PCMK_trace_tags"));
674  }
675  qb_log_filter_fn_set(crm_log_filter);
676 }
677 
678 static gboolean
679 crm_tracing_enabled(void)
680 {
681  if (crm_log_level == LOG_TRACE) {
682  return TRUE;
683  } else if (getenv("PCMK_trace_files") || getenv("PCMK_trace_functions")
684  || getenv("PCMK_trace_formats") || getenv("PCMK_trace_tags")) {
685  return TRUE;
686  }
687  return FALSE;
688 }
689 
690 static int
691 crm_priority2int(const char *name)
692 {
693  struct syslog_names {
694  const char *name;
695  int priority;
696  };
697  static struct syslog_names p_names[] = {
698  {"emerg", LOG_EMERG},
699  {"alert", LOG_ALERT},
700  {"crit", LOG_CRIT},
701  {"error", LOG_ERR},
702  {"warning", LOG_WARNING},
703  {"notice", LOG_NOTICE},
704  {"info", LOG_INFO},
705  {"debug", LOG_DEBUG},
706  {NULL, -1}
707  };
708  int lpc;
709 
710  for (lpc = 0; name != NULL && p_names[lpc].name != NULL; lpc++) {
711  if (pcmk__str_eq(p_names[lpc].name, name, pcmk__str_none)) {
712  return p_names[lpc].priority;
713  }
714  }
715  return crm_log_priority;
716 }
717 
718 
735 static void
736 set_identity(const char *entity, int argc, char **argv)
737 {
738  if (crm_system_name != NULL) {
739  return; // Already set, don't overwrite
740  }
741 
742  if (entity != NULL) {
743  crm_system_name = strdup(entity);
744 
745  } else if ((argc > 0) && (argv != NULL)) {
746  char *mutable = strdup(argv[0]);
747  char *modified = basename(mutable);
748 
749  if (strstr(modified, "lt-") == modified) {
750  modified += 3;
751  }
752  crm_system_name = strdup(modified);
753  free(mutable);
754 
755  } else {
756  crm_system_name = strdup("Unknown");
757  }
758 
759  CRM_ASSERT(crm_system_name != NULL);
760 
761  setenv("PCMK_service", crm_system_name, 1);
762 }
763 
764 void
765 crm_log_preinit(const char *entity, int argc, char **argv)
766 {
767  /* Configure libqb logging with nothing turned on */
768 
769  struct utsname res;
770  int lpc = 0;
771  int32_t qb_facility = 0;
772  pid_t pid = getpid();
773  const char *nodename = "localhost";
774  static bool have_logging = false;
775 
776  if (have_logging) {
777  return;
778  }
779 
780  have_logging = true;
781 
782  crm_xml_init(); /* Sets buffer allocation strategy */
783 
784  if (crm_trace_nonlog == 0) {
785  crm_trace_nonlog = g_quark_from_static_string("Pacemaker non-logging tracepoint");
786  }
787 
788  umask(S_IWGRP | S_IWOTH | S_IROTH);
789 
790  /* Redirect messages from glib functions to our handler */
791  glib_log_default = g_log_set_default_handler(crm_glib_handler, NULL);
792 
793  /* and for good measure... - this enum is a bit field (!) */
794  g_log_set_always_fatal((GLogLevelFlags) 0); /*value out of range */
795 
796  /* Set crm_system_name, which is used as the logging name. It may also
797  * be used for other purposes such as an IPC client name.
798  */
799  set_identity(entity, argc, argv);
800 
801  qb_facility = qb_log_facility2int("local0");
802  qb_log_init(crm_system_name, qb_facility, LOG_ERR);
803  crm_log_level = LOG_CRIT;
804 
805  /* Nuke any syslog activity until it's asked for */
806  qb_log_ctl(QB_LOG_SYSLOG, QB_LOG_CONF_ENABLED, QB_FALSE);
807 #ifdef HAVE_qb_log_conf_QB_LOG_CONF_MAX_LINE_LEN
808  // Shorter than default, generous for what we *should* send to syslog
809  qb_log_ctl(QB_LOG_SYSLOG, QB_LOG_CONF_MAX_LINE_LEN, 256);
810 #endif
811  if (uname(memset(&res, 0, sizeof(res))) == 0 && *res.nodename != '\0') {
812  nodename = res.nodename;
813  }
814 
815  /* Set format strings and disable threading
816  * Pacemaker and threads do not mix well (due to the amount of forking)
817  */
818  qb_log_tags_stringify_fn_set(crm_quark_to_string);
819  for (lpc = QB_LOG_SYSLOG; lpc < QB_LOG_TARGET_MAX; lpc++) {
820  qb_log_ctl(lpc, QB_LOG_CONF_THREADED, QB_FALSE);
821 #ifdef HAVE_qb_log_conf_QB_LOG_CONF_ELLIPSIS
822  // End truncated lines with '...'
823  qb_log_ctl(lpc, QB_LOG_CONF_ELLIPSIS, QB_TRUE);
824 #endif
825  set_format_string(lpc, crm_system_name, pid, nodename);
826  }
827 
828 #ifdef ENABLE_NLS
829  /* Enable translations (experimental). Currently we only have a few
830  * proof-of-concept translations for some option help. The goal would be to
831  * offer translations for option help and man pages rather than logs or
832  * documentation, to reduce the burden of maintaining them.
833  */
834 
835  // Load locale information for the local host from the environment
836  setlocale(LC_ALL, "");
837 
838  // Tell gettext where to find Pacemaker message catalogs
840 
841  // Tell gettext to use the Pacemaker message catalogs
842  CRM_ASSERT(textdomain(PACKAGE) != NULL);
843 
844  // Tell gettext that the translated strings are stored in UTF-8
846 #endif
847 }
848 
849 gboolean
850 crm_log_init(const char *entity, uint8_t level, gboolean daemon, gboolean to_stderr,
851  int argc, char **argv, gboolean quiet)
852 {
853  const char *syslog_priority = NULL;
854  const char *facility = pcmk__env_option(PCMK__ENV_LOGFACILITY);
855  const char *f_copy = facility;
856 
858  crm_log_preinit(entity, argc, argv);
859 
860  if (level > LOG_TRACE) {
861  level = LOG_TRACE;
862  }
863  if(level > crm_log_level) {
864  crm_log_level = level;
865  }
866 
867  /* Should we log to syslog */
868  if (facility == NULL) {
869  if (pcmk__is_daemon) {
870  facility = "daemon";
871  } else {
872  facility = PCMK__VALUE_NONE;
873  }
875  }
876 
877  if (pcmk__str_eq(facility, PCMK__VALUE_NONE, pcmk__str_casei)) {
878  quiet = TRUE;
879 
880 
881  } else {
882  qb_log_ctl(QB_LOG_SYSLOG, QB_LOG_CONF_FACILITY, qb_log_facility2int(facility));
883  }
884 
886  /* Override the default setting */
887  crm_log_level = LOG_DEBUG;
888  }
889 
890  /* What lower threshold do we have for sending to syslog */
891  syslog_priority = pcmk__env_option(PCMK__ENV_LOGPRIORITY);
892  if (syslog_priority) {
893  crm_log_priority = crm_priority2int(syslog_priority);
894  }
895  qb_log_filter_ctl(QB_LOG_SYSLOG, QB_LOG_FILTER_ADD, QB_LOG_FILTER_FILE, "*",
896  crm_log_priority);
897 
898  // Log to syslog unless requested to be quiet
899  if (!quiet) {
900  qb_log_ctl(QB_LOG_SYSLOG, QB_LOG_CONF_ENABLED, QB_TRUE);
901  }
902 
903  /* Should we log to stderr */
905  /* Override the default setting */
906  to_stderr = TRUE;
907  }
908  crm_enable_stderr(to_stderr);
909 
910  // Log to a file if we're a daemon or user asked for one
911  {
912  const char *logfile = pcmk__env_option(PCMK__ENV_LOGFILE);
913 
914  if (!pcmk__str_eq(PCMK__VALUE_NONE, logfile, pcmk__str_casei)
915  && (pcmk__is_daemon || (logfile != NULL))) {
916  // Daemons always get a log file, unless explicitly set to "none"
917  pcmk__add_logfile(logfile);
918  }
919  }
920 
921  if (pcmk__is_daemon
924  }
925 
926  /* Summary */
927  crm_trace("Quiet: %d, facility %s", quiet, f_copy);
930 
932 
933  /* Ok, now we can start logging... */
934 
935  // Disable daemon request if user isn't root or Pacemaker daemon user
936  if (pcmk__is_daemon) {
937  const char *user = getenv("USER");
938 
939  if (user != NULL && !pcmk__strcase_any_of(user, "root", CRM_DAEMON_USER, NULL)) {
940  crm_trace("Not switching to corefile directory for %s", user);
941  pcmk__is_daemon = false;
942  }
943  }
944 
945  if (pcmk__is_daemon) {
946  int user = getuid();
947  struct passwd *pwent = getpwuid(user);
948 
949  if (pwent == NULL) {
950  crm_perror(LOG_ERR, "Cannot get name for uid: %d", user);
951 
952  } else if (!pcmk__strcase_any_of(pwent->pw_name, "root", CRM_DAEMON_USER, NULL)) {
953  crm_trace("Don't change active directory for regular user: %s", pwent->pw_name);
954 
955  } else if (chdir(CRM_CORE_DIR) < 0) {
956  crm_perror(LOG_INFO, "Cannot change active directory to " CRM_CORE_DIR);
957 
958  } else {
959  crm_info("Changed active directory to " CRM_CORE_DIR);
960  }
961 
962  /* Original meanings from signal(7)
963  *
964  * Signal Value Action Comment
965  * SIGTRAP 5 Core Trace/breakpoint trap
966  * SIGUSR1 30,10,16 Term User-defined signal 1
967  * SIGUSR2 31,12,17 Term User-defined signal 2
968  *
969  * Our usage is as similar as possible
970  */
973  mainloop_add_signal(SIGTRAP, crm_trigger_blackbox);
974 
975  } else if (!quiet) {
976  crm_log_args(argc, argv);
977  }
978 
979  return TRUE;
980 }
981 
982 /* returns the old value */
983 unsigned int
984 set_crm_log_level(unsigned int level)
985 {
986  unsigned int old = crm_log_level;
987 
988  if (level > LOG_TRACE) {
989  level = LOG_TRACE;
990  }
991  crm_log_level = level;
993  crm_trace("New log level: %d", level);
994  return old;
995 }
996 
997 void
998 crm_enable_stderr(int enable)
999 {
1000  if (enable && qb_log_ctl(QB_LOG_STDERR, QB_LOG_CONF_STATE_GET, 0) != QB_LOG_STATE_ENABLED) {
1001  qb_log_ctl(QB_LOG_STDERR, QB_LOG_CONF_ENABLED, QB_TRUE);
1003 
1004  } else if (enable == FALSE) {
1005  qb_log_ctl(QB_LOG_STDERR, QB_LOG_CONF_ENABLED, QB_FALSE);
1006  }
1007 }
1008 
1018 void
1019 crm_bump_log_level(int argc, char **argv)
1020 {
1021  if (qb_log_ctl(QB_LOG_STDERR, QB_LOG_CONF_STATE_GET, 0)
1022  != QB_LOG_STATE_ENABLED) {
1023  crm_enable_stderr(TRUE);
1024  } else {
1026  }
1027 }
1028 
1029 unsigned int
1031 {
1032  return crm_log_level;
1033 }
1034 
1044 void
1045 crm_log_args(int argc, char **argv)
1046 {
1047  static bool logged = false;
1048  gchar *arg_string = NULL;
1049 
1050  if ((argc == 0) || (argv == NULL) || logged) {
1051  return;
1052  }
1053  logged = true;
1054  arg_string = g_strjoinv(" ", argv);
1055  crm_notice("Invoked: %s", arg_string);
1056  g_free(arg_string);
1057 }
1058 
1059 void
1060 crm_log_output_fn(const char *file, const char *function, int line, int level, const char *prefix,
1061  const char *output)
1062 {
1063  const char *next = NULL;
1064  const char *offset = NULL;
1065 
1066  if (level == LOG_NEVER) {
1067  return;
1068  }
1069 
1070  if (output == NULL) {
1071  if (level != LOG_STDOUT) {
1072  level = LOG_TRACE;
1073  }
1074  output = "-- empty --";
1075  }
1076 
1077  next = output;
1078  do {
1079  offset = next;
1080  next = strchrnul(offset, '\n');
1081  do_crm_log_alias(level, file, function, line, "%s [ %.*s ]", prefix,
1082  (int)(next - offset), offset);
1083  if (next[0] != 0) {
1084  next++;
1085  }
1086 
1087  } while (next != NULL && next[0] != 0);
1088 }
1089 
1090 void
1091 pcmk__cli_init_logging(const char *name, unsigned int verbosity)
1092 {
1093  crm_log_init(name, LOG_ERR, FALSE, FALSE, 0, NULL, TRUE);
1094 
1095  for (int i = 0; i < verbosity; i++) {
1096  /* These arguments are ignored, so pass placeholders. */
1097  crm_bump_log_level(0, NULL);
1098  }
1099 }
1100 
1101 // Deprecated functions kept only for backward API compatibility
1102 // LCOV_EXCL_START
1103 
1104 #include <crm/common/logging_compat.h>
1105 
1106 gboolean
1107 crm_log_cli_init(const char *entity)
1108 {
1109  pcmk__cli_init_logging(entity, 0);
1110  return TRUE;
1111 }
1112 
1113 gboolean
1114 crm_add_logfile(const char *filename)
1115 {
1116  return pcmk__add_logfile(filename) == pcmk_rc_ok;
1117 }
1118 
1119 // LCOV_EXCL_STOP
1120 // End deprecated API
#define CRM_CORE_DIR
Definition: config.h:21
#define LOG_TRACE
Definition: logging.h:37
void pcmk__cli_init_logging(const char *name, unsigned int verbosity)
Definition: logging.c:1091
A dumping ground.
#define crm_notice(fmt, args...)
Definition: logging.h:360
#define PCMK__ENV_LOGFILE
void crm_log_preinit(const char *entity, int argc, char **argv)
Initializes the logging system and defaults to the least verbose output level.
Definition: logging.c:765
gboolean mainloop_add_signal(int sig, void(*dispatch)(int sig))
Definition: mainloop.c:355
void crm_enable_blackbox(int nsig)
Definition: logging.c:452
unsigned int get_crm_log_level(void)
Definition: logging.c:1030
void crm_disable_blackbox(int nsig)
Definition: logging.c:458
const char * name
Definition: cib.c:24
bool pcmk__strcase_any_of(const char *s,...) G_GNUC_NULL_TERMINATED
Definition: strings.c:931
int pcmk__add_logfile(const char *filename)
Add a file to be used as a Pacemaker detail log.
Definition: logging.c:311
void crm_xml_init(void)
Initialize the CRM XML subsystem.
Definition: xml.c:2835
char * crm_system_name
Definition: utils.c:54
gboolean crm_is_callsite_active(struct qb_log_callsite *cs, uint8_t level, uint32_t tags)
Definition: logging.c:635
void pcmk__set_env_option(const char *option, const char *value)
Set or unset a Pacemaker environment variable option.
Definition: options.c:319
#define CRM_LOG_ASSERT(expr)
Definition: logging.h:210
#define bindtextdomain(Domainname, Dirname)
Definition: gettext.h:87
void crm_write_blackbox(int nsig, struct qb_log_callsite *cs)
Definition: logging.c:474
#define PCMK__VALUE_NONE
#define do_crm_log_alias(level, file, function, line, fmt, args...)
Log a message as if it came from a different code location.
Definition: logging.h:281
#define bind_textdomain_codeset(Domainname, Codeset)
Definition: gettext.h:90
int pcmk_daemon_user(uid_t *uid, gid_t *gid)
Get user and group IDs of pacemaker daemon user.
Definition: utils.c:97
const char * pcmk_rc_str(int rc)
Get a user-friendly description of a return code.
Definition: results.c:370
char * strerror(int errnum)
#define LOG_NEVER
Definition: logging.h:47
const char * pcmk__env_option(const char *option)
Definition: options.c:286
Deprecated Pacemaker logging API.
Wrappers for and extensions to glib mainloop.
#define FMT_MAX
Definition: logging.c:132
gboolean crm_add_logfile(const char *filename)
Definition: logging.c:1114
void crm_log_args(int argc, char **argv)
Log the command line (once)
Definition: logging.c:1045
#define textdomain(Domainname)
Definition: gettext.h:85
bool pcmk__is_daemon
Definition: logging.c:47
#define PCMK__ENV_BLACKBOX
#define crm_warn(fmt, args...)
Definition: logging.h:359
gboolean crm_log_init(const char *entity, uint8_t level, gboolean daemon, gboolean to_stderr, int argc, char **argv, gboolean quiet)
Definition: logging.c:850
int daemon(int nochdir, int noclose)
stonith_t * st
Definition: pcmk_fence.c:27
uint32_t pid
Definition: cpg.c:46
#define crm_debug(fmt, args...)
Definition: logging.h:363
time_t log_time_t
Definition: logging.c:42
unsigned int crm_log_level
Definition: logging.c:45
void crm_enable_stderr(int enable)
Definition: logging.c:998
#define DEFAULT_LOG_FILE
Definition: logging.c:184
#define crm_trace(fmt, args...)
Definition: logging.h:364
#define do_crm_log(level, fmt, args...)
Log a message.
Definition: logging.h:167
int setenv(const char *name, const char *value, int why)
#define CRM_BLACKBOX_DIR
Definition: config.h:11
char * crm_strdup_printf(char const *format,...) G_GNUC_PRINTF(1
unsigned int crm_trace_nonlog
Definition: logging.c:46
sighandler_t crm_signal_handler(int sig, sighandler_t dispatch)
Definition: mainloop.c:307
#define TIMESTAMP_FORMAT_SPEC
Definition: logging.c:41
void crm_update_callsites(void)
Definition: logging.c:664
#define PCMK__ENV_LOGPRIORITY
#define CRM_DAEMON_USER
Definition: config.h:30
int pcmk_legacy2rc(int legacy_rc)
Definition: results.c:428
void crm_log_output_fn(const char *file, const char *function, int line, int level, const char *prefix, const char *output)
Definition: logging.c:1060
#define CRM_XS
Definition: logging.h:55
#define PCMK__ENV_DEBUG
#define crm_perror(level, fmt, args...)
Send a system error message to both the log and stderr.
Definition: logging.h:309
gboolean crm_log_cli_init(const char *entity)
Definition: logging.c:1107
#define CRM_ASSERT(expr)
Definition: results.h:42
#define NAME_MAX
Definition: logging.c:103
#define PCMK__ENV_STDERR
char uname[MAX_NAME]
Definition: cpg.c:50
char * strchrnul(const char *s, int c_in)
#define pcmk_ok
Definition: results.h:68
unsigned int set_crm_log_level(unsigned int level)
Definition: logging.c:984
#define PCMK__LOCALE_DIR
Definition: config.h:543
#define PACKAGE
Definition: config.h:507
void crm_abort(const char *file, const char *function, int line, const char *condition, gboolean do_core, gboolean do_fork)
Definition: utils.c:368
#define LOG_STDOUT
Definition: logging.h:42
void crm_bump_log_level(int argc, char **argv)
Make logging more verbose.
Definition: logging.c:1019
#define crm_info(fmt, args...)
Definition: logging.h:361
void crm_log_deinit(void)
Definition: logging.c:125
uint64_t flags
Definition: remote.c:149
bool pcmk__env_option_enabled(const char *daemon, const char *option)
Definition: options.c:356
#define PCMK__ENV_LOGFACILITY