dispatcher: read device-handler's stdout into a dictionary

Device handlers need a way to pass data back to NetworkManager, such
as the ifindex and an error message. Allow them to return a dictionary
on standard output, where each line contains a "$key=$value" pair.
In the daemon, the dictionary is returned via the callback function.

man/NetworkManager-dispatcher.xml

@@ -186,7 +186,31 @@
             The script needs to perform any action needed to create the device
             for the generic connection. On successful termination, the script
             returns zero. Otherwise, it returns a non-zero value to indicate an
-            error.
+            error. The script can return values to NetworkManager by writing to
+            standard output; each line should contain a key name followed by the
+            equal sign '=' and a key value. The keys understood at the moment
+            are:
+            <variablelist>
+              <varlistentry>
+                <term><varname>IFINDEX</varname></term>
+                <listitem><para> Indicates the interface index of the interface
+                created by the script. This key is required when the script
+                succeeds; if it is not set, the activation will fail. The key is
+                ignored in case of script failure. </para></listitem>
+              </varlistentry>
+              <varlistentry>
+                <term><varname>ERROR</varname></term>
+                <listitem><para> Specifies an error message indicating the cause
+                of the script failure. It is ignored when the script succeeds.
+                </para></listitem>
+              </varlistentry>
+            </variablelist>
+            Since the dispatcher service captures stdout for parsing those keys,
+            anything written to stdout will not appear in the dispatcher service
+            journal log. Use stderr if you want to print messages to the journal
+            (for example, for debugging). Only the first 8KiB of stdout are
+            considered and among those, only the first 64 lines; the rest is
+            ignored.
           </para>
         </listitem>
       </varlistentry>
@@ -197,7 +221,11 @@
             This action is the counterpart of <literal>device-add</literal> and
             is called to delete the device for a generic connection. All the
             aspects described for <literal>device-add</literal> also apply to
-            this action.
+            this action, with the only exception that key
+            <varname>IFINDEX</varname> is ignored. It is not necessary to delete
+            the kernel link in the handler because NetworkManager already does
+            that; therefore the action is useful for any additional cleanup
+            needed.
           </para>
         </listitem>
       </varlistentry>

src/core/nm-dispatcher.c

@@ -409,6 +409,8 @@ dispatch_result_to_string(DispatchResult result)
  * @out_success: (out): for device-handler actions, the result of the script
  * @out_error_msg: (out)(transfer full): for device-handler actions, the
  *   error message in case of failure
+ * @out_dict: (out)(transfer full): for device-handler actions, the output
+ *   dictionary in case of success
  * @v_results: the GVariant containing the results to parse
  * @is_action2: whether the D-Bus method is "Action2()" (or "Action()")
  *
@@ -424,6 +426,7 @@ dispatcher_results_process(NMDispatcherAction action,
                            const char        *log_con_uuid,
                            gboolean          *out_success,
                            char             **out_error_msg,
+                           GHashTable       **out_dict,
                            GVariant          *v_results,
                            gboolean           is_action2)
 {
@@ -454,6 +457,7 @@ dispatcher_results_process(NMDispatcherAction action,
         if (action_is_dh) {
             NM_SET_OUT(out_success, FALSE);
             NM_SET_OUT(out_error_msg, g_strdup("no result returned from dispatcher service"));
+            NM_SET_OUT(out_dict, NULL);
         }
         return;
     }
@@ -480,9 +484,53 @@ dispatcher_results_process(NMDispatcherAction action,
                    dispatch_result_to_string(result),
                    err);
         }
