logging: merge branch 'th/platform-sysctl-logging-mt'

https://gitlab.freedesktop.org/NetworkManager/NetworkManager/-/merge_requests/772
This commit is contained in:
Thomas Haller 2021-03-09 09:37:57 +01:00
commit ca43239beb
No known key found for this signature in database
GPG key ID: 29C2366E4DFC5728
3 changed files with 144 additions and 32 deletions

View file

@ -1733,6 +1733,54 @@ nm_decode_version(guint version, guint *major, guint *minor, guint *micro)
_buf; \
})
#define nm_vsprintf_buf_or_alloc(format, va_last_arg, sbuf_stack, out_sbuf_heap, out_len) \
({ \
const char *const _format = (format); \
char *const _sbuf_stack = (sbuf_stack); \
char **const _out_sbuf_heap = (out_sbuf_heap); \
gsize *const _out_len = (out_len); \
const char * _msg; \
va_list _va_args; \
int _l; \
\
G_STATIC_ASSERT_EXPR(G_N_ELEMENTS(sbuf_stack) > sizeof(_sbuf_stack)); \
\
va_start(_va_args, va_last_arg); \
_l = g_vsnprintf(_sbuf_stack, sizeof(sbuf_stack), _format, _va_args); \
va_end(_va_args); \
\
nm_assert(_l >= 0 && _l < G_MAXINT); \
\
if ((gsize) _l >= sizeof(sbuf_stack)) { \
const gsize _l2 = ((gsize) _l) + 1u; \
char * _sbuf_heap; \
\
/* Don't use g_strdup_vprintf() here either, because that also needs
* to first determine the length (which is commonly does by printing
* to a stack allocated buffer of size 1. We already know the required
* size. */ \
\
_sbuf_heap = g_malloc(_l2); \
\
va_start(_va_args, va_last_arg); \
_l = g_vsnprintf(_sbuf_heap, _l2, _format, _va_args); \
va_end(_va_args); \
\
nm_assert(_l >= 0 && ((gsize) _l) == _l2 - 1u); \
\
_msg = _sbuf_heap; \
*_out_sbuf_heap = _sbuf_heap; \
} else { \
_msg = _sbuf_stack; \
*_out_sbuf_heap = NULL; \
} \
\
nm_assert(strlen(_msg) == (gsize) _l); \
NM_SET_OUT(_out_len, (gsize) _l); \
\
_msg; \
})
/* it is "unsafe" because @bufsize must not be a constant expression and
* there is no check at compiletime. Regardless of that, the buffer size
* must not be larger than 300 bytes, as this gets stack allocated. */
@ -1805,8 +1853,13 @@ NM_AUTO_DEFINE_FCN_VOID0(GMutex *, _nm_auto_unlock_g_mutex, g_mutex_unlock);
#define nm_auto_unlock_g_mutex nm_auto(_nm_auto_unlock_g_mutex)
#define _NM_G_MUTEX_LOCKED(lock, uniq) \
nm_auto_unlock_g_mutex GMutex *NM_UNIQ_T(nm_lock, uniq) = (lock)
#define _NM_G_MUTEX_LOCKED(lock, uniq) \
_nm_unused nm_auto_unlock_g_mutex GMutex *NM_UNIQ_T(nm_lock, uniq) = ({ \
GMutex *const _lock = (lock); \
\
g_mutex_lock(_lock); \
_lock; \
})
#define NM_G_MUTEX_LOCKED(lock) _NM_G_MUTEX_LOCKED(lock, NM_UNIQ)

View file

