diff --git a/callouts/nm-dispatcher-action.c b/callouts/nm-dispatcher-action.c index 1a8c99fc0..23ae11077 100644 --- a/callouts/nm-dispatcher-action.c +++ b/callouts/nm-dispatcher-action.c @@ -83,6 +83,7 @@ impl_dispatch (Handler *h, const char *vpn_ip_iface, GHashTable *vpn_ip4_props, GHashTable *vpn_ip6_props, + gboolean request_debug, DBusGMethodInvocation *context); #include "nm-dispatcher-glue.h" @@ -116,6 +117,8 @@ struct Request { char *action; char *iface; char **envp; + gboolean debug; + GPtrArray *scripts; /* list of ScriptInfo */ guint idx; @@ -170,6 +173,11 @@ quit_timeout_reschedule (Handler *h) static void start_request (Request *request) { + if (request->iface) + g_message ("Dispatching action '%s' for %s", request->action, request->iface); + else + g_message ("Dispatching action '%s'", request->action); + request->handler->current_request = request; dispatch_one_script (request); } @@ -234,6 +242,13 @@ next_script (gpointer user_data) dbus_g_method_return (request->context, results); g_ptr_array_unref (results); + + if (request->debug) { + if (request->iface) + g_message ("Dispatch '%s' on %s complete", request->action, request->iface); + else + g_message ("Dispatch '%s' complete", request->action); + } request_free (request); next_request (h); @@ -271,7 +286,10 @@ script_watch_cb (GPid pid, gint status, gpointer user_data) script->script); } - if (script->result != DISPATCH_RESULT_SUCCESS) { + if (script->result == DISPATCH_RESULT_SUCCESS) { + if (script->request->debug) + g_message ("Script '%s' complete", script->script); + } else { script->result = DISPATCH_RESULT_FAILED; g_warning ("%s", script->error); } @@ -379,8 +397,8 @@ dispatch_one_script (Request *request) argv[2] = request->action; argv[3] = NULL; - if (debug) - g_message ("Script: %s %s %s", script->script, request->iface ? request->iface : "(none)", request->action); + if (request->debug) + g_message ("Running script '%s'", script->script); if (g_spawn_async ("/", argv, request->envp, G_SPAWN_DO_NOT_REAP_CHILD, child_setup, request, &script->pid, &error)) { request->script_watch_id = g_child_watch_add (script->pid, (GChildWatchFunc) script_watch_cb, script); @@ -451,6 +469,7 @@ impl_dispatch (Handler *h, const char *vpn_ip_iface, GHashTable *vpn_ip4_props, GHashTable *vpn_ip6_props, + gboolean request_debug, DBusGMethodInvocation *context) { GSList *sorted_scripts = NULL; @@ -470,6 +489,7 @@ impl_dispatch (Handler *h, request = g_malloc0 (sizeof (*request)); request->handler = h; + request->debug = request_debug || debug; request->context = context; request->action = g_strdup (str_action); @@ -486,7 +506,7 @@ impl_dispatch (Handler *h, vpn_ip6_props, &iface); - if (debug) { + if (request->debug) { g_message ("------------ Action ID %p '%s' Interface %s Environment ------------", context, str_action, iface ? iface : "(none)"); for (p = request->envp; *p; p++) diff --git a/callouts/nm-dispatcher.xml b/callouts/nm-dispatcher.xml index cba61508d..1ae138b35 100644 --- a/callouts/nm-dispatcher.xml +++ b/callouts/nm-dispatcher.xml @@ -75,6 +75,12 @@ + + + Whether to log debug output. + + + Results of dispatching operations. Each element of the returned diff --git a/src/logging/nm-logging.c b/src/logging/nm-logging.c index 5ac267167..a7cd19101 100644 --- a/src/logging/nm-logging.c +++ b/src/logging/nm-logging.c @@ -50,7 +50,7 @@ nm_log_handler (const gchar *log_domain, LOGD_CORE | LOGD_DEVICE | LOGD_OLPC_MESH | LOGD_WIMAX | \ LOGD_INFINIBAND | LOGD_FIREWALL | LOGD_ADSL | LOGD_BOND | \ LOGD_VLAN | LOGD_BRIDGE | LOGD_DBUS_PROPS | LOGD_TEAM | LOGD_CONCHECK | \ - LOGD_DCB) + LOGD_DCB | LOGD_DISPATCH) #define LOGD_DEFAULT (LOGD_ALL & ~(LOGD_WIFI_SCAN | LOGD_DBUS_PROPS)) @@ -108,6 +108,7 @@ static const LogDesc domain_descs[] = { { LOGD_TEAM, "TEAM" }, { LOGD_CONCHECK, "CONCHECK" }, { LOGD_DCB, "DCB" }, + { LOGD_DISPATCH, "DISPATCH" }, { 0, NULL } }; diff --git a/src/logging/nm-logging.h b/src/logging/nm-logging.h index d9e483c74..8287ab9b9 100644 --- a/src/logging/nm-logging.h +++ b/src/logging/nm-logging.h @@ -62,6 +62,7 @@ enum { LOGD_TEAM = (1LL << 32), LOGD_CONCHECK = (1LL << 33), LOGD_DCB = (1LL << 34), /* Data Center Bridging */ + LOGD_DISPATCH = (1LL << 35), }; #define LOGD_DHCP (LOGD_DHCP4 | LOGD_DHCP6) diff --git a/src/nm-dispatcher.c b/src/nm-dispatcher.c index a8fee1f3f..63773862c 100644 --- a/src/nm-dispatcher.c +++ b/src/nm-dispatcher.c @@ -179,16 +179,16 @@ dispatcher_done_cb (DBusGProxy *proxy, DBusGProxyCall *call, gpointer user_data) DispatchResult result; if (item->n_values != 3) { - nm_log_dbg (LOGD_CORE, "Unexpected number of items in " - "dispatcher result (got %d, expectd 3)", - item->n_values); + nm_log_dbg (LOGD_DISPATCH, "Unexpected number of items in " + "dispatcher result (got %d, expectd 3)", + item->n_values); goto next; } /* Script */ tmp = g_value_array_get_nth (item, 0); if (G_VALUE_TYPE (tmp) != G_TYPE_STRING) { - nm_log_dbg (LOGD_CORE, "Dispatcher result %d element 0 invalid type %s", + nm_log_dbg (LOGD_DISPATCH, "Dispatcher result %d element 0 invalid type %s", i, G_VALUE_TYPE_NAME (tmp)); goto next; } @@ -197,7 +197,7 @@ dispatcher_done_cb (DBusGProxy *proxy, DBusGProxyCall *call, gpointer user_data) /* Result */ tmp = g_value_array_get_nth (item, 1); if (G_VALUE_TYPE (tmp) != G_TYPE_UINT) { - nm_log_dbg (LOGD_CORE, "Dispatcher result %d element 1 invalid type %s", + nm_log_dbg (LOGD_DISPATCH, "Dispatcher result %d element 1 invalid type %s", i, G_VALUE_TYPE_NAME (tmp)); goto next; } @@ -206,14 +206,14 @@ dispatcher_done_cb (DBusGProxy *proxy, DBusGProxyCall *call, gpointer user_data) /* Error */ tmp = g_value_array_get_nth (item, 2); if (G_VALUE_TYPE (tmp) != G_TYPE_STRING) { - nm_log_dbg (LOGD_CORE, "Dispatcher result %d element 2 invalid type %s", + nm_log_dbg (LOGD_DISPATCH, "Dispatcher result %d element 2 invalid type %s", i, G_VALUE_TYPE_NAME (tmp)); goto next; } err = g_value_get_string (tmp); if (result != DISPATCH_RESULT_SUCCESS) { - nm_log_warn (LOGD_CORE, "Dispatcher script \"%s\" failed with %s: %s", + nm_log_warn (LOGD_DISPATCH, "Dispatcher script \"%s\" failed with %s: %s", script, dispatch_result_to_string (result), err); } @@ -223,7 +223,7 @@ next: g_ptr_array_free (results, TRUE); } else { g_assert (error); - nm_log_warn (LOGD_CORE, "Dispatcher failed: (%d) %s", error->code, error->message); + nm_log_warn (LOGD_DISPATCH, "Dispatcher failed: (%d) %s", error->code, error->message); } if (info->callback) @@ -285,8 +285,16 @@ _dispatcher_call (DispatcherAction action, DispatchInfo *info; /* All actions except 'hostname' require a device */ - if (action != DISPATCHER_ACTION_HOSTNAME) + if (action == DISPATCHER_ACTION_HOSTNAME) { + nm_log_dbg (LOGD_DISPATCH, "dispatching action '%s'", + action_to_string (action)); + } else { g_return_val_if_fail (NM_IS_DEVICE (device), NULL); + + nm_log_dbg (LOGD_DISPATCH, "(%s) dispatching action '%s'", + nm_device_get_iface (device), action_to_string (action)); + } + /* VPN actions require at least an IPv4 config (for now) */ if (action == DISPATCHER_ACTION_VPN_UP) g_return_val_if_fail (vpn_ip4_config != NULL, NULL); @@ -297,7 +305,7 @@ _dispatcher_call (DispatcherAction action, NM_DISPATCHER_DBUS_PATH, NM_DISPATCHER_DBUS_IFACE); if (!proxy) { - nm_log_err (LOGD_CORE, "could not get dispatcher proxy!"); + nm_log_err (LOGD_DISPATCH, "could not get dispatcher proxy!"); return NULL; } @@ -354,6 +362,7 @@ _dispatcher_call (DispatcherAction action, G_TYPE_STRING, vpn_iface ? vpn_iface : "", DBUS_TYPE_G_MAP_OF_VARIANT, vpn_ip4_props, DBUS_TYPE_G_MAP_OF_VARIANT, vpn_ip6_props, + G_TYPE_BOOLEAN, nm_logging_enabled (LOGL_DEBUG, LOGD_DISPATCH), G_TYPE_INVALID); g_hash_table_destroy (connection_hash); g_hash_table_destroy (connection_props);