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