device: refactor scheduling the activation source

Every activation-source handler first cleared the current
activation-source (activation_source_clear()) and later
returned FALSE/G_SOURCE_REMOVE.

Do not directly attach the handlers to g_idle_add().
Instead wrap the actual handler. This wrapper
  - always clears the activation source first
  - always returns G_SOURCE_REMOVE
  - does trace logging about invoking the handler

This also avoids a possibility for a bug where the handler returns
G_SOURCE_REMOVE, without also clearing activation_source_clear().

1 files changed, 149 insertions, 102 deletions

diff --git a/src/devices/nm-device.c b/src/devices/nm-device.c
index 5fd7bfff7d..0088e894d1 100644
--- a/src/devices/nm-device.c
+++ b/src/devices/nm-device.c
@@ -135,6 +135,13 @@ enum {
 #define PENDING_ACTION_DHCP6 "dhcp6"
 #define PENDING_ACTION_AUTOCONF6 "autoconf6"
 
+typedef void (*ActivationHandleFunc) (NMDevice *self);
+
+typedef struct {
+	ActivationHandleFunc func;
+	guint id;
+} ActivationHandleData;
+
 typedef enum {
 	CLEANUP_TYPE_DECONFIGURE,
 	CLEANUP_TYPE_KEEP,
@@ -228,13 +235,11 @@ typedef struct {
 	NMActRequest *  queued_act_request;
 	gboolean        queued_act_request_is_waiting_for_carrier;
 	NMActRequest *  act_request;
-	guint           act_source_id;
-	gpointer        act_source_func;
-	guint           act_source6_id;
-	gpointer        act_source6_func;
+	ActivationHandleData act_handle4; /* for layer2 and IPv4. */
+	ActivationHandleData act_handle6;
 	guint           recheck_assume_id;
 	struct {
-		guint       		call_id;
+		guint               call_id;
 		NMDeviceStateReason available_reason;
 		NMDeviceStateReason unavailable_reason;
 	}               recheck_available;
@@ -376,6 +381,9 @@ static void _carrier_wait_check_queued_act_request (NMDevice *self);
 
 static gboolean nm_device_get_default_unmanaged (NMDevice *self);
 
+static const char *_activation_func_to_string (ActivationHandleFunc func);
+static void activation_source_handle_cb (NMDevice *self, int family);
+
 static void _set_state_full (NMDevice *self,
                              NMDeviceState state,
                              NMDeviceStateReason reason,
@@ -2776,63 +2784,119 @@ dnsmasq_state_changed_cb (NMDnsMasqManager *manager, guint32 status, gpointer us
 	}
 }
 
-static void
-activation_source_clear (NMDevice *self, gboolean remove_source, int family)
+/*****************************************************************************/
+
+static gboolean
+activation_source_handle_cb4 (gpointer user_data)
+{
+	activation_source_handle_cb (user_data, AF_INET);
+	return G_SOURCE_REMOVE;
+}
+
+static gboolean
+activation_source_handle_cb6 (gpointer user_data)
+{
+	activation_source_handle_cb (user_data, AF_INET6);
+	return G_SOURCE_REMOVE;
+}
+
+static ActivationHandleData *
+activation_source_get_by_family (NMDevice *self,
+                                 int family,
+                                 GSourceFunc *out_idle_func)
 {
 	NMDevicePrivate *priv = NM_DEVICE_GET_PRIVATE (self);
-	guint *act_source_id;
-	gpointer *act_source_func;
 
 	if (family == AF_INET6) {
-		act_source_id = &priv->act_source6_id;
-		act_source_func = &priv->act_source6_func;
+		NM_SET_OUT (out_idle_func, activation_source_handle_cb6);
+		return &priv->act_handle6;
 	} else {
-		act_source_id = &priv->act_source_id;
-		act_source_func = &priv->act_source_func;
+		NM_SET_OUT (out_idle_func, activation_source_handle_cb4);
+		g_return_val_if_fail (family == AF_INET, &priv->act_handle4);
+		return &priv->act_handle4;
 	}
+}
+
+static void
+activation_source_clear (NMDevice *self, int family)
+{
+	ActivationHandleData *act_data;
+
+	act_data = activation_source_get_by_family (self, family, NULL);
 
-	if (*act_source_id) {
-		if (remove_source)
-			g_source_remove (*act_source_id);
-		*act_source_id = 0;
-		*act_source_func = NULL;
+	if (act_data->id) {
+		_LOGD (LOGD_DEVICE, "activation-stage: clear %s,%d (id %u)",
+		       _activation_func_to_string (act_data->func), family, act_data->id);
+		nm_clear_g_source (&act_data->id);
+		act_data->func = NULL;
 	}
 }
 
 static void
-activation_source_schedule (NMDevice *self, GSourceFunc func, int family)
+activation_source_handle_cb (NMDevice *self, int family)
 {
-	NMDevicePrivate *priv = NM_DEVICE_GET_PRIVATE (self);
-	guint *act_source_id;
-	gpointer *act_source_func;
+	ActivationHandleData *act_data, a;
 
-	if (family == AF_INET6) {
-		act_source_id = &priv->act_source6_id;
-		act_source_func = &priv->act_source6_func;
-	} else {
-		act_source_id = &priv->act_source_id;
-		act_source_func = &priv->act_source_func;
+	g_return_if_fail (NM_IS_DEVICE (self));
+
+	act_data = activation_source_get_by_family (self, family, NULL);
+
+	g_return_if_fail (act_data->id);
+	g_return_if_fail (act_data->func);
+
+	a = *act_data;
+
+	act_data->func = NULL;
+	act_data->id = 0;
+
+	_LOGD (LOGD_DEVICE, "activation-stage: invoke %s,%d (id %u)",
+	       _activation_func_to_string (a.func), family, a.id);
+
+	a.func (self);
+
+	_LOGD (LOGD_DEVICE, "activation-stage: complete %s,%d (id %u)",
+	       _activation_func_to_string (a.func), family, a.id);
+}
+
+static void
+activation_source_schedule (NMDevice *self, ActivationHandleFunc func, int family)
+{
+	ActivationHandleData *act_data;
+	GSourceFunc source_func;
+	guint new_id = 0;
+
+	act_data = activation_source_get_by_family (self, family, &source_func);
+
+	if (act_data->id && act_data->func != func) {
+		/* Don't bother rescheduling the same function that's about to
+		 * run anyway.  Fixes issues with crappy wireless drivers sending
+		 * streams of associate events before NM has had a chance to process
+		 * the first one.
+		 */
+		_LOGD (LOGD_DEVICE, "activation-stage: already scheduled %s,%d (id %u)",
+		       _activation_func_to_string (func), family, act_data->id);
+		return;
 	}
 
-	if (*act_source_id) {
-		if (*act_source_func == func) {
-			/* Don't bother rescheduling the same function that's about to
-			 * run anyway.  Fixes issues with crappy wireless drivers sending
-			 * streams of associate events before NM has had a chance to process
-			 * the first one.
-			 */
-			_LOGD (LOGD_DEVICE, "activation stage already scheduled");
-			return;
-		} else {
-			_LOGW (LOGD_DEVICE, "a different activation stage already scheduled");
-			activation_source_clear (self, TRUE, family);
-		}
+	new_id = g_idle_add (source_func, self);
+
+	if (act_data->id) {
+		_LOGW (LOGD_DEVICE, "activation-stage: schedule %s,%d which replaces %s,%d (id %u -> %u)",
+		       _activation_func_to_string (func), family,
+		       _activation_func_to_string (act_data->func), family,
+		       act_data->id, new_id);
+		nm_clear_g_source (&act_data->id);
+	} else {
+		_LOGD (LOGD_DEVICE, "activation-stage: schedule %s,%d (id %u)",
+		       _activation_func_to_string (func), family, new_id);
 	}
 
-	*act_source_id = g_idle_add (func, self);
-	*act_source_func = func;
+	act_data->func = func;
+	act_data->id = new_id;
 }
 
+/*****************************************************************************/
+
 static gboolean
 get_ip_config_may_fail (NMDevice *self, int family)
 {
@@ -2907,18 +2971,14 @@ act_stage1_prepare (NMDevice *self, NMDeviceStateReason *reason)
  * Prepare for device activation
  *
  */
-static gboolean
-nm_device_activate_stage1_device_prepare (gpointer user_data)
+static void
+nm_device_activate_stage1_device_prepare (NMDevice *self)
 {
-	NMDevice *self = NM_DEVICE (user_data);
 	NMDevicePrivate *priv = NM_DEVICE_GET_PRIVATE (self);
 	NMActStageReturn ret = NM_ACT_STAGE_RETURN_SUCCESS;
 	NMDeviceStateReason reason = NM_DEVICE_STATE_REASON_NONE;
 	NMActiveConnection *active = NM_ACTIVE_CONNECTION (priv->act_request);
 
-	/* Clear the activation source ID now that this stage has run */
-	activation_source_clear (self, FALSE, 0);
-
 	priv->ip4_state = priv->ip6_state = IP_NONE;
 
 	/* Notify the new ActiveConnection along with the state change */
@@ -2943,7 +3003,6 @@ nm_device_activate_stage1_device_prepare (gpointer user_data)
 
 out:
 	_LOGD (LOGD_DEVICE, "Activation: Stage 1 of 5 (Device Prepare) complete.");
-	return FALSE;
 }
 
 
@@ -2963,7 +3022,7 @@ nm_device_activate_schedule_stage1_device_prepare (NMDevice *self)
 	priv = NM_DEVICE_GET_PRIVATE (self);
 	g_return_if_fail (priv->act_request);
 
-	activation_source_schedule (self, nm_device_activate_stage1_device_prepare, 0);
+	activation_source_schedule (self, nm_device_activate_stage1_device_prepare, AF_INET);
 
 	_LOGD (LOGD_DEVICE, "Activation: Stage 1 of 5 (Device Prepare) scheduled...");
 }
@@ -2982,10 +3041,9 @@ act_stage2_config (NMDevice *self, NMDeviceStateReason *reason)
  * for wireless devices, set SSID, keys, etc.
  *
  */
-static gboolean
-nm_device_activate_stage2_device_config (gpointer user_data)
+static void
+nm_device_activate_stage2_device_config (NMDevice *self)
 {
-	NMDevice *self = NM_DEVICE (user_data);
 	NMDevicePrivate *priv = NM_DEVICE_GET_PRIVATE (self);
 	NMActStageReturn ret;
 	NMDeviceStateReason reason = NM_DEVICE_STATE_REASON_NONE;
@@ -2993,9 +3051,6 @@ nm_device_activate_stage2_device_config (gpointer user_data)
 	NMActiveConnection *active = NM_ACTIVE_CONNECTION (priv->act_request);
 	GSList *iter;
 
-	/* Clear the activation source ID now that this stage has run */
-	activation_source_clear (self, FALSE, 0);
-
 	_LOGD (LOGD_DEVICE, "Activation: Stage 2 of 5 (Device Configure) starting...");
 	nm_device_state_changed (self, NM_DEVICE_STATE_CONFIG, NM_DEVICE_STATE_REASON_NONE);
 
@@ -3037,7 +3092,6 @@ nm_device_activate_stage2_device_config (gpointer user_data)
 
 out:
 	_LOGD (LOGD_DEVICE, "Activation: Stage 2 of 5 (Device Configure) complete.");
-	return FALSE;
 }
 
 
@@ -3082,7 +3136,7 @@ nm_device_activate_schedule_stage2_device_config (NMDevice *self)
 		}
 	}
 
-	activation_source_schedule (self, nm_device_activate_stage2_device_config, 0);
+	activation_source_schedule (self, nm_device_activate_stage2_device_config, AF_INET);
 
 	_LOGD (LOGD_DEVICE, "Activation: Stage 2 of 5 (Device Configure) scheduled...");
 }
@@ -5496,17 +5550,13 @@ nm_device_activate_stage3_ip6_start (NMDevice *self)
  * Begin automatic/manual IP configuration
  *
  */
-static gboolean
-nm_device_activate_stage3_ip_config_start (gpointer user_data)
+static void
+nm_device_activate_stage3_ip_config_start (NMDevice *self)
 {
-	NMDevice *self = NM_DEVICE (user_data);
 	NMDevicePrivate *priv = NM_DEVICE_GET_PRIVATE (self);
 	NMActiveConnection *master;
 	NMDevice *master_device;
 
-	/* Clear the activation source ID now that this stage has run */
-	activation_source_clear (self, FALSE, 0);
-
 	priv->ip4_state = priv->ip6_state = IP_WAIT;
 
 	_LOGD (LOGD_DEVICE, "Activation: Stage 3 of 5 (IP Configure Start) started...");
@@ -5548,7 +5598,6 @@ nm_device_activate_stage3_ip_config_start (gpointer user_data)
 
 out:
 	_LOGD (LOGD_DEVICE, "Activation: Stage 3 of 5 (IP Configure Start) complete.");
-	return FALSE;
 }
 
 
@@ -5578,7 +5627,7 @@ fw_change_zone_cb (NMFirewallManager *firewall_manager,
 	if (priv->state == NM_DEVICE_STATE_IP_CHECK)
 		nm_device_start_ip_check (self);
 	else {
-		activation_source_schedule (self, nm_device_activate_stage3_ip_config_start, 0);
+		activation_source_schedule (self, nm_device_activate_stage3_ip_config_start, AF_INET);
 		_LOGD (LOGD_DEVICE, "Activation: Stage 3 of 5 (IP Configure Start) scheduled.");
 	}
 }
@@ -5612,7 +5661,7 @@ nm_device_activate_schedule_stage3_ip_config_start (NMDevice *self)
 
 	if (nm_device_uses_assumed_connection (self)) {
 		_LOGD (LOGD_DEVICE, "Activation: skip setting firewall zone '%s' for assumed device", zone ? zone : "default");
-		activation_source_schedule (self, nm_device_activate_stage3_ip_config_start, 0);
+		activation_source_schedule (self, nm_device_activate_stage3_ip_config_start, AF_INET);
 		_LOGD (LOGD_DEVICE, "Activation: Stage 3 of 5 (IP Configure Start) scheduled.");
 		return;
 	}
@@ -5643,17 +5692,13 @@ act_stage4_ip4_config_timeout (NMDevice *self, NMDeviceStateReason *reason)
  * Time out on retrieving the IPv4 config.
  *
  */
-static gboolean
-nm_device_activate_ip4_config_timeout (gpointer user_data)
+static void
+nm_device_activate_ip4_config_timeout (NMDevice *self)
 {
-	NMDevice *self = NM_DEVICE (user_data);
 	NMDevicePrivate *priv = NM_DEVICE_GET_PRIVATE (self);
 	NMActStageReturn ret = NM_ACT_STAGE_RETURN_FAILURE;
 	NMDeviceStateReason reason = NM_DEVICE_STATE_REASON_NONE;
 
-	/* Clear the activation source ID now that this stage has run */
-	activation_source_clear (self, FALSE, AF_INET);
-
 	_LOGD (LOGD_DEVICE | LOGD_IP4, "Activation: Stage 4 of 5 (IPv4 Configure Timeout) started...");
 
 	ret = NM_DEVICE_GET_CLASS (self)->act_stage4_ip4_config_timeout (self, &reason);
@@ -5671,7 +5716,6 @@ nm_device_activate_ip4_config_timeout (gpointer user_data)
 
 out:
 	_LOGD (LOGD_DEVICE | LOGD_IP4, "Activation: Stage 4 of 5 (IPv4 Configure Timeout) complete.");
-	return FALSE;
 }
 
 
@@ -5715,17 +5759,13 @@ act_stage4_ip6_config_timeout (NMDevice *self, NMDeviceStateReason *reason)
  * Time out on retrieving the IPv6 config.
  *
  */
-static gboolean
-nm_device_activate_ip6_config_timeout (gpointer user_data)
+static void
+nm_device_activate_ip6_config_timeout (NMDevice *self)
 {
-	NMDevice *self = NM_DEVICE (user_data);
 	NMDevicePrivate *priv = NM_DEVICE_GET_PRIVATE (self);
 	NMActStageReturn ret = NM_ACT_STAGE_RETURN_FAILURE;
 	NMDeviceStateReason reason = NM_DEVICE_STATE_REASON_NONE;
 
-	/* Clear the activation source ID now that this stage has run */
-	activation_source_clear (self, FALSE, AF_INET6);
-
 	_LOGD (LOGD_DEVICE | LOGD_IP6, "Activation: Stage 4 of 5 (IPv6 Configure Timeout) started...");
 
 	ret = NM_DEVICE_GET_CLASS (self)->act_stage4_ip6_config_timeout (self, &reason);
@@ -5743,7 +5783,6 @@ nm_device_activate_ip6_config_timeout (gpointer user_data)
 
 out:
 	_LOGD (LOGD_DEVICE | LOGD_IP6, "Activation: Stage 4 of 5 (IPv6 Configure Timeout) complete.");
-	return FALSE;
 }
 
 
@@ -5971,10 +6010,9 @@ arp_announce (NMDevice *self)
 	priv->arp_round2_id = g_timeout_add_seconds (2, arp_announce_round2, self);
 }
 
-static gboolean
-nm_device_activate_ip4_config_commit (gpointer user_data)
+static void
+nm_device_activate_ip4_config_commit (NMDevice *self)
 {
-	NMDevice *self = NM_DEVICE (user_data);
 	NMDevicePrivate *priv = NM_DEVICE_GET_PRIVATE (self);
 	NMActRequest *req;
 	const char *method;
@@ -5982,9 +6020,6 @@ nm_device_activate_ip4_config_commit (gpointer user_data)
 	NMDeviceStateReason reason = NM_DEVICE_STATE_REASON_NONE;
 	int ip_ifindex;
 
-	/* Clear the activation source ID now that this stage has run */
-	activation_source_clear (self, FALSE, AF_INET);
-
 	_LOGD (LOGD_DEVICE, "Activation: Stage 5 of 5 (IPv4 Commit) started...");
 
 	req = nm_device_get_act_request (self);
@@ -6046,8 +6081,6 @@ nm_device_activate_ip4_config_commit (gpointer user_data)
 
 out:
 	_LOGD (LOGD_DEVICE, "Activation: Stage 5 of 5 (IPv4 Commit) complete.");
-
-	return FALSE;
 }
 
 static void
@@ -6099,19 +6132,15 @@ nm_device_activate_ip4_state_in_wait (NMDevice *self)
 	return NM_DEVICE_GET_PRIVATE (self)->ip4_state == IP_WAIT;
 }
 
-static gboolean
-nm_device_activate_ip6_config_commit (gpointer user_data)
+static void
+nm_device_activate_ip6_config_commit (NMDevice *self)
 {
-	NMDevice *self = NM_DEVICE (user_data);
 	NMDevicePrivate *priv = NM_DEVICE_GET_PRIVATE (self);
 	NMActRequest *req;
 	NMConnection *connection;
 	NMDeviceStateReason reason = NM_DEVICE_STATE_REASON_NONE;
 	int ip_ifindex;
 
-	/* Clear the activation source ID now that this stage has run */
-	activation_source_clear (self, FALSE, AF_INET6);
-
 	_LOGD (LOGD_DEVICE, "Activation: Stage 5 of 5 (IPv6 Commit) started...");
 
 	req = nm_device_get_act_request (self);
@@ -6158,8 +6187,6 @@ nm_device_activate_ip6_config_commit (gpointer user_data)
 	}
 
 	_LOGD (LOGD_DEVICE, "Activation: Stage 5 of 5 (IPv6 Commit) complete.");
-
-	return FALSE;
 }
 
 void
