From 17dc6a9da68a0809cd8d15003d7c940a898a5fb3 Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Fri, 24 May 2019 08:46:48 +0200 Subject: [PATCH 01/26] shared: add _NM_ENSURE_TYPE_CONST() The sole purpose of this is more type-safe macros. An alternative solution would be to define a function instead of a macro. But if the function is unused (currently!) you get a compiler warning (on some compilers even when marking the function as "static inline", if it's in the source file). A workaround for that would be to mark the function as _nm_unused, or to use a macro instead. _NM_ENSURE_TYPE_CONST() is to aid the macro solution. --- shared/nm-glib-aux/nm-macros-internal.h | 2 ++ 1 file changed, 2 insertions(+) diff --git a/shared/nm-glib-aux/nm-macros-internal.h b/shared/nm-glib-aux/nm-macros-internal.h index 77288dde5..1ff90dc5d 100644 --- a/shared/nm-glib-aux/nm-macros-internal.h +++ b/shared/nm-glib-aux/nm-macros-internal.h @@ -635,8 +635,10 @@ NM_G_ERROR_MSG (GError *error) * It's useful to check the let the compiler ensure that @value is * of a certain type. */ #define _NM_ENSURE_TYPE(type, value) (_Generic ((value), type: (value))) +#define _NM_ENSURE_TYPE_CONST(type, value) (_Generic ((value), const type: ((const type) (value)), type: ((const type) (value)))) #else #define _NM_ENSURE_TYPE(type, value) (value) +#define _NM_ENSURE_TYPE_CONST(type, value) ((const type) (value)) #endif #if _NM_CC_SUPPORT_GENERIC From dd72696af77db85186e8454c3e4618d790ac159f Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Thu, 23 May 2019 09:24:19 +0200 Subject: [PATCH 02/26] dispatcher/trivial: rename logging levels What we currently print as "info" level is too verbose for regular operation. It prints two messages for every dispatcher event. That's already for debugging. Next that will be downgraded, so rename "debug" to "trace" and "info" to "debug". There is only renaming, no change in behavior. --- dispatcher/nm-dispatcher.c | 28 ++++++++++++++-------------- 1 file changed, 14 insertions(+), 14 deletions(-) diff --git a/dispatcher/nm-dispatcher.c b/dispatcher/nm-dispatcher.c index 231a3f9a8..f1eb76bc6 100644 --- a/dispatcher/nm-dispatcher.c +++ b/dispatcher/nm-dispatcher.c @@ -158,7 +158,7 @@ struct Request { if (!__request) \ __request = __script->request; \ nm_assert (__request && (!__script || __script->request == __request)); \ - if ((log_always) || _LOG_R_D_enabled (__request)) { \ + if ((log_always) || _LOG_R_T_enabled (__request)) { \ if (FALSE) { \ /* g_message() alone does not warn about invalid format. Add a dummy printf() statement to * get a compiler warning about wrong format. */ \ @@ -169,17 +169,17 @@ struct Request { } G_STMT_END static gboolean -_LOG_R_D_enabled (const Request *request) +_LOG_R_T_enabled (const Request *request) { return request->debug; } -#define _LOG_R_D(_request, ...) _LOG(_request, NULL, FALSE, g_debug, __VA_ARGS__) -#define _LOG_R_I(_request, ...) _LOG(_request, NULL, TRUE, g_info, __VA_ARGS__) +#define _LOG_R_T(_request, ...) _LOG(_request, NULL, FALSE, g_debug, __VA_ARGS__) +#define _LOG_R_D(_request, ...) _LOG(_request, NULL, TRUE, g_info, __VA_ARGS__) #define _LOG_R_W(_request, ...) _LOG(_request, NULL, TRUE, g_warning, __VA_ARGS__) -#define _LOG_S_D(_script, ...) _LOG(NULL, _script, FALSE, g_debug, __VA_ARGS__) -#define _LOG_S_I(_script, ...) _LOG(NULL, _script, TRUE, g_info, __VA_ARGS__) +#define _LOG_S_T(_script, ...) _LOG(NULL, _script, FALSE, g_debug, __VA_ARGS__) +#define _LOG_S_D(_script, ...) _LOG(NULL, _script, TRUE, g_info, __VA_ARGS__) #define _LOG_S_W(_script, ...) _LOG(NULL, _script, TRUE, g_warning, __VA_ARGS__) /*****************************************************************************/ @@ -258,7 +258,7 @@ next_request (Handler *h, Request *request) return FALSE; } - _LOG_R_I (request, "start running ordered scripts..."); + _LOG_R_D (request, "start running ordered scripts..."); h->current_request = request; @@ -301,7 +301,7 @@ complete_request (Request *request) ret = g_variant_new ("(a(sus))", &results); g_dbus_method_invocation_return_value (request->context, ret); - _LOG_R_D (request, "completed (%u scripts)", request->scripts->len); + _LOG_R_T (request, "completed (%u scripts)", request->scripts->len); if (handler->current_request == request) handler->current_request = NULL; @@ -418,7 +418,7 @@ script_watch_cb (GPid pid, int status, gpointer user_data) } if (script->result == DISPATCH_RESULT_SUCCESS) { - _LOG_S_D (script, "complete"); + _LOG_S_T (script, "complete"); } else { script->result = DISPATCH_RESULT_FAILED; _LOG_S_W (script, "complete: failed with %s", script->error); @@ -533,7 +533,7 @@ script_dispatch (ScriptInfo *script) argv[2] = request->action; argv[3] = NULL; - _LOG_S_D (script, "run script%s", script->wait ? "" : " (no-wait)"); + _LOG_S_T (script, "run script%s", script->wait ? "" : " (no-wait)"); if (g_spawn_async ("/", argv, request->envp, G_SPAWN_DO_NOT_REAP_CHILD, NULL, NULL, &script->pid, &error)) { script->watch_id = g_child_watch_add (script->pid, (GChildWatchFunc) script_watch_cb, script); @@ -761,11 +761,11 @@ handle_action (NMDBusDispatcher *dbus_dispatcher, } g_slist_free (sorted_scripts); - _LOG_R_I (request, "new request (%u scripts)", request->scripts->len); - if ( _LOG_R_D_enabled (request) + _LOG_R_D (request, "new request (%u scripts)", request->scripts->len); + if ( _LOG_R_T_enabled (request) && request->envp) { for (p = request->envp; *p; p++) - _LOG_R_D (request, "environment: %s", *p); + _LOG_R_T (request, "environment: %s", *p); } if (error_message || request->scripts->len == 0) { @@ -774,7 +774,7 @@ handle_action (NMDBusDispatcher *dbus_dispatcher, if (error_message) _LOG_R_W (request, "completed: invalid request: %s", error_message); else - _LOG_R_I (request, "completed: no scripts"); + _LOG_R_D (request, "completed: no scripts"); results = g_variant_new_array (G_VARIANT_TYPE ("(sus)"), NULL, 0); g_dbus_method_invocation_return_value (context, g_variant_new ("(@a(sus))", results)); From 58704a37aed1b63bad68a85e93479d9d39f46448 Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Thu, 23 May 2019 09:10:07 +0200 Subject: [PATCH 03/26] dispatcher: don't print debug messages of dispatcher in regular mode Previously, we would log several messages with level "debug" / g_info(). _LOG_R_D (request, "start running ordered scripts..."); _LOG_R_D (request, "new request (%u scripts)", request->scripts->len); _LOG_R_D (request, "completed: no scripts"); Note that this effectively logs a message for every event. I think that is to verbose and not suitable for regular logging. Only enable these messages if debug logging is enabled. As such, these debug level messsages now are enabled together with the trace level messages. --- dispatcher/nm-dispatcher.c | 7 ++++--- 1 file changed, 4 insertions(+), 3 deletions(-) diff --git a/dispatcher/nm-dispatcher.c b/dispatcher/nm-dispatcher.c index f1eb76bc6..4a36d225c 100644 --- a/dispatcher/nm-dispatcher.c +++ b/dispatcher/nm-dispatcher.c @@ -169,17 +169,18 @@ struct Request { } G_STMT_END static gboolean -_LOG_R_T_enabled (const Request *request) +_LOG_R_D_enabled (const Request *request) { return request->debug; } +#define _LOG_R_T_enabled(request) _LOG_R_D_enabled (request) #define _LOG_R_T(_request, ...) _LOG(_request, NULL, FALSE, g_debug, __VA_ARGS__) -#define _LOG_R_D(_request, ...) _LOG(_request, NULL, TRUE, g_info, __VA_ARGS__) +#define _LOG_R_D(_request, ...) _LOG(_request, NULL, FALSE, g_info, __VA_ARGS__) #define _LOG_R_W(_request, ...) _LOG(_request, NULL, TRUE, g_warning, __VA_ARGS__) #define _LOG_S_T(_script, ...) _LOG(NULL, _script, FALSE, g_debug, __VA_ARGS__) -#define _LOG_S_D(_script, ...) _LOG(NULL, _script, TRUE, g_info, __VA_ARGS__) +#define _LOG_S_D(_script, ...) _LOG(NULL, _script, FALSE, g_info, __VA_ARGS__) #define _LOG_S_W(_script, ...) _LOG(NULL, _script, TRUE, g_warning, __VA_ARGS__) /*****************************************************************************/ From 8518a873873cb1f50b583685aaf6d51df2012e6b Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Thu, 23 May 2019 08:47:07 +0200 Subject: [PATCH 04/26] dispatcher: log messages about loading scripts per-request The messages about loading the scripts are releated to a particular request. Hence, they should be logged with that context. Also, we should avoid using g_log() directly. Use our logging macros instead. --- dispatcher/nm-dispatcher.c | 32 +++++++++++++++++--------------- 1 file changed, 17 insertions(+), 15 deletions(-) diff --git a/dispatcher/nm-dispatcher.c b/dispatcher/nm-dispatcher.c index 4a36d225c..6f49b67ee 100644 --- a/dispatcher/nm-dispatcher.c +++ b/dispatcher/nm-dispatcher.c @@ -587,7 +587,7 @@ _compare_basenames (gconstpointer a, gconstpointer b) } static void -_find_scripts (GHashTable *scripts, const char *base, const char *subdir) +_find_scripts (Request *request, GHashTable *scripts, const char *base, const char *subdir) { const char *filename; gs_free char *dirname = NULL; @@ -597,8 +597,8 @@ _find_scripts (GHashTable *scripts, const char *base, const char *subdir) dirname = g_build_filename (base, "dispatcher.d", subdir, NULL); if (!(dir = g_dir_open (dirname, 0, &error))) { - g_message ("find-scripts: Failed to open dispatcher directory '%s': %s", - dirname, error->message); + _LOG_R_W (request, "find-scripts: Failed to open dispatcher directory '%s': %s", + dirname, error->message); g_error_free (error); return; } @@ -616,26 +616,28 @@ _find_scripts (GHashTable *scripts, const char *base, const char *subdir) } static GSList * -find_scripts (const char *str_action) +find_scripts (Request *request) { gs_unref_hashtable GHashTable *scripts = NULL; GSList *script_list = NULL; GHashTableIter iter; - const char *subdir = NULL; + const char *subdir; char *path; char *filename; - if ( strcmp (str_action, NMD_ACTION_PRE_UP) == 0 - || strcmp (str_action, NMD_ACTION_VPN_PRE_UP) == 0) + if (NM_IN_STRSET (request->action, NMD_ACTION_PRE_UP, + NMD_ACTION_VPN_PRE_UP)) subdir = "pre-up.d"; - else if ( strcmp (str_action, NMD_ACTION_PRE_DOWN) == 0 - || strcmp (str_action, NMD_ACTION_VPN_PRE_DOWN) == 0) + else if (NM_IN_STRSET (request->action, NMD_ACTION_PRE_DOWN, + NMD_ACTION_VPN_PRE_DOWN)) subdir = "pre-down.d"; + else + subdir = NULL; scripts = g_hash_table_new_full (g_str_hash, g_str_equal, g_free, g_free); - _find_scripts (scripts, NMLIBDIR, subdir); - _find_scripts (scripts, NMCONFDIR, subdir); + _find_scripts (request, scripts, NMLIBDIR, subdir); + _find_scripts (request, scripts, NMCONFDIR, subdir); g_hash_table_iter_init (&iter, scripts); while (g_hash_table_iter_next (&iter, (gpointer *) &filename, (gpointer *) &path)) { @@ -653,11 +655,11 @@ find_scripts (const char *str_action) err = stat (path, &st); if (err) - g_warning ("find-scripts: Failed to stat '%s': %d", path, err); + _LOG_R_W (request, "find-scripts: Failed to stat '%s': %d", path, err); else if (!S_ISREG (st.st_mode)) ; /* silently skip. */ else if (!check_permissions (&st, &err_msg)) - g_warning ("find-scripts: Cannot execute '%s': %s", path, err_msg); + _LOG_R_W (request, "find-scripts: Cannot execute '%s': %s", path, err_msg); else { /* success */ script_list = g_slist_prepend (script_list, g_strdup (path)); @@ -724,8 +726,6 @@ handle_action (NMDBusDispatcher *dbus_dispatcher, guint i, num_nowait = 0; const char *error_message = NULL; - sorted_scripts = find_scripts (str_action); - request = g_slice_new0 (Request); request->request_id = ++request_id_counter; request->handler = h; @@ -751,6 +751,8 @@ handle_action (NMDBusDispatcher *dbus_dispatcher, &error_message); request->scripts = g_ptr_array_new_full (5, script_info_free); + + sorted_scripts = find_scripts (request); for (iter = sorted_scripts; iter; iter = g_slist_next (iter)) { ScriptInfo *s; From b4d678b31489fbc68840b7da87b3f2039007371f Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Thu, 23 May 2019 08:47:07 +0200 Subject: [PATCH 05/26] dispatcher: silence message about non-existing dispatcher directory MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Silence messages like find-scripts: Failed to open dispatcher directory '/usr/lib/NetworkManager/dispatcher.d': Error opening directory “/usr/lib/NetworkManager/dispatcher.d”: No such file or directory find-scripts: Failed to open dispatcher directory '/usr/lib/NetworkManager/dispatcher.d/pre-up.d': Error opening directory “/usr/lib/NetworkManager/dispatcher.d/pre-up.d”: No such file or directory --- dispatcher/nm-dispatcher.c | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/dispatcher/nm-dispatcher.c b/dispatcher/nm-dispatcher.c index 6f49b67ee..4d9d47b3c 100644 --- a/dispatcher/nm-dispatcher.c +++ b/dispatcher/nm-dispatcher.c @@ -597,8 +597,10 @@ _find_scripts (Request *request, GHashTable *scripts, const char *base, const ch dirname = g_build_filename (base, "dispatcher.d", subdir, NULL); if (!(dir = g_dir_open (dirname, 0, &error))) { - _LOG_R_W (request, "find-scripts: Failed to open dispatcher directory '%s': %s", - dirname, error->message); + if (!g_error_matches (error, G_FILE_ERROR, G_FILE_ERROR_NOENT)) { + _LOG_R_W (request, "find-scripts: Failed to open dispatcher directory '%s': %s", + dirname, error->message); + } g_error_free (error); return; } From 23286b2afaf918fdab5eeeb5e0d9beca6a490261 Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Thu, 23 May 2019 09:46:47 +0200 Subject: [PATCH 06/26] dispatcher: use logging macros instead of g_log() directly Also cleanup the logging macros. --- dispatcher/nm-dispatcher.c | 127 +++++++++++++++++++++++-------------- 1 file changed, 78 insertions(+), 49 deletions(-) diff --git a/dispatcher/nm-dispatcher.c b/dispatcher/nm-dispatcher.c index 4d9d47b3c..8c0fd449b 100644 --- a/dispatcher/nm-dispatcher.c +++ b/dispatcher/nm-dispatcher.c @@ -135,53 +135,82 @@ struct Request { /*****************************************************************************/ -#define __LOG_print(print_cmd, _request, _script, ...) \ +#define __LOG_print(print_cmd, ...) \ G_STMT_START { \ - nm_assert ((_request) && (!(_script) || (_script)->request == (_request))); \ - print_cmd ("req:%u '%s'%s%s%s%s%s%s: " _NM_UTILS_MACRO_FIRST (__VA_ARGS__), \ - (_request)->request_id, \ - (_request)->action, \ - (_request)->iface ? " [" : "", \ - (_request)->iface ?: "", \ - (_request)->iface ? "]" : "", \ - (_script) ? ", \"" : "", \ - (_script) ? (_script)->script : "", \ - (_script) ? "\"" : "" \ - _NM_UTILS_MACRO_REST (__VA_ARGS__)); \ - } G_STMT_END - -#define _LOG(_request, _script, log_always, print_cmd, ...) \ - G_STMT_START { \ - const Request *__request = (_request); \ - const ScriptInfo *__script = (_script); \ - \ - if (!__request) \ - __request = __script->request; \ - nm_assert (__request && (!__script || __script->request == __request)); \ - if ((log_always) || _LOG_R_T_enabled (__request)) { \ - if (FALSE) { \ - /* g_message() alone does not warn about invalid format. Add a dummy printf() statement to - * get a compiler warning about wrong format. */ \ - __LOG_print (printf, __request, __script, __VA_ARGS__); \ - } \ - __LOG_print (print_cmd, __request, __script, __VA_ARGS__); \ + if (FALSE) { \ + /* g_message() alone does not warn about invalid format. Add a dummy printf() statement to + * get a compiler warning about wrong format. */ \ + printf (__VA_ARGS__); \ } \ + print_cmd (__VA_ARGS__); \ } G_STMT_END -static gboolean -_LOG_R_D_enabled (const Request *request) -{ - return request->debug; -} +#define __LOG_print_R(print_cmd, _request, ...) \ + G_STMT_START { \ + __LOG_print (print_cmd, \ + "req:%u '%s'%s%s%s" _NM_UTILS_MACRO_FIRST (__VA_ARGS__), \ + (_request)->request_id, \ + (_request)->action, \ + (_request)->iface ? " [" : "", \ + (_request)->iface ?: "", \ + (_request)->iface ? "]" : "" \ + _NM_UTILS_MACRO_REST (__VA_ARGS__)); \ + } G_STMT_END + +#define __LOG_print_S(print_cmd, _request, _script, ...) \ + G_STMT_START { \ + __LOG_print_R (print_cmd, \ + (_request), \ + "%s%s%s" _NM_UTILS_MACRO_FIRST (__VA_ARGS__), \ + (_script) ? ", \"" : "", \ + (_script) ? (_script)->script : "", \ + (_script) ? "\"" : "" \ + _NM_UTILS_MACRO_REST (__VA_ARGS__)); \ + } G_STMT_END + +#define _LOG_X_(enabled_cmd, print_cmd, ...) \ + G_STMT_START { \ + if (enabled_cmd) \ + __LOG_print (print_cmd, __VA_ARGS__); \ + } G_STMT_END + +#define _LOG_R_(enabled_cmd, x_request, print_cmd, ...) \ + G_STMT_START { \ + const Request *const _request = (x_request); \ + \ + nm_assert (_request); \ + if (enabled_cmd) \ + __LOG_print_R (print_cmd, _request, ": "__VA_ARGS__); \ + } G_STMT_END + +#define _LOG_S_(enabled_cmd, x_script, print_cmd, ...) \ + G_STMT_START { \ + const ScriptInfo *const _script = (x_script); \ + const Request *const _request = _script ? _script->request : NULL; \ + \ + nm_assert (_script && _request); \ + if (enabled_cmd) \ + __LOG_print_S (print_cmd, _request, _script, ": "__VA_ARGS__); \ + } G_STMT_END + +#define _LOG_X_D_enabled() (debug) +#define _LOG_X_T_enabled() _LOG_X_D_enabled () + +#define _LOG_R_D_enabled(request) (_NM_ENSURE_TYPE_CONST (Request *, request)->debug) #define _LOG_R_T_enabled(request) _LOG_R_D_enabled (request) -#define _LOG_R_T(_request, ...) _LOG(_request, NULL, FALSE, g_debug, __VA_ARGS__) -#define _LOG_R_D(_request, ...) _LOG(_request, NULL, FALSE, g_info, __VA_ARGS__) -#define _LOG_R_W(_request, ...) _LOG(_request, NULL, TRUE, g_warning, __VA_ARGS__) +#define _LOG_X_T(...) _LOG_X_ (_LOG_X_T_enabled (), g_debug, __VA_ARGS__) +#define _LOG_X_D(...) _LOG_X_ (_LOG_X_D_enabled (), g_info, __VA_ARGS__) +#define _LOG_X_I(...) _LOG_X_ (TRUE, g_message, __VA_ARGS__) +#define _LOG_X_W(...) _LOG_X_ (TRUE, g_warning, __VA_ARGS__) -#define _LOG_S_T(_script, ...) _LOG(NULL, _script, FALSE, g_debug, __VA_ARGS__) -#define _LOG_S_D(_script, ...) _LOG(NULL, _script, FALSE, g_info, __VA_ARGS__) -#define _LOG_S_W(_script, ...) _LOG(NULL, _script, TRUE, g_warning, __VA_ARGS__) +#define _LOG_R_T(request, ...) _LOG_R_ (_LOG_R_T_enabled (_request), request, g_debug, __VA_ARGS__) +#define _LOG_R_D(request, ...) _LOG_R_ (_LOG_R_D_enabled (_request), request, g_info, __VA_ARGS__) +#define _LOG_R_W(request, ...) _LOG_R_ (TRUE, request, g_warning, __VA_ARGS__) + +#define _LOG_S_T(script, ...) _LOG_S_ (_LOG_R_T_enabled (_request), script, g_debug, __VA_ARGS__) +#define _LOG_S_D(script, ...) _LOG_S_ (_LOG_R_D_enabled (_request), script, g_info, __VA_ARGS__) +#define _LOG_S_W(script, ...) _LOG_S_ (TRUE, script, g_warning, __VA_ARGS__) /*****************************************************************************/ @@ -854,17 +883,17 @@ on_name_lost (GDBusConnection *connection, { if (!connection) { if (!ever_acquired_name) { - g_warning ("Could not get the system bus. Make sure the message bus daemon is running!"); + _LOG_X_W ("Could not get the system bus. Make sure the message bus daemon is running!"); exit (1); } else { - g_message ("System bus stopped. Exiting"); + _LOG_X_I ("System bus stopped. Exiting"); exit (0); } } else if (!ever_acquired_name) { - g_warning ("Could not acquire the " NM_DISPATCHER_DBUS_SERVICE " service."); + _LOG_X_W ("Could not acquire the " NM_DISPATCHER_DBUS_SERVICE " service."); exit (1); } else { - g_message ("Lost the " NM_DISPATCHER_DBUS_SERVICE " name. Exiting"); + _LOG_X_I ("Lost the " NM_DISPATCHER_DBUS_SERVICE " name. Exiting"); exit (0); } } @@ -923,7 +952,7 @@ signal_handler (gpointer user_data) { int signo = GPOINTER_TO_INT (user_data); - g_message ("Caught signal %d, shutting down...", signo); + _LOG_X_I ("Caught signal %d, shutting down...", signo); g_main_loop_quit (loop); return G_SOURCE_REMOVE; @@ -948,7 +977,7 @@ main (int argc, char **argv) g_option_context_add_main_entries (opt_ctx, entries, NULL); if (!g_option_context_parse (opt_ctx, &argc, &argv, &error)) { - g_warning ("Error parsing command line arguments: %s", error->message); + _LOG_X_W ("Error parsing command line arguments: %s", error->message); g_error_free (error); return 1; } @@ -973,8 +1002,8 @@ main (int argc, char **argv) bus = g_bus_get_sync (G_BUS_TYPE_SYSTEM, NULL, &error); if (!bus) { - g_warning ("Could not get the system bus (%s). Make sure the message bus daemon is running!", - error->message); + _LOG_X_W ("Could not get the system bus (%s). Make sure the message bus daemon is running!", + error->message); g_error_free (error); return 1; } @@ -985,7 +1014,7 @@ main (int argc, char **argv) NM_DISPATCHER_DBUS_PATH, &error); if (error) { - g_warning ("Could not export Dispatcher D-Bus interface: %s", error->message); + _LOG_X_W ("Could not export Dispatcher D-Bus interface: %s", error->message); g_error_free (error); return 1; } From bccf754347259805468ad28b0e48008c5d18e4ac Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Thu, 23 May 2019 10:47:46 +0200 Subject: [PATCH 07/26] dispatcher: namespace global variables in a struct "gl" --- dispatcher/nm-dispatcher.c | 42 ++++++++++++++++++++------------------ 1 file changed, 22 insertions(+), 20 deletions(-) diff --git a/dispatcher/nm-dispatcher.c b/dispatcher/nm-dispatcher.c index 8c0fd449b..ad4406e2e 100644 --- a/dispatcher/nm-dispatcher.c +++ b/dispatcher/nm-dispatcher.c @@ -36,11 +36,13 @@ #include "nmdbus-dispatcher.h" -static GMainLoop *loop = NULL; -static gboolean debug = FALSE; -static gboolean persist = FALSE; -static guint quit_id; -static guint request_id_counter = 0; +static struct { + GMainLoop *loop; + gboolean debug; + gboolean persist; + guint quit_id; + guint request_id_counter; +} gl; typedef struct Request Request; @@ -193,7 +195,7 @@ struct Request { __LOG_print_S (print_cmd, _request, _script, ": "__VA_ARGS__); \ } G_STMT_END -#define _LOG_X_D_enabled() (debug) +#define _LOG_X_D_enabled() (gl.debug) #define _LOG_X_T_enabled() _LOG_X_D_enabled () #define _LOG_R_D_enabled(request) (_NM_ENSURE_TYPE_CONST (Request *, request)->debug) @@ -241,16 +243,16 @@ request_free (Request *request) static gboolean quit_timeout_cb (gpointer user_data) { - g_main_loop_quit (loop); + g_main_loop_quit (gl.loop); return FALSE; } static void quit_timeout_reschedule (void) { - if (!persist) { - nm_clear_g_source (&quit_id); - quit_id = g_timeout_add_seconds (10, quit_timeout_cb, NULL); + if (!gl.persist) { + nm_clear_g_source (&gl.quit_id); + gl.quit_id = g_timeout_add_seconds (10, quit_timeout_cb, NULL); } } @@ -758,9 +760,9 @@ handle_action (NMDBusDispatcher *dbus_dispatcher, const char *error_message = NULL; request = g_slice_new0 (Request); - request->request_id = ++request_id_counter; + request->request_id = ++gl.request_id_counter; request->handler = h; - request->debug = request_debug || debug; + request->debug = request_debug || gl.debug; request->context = context; request->action = g_strdup (str_action); @@ -817,7 +819,7 @@ handle_action (NMDBusDispatcher *dbus_dispatcher, return TRUE; } - nm_clear_g_source (&quit_id); + nm_clear_g_source (&gl.quit_id); h->num_requests_pending++; @@ -953,7 +955,7 @@ signal_handler (gpointer user_data) int signo = GPOINTER_TO_INT (user_data); _LOG_X_I ("Caught signal %d, shutting down...", signo); - g_main_loop_quit (loop); + g_main_loop_quit (gl.loop); return G_SOURCE_REMOVE; } @@ -967,8 +969,8 @@ main (int argc, char **argv) Handler *handler; GOptionEntry entries[] = { - { "debug", 0, 0, G_OPTION_ARG_NONE, &debug, "Output to console rather than syslog", NULL }, - { "persist", 0, 0, G_OPTION_ARG_NONE, &persist, "Don't quit after a short timeout", NULL }, + { "debug", 0, 0, G_OPTION_ARG_NONE, &gl.debug, "Output to console rather than syslog", NULL }, + { "persist", 0, 0, G_OPTION_ARG_NONE, &gl.persist, "Don't quit after a short timeout", NULL }, { NULL } }; @@ -987,7 +989,7 @@ main (int argc, char **argv) g_unix_signal_add (SIGTERM, signal_handler, GINT_TO_POINTER (SIGTERM)); g_unix_signal_add (SIGINT, signal_handler, GINT_TO_POINTER (SIGINT)); - if (debug) { + if (gl.debug) { if (!g_getenv ("G_MESSAGES_DEBUG")) { /* we log our regular messages using g_debug() and g_info(). * When we redirect glib logging to syslog, there is no problem. @@ -998,7 +1000,7 @@ main (int argc, char **argv) } else logging_setup (); - loop = g_main_loop_new (NULL, FALSE); + gl.loop = g_main_loop_new (NULL, FALSE); bus = g_bus_get_sync (G_BUS_TYPE_SYSTEM, NULL, &error); if (!bus) { @@ -1029,12 +1031,12 @@ main (int argc, char **argv) quit_timeout_reschedule (); - g_main_loop_run (loop); + g_main_loop_run (gl.loop); g_queue_free (handler->requests_waiting); g_object_unref (handler); - if (!debug) + if (!gl.debug) logging_shutdown (); return 0; From a454e418d452708ff9515f73bac575a7f4d48f82 Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Thu, 23 May 2019 10:49:06 +0200 Subject: [PATCH 08/26] dispatcher: unref main loop at exit and remove signal handler sources --- dispatcher/nm-dispatcher.c | 16 ++++++++++++---- 1 file changed, 12 insertions(+), 4 deletions(-) diff --git a/dispatcher/nm-dispatcher.c b/dispatcher/nm-dispatcher.c index ad4406e2e..a666ef719 100644 --- a/dispatcher/nm-dispatcher.c +++ b/dispatcher/nm-dispatcher.c @@ -243,8 +243,9 @@ request_free (Request *request) static gboolean quit_timeout_cb (gpointer user_data) { + gl.quit_id = 0; g_main_loop_quit (gl.loop); - return FALSE; + return G_SOURCE_REMOVE; } static void @@ -957,7 +958,7 @@ signal_handler (gpointer user_data) _LOG_X_I ("Caught signal %d, shutting down...", signo); g_main_loop_quit (gl.loop); - return G_SOURCE_REMOVE; + return G_SOURCE_CONTINUE; } int @@ -967,6 +968,8 @@ main (int argc, char **argv) GError *error = NULL; GDBusConnection *bus; Handler *handler; + guint signal_id_term; + guint signal_id_int; GOptionEntry entries[] = { { "debug", 0, 0, G_OPTION_ARG_NONE, &gl.debug, "Output to console rather than syslog", NULL }, @@ -986,8 +989,8 @@ main (int argc, char **argv) g_option_context_free (opt_ctx); - g_unix_signal_add (SIGTERM, signal_handler, GINT_TO_POINTER (SIGTERM)); - g_unix_signal_add (SIGINT, signal_handler, GINT_TO_POINTER (SIGINT)); + signal_id_term = g_unix_signal_add (SIGTERM, signal_handler, GINT_TO_POINTER (SIGTERM)); + signal_id_int = g_unix_signal_add (SIGINT, signal_handler, GINT_TO_POINTER (SIGINT)); if (gl.debug) { if (!g_getenv ("G_MESSAGES_DEBUG")) { @@ -1036,6 +1039,11 @@ main (int argc, char **argv) g_queue_free (handler->requests_waiting); g_object_unref (handler); + nm_clear_g_source (&signal_id_term); + nm_clear_g_source (&signal_id_int); + nm_clear_g_source (&gl.quit_id); + g_clear_pointer (&gl.loop, g_main_loop_unref); + if (!gl.debug) logging_shutdown (); From 90e4ba15bcc605bd4d70abbddc0b7103bc0a3b2f Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Thu, 23 May 2019 10:58:35 +0200 Subject: [PATCH 09/26] dispatcher: move global variable ever_aquired_name into "gl" struct --- dispatcher/nm-dispatcher.c | 9 ++++----- 1 file changed, 4 insertions(+), 5 deletions(-) diff --git a/dispatcher/nm-dispatcher.c b/dispatcher/nm-dispatcher.c index a666ef719..3c6c097c8 100644 --- a/dispatcher/nm-dispatcher.c +++ b/dispatcher/nm-dispatcher.c @@ -42,6 +42,7 @@ static struct { gboolean persist; guint quit_id; guint request_id_counter; + gboolean ever_acquired_name; } gl; typedef struct Request Request; @@ -869,14 +870,12 @@ handle_action (NMDBusDispatcher *dbus_dispatcher, return TRUE; } -static gboolean ever_acquired_name = FALSE; - static void on_name_acquired (GDBusConnection *connection, const char *name, gpointer user_data) { - ever_acquired_name = TRUE; + gl.ever_acquired_name = TRUE; } static void @@ -885,14 +884,14 @@ on_name_lost (GDBusConnection *connection, gpointer user_data) { if (!connection) { - if (!ever_acquired_name) { + if (!gl.ever_acquired_name) { _LOG_X_W ("Could not get the system bus. Make sure the message bus daemon is running!"); exit (1); } else { _LOG_X_I ("System bus stopped. Exiting"); exit (0); } - } else if (!ever_acquired_name) { + } else if (!gl.ever_acquired_name) { _LOG_X_W ("Could not acquire the " NM_DISPATCHER_DBUS_SERVICE " service."); exit (1); } else { From 866189a001987a2f475685bbb324fba53e1ffd2e Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Thu, 23 May 2019 11:18:48 +0200 Subject: [PATCH 10/26] dispatcher: don't just exit() but always shutdown before exiting It's ugly to uncoordinated just call exit(). We should quit the mainloop and clean up everything we had going. Note that since Handler has no dispose() function, we also need to hack a g_signal_handlers_disconnect_by_func(). This will change soon. --- dispatcher/nm-dispatcher.c | 46 ++++++++++++++++++++++---------------- 1 file changed, 27 insertions(+), 19 deletions(-) diff --git a/dispatcher/nm-dispatcher.c b/dispatcher/nm-dispatcher.c index 3c6c097c8..a812a870b 100644 --- a/dispatcher/nm-dispatcher.c +++ b/dispatcher/nm-dispatcher.c @@ -43,6 +43,7 @@ static struct { guint quit_id; guint request_id_counter; gboolean ever_acquired_name; + bool exit_with_failure; } gl; typedef struct Request Request; @@ -886,18 +887,17 @@ on_name_lost (GDBusConnection *connection, if (!connection) { if (!gl.ever_acquired_name) { _LOG_X_W ("Could not get the system bus. Make sure the message bus daemon is running!"); - exit (1); + gl.exit_with_failure = TRUE; } else { _LOG_X_I ("System bus stopped. Exiting"); - exit (0); } } else if (!gl.ever_acquired_name) { _LOG_X_W ("Could not acquire the " NM_DISPATCHER_DBUS_SERVICE " service."); - exit (1); - } else { + gl.exit_with_failure = TRUE; + } else _LOG_X_I ("Lost the " NM_DISPATCHER_DBUS_SERVICE " name. Exiting"); - exit (0); - } + + g_main_loop_quit (gl.loop); } static void @@ -964,11 +964,11 @@ int main (int argc, char **argv) { GOptionContext *opt_ctx; - GError *error = NULL; + gs_free_error GError *error = NULL; GDBusConnection *bus; - Handler *handler; - guint signal_id_term; - guint signal_id_int; + Handler *handler = NULL; + guint signal_id_term = 0; + guint signal_id_int = 0; GOptionEntry entries[] = { { "debug", 0, 0, G_OPTION_ARG_NONE, &gl.debug, "Output to console rather than syslog", NULL }, @@ -982,8 +982,8 @@ main (int argc, char **argv) if (!g_option_context_parse (opt_ctx, &argc, &argv, &error)) { _LOG_X_W ("Error parsing command line arguments: %s", error->message); - g_error_free (error); - return 1; + gl.exit_with_failure = TRUE; + goto done; } g_option_context_free (opt_ctx); @@ -1008,8 +1008,8 @@ main (int argc, char **argv) if (!bus) { _LOG_X_W ("Could not get the system bus (%s). Make sure the message bus daemon is running!", error->message); - g_error_free (error); - return 1; + gl.exit_with_failure = TRUE; + goto done; } handler = g_object_new (HANDLER_TYPE, NULL); @@ -1019,8 +1019,8 @@ main (int argc, char **argv) &error); if (error) { _LOG_X_W ("Could not export Dispatcher D-Bus interface: %s", error->message); - g_error_free (error); - return 1; + gl.exit_with_failure = 1; + goto done; } g_bus_own_name_on_connection (bus, @@ -1035,8 +1035,16 @@ main (int argc, char **argv) g_main_loop_run (gl.loop); - g_queue_free (handler->requests_waiting); - g_object_unref (handler); +done: + + nm_clear_pointer (&handler->requests_waiting, g_queue_free); + + if (handler) { + g_signal_handlers_disconnect_by_func (handler->dbus_dispatcher, + G_CALLBACK (handle_action), + handler); + } + g_clear_object (&handler); nm_clear_g_source (&signal_id_term); nm_clear_g_source (&signal_id_int); @@ -1046,6 +1054,6 @@ main (int argc, char **argv) if (!gl.debug) logging_shutdown (); - return 0; + return gl.exit_with_failure ? 1 : 0; } From 3a3c807addf81adcc183aa107cab4ea594da1499 Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Thu, 23 May 2019 11:24:16 +0200 Subject: [PATCH 11/26] dispatcher: parse command line arguments in a seprate function Split command line parsing out of the main() function. For one, it's an self-contained step, so we can make main() simpler. Also, we don't need the GOptionEntry on the stack of the main() function for the remainder of the program. --- dispatcher/nm-dispatcher.c | 39 ++++++++++++++++++++++++-------------- 1 file changed, 25 insertions(+), 14 deletions(-) diff --git a/dispatcher/nm-dispatcher.c b/dispatcher/nm-dispatcher.c index a812a870b..8f1d45a1b 100644 --- a/dispatcher/nm-dispatcher.c +++ b/dispatcher/nm-dispatcher.c @@ -960,34 +960,45 @@ signal_handler (gpointer user_data) return G_SOURCE_CONTINUE; } +static gboolean +parse_command_line (int *p_argc, + char ***p_argv, + GError **error) +{ + GOptionContext *opt_ctx; + GOptionEntry entries[] = { + { "debug", 0, 0, G_OPTION_ARG_NONE, &gl.debug, "Output to console rather than syslog", NULL }, + { "persist", 0, 0, G_OPTION_ARG_NONE, &gl.persist, "Don't quit after a short timeout", NULL }, + { NULL } + }; + gboolean success; + + opt_ctx = g_option_context_new (NULL); + g_option_context_set_summary (opt_ctx, "Executes scripts upon actions by NetworkManager."); + g_option_context_add_main_entries (opt_ctx, entries, NULL); + + success = g_option_context_parse (opt_ctx, p_argc, p_argv, error); + + g_option_context_free (opt_ctx); + + return success; +} + int main (int argc, char **argv) { - GOptionContext *opt_ctx; gs_free_error GError *error = NULL; GDBusConnection *bus; Handler *handler = NULL; guint signal_id_term = 0; guint signal_id_int = 0; - GOptionEntry entries[] = { - { "debug", 0, 0, G_OPTION_ARG_NONE, &gl.debug, "Output to console rather than syslog", NULL }, - { "persist", 0, 0, G_OPTION_ARG_NONE, &gl.persist, "Don't quit after a short timeout", NULL }, - { NULL } - }; - - opt_ctx = g_option_context_new (NULL); - g_option_context_set_summary (opt_ctx, "Executes scripts upon actions by NetworkManager."); - g_option_context_add_main_entries (opt_ctx, entries, NULL); - - if (!g_option_context_parse (opt_ctx, &argc, &argv, &error)) { + if (!parse_command_line (&argc, &argv, &error)) { _LOG_X_W ("Error parsing command line arguments: %s", error->message); gl.exit_with_failure = TRUE; goto done; } - g_option_context_free (opt_ctx); - signal_id_term = g_unix_signal_add (SIGTERM, signal_handler, GINT_TO_POINTER (SIGTERM)); signal_id_int = g_unix_signal_add (SIGINT, signal_handler, GINT_TO_POINTER (SIGINT)); From cdea5ca7958ff2c458fda177369e661b01bc697a Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Thu, 23 May 2019 11:27:33 +0200 Subject: [PATCH 12/26] dispatcher: keep the GDBusConnection instance in the global variable It's anyway a singleton that is still referenced by other components. So unrefing it in the mainloop does not actually release any memory. However, the GDBusConnection singleton is fundamental for the run of the program. Keep it accessible in the global variables. Note that soon I will drop the GDBusInterfaceSkeleton and only operate on the GDBusConnection. Then it makes more sense to keep it around. Note that usually we want to keep the amount of global state small. But this connection is anyway a singleton (that we already implicitly use). So, it doesn't change the amount of global state nor does it really have much state (we either have a reference to the singleton or we don't). --- dispatcher/nm-dispatcher.c | 13 ++++++------- 1 file changed, 6 insertions(+), 7 deletions(-) diff --git a/dispatcher/nm-dispatcher.c b/dispatcher/nm-dispatcher.c index 8f1d45a1b..febbfd419 100644 --- a/dispatcher/nm-dispatcher.c +++ b/dispatcher/nm-dispatcher.c @@ -37,6 +37,7 @@ #include "nmdbus-dispatcher.h" static struct { + GDBusConnection *dbus_connection; GMainLoop *loop; gboolean debug; gboolean persist; @@ -988,7 +989,6 @@ int main (int argc, char **argv) { gs_free_error GError *error = NULL; - GDBusConnection *bus; Handler *handler = NULL; guint signal_id_term = 0; guint signal_id_int = 0; @@ -1015,8 +1015,8 @@ main (int argc, char **argv) gl.loop = g_main_loop_new (NULL, FALSE); - bus = g_bus_get_sync (G_BUS_TYPE_SYSTEM, NULL, &error); - if (!bus) { + gl.dbus_connection = g_bus_get_sync (G_BUS_TYPE_SYSTEM, NULL, &error); + if (!gl.dbus_connection) { _LOG_X_W ("Could not get the system bus (%s). Make sure the message bus daemon is running!", error->message); gl.exit_with_failure = TRUE; @@ -1025,7 +1025,7 @@ main (int argc, char **argv) handler = g_object_new (HANDLER_TYPE, NULL); g_dbus_interface_skeleton_export (G_DBUS_INTERFACE_SKELETON (handler->dbus_dispatcher), - bus, + gl.dbus_connection, NM_DISPATCHER_DBUS_PATH, &error); if (error) { @@ -1034,13 +1034,12 @@ main (int argc, char **argv) goto done; } - g_bus_own_name_on_connection (bus, + g_bus_own_name_on_connection (gl.dbus_connection, NM_DISPATCHER_DBUS_SERVICE, G_BUS_NAME_OWNER_FLAGS_NONE, on_name_acquired, on_name_lost, NULL, NULL); - g_object_unref (bus); quit_timeout_reschedule (); @@ -1061,10 +1060,10 @@ done: nm_clear_g_source (&signal_id_int); nm_clear_g_source (&gl.quit_id); g_clear_pointer (&gl.loop, g_main_loop_unref); + g_clear_object (&gl.dbus_connection); if (!gl.debug) logging_shutdown (); return gl.exit_with_failure ? 1 : 0; } - From 484194fa0787a4c829e1a94a9884d2b6996381ba Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Thu, 23 May 2019 11:45:20 +0200 Subject: [PATCH 13/26] dispatcher: drop Handler GObject "nm-dispatcher.c" does something rather simple. It is natural that it has a bit of global data to keep track of that it's doing ("gl"). But this does not lend itself to pack the job of dispatcher into an object. In fact, the Handler object was little more about packaging the GDBus interface skeleton and a bit of state. Global variables are often problematic because they makes unit testing hard. But first of all, we have no test for this (we should). But it's not said that you need an "object" to make testing easier. If we want to make individual bits easier testable, we can just as well pass all required parameters explicitly instead of accessing global variables. Since we package global variables neatly in "gl", this is very simple to refactor. Also, global variables can make code harder to understand. But the problem is the amount of state that is accessible. This is not alleviated by packaging the state in a Handler object. As there is always only one handler instance, this provides very little benefit. I will drop the GDBus interface skeleton soon. So this Handler object will have even less purpose. Drop it. --- dispatcher/nm-dispatcher.c | 140 +++++++++++-------------------------- 1 file changed, 42 insertions(+), 98 deletions(-) diff --git a/dispatcher/nm-dispatcher.c b/dispatcher/nm-dispatcher.c index febbfd419..9f5dd9b47 100644 --- a/dispatcher/nm-dispatcher.c +++ b/dispatcher/nm-dispatcher.c @@ -36,6 +36,8 @@ #include "nmdbus-dispatcher.h" +typedef struct Request Request; + static struct { GDBusConnection *dbus_connection; GMainLoop *loop; @@ -45,68 +47,12 @@ static struct { guint request_id_counter; gboolean ever_acquired_name; bool exit_with_failure; -} gl; -typedef struct Request Request; - -typedef struct { - GObject parent; - - /* Private data */ NMDBusDispatcher *dbus_dispatcher; - Request *current_request; GQueue *requests_waiting; int num_requests_pending; -} Handler; - -typedef struct { - GObjectClass parent; -} HandlerClass; - -GType handler_get_type (void); - -#define HANDLER_TYPE (handler_get_type ()) -#define HANDLER(object) (G_TYPE_CHECK_INSTANCE_CAST ((object), HANDLER_TYPE, Handler)) -#define HANDLER_CLASS(klass) (G_TYPE_CHECK_CLASS_CAST ((klass), HANDLER_TYPE, HandlerClass)) - -G_DEFINE_TYPE(Handler, handler, G_TYPE_OBJECT) - -static gboolean -handle_action (NMDBusDispatcher *dbus_dispatcher, - GDBusMethodInvocation *context, - const char *str_action, - GVariant *connection_dict, - GVariant *connection_props, - GVariant *device_props, - GVariant *device_proxy_props, - GVariant *device_ip4_props, - GVariant *device_ip6_props, - GVariant *device_dhcp4_props, - GVariant *device_dhcp6_props, - const char *connectivity_state, - const char *vpn_ip_iface, - GVariant *vpn_proxy_props, - GVariant *vpn_ip4_props, - GVariant *vpn_ip6_props, - gboolean request_debug, - gpointer user_data); - -static void -handler_init (Handler *h) -{ - h->requests_waiting = g_queue_new (); - h->dbus_dispatcher = nmdbus_dispatcher_skeleton_new (); - g_signal_connect (h->dbus_dispatcher, "handle-action", - G_CALLBACK (handle_action), h); -} - -static void -handler_class_init (HandlerClass *h_class) -{ -} - -static gboolean dispatch_one_script (Request *request); +} gl; typedef struct { Request *request; @@ -122,8 +68,6 @@ typedef struct { } ScriptInfo; struct Request { - Handler *handler; - guint request_id; GDBusMethodInvocation *context; @@ -219,6 +163,10 @@ struct Request { /*****************************************************************************/ +static gboolean dispatch_one_script (Request *request); + +/*****************************************************************************/ + static void script_info_free (gpointer ptr) { @@ -263,7 +211,6 @@ quit_timeout_reschedule (void) /** * next_request: * - * @h: the handler * @request: (allow-none): the request to set as next. If %NULL, dequeue the next * waiting request. Otherwise, try to set the given request. * @@ -276,27 +223,27 @@ quit_timeout_reschedule (void) * a new request as current. */ static gboolean -next_request (Handler *h, Request *request) +next_request (Request *request) { if (request) { - if (h->current_request) { - g_queue_push_tail (h->requests_waiting, request); + if (gl.current_request) { + g_queue_push_tail (gl.requests_waiting, request); return FALSE; } } else { /* when calling next_request() without explicit @request, we always * forcefully clear @current_request. That one is certainly * handled already. */ - h->current_request = NULL; + gl.current_request = NULL; - request = g_queue_pop_head (h->requests_waiting); + request = g_queue_pop_head (gl.requests_waiting); if (!request) return FALSE; } _LOG_R_D (request, "start running ordered scripts..."); - h->current_request = request; + gl.current_request = request; return TRUE; } @@ -316,7 +263,6 @@ complete_request (Request *request) GVariantBuilder results; GVariant *ret; guint i; - Handler *handler = request->handler; nm_assert (request); @@ -339,14 +285,14 @@ complete_request (Request *request) _LOG_R_T (request, "completed (%u scripts)", request->scripts->len); - if (handler->current_request == request) - handler->current_request = NULL; + if (gl.current_request == request) + gl.current_request = NULL; request_free (request); - g_assert_cmpuint (handler->num_requests_pending, >, 0); - if (--handler->num_requests_pending <= 0) { - nm_assert (!handler->current_request && !g_queue_peek_head (handler->requests_waiting)); + g_assert_cmpuint (gl.num_requests_pending, >, 0); + if (--gl.num_requests_pending <= 0) { + nm_assert (!gl.current_request && !g_queue_peek_head (gl.requests_waiting)); quit_timeout_reschedule (); } } @@ -354,7 +300,6 @@ complete_request (Request *request) static void complete_script (ScriptInfo *script) { - Handler *handler; Request *request; gboolean wait = script->wait; @@ -367,9 +312,7 @@ complete_script (ScriptInfo *script) return; } - handler = request->handler; - - nm_assert (!wait || handler->current_request == request); + nm_assert (!wait || gl.current_request == request); /* Try to complete the request. @request will be possibly free'd, * making @script and @request a dangling pointer. */ @@ -382,13 +325,13 @@ complete_script (ScriptInfo *script) * requests. However, if this was the last "no-wait" script and * there are "wait" scripts ready to run, launch them. */ - if ( handler->current_request == request - && handler->current_request->num_scripts_nowait == 0) { + if ( gl.current_request == request + && gl.current_request->num_scripts_nowait == 0) { - if (dispatch_one_script (handler->current_request)) + if (dispatch_one_script (gl.current_request)) return; - complete_request (handler->current_request); + complete_request (gl.current_request); } else return; } else { @@ -401,11 +344,11 @@ complete_script (ScriptInfo *script) * processed because only requests with "wait" scripts can become * @current_request. As there can only be one "wait" script running * at any time, it means complete_request() above completed @request. */ - nm_assert (!handler->current_request); + nm_assert (!gl.current_request); } - while (next_request (handler, NULL)) { - request = handler->current_request; + while (next_request (NULL)) { + request = gl.current_request; if (dispatch_one_script (request)) return; @@ -755,7 +698,6 @@ handle_action (NMDBusDispatcher *dbus_dispatcher, gboolean request_debug, gpointer user_data) { - Handler *h = user_data; GSList *sorted_scripts = NULL; GSList *iter; Request *request; @@ -765,7 +707,6 @@ handle_action (NMDBusDispatcher *dbus_dispatcher, request = g_slice_new0 (Request); request->request_id = ++gl.request_id_counter; - request->handler = h; request->debug = request_debug || gl.debug; request->context = context; request->action = g_strdup (str_action); @@ -825,7 +766,7 @@ handle_action (NMDBusDispatcher *dbus_dispatcher, nm_clear_g_source (&gl.quit_id); - h->num_requests_pending++; + gl.num_requests_pending++; for (i = 0; i < request->scripts->len; i++) { ScriptInfo *s = g_ptr_array_index (request->scripts, i); @@ -840,8 +781,8 @@ handle_action (NMDBusDispatcher *dbus_dispatcher, /* The request has at least one wait script. * Try next_request() to schedule the request for * execution. This either enqueues the request or - * sets it as h->current_request. */ - if (next_request (h, request)) { + * sets it as gl.current_request. */ + if (next_request (request)) { /* @request is now @current_request. Go ahead and * schedule the first wait script. */ if (!dispatch_one_script (request)) { @@ -849,7 +790,7 @@ handle_action (NMDBusDispatcher *dbus_dispatcher, * request. Try complete_request(). */ complete_request (request); - if (next_request (h, NULL)) { + if (next_request (NULL)) { /* As @request was successfully scheduled as next_request(), there is no * other request in queue that can be scheduled afterwards. Assert against * that, but call next_request() to clear current_request. */ @@ -862,7 +803,7 @@ handle_action (NMDBusDispatcher *dbus_dispatcher, * the request right away (we might have failed to schedule any * of the scripts). It will be either completed now, or later * when the pending scripts return. - * We don't enqueue it to h->requests_waiting. + * We don't enqueue it to gl.requests_waiting. * There is no need to handle next_request(), because @request is * not the current request anyway and does not interfere with requests * that have any "wait" scripts. */ @@ -989,7 +930,6 @@ int main (int argc, char **argv) { gs_free_error GError *error = NULL; - Handler *handler = NULL; guint signal_id_term = 0; guint signal_id_int = 0; @@ -1023,8 +963,12 @@ main (int argc, char **argv) goto done; } - handler = g_object_new (HANDLER_TYPE, NULL); - g_dbus_interface_skeleton_export (G_DBUS_INTERFACE_SKELETON (handler->dbus_dispatcher), + gl.requests_waiting = g_queue_new (); + gl.dbus_dispatcher = nmdbus_dispatcher_skeleton_new (); + g_signal_connect (gl.dbus_dispatcher, "handle-action", + G_CALLBACK (handle_action), NULL); + + g_dbus_interface_skeleton_export (G_DBUS_INTERFACE_SKELETON (gl.dbus_dispatcher), gl.dbus_connection, NM_DISPATCHER_DBUS_PATH, &error); @@ -1047,14 +991,14 @@ main (int argc, char **argv) done: - nm_clear_pointer (&handler->requests_waiting, g_queue_free); + nm_clear_pointer (&gl.requests_waiting, g_queue_free); - if (handler) { - g_signal_handlers_disconnect_by_func (handler->dbus_dispatcher, + if (gl.dbus_dispatcher) { + g_signal_handlers_disconnect_by_func (gl.dbus_dispatcher, G_CALLBACK (handle_action), - handler); + NULL); } - g_clear_object (&handler); + g_clear_object (&gl.dbus_dispatcher); nm_clear_g_source (&signal_id_term); nm_clear_g_source (&signal_id_int); From a01e760667458c1d7c0f95d12df10e8729f6234a Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Thu, 23 May 2019 10:59:26 +0200 Subject: [PATCH 14/26] dispatcher: drop GDBusInterfaceSkeleton and generate GDBus bindings Just hook into GDBusConnection directly. No need for this additional layer that provides nothing. It doesn't even provide extra type-safety, because you still need to get the arguments of the signal handler right. That that point, it's as hard as getting the format string for g_variant_get() right. It still adds lines of code, because the "Action" method has such a large argument list. --- dispatcher/nm-dispatcher.c | 194 ++++++++++++++++++++++++++----------- 1 file changed, 139 insertions(+), 55 deletions(-) diff --git a/dispatcher/nm-dispatcher.c b/dispatcher/nm-dispatcher.c index 9f5dd9b47..ccb15cbdf 100644 --- a/dispatcher/nm-dispatcher.c +++ b/dispatcher/nm-dispatcher.c @@ -34,7 +34,7 @@ #include "nm-libnm-core-aux/nm-dispatcher-api.h" #include "nm-dispatcher-utils.h" -#include "nmdbus-dispatcher.h" +/*****************************************************************************/ typedef struct Request Request; @@ -48,7 +48,6 @@ static struct { gboolean ever_acquired_name; bool exit_with_failure; - NMDBusDispatcher *dbus_dispatcher; Request *current_request; GQueue *requests_waiting; int num_requests_pending; @@ -678,26 +677,25 @@ script_must_wait (const char *path) return TRUE; } -static gboolean -handle_action (NMDBusDispatcher *dbus_dispatcher, - GDBusMethodInvocation *context, - const char *str_action, - GVariant *connection_dict, - GVariant *connection_props, - GVariant *device_props, - GVariant *device_proxy_props, - GVariant *device_ip4_props, - GVariant *device_ip6_props, - GVariant *device_dhcp4_props, - GVariant *device_dhcp6_props, - const char *connectivity_state, - const char *vpn_ip_iface, - GVariant *vpn_proxy_props, - GVariant *vpn_ip4_props, - GVariant *vpn_ip6_props, - gboolean request_debug, - gpointer user_data) +static void +_method_call_action (GDBusMethodInvocation *invocation, + GVariant *parameters) { + const char *action; + gs_unref_variant GVariant *connection = NULL; + gs_unref_variant GVariant *connection_properties = NULL; + gs_unref_variant GVariant *device_properties = NULL; + gs_unref_variant GVariant *device_proxy_properties = NULL; + gs_unref_variant GVariant *device_ip4_config = NULL; + gs_unref_variant GVariant *device_ip6_config = NULL; + gs_unref_variant GVariant *device_dhcp4_config = NULL; + gs_unref_variant GVariant *device_dhcp6_config = NULL; + const char *connectivity_state; + const char *vpn_ip_iface; + gs_unref_variant GVariant *vpn_proxy_properties = NULL; + gs_unref_variant GVariant *vpn_ip4_config = NULL; + gs_unref_variant GVariant *vpn_ip6_config = NULL; + gboolean debug; GSList *sorted_scripts = NULL; GSList *iter; Request *request; @@ -705,26 +703,59 @@ handle_action (NMDBusDispatcher *dbus_dispatcher, guint i, num_nowait = 0; const char *error_message = NULL; + g_variant_get (parameters, "(" + "&s" /* action */ + "@a{sa{sv}}" /* connection */ + "@a{sv}" /* connection_properties */ + "@a{sv}" /* device_properties */ + "@a{sv}" /* device_proxy_properties */ + "@a{sv}" /* device_ip4_config */ + "@a{sv}" /* device_ip6_config */ + "@a{sv}" /* device_dhcp4_config */ + "@a{sv}" /* device_dhcp6_config */ + "&s" /* connectivity_state */ + "&s" /* vpn_ip_iface */ + "@a{sv}" /* vpn_proxy_properties */ + "@a{sv}" /* vpn_ip4_config */ + "@a{sv}" /* vpn_ip6_config */ + "b" /* debug */ + ")", + &action, + &connection, + &connection_properties, + &device_properties, + &device_proxy_properties, + &device_ip4_config, + &device_ip6_config, + &device_dhcp4_config, + &device_dhcp6_config, + &connectivity_state, + &vpn_ip_iface, + &vpn_proxy_properties, + &vpn_ip4_config, + &vpn_ip6_config, + &debug); + request = g_slice_new0 (Request); request->request_id = ++gl.request_id_counter; - request->debug = request_debug || gl.debug; - request->context = context; - request->action = g_strdup (str_action); + request->debug = debug || gl.debug; + request->context = invocation; + request->action = g_strdup (action); - request->envp = nm_dispatcher_utils_construct_envp (str_action, - connection_dict, - connection_props, - device_props, - device_proxy_props, - device_ip4_props, - device_ip6_props, - device_dhcp4_props, - device_dhcp6_props, + request->envp = nm_dispatcher_utils_construct_envp (action, + connection, + connection_properties, + device_properties, + device_proxy_properties, + device_ip4_config, + device_ip6_config, + device_dhcp4_config, + device_dhcp6_config, connectivity_state, vpn_ip_iface, - vpn_proxy_props, - vpn_ip4_props, - vpn_ip6_props, + vpn_proxy_properties, + vpn_ip4_config, + vpn_ip6_config, &request->iface, &error_message); @@ -758,10 +789,10 @@ handle_action (NMDBusDispatcher *dbus_dispatcher, _LOG_R_D (request, "completed: no scripts"); results = g_variant_new_array (G_VARIANT_TYPE ("(sus)"), NULL, 0); - g_dbus_method_invocation_return_value (context, g_variant_new ("(@a(sus))", results)); + g_dbus_method_invocation_return_value (invocation, g_variant_new ("(@a(sus))", results)); request->num_scripts_done = request->scripts->len; request_free (request); - return TRUE; + return; } nm_clear_g_source (&gl.quit_id); @@ -809,8 +840,6 @@ handle_action (NMDBusDispatcher *dbus_dispatcher, * that have any "wait" scripts. */ complete_request (request); } - - return TRUE; } static void @@ -842,6 +871,64 @@ on_name_lost (GDBusConnection *connection, g_main_loop_quit (gl.loop); } +static void +_method_call (GDBusConnection *connection, + const char *sender, + const char *object_path, + const char *interface_name, + const char *method_name, + GVariant *parameters, + GDBusMethodInvocation *invocation, + gpointer user_data) +{ + if (nm_streq (interface_name, NM_DISPATCHER_DBUS_INTERFACE)) { + if (nm_streq (method_name, "Action")) { + _method_call_action (invocation, parameters); + return; + } + } + g_dbus_method_invocation_return_error (invocation, + G_DBUS_ERROR, + G_DBUS_ERROR_UNKNOWN_METHOD, + "Unknown method %s", + method_name); +} + +static GDBusInterfaceInfo *const interface_info = NM_DEFINE_GDBUS_INTERFACE_INFO ( + NM_DISPATCHER_DBUS_INTERFACE, + .methods = NM_DEFINE_GDBUS_METHOD_INFOS ( + NM_DEFINE_GDBUS_METHOD_INFO ( + "Action", + .in_args = NM_DEFINE_GDBUS_ARG_INFOS ( + NM_DEFINE_GDBUS_ARG_INFO ("action", "s"), + NM_DEFINE_GDBUS_ARG_INFO ("connection", "a{sa{sv}}"), + NM_DEFINE_GDBUS_ARG_INFO ("connection_properties", "a{sv}"), + NM_DEFINE_GDBUS_ARG_INFO ("device_properties", "a{sv}"), + NM_DEFINE_GDBUS_ARG_INFO ("device_proxy_properties", "a{sv}"), + NM_DEFINE_GDBUS_ARG_INFO ("device_ip4_config", "a{sv}"), + NM_DEFINE_GDBUS_ARG_INFO ("device_ip6_config", "a{sv}"), + NM_DEFINE_GDBUS_ARG_INFO ("device_dhcp4_config", "a{sv}"), + NM_DEFINE_GDBUS_ARG_INFO ("device_dhcp6_config", "a{sv}"), + NM_DEFINE_GDBUS_ARG_INFO ("connectivity_state", "s"), + NM_DEFINE_GDBUS_ARG_INFO ("vpn_ip_iface", "s"), + NM_DEFINE_GDBUS_ARG_INFO ("vpn_proxy_properties", "a{sv}"), + NM_DEFINE_GDBUS_ARG_INFO ("vpn_ip4_config", "a{sv}"), + NM_DEFINE_GDBUS_ARG_INFO ("vpn_ip6_config", "a{sv}"), + NM_DEFINE_GDBUS_ARG_INFO ("debug", "b"), + ), + .out_args = NM_DEFINE_GDBUS_ARG_INFOS ( + NM_DEFINE_GDBUS_ARG_INFO ("results", "a(sus)"), + ), + ), + ), +); + +static const GDBusInterfaceVTable interface_vtable = { + .method_call = _method_call, +}; + +/*****************************************************************************/ + static void log_handler (const char *log_domain, GLogLevelFlags log_level, @@ -932,6 +1019,7 @@ main (int argc, char **argv) gs_free_error GError *error = NULL; guint signal_id_term = 0; guint signal_id_int = 0; + guint dbus_regist_id = 0; if (!parse_command_line (&argc, &argv, &error)) { _LOG_X_W ("Error parsing command line arguments: %s", error->message); @@ -964,15 +1052,15 @@ main (int argc, char **argv) } gl.requests_waiting = g_queue_new (); - gl.dbus_dispatcher = nmdbus_dispatcher_skeleton_new (); - g_signal_connect (gl.dbus_dispatcher, "handle-action", - G_CALLBACK (handle_action), NULL); - g_dbus_interface_skeleton_export (G_DBUS_INTERFACE_SKELETON (gl.dbus_dispatcher), - gl.dbus_connection, - NM_DISPATCHER_DBUS_PATH, - &error); - if (error) { + dbus_regist_id = g_dbus_connection_register_object (gl.dbus_connection, + NM_DISPATCHER_DBUS_PATH, + interface_info, + NM_UNCONST_PTR (GDBusInterfaceVTable, &interface_vtable), + NULL, + NULL, + &error); + if (dbus_regist_id == 0) { _LOG_X_W ("Could not export Dispatcher D-Bus interface: %s", error->message); gl.exit_with_failure = 1; goto done; @@ -991,14 +1079,10 @@ main (int argc, char **argv) done: - nm_clear_pointer (&gl.requests_waiting, g_queue_free); + if (dbus_regist_id != 0) + g_dbus_connection_unregister_object (gl.dbus_connection, nm_steal_int (&dbus_regist_id)); - if (gl.dbus_dispatcher) { - g_signal_handlers_disconnect_by_func (gl.dbus_dispatcher, - G_CALLBACK (handle_action), - NULL); - } - g_clear_object (&gl.dbus_dispatcher); + nm_clear_pointer (&gl.requests_waiting, g_queue_free); nm_clear_g_source (&signal_id_term); nm_clear_g_source (&signal_id_int); From cdaedecaa752585b4844080aff91ad8bdba2a56c Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Thu, 23 May 2019 17:35:55 +0200 Subject: [PATCH 15/26] dispatcher: unown dispatcher D-Bus name on exit --- dispatcher/nm-dispatcher.c | 16 ++++++++++------ 1 file changed, 10 insertions(+), 6 deletions(-) diff --git a/dispatcher/nm-dispatcher.c b/dispatcher/nm-dispatcher.c index ccb15cbdf..9a7fd2aa6 100644 --- a/dispatcher/nm-dispatcher.c +++ b/dispatcher/nm-dispatcher.c @@ -1020,6 +1020,7 @@ main (int argc, char **argv) guint signal_id_term = 0; guint signal_id_int = 0; guint dbus_regist_id = 0; + guint dbus_own_name_id = 0; if (!parse_command_line (&argc, &argv, &error)) { _LOG_X_W ("Error parsing command line arguments: %s", error->message); @@ -1066,12 +1067,12 @@ main (int argc, char **argv) goto done; } - g_bus_own_name_on_connection (gl.dbus_connection, - NM_DISPATCHER_DBUS_SERVICE, - G_BUS_NAME_OWNER_FLAGS_NONE, - on_name_acquired, - on_name_lost, - NULL, NULL); + dbus_own_name_id = g_bus_own_name_on_connection (gl.dbus_connection, + NM_DISPATCHER_DBUS_SERVICE, + G_BUS_NAME_OWNER_FLAGS_NONE, + on_name_acquired, + on_name_lost, + NULL, NULL); quit_timeout_reschedule (); @@ -1079,6 +1080,9 @@ main (int argc, char **argv) done: + if (dbus_own_name_id != 0) + g_bus_unown_name (nm_steal_int (&dbus_own_name_id)); + if (dbus_regist_id != 0) g_dbus_connection_unregister_object (gl.dbus_connection, nm_steal_int (&dbus_regist_id)); From f8096448664a75fa86b07b7ae98dceeb100c3d70 Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Thu, 23 May 2019 12:38:19 +0200 Subject: [PATCH 16/26] build: don't link dispatcher with generated nmdbus-dispatcher bindings We don't need it anymore. Still, for tests let gdbus-codegen run and generate the sources and compile them. We want to keep "dispatcher/nm-dispatcher.xml" and ensure that it is still valid. --- Makefile.am | 49 ++++++++++++++----------- dispatcher/meson.build | 2 +- dispatcher/tests/meson.build | 2 +- dispatcher/tests/test-dispatcher-envp.c | 15 ++++++++ 4 files changed, 45 insertions(+), 23 deletions(-) diff --git a/Makefile.am b/Makefile.am index cf2ee34a1..c830919df 100644 --- a/Makefile.am +++ b/Makefile.am @@ -3885,6 +3885,25 @@ EXTRA_DIST += \ # dispatcher ############################################################################### +dispatcher_nmdbus_dispatcher_sources = \ + dispatcher/nmdbus-dispatcher.h \ + dispatcher/nmdbus-dispatcher.c \ + $(NULL) + +dispatcher/nmdbus-dispatcher.h: dispatcher/nm-dispatcher.xml + @$(MKDIR_P) dispatcher/ + $(AM_V_GEN) gdbus-codegen \ + --generate-c-code $(basename $@) \ + --c-namespace NMDBus \ + --interface-prefix org.freedesktop \ + $< + +dispatcher/nmdbus-dispatcher.c: dispatcher/nmdbus-dispatcher.h + +CLEANFILES += $(dispatcher_nmdbus_dispatcher_sources) + +############################################################################### + libexec_PROGRAMS += dispatcher/nm-dispatcher noinst_LTLIBRARIES += \ @@ -3905,25 +3924,6 @@ dispatcher_cppflags = \ -DNETWORKMANAGER_COMPILATION=NM_NETWORKMANAGER_COMPILATION_CLIENT \ $(NULL) - -dispatcher_nmdbus_dispatcher_sources = \ - dispatcher/nmdbus-dispatcher.h \ - dispatcher/nmdbus-dispatcher.c - -dispatcher/nmdbus-dispatcher.h: dispatcher/nm-dispatcher.xml - @$(MKDIR_P) dispatcher/ - $(AM_V_GEN) gdbus-codegen \ - --generate-c-code $(basename $@) \ - --c-namespace NMDBus \ - --interface-prefix org.freedesktop \ - $< - -dispatcher/nmdbus-dispatcher.c: dispatcher/nmdbus-dispatcher.h - -$(dispatcher_nm_dispatcher_OBJECTS): $(dispatcher_nmdbus_dispatcher_sources) - -CLEANFILES += $(dispatcher_nmdbus_dispatcher_sources) - dispatcher_libnm_dispatcher_core_la_SOURCES = \ dispatcher/nm-dispatcher-utils.c \ dispatcher/nm-dispatcher-utils.h \ @@ -3939,8 +3939,6 @@ dispatcher_nm_dispatcher_SOURCES = \ dispatcher/nm-dispatcher.c \ $(NULL) -nodist_dispatcher_nm_dispatcher_SOURCES = $(dispatcher_nmdbus_dispatcher_sources) - dispatcher_nm_dispatcher_CPPFLAGS = $(dispatcher_cppflags) dispatcher_nm_dispatcher_LDFLAGS = \ @@ -3998,12 +3996,21 @@ dispatcher_tests_test_dispatcher_envp_CPPFLAGS = \ -I$(srcdir)/libnm \ -I$(builddir)/libnm \ -I$(srcdir)/dispatcher \ + -I$(builddir)/dispatcher \ -DNETWORKMANAGER_COMPILATION_TEST \ -DNETWORKMANAGER_COMPILATION=NM_NETWORKMANAGER_COMPILATION_CLIENT \ $(GLIB_CFLAGS) \ $(SANITIZER_EXEC_CFLAGS) \ $(NULL) +dispatcher_tests_test_dispatcher_envp_SOURCES = \ + dispatcher/tests/test-dispatcher-envp.c \ + $(NULL) + +nodist_dispatcher_tests_test_dispatcher_envp_SOURCES = $(dispatcher_nmdbus_dispatcher_sources) + +$(dispatcher_tests_test_dispatcher_envp_OBJECTS): $(dispatcher_nmdbus_dispatcher_sources) + dispatcher_tests_test_dispatcher_envp_LDFLAGS = \ $(SANITIZER_EXEC_LDFLAGS) \ $(NULL) diff --git a/dispatcher/meson.build b/dispatcher/meson.build index 7bd41935c..da9ac7f29 100644 --- a/dispatcher/meson.build +++ b/dispatcher/meson.build @@ -44,7 +44,7 @@ libnm_dispatcher_core = static_library( sources = files('nm-dispatcher.c') -sources += gnome.gdbus_codegen( +nmdbus_dispatcher_sources = gnome.gdbus_codegen( 'nmdbus-dispatcher', name + '.xml', interface_prefix: 'org.freedesktop', diff --git a/dispatcher/tests/meson.build b/dispatcher/tests/meson.build index 3da3c3e91..10d1c6a93 100644 --- a/dispatcher/tests/meson.build +++ b/dispatcher/tests/meson.build @@ -7,7 +7,7 @@ incs = [ exe = executable( test_unit, - test_unit + '.c', + [ test_unit + '.c' ] + [ nmdbus_dispatcher_sources ], include_directories: incs, dependencies: libnm_core_dep, c_args: [ diff --git a/dispatcher/tests/test-dispatcher-envp.c b/dispatcher/tests/test-dispatcher-envp.c index cdc3e6b25..b1205c323 100644 --- a/dispatcher/tests/test-dispatcher-envp.c +++ b/dispatcher/tests/test-dispatcher-envp.c @@ -28,6 +28,8 @@ #include "nm-utils/nm-test-utils.h" +#include "nmdbus-dispatcher.h" + #define TEST_DIR NM_BUILD_SRCDIR"/dispatcher/tests" /*****************************************************************************/ @@ -637,6 +639,17 @@ test_up_empty_vpn_iface (void) /*****************************************************************************/ +static void +test_gdbus_codegen (void) +{ + gs_unref_object NMDBusDispatcher *dbus_dispatcher = NULL; + + dbus_dispatcher = nmdbus_dispatcher_skeleton_new (); + g_assert (NMDBUS_IS_DISPATCHER_SKELETON (dbus_dispatcher)); +} + +/*****************************************************************************/ + NMTST_DEFINE (); int @@ -653,6 +666,8 @@ main (int argc, char **argv) g_test_add_func ("/dispatcher/up_empty_vpn_iface", test_up_empty_vpn_iface); + g_test_add_func ("/dispatcher/gdbus-codegen", test_gdbus_codegen); + return g_test_run (); } From f8b0bad2c939651a6ef213c19afba3eb67c8a86e Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Thu, 23 May 2019 15:30:42 +0200 Subject: [PATCH 17/26] dispatcher: cleanup dispatcher_results_process() We don't need the two callers both unpack the GVariant and pass a GVariantIter. Let dispatcher_results_process() do the unpacking. Also, use some cleanup attributes. --- src/nm-dispatcher.c | 46 ++++++++++++++++++--------------------------- 1 file changed, 18 insertions(+), 28 deletions(-) diff --git a/src/nm-dispatcher.c b/src/nm-dispatcher.c index 8ac18ed44..4d027c10c 100644 --- a/src/nm-dispatcher.c +++ b/src/nm-dispatcher.c @@ -339,12 +339,15 @@ dispatch_result_to_string (DispatchResult result) } static void -dispatcher_results_process (guint request_id, NMDispatcherAction action, GVariantIter *results) +dispatcher_results_process (guint request_id, + NMDispatcherAction action, + GVariant *v_results) { + nm_auto_free_variant_iter GVariantIter *results = NULL; const char *script, *err; guint32 result; - g_return_if_fail (results != NULL); + g_variant_get (v_results, "(a(sus))", &results); if (g_variant_iter_n_children (results) == 0) { _LOGD ("(%u) succeeded but no scripts invoked", request_id); @@ -367,20 +370,14 @@ dispatcher_results_process (guint request_id, NMDispatcherAction action, GVarian static void dispatcher_done_cb (GObject *proxy, GAsyncResult *result, gpointer user_data) { + gs_unref_variant GVariant *ret = NULL; + gs_free_error GError *error = NULL; DispatchInfo *info = user_data; - GVariant *ret; - GVariantIter *results; - GError *error = NULL; ret = _nm_dbus_proxy_call_finish (G_DBUS_PROXY (proxy), result, G_VARIANT_TYPE ("(a(sus))"), &error); - if (ret) { - g_variant_get (ret, "(a(sus))", &results); - dispatcher_results_process (info->request_id, info->action, results); - g_variant_iter_free (results); - g_variant_unref (ret); - } else { + if (!ret) { if (_nm_dbus_error_has_name (error, "org.freedesktop.systemd1.LoadFailed")) { g_dbus_error_strip_remote_error (error); _LOGW ("(%u) failed to call dispatcher scripts: %s", @@ -389,8 +386,8 @@ dispatcher_done_cb (GObject *proxy, GAsyncResult *result, gpointer user_data) _LOGD ("(%u) failed to call dispatcher scripts: %s", info->request_id, error->message); } - g_clear_error (&error); - } + } else + dispatcher_results_process (info->request_id, info->action, ret); if (info->callback) info->callback (info->request_id, info->user_data); @@ -442,14 +439,13 @@ _dispatcher_call (NMDispatcherAction action, GVariantBuilder device_proxy_props; GVariantBuilder device_ip4_props; GVariantBuilder device_ip6_props; - GVariant *device_dhcp4_props = NULL; - GVariant *device_dhcp6_props = NULL; + gs_unref_variant GVariant *device_dhcp4_props = NULL; + gs_unref_variant GVariant *device_dhcp6_props = NULL; GVariantBuilder vpn_proxy_props; GVariantBuilder vpn_ip4_props; GVariantBuilder vpn_ip6_props; DispatchInfo *info = NULL; gboolean success = FALSE; - GError *error = NULL; static guint request_counter = 0; guint reqid = ++request_counter; const char *connectivity_state_string = "UNKNOWN"; @@ -551,8 +547,8 @@ _dispatcher_call (NMDispatcherAction action, /* Send the action to the dispatcher */ if (blocking) { - GVariant *ret; - GVariantIter *results; + gs_unref_variant GVariant *ret = NULL; + gs_free_error GError *error = NULL; ret = _nm_dbus_proxy_call_sync (dispatcher_proxy, "Action", g_variant_new ("(s@a{sa{sv}}a{sv}a{sv}a{sv}a{sv}a{sv}@a{sv}@a{sv}ssa{sv}a{sv}a{sv}b)", @@ -574,17 +570,14 @@ _dispatcher_call (NMDispatcherAction action, G_VARIANT_TYPE ("(a(sus))"), G_DBUS_CALL_FLAGS_NONE, CALL_TIMEOUT, NULL, &error); - if (ret) { - g_variant_get (ret, "(a(sus))", &results); - dispatcher_results_process (reqid, action, results); - g_variant_iter_free (results); - g_variant_unref (ret); - success = TRUE; - } else { + if (!ret) { g_dbus_error_strip_remote_error (error); _LOGW ("(%u) failed: %s", reqid, error->message); g_clear_error (&error); success = FALSE; + } else { + dispatcher_results_process (reqid, action, ret); + success = TRUE; } } else { info = g_malloc0 (sizeof (*info)); @@ -614,9 +607,6 @@ _dispatcher_call (NMDispatcherAction action, success = TRUE; } - g_variant_unref (device_dhcp4_props); - g_variant_unref (device_dhcp6_props); - if (success && info) { /* Track the request in case of cancelation */ g_hash_table_insert (requests, GUINT_TO_POINTER (info->request_id), info); From da345efc08636e04cff036eb187068e2ab617883 Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Thu, 23 May 2019 15:35:24 +0200 Subject: [PATCH 18/26] dispatcher: cleanup constructing parameter in _dispatcher_call() Don't duplicate this code. --- src/nm-dispatcher.c | 76 ++++++++++++++++++++------------------------- 1 file changed, 33 insertions(+), 43 deletions(-) diff --git a/src/nm-dispatcher.c b/src/nm-dispatcher.c index 4d027c10c..d1e2c0948 100644 --- a/src/nm-dispatcher.c +++ b/src/nm-dispatcher.c @@ -439,6 +439,7 @@ _dispatcher_call (NMDispatcherAction action, GVariantBuilder device_proxy_props; GVariantBuilder device_ip4_props; GVariantBuilder device_ip6_props; + gs_unref_variant GVariant *parameters_floating = NULL; gs_unref_variant GVariant *device_dhcp4_props = NULL; gs_unref_variant GVariant *device_dhcp6_props = NULL; GVariantBuilder vpn_proxy_props; @@ -538,38 +539,38 @@ _dispatcher_call (NMDispatcherAction action, } } - if (!device_dhcp4_props) - device_dhcp4_props = g_variant_ref_sink (g_variant_new_array (G_VARIANT_TYPE ("{sv}"), NULL, 0)); - if (!device_dhcp6_props) - device_dhcp6_props = g_variant_ref_sink (g_variant_new_array (G_VARIANT_TYPE ("{sv}"), NULL, 0)); - connectivity_state_string = nm_connectivity_state_to_string (connectivity_state); + parameters_floating = g_variant_new ("(s@a{sa{sv}}a{sv}a{sv}a{sv}a{sv}a{sv}@a{sv}@a{sv}ssa{sv}a{sv}a{sv}b)", + action_to_string (action), + connection_dict, + &connection_props, + &device_props, + &device_proxy_props, + &device_ip4_props, + &device_ip6_props, + device_dhcp4_props ?: g_variant_new_array (G_VARIANT_TYPE ("{sv}"), NULL, 0), + device_dhcp6_props ?: g_variant_new_array (G_VARIANT_TYPE ("{sv}"), NULL, 0), + connectivity_state_string, + vpn_iface ?: "", + &vpn_proxy_props, + &vpn_ip4_props, + &vpn_ip6_props, + nm_logging_enabled (LOGL_DEBUG, LOGD_DISPATCH)); + /* Send the action to the dispatcher */ if (blocking) { gs_unref_variant GVariant *ret = NULL; gs_free_error GError *error = NULL; - ret = _nm_dbus_proxy_call_sync (dispatcher_proxy, "Action", - g_variant_new ("(s@a{sa{sv}}a{sv}a{sv}a{sv}a{sv}a{sv}@a{sv}@a{sv}ssa{sv}a{sv}a{sv}b)", - action_to_string (action), - connection_dict, - &connection_props, - &device_props, - &device_proxy_props, - &device_ip4_props, - &device_ip6_props, - device_dhcp4_props, - device_dhcp6_props, - connectivity_state_string, - vpn_iface ?: "", - &vpn_proxy_props, - &vpn_ip4_props, - &vpn_ip6_props, - nm_logging_enabled (LOGL_DEBUG, LOGD_DISPATCH)), + ret = _nm_dbus_proxy_call_sync (dispatcher_proxy, + "Action", + g_steal_pointer (¶meters_floating), G_VARIANT_TYPE ("(a(sus))"), - G_DBUS_CALL_FLAGS_NONE, CALL_TIMEOUT, - NULL, &error); + G_DBUS_CALL_FLAGS_NONE, + CALL_TIMEOUT, + NULL, + &error); if (!ret) { g_dbus_error_strip_remote_error (error); _LOGW ("(%u) failed: %s", reqid, error->message); @@ -585,25 +586,14 @@ _dispatcher_call (NMDispatcherAction action, info->request_id = reqid; info->callback = callback; info->user_data = user_data; - g_dbus_proxy_call (dispatcher_proxy, "Action", - g_variant_new ("(s@a{sa{sv}}a{sv}a{sv}a{sv}a{sv}a{sv}@a{sv}@a{sv}ssa{sv}a{sv}a{sv}b)", - action_to_string (action), - connection_dict, - &connection_props, - &device_props, - &device_proxy_props, - &device_ip4_props, - &device_ip6_props, - device_dhcp4_props, - device_dhcp6_props, - connectivity_state_string, - vpn_iface ?: "", - &vpn_proxy_props, - &vpn_ip4_props, - &vpn_ip6_props, - nm_logging_enabled (LOGL_DEBUG, LOGD_DISPATCH)), - G_DBUS_CALL_FLAGS_NONE, CALL_TIMEOUT, - NULL, dispatcher_done_cb, info); + g_dbus_proxy_call (dispatcher_proxy, + "Action", + g_steal_pointer (¶meters_floating), + G_DBUS_CALL_FLAGS_NONE, + CALL_TIMEOUT, + NULL, + dispatcher_done_cb, + info); success = TRUE; } From c82703d4177da7b146e1d85a41b493624c1bc0b3 Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Thu, 23 May 2019 15:58:20 +0200 Subject: [PATCH 19/26] dispatcher: add logging macros for per-request messages This way, we avoid code duplication of how to print the request-id ("(%u) "), but it also will allow up to attach the interface name and connection name to the call-id, so that we can use it for structured logging. --- src/nm-dispatcher.c | 69 +++++++++++++++++++++++++++++---------------- 1 file changed, 45 insertions(+), 24 deletions(-) diff --git a/src/nm-dispatcher.c b/src/nm-dispatcher.c index d1e2c0948..1f0e08d93 100644 --- a/src/nm-dispatcher.c +++ b/src/nm-dispatcher.c @@ -44,6 +44,26 @@ #define _NMLOG_DOMAIN LOGD_DISPATCH #define _NMLOG(level, ...) __NMLOG_DEFAULT (level, _NMLOG_DOMAIN, "dispatcher", __VA_ARGS__) +#define _NMLOG2_DOMAIN LOGD_DISPATCH +#define _NMLOG2(level, request_id, ...) \ + G_STMT_START { \ + const NMLogLevel __level = (level); \ + \ + if (nm_logging_enabled (__level, _NMLOG2_DOMAIN)) { \ + _nm_log (__level, _NMLOG2_DOMAIN, 0, \ + NULL, \ + NULL, \ + "dispatcher: (%u) " \ + _NM_UTILS_MACRO_FIRST (__VA_ARGS__), \ + (request_id) \ + _NM_UTILS_MACRO_REST (__VA_ARGS__)); \ + } \ + } G_STMT_END + +#define _NMLOG3_DOMAIN LOGD_DISPATCH +#define _NMLOG3(level, call_id, ...) _NMLOG2 (level, (call_id)->request_id, __VA_ARGS__) + + static GDBusProxy *dispatcher_proxy; static GHashTable *requests = NULL; @@ -339,7 +359,7 @@ dispatch_result_to_string (DispatchResult result) } static void -dispatcher_results_process (guint request_id, +dispatcher_results_process (guint32 request_id, NMDispatcherAction action, GVariant *v_results) { @@ -350,19 +370,19 @@ dispatcher_results_process (guint request_id, g_variant_get (v_results, "(a(sus))", &results); if (g_variant_iter_n_children (results) == 0) { - _LOGD ("(%u) succeeded but no scripts invoked", request_id); + _LOG2D (request_id, "succeeded but no scripts invoked"); return; } while (g_variant_iter_next (results, "(&su&s)", &script, &result, &err)) { if (result == DISPATCH_RESULT_SUCCESS) { - _LOGD ("(%u) %s succeeded", request_id, script); + _LOG2D (request_id, "%s succeeded", script); } else { - _LOGW ("(%u) %s failed (%s): %s", - request_id, - script, - dispatch_result_to_string (result), - err); + _LOG2W (request_id, + "%s failed (%s): %s", + script, + dispatch_result_to_string (result), + err); } } } @@ -380,11 +400,11 @@ dispatcher_done_cb (GObject *proxy, GAsyncResult *result, gpointer user_data) if (!ret) { if (_nm_dbus_error_has_name (error, "org.freedesktop.systemd1.LoadFailed")) { g_dbus_error_strip_remote_error (error); - _LOGW ("(%u) failed to call dispatcher scripts: %s", - info->request_id, error->message); + _LOG3W (info, "failed to call dispatcher scripts: %s", + error->message); } else { - _LOGD ("(%u) failed to call dispatcher scripts: %s", - info->request_id, error->message); + _LOG3D (info, "failed to call dispatcher scripts: %s", + error->message); } } else dispatcher_results_process (info->request_id, info->action, ret); @@ -465,21 +485,22 @@ _dispatcher_call (NMDispatcherAction action, /* All actions except 'hostname' and 'connectivity-change' require a device */ if ( action == NM_DISPATCHER_ACTION_HOSTNAME || action == NM_DISPATCHER_ACTION_CONNECTIVITY_CHANGE) { - _LOGD ("(%u) dispatching action '%s'%s", - reqid, action_to_string (action), - blocking + _LOG2D (reqid, + "dispatching action '%s'%s", + action_to_string (action), + blocking ? " (blocking)" : (callback ? " (with callback)" : "")); } else { g_return_val_if_fail (NM_IS_DEVICE (device), FALSE); - _LOGD ("(%u) (%s) dispatching action '%s'%s", - reqid, - vpn_iface ?: nm_device_get_iface(device), - action_to_string (action), - blocking - ? " (blocking)" - : (callback ? " (with callback)" : "")); + _LOG2D (reqid, + "(%s) dispatching action '%s'%s", + vpn_iface ?: nm_device_get_iface(device), + action_to_string (action), + blocking + ? " (blocking)" + : (callback ? " (with callback)" : "")); } if (applied_connection) @@ -573,7 +594,7 @@ _dispatcher_call (NMDispatcherAction action, &error); if (!ret) { g_dbus_error_strip_remote_error (error); - _LOGW ("(%u) failed: %s", reqid, error->message); + _LOG2W (reqid, "failed: %s", error->message); g_clear_error (&error); success = FALSE; } else { @@ -824,7 +845,7 @@ nm_dispatcher_call_cancel (guint call_id) g_return_if_fail (info); if (info && info->callback) { - _LOGD ("(%u) cancelling dispatcher callback action", call_id); + _LOG3D (info, "cancelling dispatcher callback action"); info->callback = NULL; } } From c3e2959a5adc730648a616d5299ae9f62aba266f Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Thu, 23 May 2019 13:57:39 +0200 Subject: [PATCH 20/26] dispatcher: replace guint call-id by opaque NMDispatcherCallId A guint value can wrap, so we would need to check that we don't allocate duplicate IDs (which we currently don't, and it's likely never to actually hit). Just expose the (opaque) pointer of the call-id. We still keep a "request_id", but that is only for logging purpose. --- src/devices/nm-device.c | 18 ++--- src/nm-dispatcher.c | 131 ++++++++++++++++-------------------- src/nm-dispatcher.h | 14 ++-- src/vpn/nm-vpn-connection.c | 22 +++--- 4 files changed, 89 insertions(+), 96 deletions(-) diff --git a/src/devices/nm-device.c b/src/devices/nm-device.c index d752f3b13..d40184e8b 100644 --- a/src/devices/nm-device.c +++ b/src/devices/nm-device.c @@ -328,16 +328,18 @@ typedef struct _NMDevicePrivate { ActivationHandleData act_handle4; /* for layer2 and IPv4. */ ActivationHandleData act_handle6; guint recheck_assume_id; + struct { guint call_id; NMDeviceStateReason available_reason; NMDeviceStateReason unavailable_reason; - } recheck_available; + } recheck_available; + struct { - guint call_id; + NMDispatcherCallId *call_id; NMDeviceState post_state; NMDeviceStateReason post_state_reason; - } dispatcher; + } dispatcher; /* Link stuff */ guint link_connected_id; @@ -12380,21 +12382,21 @@ dispatcher_cleanup (NMDevice *self) if (priv->dispatcher.call_id) { nm_dispatcher_call_cancel (priv->dispatcher.call_id); - priv->dispatcher.call_id = 0; + priv->dispatcher.call_id = NULL; priv->dispatcher.post_state = NM_DEVICE_STATE_UNKNOWN; priv->dispatcher.post_state_reason = NM_DEVICE_STATE_REASON_NONE; } } static void -dispatcher_complete_proceed_state (guint call_id, gpointer user_data) +dispatcher_complete_proceed_state (NMDispatcherCallId *call_id, gpointer user_data) { NMDevice *self = NM_DEVICE (user_data); NMDevicePrivate *priv = NM_DEVICE_GET_PRIVATE (self); g_return_if_fail (call_id == priv->dispatcher.call_id); - priv->dispatcher.call_id = 0; + priv->dispatcher.call_id = NULL; nm_device_queue_state (self, priv->dispatcher.post_state, priv->dispatcher.post_state_reason); priv->dispatcher.post_state = NM_DEVICE_STATE_UNKNOWN; @@ -14822,7 +14824,7 @@ deactivate_async_ready (NMDevice *self, } static void -deactivate_dispatcher_complete (guint call_id, gpointer user_data) +deactivate_dispatcher_complete (NMDispatcherCallId *call_id, gpointer user_data) { NMDevice *self = NM_DEVICE (user_data); NMDevicePrivate *priv = NM_DEVICE_GET_PRIVATE (self); @@ -14833,7 +14835,7 @@ deactivate_dispatcher_complete (guint call_id, gpointer user_data) reason = priv->dispatcher.post_state_reason; - priv->dispatcher.call_id = 0; + priv->dispatcher.call_id = NULL; priv->dispatcher.post_state = NM_DEVICE_STATE_UNKNOWN; priv->dispatcher.post_state_reason = NM_DEVICE_STATE_REASON_NONE; diff --git a/src/nm-dispatcher.c b/src/nm-dispatcher.c index 1f0e08d93..dbb79b757 100644 --- a/src/nm-dispatcher.c +++ b/src/nm-dispatcher.c @@ -63,10 +63,21 @@ #define _NMLOG3_DOMAIN LOGD_DISPATCH #define _NMLOG3(level, call_id, ...) _NMLOG2 (level, (call_id)->request_id, __VA_ARGS__) +/*****************************************************************************/ static GDBusProxy *dispatcher_proxy; static GHashTable *requests = NULL; +struct NMDispatcherCallId { + NMDispatcherFunc callback; + gpointer user_data; + NMDispatcherAction action; + guint idle_id; + guint32 request_id; +}; + +/*****************************************************************************/ + static void dump_proxy_to_props (NMProxyConfig *proxy, GVariantBuilder *builder) { @@ -307,20 +318,11 @@ fill_vpn_props (NMProxyConfig *proxy_config, dump_ip6_to_props (ip6_config, ip6_builder); } -typedef struct { - NMDispatcherAction action; - guint request_id; - NMDispatcherFunc callback; - gpointer user_data; - guint idle_id; -} DispatchInfo; - static void -dispatcher_info_free (DispatchInfo *info) +dispatcher_call_id_free (NMDispatcherCallId *call_id) { - if (info->idle_id) - g_source_remove (info->idle_id); - g_free (info); + nm_clear_g_source (&call_id->idle_id); + g_slice_free (NMDispatcherCallId, call_id); } static void @@ -330,16 +332,10 @@ _ensure_requests (void) requests = g_hash_table_new_full (nm_direct_hash, NULL, NULL, - (GDestroyNotify) dispatcher_info_free); + (GDestroyNotify) dispatcher_call_id_free); } } -static void -dispatcher_info_cleanup (DispatchInfo *info) -{ - g_hash_table_remove (requests, GUINT_TO_POINTER (info->request_id)); -} - static const char * dispatch_result_to_string (DispatchResult result) { @@ -392,7 +388,7 @@ dispatcher_done_cb (GObject *proxy, GAsyncResult *result, gpointer user_data) { gs_unref_variant GVariant *ret = NULL; gs_free_error GError *error = NULL; - DispatchInfo *info = user_data; + NMDispatcherCallId *call_id = user_data; ret = _nm_dbus_proxy_call_finish (G_DBUS_PROXY (proxy), result, G_VARIANT_TYPE ("(a(sus))"), @@ -400,19 +396,19 @@ dispatcher_done_cb (GObject *proxy, GAsyncResult *result, gpointer user_data) if (!ret) { if (_nm_dbus_error_has_name (error, "org.freedesktop.systemd1.LoadFailed")) { g_dbus_error_strip_remote_error (error); - _LOG3W (info, "failed to call dispatcher scripts: %s", + _LOG3W (call_id, "failed to call dispatcher scripts: %s", error->message); } else { - _LOG3D (info, "failed to call dispatcher scripts: %s", + _LOG3D (call_id, "failed to call dispatcher scripts: %s", error->message); } } else - dispatcher_results_process (info->request_id, info->action, ret); + dispatcher_results_process (call_id->request_id, call_id->action, ret); - if (info->callback) - info->callback (info->request_id, info->user_data); + if (call_id->callback) + call_id->callback (call_id, call_id->user_data); - dispatcher_info_cleanup (info); + g_hash_table_remove (requests, call_id); } static const char *action_table[] = { @@ -451,7 +447,7 @@ _dispatcher_call (NMDispatcherAction action, NMIP6Config *vpn_ip6_config, NMDispatcherFunc callback, gpointer user_data, - guint *out_call_id) + NMDispatcherCallId **out_call_id) { GVariant *connection_dict; GVariantBuilder connection_props; @@ -465,12 +461,13 @@ _dispatcher_call (NMDispatcherAction action, GVariantBuilder vpn_proxy_props; GVariantBuilder vpn_ip4_props; GVariantBuilder vpn_ip6_props; - DispatchInfo *info = NULL; - gboolean success = FALSE; + NMDispatcherCallId *call_id = NULL; static guint request_counter = 0; guint reqid = ++request_counter; const char *connectivity_state_string = "UNKNOWN"; + NM_SET_OUT (out_call_id, NULL); + if (!dispatcher_proxy) return FALSE; @@ -595,38 +592,30 @@ _dispatcher_call (NMDispatcherAction action, if (!ret) { g_dbus_error_strip_remote_error (error); _LOG2W (reqid, "failed: %s", error->message); - g_clear_error (&error); - success = FALSE; - } else { - dispatcher_results_process (reqid, action, ret); - success = TRUE; + return FALSE; } - } else { - info = g_malloc0 (sizeof (*info)); - info->action = action; - info->request_id = reqid; - info->callback = callback; - info->user_data = user_data; - g_dbus_proxy_call (dispatcher_proxy, - "Action", - g_steal_pointer (¶meters_floating), - G_DBUS_CALL_FLAGS_NONE, - CALL_TIMEOUT, - NULL, - dispatcher_done_cb, - info); - success = TRUE; + dispatcher_results_process (reqid, action, ret); + return TRUE; } - if (success && info) { - /* Track the request in case of cancelation */ - g_hash_table_insert (requests, GUINT_TO_POINTER (info->request_id), info); - if (out_call_id) - *out_call_id = info->request_id; - } else if (out_call_id) - *out_call_id = 0; - - return success; + call_id = g_slice_new (NMDispatcherCallId); + *call_id = (NMDispatcherCallId) { + .action = action, + .request_id = reqid, + .callback = callback, + .user_data = user_data, + }; + g_dbus_proxy_call (dispatcher_proxy, + "Action", + g_steal_pointer (¶meters_floating), + G_DBUS_CALL_FLAGS_NONE, + CALL_TIMEOUT, + NULL, + dispatcher_done_cb, + call_id); + g_hash_table_add (requests, call_id); + NM_SET_OUT (out_call_id, call_id); + return TRUE; } /** @@ -643,7 +632,7 @@ _dispatcher_call (NMDispatcherAction action, gboolean nm_dispatcher_call_hostname (NMDispatcherFunc callback, gpointer user_data, - guint *out_call_id) + NMDispatcherCallId **out_call_id) { return _dispatcher_call (NM_DISPATCHER_ACTION_HOSTNAME, FALSE, NULL, NULL, NULL, FALSE, @@ -674,7 +663,7 @@ nm_dispatcher_call_device (NMDispatcherAction action, NMActRequest *act_request, NMDispatcherFunc callback, gpointer user_data, - guint *out_call_id) + NMDispatcherCallId **out_call_id) { nm_assert (NM_IS_DEVICE (device)); if (!act_request) { @@ -758,7 +747,7 @@ nm_dispatcher_call_vpn (NMDispatcherAction action, NMIP6Config *vpn_ip6_config, NMDispatcherFunc callback, gpointer user_data, - guint *out_call_id) + NMDispatcherCallId **out_call_id) { return _dispatcher_call (action, FALSE, parent_device, @@ -822,7 +811,7 @@ gboolean nm_dispatcher_call_connectivity (NMConnectivityState connectivity_state, NMDispatcherFunc callback, gpointer user_data, - guint *out_call_id) + NMDispatcherCallId **out_call_id) { return _dispatcher_call (NM_DISPATCHER_ACTION_CONNECTIVITY_CHANGE, FALSE, NULL, NULL, NULL, FALSE, @@ -832,22 +821,18 @@ nm_dispatcher_call_connectivity (NMConnectivityState connectivity_state, } void -nm_dispatcher_call_cancel (guint call_id) +nm_dispatcher_call_cancel (NMDispatcherCallId *call_id) { - DispatchInfo *info; - - _ensure_requests (); + if ( !call_id + || g_hash_table_lookup (requests, call_id) != call_id + || !call_id->callback) + g_return_if_reached (); /* Canceling just means the callback doesn't get called, so set the * DispatcherInfo's callback to NULL. */ - info = g_hash_table_lookup (requests, GUINT_TO_POINTER (call_id)); - g_return_if_fail (info); - - if (info && info->callback) { - _LOG3D (info, "cancelling dispatcher callback action"); - info->callback = NULL; - } + _LOG3D (call_id, "cancelling dispatcher callback action"); + call_id->callback = NULL; } void diff --git a/src/nm-dispatcher.h b/src/nm-dispatcher.h index 1cdeeb882..10fb86fb6 100644 --- a/src/nm-dispatcher.h +++ b/src/nm-dispatcher.h @@ -39,18 +39,20 @@ typedef enum { NM_DISPATCHER_ACTION_CONNECTIVITY_CHANGE } NMDispatcherAction; -typedef void (*NMDispatcherFunc) (guint call_id, gpointer user_data); +typedef struct NMDispatcherCallId NMDispatcherCallId; + +typedef void (*NMDispatcherFunc) (NMDispatcherCallId *call_id, gpointer user_data); gboolean nm_dispatcher_call_hostname (NMDispatcherFunc callback, gpointer user_data, - guint *out_call_id); + NMDispatcherCallId **out_call_id); gboolean nm_dispatcher_call_device (NMDispatcherAction action, NMDevice *device, NMActRequest *act_request, NMDispatcherFunc callback, gpointer user_data, - guint *out_call_id); + NMDispatcherCallId **out_call_id); gboolean nm_dispatcher_call_device_sync (NMDispatcherAction action, NMDevice *device, @@ -66,7 +68,7 @@ gboolean nm_dispatcher_call_vpn (NMDispatcherAction action, NMIP6Config *vpn_ip6_config, NMDispatcherFunc callback, gpointer user_data, - guint *out_call_id); + NMDispatcherCallId **out_call_id); gboolean nm_dispatcher_call_vpn_sync (NMDispatcherAction action, NMSettingsConnection *settings_connection, @@ -80,9 +82,9 @@ gboolean nm_dispatcher_call_vpn_sync (NMDispatcherAction action, gboolean nm_dispatcher_call_connectivity (NMConnectivityState state, NMDispatcherFunc callback, gpointer user_data, - guint *out_call_id); + NMDispatcherCallId **out_call_id); -void nm_dispatcher_call_cancel (guint call_id); +void nm_dispatcher_call_cancel (NMDispatcherCallId *call_id); void nm_dispatcher_init (void); diff --git a/src/vpn/nm-vpn-connection.c b/src/vpn/nm-vpn-connection.c index 2c4f33359..99bcd0271 100644 --- a/src/vpn/nm-vpn-connection.c +++ b/src/vpn/nm-vpn-connection.c @@ -103,7 +103,7 @@ typedef struct { char *username; VpnState vpn_state; - guint dispatcher_id; + NMDispatcherCallId *dispatcher_id; NMActiveConnectionStateReason failure_reason; NMVpnServiceState service_state; @@ -418,22 +418,28 @@ vpn_cleanup (NMVpnConnection *self, NMDevice *parent_dev) } static void -dispatcher_pre_down_done (guint call_id, gpointer user_data) +dispatcher_pre_down_done (NMDispatcherCallId *call_id, gpointer user_data) { NMVpnConnection *self = NM_VPN_CONNECTION (user_data); NMVpnConnectionPrivate *priv = NM_VPN_CONNECTION_GET_PRIVATE (self); - priv->dispatcher_id = 0; + nm_assert (call_id); + nm_assert (priv->dispatcher_id == call_id); + + priv->dispatcher_id = NULL; _set_vpn_state (self, STATE_DISCONNECTED, NM_ACTIVE_CONNECTION_STATE_REASON_USER_DISCONNECTED, FALSE); } static void -dispatcher_pre_up_done (guint call_id, gpointer user_data) +dispatcher_pre_up_done (NMDispatcherCallId *call_id, gpointer user_data) { NMVpnConnection *self = NM_VPN_CONNECTION (user_data); NMVpnConnectionPrivate *priv = NM_VPN_CONNECTION_GET_PRIVATE (self); - priv->dispatcher_id = 0; + nm_assert (call_id); + nm_assert (priv->dispatcher_id == call_id); + + priv->dispatcher_id = NULL; _set_vpn_state (self, STATE_ACTIVATED, NM_ACTIVE_CONNECTION_STATE_REASON_NONE, FALSE); } @@ -442,10 +448,8 @@ dispatcher_cleanup (NMVpnConnection *self) { NMVpnConnectionPrivate *priv = NM_VPN_CONNECTION_GET_PRIVATE (self); - if (priv->dispatcher_id) { - nm_dispatcher_call_cancel (priv->dispatcher_id); - priv->dispatcher_id = 0; - } + if (priv->dispatcher_id) + nm_dispatcher_call_cancel (g_steal_pointer (&priv->dispatcher_id)); } static void From 3dbda5addcedbc5f752a083045756ae1a4a84011 Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Thu, 23 May 2019 16:13:47 +0200 Subject: [PATCH 21/26] dispatcher: use GDBusConnection instead of GDBusProxy in "nm-dispatcher.c" - drops nm_dispatcher_init(), which was called early in the main loop and created a proxy synchronously. Instead, the GDBusConnection is always ready. - reuse the GDBusConnection of NMDBusManager. This means, we won't even try from in "initrd" configure-and-quit mode. - as before, there is no "manager" instance. Instead, the data is stored in a global variable. That's ok. What is not OK is how the entire shutdown is handled (calling dispatcher blockingly, not waiting for requests to complete). That is fixable, but a lot of work. It is independent of whether we use a manager object or not. --- src/main.c | 2 - src/nm-dispatcher.c | 148 +++++++++++++++++++++++--------------------- src/nm-dispatcher.h | 2 - 3 files changed, 76 insertions(+), 76 deletions(-) diff --git a/src/main.c b/src/main.c index 4737d2a16..e9e2c4306 100644 --- a/src/main.c +++ b/src/main.c @@ -436,8 +436,6 @@ main (int argc, char *argv[]) nm_manager_dbus_set_property_handle, manager); - nm_dispatcher_init (); - g_signal_connect (manager, NM_MANAGER_CONFIGURE_QUIT, G_CALLBACK (manager_configure_quit), config); if (!nm_manager_start (manager, &error)) { diff --git a/src/nm-dispatcher.c b/src/nm-dispatcher.c index dbb79b757..488850024 100644 --- a/src/nm-dispatcher.c +++ b/src/nm-dispatcher.c @@ -65,9 +65,6 @@ /*****************************************************************************/ -static GDBusProxy *dispatcher_proxy; -static GHashTable *requests = NULL; - struct NMDispatcherCallId { NMDispatcherFunc callback; gpointer user_data; @@ -78,6 +75,36 @@ struct NMDispatcherCallId { /*****************************************************************************/ +static struct { + GDBusConnection *dbus_connection; + GHashTable *requests; + guint request_id_counter; +} gl; + +/*****************************************************************************/ + +static void dispatcher_call_id_free (NMDispatcherCallId *info); + +/*****************************************************************************/ + + +static void +_init_dispatcher (void) +{ + if (G_UNLIKELY (gl.requests == NULL)) { + gl.requests = g_hash_table_new_full (nm_direct_hash, + NULL, + NULL, + (GDestroyNotify) dispatcher_call_id_free); + gl.dbus_connection = nm_g_object_ref (NM_MAIN_DBUS_CONNECTION_GET); + + if (!gl.dbus_connection) + _LOGD ("No D-Bus connection to talk with NetworkManager-dispatcher service"); + } +} + +/*****************************************************************************/ + static void dump_proxy_to_props (NMProxyConfig *proxy, GVariantBuilder *builder) { @@ -325,17 +352,6 @@ dispatcher_call_id_free (NMDispatcherCallId *call_id) g_slice_free (NMDispatcherCallId, call_id); } -static void -_ensure_requests (void) -{ - if (G_UNLIKELY (requests == NULL)) { - requests = g_hash_table_new_full (nm_direct_hash, - NULL, - NULL, - (GDestroyNotify) dispatcher_call_id_free); - } -} - static const char * dispatch_result_to_string (DispatchResult result) { @@ -384,15 +400,17 @@ dispatcher_results_process (guint32 request_id, } static void -dispatcher_done_cb (GObject *proxy, GAsyncResult *result, gpointer user_data) +dispatcher_done_cb (GObject *source, GAsyncResult *result, gpointer user_data) { gs_unref_variant GVariant *ret = NULL; gs_free_error GError *error = NULL; NMDispatcherCallId *call_id = user_data; - ret = _nm_dbus_proxy_call_finish (G_DBUS_PROXY (proxy), result, - G_VARIANT_TYPE ("(a(sus))"), - &error); + nm_assert ((gpointer) source == gl.dbus_connection); + + ret = g_dbus_connection_call_finish (G_DBUS_CONNECTION (source), + result, + &error); if (!ret) { if (_nm_dbus_error_has_name (error, "org.freedesktop.systemd1.LoadFailed")) { g_dbus_error_strip_remote_error (error); @@ -408,7 +426,7 @@ dispatcher_done_cb (GObject *proxy, GAsyncResult *result, gpointer user_data) if (call_id->callback) call_id->callback (call_id, call_id->user_data); - g_hash_table_remove (requests, call_id); + g_hash_table_remove (gl.requests, call_id); } static const char *action_table[] = { @@ -462,27 +480,26 @@ _dispatcher_call (NMDispatcherAction action, GVariantBuilder vpn_ip4_props; GVariantBuilder vpn_ip6_props; NMDispatcherCallId *call_id = NULL; - static guint request_counter = 0; - guint reqid = ++request_counter; + guint request_id; const char *connectivity_state_string = "UNKNOWN"; + g_return_val_if_fail (!blocking || (!callback && !user_data), FALSE); + NM_SET_OUT (out_call_id, NULL); - if (!dispatcher_proxy) + _init_dispatcher (); + + if (!gl.dbus_connection) return FALSE; - /* Wrapping protection */ - if (G_UNLIKELY (!reqid)) - reqid = ++request_counter; - - g_assert (!blocking || (!callback && !user_data)); - - _ensure_requests (); + request_id = ++gl.request_id_counter; + if (G_UNLIKELY (!request_id)) + request_id = ++gl.request_id_counter; /* All actions except 'hostname' and 'connectivity-change' require a device */ if ( action == NM_DISPATCHER_ACTION_HOSTNAME || action == NM_DISPATCHER_ACTION_CONNECTIVITY_CHANGE) { - _LOG2D (reqid, + _LOG2D (request_id, "dispatching action '%s'%s", action_to_string (action), blocking @@ -491,7 +508,7 @@ _dispatcher_call (NMDispatcherAction action, } else { g_return_val_if_fail (NM_IS_DEVICE (device), FALSE); - _LOG2D (reqid, + _LOG2D (request_id, "(%s) dispatching action '%s'%s", vpn_iface ?: nm_device_get_iface(device), action_to_string (action), @@ -581,39 +598,46 @@ _dispatcher_call (NMDispatcherAction action, gs_unref_variant GVariant *ret = NULL; gs_free_error GError *error = NULL; - ret = _nm_dbus_proxy_call_sync (dispatcher_proxy, - "Action", - g_steal_pointer (¶meters_floating), - G_VARIANT_TYPE ("(a(sus))"), - G_DBUS_CALL_FLAGS_NONE, - CALL_TIMEOUT, - NULL, - &error); + ret = g_dbus_connection_call_sync (gl.dbus_connection, + NM_DISPATCHER_DBUS_SERVICE, + NM_DISPATCHER_DBUS_PATH, + NM_DISPATCHER_DBUS_INTERFACE, + "Action", + g_steal_pointer (¶meters_floating), + G_VARIANT_TYPE ("(a(sus))"), + G_DBUS_CALL_FLAGS_NONE, + CALL_TIMEOUT, + NULL, + &error); if (!ret) { g_dbus_error_strip_remote_error (error); - _LOG2W (reqid, "failed: %s", error->message); + _LOG2W (request_id, "failed: %s", error->message); return FALSE; } - dispatcher_results_process (reqid, action, ret); + dispatcher_results_process (request_id, action, ret); return TRUE; } call_id = g_slice_new (NMDispatcherCallId); *call_id = (NMDispatcherCallId) { .action = action, - .request_id = reqid, + .request_id = request_id, .callback = callback, .user_data = user_data, }; - g_dbus_proxy_call (dispatcher_proxy, - "Action", - g_steal_pointer (¶meters_floating), - G_DBUS_CALL_FLAGS_NONE, - CALL_TIMEOUT, - NULL, - dispatcher_done_cb, - call_id); - g_hash_table_add (requests, call_id); + g_dbus_connection_call (gl.dbus_connection, + NM_DISPATCHER_DBUS_SERVICE, + NM_DISPATCHER_DBUS_PATH, + NM_DISPATCHER_DBUS_INTERFACE, + "Action", + g_steal_pointer (¶meters_floating), + G_VARIANT_TYPE ("(a(sus))"), + G_DBUS_CALL_FLAGS_NONE, + CALL_TIMEOUT, + NULL, + dispatcher_done_cb, + call_id); + g_hash_table_add (gl.requests, call_id); NM_SET_OUT (out_call_id, call_id); return TRUE; } @@ -824,7 +848,7 @@ void nm_dispatcher_call_cancel (NMDispatcherCallId *call_id) { if ( !call_id - || g_hash_table_lookup (requests, call_id) != call_id + || g_hash_table_lookup (gl.requests, call_id) != call_id || !call_id->callback) g_return_if_reached (); @@ -834,23 +858,3 @@ nm_dispatcher_call_cancel (NMDispatcherCallId *call_id) _LOG3D (call_id, "cancelling dispatcher callback action"); call_id->callback = NULL; } - -void -nm_dispatcher_init (void) -{ - GError *error = NULL; - - dispatcher_proxy = g_dbus_proxy_new_for_bus_sync (G_BUS_TYPE_SYSTEM, - G_DBUS_PROXY_FLAGS_DO_NOT_LOAD_PROPERTIES | - G_DBUS_PROXY_FLAGS_DO_NOT_CONNECT_SIGNALS, - NULL, - NM_DISPATCHER_DBUS_SERVICE, - NM_DISPATCHER_DBUS_PATH, - NM_DISPATCHER_DBUS_INTERFACE, - NULL, &error); - if (!dispatcher_proxy) { - _LOGE ("could not get dispatcher proxy! %s", error->message); - g_clear_error (&error); - } -} - diff --git a/src/nm-dispatcher.h b/src/nm-dispatcher.h index 10fb86fb6..3c79f3bbf 100644 --- a/src/nm-dispatcher.h +++ b/src/nm-dispatcher.h @@ -86,6 +86,4 @@ gboolean nm_dispatcher_call_connectivity (NMConnectivityState state, void nm_dispatcher_call_cancel (NMDispatcherCallId *call_id); -void nm_dispatcher_init (void); - #endif /* __NM_DISPATCHER_H__ */ From 55be5166f09d11121ff504f02a0f7ba305715d3c Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Thu, 23 May 2019 16:51:42 +0200 Subject: [PATCH 22/26] dispatcher: cleanup nm_dispatcher_call_cancel() Remove the call-id from the requests hash before invoking the callback. This prevents the user to cancel the request from within the callback. Supporting such a use case is not necessary so prevent it and tighten the callers up. --- src/devices/nm-device.c | 24 ++++++++++++------------ src/nm-dispatcher.c | 14 +++++++------- 2 files changed, 19 insertions(+), 19 deletions(-) diff --git a/src/devices/nm-device.c b/src/devices/nm-device.c index d40184e8b..493288c19 100644 --- a/src/devices/nm-device.c +++ b/src/devices/nm-device.c @@ -12375,17 +12375,18 @@ nm_device_get_ip6_config (NMDevice *self) /*****************************************************************************/ -static void +static gboolean dispatcher_cleanup (NMDevice *self) { NMDevicePrivate *priv = NM_DEVICE_GET_PRIVATE (self); - if (priv->dispatcher.call_id) { - nm_dispatcher_call_cancel (priv->dispatcher.call_id); - priv->dispatcher.call_id = NULL; - priv->dispatcher.post_state = NM_DEVICE_STATE_UNKNOWN; - priv->dispatcher.post_state_reason = NM_DEVICE_STATE_REASON_NONE; - } + if (!priv->dispatcher.call_id) + return FALSE; + + nm_dispatcher_call_cancel (g_steal_pointer (&priv->dispatcher.call_id)); + priv->dispatcher.post_state = NM_DEVICE_STATE_UNKNOWN; + priv->dispatcher.post_state_reason = NM_DEVICE_STATE_REASON_NONE; + return TRUE; } static void @@ -12397,7 +12398,8 @@ dispatcher_complete_proceed_state (NMDispatcherCallId *call_id, gpointer user_da g_return_if_fail (call_id == priv->dispatcher.call_id); priv->dispatcher.call_id = NULL; - nm_device_queue_state (self, priv->dispatcher.post_state, + nm_device_queue_state (self, + priv->dispatcher.post_state, priv->dispatcher.post_state_reason); priv->dispatcher.post_state = NM_DEVICE_STATE_UNKNOWN; priv->dispatcher.post_state_reason = NM_DEVICE_STATE_REASON_NONE; @@ -12410,10 +12412,8 @@ ip_check_pre_up (NMDevice *self) { NMDevicePrivate *priv = NM_DEVICE_GET_PRIVATE (self); - if (priv->dispatcher.call_id != 0) { - g_warn_if_reached (); - dispatcher_cleanup (self); - } + if (dispatcher_cleanup (self)) + nm_assert_not_reached (); priv->dispatcher.post_state = NM_DEVICE_STATE_SECONDARIES; priv->dispatcher.post_state_reason = NM_DEVICE_STATE_REASON_NONE; diff --git a/src/nm-dispatcher.c b/src/nm-dispatcher.c index 488850024..5d860f2e3 100644 --- a/src/nm-dispatcher.c +++ b/src/nm-dispatcher.c @@ -92,10 +92,7 @@ static void _init_dispatcher (void) { if (G_UNLIKELY (gl.requests == NULL)) { - gl.requests = g_hash_table_new_full (nm_direct_hash, - NULL, - NULL, - (GDestroyNotify) dispatcher_call_id_free); + gl.requests = g_hash_table_new (nm_direct_hash, NULL); gl.dbus_connection = nm_g_object_ref (NM_MAIN_DBUS_CONNECTION_GET); if (!gl.dbus_connection) @@ -423,10 +420,12 @@ dispatcher_done_cb (GObject *source, GAsyncResult *result, gpointer user_data) } else dispatcher_results_process (call_id->request_id, call_id->action, ret); + g_hash_table_remove (gl.requests, call_id); + if (call_id->callback) call_id->callback (call_id, call_id->user_data); - g_hash_table_remove (gl.requests, call_id); + dispatcher_call_id_free (call_id); } static const char *action_table[] = { @@ -447,8 +446,9 @@ static const char *action_table[] = { static const char * action_to_string (NMDispatcherAction action) { - g_assert ((gsize) action < G_N_ELEMENTS (action_table)); - return action_table[action]; + if (G_UNLIKELY ((gsize) action >= G_N_ELEMENTS (action_table))) + g_return_val_if_reached (NULL); + return action_table[(gsize) action]; } static gboolean From aafeaeab18d3066ffa0053f9bc544202bf6d49aa Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Thu, 23 May 2019 17:54:36 +0200 Subject: [PATCH 23/26] dispatcher: log ifname/con_uuid as structured logging for dispatcher requests --- src/nm-dispatcher.c | 137 +++++++++++++++++++++++++++++++------------- 1 file changed, 98 insertions(+), 39 deletions(-) diff --git a/src/nm-dispatcher.c b/src/nm-dispatcher.c index 5d860f2e3..9e74bdf5b 100644 --- a/src/nm-dispatcher.c +++ b/src/nm-dispatcher.c @@ -45,32 +45,35 @@ #define _NMLOG(level, ...) __NMLOG_DEFAULT (level, _NMLOG_DOMAIN, "dispatcher", __VA_ARGS__) #define _NMLOG2_DOMAIN LOGD_DISPATCH -#define _NMLOG2(level, request_id, ...) \ - G_STMT_START { \ - const NMLogLevel __level = (level); \ - \ - if (nm_logging_enabled (__level, _NMLOG2_DOMAIN)) { \ - _nm_log (__level, _NMLOG2_DOMAIN, 0, \ - NULL, \ - NULL, \ - "dispatcher: (%u) " \ - _NM_UTILS_MACRO_FIRST (__VA_ARGS__), \ - (request_id) \ - _NM_UTILS_MACRO_REST (__VA_ARGS__)); \ - } \ - } G_STMT_END +#define _NMLOG2(level, request_id, log_ifname, log_con_uuid, ...) \ + nm_log ((level), \ + _NMLOG2_DOMAIN, \ + (log_ifname), \ + (log_con_uuid), \ + "dispatcher: (%u) " \ + _NM_UTILS_MACRO_FIRST (__VA_ARGS__), \ + (request_id) \ + _NM_UTILS_MACRO_REST (__VA_ARGS__)) #define _NMLOG3_DOMAIN LOGD_DISPATCH -#define _NMLOG3(level, call_id, ...) _NMLOG2 (level, (call_id)->request_id, __VA_ARGS__) +#define _NMLOG3(level, call_id, ...) \ + G_STMT_START { \ + const NMDispatcherCallId *const _call_id = (call_id); \ + \ + _NMLOG2 (level, _call_id->request_id, _call_id->log_ifname, _call_id->log_con_uuid, __VA_ARGS__); \ + } G_STMT_END /*****************************************************************************/ struct NMDispatcherCallId { NMDispatcherFunc callback; gpointer user_data; + const char *log_ifname; + const char *log_con_uuid; NMDispatcherAction action; guint idle_id; guint32 request_id; + char extra_strings[]; }; /*****************************************************************************/ @@ -83,7 +86,54 @@ static struct { /*****************************************************************************/ -static void dispatcher_call_id_free (NMDispatcherCallId *info); +static NMDispatcherCallId * +dispatcher_call_id_new (guint32 request_id, + NMDispatcherAction action, + NMDispatcherFunc callback, + gpointer user_data, + const char *log_ifname, + const char *log_con_uuid) +{ + NMDispatcherCallId *call_id; + gsize l_log_ifname; + gsize l_log_con_uuid; + char *extra_strings; + + l_log_ifname = log_ifname ? (strlen (log_ifname) + 1) : 0u; + l_log_con_uuid = log_con_uuid ? (strlen (log_con_uuid) + 1) : 0u; + + call_id = g_malloc (sizeof (NMDispatcherCallId) + l_log_ifname + l_log_con_uuid); + + call_id->action = action; + call_id->request_id = request_id; + call_id->callback = callback; + call_id->user_data = user_data; + call_id->idle_id = 0; + + extra_strings = &call_id->extra_strings[0]; + + if (log_ifname) { + call_id->log_ifname = extra_strings; + memcpy (extra_strings, log_ifname, l_log_ifname); + extra_strings += l_log_ifname; + } else + call_id->log_ifname = NULL; + + if (log_con_uuid) { + call_id->log_con_uuid = extra_strings; + memcpy (extra_strings, log_con_uuid, l_log_con_uuid); + } else + call_id->log_con_uuid = NULL; + + return call_id; +} + +static void +dispatcher_call_id_free (NMDispatcherCallId *call_id) +{ + nm_clear_g_source (&call_id->idle_id); + g_free (call_id); +} /*****************************************************************************/ @@ -342,13 +392,6 @@ fill_vpn_props (NMProxyConfig *proxy_config, dump_ip6_to_props (ip6_config, ip6_builder); } -static void -dispatcher_call_id_free (NMDispatcherCallId *call_id) -{ - nm_clear_g_source (&call_id->idle_id); - g_slice_free (NMDispatcherCallId, call_id); -} - static const char * dispatch_result_to_string (DispatchResult result) { @@ -369,7 +412,8 @@ dispatch_result_to_string (DispatchResult result) static void dispatcher_results_process (guint32 request_id, - NMDispatcherAction action, + const char *log_ifname, + const char *log_con_uuid, GVariant *v_results) { nm_auto_free_variant_iter GVariantIter *results = NULL; @@ -379,15 +423,17 @@ dispatcher_results_process (guint32 request_id, g_variant_get (v_results, "(a(sus))", &results); if (g_variant_iter_n_children (results) == 0) { - _LOG2D (request_id, "succeeded but no scripts invoked"); + _LOG2D (request_id, log_ifname, log_con_uuid, "succeeded but no scripts invoked"); return; } while (g_variant_iter_next (results, "(&su&s)", &script, &result, &err)) { if (result == DISPATCH_RESULT_SUCCESS) { - _LOG2D (request_id, "%s succeeded", script); + _LOG2D (request_id, log_ifname, log_con_uuid, "%s succeeded", script); } else { _LOG2W (request_id, + log_ifname, + log_con_uuid, "%s failed (%s): %s", script, dispatch_result_to_string (result), @@ -417,8 +463,12 @@ dispatcher_done_cb (GObject *source, GAsyncResult *result, gpointer user_data) _LOG3D (call_id, "failed to call dispatcher scripts: %s", error->message); } - } else - dispatcher_results_process (call_id->request_id, call_id->action, ret); + } else { + dispatcher_results_process (call_id->request_id, + call_id->log_ifname, + call_id->log_con_uuid, + ret); + } g_hash_table_remove (gl.requests, call_id); @@ -479,9 +529,11 @@ _dispatcher_call (NMDispatcherAction action, GVariantBuilder vpn_proxy_props; GVariantBuilder vpn_ip4_props; GVariantBuilder vpn_ip6_props; - NMDispatcherCallId *call_id = NULL; + NMDispatcherCallId *call_id; guint request_id; const char *connectivity_state_string = "UNKNOWN"; + const char *log_ifname; + const char *log_con_uuid; g_return_val_if_fail (!blocking || (!callback && !user_data), FALSE); @@ -492,6 +544,9 @@ _dispatcher_call (NMDispatcherAction action, if (!gl.dbus_connection) return FALSE; + log_ifname = device ? nm_device_get_iface (device) : NULL; + log_con_uuid = settings_connection ? nm_settings_connection_get_uuid (settings_connection) : NULL; + request_id = ++gl.request_id_counter; if (G_UNLIKELY (!request_id)) request_id = ++gl.request_id_counter; @@ -500,6 +555,8 @@ _dispatcher_call (NMDispatcherAction action, if ( action == NM_DISPATCHER_ACTION_HOSTNAME || action == NM_DISPATCHER_ACTION_CONNECTIVITY_CHANGE) { _LOG2D (request_id, + log_ifname, + log_con_uuid, "dispatching action '%s'%s", action_to_string (action), blocking @@ -509,8 +566,10 @@ _dispatcher_call (NMDispatcherAction action, g_return_val_if_fail (NM_IS_DEVICE (device), FALSE); _LOG2D (request_id, + log_ifname, + log_con_uuid, "(%s) dispatching action '%s'%s", - vpn_iface ?: nm_device_get_iface(device), + vpn_iface ?: nm_device_get_iface (device), action_to_string (action), blocking ? " (blocking)" @@ -611,20 +670,20 @@ _dispatcher_call (NMDispatcherAction action, &error); if (!ret) { g_dbus_error_strip_remote_error (error); - _LOG2W (request_id, "failed: %s", error->message); + _LOG2W (request_id, log_ifname, log_con_uuid, "failed: %s", error->message); return FALSE; } - dispatcher_results_process (request_id, action, ret); + dispatcher_results_process (request_id, log_ifname, log_con_uuid, ret); return TRUE; } - call_id = g_slice_new (NMDispatcherCallId); - *call_id = (NMDispatcherCallId) { - .action = action, - .request_id = request_id, - .callback = callback, - .user_data = user_data, - }; + call_id = dispatcher_call_id_new (request_id, + action, + callback, + user_data, + log_ifname, + log_con_uuid); + g_dbus_connection_call (gl.dbus_connection, NM_DISPATCHER_DBUS_SERVICE, NM_DISPATCHER_DBUS_PATH, From 947f979f267d1e58defaf9fca5ccc33973bcf5e5 Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Fri, 24 May 2019 09:03:27 +0200 Subject: [PATCH 24/26] dispatcher/trivial: add FIXME comment about how to fix shutdown of NtworkManager --- src/nm-dispatcher.c | 8 ++++++++ 1 file changed, 8 insertions(+) diff --git a/src/nm-dispatcher.c b/src/nm-dispatcher.c index 9e74bdf5b..d65f34494 100644 --- a/src/nm-dispatcher.c +++ b/src/nm-dispatcher.c @@ -78,6 +78,14 @@ struct NMDispatcherCallId { /*****************************************************************************/ +/* FIXME(shutdown): on shutdown, we should not run dispatcher scripts synchronously. + * Instead, we should of course still run them asynchronously. + * + * Also, we should wait for all pending requests to complete before exiting the main-loop + * (with a watchdog). If we hit a timeout, we log a warning and quit (but leave the scripts + * running). + * + * Finally, cleanup the global structures. */ static struct { GDBusConnection *dbus_connection; GHashTable *requests; From acc335aad4c310fef3760d43b2fb137e5206615c Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Fri, 24 May 2019 09:16:36 +0200 Subject: [PATCH 25/26] dispatcher/systemd: order NetworkManager-dispatcher.service Before=NetworkManager.service During shutdown, systemd should first stop NetworkManager and then the dispatcher service. Note that dispatcher service is D-Bus activated, so the two services don't Want/Require each other. But the ordering still matters. --- data/NetworkManager-dispatcher.service.in | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/data/NetworkManager-dispatcher.service.in b/data/NetworkManager-dispatcher.service.in index c450478ba..80dc2a1b8 100644 --- a/data/NetworkManager-dispatcher.service.in +++ b/data/NetworkManager-dispatcher.service.in @@ -1,6 +1,12 @@ [Unit] Description=Network Manager Script Dispatcher Service +# Order the dispatcher before NetworkManager. While dispatcher +# is D-Bus activate (and not intended to be explicitly wanted by +# another service/target), the ordering dependency matters during +# shutdown. We want first NetworkManager to be stopped. +Before=NetworkManager.service + [Service] Type=dbus BusName=org.freedesktop.nm_dispatcher From 7ea76c07e52ed6c5f4d78e52fd03e1e7e9b3da78 Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Fri, 24 May 2019 09:14:45 +0200 Subject: [PATCH 26/26] dispatcher: log warning when nm-dispatcher quits with requests pending --- dispatcher/nm-dispatcher.c | 15 +++++++++++++++ 1 file changed, 15 insertions(+) diff --git a/dispatcher/nm-dispatcher.c b/dispatcher/nm-dispatcher.c index 9a7fd2aa6..a803c9759 100644 --- a/dispatcher/nm-dispatcher.c +++ b/dispatcher/nm-dispatcher.c @@ -1080,6 +1080,21 @@ main (int argc, char **argv) done: + if (gl.num_requests_pending > 0) { + /* this only happens when we quit due to SIGTERM (not due to the idle timer). + * + * Log a warning about pending scripts. + * + * Maybe we should notify NetworkManager that these scripts are left in an unknown state. + * But this is either a bug of a dispatcher script (not terminating in time). + * + * FIXME(shutdown): Also, currently NetworkManager behaves wrongly on shutdown. + * Note that systemd would not terminate NetworkManager-dispatcher before NetworkManager. + * It's NetworkManager's responsibility to keep running long enough so that all requests + * can complete (with a watchdog timer, and a warning that user provided scripts hang). */ + _LOG_X_W ("exiting but there are still %u requests pending", gl.num_requests_pending); + } + if (dbus_own_name_id != 0) g_bus_unown_name (nm_steal_int (&dbus_own_name_id));