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