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