From 098ac7dbc0a7f8847d357f9e25aec929237f745f Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Wed, 13 Jan 2021 16:10:37 +0100 Subject: [PATCH 1/6] shared: fix behavior of NM_G_MUTEX_LOCKED() The idea of NM_G_MUTEX_LOCKED() macro is not only to register a mutex for unlocking (via nm_auto_unlock_g_mutex) but also to lock it at the same time. That is a useful helper macro. If you have to lock the mutex yourself, it makes usage less convenient. At which point you don't need the macro anymore and you should instead take full control and lock/unlock yourself. Fix the macro and change behavior. The macro was not used so far, so it's not a problem. Fixes: dd33b3a14e9c ('shared: add nm_auto_unlock_g_mutex and NM_G_MUTEX_LOCKED() helper macros') --- src/libnm-glib-aux/nm-macros-internal.h | 9 +++++++-- 1 file changed, 7 insertions(+), 2 deletions(-) diff --git a/src/libnm-glib-aux/nm-macros-internal.h b/src/libnm-glib-aux/nm-macros-internal.h index 113a67a0d2..3f45cfaea2 100644 --- a/src/libnm-glib-aux/nm-macros-internal.h +++ b/src/libnm-glib-aux/nm-macros-internal.h @@ -1805,8 +1805,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) From 45ba49f322abc0e0fca7abda33778742fecad4ce Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Thu, 14 Jan 2021 11:43:39 +0100 Subject: [PATCH 2/6] shared: add nm_vsprintf_buf_or_alloc() macro --- src/libnm-glib-aux/nm-macros-internal.h | 48 +++++++++++++++++++++++++ 1 file changed, 48 insertions(+) diff --git a/src/libnm-glib-aux/nm-macros-internal.h b/src/libnm-glib-aux/nm-macros-internal.h index 3f45cfaea2..37dde0173b 100644 --- a/src/libnm-glib-aux/nm-macros-internal.h +++ b/src/libnm-glib-aux/nm-macros-internal.h @@ -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. */ From 29e93b17385806e50da5b2b45bf6a6c0c96a1373 Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Thu, 14 Jan 2021 11:43:56 +0100 Subject: [PATCH 3/6] logging: prefer stack buffer for logging message --- src/libnm-log-core/nm-logging.c | 11 ++++------- 1 file changed, 4 insertions(+), 7 deletions(-) diff --git a/src/libnm-log-core/nm-logging.c b/src/libnm-log-core/nm-logging.c index 06f6044e69..cb0a634b5b 100644 --- a/src/libnm-log-core/nm-logging.c +++ b/src/libnm-log-core/nm-logging.c @@ -656,8 +656,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 +699,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 +796,6 @@ _nm_log_impl(const char *file, break; } - g_free(msg); - errno = errsv; } From 597ad6aa8af62f9c3684f29d26a03423ee4d9204 Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Thu, 14 Jan 2021 10:52:07 +0100 Subject: [PATCH 4/6] logging: use NMStrBuf in _domains_to_string() --- src/libnm-log-core/nm-logging.c | 19 +++++++++++-------- 1 file changed, 11 insertions(+), 8 deletions(-) diff --git a/src/libnm-log-core/nm-logging.c b/src/libnm-log-core/nm-logging.c index cb0a634b5b..b3a4b267b9 100644 --- a/src/libnm-log-core/nm-logging.c +++ b/src/libnm-log-core/nm-logging.c @@ -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" /*****************************************************************************/ @@ -457,22 +458,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 +481,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 +490,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]; From 8dbfbce9f6cc71d70c77817c6856700d0e0e1d75 Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Wed, 13 Jan 2021 15:11:10 +0100 Subject: [PATCH 5/6] platform: add NM_LINUX_PLATFORM_FROM_PRIVATE() helper function --- src/libnm-platform/nm-linux-platform.c | 12 ++++++++++++ 1 file changed, 12 insertions(+) diff --git a/src/libnm-platform/nm-linux-platform.c b/src/libnm-platform/nm-linux-platform.c index d689dfae63..10f4bf86a2 100644 --- a/src/libnm-platform/nm-linux-platform.c +++ b/src/libnm-platform/nm-linux-platform.c @@ -463,6 +463,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" From 3c0ae1b5da288820856ed83b8fecac1fc8f86d80 Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Wed, 13 Jan 2021 15:12:54 +0100 Subject: [PATCH 6/6] platform: make global logging cache for NMPlatform's sysctl values thread-safe We have a cache for sysctl values, so that we can log changes and previous values. When resetting the log level, we prune that cache, which is done by _nm_logging_clear_platform_logging_cache(). That function is called by nm_logging_setup(), which is guaranteed to only happen on the main thread. NMPlatform in general is not thread safe (meaning, that the same NMPlatform instance cannot be used by multiple threads at the same time). There is however a reasonable aim that you could use different NMPlatform instances on their own threads. That currently doesn't work, mainly due to nm-logging which always must be done from the main thread -- unless we would set NM_THREAD_SAFE_ON_MAIN_THREAD in all of NMPlatform (which would be too expensive for something we don't actually need). That means also the sysctl getter must only be called on the main thread an all was good already. Still, we could have NMPlatform usable from multiple thread by setting NM_THREAD_SAFE_ON_MAIN_THREAD. As we are almost there to have the code thread-safe, make accessing the sysctl value cache thread-safe (even if we currently don't actually access it from multiple thread). --- src/libnm-log-core/nm-logging.c | 5 +- src/libnm-platform/nm-linux-platform.c | 72 +++++++++++++++++++++----- 2 files changed, 62 insertions(+), 15 deletions(-) diff --git a/src/libnm-log-core/nm-logging.c b/src/libnm-log-core/nm-logging.c index b3a4b267b9..2ab0d92e07 100644 --- a/src/libnm-log-core/nm-logging.c +++ b/src/libnm-log-core/nm-logging.c @@ -402,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(); } diff --git a/src/libnm-platform/nm-linux-platform.c b/src/libnm-platform/nm-linux-platform.c index 10f4bf86a2..0ee3a227ea 100644 --- a/src/libnm-platform/nm-linux-platform.c +++ b/src/libnm-platform/nm-linux-platform.c @@ -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 { @@ -5462,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); } } @@ -5496,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, @@ -5522,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); @@ -5535,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); } @@ -9374,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 = @@ -9529,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; @@ -9588,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);