+
         if (action_is_dh) {
-            NM_SET_OUT(out_success, result == DISPATCH_RESULT_SUCCESS);
-            NM_SET_OUT(out_error_msg, g_strdup(err));
+            if (result == DISPATCH_RESULT_SUCCESS) {
+                gs_unref_variant GVariant     *output_dict = NULL;
+                gs_unref_hashtable GHashTable *hash        = NULL;
+                GVariantIter                   iter;
+                const char                    *value;
+                const char                    *key;
+
+                hash = g_hash_table_new_full(nm_str_hash, g_str_equal, g_free, g_free);
+                output_dict =
+                    g_variant_lookup_value(options, "output_dict", G_VARIANT_TYPE("a{ss}"));
+                if (output_dict) {
+                    g_variant_iter_init(&iter, output_dict);
+                    while (g_variant_iter_next(&iter, "{&s&s}", &key, &value)) {
+                        const char *unescaped;
+                        gpointer    to_free;
+                        gsize       len;
+
+                        unescaped = nm_utils_buf_utf8safe_unescape(value,
+                                                                   NM_UTILS_STR_UTF8_SAFE_FLAG_NONE,
+                                                                   &len,
+                                                                   &to_free);
+                        g_hash_table_insert(hash,
+                                            g_strdup(key),
+                                            ((char *) to_free) ?: g_strdup(unescaped));
+                    }
+                }
+
+                NM_SET_OUT(out_success, TRUE);
+                NM_SET_OUT(out_dict, g_steal_pointer(&hash));
+                NM_SET_OUT(out_error_msg, NULL);
+            } else {
+                gs_unref_variant GVariant *output_dict = NULL;
+                const char                *err2        = NULL;
+
+                output_dict =
+                    g_variant_lookup_value(options, "output_dict", G_VARIANT_TYPE("a{ss}"));
+                if (output_dict) {
+                    g_variant_lookup(output_dict, "ERROR", "&s", &err2);
+                }
+
+                NM_SET_OUT(out_success, FALSE);
+                NM_SET_OUT(out_dict, NULL);
+                NM_SET_OUT(out_error_msg,
+                           err2 ? g_strdup_printf("%s: Error: %s", err, err2) : g_strdup(err));
+            }
             break;
         }
     }
@@ -491,13 +539,14 @@ dispatcher_results_process(NMDispatcherAction action,
 static void
 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;
-    gint64                     now_msec;
-    gboolean                   action_is_dh;
-    gboolean                   success   = TRUE;
-    gs_free char              *error_msg = NULL;
+    gs_unref_variant GVariant     *ret     = NULL;
+    gs_free_error GError          *error   = NULL;
+    NMDispatcherCallId            *call_id = user_data;
+    gint64                         now_msec;
+    gboolean                       action_is_dh;
+    gboolean                       success   = TRUE;
+    gs_free char                  *error_msg = NULL;
+    gs_unref_hashtable GHashTable *hash      = NULL;
 
     nm_assert((gpointer) source == gl.dbus_connection);
 
@@ -547,6 +596,7 @@ dispatcher_done_cb(GObject *source, GAsyncResult *result, gpointer user_data)
                                    call_id->log_con_uuid,
                                    &success,
                                    &error_msg,
+                                   &hash,
                                    ret,
                                    call_id->is_action2);
     }
