pacemaker  3.0.0-d8340737c4
Scalable High-Availability cluster resource manager
logging.c
Go to the documentation of this file.
1 /*
2  * Copyright 2004-2024 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 guint pcmk__log_id = 0;
51 static guint pcmk__glib_log_id = 0;
52 static guint pcmk__gio_log_id = 0;
53 static guint pcmk__gmodule_log_id = 0;
54 static guint pcmk__gthread_log_id = 0;
55 static pcmk__output_t *logger_out = NULL;
56 
61 
62 static gboolean crm_tracing_enabled(void);
63 
64 static void
65 crm_glib_handler(const gchar * log_domain, GLogLevelFlags flags, const gchar * message,
66  gpointer user_data)
67 {
68  int log_level = LOG_WARNING;
69  GLogLevelFlags msg_level = (flags & G_LOG_LEVEL_MASK);
70  static struct qb_log_callsite *glib_cs = NULL;
71 
72  if (glib_cs == NULL) {
73  glib_cs = qb_log_callsite_get(__func__, __FILE__, "glib-handler",
74  LOG_DEBUG, __LINE__, crm_trace_nonlog);
75  }
76 
77  switch (msg_level) {
78  case G_LOG_LEVEL_CRITICAL:
79  log_level = LOG_CRIT;
80 
81  if (!crm_is_callsite_active(glib_cs, LOG_DEBUG, crm_trace_nonlog)) {
82  /* log and record how we got here */
83  crm_abort(__FILE__, __func__, __LINE__, message, TRUE, TRUE);
84  }
85  break;
86 
87  case G_LOG_LEVEL_ERROR:
88  log_level = LOG_ERR;
89  break;
90  case G_LOG_LEVEL_MESSAGE:
91  log_level = LOG_NOTICE;
92  break;
93  case G_LOG_LEVEL_INFO:
94  log_level = LOG_INFO;
95  break;
96  case G_LOG_LEVEL_DEBUG:
97  log_level = LOG_DEBUG;
98  break;
99 
100  case G_LOG_LEVEL_WARNING:
101  case G_LOG_FLAG_RECURSION:
102  case G_LOG_FLAG_FATAL:
103  case G_LOG_LEVEL_MASK:
104  log_level = LOG_WARNING;
105  break;
106  }
107 
108  do_crm_log(log_level, "%s: %s", log_domain, message);
109 }
110 
111 #ifndef NAME_MAX
112 # define NAME_MAX 256
113 #endif
114 
123 static void
124 crm_trigger_blackbox(int nsig)
125 {
126  if(nsig == SIGTRAP) {
127  /* Turn it on if it wasn't already */
128  crm_enable_blackbox(nsig);
129  }
130  crm_write_blackbox(nsig, NULL);
131 }
132 
133 void
135 {
136  if (pcmk__log_id == 0) {
137  return;
138  }
139 
140  g_log_remove_handler(G_LOG_DOMAIN, pcmk__log_id);
141  pcmk__log_id = 0;
142  g_log_remove_handler("GLib", pcmk__glib_log_id);
143  pcmk__glib_log_id = 0;
144  g_log_remove_handler("GLib-GIO", pcmk__gio_log_id);
145  pcmk__gio_log_id = 0;
146  g_log_remove_handler("GModule", pcmk__gmodule_log_id);
147  pcmk__gmodule_log_id = 0;
148  g_log_remove_handler("GThread", pcmk__gthread_log_id);
149  pcmk__gthread_log_id = 0;
150 }
151 
152 #define FMT_MAX 256
153 
165 /* XXX __attribute__((nonnull)) for use_nodename parameter */
166 static void
167 set_format_string(int method, const char *daemon, pid_t use_pid,
168  const char *use_nodename)
169 {
170  if (method == QB_LOG_SYSLOG) {
171  // The system log gets a simplified, user-friendly format
172  qb_log_ctl(method, QB_LOG_CONF_EXTENDED, QB_FALSE);
173  qb_log_format_set(method, "%g %p: %b");
174 
175  } else {
176  // Everything else gets more detail, for advanced troubleshooting
177 
178  int offset = 0;
179  char fmt[FMT_MAX];
180 
181  if (method > QB_LOG_STDERR) {
182  // If logging to file, prefix with timestamp, node name, daemon ID
183  offset += snprintf(fmt + offset, FMT_MAX - offset,
184  TIMESTAMP_FORMAT_SPEC " %s %-20s[%lu] ",
185  use_nodename, daemon, (unsigned long) use_pid);
186  }
187 
188  // Add function name (in parentheses)
189  offset += snprintf(fmt + offset, FMT_MAX - offset, "(%%n");
190  if (crm_tracing_enabled()) {
191  // When tracing, add file and line number
192  offset += snprintf(fmt + offset, FMT_MAX - offset, "@%%f:%%l");
193  }
194  offset += snprintf(fmt + offset, FMT_MAX - offset, ")");
195 
196  // Add tag (if any), severity, and actual message
197  offset += snprintf(fmt + offset, FMT_MAX - offset, " %%g\t%%p: %%b");
198 
199  CRM_LOG_ASSERT(offset > 0);
200  qb_log_format_set(method, fmt);
201  }
202 }
203 
204 #define DEFAULT_LOG_FILE CRM_LOG_DIR "/pacemaker.log"
205 
206 static bool
207 logfile_disabled(const char *filename)
208 {
209  return pcmk__str_eq(filename, PCMK_VALUE_NONE, pcmk__str_casei)
210  || pcmk__str_eq(filename, "/dev/null", pcmk__str_none);
211 }
212 
222 static int
223 chown_logfile(const char *filename, int logfd)
224 {
225  uid_t pcmk_uid = 0;
226  gid_t pcmk_gid = 0;
227  struct stat st;
228  int rc;
229 
230  // Get the log file's current ownership and permissions
231  if (fstat(logfd, &st) < 0) {
232  return errno;
233  }
234 
235  // Any other errors don't prevent file from being used as log
236 
237  rc = pcmk_daemon_user(&pcmk_uid, &pcmk_gid);
238  if (rc != pcmk_ok) {
239  rc = pcmk_legacy2rc(rc);
240  crm_warn("Not changing '%s' ownership because user information "
241  "unavailable: %s", filename, pcmk_rc_str(rc));
242  return pcmk_rc_ok;
243  }
244  if ((st.st_gid == pcmk_gid)
245  && ((st.st_mode & S_IRWXG) == (S_IRGRP|S_IWGRP))) {
246  return pcmk_rc_ok;
247  }
248  if (fchown(logfd, pcmk_uid, pcmk_gid) < 0) {
249  crm_warn("Couldn't change '%s' ownership to user %s gid %d: %s",
250  filename, CRM_DAEMON_USER, pcmk_gid, strerror(errno));
251  }
252  return pcmk_rc_ok;
253 }
254 
255 // Reset log file permissions (using environment variable if set)
256 static void
257 chmod_logfile(const char *filename, int logfd)
258 {
259  const char *modestr = pcmk__env_option(PCMK__ENV_LOGFILE_MODE);
260  mode_t filemode = S_IRUSR | S_IWUSR | S_IRGRP | S_IWGRP;
261 
262  if (modestr != NULL) {
263  long filemode_l = strtol(modestr, NULL, 8);
264 
265  if ((filemode_l != LONG_MIN) && (filemode_l != LONG_MAX)) {
266  filemode = (mode_t) filemode_l;
267  }
268  }
269  if ((filemode != 0) && (fchmod(logfd, filemode) < 0)) {
270  crm_warn("Couldn't change '%s' mode to %04o: %s",
271  filename, filemode, strerror(errno));
272  }
273 }
274 
275 // If we're root, correct a log file's permissions if needed
276 static int
277 set_logfile_permissions(const char *filename, FILE *logfile)
278 {
279  if (geteuid() == 0) {
280  int logfd = fileno(logfile);
281  int rc = chown_logfile(filename, logfd);
282 
283  if (rc != pcmk_rc_ok) {
284  return rc;
285  }
286  chmod_logfile(filename, logfd);
287  }
288  return pcmk_rc_ok;
289 }
290 
291 // Enable libqb logging to a new log file
292 static void
293 enable_logfile(int fd)
294 {
295  qb_log_ctl(fd, QB_LOG_CONF_ENABLED, QB_TRUE);
296 #if 0
297  qb_log_ctl(fd, QB_LOG_CONF_FILE_SYNC, 1); // Turn on synchronous writes
298 #endif
299 
300 #ifdef HAVE_qb_log_conf_QB_LOG_CONF_MAX_LINE_LEN
301  // Longer than default, for logging long XML lines
302  qb_log_ctl(fd, QB_LOG_CONF_MAX_LINE_LEN, 800);
303 #endif
304 
306 }
307 
308 static inline void
309 disable_logfile(int fd)
310 {
311  qb_log_ctl(fd, QB_LOG_CONF_ENABLED, QB_FALSE);
312 }
313 
314 static void
315 setenv_logfile(const char *filename)
316 {
317  // Some resource agents will log only if environment variable is set
318  if (pcmk__env_option(PCMK__ENV_LOGFILE) == NULL) {
319  pcmk__set_env_option(PCMK__ENV_LOGFILE, filename, true);
320  }
321 }
322 
330 int
331 pcmk__add_logfile(const char *filename)
332 {
333  /* No log messages from this function will be logged to the new log!
334  * If another target such as syslog has already been added, the messages
335  * should show up there.
336  */
337 
338  int fd = 0;
339  int rc = pcmk_rc_ok;
340  FILE *logfile = NULL;
341  bool is_default = false;
342 
343  static int default_fd = -1;
344  static bool have_logfile = false;
345 
346  // Use default if caller didn't specify (and we don't already have one)
347  if (filename == NULL) {
348  if (have_logfile) {
349  return pcmk_rc_ok;
350  }
351  filename = DEFAULT_LOG_FILE;
352  }
353 
354  // If the user doesn't want logging, we're done
355  if (logfile_disabled(filename)) {
356  return pcmk_rc_ok;
357  }
358 
359  // If the caller wants the default and we already have it, we're done
360  is_default = pcmk__str_eq(filename, DEFAULT_LOG_FILE, pcmk__str_none);
361  if (is_default && (default_fd >= 0)) {
362  return pcmk_rc_ok;
363  }
364 
365  // Check whether we have write access to the file
366  logfile = fopen(filename, "a");
367  if (logfile == NULL) {
368  rc = errno;
369  crm_warn("Logging to '%s' is disabled: %s " QB_XS " uid=%u gid=%u",
370  filename, strerror(rc), geteuid(), getegid());
371  return rc;
372  }
373 
374  rc = set_logfile_permissions(filename, logfile);
375  if (rc != pcmk_rc_ok) {
376  crm_warn("Logging to '%s' is disabled: %s " QB_XS " permissions",
377  filename, strerror(rc));
378  fclose(logfile);
379  return rc;
380  }
381 
382  // Close and reopen as libqb logging target
383  fclose(logfile);
384  fd = qb_log_file_open(filename);
385  if (fd < 0) {
386  crm_warn("Logging to '%s' is disabled: %s " QB_XS " qb_log_file_open",
387  filename, strerror(-fd));
388  return -fd; // == +errno
389  }
390 
391  if (is_default) {
392  default_fd = fd;
393  setenv_logfile(filename);
394 
395  } else if (default_fd >= 0) {
396  crm_notice("Switching logging to %s", filename);
397  disable_logfile(default_fd);
398  }
399 
400  crm_notice("Additional logging available in %s", filename);
401  enable_logfile(fd);
402  have_logfile = true;
403  return pcmk_rc_ok;
404 }
405 
414 void
415 pcmk__add_logfiles(gchar **log_files, pcmk__output_t *out)
416 {
417  if (log_files == NULL) {
418  return;
419  }
420 
421  for (gchar **fname = log_files; *fname != NULL; fname++) {
422  int rc = pcmk__add_logfile(*fname);
423 
424  if (rc != pcmk_rc_ok) {
425  out->err(out, "Logging to %s is disabled: %s",
426  *fname, pcmk_rc_str(rc));
427  }
428  }
429 }
430 
431 static int blackbox_trigger = 0;
432 static volatile char *blackbox_file_prefix = NULL;
433 
434 static void
435 blackbox_logger(int32_t t, struct qb_log_callsite *cs, log_time_t timestamp,
436  const char *msg)
437 {
438  if(cs && cs->priority < LOG_ERR) {
439  crm_write_blackbox(SIGTRAP, cs); /* Bypass the over-dumping logic */
440  } else {
441  crm_write_blackbox(0, cs);
442  }
443 }
444 
445 static void
446 crm_control_blackbox(int nsig, bool enable)
447 {
448  int lpc = 0;
449 
450  if (blackbox_file_prefix == NULL) {
451  pid_t pid = getpid();
452 
453  blackbox_file_prefix = crm_strdup_printf("%s/%s-%lu",
456  (unsigned long) pid);
457  }
458 
459  if (enable && qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_STATE_GET, 0) != QB_LOG_STATE_ENABLED) {
460  qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_SIZE, 5 * 1024 * 1024); /* Any size change drops existing entries */
461  qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_ENABLED, QB_TRUE); /* Setting the size seems to disable it */
462 
463  /* Enable synchronous logging */
464  for (lpc = QB_LOG_BLACKBOX; lpc < QB_LOG_TARGET_MAX; lpc++) {
465  qb_log_ctl(lpc, QB_LOG_CONF_FILE_SYNC, QB_TRUE);
466  }
467 
468  crm_notice("Initiated blackbox recorder: %s", blackbox_file_prefix);
469 
470  /* Save to disk on abnormal termination */
471  crm_signal_handler(SIGSEGV, crm_trigger_blackbox);
472  crm_signal_handler(SIGABRT, crm_trigger_blackbox);
473  crm_signal_handler(SIGILL, crm_trigger_blackbox);
474  crm_signal_handler(SIGBUS, crm_trigger_blackbox);
475  crm_signal_handler(SIGFPE, crm_trigger_blackbox);
476 
478 
479  blackbox_trigger = qb_log_custom_open(blackbox_logger, NULL, NULL, NULL);
480  qb_log_ctl(blackbox_trigger, QB_LOG_CONF_ENABLED, QB_TRUE);
481  crm_trace("Trigger: %d is %d %d", blackbox_trigger,
482  qb_log_ctl(blackbox_trigger, QB_LOG_CONF_STATE_GET, 0), QB_LOG_STATE_ENABLED);
483 
485 
486  } else if (!enable && qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_STATE_GET, 0) == QB_LOG_STATE_ENABLED) {
487  qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_ENABLED, QB_FALSE);
488 
489  /* Disable synchronous logging again when the blackbox is disabled */
490  for (lpc = QB_LOG_BLACKBOX; lpc < QB_LOG_TARGET_MAX; lpc++) {
491  qb_log_ctl(lpc, QB_LOG_CONF_FILE_SYNC, QB_FALSE);
492  }
493  }
494 }
495 
496 void
498 {
499  crm_control_blackbox(nsig, TRUE);
500 }
501 
502 void
504 {
505  crm_control_blackbox(nsig, FALSE);
506 }
507 
518 void
519 crm_write_blackbox(int nsig, const struct qb_log_callsite *cs)
520 {
521  static volatile int counter = 1;
522  static volatile time_t last = 0;
523 
524  char buffer[NAME_MAX];
525  time_t now = time(NULL);
526 
527  if (blackbox_file_prefix == NULL) {
528  return;
529  }
530 
531  switch (nsig) {
532  case 0:
533  case SIGTRAP:
534  /* The graceful case - such as assertion failure or user request */
535 
536  if (nsig == 0 && now == last) {
537  /* Prevent over-dumping */
538  return;
539  }
540 
541  snprintf(buffer, NAME_MAX, "%s.%d", blackbox_file_prefix, counter++);
542  if (nsig == SIGTRAP) {
543  crm_notice("Blackbox dump requested, please see %s for contents", buffer);
544 
545  } else if (cs) {
546  syslog(LOG_NOTICE,
547  "Problem detected at %s:%d (%s), please see %s for additional details",
548  cs->function, cs->lineno, cs->filename, buffer);
549  } else {
550  crm_notice("Problem detected, please see %s for additional details", buffer);
551  }
552 
553  last = now;
554  qb_log_blackbox_write_to_file(buffer);
555 
556  /* Flush the existing contents
557  * A size change would also work
558  */
559  qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_ENABLED, QB_FALSE);
560  qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_ENABLED, QB_TRUE);
561  break;
562 
563  default:
564  /* Do as little as possible, just try to get what we have out
565  * We logged the filename when the blackbox was enabled
566  */
567  crm_signal_handler(nsig, SIG_DFL);
568  qb_log_blackbox_write_to_file((const char *)blackbox_file_prefix);
569  qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_ENABLED, QB_FALSE);
570  raise(nsig);
571  break;
572  }
573 }
574 
575 static const char *
576 crm_quark_to_string(uint32_t tag)
577 {
578  const char *text = g_quark_to_string(tag);
579 
580  if (text) {
581  return text;
582  }
583  return "";
584 }
585 
586 static void
587 crm_log_filter_source(int source, const char *trace_files, const char *trace_fns,
588  const char *trace_fmts, const char *trace_tags, const char *trace_blackbox,
589  struct qb_log_callsite *cs)
590 {
591  if (qb_log_ctl(source, QB_LOG_CONF_STATE_GET, 0) != QB_LOG_STATE_ENABLED) {
592  return;
593  } else if (cs->tags != crm_trace_nonlog && source == QB_LOG_BLACKBOX) {
594  /* Blackbox gets everything if enabled */
595  qb_bit_set(cs->targets, source);
596 
597  } else if (source == blackbox_trigger && blackbox_trigger > 0) {
598  /* Should this log message result in the blackbox being dumped */
599  if (cs->priority <= LOG_ERR) {
600  qb_bit_set(cs->targets, source);
601 
602  } else if (trace_blackbox) {
603  char *key = crm_strdup_printf("%s:%d", cs->function, cs->lineno);
604 
605  if (strstr(trace_blackbox, key) != NULL) {
606  qb_bit_set(cs->targets, source);
607  }
608  free(key);
609  }
610 
611  } else if (source == QB_LOG_SYSLOG) { /* No tracing to syslog */
612  if (cs->priority <= crm_log_priority && cs->priority <= crm_log_level) {
613  qb_bit_set(cs->targets, source);
614  }
615  /* Log file tracing options... */
616  } else if (cs->priority <= crm_log_level) {
617  qb_bit_set(cs->targets, source);
618  } else if (trace_files && strstr(trace_files, cs->filename) != NULL) {
619  qb_bit_set(cs->targets, source);
620  } else if (trace_fns && strstr(trace_fns, cs->function) != NULL) {
621  qb_bit_set(cs->targets, source);
622  } else if (trace_fmts && strstr(trace_fmts, cs->format) != NULL) {
623  qb_bit_set(cs->targets, source);
624  } else if (trace_tags
625  && cs->tags != 0
626  && cs->tags != crm_trace_nonlog && g_quark_to_string(cs->tags) != NULL) {
627  qb_bit_set(cs->targets, source);
628  }
629 }
630 
631 #ifndef HAVE_STRCHRNUL
632 /* strchrnul() is a GNU extension. If not present, use our own definition.
633  * The GNU version returns char*, but we only need it to be const char*.
634  */
635 static const char *
636 strchrnul(const char *s, int c)
637 {
638  while ((*s != c) && (*s != '\0')) {
639  ++s;
640  }
641  return s;
642 }
643 #endif
644 
645 static void
646 crm_log_filter(struct qb_log_callsite *cs)
647 {
648  int lpc = 0;
649  static int need_init = 1;
650  static const char *trace_fns = NULL;
651  static const char *trace_tags = NULL;
652  static const char *trace_fmts = NULL;
653  static const char *trace_files = NULL;
654  static const char *trace_blackbox = NULL;
655 
656  if (need_init) {
657  need_init = 0;
662  trace_blackbox = pcmk__env_option(PCMK__ENV_TRACE_BLACKBOX);
663 
664  if (trace_tags != NULL) {
665  uint32_t tag;
666  char token[500];
667  const char *offset = NULL;
668  const char *next = trace_tags;
669 
670  do {
671  offset = next;
672  next = strchrnul(offset, ',');
673  snprintf(token, sizeof(token), "%.*s", (int)(next - offset), offset);
674 
675  tag = g_quark_from_string(token);
676  crm_info("Created GQuark %u from token '%s' in '%s'", tag, token, trace_tags);
677 
678  if (next[0] != 0) {
679  next++;
680  }
681 
682  } while (next != NULL && next[0] != 0);
683  }
684  }
685 
686  cs->targets = 0; /* Reset then find targets to enable */
687  for (lpc = QB_LOG_SYSLOG; lpc < QB_LOG_TARGET_MAX; lpc++) {
688  crm_log_filter_source(lpc, trace_files, trace_fns, trace_fmts, trace_tags, trace_blackbox,
689  cs);
690  }
691 }
692 
693 gboolean
694 crm_is_callsite_active(struct qb_log_callsite *cs, uint8_t level, uint32_t tags)
695 {
696  gboolean refilter = FALSE;
697 
698  if (cs == NULL) {
699  return FALSE;
700  }
701 
702  if (cs->priority != level) {
703  cs->priority = level;
704  refilter = TRUE;
705  }
706 
707  if (cs->tags != tags) {
708  cs->tags = tags;
709  refilter = TRUE;
710  }
711 
712  if (refilter) {
713  crm_log_filter(cs);
714  }
715 
716  if (cs->targets == 0) {
717  return FALSE;
718  }
719  return TRUE;
720 }
721 
722 void
724 {
725  static gboolean log = TRUE;
726 
727  if (log) {
728  log = FALSE;
729  crm_debug
730  ("Enabling callsites based on priority=%d, files=%s, functions=%s, formats=%s, tags=%s",
735  }
736  qb_log_filter_fn_set(crm_log_filter);
737 }
738 
739 static gboolean
740 crm_tracing_enabled(void)
741 {
742  return (crm_log_level == LOG_TRACE)
747 }
748 
749 static int
750 crm_priority2int(const char *name)
751 {
752  struct syslog_names {
753  const char *name;
754  int priority;
755  };
756  static struct syslog_names p_names[] = {
757  {"emerg", LOG_EMERG},
758  {"alert", LOG_ALERT},
759  {"crit", LOG_CRIT},
760  {"error", LOG_ERR},
761  {"warning", LOG_WARNING},
762  {"notice", LOG_NOTICE},
763  {"info", LOG_INFO},
764  {"debug", LOG_DEBUG},
765  {NULL, -1}
766  };
767  int lpc;
768 
769  for (lpc = 0; name != NULL && p_names[lpc].name != NULL; lpc++) {
770  if (pcmk__str_eq(p_names[lpc].name, name, pcmk__str_none)) {
771  return p_names[lpc].priority;
772  }
773  }
774  return crm_log_priority;
775 }
776 
777 
794 static void
795 set_identity(const char *entity, int argc, char *const *argv)
796 {
797  if (crm_system_name != NULL) {
798  return; // Already set, don't overwrite
799  }
800 
801  if (entity != NULL) {
803 
804  } else if ((argc > 0) && (argv != NULL)) {
805  char *mutable = strdup(argv[0]);
806  char *modified = basename(mutable);
807 
808  if (strstr(modified, "lt-") == modified) {
809  modified += 3;
810  }
811  crm_system_name = pcmk__str_copy(modified);
812  free(mutable);
813 
814  } else {
815  crm_system_name = pcmk__str_copy("Unknown");
816  }
817 
818  // Used by fencing.py.py (in fence-agents)
820 }
821 
822 void
823 crm_log_preinit(const char *entity, int argc, char *const *argv)
824 {
825  /* Configure libqb logging with nothing turned on */
826 
827  struct utsname res;
828  int lpc = 0;
829  int32_t qb_facility = 0;
830  pid_t pid = getpid();
831  const char *nodename = "localhost";
832  static bool have_logging = false;
833  GLogLevelFlags log_levels;
834 
835  if (have_logging) {
836  return;
837  }
838 
839  have_logging = true;
840 
841  pcmk__xml_init();
842 
843  if (crm_trace_nonlog == 0) {
844  crm_trace_nonlog = g_quark_from_static_string("Pacemaker non-logging tracepoint");
845  }
846 
847  umask(S_IWGRP | S_IWOTH | S_IROTH);
848 
849  /* Add a log handler for messages from our log domain at any log level. */
850  log_levels = G_LOG_LEVEL_MASK | G_LOG_FLAG_FATAL | G_LOG_FLAG_RECURSION;
851  pcmk__log_id = g_log_set_handler(G_LOG_DOMAIN, log_levels, crm_glib_handler, NULL);
852  /* Add a log handler for messages from the GLib domains at any log level. */
853  pcmk__glib_log_id = g_log_set_handler("GLib", log_levels, crm_glib_handler, NULL);
854  pcmk__gio_log_id = g_log_set_handler("GLib-GIO", log_levels, crm_glib_handler, NULL);
855  pcmk__gmodule_log_id = g_log_set_handler("GModule", log_levels, crm_glib_handler, NULL);
856  pcmk__gthread_log_id = g_log_set_handler("GThread", log_levels, crm_glib_handler, NULL);
857 
858  /* glib should not abort for any messages from the Pacemaker domain, but
859  * other domains are still free to specify their own behavior. However,
860  * note that G_LOG_LEVEL_ERROR is always fatal regardless of what we do
861  * here.
862  */
863  g_log_set_fatal_mask(G_LOG_DOMAIN, 0);
864 
865  /* Set crm_system_name, which is used as the logging name. It may also
866  * be used for other purposes such as an IPC client name.
867  */
868  set_identity(entity, argc, argv);
869 
870  qb_facility = qb_log_facility2int("local0");
871  qb_log_init(crm_system_name, qb_facility, LOG_ERR);
872  crm_log_level = LOG_CRIT;
873 
874  /* Nuke any syslog activity until it's asked for */
875  qb_log_ctl(QB_LOG_SYSLOG, QB_LOG_CONF_ENABLED, QB_FALSE);
876 #ifdef HAVE_qb_log_conf_QB_LOG_CONF_MAX_LINE_LEN
877  // Shorter than default, generous for what we *should* send to syslog
878  qb_log_ctl(QB_LOG_SYSLOG, QB_LOG_CONF_MAX_LINE_LEN, 256);
879 #endif
880  if (uname(memset(&res, 0, sizeof(res))) == 0 && *res.nodename != '\0') {
881  nodename = res.nodename;
882  }
883 
884  /* Set format strings and disable threading
885  * Pacemaker and threads do not mix well (due to the amount of forking)
886  */
887  qb_log_tags_stringify_fn_set(crm_quark_to_string);
888  for (lpc = QB_LOG_SYSLOG; lpc < QB_LOG_TARGET_MAX; lpc++) {
889  qb_log_ctl(lpc, QB_LOG_CONF_THREADED, QB_FALSE);
890 #ifdef HAVE_qb_log_conf_QB_LOG_CONF_ELLIPSIS
891  // End truncated lines with '...'
892  qb_log_ctl(lpc, QB_LOG_CONF_ELLIPSIS, QB_TRUE);
893 #endif
894  set_format_string(lpc, crm_system_name, pid, nodename);
895  }
896 
897 #ifdef ENABLE_NLS
898  /* Enable translations (experimental). Currently we only have a few
899  * proof-of-concept translations for some option help. The goal would be to
900  * offer translations for option help and man pages rather than logs or
901  * documentation, to reduce the burden of maintaining them.
902  */
903 
904  // Load locale information for the local host from the environment
905  setlocale(LC_ALL, "");
906 
907  // Tell gettext where to find Pacemaker message catalogs
909 
910  // Tell gettext to use the Pacemaker message catalogs
911  pcmk__assert(textdomain(PACKAGE) != NULL);
912 
913  // Tell gettext that the translated strings are stored in UTF-8
915 #endif
916 }
917 
918 gboolean
919 crm_log_init(const char *entity, uint8_t level, gboolean daemon, gboolean to_stderr,
920  int argc, char **argv, gboolean quiet)
921 {
922  const char *syslog_priority = NULL;
923  const char *facility = pcmk__env_option(PCMK__ENV_LOGFACILITY);
924  const char *f_copy = facility;
925 
926  pcmk__is_daemon = daemon;
927  crm_log_preinit(entity, argc, argv);
928 
929  if (level > LOG_TRACE) {
930  level = LOG_TRACE;
931  }
932  if(level > crm_log_level) {
933  crm_log_level = level;
934  }
935 
936  /* Should we log to syslog */
937  if (facility == NULL) {
938  if (pcmk__is_daemon) {
939  facility = "daemon";
940  } else {
941  facility = PCMK_VALUE_NONE;
942  }
944  }
945 
946  if (pcmk__str_eq(facility, PCMK_VALUE_NONE, pcmk__str_casei)) {
947  quiet = TRUE;
948 
949 
950  } else {
951  qb_log_ctl(QB_LOG_SYSLOG, QB_LOG_CONF_FACILITY, qb_log_facility2int(facility));
952  }
953 
955  /* Override the default setting */
956  crm_log_level = LOG_DEBUG;
957  }
958 
959  /* What lower threshold do we have for sending to syslog */
960  syslog_priority = pcmk__env_option(PCMK__ENV_LOGPRIORITY);
961  if (syslog_priority) {
962  crm_log_priority = crm_priority2int(syslog_priority);
963  }
964  qb_log_filter_ctl(QB_LOG_SYSLOG, QB_LOG_FILTER_ADD, QB_LOG_FILTER_FILE, "*",
965  crm_log_priority);
966 
967  // Log to syslog unless requested to be quiet
968  if (!quiet) {
969  qb_log_ctl(QB_LOG_SYSLOG, QB_LOG_CONF_ENABLED, QB_TRUE);
970  }
971 
972  /* Should we log to stderr */
974  /* Override the default setting */
975  to_stderr = TRUE;
976  }
977  crm_enable_stderr(to_stderr);
978 
979  // Log to a file if we're a daemon or user asked for one
980  {
981  const char *logfile = pcmk__env_option(PCMK__ENV_LOGFILE);
982 
983  if (!pcmk__str_eq(PCMK_VALUE_NONE, logfile, pcmk__str_casei)
984  && (pcmk__is_daemon || (logfile != NULL))) {
985  // Daemons always get a log file, unless explicitly set to "none"
986  pcmk__add_logfile(logfile);
987  }
988  }
989 
990  if (pcmk__is_daemon
993  }
994 
995  /* Summary */
996  crm_trace("Quiet: %d, facility %s", quiet, f_copy);
999 
1001 
1002  /* Ok, now we can start logging... */
1003 
1004  // Disable daemon request if user isn't root or Pacemaker daemon user
1005  if (pcmk__is_daemon) {
1006  const char *user = getenv("USER");
1007 
1008  if (user != NULL && !pcmk__strcase_any_of(user, "root", CRM_DAEMON_USER, NULL)) {
1009  crm_trace("Not switching to corefile directory for %s", user);
1010  pcmk__is_daemon = false;
1011  }
1012  }
1013 
1014  if (pcmk__is_daemon) {
1015  int user = getuid();
1016  struct passwd *pwent = getpwuid(user);
1017 
1018  if (pwent == NULL) {
1019  crm_perror(LOG_ERR, "Cannot get name for uid: %d", user);
1020 
1021  } else if (!pcmk__strcase_any_of(pwent->pw_name, "root", CRM_DAEMON_USER, NULL)) {
1022  crm_trace("Don't change active directory for regular user: %s", pwent->pw_name);
1023 
1024  } else if (chdir(CRM_CORE_DIR) < 0) {
1025  crm_perror(LOG_INFO, "Cannot change active directory to " CRM_CORE_DIR);
1026 
1027  } else {
1028  crm_info("Changed active directory to " CRM_CORE_DIR);
1029  }
1030 
1031  /* Original meanings from signal(7)
1032  *
1033  * Signal Value Action Comment
1034  * SIGTRAP 5 Core Trace/breakpoint trap
1035  * SIGUSR1 30,10,16 Term User-defined signal 1
1036  * SIGUSR2 31,12,17 Term User-defined signal 2
1037  *
1038  * Our usage is as similar as possible
1039  */
1042  mainloop_add_signal(SIGTRAP, crm_trigger_blackbox);
1043 
1044  } else if (!quiet) {
1045  crm_log_args(argc, argv);
1046  }
1047 
1048  return TRUE;
1049 }
1050 
1051 /* returns the old value */
1052 unsigned int
1053 set_crm_log_level(unsigned int level)
1054 {
1055  unsigned int old = crm_log_level;
1056 
1057  if (level > LOG_TRACE) {
1058  level = LOG_TRACE;
1059  }
1060  crm_log_level = level;
1062  crm_trace("New log level: %d", level);
1063  return old;
1064 }
1065 
1066 void
1068 {
1069  if (enable && qb_log_ctl(QB_LOG_STDERR, QB_LOG_CONF_STATE_GET, 0) != QB_LOG_STATE_ENABLED) {
1070  qb_log_ctl(QB_LOG_STDERR, QB_LOG_CONF_ENABLED, QB_TRUE);
1072 
1073  } else if (enable == FALSE) {
1074  qb_log_ctl(QB_LOG_STDERR, QB_LOG_CONF_ENABLED, QB_FALSE);
1075  }
1076 }
1077 
1087 void
1088 crm_bump_log_level(int argc, char **argv)
1089 {
1090  if (qb_log_ctl(QB_LOG_STDERR, QB_LOG_CONF_STATE_GET, 0)
1091  != QB_LOG_STATE_ENABLED) {
1092  crm_enable_stderr(TRUE);
1093  } else {
1095  }
1096 }
1097 
1098 unsigned int
1100 {
1101  return crm_log_level;
1102 }
1103 
1113 void
1114 crm_log_args(int argc, char **argv)
1115 {
1116  static bool logged = false;
1117  gchar *arg_string = NULL;
1118 
1119  if ((argc == 0) || (argv == NULL) || logged) {
1120  return;
1121  }
1122  logged = true;
1123  arg_string = g_strjoinv(" ", argv);
1124  crm_notice("Invoked: %s", arg_string);
1125  g_free(arg_string);
1126 }
1127 
1128 void
1129 crm_log_output_fn(const char *file, const char *function, int line, int level, const char *prefix,
1130  const char *output)
1131 {
1132  const char *next = NULL;
1133  const char *offset = NULL;
1134 
1135  if (level == LOG_NEVER) {
1136  return;
1137  }
1138 
1139  if (output == NULL) {
1140  if (level != LOG_STDOUT) {
1141  level = LOG_TRACE;
1142  }
1143  output = "-- empty --";
1144  }
1145 
1146  next = output;
1147  do {
1148  offset = next;
1149  next = strchrnul(offset, '\n');
1150  do_crm_log_alias(level, file, function, line, "%s [ %.*s ]", prefix,
1151  (int)(next - offset), offset);
1152  if (next[0] != 0) {
1153  next++;
1154  }
1155 
1156  } while (next != NULL && next[0] != 0);
1157 }
1158 
1159 void
1160 pcmk__cli_init_logging(const char *name, unsigned int verbosity)
1161 {
1162  crm_log_init(name, LOG_ERR, FALSE, FALSE, 0, NULL, TRUE);
1163 
1164  for (int i = 0; i < verbosity; i++) {
1165  /* These arguments are ignored, so pass placeholders. */
1166  crm_bump_log_level(0, NULL);
1167  }
1168 }
1169 
1185 void
1186 pcmk_log_xml_as(const char *file, const char *function, uint32_t line,
1187  uint32_t tags, uint8_t level, const char *text, const xmlNode *xml)
1188 {
1189  if (xml == NULL) {
1190  do_crm_log(level, "%s%sNo data to dump as XML",
1191  pcmk__s(text, ""), pcmk__str_empty(text)? "" : " ");
1192 
1193  } else {
1194  if (logger_out == NULL) {
1195  CRM_CHECK(pcmk__log_output_new(&logger_out) == pcmk_rc_ok, return);
1196  }
1197 
1198  pcmk__output_set_log_level(logger_out, level);
1199  pcmk__output_set_log_filter(logger_out, file, function, line, tags);
1200  pcmk__xml_show(logger_out, text, xml, 1,
1205  pcmk__output_set_log_filter(logger_out, NULL, NULL, 0U, 0U);
1206  }
1207 }
1208 
1222 void
1223 pcmk__log_xml_changes_as(const char *file, const char *function, uint32_t line,
1224  uint32_t tags, uint8_t level, const xmlNode *xml)
1225 {
1226  if (xml == NULL) {
1227  do_crm_log(level, "No XML to dump");
1228  return;
1229  }
1230 
1231  if (logger_out == NULL) {
1232  CRM_CHECK(pcmk__log_output_new(&logger_out) == pcmk_rc_ok, return);
1233  }
1234  pcmk__output_set_log_level(logger_out, level);
1235  pcmk__output_set_log_filter(logger_out, file, function, line, tags);
1236  pcmk__xml_show_changes(logger_out, xml);
1237  pcmk__output_set_log_filter(logger_out, NULL, NULL, 0U, 0U);
1238 }
1239 
1253 void
1254 pcmk__log_xml_patchset_as(const char *file, const char *function, uint32_t line,
1255  uint32_t tags, uint8_t level, const xmlNode *patchset)
1256 {
1257  if (patchset == NULL) {
1258  do_crm_log(level, "No patchset to dump");
1259  return;
1260  }
1261 
1262  if (logger_out == NULL) {
1263  CRM_CHECK(pcmk__log_output_new(&logger_out) == pcmk_rc_ok, return);
1264  }
1265  pcmk__output_set_log_level(logger_out, level);
1266  pcmk__output_set_log_filter(logger_out, file, function, line, tags);
1267  logger_out->message(logger_out, "xml-patchset", patchset);
1268  pcmk__output_set_log_filter(logger_out, NULL, NULL, 0U, 0U);
1269 }
1270 
1275 void
1277 {
1278  if (logger_out != NULL) {
1279  logger_out->finish(logger_out, CRM_EX_OK, true, NULL);
1280  pcmk__output_free(logger_out);
1281  logger_out = NULL;
1282  }
1283 }
1284 
1285 void pcmk__set_config_error_handler(pcmk__config_error_func error_handler, void *error_context)
1286 {
1287  pcmk__config_error_handler = error_handler;
1288  pcmk__config_error_context = error_context;
1289 }
1290 
1291 void pcmk__set_config_warning_handler(pcmk__config_warning_func warning_handler, void *warning_context)
1292 {
1293  pcmk__config_warning_handler = warning_handler;
1294  pcmk__config_warning_context = warning_context;
1295 }
#define CRM_CORE_DIR
Definition: config.h:18
#define LOG_TRACE
Definition: logging.h:38
#define CRM_CHECK(expr, failure_action)
Definition: logging.h:213
void pcmk__set_config_error_handler(pcmk__config_error_func error_handler, void *error_context)
Definition: logging.c:1285
void pcmk__cli_init_logging(const char *name, unsigned int verbosity)
Definition: logging.c:1160
A dumping ground.
pcmk__config_warning_func pcmk__config_warning_handler
Definition: logging.c:58
#define crm_notice(fmt, args...)
Definition: logging.h:365
#define PCMK__ENV_LOGFILE
#define PCMK__ENV_TRACE_TAGS
gboolean mainloop_add_signal(int sig, void(*dispatch)(int sig))
Definition: mainloop.c:353
void crm_enable_blackbox(int nsig)
Definition: logging.c:497
#define PCMK__ENV_TRACE_FUNCTIONS
unsigned int get_crm_log_level(void)
Definition: logging.c:1099
void crm_disable_blackbox(int nsig)
Definition: logging.c:503
const char * name
Definition: cib.c:26
void(*) typedef void(* pcmk__config_warning_func)(void *ctx, const char *msg,...) G_GNUC_PRINTF(2
bool pcmk__strcase_any_of(const char *s,...) G_GNUC_NULL_TERMINATED
Definition: strings.c:1027
int(* message)(pcmk__output_t *out, const char *message_id,...)
#define PCMK__ENV_TRACE_FORMATS
void * pcmk__config_error_context
Definition: logging.c:59
void crm_abort(const char *file, const char *function, int line, const char *condition, gboolean do_core, gboolean do_fork)
Definition: results.c:215
void pcmk__xml_init(void)
Definition: xml.c:1430
int pcmk__add_logfile(const char *filename)
Add a file to be used as a Pacemaker detail log.
Definition: logging.c:331
Include the opening tag of an XML element, and include XML comments.
Definition: xml_internal.h:152
char * crm_system_name
Definition: utils.c:44
gboolean crm_is_callsite_active(struct qb_log_callsite *cs, uint8_t level, uint32_t tags)
Definition: logging.c:694
#define CRM_LOG_ASSERT(expr)
Definition: logging.h:196
#define bindtextdomain(Domainname, Dirname)
Definition: gettext.h:87
#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:268
void pcmk__output_set_log_filter(pcmk__output_t *out, const char *file, const char *function, uint32_t line, uint32_t tags)
Definition: output_log.c:419
#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:139
const char * pcmk_rc_str(int rc)
Get a user-friendly description of a return code.
Definition: results.c:609
void pcmk__output_set_log_level(pcmk__output_t *out, uint8_t log_level)
Definition: output_log.c:390
void * pcmk__config_warning_context
Definition: logging.c:60
#define PCMK__ENV_SERVICE
#define LOG_NEVER
Definition: logging.h:48
const char * pcmk__env_option(const char *option)
Definition: options.c:1075
Wrappers for and extensions to glib mainloop.
Include indentation and newlines.
Definition: xml_internal.h:149
#define FMT_MAX
Definition: logging.c:152
void pcmk__log_xml_patchset_as(const char *file, const char *function, uint32_t line, uint32_t tags, uint8_t level, const xmlNode *patchset)
Definition: logging.c:1254
pcmk__config_error_func pcmk__config_error_handler
Definition: logging.c:57
void crm_log_preinit(const char *entity, int argc, char *const *argv)
Initializes the logging system and defaults to the least verbose output level.
Definition: logging.c:823
void pcmk__free_common_logger(void)
Definition: logging.c:1276
void crm_log_args(int argc, char **argv)
Log the command line (once)
Definition: logging.c:1114
void pcmk__set_env_option(const char *option, const char *value, bool compat)
Set or unset a Pacemaker environment variable option.
Definition: options.c:1125
#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:362
gboolean crm_log_init(const char *entity, uint8_t level, gboolean daemon, gboolean to_stderr, int argc, char **argv, gboolean quiet)
Definition: logging.c:919
void pcmk__log_xml_changes_as(const char *file, const char *function, uint32_t line, uint32_t tags, uint8_t level, const xmlNode *xml)
Definition: logging.c:1223
stonith_t * st
Definition: pcmk_fence.c:30
uint32_t pid
Definition: cpg.c:49
#define crm_debug(fmt, args...)
Definition: logging.h:370
Include the children of an XML element.
Definition: xml_internal.h:155
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:1067
#define DEFAULT_LOG_FILE
Definition: logging.c:204
#define PCMK_VALUE_NONE
Definition: options.h:179
#define crm_trace(fmt, args...)
Definition: logging.h:372
#define do_crm_log(level, fmt, args...)
Log a message.
Definition: logging.h:149
#define CRM_BLACKBOX_DIR
Definition: config.h:8
int(*) int(*) void(* err)(pcmk__output_t *out, const char *format,...) G_GNUC_PRINTF(2
unsigned int crm_trace_nonlog
Definition: logging.c:46
sighandler_t crm_signal_handler(int sig, sighandler_t dispatch)
Definition: mainloop.c:304
#define TIMESTAMP_FORMAT_SPEC
Definition: logging.c:41
void(* finish)(pcmk__output_t *out, crm_exit_t exit_status, bool print, void **copy_dest)
void crm_update_callsites(void)
Definition: logging.c:723
#define PCMK__ENV_LOGPRIORITY
#define CRM_DAEMON_USER
Definition: config.h:27
Success.
Definition: results.h:231
int pcmk_legacy2rc(int legacy_rc)
Definition: results.c:667
void crm_write_blackbox(int nsig, const struct qb_log_callsite *cs)
Definition: logging.c:519
#define PCMK__ENV_LOGFILE_MODE
#define pcmk__str_copy(str)
void(* pcmk__config_error_func)(void *ctx, const char *msg,...) G_GNUC_PRINTF(2
void pcmk__output_free(pcmk__output_t *out)
Definition: output.c:30
#define pcmk__assert(expr)
void crm_log_output_fn(const char *file, const char *function, int line, int level, const char *prefix, const char *output)
Definition: logging.c:1129
#define PCMK__ENV_TRACE_BLACKBOX
void pcmk_log_xml_as(const char *file, const char *function, uint32_t line, uint32_t tags, uint8_t level, const char *text, const xmlNode *xml)
Log XML line-by-line in a formatted fashion.
Definition: logging.c:1186
#define PCMK__ENV_TRACE_FILES
#define PCMK__ENV_DEBUG
#define crm_perror(level, fmt, args...)
Send a system error message to both the log and stderr.
Definition: logging.h:299
int pcmk__xml_show(pcmk__output_t *out, const char *prefix, const xmlNode *data, int depth, uint32_t options)
Definition: xml_display.c:221
void pcmk__set_config_warning_handler(pcmk__config_warning_func warning_handler, void *warning_context)
Definition: logging.c:1291
Include the closing tag of an XML element.
Definition: xml_internal.h:158
#define NAME_MAX
Definition: logging.c:112
int pcmk__xml_show_changes(pcmk__output_t *out, const xmlNode *xml)
Definition: xml_display.c:362
#define PCMK__ENV_STDERR
This structure contains everything that makes up a single output formatter.
char uname[MAX_NAME]
Definition: cpg.c:53
#define pcmk_ok
Definition: results.h:65
unsigned int set_crm_log_level(unsigned int level)
Definition: logging.c:1053
#define PCMK__LOCALE_DIR
Definition: config.h:502
#define PACKAGE
Definition: config.h:442
void pcmk__add_logfiles(gchar **log_files, pcmk__output_t *out)
Add multiple additional log files.
Definition: logging.c:415
#define LOG_STDOUT
Definition: logging.h:43
void crm_bump_log_level(int argc, char **argv)
Make logging more verbose.
Definition: logging.c:1088
#define G_LOG_DOMAIN
Definition: crm_internal.h:27
#define crm_info(fmt, args...)
Definition: logging.h:367
void crm_log_deinit(void)
Definition: logging.c:134
uint64_t flags
Definition: remote.c:211
int pcmk__log_output_new(pcmk__output_t **out)
Definition: output.c:291
bool pcmk__env_option_enabled(const char *daemon, const char *option)
Definition: options.c:1182
char * crm_strdup_printf(char const *format,...) G_GNUC_PRINTF(1
#define PCMK__ENV_LOGFACILITY