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