@@ -6629,7 +6656,7 @@ nm_device_is_activating (NMDevice *self)
 	 * handler is actually run.  If there's an activation handler scheduled
 	 * we're activating anyway.
 	 */
-	return priv->act_source_id ? TRUE : FALSE;
+	return priv->act_handle4.id ? TRUE : FALSE;
 }
 
 /* IP Configuration stuff */
@@ -8386,8 +8413,8 @@ _cancel_activation (NMDevice *self)
 	ip_check_gw_ping_cleanup (self);
 
 	/* Break the activation chain */
-	activation_source_clear (self, TRUE, AF_INET);
-	activation_source_clear (self, TRUE, AF_INET6);
+	activation_source_clear (self, AF_INET);
+	activation_source_clear (self, AF_INET6);
 }
 
 static void
@@ -8819,7 +8846,7 @@ _set_state_full (NMDevice *self,
 	 */
 	if (   (priv->state == state)
 	    && !(state == NM_DEVICE_STATE_UNAVAILABLE && priv->firmware_missing)) {
-		_LOGt (LOGD_DEVICE, "device state change: %s -> %s (reason '%s') [%d %d %d] (skip due to missing firmware)",
+		_LOGD (LOGD_DEVICE, "device state change: %s -> %s (reason '%s') [%d %d %d] (skip due to missing firmware)",
 		       state_to_string (old_state),
 		       state_to_string (state),
 		       reason_to_string (reason),
@@ -9399,6 +9426,26 @@ spec_match_list (NMDevice *self, const GSList *specs)
 
 /***********************************************************/
 
+static const char *
+_activation_func_to_string (ActivationHandleFunc func)
+{
+#define FUNC_TO_STRING_CHECK_AND_RETURN(func, f) \
+	G_STMT_START { \
+		if ((func) == (f)) \
+			return #f; \
+	} G_STMT_END
+	FUNC_TO_STRING_CHECK_AND_RETURN (func, nm_device_activate_stage1_device_prepare);
+	FUNC_TO_STRING_CHECK_AND_RETURN (func, nm_device_activate_stage2_device_config);
+	FUNC_TO_STRING_CHECK_AND_RETURN (func, nm_device_activate_stage3_ip_config_start);
+	FUNC_TO_STRING_CHECK_AND_RETURN (func, nm_device_activate_ip4_config_timeout);
+	FUNC_TO_STRING_CHECK_AND_RETURN (func, nm_device_activate_ip6_config_timeout);
+	FUNC_TO_STRING_CHECK_AND_RETURN (func, nm_device_activate_ip4_config_commit);
+	FUNC_TO_STRING_CHECK_AND_RETURN (func, nm_device_activate_ip6_config_commit);
+	g_return_val_if_reached ("unknown");
+}
+
+/***********************************************************/
+
 #define DEFAULT_AUTOCONNECT TRUE
 
 static void