@ -24,6 +24,7 @@
#include "libnm-glib-aux/nm-logging-base.h"
#include "libnm-glib-aux/nm-time-utils.h"
#include "libnm-glib-aux/nm-str-buf.h"
/*****************************************************************************/
@ -401,7 +402,10 @@ nm_logging_setup(const char *level, const char *domains, char **bad_domains, GEr
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. */
* cache right away.
*
* It's important that we call this without having a lock on "log", because
* otherwise we might deadlock. */
_nm_logging_clear_platform_logging_cache();
}
@ -457,22 +461,22 @@ _domains_to_string(gboolean include_level_override,
const NMLogDomain log_state[static _LOGL_N_REAL])
{
const LogDesc *diter;
GString * str;
NMStrBuf sbuf;
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);
nm_str_buf_init(&sbuf, NM_UTILS_GET_NEXT_REALLOC_SIZE_40, FALSE);
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);
nm_str_buf_append_required_delimiter(&sbuf, ',');
nm_str_buf_append(&sbuf, diter->name);
if (!include_level_override)
continue;
@ -480,7 +484,8 @@ _domains_to_string(gboolean include_level_override,
/* 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);
nm_str_buf_append_c(&sbuf, ':');
nm_str_buf_append(&sbuf, nm_log_level_desc[i].name);
break;
}
}
@ -488,13 +493,14 @@ _domains_to_string(gboolean include_level_override,
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);
nm_str_buf_append_c(&sbuf, ':');
nm_str_buf_append(&sbuf, nm_log_level_desc[i].name);
break;
}
}
}
}
return g_string_free(str, FALSE);
return nm_str_buf_finalize(&sbuf, NULL);
}
static char _all_logging_domains_to_str[273];
@ -656,8 +662,9 @@ _nm_log_impl(const char *file,
const char *fmt,
...)
{
va_list args;
char * msg;
char msg_stack[400];
gs_free char * msg_heap = NULL;
const char * msg;
GTimeVal tv;
int errsv;
const NMLogDomain *cur_log_state;
@ -698,9 +705,7 @@ _nm_log_impl(const char *file,
errno = error;
}
va_start(args, fmt);
msg = g_strdup_vprintf(fmt, args);
va_end(args);
msg = nm_vsprintf_buf_or_alloc(fmt, fmt, msg_stack, &msg_heap, NULL);
#define MESSAGE_FMT "%s%-7s [%ld.%04ld] %s"
#define MESSAGE_ARG(prefix, tv, msg) \
@ -797,8 +802,6 @@ _nm_log_impl(const char *file,
break;
}
g_free(msg);
errno = errsv;
}

View file

@ -429,6 +429,7 @@ typedef struct {
GHashTable *sysctl_get_prev_values;
CList sysctl_list;
CList sysctl_clear_cache_lst;
NMUdevClient *udev_client;
@ -447,6 +448,7 @@ typedef struct {
int is_handling;
} delayed_action;
} NMLinuxPlatformPrivate;
struct _NMLinuxPlatform {
@ -463,6 +465,18 @@ G_DEFINE_TYPE(NMLinuxPlatform, nm_linux_platform, NM_TYPE_PLATFORM)
#define NM_LINUX_PLATFORM_GET_PRIVATE(self) \
_NM_GET_PRIVATE(self, NMLinuxPlatform, NM_IS_LINUX_PLATFORM, NMPlatform)
static NMPlatform *
NM_LINUX_PLATFORM_FROM_PRIVATE(NMLinuxPlatformPrivate *priv)
{
gpointer self;
nm_assert(priv);
self = (((char *) priv) - G_STRUCT_OFFSET(NMLinuxPlatform, _priv));
nm_assert(NM_IS_LINUX_PLATFORM(self));
return self;
}
/*****************************************************************************/
#define _NMLOG_PREFIX_NAME "platform-linux"
@ -5450,19 +5464,28 @@ sysctl_set_async(NMPlatform * platform,
g_object_unref(task);
}
static GSList *sysctl_clear_cache_list;
static CList sysctl_clear_cache_lst_head = C_LIST_INIT(sysctl_clear_cache_lst_head);
static GMutex sysctl_clear_cache_lock;
void
_nm_logging_clear_platform_logging_cache(void)
{
while (sysctl_clear_cache_list) {
NMLinuxPlatformPrivate *priv = NM_LINUX_PLATFORM_GET_PRIVATE(sysctl_clear_cache_list->data);
NM_G_MUTEX_LOCKED(&sysctl_clear_cache_lock);
sysctl_clear_cache_list =
g_slist_delete_link(sysctl_clear_cache_list, sysctl_clear_cache_list);
while (TRUE) {
NMLinuxPlatformPrivate *priv;
g_hash_table_destroy(priv->sysctl_get_prev_values);
priv->sysctl_get_prev_values = NULL;
priv = c_list_first_entry(&sysctl_clear_cache_lst_head,
NMLinuxPlatformPrivate,
sysctl_clear_cache_lst);
if (!priv)
return;
nm_assert(NM_IS_LINUX_PLATFORM(NM_LINUX_PLATFORM_FROM_PRIVATE(priv)));
c_list_unlink(&priv->sysctl_clear_cache_lst);
nm_clear_pointer(&priv->sysctl_get_prev_values, g_hash_table_destroy);
}
}
@ -5484,11 +5507,33 @@ sysctl_cache_entry_free(SysctlCacheEntry *entry)
static void
_log_dbg_sysctl_get_impl(NMPlatform *platform, const char *pathid, const char *contents)
{
/* Note that we only have on global mutex for all NMPlatform instances. But in general
* we hardly run with concurrent threads and there are few NMPlatform instances. So
* this is acceptable.
*
* Note that there are only three functions that touch
* - sysctl_clear_cache_lst_head
* - priv->sysctl_get_prev_values
* - priv->sysctl_list
* - priv->sysctl_clear_cache_lst
* these are:
* 1) _nm_logging_clear_platform_logging_cache()
* 2) _log_dbg_sysctl_get_impl()
* 3) finalize()
*
* Note that 2) keeps the lock while also log! Logging itself may take a lock
* and it may even call back into our code again (like g_log() handlers
* and _nm_logging_clear_platform_logging_cache() which is called by logging).
*
* But in practice this is safe because logging code releases its lock before
* calling _nm_logging_clear_platform_logging_cache().
**/
NM_G_MUTEX_LOCKED(&sysctl_clear_cache_lock);
NMLinuxPlatformPrivate *priv = NM_LINUX_PLATFORM_GET_PRIVATE(platform);
SysctlCacheEntry * entry = NULL;
if (!priv->sysctl_get_prev_values) {
sysctl_clear_cache_list = g_slist_prepend(sysctl_clear_cache_list, platform);
c_list_link_tail(&sysctl_clear_cache_lst_head, &priv->sysctl_clear_cache_lst);
c_list_init(&priv->sysctl_list);
priv->sysctl_get_prev_values =
g_hash_table_new_full(nm_pstr_hash,
@ -5510,6 +5555,7 @@ _log_dbg_sysctl_get_impl(NMPlatform *platform, const char *pathid, const char *c
g_free(entry->value);
entry->value = g_strdup(contents);
}
nm_c_list_move_front(&priv->sysctl_list, &entry->lst);
} else {
gs_free char * contents_escaped = g_strescape(contents, NULL);
@ -5523,7 +5569,7 @@ _log_dbg_sysctl_get_impl(NMPlatform *platform, const char *pathid, const char *c
memcpy(entry->path_data, pathid, len + 1);
/* Remove oldest entry when the cache becomes too big */
if (g_hash_table_size(priv->sysctl_get_prev_values) > 1000) {
if (g_hash_table_size(priv->sysctl_get_prev_values) > 1000u) {
old = c_list_last_entry(&priv->sysctl_list, SysctlCacheEntry, lst);
g_hash_table_remove(priv->sysctl_get_prev_values, old);
}
@ -9362,6 +9408,9 @@ nm_linux_platform_init(NMLinuxPlatform *self)
{
NMLinuxPlatformPrivate *priv = NM_LINUX_PLATFORM_GET_PRIVATE(self);
c_list_init(&priv->sysctl_clear_cache_lst);
c_list_init(&priv->sysctl_list);
priv->delayed_action.list_master_connected = g_ptr_array_new();
priv->delayed_action.list_refresh_link = g_ptr_array_new();
priv->delayed_action.list_wait_for_nl_response =
@ -9517,8 +9566,8 @@ path_is_read_only_fs(const char *path)
return TRUE;
/* On NFS, statvfs() might not reflect whether we can actually
* write to the remote share. Let's try again with
* access(W_OK) which is more reliable, at least sometimes. */
* write to the remote share. Let's try again with
* access(W_OK) which is more reliable, at least sometimes. */
if (access(path, W_OK) < 0 && errno == EROFS)
return TRUE;
@ -9576,9 +9625,16 @@ finalize(GObject *object)
nl_socket_free(priv->nlh);
if (priv->sysctl_get_prev_values) {
sysctl_clear_cache_list = g_slist_remove(sysctl_clear_cache_list, object);
g_hash_table_destroy(priv->sysctl_get_prev_values);
{
NM_G_MUTEX_LOCKED(&sysctl_clear_cache_lock);
if (priv->sysctl_get_prev_values) {
c_list_unlink(&priv->sysctl_clear_cache_lst);
g_hash_table_destroy(priv->sysctl_get_prev_values);
}
nm_assert(c_list_is_empty(&priv->sysctl_clear_cache_lst));
nm_assert(c_list_is_empty(&priv->sysctl_list));
}
priv->udev_client = nm_udev_client_destroy(priv->udev_client);