@@ -558,7 +608,7 @@ dispatcher_done_cb(GObject *source, GAsyncResult *result, gpointer user_data)
         if (action_is_dh) {
             NMDispatcherFuncDH cb = (NMDispatcherFuncDH) call_id->callback;
 
-            cb(call_id, call_id->user_data, success, error_msg);
+            cb(call_id, call_id->user_data, success, error_msg, hash);
         } else {
             NMDispatcherFunc cb = (NMDispatcherFunc) call_id->callback;
 
@@ -854,6 +904,7 @@ _dispatcher_call(NMDispatcherAction    action,
                                    log_con_uuid,
                                    NULL,
                                    NULL,
+                                   NULL,
                                    ret,
                                    is_action2);
         return TRUE;

src/core/nm-dispatcher.h

@@ -39,7 +39,8 @@ typedef void (*NMDispatcherFunc)(NMDispatcherCallId *call_id, gpointer user_data
 typedef void (*NMDispatcherFuncDH)(NMDispatcherCallId *call_id,
                                    gpointer            user_data,
                                    gboolean            success,
-                                   const char         *error_msg);
+                                   const char         *error_msg,
+                                   GHashTable         *dict);
 
 gboolean nm_dispatcher_call_hostname(NMDispatcherFunc     callback,
                                      gpointer             user_data,

src/nm-dispatcher/nm-dispatcher.c

@@ -20,6 +20,7 @@
 #include "libnm-core-aux-extern/nm-dispatcher-api.h"
 #include "libnm-glib-aux/nm-dbus-aux.h"
 #include "libnm-glib-aux/nm-io-utils.h"
+#include "libnm-glib-aux/nm-str-buf.h"
 #include "libnm-glib-aux/nm-time-utils.h"
 #include "nm-dispatcher-utils.h"
 
@@ -75,6 +76,10 @@ typedef struct {
     gboolean       dispatched;
     GSource       *watch_source;
     GSource       *timeout_source;
+
+    int      stdout_fd;
+    GSource *stdout_source;
+    NMStrBuf stdout_buffer;
 } ScriptInfo;
 
 struct Request {
@@ -194,6 +199,12 @@ script_info_free(gpointer ptr)
 {
     ScriptInfo *info = ptr;
 
+    nm_assert(info->pid == -1);
+    nm_assert(info->stdout_fd == -1);
+    nm_assert(!info->stdout_source);
+    nm_assert(!info->timeout_source);
+    nm_assert(!info->watch_source);
+
     g_free(info->script);
     g_free(info->error);
     g_slice_free(ScriptInfo, info);
@@ -282,6 +293,64 @@ next_request(Request *request)
     return TRUE;
 }
 
+static GVariant *
+build_result_options(char *stdout)
+{
+    gs_unref_hashtable GHashTable *hash = NULL;
+    GHashTableIter                 iter;
+    gs_strfreev char             **lines = NULL;
+    GVariantBuilder                builder_opts;
+    GVariantBuilder                builder_out_dict;
+    guint                          i;
+    char                          *eq;
+    char                          *key;
+    char                          *value;
+
+    lines = g_strsplit(stdout, "\n", 65);
+
+    for (i = 0; lines[i] && i < 64; i++) {
+        eq = strchr(lines[i], '=');
+        if (!eq)
+            continue;
+        *eq = '\0';
+
+        if (!NM_STRCHAR_ALL(lines[i],
+                            ch,
+                            (ch >= 'A' && ch <= 'Z') || (ch >= '0' && ch <= '9') || ch == '_'))
+            continue;
+
+        if (!hash) {
+            hash = g_hash_table_new_full(nm_str_hash, g_str_equal, g_free, g_free);
+        }
+
+        g_hash_table_insert(hash, g_strdup(lines[i]), g_strdup(eq + 1));
+    }
+
+    g_variant_builder_init(&builder_out_dict, G_VARIANT_TYPE("a{ss}"));
+    if (hash) {
+        g_hash_table_iter_init(&iter, hash);
+        while (g_hash_table_iter_next(&iter, (gpointer *) &key, (gpointer *) &value)) {
+            gs_free char *to_free = NULL;
+
+            g_variant_builder_add(&builder_out_dict,
+                                  "{ss}",
+                                  key,
+                                  nm_utils_buf_utf8safe_escape(value,
+                                                               -1,
+                                                               NM_UTILS_STR_UTF8_SAFE_FLAG_NONE,
+                                                               &to_free));
+        }
+    }
+
+    g_variant_builder_init(&builder_opts, G_VARIANT_TYPE("a{sv}"));
+    g_variant_builder_add(&builder_opts,
+                          "{sv}",
+                          "output_dict",
+                          g_variant_builder_end(&builder_out_dict));
+
+    return g_variant_builder_end(&builder_opts);
+}
+
 static void
 request_dbus_method_return(Request *request)
 {
@@ -295,7 +364,14 @@ request_dbus_method_return(Request *request)
     }
 
     for (i = 0; i < request->scripts->len; i++) {
-        ScriptInfo *script = g_ptr_array_index(request->scripts, i);
+        ScriptInfo   *script  = g_ptr_array_index(request->scripts, i);
+        GVariant     *options = NULL;
+        gs_free char *stdout  = NULL;
+
+        if (request->is_device_handler) {
+            stdout  = nm_str_buf_finalize(&script->stdout_buffer, NULL);
+            options = build_result_options(stdout);
+        }
 
         if (request->is_action2) {
             g_variant_builder_add(&results,
@@ -303,7 +379,7 @@ request_dbus_method_return(Request *request)
                                   script->script,
                                   script->result,
                                   script->error ?: "",
-                                  nm_g_variant_singleton_aLsvI());
+                                  options ?: nm_g_variant_singleton_aLsvI());
         } else {
             g_variant_builder_add(&results,
                                   "(sus)",
@@ -356,10 +432,17 @@ complete_request(Request *request)
 static void
 complete_script(ScriptInfo *script)
 {
-    Request *request;
-    gboolean wait = script->wait;
+    Request *request = script->request;
+    gboolean wait    = script->wait;
 
-    request = script->request;
+    if (script->pid != -1 || script->stdout_fd != -1) {
+        /* Wait that process has terminated and stdout is closed */
+        return;
+    }
+
+    script->request->num_scripts_done++;
+    if (!script->wait)
+        script->request->num_scripts_nowait--;
 
     if (wait) {
         /* for "wait" scripts, try to schedule the next blocking script.
@@ -427,14 +510,12 @@ script_watch_cb(GPid pid, int status, gpointer user_data)
 
     nm_clear_g_source_inst(&script->watch_source);
     nm_clear_g_source_inst(&script->timeout_source);
-    script->request->num_scripts_done++;
-    if (!script->wait)
-        script->request->num_scripts_nowait--;
 
     if (WIFEXITED(status) && WEXITSTATUS(status) == 0) {
         script->result = DISPATCH_RESULT_SUCCESS;
     } else {
-        status_desc   = nm_utils_get_process_exit_status_desc(status);
+        status_desc = nm_utils_get_process_exit_status_desc(status);
+        nm_clear_g_free(&script->error);
         script->error = g_strdup_printf("Script '%s' %s", script->script, status_desc);
     }
 
@@ -445,8 +526,7 @@ script_watch_cb(GPid pid, int status, gpointer user_data)
         _LOG_S_W(script, "complete: process failed with %s", script->error);
     }
 
-    g_spawn_close_pid(script->pid);
-
+    script->pid = -1;
     complete_script(script);
 }
 
@@ -457,9 +537,8 @@ script_timeout_cb(gpointer user_data)
 
     nm_clear_g_source_inst(&script->timeout_source);
     nm_clear_g_source_inst(&script->watch_source);
-    script->request->num_scripts_done++;
-    if (!script->wait)
-        script->request->num_scripts_nowait--;
+    nm_clear_g_source_inst(&script->stdout_source);
+    nm_clear_fd(&script->stdout_fd);
 
     _LOG_S_W(script, "complete: timeout (kill script)");
 
@@ -473,8 +552,7 @@ again:
     script->error  = g_strdup_printf("Script '%s' timed out", script->script);
     script->result = DISPATCH_RESULT_TIMEOUT;
 
-    g_spawn_close_pid(script->pid);
-
+    script->pid = -1;
     complete_script(script);
 
     return G_SOURCE_CONTINUE;
@@ -537,12 +615,46 @@ check_filename(const char *file_name)
 
 #define SCRIPT_TIMEOUT 600 /* 10 minutes */
 
+static gboolean
+script_have_data(int fd, GIOCondition condition, gpointer user_data)
+{
+    ScriptInfo *script = user_data;
+    gssize      n_read;
+
+    n_read = nm_utils_fd_read(fd, &script->stdout_buffer);
+
+    if (n_read == -EAGAIN) {
+        return G_SOURCE_CONTINUE;
+    } else if (n_read > 0) {
+        if (script->stdout_buffer.len < 8 * 1024)
+            return G_SOURCE_CONTINUE;
+        /* Don't allow the buffer to grow indefinitely. */
+        _LOG_S_W(script, "complete: ignoring script stdout exceeding 8KiB");
+        nm_str_buf_set_size(&script->stdout_buffer, 8 * 1024, FALSE, FALSE);
+    } else if (n_read == 0) {
+        _LOG_S_T(script, "complete: stdout closed");
+    } else {
+        _LOG_S_T(script,
+                 "complete: reading stdout failed with %d (%s)",
+                 (int) n_read,
+                 nm_strerror_native((int) -n_read));
+    }
+
+    nm_clear_g_source_inst(&script->stdout_source);
+    nm_clear_fd(&script->stdout_fd);
+
+    complete_script(script);
+
+    return G_SOURCE_CONTINUE;
+}
+
 static gboolean
 script_dispatch(ScriptInfo *script)
 {
     gs_free_error GError *error = NULL;
     char                 *argv[4];
-    Request              *request = script->request;
+    Request              *request           = script->request;
+    gboolean              is_device_handler = script->request->is_device_handler;
 
     if (script->dispatched)
         return FALSE;
@@ -559,14 +671,17 @@ script_dispatch(ScriptInfo *script)
 
     _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)) {
+    if (!g_spawn_async_with_pipes("/",
+                                  argv,
+                                  request->envp,
+                                  G_SPAWN_CLOEXEC_PIPES | G_SPAWN_DO_NOT_REAP_CHILD,
+                                  NULL,
+                                  NULL,
+                                  &script->pid,
+                                  NULL,
+                                  is_device_handler ? &script->stdout_fd : NULL,
+                                  NULL,
+                                  &error)) {
         _LOG_S_W(script, "complete: failed to execute script: %s", error->message);
         script->result = DISPATCH_RESULT_EXEC_FAILED;
         script->error  = g_strdup(error->message);
@@ -579,6 +694,19 @@ script_dispatch(ScriptInfo *script)
         nm_g_timeout_add_seconds_source(SCRIPT_TIMEOUT, script_timeout_cb, script);
     if (!script->wait)
         request->num_scripts_nowait++;
+
+    if (is_device_handler) {
+        /* Watch process stdout */
+        nm_io_fcntl_setfl_update_nonblock(script->stdout_fd);
+        script->stdout_source = nm_g_unix_fd_source_new(script->stdout_fd,
+                                                        G_IO_IN | G_IO_ERR | G_IO_HUP,
+                                                        G_PRIORITY_DEFAULT,
+                                                        script_have_data,
+                                                        script,
+                                                        NULL);
+        g_source_attach(script->stdout_source, NULL);
+    }
+
     return TRUE;
 }
 
@@ -914,10 +1042,13 @@ _handle_action(GDBusMethodInvocation *invocation, GVariant *parameters, gboolean
         for (iter = sorted_scripts; iter; iter = g_slist_next(iter)) {
             ScriptInfo *s;
 
-            s          = g_slice_new0(ScriptInfo);
-            s->request = request;
-            s->script  = iter->data;
-            s->wait    = script_must_wait(s->script);
+            s                = g_slice_new0(ScriptInfo);
+            s->request       = request;
+            s->script        = iter->data;
+            s->wait          = script_must_wait(s->script);
+            s->stdout_fd     = -1;
+            s->pid           = -1;
+            s->stdout_buffer = NM_STR_BUF_INIT(0, FALSE);
             g_ptr_array_add(request->scripts, s);
         }
         g_slist_free(sorted_scripts);