summaryrefslogtreecommitdiff
path: root/src/libnm-log-core/nm-logging.c
diff options
context:
space:
mode:
authorThomas Haller <thaller@redhat.com>2021-02-18 17:37:47 +0100
committerThomas Haller <thaller@redhat.com>2021-02-18 19:47:16 +0100
commitfbf82f51b72a27b00c39ea37d4d359f09da4bf02 (patch)
tree035559bbae2df761c02c36f0874533f617ffb393 /src/libnm-log-core/nm-logging.c
parent61f006caf47aaa184ff4d54a6280956acc1fbad9 (diff)
downloadNetworkManager-fbf82f51b72a27b00c39ea37d4d359f09da4bf02.tar.gz
build: move "shared/nm-{glib-aux,log-null,log-core}" to "src/libnm-{glib-aux,log-null,log-core}"th/libnm-core-split2
Diffstat (limited to 'src/libnm-log-core/nm-logging.c')
-rw-r--r--src/libnm-log-core/nm-logging.c1035
1 files changed, 1035 insertions, 0 deletions
diff --git a/src/libnm-log-core/nm-logging.c b/src/libnm-log-core/nm-logging.c
new file mode 100644
index 0000000000..7a23344b94
--- /dev/null
+++ b/src/libnm-log-core/nm-logging.c
@@ -0,0 +1,1035 @@
+/* SPDX-License-Identifier: GPL-2.0-or-later */
+/*
+ * Copyright (C) 2006 - 2012 Red Hat, Inc.
+ * Copyright (C) 2006 - 2008 Novell, Inc.
+ */
+
+#include "libnm-glib-aux/nm-default-glib-i18n-lib.h"
+
+#include "nm-logging.h"
+
+#include <dlfcn.h>
+#include <syslog.h>
+#include <stdio.h>
+#include <stdlib.h>
+#include <unistd.h>
+#include <sys/wait.h>
+#include <sys/stat.h>
+#include <strings.h>
+
+#if SYSTEMD_JOURNAL
+ #define SD_JOURNAL_SUPPRESS_LOCATION
+ #include <systemd/sd-journal.h>
+#endif
+
+#include "libnm-glib-aux/nm-logging-base.h"
+#include "libnm-glib-aux/nm-time-utils.h"
+
+/*****************************************************************************/
+
+/* Notes about thread-safety:
+ *
+ * NetworkManager generally is single-threaded and uses a (GLib) mainloop.
+ * However, nm-logging is in parts thread-safe. That means:
+ *
+ * - functions that configure logging (nm_logging_init(), nm_logging_setup()) and
+ * most other functions MUST be called only from the main-thread. These functions
+ * are expected to be called infrequently, so they may or may not use a mutex
+ * (but the overhead is negligible here).
+ *
+ * - functions that do the actual logging logging (nm_log(), nm_logging_enabled()) are
+ * thread-safe and may be used from multiple threads.
+ * - When called from the not-main-thread, @mt_require_locking must be set to %TRUE.
+ * In this case, a Mutex will be used for accessing the global state.
+ * - When called from the main-thread, they may optionally pass @mt_require_locking %FALSE.
+ * This avoids extra locking and is in particular interesting for nm_logging_enabled(),
+ * which is expected to be called frequently and from the main-thread.
+ *
+ * Note that the logging macros honor %NM_THREAD_SAFE_ON_MAIN_THREAD define, to automatically
+ * set @mt_require_locking. That means, by default %NM_THREAD_SAFE_ON_MAIN_THREAD is "1",
+ * and code that only runs on the main-thread (which is the majority), can get away
+ * without locking.
+ */
+
+/*****************************************************************************/
+
+G_STATIC_ASSERT(LOG_EMERG == 0);
+G_STATIC_ASSERT(LOG_ALERT == 1);
+G_STATIC_ASSERT(LOG_CRIT == 2);
+G_STATIC_ASSERT(LOG_ERR == 3);
+G_STATIC_ASSERT(LOG_WARNING == 4);
+G_STATIC_ASSERT(LOG_NOTICE == 5);
+G_STATIC_ASSERT(LOG_INFO == 6);
+G_STATIC_ASSERT(LOG_DEBUG == 7);
+
+/* We have more then 32 logging domains. Assert that it compiles to a 64 bit sized enum */
+G_STATIC_ASSERT(sizeof(NMLogDomain) >= sizeof(guint64));
+
+/* Combined domains */
+#define LOGD_ALL_STRING "ALL"
+#define LOGD_DEFAULT_STRING "DEFAULT"
+#define LOGD_DHCP_STRING "DHCP"
+#define LOGD_IP_STRING "IP"
+
+/*****************************************************************************/
+
+typedef enum {
+ LOG_BACKEND_GLIB,
+ LOG_BACKEND_SYSLOG,
+ LOG_BACKEND_JOURNAL,
+} LogBackend;
+
+typedef struct {
+ NMLogDomain num;
+ const char *name;
+} LogDesc;
+
+typedef struct {
+ char *logging_domains_to_string;
+} GlobalMain;
+
+typedef struct {
+ NMLogLevel log_level;
+ bool uses_syslog : 1;
+ bool init_pre_done : 1;
+ bool init_done : 1;
+ bool debug_stderr : 1;
+ const char *prefix;
+ const char *syslog_identifier;
+
+ /* before we setup syslog (during start), the backend defaults to GLIB, meaning:
+ * we use g_log() for all logging. At that point, the application is not yet supposed
+ * to do any logging and doing so indicates a bug.
+ *
+ * Afterwards, the backend is either SYSLOG or JOURNAL. From that point, also
+ * g_log() is redirected to this backend via a logging handler. */
+ LogBackend log_backend;
+} Global;
+
+/*****************************************************************************/
+
+G_LOCK_DEFINE_STATIC(log);
+
+/* This data must only be accessed from the main-thread (and as
+ * such does not need any lock). */
+static GlobalMain gl_main = {};
+
+static union {
+ /* a union with an immutable and a mutable alias for the Global.
+ * Since nm-logging must be thread-safe, we must take care at which
+ * places we only read value ("imm") and where we modify them ("mut"). */
+ Global mut;
+ const Global imm;
+} gl = {
+ .imm =
+ {
+ /* nm_logging_setup ("INFO", LOGD_DEFAULT_STRING, NULL, NULL); */
+ .log_level = LOGL_INFO,
+ .log_backend = LOG_BACKEND_GLIB,
+ .syslog_identifier = "SYSLOG_IDENTIFIER=" G_LOG_DOMAIN,
+ .prefix = "",
+ },
+};
+
+NMLogDomain _nm_logging_enabled_state[_LOGL_N_REAL] = {
+ /* nm_logging_setup ("INFO", LOGD_DEFAULT_STRING, NULL, NULL);
+ *
+ * Note: LOGD_VPN_PLUGIN is special and must be disabled for
+ * DEBUG and TRACE levels. */
+ [LOGL_INFO] = LOGD_DEFAULT,
+ [LOGL_WARN] = LOGD_DEFAULT,
+ [LOGL_ERR] = LOGD_DEFAULT,
+};
+
+/*****************************************************************************/
+
+static const LogDesc domain_desc[] = {
+ {LOGD_PLATFORM, "PLATFORM"},
+ {LOGD_RFKILL, "RFKILL"},
+ {LOGD_ETHER, "ETHER"},
+ {LOGD_WIFI, "WIFI"},
+ {LOGD_BT, "BT"},
+ {LOGD_MB, "MB"},
+ {LOGD_DHCP4, "DHCP4"},
+ {LOGD_DHCP6, "DHCP6"},
+ {LOGD_PPP, "PPP"},
+ {LOGD_WIFI_SCAN, "WIFI_SCAN"},
+ {LOGD_IP4, "IP4"},
+ {LOGD_IP6, "IP6"},
+ {LOGD_AUTOIP4, "AUTOIP4"},
+ {LOGD_DNS, "DNS"},
+ {LOGD_VPN, "VPN"},
+ {LOGD_SHARING, "SHARING"},
+ {LOGD_SUPPLICANT, "SUPPLICANT"},
+ {LOGD_AGENTS, "AGENTS"},
+ {LOGD_SETTINGS, "SETTINGS"},
+ {LOGD_SUSPEND, "SUSPEND"},
+ {LOGD_CORE, "CORE"},
+ {LOGD_DEVICE, "DEVICE"},
+ {LOGD_OLPC, "OLPC"},
+ {LOGD_INFINIBAND, "INFINIBAND"},
+ {LOGD_FIREWALL, "FIREWALL"},
+ {LOGD_ADSL, "ADSL"},
+ {LOGD_BOND, "BOND"},
+ {LOGD_VLAN, "VLAN"},
+ {LOGD_BRIDGE, "BRIDGE"},
+ {LOGD_DBUS_PROPS, "DBUS_PROPS"},
+ {LOGD_TEAM, "TEAM"},
+ {LOGD_CONCHECK, "CONCHECK"},
+ {LOGD_DCB, "DCB"},
+ {LOGD_DISPATCH, "DISPATCH"},
+ {LOGD_AUDIT, "AUDIT"},
+ {LOGD_SYSTEMD, "SYSTEMD"},
+ {LOGD_VPN_PLUGIN, "VPN_PLUGIN"},
+ {LOGD_PROXY, "PROXY"},
+ {0},
+};
+
+/*****************************************************************************/
+
+static char *_domains_to_string(gboolean include_level_override,
+ NMLogLevel log_level,
+ const NMLogDomain log_state[static _LOGL_N_REAL]);
+
+/*****************************************************************************/
+
+static gboolean
+_syslog_identifier_valid_domain(const char *domain)
+{
+ char c;
+
+ if (!domain || !domain[0])
+ return FALSE;
+
+ /* we pass the syslog identifier as format string. No funny stuff. */
+
+ for (; (c = domain[0]); domain++) {
+ if ((c >= 'a' && c <= 'z') || (c >= 'A' && c <= 'Z') || (c >= '0' && c <= '9')
+ || NM_IN_SET(c, '-', '_'))
+ continue;
+ return FALSE;
+ }
+ return TRUE;
+}
+
+static gboolean
+_syslog_identifier_assert(const char *syslog_identifier)
+{
+ g_assert(syslog_identifier);
+ g_assert(g_str_has_prefix(syslog_identifier, "SYSLOG_IDENTIFIER="));
+ g_assert(_syslog_identifier_valid_domain(&syslog_identifier[NM_STRLEN("SYSLOG_IDENTIFIER=")]));
+ return TRUE;
+}
+
+static const char *
+syslog_identifier_domain(const char *syslog_identifier)
+{
+ nm_assert(_syslog_identifier_assert(syslog_identifier));
+ return &syslog_identifier[NM_STRLEN("SYSLOG_IDENTIFIER=")];
+}
+
+#if SYSTEMD_JOURNAL
+static const char *
+syslog_identifier_full(const char *syslog_identifier)
+{
+ nm_assert(_syslog_identifier_assert(syslog_identifier));
+ return &syslog_identifier[0];
+}
+#endif
+
+/*****************************************************************************/
+
+static gboolean
+match_log_level(const char *level, NMLogLevel *out_level, GError **error)
+{
+ if (_nm_log_parse_level(level, out_level))
+ return TRUE;
+
+ g_set_error(error,
+ _NM_MANAGER_ERROR,
+ _NM_MANAGER_ERROR_UNKNOWN_LOG_LEVEL,
+ _("Unknown log level '%s'"),
+ level);
+ return FALSE;
+}
+
+gboolean
+nm_logging_setup(const char *level, const char *domains, char **bad_domains, GError **error)
+{
+ GString * unrecognized = NULL;
+ NMLogDomain cur_log_state[_LOGL_N_REAL];
+ NMLogDomain new_log_state[_LOGL_N_REAL];
+ NMLogLevel cur_log_level;
+ NMLogLevel new_log_level;
+ gs_free const char **domains_v = NULL;
+ gsize i_d;
+ int i;
+ gboolean had_platform_debug;
+ gs_free char * domains_free = NULL;
+
+ NM_ASSERT_ON_MAIN_THREAD();
+
+ g_return_val_if_fail(!bad_domains || !*bad_domains, FALSE);
+ g_return_val_if_fail(!error || !*error, FALSE);
+
+ cur_log_level = gl.imm.log_level;
+ memcpy(cur_log_state, _nm_logging_enabled_state, sizeof(cur_log_state));
+
+ new_log_level = cur_log_level;
+
+ if (!domains || !*domains) {
+ domains_free = _domains_to_string(FALSE, cur_log_level, cur_log_state);
+ domains = domains_free;
+ }
+
+ for (i = 0; i < G_N_ELEMENTS(new_log_state); i++)
+ new_log_state[i] = 0;
+
+ if (level && *level) {
+ if (!match_log_level(level, &new_log_level, error))
+ return FALSE;
+ if (new_log_level == _LOGL_KEEP) {
+ new_log_level = cur_log_level;
+ for (i = 0; i < G_N_ELEMENTS(new_log_state); i++)
+ new_log_state[i] = cur_log_state[i];
+ }
+ }
+
+ domains_v = nm_utils_strsplit_set(domains, ", ");
+ for (i_d = 0; domains_v && domains_v[i_d]; i_d++) {
+ const char * s = domains_v[i_d];
+ const char * p;
+ const LogDesc *diter;
+ NMLogLevel domain_log_level;
+ NMLogDomain bits;
+
+ /* LOGD_VPN_PLUGIN is protected, that is, when setting ALL or DEFAULT,
+ * it does not enable the verbose levels DEBUG and TRACE, because that
+ * may expose sensitive data. */
+ NMLogDomain protect = LOGD_NONE;
+
+ p = strchr(s, ':');
+ if (p) {
+ *((char *) p) = '\0';
+ if (!match_log_level(p + 1, &domain_log_level, error))
+ return FALSE;
+ } else
+ domain_log_level = new_log_level;
+
+ bits = 0;
+
+ if (domains_free) {
+ /* The caller didn't provide any domains to set (`nmcli general logging level DEBUG`).
+ * We reset all domains that were previously set, but we still want to protect
+ * VPN_PLUGIN domain. */
+ protect = LOGD_VPN_PLUGIN;
+ }
+
+ /* Check for combined domains */
+ if (!g_ascii_strcasecmp(s, LOGD_ALL_STRING)) {
+ bits = LOGD_ALL;
+ protect = LOGD_VPN_PLUGIN;
+ } else if (!g_ascii_strcasecmp(s, LOGD_DEFAULT_STRING)) {
+ bits = LOGD_DEFAULT;
+ protect = LOGD_VPN_PLUGIN;
+ } else if (!g_ascii_strcasecmp(s, LOGD_DHCP_STRING))
+ bits = LOGD_DHCP;
+ else if (!g_ascii_strcasecmp(s, LOGD_IP_STRING))
+ bits = LOGD_IP;
+
+ /* Check for compatibility domains */
+ else if (!g_ascii_strcasecmp(s, "HW"))
+ bits = LOGD_PLATFORM;
+ else if (!g_ascii_strcasecmp(s, "WIMAX"))
+ continue;
+
+ else {
+ for (diter = &domain_desc[0]; diter->name; diter++) {
+ if (!g_ascii_strcasecmp(diter->name, s)) {
+ bits = diter->num;
+ break;
+ }
+ }
+
+ if (!bits) {
+ if (!bad_domains) {
+ g_set_error(error,
+ _NM_MANAGER_ERROR,
+ _NM_MANAGER_ERROR_UNKNOWN_LOG_DOMAIN,
+ _("Unknown log domain '%s'"),
+ s);
+ return FALSE;
+ }
+
+ if (unrecognized)
+ g_string_append(unrecognized, ", ");
+ else
+ unrecognized = g_string_new(NULL);
+ g_string_append(unrecognized, s);
+ continue;
+ }
+ }
+
+ if (domain_log_level == _LOGL_KEEP) {
+ for (i = 0; i < G_N_ELEMENTS(new_log_state); i++)
+ new_log_state[i] = (new_log_state[i] & ~bits) | (cur_log_state[i] & bits);
+ } else {
+ for (i = 0; i < G_N_ELEMENTS(new_log_state); i++) {
+ if (i < domain_log_level)
+ new_log_state[i] &= ~bits;
+ else {
+ new_log_state[i] |= bits;
+ if ((protect & bits) && i < LOGL_INFO)
+ new_log_state[i] &= ~protect;
+ }
+ }
+ }
+ }
+
+ nm_clear_g_free(&gl_main.logging_domains_to_string);
+
+ had_platform_debug = _nm_logging_enabled_lockfree(LOGL_DEBUG, LOGD_PLATFORM);
+
+ G_LOCK(log);
+
+ gl.mut.log_level = new_log_level;
+ for (i = 0; i < G_N_ELEMENTS(new_log_state); i++)
+ _nm_logging_enabled_state[i] = new_log_state[i];
+
+ G_UNLOCK(log);
+
+ if (had_platform_debug && !_nm_logging_enabled_lockfree(LOGL_DEBUG, LOGD_PLATFORM)) {
+ /* when debug logging is enabled, platform will cache all access to
+ * sysctl. When the user disables debug-logging, we want to clear that
+ * cache right away. */
+ _nm_logging_clear_platform_logging_cache();
+ }
+
+ if (unrecognized)
+ *bad_domains = g_string_free(unrecognized, FALSE);
+
+ return TRUE;
+}
+
+const char *
+nm_logging_level_to_string(void)
+{
+ NM_ASSERT_ON_MAIN_THREAD();
+
+ return level_desc[gl.imm.log_level].name;
+}
+
+const char *
+nm_logging_all_levels_to_string(void)
+{
+ static GString *str;
+
+ if (G_UNLIKELY(!str)) {
+ int i;
+
+ str = g_string_new(NULL);
+ for (i = 0; i < G_N_ELEMENTS(level_desc); i++) {
+ if (str->len)
+ g_string_append_c(str, ',');
+ g_string_append(str, level_desc[i].name);
+ }
+ }
+
+ return str->str;
+}
+
+const char *
+nm_logging_domains_to_string(void)
+{
+ NM_ASSERT_ON_MAIN_THREAD();
+
+ if (G_UNLIKELY(!gl_main.logging_domains_to_string)) {
+ gl_main.logging_domains_to_string =
+ _domains_to_string(TRUE, gl.imm.log_level, _nm_logging_enabled_state);
+ }
+
+ return gl_main.logging_domains_to_string;
+}
+
+static char *
+_domains_to_string(gboolean include_level_override,
+ NMLogLevel log_level,
+ const NMLogDomain log_state[static _LOGL_N_REAL])
+{
+ const LogDesc *diter;
+ GString * str;
+ int i;
+
+ /* We don't just return g_strdup() the logging domains that were set during
+ * nm_logging_setup(), because we want to expand "DEFAULT" and "ALL".
+ */
+
+ str = g_string_sized_new(75);
+ for (diter = &domain_desc[0]; diter->name; diter++) {
+ /* If it's set for any lower level, it will also be set for LOGL_ERR */
+ if (!(diter->num & log_state[LOGL_ERR]))
+ continue;
+
+ if (str->len)
+ g_string_append_c(str, ',');
+ g_string_append(str, diter->name);
+
+ if (!include_level_override)
+ continue;
+
+ /* Check if it's logging at a lower level than the default. */
+ for (i = 0; i < log_level; i++) {
+ if (diter->num & log_state[i]) {
+ g_string_append_printf(str, ":%s", level_desc[i].name);
+ break;
+ }
+ }
+ /* Check if it's logging at a higher level than the default. */
+ if (!(diter->num & log_state[log_level])) {
+ for (i = log_level + 1; i < _LOGL_N_REAL; i++) {
+ if (diter->num & log_state[i]) {
+ g_string_append_printf(str, ":%s", level_desc[i].name);
+ break;
+ }
+ }
+ }
+ }
+ return g_string_free(str, FALSE);
+}
+
+static char _all_logging_domains_to_str[273];
+
+const char *
+nm_logging_all_domains_to_string(void)
+{
+ static const char *volatile str = NULL;
+ const char *s;
+
+again:
+ s = g_atomic_pointer_get(&str);
+ if (G_UNLIKELY(!s)) {
+ static gsize once = 0;
+ const LogDesc *diter;
+ gsize buf_l;
+ char * buf_p;
+
+ if (!g_once_init_enter(&once))
+ goto again;
+
+ buf_p = _all_logging_domains_to_str;
+ buf_l = sizeof(_all_logging_domains_to_str);
+
+ nm_utils_strbuf_append_str(&buf_p, &buf_l, LOGD_DEFAULT_STRING);
+ for (diter = &domain_desc[0]; diter->name; diter++) {
+ nm_utils_strbuf_append_c(&buf_p, &buf_l, ',');
+ nm_utils_strbuf_append_str(&buf_p, &buf_l, diter->name);
+ if (diter->num == LOGD_DHCP6)
+ nm_utils_strbuf_append_str(&buf_p, &buf_l, "," LOGD_DHCP_STRING);
+ else if (diter->num == LOGD_IP6)
+ nm_utils_strbuf_append_str(&buf_p, &buf_l, "," LOGD_IP_STRING);
+ }
+ nm_utils_strbuf_append_str(&buf_p, &buf_l, LOGD_ALL_STRING);
+
+ /* Did you modify the logging domains (or their names)? Adjust the size of
+ * _all_logging_domains_to_str buffer above to have the exact size. */
+ nm_assert(strlen(_all_logging_domains_to_str) == sizeof(_all_logging_domains_to_str) - 1);
+ nm_assert(buf_l == 1);
+
+ s = _all_logging_domains_to_str;
+ g_atomic_pointer_set(&str, s);
+ g_once_init_leave(&once, 1);
+ }
+
+ return s;
+}
+
+/**
+ * nm_logging_get_level:
+ * @domain: find the lowest enabled logging level for the
+ * given domain. If this is a set of multiple
+ * domains, the most verbose level will be returned.
+ *
+ * Returns: the lowest (most verbose) logging level for the
+ * give @domain, or %_LOGL_OFF if it is disabled.
+ **/
+NMLogLevel
+nm_logging_get_level(NMLogDomain domain)
+{
+ NMLogLevel sl = _LOGL_OFF;
+
+ G_STATIC_ASSERT(LOGL_TRACE == 0);
+ while (sl > LOGL_TRACE && _nm_logging_enabled_lockfree(sl - 1, domain))
+ sl--;
+ return sl;
+}
+
+gboolean
+_nm_logging_enabled_locking(NMLogLevel level, NMLogDomain domain)
+{
+ gboolean v;
+
+ G_LOCK(log);
+ v = _nm_logging_enabled_lockfree(level, domain);
+ G_UNLOCK(log);
+ return v;
+}
+
+gboolean
+_nm_log_enabled_impl(gboolean mt_require_locking, NMLogLevel level, NMLogDomain domain)
+{
+ return nm_logging_enabled_mt(mt_require_locking, level, domain);
+}
+
+#if SYSTEMD_JOURNAL
+static void
+_iovec_set(struct iovec *iov, const void *str, gsize len)
+{
+ iov->iov_base = (void *) str;
+ iov->iov_len = len;
+}
+
+static void
+_iovec_set_string(struct iovec *iov, const char *str)
+{
+ _iovec_set(iov, str, strlen(str));
+}
+
+ #define _iovec_set_string_literal(iov, str) _iovec_set((iov), "" str "", NM_STRLEN(str))
+
+_nm_printf(3, 4) static void _iovec_set_format(struct iovec *iov,
+ char ** iov_free,
+ const char * format,
+ ...)
+{
+ va_list ap;
+ char * str;
+
+ va_start(ap, format);
+ str = g_strdup_vprintf(format, ap);
+ va_end(ap);
+
+ _iovec_set_string(iov, str);
+ *iov_free = str;
+}
+
+ #define _iovec_set_format_a(iov, reserve_extra, format, ...) \
+ G_STMT_START \
+ { \
+ const gsize _size = (reserve_extra) + (NM_STRLEN(format) + 3); \
+ char *const _buf = g_alloca(_size); \
+ int _len; \
+ \
+ G_STATIC_ASSERT_EXPR((reserve_extra) + (NM_STRLEN(format) + 3) <= 96); \
+ \
+ _len = g_snprintf(_buf, _size, "" format "", ##__VA_ARGS__); \
+ \
+ nm_assert(_len >= 0); \
+ nm_assert(_len < _size); \
+ nm_assert(_len == strlen(_buf)); \
+ \
+ _iovec_set((iov), _buf, _len); \
+ } \
+ G_STMT_END
+
+ #define _iovec_set_format_str_a(iov, max_str_len, format, str_arg) \
+ G_STMT_START \
+ { \
+ const char *_str_arg = (str_arg); \
+ \
+ nm_assert(_str_arg &&strlen(_str_arg) < (max_str_len)); \
+ _iovec_set_format_a((iov), (max_str_len), format, str_arg); \
+ } \
+ G_STMT_END
+
+#endif
+
+void
+_nm_log_impl(const char *file,
+ guint line,
+ const char *func,
+ gboolean mt_require_locking,
+ NMLogLevel level,
+ NMLogDomain domain,
+ int error,
+ const char *ifname,
+ const char *conn_uuid,
+ const char *fmt,
+ ...)
+{
+ va_list args;
+ char * msg;
+ GTimeVal tv;
+ int errsv;
+ const NMLogDomain *cur_log_state;
+ NMLogDomain cur_log_state_copy[_LOGL_N_REAL];
+ Global g_copy;
+ const Global * g;
+
+ if (G_UNLIKELY(mt_require_locking)) {
+ G_LOCK(log);
+ /* we evaluate logging-enabled under lock. There is still a race that
+ * we might log the message below *after* logging was disabled. That means,
+ * when disabling logging, we might still log messages. */
+ if (!_nm_logging_enabled_lockfree(level, domain)) {
+ G_UNLOCK(log);
+ return;
+ }
+ g_copy = gl.imm;
+ memcpy(cur_log_state_copy, _nm_logging_enabled_state, sizeof(cur_log_state_copy));
+ G_UNLOCK(log);
+ g = &g_copy;
+ cur_log_state = cur_log_state_copy;
+ } else {
+ NM_ASSERT_ON_MAIN_THREAD();
+ if (!_nm_logging_enabled_lockfree(level, domain))
+ return;
+ g = &gl.imm;
+ cur_log_state = _nm_logging_enabled_state;
+ }
+
+ (void) cur_log_state;
+
+ errsv = errno;
+
+ /* Make sure that %m maps to the specified error */
+ if (error != 0) {
+ if (error < 0)
+ error = -error;
+ errno = error;
+ }
+
+ va_start(args, fmt);
+ msg = g_strdup_vprintf(fmt, args);
+ va_end(args);
+
+#define MESSAGE_FMT "%s%-7s [%ld.%04ld] %s"
+#define MESSAGE_ARG(prefix, tv, msg) \
+ prefix, level_desc[level].level_str, (tv).tv_sec, ((tv).tv_usec / 100), (msg)
+
+ g_get_current_time(&tv);
+
+ if (g->debug_stderr)
+ g_printerr(MESSAGE_FMT "\n", MESSAGE_ARG(g->prefix, tv, msg));
+
+ switch (g->log_backend) {
+#if SYSTEMD_JOURNAL
+ case LOG_BACKEND_JOURNAL:
+ {
+ gint64 now, boottime;
+ struct iovec iov_data[15];
+ struct iovec * iov = iov_data;
+ char * iov_free_data[5];
+ char ** iov_free = iov_free_data;
+ const LogDesc *diter;
+ NMLogDomain dom_all;
+ char s_log_domains_buf[NM_STRLEN("NM_LOG_DOMAINS=") + sizeof(_all_logging_domains_to_str)];
+ char *s_log_domains;
+ gsize l_log_domains;
+
+ now = nm_utils_get_monotonic_timestamp_nsec();
+ boottime = nm_utils_monotonic_timestamp_as_boottime(now, 1);
+
+ _iovec_set_format_a(iov++, 30, "PRIORITY=%d", level_desc[level].syslog_level);
+ _iovec_set_format(iov++,
+ iov_free++,
+ "MESSAGE=" MESSAGE_FMT,
+ MESSAGE_ARG(g->prefix, tv, msg));
+ _iovec_set_string(iov++, syslog_identifier_full(g->syslog_identifier));
+ _iovec_set_format_a(iov++, 30, "SYSLOG_PID=%ld", (long) getpid());
+
+ dom_all = domain;
+ s_log_domains = s_log_domains_buf;
+ l_log_domains = sizeof(s_log_domains_buf);
+
+ nm_utils_strbuf_append_str(&s_log_domains, &l_log_domains, "NM_LOG_DOMAINS=");
+ for (diter = &domain_desc[0]; dom_all != 0 && diter->name; diter++) {
+ if (!NM_FLAGS_ANY(dom_all, diter->num))
+ continue;
+ if (dom_all != domain)
+ nm_utils_strbuf_append_c(&s_log_domains, &l_log_domains, ',');
+ nm_utils_strbuf_append_str(&s_log_domains, &l_log_domains, diter->name);
+ dom_all &= ~diter->num;
+ }
+ nm_assert(l_log_domains > 0);
+ _iovec_set(iov++, s_log_domains_buf, s_log_domains - s_log_domains_buf);
+
+ G_STATIC_ASSERT_EXPR(LOG_FAC(LOG_DAEMON) == 3);
+ _iovec_set_string_literal(iov++, "SYSLOG_FACILITY=3");
+ _iovec_set_format_str_a(iov++, 15, "NM_LOG_LEVEL=%s", level_desc[level].name);
+ if (func)
+ _iovec_set_format(iov++, iov_free++, "CODE_FUNC=%s", func);
+ _iovec_set_format(iov++, iov_free++, "CODE_FILE=%s", file ?: "");
+ _iovec_set_format_a(iov++, 20, "CODE_LINE=%u", line);
+ _iovec_set_format_a(iov++,
+ 60,
+ "TIMESTAMP_MONOTONIC=%lld.%06lld",
+ (long long) (now / NM_UTILS_NSEC_PER_SEC),
+ (long long) ((now % NM_UTILS_NSEC_PER_SEC) / 1000));
+ _iovec_set_format_a(iov++,
+ 60,
+ "TIMESTAMP_BOOTTIME=%lld.%06lld",
+ (long long) (boottime / NM_UTILS_NSEC_PER_SEC),
+ (long long) ((boottime % NM_UTILS_NSEC_PER_SEC) / 1000));
+ if (error != 0)
+ _iovec_set_format_a(iov++, 30, "ERRNO=%d", error);
+ if (ifname)
+ _iovec_set_format(iov++, iov_free++, "NM_DEVICE=%s", ifname);
+ if (conn_uuid)
+ _iovec_set_format(iov++, iov_free++, "NM_CONNECTION=%s", conn_uuid);
+
+ nm_assert(iov <= &iov_data[G_N_ELEMENTS(iov_data)]);
+ nm_assert(iov_free <= &iov_free_data[G_N_ELEMENTS(iov_free_data)]);
+
+ sd_journal_sendv(iov_data, iov - iov_data);
+
+ for (; --iov_free >= iov_free_data;)
+ g_free(*iov_free);
+ } break;
+#endif
+ case LOG_BACKEND_SYSLOG:
+ syslog(level_desc[level].syslog_level, MESSAGE_FMT, MESSAGE_ARG(g->prefix, tv, msg));
+ break;
+ default:
+ g_log(syslog_identifier_domain(g->syslog_identifier),
+ level_desc[level].g_log_level,
+ MESSAGE_FMT,
+ MESSAGE_ARG(g->prefix, tv, msg));
+ break;
+ }
+
+ g_free(msg);
+
+ errno = errsv;
+}
+
+/*****************************************************************************/
+
+void
+_nm_utils_monotonic_timestamp_initialized(const struct timespec *tp,
+ gint64 offset_sec,
+ gboolean is_boottime)
+{
+ NM_ASSERT_ON_MAIN_THREAD();
+
+ if (_nm_logging_enabled_lockfree(LOGL_DEBUG, LOGD_CORE)) {
+ time_t now = time(NULL);
+ struct tm tm;
+ char s[255];
+
+ strftime(s, sizeof(s), "%Y-%m-%d %H:%M:%S", localtime_r(&now, &tm));
+ nm_log_dbg(LOGD_CORE,
+ "monotonic timestamp started counting 1.%09ld seconds ago with "
+ "an offset of %lld.0 seconds to %s (local time is %s)",
+ tp->tv_nsec,
+ (long long) -offset_sec,
+ is_boottime ? "CLOCK_BOOTTIME" : "CLOCK_MONOTONIC",
+ s);
+ }
+}
+
+/*****************************************************************************/
+
+static void
+nm_log_handler(const char *log_domain, GLogLevelFlags level, const char *message, gpointer ignored)
+{
+ int syslog_priority;
+
+ switch (level & G_LOG_LEVEL_MASK) {
+ case G_LOG_LEVEL_ERROR:
+ syslog_priority = LOG_CRIT;
+ break;
+ case G_LOG_LEVEL_CRITICAL:
+ syslog_priority = LOG_ERR;
+ break;
+ case G_LOG_LEVEL_WARNING:
+ syslog_priority = LOG_WARNING;
+ break;
+ case G_LOG_LEVEL_MESSAGE:
+ syslog_priority = LOG_NOTICE;
+ break;
+ case G_LOG_LEVEL_DEBUG:
+ syslog_priority = LOG_DEBUG;
+ break;
+ case G_LOG_LEVEL_INFO:
+ default:
+ syslog_priority = LOG_INFO;
+ break;
+ }
+
+ /* we don't need any locking here. The glib log handler gets only registered
+ * once during nm_logging_init() and the global data is not modified afterwards. */
+ nm_assert(gl.imm.init_done);
+
+ if (gl.imm.debug_stderr)
+ g_printerr("%s%s\n", gl.imm.prefix, message ?: "");
+
+ switch (gl.imm.log_backend) {
+#if SYSTEMD_JOURNAL
+ case LOG_BACKEND_JOURNAL:
+ {
+ gint64 now, boottime;
+
+ now = nm_utils_get_monotonic_timestamp_nsec();
+ boottime = nm_utils_monotonic_timestamp_as_boottime(now, 1);
+
+ sd_journal_send("PRIORITY=%d",
+ syslog_priority,
+ "MESSAGE=%s%s",
+ gl.imm.prefix,
+ message ?: "",
+ syslog_identifier_full(gl.imm.syslog_identifier),
+ "SYSLOG_PID=%ld",
+ (long) getpid(),
+ "SYSLOG_FACILITY=3",
+ "GLIB_DOMAIN=%s",
+ log_domain ?: "",
+ "GLIB_LEVEL=%d",
+ (int) (level & G_LOG_LEVEL_MASK),
+ "TIMESTAMP_MONOTONIC=%lld.%06lld",
+ (long long) (now / NM_UTILS_NSEC_PER_SEC),
+ (long long) ((now % NM_UTILS_NSEC_PER_SEC) / 1000),
+ "TIMESTAMP_BOOTTIME=%lld.%06lld",
+ (long long) (boottime / NM_UTILS_NSEC_PER_SEC),
+ (long long) ((boottime % NM_UTILS_NSEC_PER_SEC) / 1000),
+ NULL);
+ } break;
+#endif
+ default:
+ syslog(syslog_priority, "%s%s", gl.imm.prefix, message ?: "");
+ break;
+ }
+}
+
+gboolean
+nm_logging_syslog_enabled(void)
+{
+ NM_ASSERT_ON_MAIN_THREAD();
+
+ return gl.imm.uses_syslog;
+}
+
+void
+nm_logging_init_pre(const char *syslog_identifier, char *prefix_take)
+{
+ /* this function may be called zero or one times, and only
+ * - on the main thread
+ * - not after nm_logging_init(). */
+
+ NM_ASSERT_ON_MAIN_THREAD();
+
+ if (gl.imm.init_pre_done)
+ g_return_if_reached();
+
+ if (gl.imm.init_done)
+ g_return_if_reached();
+
+ if (!_syslog_identifier_valid_domain(syslog_identifier))
+ g_return_if_reached();
+
+ if (!prefix_take || !prefix_take[0])
+ g_return_if_reached();
+
+ G_LOCK(log);
+
+ gl.mut.init_pre_done = TRUE;
+
+ gl.mut.syslog_identifier = g_strdup_printf("SYSLOG_IDENTIFIER=%s", syslog_identifier);
+ nm_assert(_syslog_identifier_assert(gl.imm.syslog_identifier));
+
+ /* we pass the allocated string on and never free it. */
+ gl.mut.prefix = prefix_take;
+
+ G_UNLOCK(log);
+}
+
+void
+nm_logging_init(const char *logging_backend, gboolean debug)
+{
+ gboolean fetch_monotonic_timestamp = FALSE;
+ gboolean obsolete_debug_backend = FALSE;
+ LogBackend x_log_backend;
+
+ /* this function may be called zero or one times, and only on the
+ * main thread. */
+
+ NM_ASSERT_ON_MAIN_THREAD();
+
+ nm_assert(NM_IN_STRSET("" NM_CONFIG_DEFAULT_LOGGING_BACKEND,
+ NM_LOG_CONFIG_BACKEND_JOURNAL,
+ NM_LOG_CONFIG_BACKEND_SYSLOG));
+
+ if (gl.imm.init_done)
+ g_return_if_reached();
+
+ if (!logging_backend)
+ logging_backend = "" NM_CONFIG_DEFAULT_LOGGING_BACKEND;
+
+ if (nm_streq(logging_backend, NM_LOG_CONFIG_BACKEND_DEBUG)) {
+ /* "debug" was wrongly documented as a valid logging backend. It makes no sense however,
+ * because printing to stderr only makes sense when not demonizing. Whether to daemonize
+ * is only controlled via command line arguments (--no-daemon, --debug) and not via the
+ * logging backend from configuration.
+ *
+ * Fall back to the default. */
+ logging_backend = "" NM_CONFIG_DEFAULT_LOGGING_BACKEND;
+ obsolete_debug_backend = TRUE;
+ }
+
+ G_LOCK(log);
+
+#if SYSTEMD_JOURNAL
+ if (!nm_streq(logging_backend, NM_LOG_CONFIG_BACKEND_SYSLOG)) {
+ x_log_backend = LOG_BACKEND_JOURNAL;
+
+ /* We only log the monotonic-timestamp with structured logging (journal).
+ * Only in this case, fetch the timestamp. */
+ fetch_monotonic_timestamp = TRUE;
+ } else
+#endif
+ {
+ x_log_backend = LOG_BACKEND_SYSLOG;
+ openlog(syslog_identifier_domain(gl.imm.syslog_identifier), LOG_PID, LOG_DAEMON);
+ }
+
+ gl.mut.init_done = TRUE;
+ gl.mut.log_backend = x_log_backend;
+ gl.mut.uses_syslog = TRUE;
+ gl.mut.debug_stderr = debug;
+
+ g_log_set_handler(syslog_identifier_domain(gl.imm.syslog_identifier),
+ G_LOG_LEVEL_MASK | G_LOG_FLAG_FATAL | G_LOG_FLAG_RECURSION,
+ nm_log_handler,
+ NULL);
+
+ G_UNLOCK(log);
+
+ if (fetch_monotonic_timestamp) {
+ /* ensure we read a monotonic timestamp. Reading the timestamp the first
+ * time causes a logging message. We don't want to do that during _nm_log_impl. */
+ nm_utils_get_monotonic_timestamp_nsec();
+ }
+
+ if (obsolete_debug_backend)
+ nm_log_dbg(LOGD_CORE,
+ "config: ignore deprecated logging backend 'debug', fallback to '%s'",
+ logging_backend);
+
+ if (nm_streq(logging_backend, NM_LOG_CONFIG_BACKEND_SYSLOG)) {
+ /* good */
+ } else if (nm_streq(logging_backend, NM_LOG_CONFIG_BACKEND_JOURNAL)) {
+#if !SYSTEMD_JOURNAL
+ nm_log_warn(LOGD_CORE,
+ "config: logging backend 'journal' is not available, fallback to 'syslog'");
+#endif
+ } else {
+ nm_log_warn(LOGD_CORE,
+ "config: invalid logging backend '%s', fallback to '%s'",
+ logging_backend,
+#if SYSTEMD_JOURNAL
+ NM_LOG_CONFIG_BACKEND_JOURNAL
+#else
+ NM_LOG_CONFIG_BACKEND_SYSLOG
+#endif
+ );
+ }
+}