diff --git a/cib/io.c b/cib/io.c index a2b4e862fa..26f0aea6e1 100644 --- a/cib/io.c +++ b/cib/io.c @@ -1,756 +1,753 @@ /* * Copyright (C) 2004 Andrew Beekhof * * This program is free software; you can redistribute it and/or * modify it under the terms of the GNU General Public * License as published by the Free Software Foundation; either * version 2 of the License, or (at your option) any later version. * * This software is distributed in the hope that it will be useful, * but WITHOUT ANY WARRANTY; without even the implied warranty of * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU * General Public License for more details. * * You should have received a copy of the GNU General Public * License along with this library; if not, write to the Free Software * Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA */ #include #include #include #include #include #include #include #include #include #include #include #include #include #include #include #include #include #include #include #include #define CIB_SERIES "cib" extern const char *cib_root; static int cib_wrap = 100; #define CIB_WRITE_PARANOIA 0 const char *local_resource_path[] = { XML_CIB_TAG_STATUS, }; const char *resource_path[] = { XML_CIB_TAG_RESOURCES, }; const char *node_path[] = { XML_CIB_TAG_NODES, }; const char *constraint_path[] = { XML_CIB_TAG_CONSTRAINTS, }; crm_trigger_t *cib_writer = NULL; gboolean initialized = FALSE; xmlNode *node_search = NULL; xmlNode *resource_search = NULL; xmlNode *constraint_search = NULL; xmlNode *status_search = NULL; extern int cib_status; int set_connected_peers(xmlNode * xml_obj); void GHFunc_count_peers(gpointer key, gpointer value, gpointer user_data); int write_cib_contents(gpointer p); extern void cib_cleanup(void); static gboolean validate_cib_digest(xmlNode * local_cib, const char *sigfile) { char *digest = NULL; char *expected = NULL; gboolean passed = FALSE; FILE *expected_strm = NULL; int start = 0, length = 0, read_len = 0; CRM_ASSERT(sigfile != NULL); expected_strm = fopen(sigfile, "r"); if (expected_strm == NULL && errno == ENOENT) { crm_warn("No on-disk digest present"); return TRUE; } else if (expected_strm == NULL) { crm_perror(LOG_ERR, "Could not open signature file %s for reading", sigfile); goto bail; } if (local_cib != NULL) { digest = calculate_on_disk_digest(local_cib); } start = ftell(expected_strm); fseek(expected_strm, 0L, SEEK_END); length = ftell(expected_strm); fseek(expected_strm, 0L, start); CRM_ASSERT(length >= 0); CRM_ASSERT(start == ftell(expected_strm)); if (length > 0) { crm_trace("Reading %d bytes from file", length); expected = calloc(1, (length + 1)); read_len = fread(expected, 1, length, expected_strm); /* Coverity: False positive */ CRM_ASSERT(read_len == length); } fclose(expected_strm); bail: if (expected == NULL) { crm_err("On-disk digest is empty"); } else if (safe_str_eq(expected, digest)) { crm_trace("Digest comparision passed: %s", digest); passed = TRUE; } else { crm_err("Digest comparision failed: expected %s (%s), calculated %s", expected, sigfile, digest); } free(digest); free(expected); return passed; } static int write_cib_digest(xmlNode * local_cib, const char *digest_file, int fd, char *digest) { int rc = 0; char *local_digest = NULL; FILE *digest_strm = fdopen(fd, "w"); if (digest_strm == NULL) { crm_perror(LOG_ERR, "Cannot open signature file %s for writing", digest_file); return -1; } if (digest == NULL) { local_digest = calculate_on_disk_digest(local_cib); CRM_ASSERT(digest != NULL); digest = local_digest; } rc = fprintf(digest_strm, "%s", digest); if (rc < 0) { crm_perror(LOG_ERR, "Cannot write to signature file %s", digest_file); } CRM_ASSERT(digest_strm != NULL); if (fflush(digest_strm) != 0) { crm_perror(LOG_ERR, "Couldnt flush the contents of %s", digest_file); rc = -1; } if (fsync(fileno(digest_strm)) < 0) { crm_perror(LOG_ERR, "Couldnt sync the contents of %s", digest_file); rc = -1; } fclose(digest_strm); free(local_digest); return rc; } static gboolean validate_on_disk_cib(const char *filename, xmlNode ** on_disk_cib) { int s_res = -1; struct stat buf; gboolean passed = TRUE; xmlNode *root = NULL; CRM_ASSERT(filename != NULL); s_res = stat(filename, &buf); if (s_res == 0) { char *sigfile = NULL; size_t fnsize; crm_trace("Reading cluster configuration from: %s", filename); root = filename2xml(filename); fnsize = strlen(filename) + 5; sigfile = calloc(1, fnsize); snprintf(sigfile, fnsize, "%s.sig", filename); if (validate_cib_digest(root, sigfile) == FALSE) { passed = FALSE; } free(sigfile); } if (on_disk_cib != NULL) { *on_disk_cib = root; } else { free_xml(root); } return passed; } static int cib_rename(const char *old, const char *new) { int rc = 0; int automatic_fd = 0; char *automatic = NULL; if (new == NULL) { umask(S_IWGRP | S_IWOTH | S_IROTH); automatic = g_strdup_printf("%s/cib.auto.XXXXXX", cib_root); automatic_fd = mkstemp(automatic); new = automatic; crm_err("Archiving corrupt or unusable file %s as %s", old, automatic); } rc = rename(old, new); if (rc < 0) { crm_perror(LOG_ERR, "Couldn't rename %s as %s - Disabling disk writes and continuing", old, new); cib_writes_enabled = FALSE; } if (automatic_fd > 0) { close(automatic_fd); } free(automatic); return rc; } /* * It is the callers responsibility to free the output of this function */ static xmlNode * retrieveCib(const char *filename, const char *sigfile, gboolean archive_invalid) { struct stat buf; xmlNode *root = NULL; crm_info("Reading cluster configuration from: %s (digest: %s)", filename, sigfile); if (stat(filename, &buf) != 0) { crm_warn("Cluster configuration not found: %s", filename); return NULL; } root = filename2xml(filename); if (root == NULL) { crm_err("%s exists but does NOT contain valid XML. ", filename); crm_warn("Continuing but %s will NOT used.", filename); } else if (validate_cib_digest(root, sigfile) == FALSE) { crm_err("Checksum of %s failed! Configuration contents ignored!", filename); crm_err("Usually this is caused by manual changes, " "please refer to http://clusterlabs.org/wiki/FAQ#cib_changes_detected"); crm_warn("Continuing but %s will NOT used.", filename); free_xml(root); root = NULL; if (archive_invalid) { /* Archive the original files so the contents are not lost */ cib_rename(filename, NULL); cib_rename(sigfile, NULL); } } return root; } xmlNode * readCibXmlFile(const char *dir, const char *file, gboolean discard_status) { int seq = 0; char *backup_file = NULL; char *filename = NULL, *sigfile = NULL; const char *name = NULL; const char *value = NULL; const char *validation = NULL; const char *use_valgrind = getenv("HA_VALGRIND_ENABLED"); xmlNode *root = NULL; xmlNode *status = NULL; if (!crm_is_writable(dir, file, CRM_DAEMON_USER, NULL, FALSE)) { cib_status = -EACCES; return NULL; } filename = crm_concat(dir, file, '/'); sigfile = crm_concat(filename, "sig", '.'); cib_status = pcmk_ok; root = retrieveCib(filename, sigfile, TRUE); if (root == NULL) { crm_warn("Primary configuration corrupt or unusable, trying backup..."); seq = get_last_sequence(cib_root, CIB_SERIES); } while (root == NULL) { struct stat buf; free(sigfile); if (seq == 0) { seq += cib_wrap; /* unwrap */ } backup_file = generate_series_filename(cib_root, CIB_SERIES, seq - 1, FALSE); sigfile = crm_concat(filename, "sig", '.'); if (stat(backup_file, &buf) != 0) { crm_debug("Backup file %s not found", backup_file); break; } crm_warn("Attempting to load: %s", backup_file); root = retrieveCib(backup_file, sigfile, FALSE); seq--; } free(backup_file); if (root == NULL) { root = createEmptyCib(); crm_xml_add(root, XML_ATTR_GENERATION, "0"); crm_xml_add(root, XML_ATTR_NUMUPDATES, "0"); crm_xml_add(root, XML_ATTR_GENERATION_ADMIN, "0"); crm_xml_add(root, XML_ATTR_VALIDATION, LATEST_SCHEMA_VERSION); crm_warn("Continuing with an empty configuration."); } if (cib_writes_enabled && use_valgrind) { if (crm_is_true(use_valgrind) || strstr(use_valgrind, "cib")) { cib_writes_enabled = FALSE; crm_err("*********************************************************"); crm_err("*** Disabling disk writes to avoid confusing Valgrind ***"); crm_err("*********************************************************"); } } status = find_xml_node(root, XML_CIB_TAG_STATUS, FALSE); if (discard_status && status != NULL) { /* strip out the status section if there is one */ free_xml(status); status = NULL; } if (status == NULL) { create_xml_node(root, XML_CIB_TAG_STATUS); } /* Do this before DTD validation happens */ /* fill in some defaults */ name = XML_ATTR_GENERATION_ADMIN; value = crm_element_value(root, name); if (value == NULL) { crm_warn("No value for %s was specified in the configuration.", name); crm_warn("The reccomended course of action is to shutdown," " run crm_verify and fix any errors it reports."); crm_warn("We will default to zero and continue but may get" " confused about which configuration to use if" " multiple nodes are powered up at the same time."); crm_xml_add_int(root, name, 0); } name = XML_ATTR_GENERATION; value = crm_element_value(root, name); if (value == NULL) { crm_xml_add_int(root, name, 0); } name = XML_ATTR_NUMUPDATES; value = crm_element_value(root, name); if (value == NULL) { crm_xml_add_int(root, name, 0); } /* unset these and require the DC/CCM to update as needed */ xml_remove_prop(root, XML_ATTR_DC_UUID); if (discard_status) { crm_log_xml_trace(root, "[on-disk]"); } validation = crm_element_value(root, XML_ATTR_VALIDATION); if (validate_xml(root, NULL, TRUE) == FALSE) { crm_err("CIB does not validate with %s", crm_str(validation)); cib_status = -pcmk_err_dtd_validation; } else if (validation == NULL) { int version = 0; update_validation(&root, &version, FALSE, FALSE); if (version > 0) { crm_notice("Enabling %s validation on" " the existing (sane) configuration", get_schema_name(version)); } else { crm_err("CIB does not validate with any known DTD or schema"); cib_status = -pcmk_err_dtd_validation; } } free(filename); free(sigfile); return root; } /* * The caller should never free the return value */ xmlNode * get_the_CIB(void) { return the_cib; } gboolean uninitializeCib(void) { xmlNode *tmp_cib = the_cib; if (tmp_cib == NULL) { crm_debug("The CIB has already been deallocated."); return FALSE; } initialized = FALSE; the_cib = NULL; node_search = NULL; resource_search = NULL; constraint_search = NULL; status_search = NULL; crm_debug("Deallocating the CIB."); free_xml(tmp_cib); crm_debug("The CIB has been deallocated."); return TRUE; } /* * This method will not free the old CIB pointer or the new one. * We rely on the caller to have saved a pointer to the old CIB * and to free the old/bad one depending on what is appropriate. */ gboolean initializeCib(xmlNode * new_cib) { if (new_cib == NULL) { return FALSE; } the_cib = new_cib; initialized = TRUE; return TRUE; } static void sync_directory(const char *name) { int fd = 0; DIR *directory = NULL; directory = opendir(name); if (directory == NULL) { crm_perror(LOG_ERR, "Could not open %s for syncing", name); return; } fd = dirfd(directory); if (fd < 0) { crm_perror(LOG_ERR, "Could not obtain file descriptor for %s", name); } else if (fsync(fd) < 0) { crm_perror(LOG_ERR, "Could not sync %s", name); } if (closedir(directory) < 0) { crm_perror(LOG_ERR, "Could not close %s after fsync", name); } } /* * This method will free the old CIB pointer on success and the new one * on failure. */ int activateCibXml(xmlNode * new_cib, gboolean to_disk, const char *op) { xmlNode *saved_cib = the_cib; CRM_ASSERT(new_cib != saved_cib); if (initializeCib(new_cib) == FALSE) { free_xml(new_cib); crm_err("Ignoring invalid or NULL CIB"); if (saved_cib != NULL) { crm_warn("Reverting to last known CIB"); if (initializeCib(saved_cib) == FALSE) { /* oh we are so dead */ crm_crit("Couldn't re-initialize the old CIB!"); exit(1); } } else { crm_crit("Could not write out new CIB and no saved" " version to revert to"); } return -ENODATA; } free_xml(saved_cib); if (cib_writes_enabled && cib_status == pcmk_ok && to_disk) { crm_debug("Triggering CIB write for %s op", op); mainloop_set_trigger(cib_writer); } return pcmk_ok; } static void cib_diskwrite_complete(mainloop_child_t * p, pid_t pid, int core, int signo, int exitcode) { if (signo) { crm_notice("Disk write process terminated with signal %d (pid=%d, core=%d)", signo, pid, core); } else { do_crm_log(exitcode == 0 ? LOG_TRACE : LOG_ERR, "Disk write process exited (pid=%d, rc=%d)", pid, exitcode); } if (exitcode != 0 && cib_writes_enabled) { crm_err("Disabling disk writes after write failure"); cib_writes_enabled = FALSE; } mainloop_trigger_complete(cib_writer); } int write_cib_contents(gpointer p) { int fd = -1; - int exit_rc = EX_OK; + int exit_rc = pcmk_ok; char *digest = NULL; xmlNode *cib_status_root = NULL; xmlNode *cib_local = NULL; xmlNode *cib_tmp = NULL; int tmp_cib_fd = 0; int tmp_digest_fd = 0; char *tmp_cib = NULL; char *tmp_digest = NULL; char *digest_file = NULL; char *primary_file = NULL; char *backup_file = NULL; char *backup_digest = NULL; const char *epoch = NULL; const char *admin_epoch = NULL; if (p) { /* Synchronous write out */ cib_local = copy_xml(p); } else { int pid = 0; int bb_state = qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_STATE_GET, 0); /* Turn it off before the fork() to avoid: * - 2 processes writing to the same shared mem * - the child needing to disable it * (which would close it from underneath the parent) * This way, the shared mem files are already closed */ qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_ENABLED, QB_FALSE); pid = fork(); if (pid < 0) { crm_perror(LOG_ERR, "Disabling disk writes after fork failure"); cib_writes_enabled = FALSE; return FALSE; } if (pid) { /* Parent */ mainloop_child_add(pid, 0, "disk-writer", NULL, cib_diskwrite_complete); if (bb_state == QB_LOG_STATE_ENABLED) { /* Re-enable now that it it safe */ qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_ENABLED, QB_TRUE); } return -1; /* -1 means 'still work to do' */ } /* A-synchronous write out after a fork() */ - /* Don't log anything unless strictly necessary */ - set_crm_log_level(LOG_ERR); - /* In theory we can scribble on "the_cib" here and not affect the parent * But lets be safe anyway */ cib_local = copy_xml(the_cib); } epoch = crm_element_value(cib_local, XML_ATTR_GENERATION); admin_epoch = crm_element_value(cib_local, XML_ATTR_GENERATION_ADMIN); primary_file = crm_concat(cib_root, "cib.xml", '/'); digest_file = crm_concat(primary_file, "sig", '.'); /* Always write out with num_updates=0 */ crm_xml_add(cib_local, XML_ATTR_NUMUPDATES, "0"); fd = open(primary_file, O_NOFOLLOW); if (fd >= 0) { int rc = 0; int seq = get_last_sequence(cib_root, CIB_SERIES); /* check the admin didnt modify it underneath us */ if (validate_on_disk_cib(primary_file, NULL) == FALSE) { crm_err("%s was manually modified while the cluster was active!", primary_file); - exit_rc = 1; + exit_rc = pcmk_err_cib_modified; goto cleanup; } backup_file = generate_series_filename(cib_root, CIB_SERIES, seq, FALSE); backup_digest = crm_concat(backup_file, "sig", '.'); unlink(backup_file); unlink(backup_digest); rc = link(primary_file, backup_file); if (rc < 0) { - exit_rc = 4; + exit_rc = pcmk_err_cib_backup; crm_perror(LOG_ERR, "Cannot link %s to %s", primary_file, backup_file); goto cleanup; } rc = link(digest_file, backup_digest); if (rc < 0 && errno != ENOENT) { - exit_rc = 5; + exit_rc = pcmk_err_cib_backup; crm_perror(LOG_ERR, "Cannot link %s to %s", digest_file, backup_digest); goto cleanup; } write_last_sequence(cib_root, CIB_SERIES, seq + 1, cib_wrap); sync_directory(cib_root); crm_info("Archived previous version as %s", backup_file); } /* Given that we discard the status section on startup * there is no point writing it out in the first place * since users just get confused by it * * So delete the status section before we write it out */ crm_debug("Writing CIB to disk"); if (p == NULL) { cib_status_root = find_xml_node(cib_local, XML_CIB_TAG_STATUS, TRUE); CRM_LOG_ASSERT(cib_status_root != NULL); if (cib_status_root != NULL) { free_xml(cib_status_root); } } tmp_cib = g_strdup_printf("%s/cib.XXXXXX", cib_root); tmp_digest = g_strdup_printf("%s/cib.XXXXXX", cib_root); umask(S_IWGRP | S_IWOTH | S_IROTH); tmp_cib_fd = mkstemp(tmp_cib); if (write_xml_fd(cib_local, tmp_cib, tmp_cib_fd, FALSE) <= 0) { crm_err("Changes couldn't be written to %s", tmp_cib); - exit_rc = 2; + exit_rc = pcmk_err_cib_save; goto cleanup; } /* Must calculate the digest after writing as write_xml_file() updates the last-written field */ digest = calculate_on_disk_digest(cib_local); crm_info("Wrote version %s.%s.0 of the CIB to disk (digest: %s)", admin_epoch ? admin_epoch : "0", epoch ? epoch : "0", digest); tmp_digest_fd = mkstemp(tmp_digest); if (write_cib_digest(cib_local, tmp_digest, tmp_digest_fd, digest) <= 0) { crm_err("Digest couldn't be written to %s", tmp_digest); - exit_rc = 3; + exit_rc = pcmk_err_cib_save; goto cleanup; } crm_debug("Wrote digest %s to disk", digest); cib_tmp = retrieveCib(tmp_cib, tmp_digest, FALSE); CRM_ASSERT(cib_tmp != NULL); sync_directory(cib_root); crm_debug("Activating %s", tmp_cib); cib_rename(tmp_cib, primary_file); cib_rename(tmp_digest, digest_file); sync_directory(cib_root); cleanup: free(backup_digest); free(primary_file); free(backup_file); free(digest_file); free(digest); free(tmp_digest); free(tmp_cib); free_xml(cib_tmp); free_xml(cib_local); if (fd >= 0) { close(fd); } if (p == NULL) { /* exit() could potentially affect the parent by closing things it shouldn't * Use _exit instead */ _exit(exit_rc); } return exit_rc; } void GHFunc_count_peers(gpointer key, gpointer value, gpointer user_data) { int *active = user_data; if (safe_str_eq(value, ONLINESTATUS)) { (*active)++; } else if (safe_str_eq(value, JOINSTATUS)) { (*active)++; } } diff --git a/lib/common/logging.c b/lib/common/logging.c index 39db22525e..242559fa78 100644 --- a/lib/common/logging.c +++ b/lib/common/logging.c @@ -1,958 +1,964 @@ /* * Copyright (C) 2004 Andrew Beekhof * * This library is free software; you can redistribute it and/or * modify it under the terms of the GNU Lesser General Public * License as published by the Free Software Foundation; either * version 2.1 of the License, or (at your option) any later version. * * This library is distributed in the hope that it will be useful, * but WITHOUT ANY WARRANTY; without even the implied warranty of * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU * Lesser General Public License for more details. * * You should have received a copy of the GNU Lesser General Public * License along with this library; if not, write to the Free Software * Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA */ #include #include #include #include #include #include #include #include #include #include #include #include #include #include #include #include #include #include #include #include #include unsigned int crm_log_priority = LOG_NOTICE; unsigned int crm_log_level = LOG_INFO; static gboolean crm_tracing_enabled(void); unsigned int crm_trace_nonlog = 0; #ifdef HAVE_G_LOG_SET_DEFAULT_HANDLER GLogFunc glib_log_default; static void crm_glib_handler(const gchar * log_domain, GLogLevelFlags flags, const gchar * message, gpointer user_data) { int log_level = LOG_WARNING; GLogLevelFlags msg_level = (flags & G_LOG_LEVEL_MASK); switch (msg_level) { case G_LOG_LEVEL_CRITICAL: /* log and record how we got here */ crm_abort(__FILE__, __PRETTY_FUNCTION__, __LINE__, message, TRUE, TRUE); return; case G_LOG_LEVEL_ERROR: log_level = LOG_ERR; break; case G_LOG_LEVEL_MESSAGE: log_level = LOG_NOTICE; break; case G_LOG_LEVEL_INFO: log_level = LOG_INFO; break; case G_LOG_LEVEL_DEBUG: log_level = LOG_DEBUG; break; case G_LOG_LEVEL_WARNING: case G_LOG_FLAG_RECURSION: case G_LOG_FLAG_FATAL: case G_LOG_LEVEL_MASK: log_level = LOG_WARNING; break; } do_crm_log(log_level, "%s: %s", log_domain, message); } #endif #ifndef NAME_MAX # define NAME_MAX 256 #endif static void crm_trigger_blackbox(int nsig) { crm_write_blackbox(nsig, NULL); } const char * daemon_option(const char *option) { char env_name[NAME_MAX]; const char *value = NULL; snprintf(env_name, NAME_MAX, "PCMK_%s", option); value = getenv(env_name); if (value != NULL) { crm_trace("Found %s = %s", env_name, value); return value; } snprintf(env_name, NAME_MAX, "HA_%s", option); value = getenv(env_name); if (value != NULL) { crm_trace("Found %s = %s", env_name, value); return value; } crm_trace("Nothing found for %s", option); return NULL; } void set_daemon_option(const char *option, const char *value) { char env_name[NAME_MAX]; snprintf(env_name, NAME_MAX, "PCMK_%s", option); if (value) { crm_trace("Setting %s to %s", env_name, value); setenv(env_name, value, 1); } else { crm_trace("Unsetting %s", env_name); unsetenv(env_name); } snprintf(env_name, NAME_MAX, "HA_%s", option); if (value) { crm_trace("Setting %s to %s", env_name, value); setenv(env_name, value, 1); } else { crm_trace("Unsetting %s", env_name); unsetenv(env_name); } } gboolean daemon_option_enabled(const char *daemon, const char *option) { const char *value = daemon_option(option); if (value != NULL && crm_is_true(value)) { return TRUE; } else if (value != NULL && strstr(value, daemon)) { return TRUE; } return FALSE; } void crm_log_deinit(void) { #ifdef HAVE_G_LOG_SET_DEFAULT_HANDLER g_log_set_default_handler(glib_log_default, NULL); #endif } #define FMT_MAX 256 static void set_format_string(int method, const char *daemon) { int offset = 0; char fmt[FMT_MAX]; if (method > QB_LOG_STDERR) { /* When logging to a file */ struct utsname res; if (uname(&res) == 0) { offset += snprintf(fmt + offset, FMT_MAX - offset, "%%t [%d] %s %10s: ", getpid(), res.nodename, daemon); } else { offset += snprintf(fmt + offset, FMT_MAX - offset, "%%t [%d] %10s: ", getpid(), daemon); } } if (crm_tracing_enabled() && method >= QB_LOG_STDERR) { offset += snprintf(fmt + offset, FMT_MAX - offset, "(%%-12f:%%5l %%g) %%-7p: %%n: "); } else { offset += snprintf(fmt + offset, FMT_MAX - offset, "%%g %%-7p: %%n: "); } if (method == QB_LOG_SYSLOG) { offset += snprintf(fmt + offset, FMT_MAX - offset, "%%b"); } else { offset += snprintf(fmt + offset, FMT_MAX - offset, "\t%%b"); } qb_log_format_set(method, fmt); } gboolean crm_add_logfile(const char *filename) { struct stat parent; int fd = 0, rc = 0; FILE *logfile = NULL; char *parent_dir = NULL; char *filename_cp; static gboolean have_logfile = FALSE; if (filename == NULL && have_logfile == FALSE) { filename = "/var/log/pacemaker.log"; } if (filename == NULL) { return FALSE; /* Nothing to do */ } /* Check the parent directory */ filename_cp = strdup(filename); parent_dir = dirname(filename_cp); rc = stat(parent_dir, &parent); if (rc != 0) { crm_err("Directory '%s' does not exist: logging to '%s' is disabled", parent_dir, filename); free(filename_cp); return FALSE; } free(filename_cp); errno = 0; logfile = fopen(filename, "a"); if(logfile == NULL) { crm_err("%s (%d): Logging to '%s' as uid=%u, gid=%u is disabled", pcmk_strerror(errno), errno, filename, geteuid(), getegid()); return FALSE; } /* Check/Set permissions if we're root */ if (geteuid() == 0) { struct stat st; uid_t pcmk_uid = 0; gid_t pcmk_gid = 0; gboolean fix = FALSE; int logfd = fileno(logfile); rc = fstat(logfd, &st); if (rc < 0) { crm_perror(LOG_WARNING, "Cannot stat %s", filename); fclose(logfile); return FALSE; } crm_user_lookup(CRM_DAEMON_USER, &pcmk_uid, &pcmk_gid); if (st.st_gid != pcmk_gid) { /* Wrong group */ fix = TRUE; } else if ((st.st_mode & S_IRWXG) != (S_IRGRP | S_IWGRP)) { /* Not read/writable by the correct group */ fix = TRUE; } if (fix) { rc = fchown(logfd, pcmk_uid, pcmk_gid); if (rc < 0) { crm_warn("Cannot change the ownership of %s to user %s and gid %d", filename, CRM_DAEMON_USER, pcmk_gid); } rc = fchmod(logfd, S_IRUSR | S_IWUSR | S_IRGRP | S_IWGRP); if (rc < 0) { crm_warn("Cannot change the mode of %s to rw-rw----", filename); } fprintf(logfile, "Set r/w permissions for uid=%d, gid=%d on %s\n", pcmk_uid, pcmk_gid, filename); if (fflush(logfile) < 0 || fsync(logfd) < 0) { crm_err("Couldn't write out logfile: %s", filename); } } } /* Close and reopen with libqb */ fclose(logfile); fd = qb_log_file_open(filename); if (fd < 0) { crm_perror(LOG_WARNING, "Couldn't send additional logging to %s", filename); return FALSE; } crm_notice("Additional logging available in %s", filename); qb_log_ctl(fd, QB_LOG_CONF_ENABLED, QB_TRUE); /* Enable callsites */ crm_update_callsites(); have_logfile = TRUE; return TRUE; } static int blackbox_trigger = 0; static char *blackbox_file_prefix = NULL; static void blackbox_logger(int32_t t, struct qb_log_callsite *cs, time_t timestamp, const char *msg) { if(cs && cs->priority < LOG_ERR) { crm_write_blackbox(SIGABRT, cs); /* Bypass the over-dumping logic */ } else { crm_write_blackbox(0, cs); } } void crm_enable_blackbox(int nsig) { if (blackbox_file_prefix == NULL) { pid_t pid = getpid(); blackbox_file_prefix = malloc(NAME_MAX); snprintf(blackbox_file_prefix, NAME_MAX, "%s/%s-%d", CRM_BLACKBOX_DIR, crm_system_name, pid); } if (qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_STATE_GET, 0) != QB_LOG_STATE_ENABLED) { qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_SIZE, 5 * 1024 * 1024); /* Any size change drops existing entries */ qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_ENABLED, QB_TRUE); /* Setting the size seems to disable it */ crm_notice("Initiated blackbox recorder: %s", blackbox_file_prefix); crm_signal(SIGSEGV, crm_trigger_blackbox); crm_update_callsites(); /* Original meanings from signal(7) * * Signal Value Action Comment * SIGTRAP 5 Core Trace/breakpoint trap * * Our usage is as similar as possible */ mainloop_add_signal(SIGTRAP, crm_trigger_blackbox); blackbox_trigger = qb_log_custom_open(blackbox_logger, NULL, NULL, NULL); qb_log_ctl(blackbox_trigger, QB_LOG_CONF_ENABLED, QB_TRUE); crm_info("Trigger: %d is %d %d", blackbox_trigger, qb_log_ctl(blackbox_trigger, QB_LOG_CONF_STATE_GET, 0), QB_LOG_STATE_ENABLED); crm_update_callsites(); } } void crm_write_blackbox(int nsig, struct qb_log_callsite *cs) { static int counter = 1; static time_t last = 0; char buffer[NAME_MAX]; time_t now = time(NULL); if (blackbox_file_prefix == NULL) { return; } switch (nsig) { case 0: case SIGABRT: case SIGTRAP: /* The graceful case - such as assertion failure or user request */ if (nsig == 0 && now == last) { /* Prevent over-dumping */ return; } snprintf(buffer, NAME_MAX, "%s.%d", blackbox_file_prefix, counter++); if (nsig == SIGTRAP) { crm_notice("Blackbox dump requested, please see %s for contents", buffer); } else if (cs) { syslog(LOG_NOTICE, "Problem detected at %s:%d (%s), please see %s for additional details", cs->function, cs->lineno, cs->filename, buffer); } else { crm_notice("Problem detected, please see %s for additional details", buffer); } last = now; qb_log_blackbox_write_to_file(buffer); /* Flush the existing contents * A size change would also work */ qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_ENABLED, QB_FALSE); qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_ENABLED, QB_TRUE); break; default: /* Do as little as possible, just try to get what we have out * We logged the filename when the blackbox was enabled */ crm_signal(nsig, SIG_DFL); qb_log_blackbox_write_to_file(blackbox_file_prefix); qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_ENABLED, QB_FALSE); raise(nsig); break; } } gboolean crm_log_cli_init(const char *entity) { return crm_log_init(entity, LOG_ERR, FALSE, FALSE, 0, NULL, TRUE); } static const char * crm_quark_to_string(uint32_t tag) { const char *text = g_quark_to_string(tag); if (text) { return text; } return ""; } static void crm_log_filter_source(int source, const char *trace_files, const char *trace_fns, const char *trace_fmts, const char *trace_tags, const char *trace_blackbox, struct qb_log_callsite *cs) { if (qb_log_ctl(source, QB_LOG_CONF_STATE_GET, 0) != QB_LOG_STATE_ENABLED) { return; } else if (cs->tags != crm_trace_nonlog && source == QB_LOG_BLACKBOX) { /* Blackbox gets everything if enabled */ qb_bit_set(cs->targets, source); } else if (source == blackbox_trigger && blackbox_trigger > 0) { /* Should this log message result in the blackbox being dumped */ if (cs->priority <= LOG_ERR) { qb_bit_set(cs->targets, source); } else if (trace_blackbox) { char *key = g_strdup_printf("%s:%d", cs->function, cs->lineno); if (strstr(trace_blackbox, key) != NULL) { qb_bit_set(cs->targets, source); } free(key); } } else if (source == QB_LOG_SYSLOG) { /* No tracing to syslog */ if (cs->priority <= crm_log_priority && cs->priority <= crm_log_level) { qb_bit_set(cs->targets, source); } /* Log file tracing options... */ } else if (cs->priority <= crm_log_level) { qb_bit_set(cs->targets, source); } else if (trace_files && strstr(trace_files, cs->filename) != NULL) { qb_bit_set(cs->targets, source); } else if (trace_fns && strstr(trace_fns, cs->function) != NULL) { qb_bit_set(cs->targets, source); } else if (trace_fmts && strstr(trace_fmts, cs->format) != NULL) { qb_bit_set(cs->targets, source); } else if (trace_tags && cs->tags != 0 && cs->tags != crm_trace_nonlog && g_quark_to_string(cs->tags) != NULL) { qb_bit_set(cs->targets, source); } } static void crm_log_filter(struct qb_log_callsite *cs) { int lpc = 0; static int need_init = 1; static const char *trace_fns = NULL; static const char *trace_tags = NULL; static const char *trace_fmts = NULL; static const char *trace_files = NULL; static const char *trace_blackbox = NULL; if (need_init) { need_init = 0; trace_fns = getenv("PCMK_trace_functions"); trace_fmts = getenv("PCMK_trace_formats"); trace_tags = getenv("PCMK_trace_tags"); trace_files = getenv("PCMK_trace_files"); trace_blackbox = getenv("PCMK_trace_blackbox"); if (trace_tags != NULL) { uint32_t tag; char token[500]; const char *offset = NULL; const char *next = trace_tags; do { offset = next; next = strchrnul(offset, ','); snprintf(token, 499, "%.*s", (int)(next - offset), offset); tag = g_quark_from_string(token); crm_info("Created GQuark %u from token '%s' in '%s'", tag, token, trace_tags); if (next[0] != 0) { next++; } } while (next != NULL && next[0] != 0); } } cs->targets = 0; /* Reset then find targets to enable */ for (lpc = QB_LOG_SYSLOG; lpc < QB_LOG_TARGET_MAX; lpc++) { crm_log_filter_source(lpc, trace_files, trace_fns, trace_fmts, trace_tags, trace_blackbox, cs); } } gboolean crm_is_callsite_active(struct qb_log_callsite *cs, int level, int tags) { gboolean refilter = FALSE; if (cs == NULL) { return FALSE; } if (cs->priority != level) { cs->priority = level; refilter = TRUE; } if (cs->tags != tags) { cs->tags = tags; refilter = TRUE; } if (refilter) { crm_log_filter(cs); } if (cs->targets == 0) { return FALSE; } return TRUE; } void crm_update_callsites(void) { static gboolean log = TRUE; if (log) { log = FALSE; crm_debug ("Enabling callsites based on priority=%d, files=%s, functions=%s, formats=%s, tags=%s", crm_log_level, getenv("PCMK_trace_files"), getenv("PCMK_trace_functions"), getenv("PCMK_trace_formats"), getenv("PCMK_trace_tags")); } qb_log_filter_fn_set(crm_log_filter); } static gboolean crm_tracing_enabled(void) { if (crm_log_level >= LOG_TRACE) { return TRUE; } else if (getenv("PCMK_trace_files") || getenv("PCMK_trace_functions") || getenv("PCMK_trace_formats") || getenv("PCMK_trace_tags")) { return TRUE; } return FALSE; } static int crm_priority2int(const char *name) { struct syslog_names { const char *name; int priority; }; static struct syslog_names p_names[] = { {"emerg", LOG_EMERG}, {"alert", LOG_ALERT}, {"crit", LOG_CRIT}, {"error", LOG_ERR}, {"warning", LOG_WARNING}, {"notice", LOG_NOTICE}, {"info", LOG_INFO}, {"debug", LOG_DEBUG}, {NULL, -1} }; int lpc; for (lpc = 0; name != NULL && p_names[lpc].name != NULL; lpc++) { if (crm_str_eq(p_names[lpc].name, name, TRUE)) { return p_names[lpc].priority; } } return crm_log_priority; } gboolean crm_log_init(const char *entity, int level, gboolean daemon, gboolean to_stderr, int argc, char **argv, gboolean quiet) { int lpc = 0; const char *logfile = daemon_option("debugfile"); const char *facility = daemon_option("logfacility"); const char *f_copy = facility; if (crm_trace_nonlog == 0) { crm_trace_nonlog = g_quark_from_static_string("Pacemaker non-logging tracepoint"); } umask(S_IWGRP | S_IWOTH | S_IROTH); /* Redirect messages from glib functions to our handler */ #ifdef HAVE_G_LOG_SET_DEFAULT_HANDLER glib_log_default = g_log_set_default_handler(crm_glib_handler, NULL); #endif /* and for good measure... - this enum is a bit field (!) */ g_log_set_always_fatal((GLogLevelFlags) 0); /*value out of range */ if (facility == NULL) { facility = "daemon"; } else if (safe_str_eq(facility, "none")) { facility = "daemon"; quiet = TRUE; } if (entity) { crm_system_name = entity; } else if (argc > 0 && argv != NULL) { char *mutable = strdup(argv[0]); crm_system_name = basename(mutable); if (strstr(crm_system_name, "lt-") == crm_system_name) { crm_system_name += 3; } } else if (crm_system_name == NULL) { crm_system_name = "Unknown"; } setenv("PCMK_service", crm_system_name, 1); if (daemon_option_enabled(crm_system_name, "debug")) { /* Override the default setting */ level = LOG_DEBUG; } if (daemon_option_enabled(crm_system_name, "stderr")) { /* Override the default setting */ to_stderr = TRUE; } crm_log_priority = crm_priority2int(daemon_option("logpriority")); crm_log_level = level; qb_log_init(crm_system_name, qb_log_facility2int(facility), level); qb_log_tags_stringify_fn_set(crm_quark_to_string); /* Set default format strings */ for (lpc = QB_LOG_SYSLOG; lpc < QB_LOG_TARGET_MAX; lpc++) { set_format_string(lpc, crm_system_name); } crm_enable_stderr(to_stderr); if (logfile) { crm_add_logfile(logfile); } if (daemon_option_enabled(crm_system_name, "blackbox")) { crm_enable_blackbox(0); } crm_trace("Quiet: %d, facility %s", quiet, f_copy); daemon_option("debugfile"); daemon_option("logfacility"); if (quiet) { /* Nuke any syslog activity */ facility = NULL; qb_log_ctl(QB_LOG_SYSLOG, QB_LOG_CONF_ENABLED, QB_FALSE); } if (daemon) { set_daemon_option("logfacility", facility); } if (daemon && crm_tracing_enabled() && qb_log_ctl(QB_LOG_STDERR, QB_LOG_CONF_STATE_GET, 0) != QB_LOG_STATE_ENABLED && qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_STATE_GET, 0) != QB_LOG_STATE_ENABLED) { /* Make sure tracing goes somewhere */ crm_add_logfile(NULL); } crm_update_callsites(); /* Ok, now we can start logging... */ if (quiet == FALSE && daemon == FALSE) { crm_log_args(argc, argv); } if (daemon) { const char *user = getenv("USER"); if (user != NULL && safe_str_neq(user, "root") && safe_str_neq(user, CRM_DAEMON_USER)) { crm_trace("Not switching to corefile directory for %s", user); daemon = FALSE; } } if (daemon) { int user = getuid(); const char *base = CRM_CORE_DIR; struct passwd *pwent = getpwuid(user); if (pwent == NULL) { crm_perror(LOG_ERR, "Cannot get name for uid: %d", user); } else if (safe_str_neq(pwent->pw_name, "root") && safe_str_neq(pwent->pw_name, CRM_DAEMON_USER)) { crm_trace("Don't change active directory for regular user: %s", pwent->pw_name); } else if (chdir(base) < 0) { crm_perror(LOG_INFO, "Cannot change active directory to %s", base); } else { crm_info("Changed active directory to %s/%s", base, pwent->pw_name); #if 0 { char path[512]; snprintf(path, 512, "%s-%d", crm_system_name, getpid()); mkdir(path, 0750); chdir(path); crm_info("Changed active directory to %s/%s/%s", base, pwent->pw_name, path); } #endif } mainloop_add_signal(SIGUSR1, crm_enable_blackbox); } crm_xml_init(); /* Sets buffer allocation strategy */ return TRUE; } /* returns the old value */ unsigned int set_crm_log_level(unsigned int level) { unsigned int old = crm_log_level; crm_log_level = level; crm_update_callsites(); crm_trace("New log level: %d", level); return old; } void crm_enable_stderr(int enable) { if (enable && qb_log_ctl(QB_LOG_STDERR, QB_LOG_CONF_STATE_GET, 0) != QB_LOG_STATE_ENABLED) { qb_log_ctl(QB_LOG_STDERR, QB_LOG_CONF_ENABLED, QB_TRUE); crm_update_callsites(); } else if (enable == FALSE) { qb_log_ctl(QB_LOG_STDERR, QB_LOG_CONF_ENABLED, QB_FALSE); } } void crm_bump_log_level(int argc, char **argv) { static int args = TRUE; int level = crm_log_level; if (args && argc > 1) { crm_log_args(argc, argv); } if (qb_log_ctl(QB_LOG_STDERR, QB_LOG_CONF_STATE_GET, 0) == QB_LOG_STATE_ENABLED) { set_crm_log_level(level + 1); } /* Enable after potentially logging the argstring, not before */ crm_enable_stderr(TRUE); } unsigned int get_crm_log_level(void) { return crm_log_level; } #define ARGS_FMT "Invoked: %s" void crm_log_args(int argc, char **argv) { int lpc = 0; int len = 0; int restore = FALSE; int existing_len = 0; int line = __LINE__; static int logged = 0; char *arg_string = NULL; struct qb_log_callsite *args_cs = qb_log_callsite_get(__func__, __FILE__, ARGS_FMT, LOG_NOTICE, line, 0); if (argc == 0 || argv == NULL || logged) { return; } logged = 1; qb_bit_set(args_cs->targets, QB_LOG_SYSLOG); /* Turn on syslog too */ restore = qb_log_ctl(QB_LOG_SYSLOG, QB_LOG_CONF_STATE_GET, 0); qb_log_ctl(QB_LOG_SYSLOG, QB_LOG_CONF_ENABLED, QB_TRUE); for (; lpc < argc; lpc++) { if (argv[lpc] == NULL) { break; } len = 2 + strlen(argv[lpc]); /* +1 space, +1 EOS */ arg_string = realloc(arg_string, len + existing_len); existing_len += sprintf(arg_string + existing_len, "%s ", argv[lpc]); } qb_log_from_external_source(__func__, __FILE__, ARGS_FMT, LOG_NOTICE, line, 0, arg_string); qb_log_ctl(QB_LOG_SYSLOG, QB_LOG_CONF_ENABLED, restore); free(arg_string); } const char * pcmk_strerror(int rc) { int error = rc; if (rc < 0) { error = 0 - rc; } if (error == 0) { return "OK"; } else if (error < PCMK_ERROR_OFFSET) { return strerror(error); } switch (error) { case pcmk_err_generic: return "Generic Pacemaker error"; case pcmk_err_no_quorum: return "Operation requires quorum"; case pcmk_err_dtd_validation: return "Update does not conform to the configured schema"; case pcmk_err_transform_failed: return "Schema transform failed"; case pcmk_err_old_data: return "Update was older than existing configuration"; case pcmk_err_diff_failed: return "Application of an update diff failed"; case pcmk_err_diff_resync: return "Application of an update diff failed, requesting a full refresh"; + case pcmk_err_cib_modified: + return "The on-disk configuration was manually modified"; + case pcmk_err_cib_backup: + return "Could not archive the previous configuration"; + case pcmk_err_cib_save: + return "Could not save the new configuration to disk"; /* The following cases will only be hit on systems for which they are non-standard */ /* coverity[dead_error_condition] False positive on non-Linux */ case ENOTUNIQ: return "Name not unique on network"; /* coverity[dead_error_condition] False positive on non-Linux */ case ECOMM: return "Communication error on send"; /* coverity[dead_error_condition] False positive on non-Linux */ case ELIBACC: return "Can not access a needed shared library"; /* coverity[dead_error_condition] False positive on non-Linux */ case EREMOTEIO: return "Remote I/O error"; /* coverity[dead_error_condition] False positive on non-Linux */ case EUNATCH: return "Protocol driver not attached"; /* coverity[dead_error_condition] False positive on non-Linux */ case ENOKEY: return "Required key not available"; } crm_err("Unknown error code: %d", rc); return "Unknown error"; } const char * bz2_strerror(int rc) { /* http://www.bzip.org/1.0.3/html/err-handling.html */ switch (rc) { case BZ_OK: case BZ_RUN_OK: case BZ_FLUSH_OK: case BZ_FINISH_OK: case BZ_STREAM_END: return "Ok"; case BZ_CONFIG_ERROR: return "libbz2 has been improperly compiled on your platform"; case BZ_SEQUENCE_ERROR: return "library functions called in the wrong order"; case BZ_PARAM_ERROR: return "parameter is out of range or otherwise incorrect"; case BZ_MEM_ERROR: return "memory allocation failed"; case BZ_DATA_ERROR: return "data integrity error is detected during decompression"; case BZ_DATA_ERROR_MAGIC: return "the compressed stream does not start with the correct magic bytes"; case BZ_IO_ERROR: return "error reading or writing in the compressed file"; case BZ_UNEXPECTED_EOF: return "compressed file finishes before the logical end of stream is detected"; case BZ_OUTBUFF_FULL: return "output data will not fit into the buffer provided"; } return "Unknown error"; } void crm_log_output_fn(const char *file, const char *function, int line, int level, const char *prefix, const char *output) { const char *next = NULL; const char *offset = NULL; if (output) { next = output; do { offset = next; next = strchrnul(offset, '\n'); do_crm_log_alias(level, file, function, line, "%s [ %.*s ]", prefix, (int)(next - offset), offset); if (next[0] != 0) { next++; } } while (next != NULL && next[0] != 0); } }