diff --git a/include/crm/common/logging.h b/include/crm/common/logging.h index 2878fba8a2..eea4cec9aa 100644 --- a/include/crm/common/logging.h +++ b/include/crm/common/logging.h @@ -1,411 +1,415 @@ /* * Copyright 2004-2023 the Pacemaker project contributors * * The version control history for this file may have further details. * * This source code is licensed under the GNU General Public License version 2 * or later (GPLv2+) WITHOUT ANY WARRANTY. */ #ifndef PCMK__CRM_COMMON_LOGGING__H # define PCMK__CRM_COMMON_LOGGING__H # include +# include // uint8_t, uint32_t # include # include # include #ifdef __cplusplus extern "C" { #endif /** * \file * \brief Wrappers for and extensions to libqb logging * \ingroup core */ /* Define custom log priorities. * * syslog(3) uses int for priorities, but libqb's struct qb_log_callsite uses * uint8_t, so make sure they fit in the latter. */ // Define something even less desired than debug # ifndef LOG_TRACE # define LOG_TRACE (LOG_DEBUG+1) # endif // Print message to stdout instead of logging it # ifndef LOG_STDOUT # define LOG_STDOUT 254 # endif // Don't send message anywhere # ifndef LOG_NEVER # define LOG_NEVER 255 # endif /* "Extended information" logging support */ #ifdef QB_XS # define CRM_XS QB_XS # define crm_extended_logging(t, e) qb_log_ctl((t), QB_LOG_CONF_EXTENDED, (e)) #else # define CRM_XS "|" /* A caller might want to check the return value, so we can't define this as a * no-op, and we can't simply define it to be 0 because gcc will then complain * when the value isn't checked. */ static inline int crm_extended_logging(int t, int e) { return 0; } #endif extern unsigned int crm_log_level; extern unsigned int crm_trace_nonlog; /*! \deprecated Pacemaker library functions set this when a configuration * error is found, which turns on extra messages at the end of * processing. It should not be used directly and will be removed * from the public C API in a future release. */ extern gboolean crm_config_error; /*! \deprecated Pacemaker library functions set this when a configuration * warning is found, which turns on extra messages at the end of * processing. It should not be used directly and will be removed * from the public C API in a future release. */ extern gboolean crm_config_warning; void crm_enable_blackbox(int nsig); void crm_disable_blackbox(int nsig); void crm_write_blackbox(int nsig, const struct qb_log_callsite *callsite); void crm_update_callsites(void); void crm_log_deinit(void); /*! * \brief Initializes the logging system and defaults to the least verbose output level * * \param[in] entity If not NULL, will be used as the identity for logging purposes * \param[in] argc The number of command line parameters * \param[in] argv The command line parameter values */ void crm_log_preinit(const char *entity, int argc, char *const *argv); gboolean crm_log_init(const char *entity, uint8_t level, gboolean daemon, gboolean to_stderr, int argc, char **argv, gboolean quiet); void crm_log_args(int argc, char **argv); void crm_log_output_fn(const char *file, const char *function, int line, int level, const char *prefix, const char *output); // Log a block of text line by line #define crm_log_output(level, prefix, output) \ crm_log_output_fn(__FILE__, __func__, __LINE__, level, prefix, output) void crm_bump_log_level(int argc, char **argv); void crm_enable_stderr(int enable); gboolean crm_is_callsite_active(struct qb_log_callsite *cs, uint8_t level, uint32_t tags); /* returns the old value */ unsigned int set_crm_log_level(unsigned int level); unsigned int get_crm_log_level(void); -void pcmk_log_xml_impl(uint8_t level, const char *text, const xmlNode *xml); +void pcmk_log_xml_as(const char *file, const char *function, uint32_t line, + uint32_t tags, uint8_t level, const char *text, + const xmlNode *xml); /* * Throughout the macros below, note the leading, pre-comma, space in the * various ' , ##args' occurrences to aid portability across versions of 'gcc'. * https://gcc.gnu.org/onlinedocs/cpp/Variadic-Macros.html#Variadic-Macros */ #if defined(__clang__) # define CRM_TRACE_INIT_DATA(name) # else # include // required by QB_LOG_INIT_DATA() macro # define CRM_TRACE_INIT_DATA(name) QB_LOG_INIT_DATA(name) #endif /*! * \internal * \brief Clip log_level to \p uint8_t range * * \param[in] level Log level to clip * * \return 0 if \p level is less than 0, \p UINT8_MAX if \p level is greater * than \p UINT8_MAX, or \p level otherwise */ /* @COMPAT: Make this function internal at a compatibility break. It's used in * public macros for now. */ static inline uint8_t pcmk__clip_log_level(int level) { if (level <= 0) { return 0; } if (level >= UINT8_MAX) { return UINT8_MAX; } return level; } /* Using "switch" instead of "if" in these macro definitions keeps * static analysis from complaining about constant evaluations */ /*! * \brief Log a message * * \param[in] level Priority at which to log the message * \param[in] fmt printf-style format string literal for message * \param[in] args Any arguments needed by format string */ # define do_crm_log(level, fmt, args...) do { \ uint8_t _level = pcmk__clip_log_level(level); \ \ switch (_level) { \ case LOG_STDOUT: \ printf(fmt "\n" , ##args); \ break; \ case LOG_NEVER: \ break; \ default: \ qb_log_from_external_source(__func__, __FILE__, fmt, \ _level, __LINE__, 0 , ##args); \ break; \ } \ } while (0) /*! * \brief Log a message that is likely to be filtered out * * \param[in] level Priority at which to log the message * \param[in] fmt printf-style format string for message * \param[in] args Any arguments needed by format string * * \note This does nothing when level is \p LOG_STDOUT. */ # define do_crm_log_unlikely(level, fmt, args...) do { \ uint8_t _level = pcmk__clip_log_level(level); \ \ switch (_level) { \ case LOG_STDOUT: case LOG_NEVER: \ break; \ default: { \ static struct qb_log_callsite *trace_cs = NULL; \ if (trace_cs == NULL) { \ trace_cs = qb_log_callsite_get(__func__, __FILE__, fmt, \ _level, __LINE__, 0); \ } \ if (crm_is_callsite_active(trace_cs, _level, 0)) { \ qb_log_from_external_source(__func__, __FILE__, fmt, \ _level, __LINE__, 0 , \ ##args); \ } \ } \ break; \ } \ } while (0) # define CRM_LOG_ASSERT(expr) do { \ if (!(expr)) { \ static struct qb_log_callsite *core_cs = NULL; \ if(core_cs == NULL) { \ core_cs = qb_log_callsite_get(__func__, __FILE__, \ "log-assert", LOG_TRACE, \ __LINE__, 0); \ } \ crm_abort(__FILE__, __func__, __LINE__, #expr, \ core_cs?core_cs->targets:FALSE, TRUE); \ } \ } while(0) /* 'failure_action' MUST NOT be 'continue' as it will apply to the * macro's do-while loop */ # define CRM_CHECK(expr, failure_action) do { \ if (!(expr)) { \ static struct qb_log_callsite *core_cs = NULL; \ if (core_cs == NULL) { \ core_cs = qb_log_callsite_get(__func__, __FILE__, \ "check-assert", \ LOG_TRACE, __LINE__, 0); \ } \ crm_abort(__FILE__, __func__, __LINE__, #expr, \ (core_cs? core_cs->targets: FALSE), TRUE); \ failure_action; \ } \ } while(0) /*! * \brief Log XML line-by-line in a formatted fashion * * \param[in] level Priority at which to log the messages * \param[in] text Prefix for each line * \param[in] xml XML to log * * \note This does nothing when \p level is \p LOG_STDOUT. */ # define do_crm_log_xml(level, text, xml) do { \ uint8_t _level = pcmk__clip_log_level(level); \ static struct qb_log_callsite *xml_cs = NULL; \ \ switch (_level) { \ case LOG_STDOUT: \ case LOG_NEVER: \ break; \ default: \ if (xml_cs == NULL) { \ xml_cs = qb_log_callsite_get(__func__, __FILE__, \ "xml-blob", _level, \ __LINE__, 0); \ } \ if (crm_is_callsite_active(xml_cs, _level, 0)) { \ - pcmk_log_xml_impl(_level, text, xml); \ + pcmk_log_xml_as(__FILE__, __func__, __LINE__, 0, \ + _level, text, (xml)); \ } \ break; \ } \ } while(0) /*! * \brief Log a message as if it came from a different code location * * \param[in] level Priority at which to log the message * \param[in] file Source file name to use instead of __FILE__ * \param[in] function Source function name to use instead of __func__ * \param[in] line Source line number to use instead of __line__ * \param[in] fmt printf-style format string literal for message * \param[in] args Any arguments needed by format string */ # define do_crm_log_alias(level, file, function, line, fmt, args...) do { \ uint8_t _level = pcmk__clip_log_level(level); \ \ switch (_level) { \ case LOG_STDOUT: \ printf(fmt "\n" , ##args); \ break; \ case LOG_NEVER: \ break; \ default: \ qb_log_from_external_source(function, file, fmt, _level, \ line, 0 , ##args); \ break; \ } \ } while (0) /*! * \brief Send a system error message to both the log and stderr * * \param[in] level Priority at which to log the message * \param[in] fmt printf-style format string for message * \param[in] args Any arguments needed by format string * * \deprecated One of the other logging functions should be used with * pcmk_strerror() instead. * \note This is a macro, and \p level may be evaluated more than once. * \note Because crm_perror() adds the system error message and error number * onto the end of fmt, that information will become extended information * if CRM_XS is used inside fmt and will not show up in syslog. */ # define crm_perror(level, fmt, args...) do { \ uint8_t _level = pcmk__clip_log_level(level); \ \ switch (_level) { \ case LOG_NEVER: \ break; \ default: { \ const char *err = strerror(errno); \ if (_level <= crm_log_level) { \ fprintf(stderr, fmt ": %s (%d)\n" , ##args, err, \ errno); \ } \ /* Pass original level arg since do_crm_log() also declares \ * _level \ */ \ do_crm_log((level), fmt ": %s (%d)" , ##args, err, errno); \ } \ break; \ } \ } while (0) /*! * \brief Log a message with a tag (for use with PCMK_trace_tags) * * \param[in] level Priority at which to log the message * \param[in] tag String to tag message with * \param[in] fmt printf-style format string for message * \param[in] args Any arguments needed by format string * * \note This does nothing when level is LOG_STDOUT. */ # define crm_log_tag(level, tag, fmt, args...) do { \ uint8_t _level = pcmk__clip_log_level(level); \ \ switch (_level) { \ case LOG_STDOUT: case LOG_NEVER: \ break; \ default: { \ static struct qb_log_callsite *trace_tag_cs = NULL; \ int converted_tag = g_quark_try_string(tag); \ if (trace_tag_cs == NULL) { \ trace_tag_cs = qb_log_callsite_get(__func__, __FILE__, \ fmt, _level, \ __LINE__, \ converted_tag); \ } \ if (crm_is_callsite_active(trace_tag_cs, _level, \ converted_tag)) { \ qb_log_from_external_source(__func__, __FILE__, fmt, \ _level, __LINE__, \ converted_tag , ##args); \ } \ } \ } \ } while (0) # define crm_emerg(fmt, args...) qb_log(LOG_EMERG, fmt , ##args) # define crm_crit(fmt, args...) qb_logt(LOG_CRIT, 0, fmt , ##args) # define crm_err(fmt, args...) qb_logt(LOG_ERR, 0, fmt , ##args) # define crm_warn(fmt, args...) qb_logt(LOG_WARNING, 0, fmt , ##args) # define crm_notice(fmt, args...) qb_logt(LOG_NOTICE, 0, fmt , ##args) # define crm_info(fmt, args...) qb_logt(LOG_INFO, 0, fmt , ##args) # define crm_debug(fmt, args...) do_crm_log_unlikely(LOG_DEBUG, fmt , ##args) # define crm_trace(fmt, args...) do_crm_log_unlikely(LOG_TRACE, fmt , ##args) # define crm_log_xml_crit(xml, text) do_crm_log_xml(LOG_CRIT, text, xml) # define crm_log_xml_err(xml, text) do_crm_log_xml(LOG_ERR, text, xml) # define crm_log_xml_warn(xml, text) do_crm_log_xml(LOG_WARNING, text, xml) # define crm_log_xml_notice(xml, text) do_crm_log_xml(LOG_NOTICE, text, xml) # define crm_log_xml_info(xml, text) do_crm_log_xml(LOG_INFO, text, xml) # define crm_log_xml_debug(xml, text) do_crm_log_xml(LOG_DEBUG, text, xml) # define crm_log_xml_trace(xml, text) do_crm_log_xml(LOG_TRACE, text, xml) # define crm_log_xml_explicit(xml, text) do { \ static struct qb_log_callsite *digest_cs = NULL; \ digest_cs = qb_log_callsite_get( \ __func__, __FILE__, text, LOG_TRACE, __LINE__, \ crm_trace_nonlog); \ if (digest_cs && digest_cs->targets) { \ do_crm_log_xml(LOG_TRACE, text, xml); \ } \ } while(0) #if !defined(PCMK_ALLOW_DEPRECATED) || (PCMK_ALLOW_DEPRECATED == 1) #include #endif #ifdef __cplusplus } #endif #endif diff --git a/include/crm/common/logging_compat.h b/include/crm/common/logging_compat.h index cfdb56232e..b57a802a11 100644 --- a/include/crm/common/logging_compat.h +++ b/include/crm/common/logging_compat.h @@ -1,85 +1,89 @@ /* * Copyright 2004-2023 the Pacemaker project contributors * * The version control history for this file may have further details. * * This source code is licensed under the GNU General Public License version 2 * or later (GPLv2+) WITHOUT ANY WARRANTY. */ #ifndef PCMK__CRM_COMMON_LOGGING_COMPAT__H # define PCMK__CRM_COMMON_LOGGING_COMPAT__H +#include // uint8_t #include #include #ifdef __cplusplus extern "C" { #endif /** * \file * \brief Deprecated Pacemaker logging API * \ingroup core * \deprecated Do not include this header directly. Do not use Pacemaker * libraries for general-purpose logging; libqb's logging API is a * suitable replacement. The logging APIs in this header, and the * header itself, will be removed in a future release. */ //! \deprecated This enum will be removed in a future release enum xml_log_options { xml_log_option_filtered = 0x0001, xml_log_option_formatted = 0x0002, xml_log_option_text = 0x0004, xml_log_option_full_fledged = 0x0008, xml_log_option_diff_plus = 0x0010, xml_log_option_diff_minus = 0x0020, xml_log_option_diff_short = 0x0040, xml_log_option_diff_all = 0x0100, xml_log_option_dirty_add = 0x1000, xml_log_option_open = 0x2000, xml_log_option_children = 0x4000, xml_log_option_close = 0x8000, }; /*! * \brief Log a message using constant priority * * \param[in] level Priority at which to log the message * \param[in] fmt printf-style format string literal for message * \param[in] args Any arguments needed by format string * * \deprecated Do not use Pacemaker for general-purpose logging * \note This is a macro, and \p level may be evaluated more than once. * This does nothing when level is LOG_STDOUT. */ # define do_crm_log_always(level, fmt, args...) do { \ switch (level) { \ case LOG_STDOUT: case LOG_NEVER: \ break; \ default: \ qb_log((level), fmt , ##args); \ break; \ } \ } while (0) //! \deprecated Do not use Pacemaker for general-purpose string handling #define crm_str(x) (const char *) ((x)? (x) : "") //! \deprecated Do not use Pacemaker for general-purpose logging gboolean crm_log_cli_init(const char *entity); //! \deprecated Do not use Pacemaker for general-purpose logging gboolean crm_add_logfile(const char *filename); //! \deprecated Do not use Pacemaker for general-purpose logging void log_data_element(int log_level, const char *file, const char *function, int line, const char *prefix, const xmlNode *data, int depth, int legacy_options); +//! \deprecated Do not use Pacemaker for general-purpose logging +void pcmk_log_xml_impl(uint8_t level, const char *text, const xmlNode *xml); + #ifdef __cplusplus } #endif #endif // PCMK__CRM_COMMON_LOGGING_COMPAT__H diff --git a/include/crm/common/output_internal.h b/include/crm/common/output_internal.h index e7b631e574..274bd852bc 100644 --- a/include/crm/common/output_internal.h +++ b/include/crm/common/output_internal.h @@ -1,989 +1,994 @@ /* * Copyright 2019-2023 the Pacemaker project contributors * * The version control history for this file may have further details. * * This source code is licensed under the GNU Lesser General Public License * version 2.1 or later (LGPLv2.1+) WITHOUT ANY WARRANTY. */ #ifndef PCMK__OUTPUT_INTERNAL__H # define PCMK__OUTPUT_INTERNAL__H # include # include # include # include # include # include # include #ifdef __cplusplus extern "C" { #endif /** * \file * \brief Formatted output for pacemaker tools */ #if defined(PCMK__WITH_ATTRIBUTE_OUTPUT_ARGS) # define PCMK__OUTPUT_ARGS(ARGS...) __attribute__((output_args(ARGS))) #else # define PCMK__OUTPUT_ARGS(ARGS...) #endif typedef struct pcmk__output_s pcmk__output_t; /*! * \internal * \brief The type of a function that creates a ::pcmk__output_t. * * Instances of this type are passed to pcmk__register_format(), stored in an * internal data structure, and later accessed by pcmk__output_new(). For * examples, see pcmk__mk_xml_output() and pcmk__mk_text_output(). * * \param[in] argv The list of command line arguments. */ typedef pcmk__output_t * (*pcmk__output_factory_t)(char **argv); /*! * \internal * \brief The type of a custom message formatting function. * * These functions are defined by various libraries to support formatting of * types aside from the basic types provided by a ::pcmk__output_t. * * The meaning of the return value will be different for each message. * In general, however, 0 should be returned on success and a positive value * on error. * * \param[in,out] out Output object to use to display message * \param[in,out] args Message-specific arguments needed * * \note These functions must not call va_start or va_end - that is done * automatically before the custom formatting function is called. */ typedef int (*pcmk__message_fn_t)(pcmk__output_t *out, va_list args); /*! * \internal * \brief Internal type for tracking custom messages. * * Each library can register functions that format custom message types. These * are commonly used to handle some library-specific type. Registration is * done by first defining a table of ::pcmk__message_entry_t structures and * then passing that table to pcmk__register_messages(). Separate handlers * can be defined for the same message, but for different formats (xml vs. * text). Unknown formats will be ignored. * * Additionally, a "default" value for fmt_table can be used. In this case, * fn will be registered for all supported formats. It is also possible to * register a default and then override that registration with a format-specific * function if necessary. * * \note The ::pcmk__message_entry_t table is processed in one pass, in order, * from top to bottom. This means later entries with the same message_id will * override previous ones. Thus, any default entry must come before any * format-specific entries for the same message_id. */ typedef struct pcmk__message_entry_s { /*! * \brief The message to be handled. * * This must be the same ID that is passed to the message function of * a ::pcmk__output_t. Unknown message IDs will be ignored. */ const char *message_id; /*! * \brief The format type this handler is for. * * This name must match the fmt_name of the currently active formatter in * order for the registered function to be called. It is valid to have * multiple entries for the same message_id but with different fmt_name * values. */ const char *fmt_name; /*! * \brief The function to be called for message_id given a match on * fmt_name. See comments on ::pcmk__message_fn_t. */ pcmk__message_fn_t fn; } pcmk__message_entry_t; /*! * \internal * \brief This structure contains everything needed to add support for a * single output formatter to a command line program. */ typedef struct pcmk__supported_format_s { /*! * \brief The name of this output formatter, which should match the * fmt_name parameter in some ::pcmk__output_t structure. */ const char *name; /*! * \brief A function that creates a ::pcmk__output_t. */ pcmk__output_factory_t create; /*! * \brief Format-specific command line options. This can be NULL if * no command line options should be supported. */ GOptionEntry *options; } pcmk__supported_format_t; /* The following three blocks need to be updated each time a new base formatter * is added. */ extern GOptionEntry pcmk__html_output_entries[]; extern GOptionEntry pcmk__log_output_entries[]; extern GOptionEntry pcmk__none_output_entries[]; extern GOptionEntry pcmk__text_output_entries[]; extern GOptionEntry pcmk__xml_output_entries[]; pcmk__output_t *pcmk__mk_html_output(char **argv); pcmk__output_t *pcmk__mk_log_output(char **argv); pcmk__output_t *pcmk__mk_none_output(char **argv); pcmk__output_t *pcmk__mk_text_output(char **argv); pcmk__output_t *pcmk__mk_xml_output(char **argv); #define PCMK__SUPPORTED_FORMAT_HTML { "html", pcmk__mk_html_output, pcmk__html_output_entries } #define PCMK__SUPPORTED_FORMAT_LOG { "log", pcmk__mk_log_output, pcmk__log_output_entries } #define PCMK__SUPPORTED_FORMAT_NONE { PCMK__VALUE_NONE, pcmk__mk_none_output, \ pcmk__none_output_entries } #define PCMK__SUPPORTED_FORMAT_TEXT { "text", pcmk__mk_text_output, pcmk__text_output_entries } #define PCMK__SUPPORTED_FORMAT_XML { "xml", pcmk__mk_xml_output, pcmk__xml_output_entries } /*! * \brief This structure contains everything that makes up a single output * formatter. * * Instances of this structure may be created by calling pcmk__output_new() * with the name of the desired formatter. They should later be freed with * pcmk__output_free(). */ struct pcmk__output_s { /*! * \brief The name of this output formatter. */ const char *fmt_name; /*! * \brief Should this formatter supress most output? * * \note This setting is not respected by all formatters. In general, * machine-readable output formats will not support this while * user-oriented formats will. Callers should use is_quiet() * to test whether to print or not. */ bool quiet; /*! * \brief A copy of the request that generated this output. * * In the case of command line usage, this would be the command line * arguments. For other use cases, it could be different. */ gchar *request; /*! * \brief Where output should be written. * * This could be a file handle, or stdout or stderr. This is really only * useful internally. */ FILE *dest; /*! * \brief Custom messages that are currently registered on this formatter. * * Keys are the string message IDs, values are ::pcmk__message_fn_t function * pointers. */ GHashTable *messages; /*! * \brief Implementation-specific private data. * * Each individual formatter may have some private data useful in its * implementation. This points to that data. Callers should not rely on * its contents or structure. */ void *priv; /*! * \internal * \brief Take whatever actions are necessary to prepare out for use. This is * called by pcmk__output_new(). End users should not need to call this. * * \note For formatted output implementers - This function should be written in * such a way that it can be called repeatedly on an already initialized * object without causing problems, or on a previously finished object * without crashing. * * \param[in,out] out The output functions structure. * * \return true on success, false on error. */ bool (*init) (pcmk__output_t *out); /*! * \internal * \brief Free the private formatter-specific data. * * This is called from pcmk__output_free() and does not typically need to be * called directly. * * \param[in,out] out The output functions structure. */ void (*free_priv) (pcmk__output_t *out); /*! * \internal * \brief Take whatever actions are necessary to end formatted output. * * This could include flushing output to a file, but does not include freeing * anything. The finish method can potentially be fairly complicated, adding * additional information to the internal data structures or doing whatever * else. It is therefore suggested that finish only be called once. * * \note The print parameter will only affect those formatters that do all * their output at the end. Console-oriented formatters typically print * a line at a time as they go, so this parameter will not affect them. * Structured formatters will honor it, however. * * \note The copy_dest parameter does not apply to all formatters. Console- * oriented formatters do not build up a structure as they go, and thus * do not have anything to return. Structured formatters will honor it, * however. Note that each type of formatter will return a different * type of value in this parameter. To use this parameter, call this * function like so: * * \code * xmlNode *dest = NULL; * out->finish(out, exit_code, false, (void **) &dest); * \endcode * * \param[in,out] out The output functions structure. * \param[in] exit_status The exit value of the whole program. * \param[in] print Whether this function should write any output. * \param[out] copy_dest A destination to store a copy of the internal * data structure for this output, or NULL if no * copy is required. The caller should free this * memory when done with it. */ void (*finish) (pcmk__output_t *out, crm_exit_t exit_status, bool print, void **copy_dest); /*! * \internal * \brief Finalize output and then immediately set back up to start a new set * of output. * * This is conceptually the same as calling finish and then init, though in * practice more be happening behind the scenes. * * \note This function differs from finish in that no exit_status is added. * The idea is that the program is not shutting down, so there is not * yet a final exit code. Call finish on the last time through if this * is needed. * * \param[in,out] out The output functions structure. */ void (*reset) (pcmk__output_t *out); /*! * \internal * \brief Register a custom message. * * \param[in,out] out The output functions structure. * \param[in] message_id The name of the message to register. This name * will be used as the message_id parameter to the * message function in order to call the custom * format function. * \param[in] fn The custom format function to call for message_id. */ void (*register_message) (pcmk__output_t *out, const char *message_id, pcmk__message_fn_t fn); /*! * \internal * \brief Call a previously registered custom message. * * \param[in,out] out The output functions structure. * \param[in] message_id The name of the message to call. This name must * be the same as the message_id parameter of some * previous call to register_message. * \param[in] ... Arguments to be passed to the registered function. * * \return A standard Pacemaker return code. Generally: 0 if a function was * registered for the message, that function was called, and returned * successfully; EINVAL if no function was registered; or pcmk_rc_no_output * if a function was called but produced no output. */ int (*message) (pcmk__output_t *out, const char *message_id, ...); /*! * \internal * \brief Format the output of a completed subprocess. * * \param[in,out] out The output functions structure. * \param[in] exit_status The exit value of the subprocess. * \param[in] proc_stdout stdout from the completed subprocess. * \param[in] proc_stderr stderr from the completed subprocess. */ void (*subprocess_output) (pcmk__output_t *out, int exit_status, const char *proc_stdout, const char *proc_stderr); /*! * \internal * \brief Format version information. This is useful for the --version * argument of command line tools. * * \param[in,out] out The output functions structure. * \param[in] extended Add additional version information. */ void (*version) (pcmk__output_t *out, bool extended); /*! * \internal * \brief Format an informational message that should be shown to * to an interactive user. Not all formatters will do this. * * \note A newline will automatically be added to the end of the format * string, so callers should not include a newline. * * \note It is possible for a formatter that supports this method to * still not print anything out if is_quiet returns true. * * \param[in,out] out The output functions structure. * \param[in] buf The message to be printed. * \param[in] ... Arguments to be formatted. * * \return A standard Pacemaker return code. Generally: pcmk_rc_ok * if output was produced and pcmk_rc_no_output if it was not. * As not all formatters implement this function, those that * do not will always just return pcmk_rc_no_output. */ int (*info) (pcmk__output_t *out, const char *format, ...) G_GNUC_PRINTF(2, 3); /*! * \internal * \brief Like \p info() but for messages that should appear only * transiently. Not all formatters will do this. * * The originally envisioned use case is for console output, where a * transient status-related message may be quickly overwritten by a refresh. * * \param[in,out] out The output functions structure. * \param[in] format The format string of the message to be printed. * \param[in] ... Arguments to be formatted. * * \return A standard Pacemaker return code. Generally: \p pcmk_rc_ok if * output was produced and \p pcmk_rc_no_output if it was not. As * not all formatters implement this function, those that do not * will always just return \p pcmk_rc_no_output. */ int (*transient) (pcmk__output_t *out, const char *format, ...) G_GNUC_PRINTF(2, 3); /*! * \internal * \brief Format an error message that should be shown to an interactive * user. Not all formatters will do this. * * \note A newline will automatically be added to the end of the format * string, so callers should not include a newline. * * \note Formatters that support this method should always generate output, * even if is_quiet returns true. * * \param[in,out] out The output functions structure. * \param[in] buf The message to be printed. * \param[in] ... Arguments to be formatted. */ void (*err) (pcmk__output_t *out, const char *format, ...) G_GNUC_PRINTF(2, 3); /*! * \internal * \brief Format already formatted XML. * * \param[in,out] out The output functions structure. * \param[in] name A name to associate with the XML. * \param[in] buf The XML in a string. */ void (*output_xml) (pcmk__output_t *out, const char *name, const char *buf); /*! * \internal * \brief Start a new list of items. * * \note For text output, this corresponds to another level of indentation. For * XML output, this corresponds to wrapping any following output in another * layer of tags. * * \note If singular_noun and plural_noun are non-NULL, calling end_list will * result in a summary being added. * * \param[in,out] out The output functions structure. * \param[in] singular_noun When outputting the summary for a list with * one item, the noun to use. * \param[in] plural_noun When outputting the summary for a list with * more than one item, the noun to use. * \param[in] format The format string. * \param[in] ... Arguments to be formatted. */ void (*begin_list) (pcmk__output_t *out, const char *singular_noun, const char *plural_noun, const char *format, ...) G_GNUC_PRINTF(4, 5); /*! * \internal * \brief Format a single item in a list. * * \param[in,out] out The output functions structure. * \param[in] name A name to associate with this item. * \param[in] format The format string. * \param[in] ... Arguments to be formatted. */ void (*list_item) (pcmk__output_t *out, const char *name, const char *format, ...) G_GNUC_PRINTF(3, 4); /*! * \internal * \brief Increment the internal counter of the current list's length. * * Typically, this counter is maintained behind the scenes as a side effect * of calling list_item(). However, custom functions that maintain lists * some other way will need to manage this counter manually. This is * useful for implementing custom message functions and should not be * needed otherwise. * * \param[in,out] out The output functions structure. */ void (*increment_list) (pcmk__output_t *out); /*! * \internal * \brief Conclude a list. * * \note If begin_list was called with non-NULL for both the singular_noun * and plural_noun arguments, this function will output a summary. * Otherwise, no summary will be added. * * \param[in,out] out The output functions structure. */ void (*end_list) (pcmk__output_t *out); /*! * \internal * \brief Should anything be printed to the user? * * \note This takes into account both the \p quiet value as well as the * current formatter. * * \param[in,out] out The output functions structure. * * \return true if output should be supressed, false otherwise. */ bool (*is_quiet) (pcmk__output_t *out); /*! * \internal * \brief Output a spacer. Not all formatters will do this. * * \param[in,out] out The output functions structure. */ void (*spacer) (pcmk__output_t *out); /*! * \internal * \brief Output a progress indicator. This is likely only useful for * plain text, console based formatters. * * \param[in,out] out The output functions structure * \param[in] end If true, output a newline afterwards (this should * only be used the last time this function is called) * */ void (*progress) (pcmk__output_t *out, bool end); /*! * \internal * \brief Prompt the user for input. Not all formatters will do this. * * \note This function is part of pcmk__output_t, but unlike all other * function it does not take that as an argument. In general, a * prompt will go directly to the screen and therefore bypass any * need to use the formatted output code to decide where and how * to display. * * \param[in] prompt The prompt to display. This is required. * \param[in] echo If true, echo the user's input to the screen. Set * to false for password entry. * \param[out] dest Where to store the user's response. This is * required. */ void (*prompt) (const char *prompt, bool echo, char **dest); }; /*! * \internal * \brief Call a formatting function for a previously registered message. * * \note This function is for implementing custom formatters. It should not * be called directly. Instead, call out->message. * * \param[in,out] out The output functions structure. * \param[in] message_id The message to be handled. Unknown messages * will be ignored. * \param[in] ... Arguments to be passed to the registered function. */ int pcmk__call_message(pcmk__output_t *out, const char *message_id, ...); /*! * \internal * \brief Free a ::pcmk__output_t structure that was previously created by * pcmk__output_new(). * * \note While the create and finish functions are designed in such a way that * they can be called repeatedly, this function will completely free the * memory of the object. Once this function has been called, producing * more output requires starting over from pcmk__output_new(). * * \param[in,out] out The output structure. */ void pcmk__output_free(pcmk__output_t *out); /*! * \internal * \brief Create a new ::pcmk__output_t structure. * * This also registers message functions from libcrmcommon. * * \param[in,out] out The destination of the new ::pcmk__output_t. * \param[in] fmt_name How should output be formatted? * \param[in] filename Where should formatted output be written to? This * can be a filename (which will be overwritten if it * already exists), or NULL or "-" for stdout. For no * output, pass a filename of "/dev/null". * \param[in] argv The list of command line arguments. * * \return Standard Pacemaker return code */ int pcmk__output_new(pcmk__output_t **out, const char *fmt_name, const char *filename, char **argv); /*! * \internal * \brief Register a new output formatter, making it available for use * the same as a base formatter. * * \param[in,out] group A ::GOptionGroup that formatted output related command * line arguments should be added to. This can be NULL * for use outside of command line programs. * \param[in] name The name of the format. This will be used to select a * format from command line options and for displaying help. * \param[in] create A function that creates a ::pcmk__output_t. * \param[in] options Format-specific command line options. These will be * added to the context. This argument can also be NULL. * * \return Standard Pacemaker return code */ int pcmk__register_format(GOptionGroup *group, const char *name, pcmk__output_factory_t create, const GOptionEntry *options); /*! * \internal * \brief Register an entire table of output formatters at once. * * \param[in,out] group A ::GOptionGroup that formatted output related command * line arguments should be added to. This can be NULL * for use outside of command line programs. * \param[in] table An array of ::pcmk__supported_format_t which should * all be registered. This array must be NULL-terminated. * */ void pcmk__register_formats(GOptionGroup *group, const pcmk__supported_format_t *table); /*! * \internal * \brief Unregister a previously registered table of custom formatting * functions and destroy the internal data structures associated with them. */ void pcmk__unregister_formats(void); /*! * \internal * \brief Register a function to handle a custom message. * * \note This function is for implementing custom formatters. It should not * be called directly. Instead, call out->register_message. * * \param[in,out] out The output functions structure. * \param[in] message_id The message to be handled. * \param[in] fn The custom format function to call for message_id. */ void pcmk__register_message(pcmk__output_t *out, const char *message_id, pcmk__message_fn_t fn); /*! * \internal * \brief Register an entire table of custom formatting functions at once. * * This table can contain multiple formatting functions for the same message ID * if they are for different format types. * * \param[in,out] out The output functions structure. * \param[in] table An array of ::pcmk__message_entry_t values which should * all be registered. This array must be NULL-terminated. */ void pcmk__register_messages(pcmk__output_t *out, const pcmk__message_entry_t *table); /* Functions that are useful for implementing custom message formatters */ /*! * \internal * \brief A printf-like function. * * This function writes to out->dest and indents the text to the current level * of the text formatter's nesting. This function should be used when implementing * custom message functions for the text output format. It should not be used * for any other purpose. * * Typically, this function should be used instead of printf. * * \param[in,out] out The output functions structure. * \param[in] format The format string. * \param[in] ... Arguments to be passed to the format string. */ void pcmk__indented_printf(pcmk__output_t *out, const char *format, ...) G_GNUC_PRINTF(2, 3); /*! * \internal * \brief A vprintf-like function. * * This function is like pcmk__indented_printf(), except it takes a va_list instead * of a list of arguments. This function should be used when implementing custom * functions for the text output format. It should not be used for any other purpose. * * Typically, this function should be used instead of vprintf. * * \param[in,out] out The output functions structure. * \param[in] format The format string. * \param[in] args A list of arguments to apply to the format string. */ void pcmk__indented_vprintf(pcmk__output_t *out, const char *format, va_list args) G_GNUC_PRINTF(2, 0); /*! * \internal * \brief A printf-like function. * * This function writes to out->dest without indenting the text. This function * should be used when implementing custom message functions for the text output * format. It should not be used for any other purpose. * * \param[in,out] out The output functions structure. * \param[in] format The format string. * \param[in] ... Arguments to be passed to the format string. */ void pcmk__formatted_printf(pcmk__output_t *out, const char *format, ...) G_GNUC_PRINTF(2, 3); /*! * \internal * \brief A vprintf-like function. * * This function is like pcmk__formatted_printf(), except it takes a va_list instead * of a list of arguments. This function should be used when implementing custom * message functions for the text output format. It should not be used for any * other purpose. * * \param[in,out] out The output functions structure. * \param[in] format The format string. * \param[in] args A list of arguments to apply to the format string. */ void pcmk__formatted_vprintf(pcmk__output_t *out, const char *format, va_list args) G_GNUC_PRINTF(2, 0); /*! * \internal * \brief Prompt the user for input. * * \param[in] prompt The prompt to display * \param[in] echo If true, echo the user's input to the screen. Set * to false for password entry. * \param[out] dest Where to store the user's response. */ void pcmk__text_prompt(const char *prompt, bool echo, char **dest); /*! * \internal * \brief Get the log level used by the formatted output logger * * \param[in] out Output object * * \return Log level used by \p out */ uint8_t pcmk__output_get_log_level(const pcmk__output_t *out); /*! * \internal * \brief Set the log level used by the formatted output logger. * * \param[in,out] out The output functions structure. * \param[in] log_level The log level constant (LOG_INFO, LOG_ERR, etc.) * to use. * * \note By default, LOG_INFO is used. * \note Almost all formatted output messages will respect this setting. * However, out->err will always log at LOG_ERR. */ void pcmk__output_set_log_level(pcmk__output_t *out, uint8_t log_level); +void pcmk__output_set_log_filter(pcmk__output_t *out, const char *file, + const char *function, uint32_t line, + uint32_t tags); + + /*! * \internal * \brief Create and return a new XML node with the given name, as a child of the * current list parent. The new node is then added as the new list parent, * meaning all subsequent nodes will be its children. This is used when * implementing custom functions. * * \param[in,out] out The output functions structure. * \param[in] name The name of the node to be created. * \param[in] ... Name/value pairs to set as XML properties. */ xmlNodePtr pcmk__output_xml_create_parent(pcmk__output_t *out, const char *name, ...) G_GNUC_NULL_TERMINATED; /*! * \internal * \brief Add a copy of the given node as a child of the current list parent. * This is used when implementing custom message functions. * * \param[in,out] out The output functions structure. * \param[in] node An XML node to copy as a child. */ void pcmk__output_xml_add_node_copy(pcmk__output_t *out, xmlNodePtr node); /*! * \internal * \brief Create and return a new XML node with the given name, as a child of the * current list parent. This is used when implementing custom functions. * * \param[in,out] out The output functions structure. * \param[in] name The name of the node to be created. * \param[in] ... Name/value pairs to set as XML properties. */ xmlNodePtr pcmk__output_create_xml_node(pcmk__output_t *out, const char *name, ...) G_GNUC_NULL_TERMINATED; /*! * \internal * \brief Like pcmk__output_create_xml_node(), but add the given text content to the * new node. * * \param[in,out] out The output functions structure. * \param[in] name The name of the node to be created. * \param[in] content The text content of the node. */ xmlNodePtr pcmk__output_create_xml_text_node(pcmk__output_t *out, const char *name, const char *content); /*! * \internal * \brief Push a parent XML node onto the stack. This is used when implementing * custom message functions. * * The XML output formatter maintains an internal stack to keep track of which nodes * are parents in order to build up the tree structure. This function can be used * to temporarily push a new node onto the stack. After calling this function, any * other formatting functions will have their nodes added as children of this new * parent. * * \param[in,out] out The output functions structure * \param[in] parent XML node to add */ void pcmk__output_xml_push_parent(pcmk__output_t *out, xmlNodePtr parent); /*! * \internal * \brief Pop a parent XML node onto the stack. This is used when implementing * custom message functions. * * This function removes a parent node from the stack. See pcmk__xml_push_parent() * for more details. * * \note Little checking is done with this function. Be sure you only pop parents * that were previously pushed. In general, it is best to keep the code between * push and pop simple. * * \param[in,out] out The output functions structure. */ void pcmk__output_xml_pop_parent(pcmk__output_t *out); /*! * \internal * \brief Peek a parent XML node onto the stack. This is used when implementing * custom message functions. * * This function peeks a parent node on stack. See pcmk__xml_push_parent() * for more details. It has no side-effect and can be called for an empty stack. * * \note Little checking is done with this function. * * \param[in,out] out The output functions structure. * * \return NULL if stack is empty, otherwise the parent of the stack. */ xmlNodePtr pcmk__output_xml_peek_parent(pcmk__output_t *out); /*! * \internal * \brief Create a new XML node consisting of the provided text inside an HTML * element node of the given name. * * \param[in,out] out The output functions structure. * \param[in] element_name The name of the new HTML element. * \param[in] id The CSS ID selector to apply to this element. * If NULL, no ID is added. * \param[in] class_name The CSS class selector to apply to this element. * If NULL, no class is added. * \param[in] text The text content of the node. */ xmlNodePtr pcmk__output_create_html_node(pcmk__output_t *out, const char *element_name, const char *id, const char *class_name, const char *text); /*! * \internal * \brief Add an HTML tag to the section. * * The arguments after name are a NULL-terminated list of keys and values, * all of which will be added as attributes to the given tag. For instance, * the following code would generate the tag "": * * \code * pcmk__html_add_header("meta", "http-equiv", "refresh", "content", "19", NULL); * \endcode * * \param[in] name The HTML tag for the new node. * \param[in] ... A NULL-terminated key/value list of attributes. */ void pcmk__html_add_header(const char *name, ...) G_GNUC_NULL_TERMINATED; /*! * \internal * \brief Handle end-of-program error reporting * * \param[in,out] error A GError object potentially containing some error. * If NULL, do nothing. * \param[in,out] out The output functions structure. If NULL, any errors * will simply be printed to stderr. */ void pcmk__output_and_clear_error(GError **error, pcmk__output_t *out); int pcmk__xml_output_new(pcmk__output_t **out, xmlNodePtr *xml); void pcmk__xml_output_finish(pcmk__output_t *out, xmlNodePtr *xml); int pcmk__log_output_new(pcmk__output_t **out); int pcmk__text_output_new(pcmk__output_t **out, const char *filename); /*! * \internal * \brief Select an updated return code for an operation on a \p pcmk__output_t * * This function helps to keep an up-to-date record of the most relevant return * code from a series of operations on a \p pcmk__output_t object. For example, * suppose the object has already produced some output, and we've saved a * \p pcmk_rc_ok return code. A new operation did not produce any output and * returned \p pcmk_rc_no_output. We can ignore the new \p pcmk_rc_no_output * return code and keep the previous \p pcmk_rc_ok return code. * * It prioritizes return codes as follows (from highest to lowest priority): * 1. Other return codes (unexpected errors) * 2. \p pcmk_rc_ok * 3. \p pcmk_rc_no_output * * \param[in] old_rc Saved return code from \p pcmk__output_t operations * \param[in] new_rc New return code from a \p pcmk__output_t operation * * \retval \p old_rc \p new_rc is \p pcmk_rc_no_output, or \p new_rc is * \p pcmk_rc_ok and \p old_rc is not \p pcmk_rc_no_output * \retval \p new_rc Otherwise */ static inline int pcmk__output_select_rc(int old_rc, int new_rc) { switch (new_rc) { case pcmk_rc_no_output: return old_rc; case pcmk_rc_ok: switch (old_rc) { case pcmk_rc_no_output: return new_rc; default: return old_rc; } default: return new_rc; } } #if defined(PCMK__UNIT_TESTING) /* If we are building libcrmcommon_test.a, add this accessor function so we can * inspect the internal formatters hash table. */ GHashTable *pcmk__output_formatters(void); #endif #define PCMK__OUTPUT_SPACER_IF(out_obj, cond) \ if (cond) { \ out->spacer(out); \ } #define PCMK__OUTPUT_LIST_HEADER(out_obj, cond, retcode, title...) \ if (retcode == pcmk_rc_no_output) { \ PCMK__OUTPUT_SPACER_IF(out_obj, cond); \ retcode = pcmk_rc_ok; \ out_obj->begin_list(out_obj, NULL, NULL, title); \ } #define PCMK__OUTPUT_LIST_FOOTER(out_obj, retcode) \ if (retcode == pcmk_rc_ok) { \ out_obj->end_list(out_obj); \ } #ifdef __cplusplus } #endif #endif diff --git a/lib/common/logging.c b/lib/common/logging.c index dded87307a..24d1ffe595 100644 --- a/lib/common/logging.c +++ b/lib/common/logging.c @@ -1,1192 +1,1205 @@ /* * Copyright 2004-2023 the Pacemaker project contributors * * The version control history for this file may have further details. * * This source code is licensed under the GNU Lesser General Public License * version 2.1 or later (LGPLv2.1+) WITHOUT ANY WARRANTY. */ #include #include #include #include #include #include #include #include #include #include #include #include #include #include #include #include #include #include #include #include #include // Use high-resolution (millisecond) timestamps if libqb supports them #ifdef QB_FEATURE_LOG_HIRES_TIMESTAMPS #define TIMESTAMP_FORMAT_SPEC "%%T" typedef struct timespec *log_time_t; #else #define TIMESTAMP_FORMAT_SPEC "%%t" typedef time_t log_time_t; #endif unsigned int crm_log_level = LOG_INFO; unsigned int crm_trace_nonlog = 0; bool pcmk__is_daemon = false; char *pcmk__our_nodename = NULL; static unsigned int crm_log_priority = LOG_NOTICE; static GLogFunc glib_log_default = NULL; static pcmk__output_t *logger_out = NULL; static gboolean crm_tracing_enabled(void); 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); static struct qb_log_callsite *glib_cs = NULL; if (glib_cs == NULL) { glib_cs = qb_log_callsite_get(__func__, __FILE__, "glib-handler", LOG_DEBUG, __LINE__, crm_trace_nonlog); } switch (msg_level) { case G_LOG_LEVEL_CRITICAL: log_level = LOG_CRIT; if (!crm_is_callsite_active(glib_cs, LOG_DEBUG, crm_trace_nonlog)) { /* log and record how we got here */ crm_abort(__FILE__, __func__, __LINE__, message, TRUE, TRUE); } break; 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); } #ifndef NAME_MAX # define NAME_MAX 256 #endif /*! * \internal * \brief Write out a blackbox (enabling blackboxes if needed) * * \param[in] nsig Signal number that was received * * \note This is a true signal handler, and so must be async-safe. */ static void crm_trigger_blackbox(int nsig) { if(nsig == SIGTRAP) { /* Turn it on if it wasn't already */ crm_enable_blackbox(nsig); } crm_write_blackbox(nsig, NULL); } void crm_log_deinit(void) { if (glib_log_default != NULL) { g_log_set_default_handler(glib_log_default, NULL); } } #define FMT_MAX 256 /*! * \internal * \brief Set the log format string based on the passed-in method * * \param[in] method The detail level of the log output * \param[in] daemon The daemon ID included in error messages * \param[in] use_pid Cached result of getpid() call, for efficiency * \param[in] use_nodename Cached result of uname() call, for efficiency * */ /* XXX __attribute__((nonnull)) for use_nodename parameter */ static void set_format_string(int method, const char *daemon, pid_t use_pid, const char *use_nodename) { if (method == QB_LOG_SYSLOG) { // The system log gets a simplified, user-friendly format crm_extended_logging(method, QB_FALSE); qb_log_format_set(method, "%g %p: %b"); } else { // Everything else gets more detail, for advanced troubleshooting int offset = 0; char fmt[FMT_MAX]; if (method > QB_LOG_STDERR) { // If logging to file, prefix with timestamp, node name, daemon ID offset += snprintf(fmt + offset, FMT_MAX - offset, TIMESTAMP_FORMAT_SPEC " %s %-20s[%lu] ", use_nodename, daemon, (unsigned long) use_pid); } // Add function name (in parentheses) offset += snprintf(fmt + offset, FMT_MAX - offset, "(%%n"); if (crm_tracing_enabled()) { // When tracing, add file and line number offset += snprintf(fmt + offset, FMT_MAX - offset, "@%%f:%%l"); } offset += snprintf(fmt + offset, FMT_MAX - offset, ")"); // Add tag (if any), severity, and actual message offset += snprintf(fmt + offset, FMT_MAX - offset, " %%g\t%%p: %%b"); CRM_LOG_ASSERT(offset > 0); qb_log_format_set(method, fmt); } } #define DEFAULT_LOG_FILE CRM_LOG_DIR "/pacemaker.log" static bool logfile_disabled(const char *filename) { return pcmk__str_eq(filename, PCMK__VALUE_NONE, pcmk__str_casei) || pcmk__str_eq(filename, "/dev/null", pcmk__str_none); } /*! * \internal * \brief Fix log file ownership if group is wrong or doesn't have access * * \param[in] filename Log file name (for logging only) * \param[in] logfd Log file descriptor * * \return Standard Pacemaker return code */ static int chown_logfile(const char *filename, int logfd) { uid_t pcmk_uid = 0; gid_t pcmk_gid = 0; struct stat st; int rc; // Get the log file's current ownership and permissions if (fstat(logfd, &st) < 0) { return errno; } // Any other errors don't prevent file from being used as log rc = pcmk_daemon_user(&pcmk_uid, &pcmk_gid); if (rc != pcmk_ok) { rc = pcmk_legacy2rc(rc); crm_warn("Not changing '%s' ownership because user information " "unavailable: %s", filename, pcmk_rc_str(rc)); return pcmk_rc_ok; } if ((st.st_gid == pcmk_gid) && ((st.st_mode & S_IRWXG) == (S_IRGRP|S_IWGRP))) { return pcmk_rc_ok; } if (fchown(logfd, pcmk_uid, pcmk_gid) < 0) { crm_warn("Couldn't change '%s' ownership to user %s gid %d: %s", filename, CRM_DAEMON_USER, pcmk_gid, strerror(errno)); } return pcmk_rc_ok; } // Reset log file permissions (using environment variable if set) static void chmod_logfile(const char *filename, int logfd) { const char *modestr = getenv("PCMK_logfile_mode"); mode_t filemode = S_IRUSR | S_IWUSR | S_IRGRP | S_IWGRP; if (modestr != NULL) { long filemode_l = strtol(modestr, NULL, 8); if ((filemode_l != LONG_MIN) && (filemode_l != LONG_MAX)) { filemode = (mode_t) filemode_l; } } if ((filemode != 0) && (fchmod(logfd, filemode) < 0)) { crm_warn("Couldn't change '%s' mode to %04o: %s", filename, filemode, strerror(errno)); } } // If we're root, correct a log file's permissions if needed static int set_logfile_permissions(const char *filename, FILE *logfile) { if (geteuid() == 0) { int logfd = fileno(logfile); int rc = chown_logfile(filename, logfd); if (rc != pcmk_rc_ok) { return rc; } chmod_logfile(filename, logfd); } return pcmk_rc_ok; } // Enable libqb logging to a new log file static void enable_logfile(int fd) { qb_log_ctl(fd, QB_LOG_CONF_ENABLED, QB_TRUE); #if 0 qb_log_ctl(fd, QB_LOG_CONF_FILE_SYNC, 1); // Turn on synchronous writes #endif #ifdef HAVE_qb_log_conf_QB_LOG_CONF_MAX_LINE_LEN // Longer than default, for logging long XML lines qb_log_ctl(fd, QB_LOG_CONF_MAX_LINE_LEN, 800); #endif crm_update_callsites(); } static inline void disable_logfile(int fd) { qb_log_ctl(fd, QB_LOG_CONF_ENABLED, QB_FALSE); } static void setenv_logfile(const char *filename) { // Some resource agents will log only if environment variable is set if (pcmk__env_option(PCMK__ENV_LOGFILE) == NULL) { pcmk__set_env_option(PCMK__ENV_LOGFILE, filename); } } /*! * \brief Add a file to be used as a Pacemaker detail log * * \param[in] filename Name of log file to use * * \return Standard Pacemaker return code */ int pcmk__add_logfile(const char *filename) { /* No log messages from this function will be logged to the new log! * If another target such as syslog has already been added, the messages * should show up there. */ int fd = 0; int rc = pcmk_rc_ok; FILE *logfile = NULL; bool is_default = false; static int default_fd = -1; static bool have_logfile = false; // Use default if caller didn't specify (and we don't already have one) if (filename == NULL) { if (have_logfile) { return pcmk_rc_ok; } filename = DEFAULT_LOG_FILE; } // If the user doesn't want logging, we're done if (logfile_disabled(filename)) { return pcmk_rc_ok; } // If the caller wants the default and we already have it, we're done is_default = pcmk__str_eq(filename, DEFAULT_LOG_FILE, pcmk__str_none); if (is_default && (default_fd >= 0)) { return pcmk_rc_ok; } // Check whether we have write access to the file logfile = fopen(filename, "a"); if (logfile == NULL) { rc = errno; crm_warn("Logging to '%s' is disabled: %s " CRM_XS " uid=%u gid=%u", filename, strerror(rc), geteuid(), getegid()); return rc; } rc = set_logfile_permissions(filename, logfile); if (rc != pcmk_rc_ok) { crm_warn("Logging to '%s' is disabled: %s " CRM_XS " permissions", filename, strerror(rc)); fclose(logfile); return rc; } // Close and reopen as libqb logging target fclose(logfile); fd = qb_log_file_open(filename); if (fd < 0) { crm_warn("Logging to '%s' is disabled: %s " CRM_XS " qb_log_file_open", filename, strerror(-fd)); return -fd; // == +errno } if (is_default) { default_fd = fd; setenv_logfile(filename); } else if (default_fd >= 0) { crm_notice("Switching logging to %s", filename); disable_logfile(default_fd); } crm_notice("Additional logging available in %s", filename); enable_logfile(fd); have_logfile = true; return pcmk_rc_ok; } /*! * \brief Add multiple additional log files * * \param[in] log_files Array of log files to add * \param[in] out Output object to use for error reporting * * \return Standard Pacemaker return code */ void pcmk__add_logfiles(gchar **log_files, pcmk__output_t *out) { if (log_files == NULL) { return; } for (gchar **fname = log_files; *fname != NULL; fname++) { int rc = pcmk__add_logfile(*fname); if (rc != pcmk_rc_ok) { out->err(out, "Logging to %s is disabled: %s", *fname, pcmk_rc_str(rc)); } } } static int blackbox_trigger = 0; static volatile char *blackbox_file_prefix = NULL; static void blackbox_logger(int32_t t, struct qb_log_callsite *cs, log_time_t timestamp, const char *msg) { if(cs && cs->priority < LOG_ERR) { crm_write_blackbox(SIGTRAP, cs); /* Bypass the over-dumping logic */ } else { crm_write_blackbox(0, cs); } } static void crm_control_blackbox(int nsig, bool enable) { int lpc = 0; if (blackbox_file_prefix == NULL) { pid_t pid = getpid(); blackbox_file_prefix = crm_strdup_printf("%s/%s-%lu", CRM_BLACKBOX_DIR, crm_system_name, (unsigned long) pid); } if (enable && 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 */ /* Enable synchronous logging */ for (lpc = QB_LOG_BLACKBOX; lpc < QB_LOG_TARGET_MAX; lpc++) { qb_log_ctl(lpc, QB_LOG_CONF_FILE_SYNC, QB_TRUE); } crm_notice("Initiated blackbox recorder: %s", blackbox_file_prefix); /* Save to disk on abnormal termination */ crm_signal_handler(SIGSEGV, crm_trigger_blackbox); crm_signal_handler(SIGABRT, crm_trigger_blackbox); crm_signal_handler(SIGILL, crm_trigger_blackbox); crm_signal_handler(SIGBUS, crm_trigger_blackbox); crm_signal_handler(SIGFPE, crm_trigger_blackbox); crm_update_callsites(); blackbox_trigger = qb_log_custom_open(blackbox_logger, NULL, NULL, NULL); qb_log_ctl(blackbox_trigger, QB_LOG_CONF_ENABLED, QB_TRUE); crm_trace("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(); } else if (!enable && 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_ENABLED, QB_FALSE); /* Disable synchronous logging again when the blackbox is disabled */ for (lpc = QB_LOG_BLACKBOX; lpc < QB_LOG_TARGET_MAX; lpc++) { qb_log_ctl(lpc, QB_LOG_CONF_FILE_SYNC, QB_FALSE); } } } void crm_enable_blackbox(int nsig) { crm_control_blackbox(nsig, TRUE); } void crm_disable_blackbox(int nsig) { crm_control_blackbox(nsig, FALSE); } /*! * \internal * \brief Write out a blackbox, if blackboxes are enabled * * \param[in] nsig Signal that was received * \param[in] cs libqb callsite * * \note This may be called via a true signal handler and so must be async-safe. * @TODO actually make this async-safe */ void crm_write_blackbox(int nsig, const struct qb_log_callsite *cs) { static volatile int counter = 1; static volatile time_t last = 0; char buffer[NAME_MAX]; time_t now = time(NULL); if (blackbox_file_prefix == NULL) { return; } switch (nsig) { case 0: 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_handler(nsig, SIG_DFL); qb_log_blackbox_write_to_file((const char *)blackbox_file_prefix); qb_log_ctl(QB_LOG_BLACKBOX, QB_LOG_CONF_ENABLED, QB_FALSE); raise(nsig); break; } } 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 = crm_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, sizeof(token), "%.*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, uint8_t level, uint32_t 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 (pcmk__str_eq(p_names[lpc].name, name, pcmk__str_none)) { return p_names[lpc].priority; } } return crm_log_priority; } /*! * \internal * \brief Set the identifier for the current process * * If the identifier crm_system_name is not already set, then it is set as follows: * - it is passed to the function via the "entity" parameter, or * - it is derived from the executable name * * The identifier can be used in logs, IPC, and more. * * This method also sets the PCMK_service environment variable. * * \param[in] entity If not NULL, will be assigned to the identifier * \param[in] argc The number of command line parameters * \param[in] argv The command line parameter values */ static void set_identity(const char *entity, int argc, char *const *argv) { if (crm_system_name != NULL) { return; // Already set, don't overwrite } if (entity != NULL) { crm_system_name = strdup(entity); } else if ((argc > 0) && (argv != NULL)) { char *mutable = strdup(argv[0]); char *modified = basename(mutable); if (strstr(modified, "lt-") == modified) { modified += 3; } crm_system_name = strdup(modified); free(mutable); } else { crm_system_name = strdup("Unknown"); } CRM_ASSERT(crm_system_name != NULL); setenv("PCMK_service", crm_system_name, 1); } void crm_log_preinit(const char *entity, int argc, char *const *argv) { /* Configure libqb logging with nothing turned on */ struct utsname res; int lpc = 0; int32_t qb_facility = 0; pid_t pid = getpid(); const char *nodename = "localhost"; static bool have_logging = false; if (have_logging) { return; } have_logging = true; crm_xml_init(); /* Sets buffer allocation strategy */ 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 */ glib_log_default = g_log_set_default_handler(crm_glib_handler, NULL); /* and for good measure... - this enum is a bit field (!) */ g_log_set_always_fatal((GLogLevelFlags) 0); /*value out of range */ /* Set crm_system_name, which is used as the logging name. It may also * be used for other purposes such as an IPC client name. */ set_identity(entity, argc, argv); qb_facility = qb_log_facility2int("local0"); qb_log_init(crm_system_name, qb_facility, LOG_ERR); crm_log_level = LOG_CRIT; /* Nuke any syslog activity until it's asked for */ qb_log_ctl(QB_LOG_SYSLOG, QB_LOG_CONF_ENABLED, QB_FALSE); #ifdef HAVE_qb_log_conf_QB_LOG_CONF_MAX_LINE_LEN // Shorter than default, generous for what we *should* send to syslog qb_log_ctl(QB_LOG_SYSLOG, QB_LOG_CONF_MAX_LINE_LEN, 256); #endif if (uname(memset(&res, 0, sizeof(res))) == 0 && *res.nodename != '\0') { nodename = res.nodename; } /* Set format strings and disable threading * Pacemaker and threads do not mix well (due to the amount of forking) */ qb_log_tags_stringify_fn_set(crm_quark_to_string); for (lpc = QB_LOG_SYSLOG; lpc < QB_LOG_TARGET_MAX; lpc++) { qb_log_ctl(lpc, QB_LOG_CONF_THREADED, QB_FALSE); #ifdef HAVE_qb_log_conf_QB_LOG_CONF_ELLIPSIS // End truncated lines with '...' qb_log_ctl(lpc, QB_LOG_CONF_ELLIPSIS, QB_TRUE); #endif set_format_string(lpc, crm_system_name, pid, nodename); } #ifdef ENABLE_NLS /* Enable translations (experimental). Currently we only have a few * proof-of-concept translations for some option help. The goal would be to * offer translations for option help and man pages rather than logs or * documentation, to reduce the burden of maintaining them. */ // Load locale information for the local host from the environment setlocale(LC_ALL, ""); // Tell gettext where to find Pacemaker message catalogs CRM_ASSERT(bindtextdomain(PACKAGE, PCMK__LOCALE_DIR) != NULL); // Tell gettext to use the Pacemaker message catalogs CRM_ASSERT(textdomain(PACKAGE) != NULL); // Tell gettext that the translated strings are stored in UTF-8 bind_textdomain_codeset(PACKAGE, "UTF-8"); #endif } gboolean crm_log_init(const char *entity, uint8_t level, gboolean daemon, gboolean to_stderr, int argc, char **argv, gboolean quiet) { const char *syslog_priority = NULL; const char *facility = pcmk__env_option(PCMK__ENV_LOGFACILITY); const char *f_copy = facility; pcmk__is_daemon = daemon; crm_log_preinit(entity, argc, argv); if (level > LOG_TRACE) { level = LOG_TRACE; } if(level > crm_log_level) { crm_log_level = level; } /* Should we log to syslog */ if (facility == NULL) { if (pcmk__is_daemon) { facility = "daemon"; } else { facility = PCMK__VALUE_NONE; } pcmk__set_env_option(PCMK__ENV_LOGFACILITY, facility); } if (pcmk__str_eq(facility, PCMK__VALUE_NONE, pcmk__str_casei)) { quiet = TRUE; } else { qb_log_ctl(QB_LOG_SYSLOG, QB_LOG_CONF_FACILITY, qb_log_facility2int(facility)); } if (pcmk__env_option_enabled(crm_system_name, PCMK__ENV_DEBUG)) { /* Override the default setting */ crm_log_level = LOG_DEBUG; } /* What lower threshold do we have for sending to syslog */ syslog_priority = pcmk__env_option(PCMK__ENV_LOGPRIORITY); if (syslog_priority) { crm_log_priority = crm_priority2int(syslog_priority); } qb_log_filter_ctl(QB_LOG_SYSLOG, QB_LOG_FILTER_ADD, QB_LOG_FILTER_FILE, "*", crm_log_priority); // Log to syslog unless requested to be quiet if (!quiet) { qb_log_ctl(QB_LOG_SYSLOG, QB_LOG_CONF_ENABLED, QB_TRUE); } /* Should we log to stderr */ if (pcmk__env_option_enabled(crm_system_name, PCMK__ENV_STDERR)) { /* Override the default setting */ to_stderr = TRUE; } crm_enable_stderr(to_stderr); // Log to a file if we're a daemon or user asked for one { const char *logfile = pcmk__env_option(PCMK__ENV_LOGFILE); if (!pcmk__str_eq(PCMK__VALUE_NONE, logfile, pcmk__str_casei) && (pcmk__is_daemon || (logfile != NULL))) { // Daemons always get a log file, unless explicitly set to "none" pcmk__add_logfile(logfile); } } if (pcmk__is_daemon && pcmk__env_option_enabled(crm_system_name, PCMK__ENV_BLACKBOX)) { crm_enable_blackbox(0); } /* Summary */ crm_trace("Quiet: %d, facility %s", quiet, f_copy); pcmk__env_option(PCMK__ENV_LOGFILE); pcmk__env_option(PCMK__ENV_LOGFACILITY); crm_update_callsites(); /* Ok, now we can start logging... */ // Disable daemon request if user isn't root or Pacemaker daemon user if (pcmk__is_daemon) { const char *user = getenv("USER"); if (user != NULL && !pcmk__strcase_any_of(user, "root", CRM_DAEMON_USER, NULL)) { crm_trace("Not switching to corefile directory for %s", user); pcmk__is_daemon = false; } } if (pcmk__is_daemon) { int user = getuid(); struct passwd *pwent = getpwuid(user); if (pwent == NULL) { crm_perror(LOG_ERR, "Cannot get name for uid: %d", user); } else if (!pcmk__strcase_any_of(pwent->pw_name, "root", CRM_DAEMON_USER, NULL)) { crm_trace("Don't change active directory for regular user: %s", pwent->pw_name); } else if (chdir(CRM_CORE_DIR) < 0) { crm_perror(LOG_INFO, "Cannot change active directory to " CRM_CORE_DIR); } else { crm_info("Changed active directory to " CRM_CORE_DIR); } /* Original meanings from signal(7) * * Signal Value Action Comment * SIGTRAP 5 Core Trace/breakpoint trap * SIGUSR1 30,10,16 Term User-defined signal 1 * SIGUSR2 31,12,17 Term User-defined signal 2 * * Our usage is as similar as possible */ mainloop_add_signal(SIGUSR1, crm_enable_blackbox); mainloop_add_signal(SIGUSR2, crm_disable_blackbox); mainloop_add_signal(SIGTRAP, crm_trigger_blackbox); } else if (!quiet) { crm_log_args(argc, argv); } return TRUE; } /* returns the old value */ unsigned int set_crm_log_level(unsigned int level) { unsigned int old = crm_log_level; if (level > LOG_TRACE) { level = LOG_TRACE; } 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); } } /*! * \brief Make logging more verbose * * If logging to stderr is not already enabled when this function is called, * enable it. Otherwise, increase the log level by 1. * * \param[in] argc Ignored * \param[in] argv Ignored */ void crm_bump_log_level(int argc, char **argv) { if (qb_log_ctl(QB_LOG_STDERR, QB_LOG_CONF_STATE_GET, 0) != QB_LOG_STATE_ENABLED) { crm_enable_stderr(TRUE); } else { set_crm_log_level(crm_log_level + 1); } } unsigned int get_crm_log_level(void) { return crm_log_level; } /*! * \brief Log the command line (once) * * \param[in] Number of values in \p argv * \param[in] Command-line arguments (including command name) * * \note This function will only log once, even if called with different * arguments. */ void crm_log_args(int argc, char **argv) { static bool logged = false; gchar *arg_string = NULL; if ((argc == 0) || (argv == NULL) || logged) { return; } logged = true; arg_string = g_strjoinv(" ", argv); crm_notice("Invoked: %s", arg_string); g_free(arg_string); } 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 (level == LOG_NEVER) { return; } if (output == NULL) { if (level != LOG_STDOUT) { level = LOG_TRACE; } output = "-- empty --"; } 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); } void pcmk__cli_init_logging(const char *name, unsigned int verbosity) { crm_log_init(name, LOG_ERR, FALSE, FALSE, 0, NULL, TRUE); for (int i = 0; i < verbosity; i++) { /* These arguments are ignored, so pass placeholders. */ crm_bump_log_level(0, NULL); } } /*! * \brief Log XML line-by-line in a formatted fashion * - * \param[in] level Priority at which to log the messages - * \param[in] text Prefix for each line - * \param[in] xml XML to log + * \param[in] file File name to use for log filtering + * \param[in] function Function name to use for log filtering + * \param[in] line Line number to use for log filtering + * \param[in] tags Logging tags to use for log filtering + * \param[in] level Priority at which to log the messages + * \param[in] text Prefix for each line + * \param[in] xml XML to log * * \note This does nothing when \p level is \p LOG_STDOUT. * \note Do not call this function directly. It should be called only from the * \p do_crm_log_xml() macro. */ void -pcmk_log_xml_impl(uint8_t level, const char *text, const xmlNode *xml) +pcmk_log_xml_as(const char *file, const char *function, uint32_t line, + uint32_t tags, uint8_t level, const char *text, const xmlNode *xml) { if (xml == NULL) { do_crm_log(level, "%s%sNo data to dump as XML", pcmk__s(text, ""), pcmk__str_empty(text)? "" : " "); } else { if (logger_out == NULL) { CRM_CHECK(pcmk__log_output_new(&logger_out) == pcmk_rc_ok, return); } pcmk__output_set_log_level(logger_out, level); + pcmk__output_set_log_filter(logger_out, file, function, line, tags); pcmk__xml_show(logger_out, text, xml, 1, pcmk__xml_fmt_pretty |pcmk__xml_fmt_open |pcmk__xml_fmt_children |pcmk__xml_fmt_close); + pcmk__output_set_log_filter(logger_out, NULL, NULL, 0U, 0U); } } /*! * \internal * \brief Free the logging library's internal log output object */ void pcmk__free_common_logger(void) { if (logger_out != NULL) { logger_out->finish(logger_out, CRM_EX_OK, true, NULL); pcmk__output_free(logger_out); logger_out = NULL; } } // Deprecated functions kept only for backward API compatibility // LCOV_EXCL_START #include gboolean crm_log_cli_init(const char *entity) { pcmk__cli_init_logging(entity, 0); return TRUE; } gboolean crm_add_logfile(const char *filename) { return pcmk__add_logfile(filename) == pcmk_rc_ok; } +void +pcmk_log_xml_impl(uint8_t level, const char *text, const xmlNode *xml) +{ + pcmk_log_xml_as(__FILE__, __func__, __LINE__, 0, level, text, xml); +} + // LCOV_EXCL_STOP // End deprecated API diff --git a/lib/common/output_log.c b/lib/common/output_log.c index aca168d0b4..54fa37eece 100644 --- a/lib/common/output_log.c +++ b/lib/common/output_log.c @@ -1,353 +1,407 @@ /* * Copyright 2019-2023 the Pacemaker project contributors * * The version control history for this file may have further details. * * This source code is licensed under the GNU Lesser General Public License * version 2.1 or later (LGPLv2.1+) WITHOUT ANY WARRANTY. */ #include #include #include #include +#include #include #include GOptionEntry pcmk__log_output_entries[] = { { NULL } }; typedef struct private_data_s { /* gathered in log_begin_list */ GQueue/**/ *prefixes; uint8_t log_level; + const char *function; + const char *file; + uint32_t line; + uint32_t tags; } private_data_t; +/*! + * \internal + * \brief Log a message using output object's log level and filters + * + * \param[in] priv Output object's private_data_t + * \param[in] fmt printf(3)-style format string + * \param[in] args... Format string arguments + */ +#define logger(priv, fmt, args...) do { \ + qb_log_from_external_source(pcmk__s((priv)->function, __func__), \ + pcmk__s((priv)->file, __FILE__), fmt, (priv)->log_level, \ + (((priv)->line == 0)? __LINE__ : (priv)->line), (priv)->tags, \ + ##args); \ + } while (0); + +/*! + * \internal + * \brief Log a message using an explicit log level and output object's filters + * + * \param[in] priv Output object's private_data_t + * \param[in] level Log level + * \param[in] fmt printf(3)-style format string + * \param[in] ap Variadic arguments + */ +#define logger_va(priv, level, fmt, ap) do { \ + qb_log_from_external_source_va(pcmk__s((priv)->function, __func__), \ + pcmk__s((priv)->file, __FILE__), fmt, level, \ + (((priv)->line == 0)? __LINE__ : (priv)->line), (priv)->tags, \ + ap); \ + } while (0); + static void log_subprocess_output(pcmk__output_t *out, int exit_status, const char *proc_stdout, const char *proc_stderr) { /* This function intentionally left blank */ } static void log_free_priv(pcmk__output_t *out) { private_data_t *priv = NULL; if (out == NULL || out->priv == NULL) { return; } priv = out->priv; g_queue_free(priv->prefixes); free(priv); out->priv = NULL; } static bool log_init(pcmk__output_t *out) { private_data_t *priv = NULL; CRM_ASSERT(out != NULL); /* If log_init was previously called on this output struct, just return. */ if (out->priv != NULL) { return true; } out->priv = calloc(1, sizeof(private_data_t)); if (out->priv == NULL) { return false; } priv = out->priv; priv->prefixes = g_queue_new(); priv->log_level = LOG_INFO; return true; } static void log_finish(pcmk__output_t *out, crm_exit_t exit_status, bool print, void **copy_dest) { /* This function intentionally left blank */ } static void log_reset(pcmk__output_t *out) { CRM_ASSERT(out != NULL); out->dest = freopen(NULL, "w", out->dest); CRM_ASSERT(out->dest != NULL); log_free_priv(out); log_init(out); } static void log_version(pcmk__output_t *out, bool extended) { private_data_t *priv = NULL; CRM_ASSERT(out != NULL && out->priv != NULL); priv = out->priv; if (extended) { - do_crm_log(priv->log_level, "Pacemaker %s (Build: %s): %s", - PACEMAKER_VERSION, BUILD_VERSION, CRM_FEATURES); + logger(priv, "Pacemaker %s (Build: %s): %s", + PACEMAKER_VERSION, BUILD_VERSION, CRM_FEATURES); } else { - do_crm_log(priv->log_level, "Pacemaker %s", PACEMAKER_VERSION); - do_crm_log(priv->log_level, "Written by Andrew Beekhof and" - "the Pacemaker project contributors"); + logger(priv, "Pacemaker " PACEMAKER_VERSION); + logger(priv, "Written by Andrew Beekhof and " + "the Pacemaker project contributors"); } } G_GNUC_PRINTF(2, 3) static void -log_err(pcmk__output_t *out, const char *format, ...) { +log_err(pcmk__output_t *out, const char *format, ...) +{ va_list ap; - char* buffer = NULL; - int len = 0; + private_data_t *priv = NULL; - CRM_ASSERT(out != NULL); + CRM_ASSERT((out != NULL) && (out->priv != NULL)); + priv = out->priv; - va_start(ap, format); - /* Informational output does not get indented, to separate it from other + /* Error output does not get indented, to separate it from other * potentially indented list output. */ - len = vasprintf(&buffer, format, ap); - CRM_ASSERT(len >= 0); + va_start(ap, format); + logger_va(priv, LOG_ERR, format, ap); va_end(ap); - - crm_err("%s", buffer); - - free(buffer); } static void log_output_xml(pcmk__output_t *out, const char *name, const char *buf) { xmlNodePtr node = NULL; private_data_t *priv = NULL; CRM_ASSERT(out != NULL && out->priv != NULL); priv = out->priv; node = create_xml_node(NULL, name); xmlNodeSetContent(node, (pcmkXmlStr) buf); do_crm_log_xml(priv->log_level, name, node); free(node); } G_GNUC_PRINTF(4, 5) static void log_begin_list(pcmk__output_t *out, const char *singular_noun, const char *plural_noun, const char *format, ...) { int len = 0; va_list ap; char* buffer = NULL; private_data_t *priv = NULL; CRM_ASSERT(out != NULL && out->priv != NULL); priv = out->priv; va_start(ap, format); len = vasprintf(&buffer, format, ap); CRM_ASSERT(len >= 0); va_end(ap); /* Don't skip empty prefixes, * otherwise there will be mismatch * in the log_end_list */ if(strcmp(buffer, "") == 0) { /* nothing */ } g_queue_push_tail(priv->prefixes, buffer); } G_GNUC_PRINTF(3, 4) static void log_list_item(pcmk__output_t *out, const char *name, const char *format, ...) { int len = 0; va_list ap; private_data_t *priv = NULL; char prefix[LINE_MAX] = { 0 }; int offset = 0; char* buffer = NULL; CRM_ASSERT(out != NULL && out->priv != NULL); priv = out->priv; for (GList* gIter = priv->prefixes->head; gIter; gIter = gIter->next) { if (strcmp(prefix, "") != 0) { offset += snprintf(prefix + offset, LINE_MAX - offset, ": %s", (char *)gIter->data); } else { offset = snprintf(prefix, LINE_MAX, "%s", (char *)gIter->data); } } va_start(ap, format); len = vasprintf(&buffer, format, ap); CRM_ASSERT(len >= 0); va_end(ap); if (strcmp(buffer, "") != 0) { /* We don't want empty messages */ if ((name != NULL) && (strcmp(name, "") != 0)) { if (strcmp(prefix, "") != 0) { - do_crm_log(priv->log_level, "%s: %s: %s", prefix, name, buffer); + logger(priv, "%s: %s: %s", prefix, name, buffer); } else { - do_crm_log(priv->log_level, "%s: %s", name, buffer); + logger(priv, "%s: %s", name, buffer); } } else { if (strcmp(prefix, "") != 0) { - do_crm_log(priv->log_level, "%s: %s", prefix, buffer); + logger(priv, "%s: %s", prefix, buffer); } else { - do_crm_log(priv->log_level, "%s", buffer); + logger(priv, "%s", buffer); } } } free(buffer); } static void log_end_list(pcmk__output_t *out) { private_data_t *priv = NULL; CRM_ASSERT(out != NULL && out->priv != NULL); priv = out->priv; if (priv->prefixes == NULL) { return; } CRM_ASSERT(priv->prefixes->tail != NULL); free((char *)priv->prefixes->tail->data); g_queue_pop_tail(priv->prefixes); } G_GNUC_PRINTF(2, 3) static int -log_info(pcmk__output_t *out, const char *format, ...) { - private_data_t *priv = NULL; - int len = 0; +log_info(pcmk__output_t *out, const char *format, ...) +{ va_list ap; - char* buffer = NULL; + private_data_t *priv = NULL; CRM_ASSERT(out != NULL && out->priv != NULL); priv = out->priv; + /* Informational output does not get indented, to separate it from other + * potentially indented list output. + */ va_start(ap, format); - len = vasprintf(&buffer, format, ap); - CRM_ASSERT(len >= 0); + logger_va(priv, priv->log_level, format, ap); va_end(ap); - do_crm_log(priv->log_level, "%s", buffer); - - free(buffer); return pcmk_rc_ok; } G_GNUC_PRINTF(2, 3) static int log_transient(pcmk__output_t *out, const char *format, ...) { - private_data_t *priv = NULL; - int len = 0; va_list ap; - char *buffer = NULL; + private_data_t *priv = NULL; CRM_ASSERT(out != NULL && out->priv != NULL); priv = out->priv; va_start(ap, format); - len = vasprintf(&buffer, format, ap); - CRM_ASSERT(len >= 0); + logger_va(priv, QB_MAX(priv->log_level, LOG_DEBUG), format, ap); va_end(ap); - do_crm_log(QB_MAX(priv->log_level, LOG_DEBUG), "%s", buffer); - - free(buffer); return pcmk_rc_ok; } static bool log_is_quiet(pcmk__output_t *out) { return false; } static void log_spacer(pcmk__output_t *out) { /* This function intentionally left blank */ } static void log_progress(pcmk__output_t *out, bool end) { /* This function intentionally left blank */ } static void log_prompt(const char *prompt, bool echo, char **dest) { /* This function intentionally left blank */ } pcmk__output_t * pcmk__mk_log_output(char **argv) { pcmk__output_t *retval = calloc(1, sizeof(pcmk__output_t)); if (retval == NULL) { return NULL; } retval->fmt_name = "log"; retval->request = pcmk__quote_cmdline(argv); retval->init = log_init; retval->free_priv = log_free_priv; retval->finish = log_finish; retval->reset = log_reset; retval->register_message = pcmk__register_message; retval->message = pcmk__call_message; retval->subprocess_output = log_subprocess_output; retval->version = log_version; retval->info = log_info; retval->transient = log_transient; retval->err = log_err; retval->output_xml = log_output_xml; retval->begin_list = log_begin_list; retval->list_item = log_list_item; retval->end_list = log_end_list; retval->is_quiet = log_is_quiet; retval->spacer = log_spacer; retval->progress = log_progress; retval->prompt = log_prompt; return retval; } uint8_t pcmk__output_get_log_level(const pcmk__output_t *out) { private_data_t *priv = NULL; CRM_ASSERT((out != NULL) && (out->priv != NULL)); CRM_CHECK(pcmk__str_eq(out->fmt_name, "log", pcmk__str_none), return 0); priv = out->priv; return priv->log_level; } void pcmk__output_set_log_level(pcmk__output_t *out, uint8_t log_level) { private_data_t *priv = NULL; CRM_ASSERT(out != NULL && out->priv != NULL); CRM_CHECK(pcmk__str_eq(out->fmt_name, "log", pcmk__str_none), return); priv = out->priv; priv->log_level = log_level; } + +/*! + * \internal + * \brief Set the file, function, line, and tags used to filter log output + * + * \param[in,out] out Logger output object + * \param[in] file File name to filter with (or NULL for default) + * \param[in] function Function name to filter with (or NULL for default) + * \param[in] line Line number to filter with (or 0 for default) + * \param[in] tags Tags to filter with (or 0 for none) + * + * \note Custom filters should generally be used only in short areas of a single + * function. When done, callers should call this function again with + * NULL/0 arguments to reset the filters. + */ +void +pcmk__output_set_log_filter(pcmk__output_t *out, const char *file, + const char *function, uint32_t line, uint32_t tags) +{ + private_data_t *priv = NULL; + + CRM_ASSERT((out != NULL) && (out->priv != NULL)); + CRM_CHECK(pcmk__str_eq(out->fmt_name, "log", pcmk__str_none), return); + + priv = out->priv; + priv->file = file; + priv->function = function; + priv->line = line; + priv->tags = tags; +}