fdo-mirrors/NetworkManager
1
0
Fork 0
mirror of https://gitlab.freedesktop.org/NetworkManager/NetworkManager.git synced 2025-12-20 07:00:05 +01:00
Code Issues Projects Releases Packages Wiki Activity Actions
NetworkManager/src/libnm-log-core/nm-logging.c
Thomas Haller 2665b91288
core: rename level_desc global variable 
Symbols in header files should almost always have an "nm" prefix.

That is not purely cosmetic, because core modules (like libnm-device-plugin*.so
and libnm-settings-plugin*so) should re-use the symbols of the NetworkManager
binary. For NetworkManager we generate a linker version script to only expose
the symbols that are needed. It thereby excludes symbols that don't have an "nm"
prefix.

Hence, the plugins otherwise cannot reuse the global symbol.

The only reason that we currently don't have a linker error is because
we also link the logging static library into the plugin modules. That is
wrong, because we should not duplicate these symbols.
2021-02-28 10:42:03 +01:00

1035 lines
34 KiB
C
Raw Blame History

/* 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 nm_log_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(nm_log_level_desc); i++) {
if (str->len)
g_string_append_c(str, ',');
g_string_append(str, nm_log_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", nm_log_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", nm_log_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, nm_log_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", nm_log_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", nm_log_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(nm_log_level_desc[level].syslog_level, MESSAGE_FMT, MESSAGE_ARG(g->prefix, tv, msg));
break;
default:
g_log(syslog_identifier_domain(g->syslog_identifier),
nm_log_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
);
}
}
Reference in a new issue View git blame Copy permalink