From b2cec90b7956caf9b0a8577d694434d1e32e6a7c Mon Sep 17 00:00:00 2001 From: Dan Williams Date: Mon, 9 Dec 2013 12:55:04 -0600 Subject: [PATCH 1/3] core: convert pending actions from a counter to a GArray This lets us do two things: 1) ensure that pending actions are unique and not doubly added/removed 2) we can (eventually) print out the pending action list for debugging However, since we cannot have two pending actions with the same name at the same time, we need to change the queued device state actions to include the state name. But that makes debugging even more descriptive so it's a bonus. --- src/devices/nm-device.c | 124 +++++++++++++++++++++++++++++++--------- 1 file changed, 96 insertions(+), 28 deletions(-) diff --git a/src/devices/nm-device.c b/src/devices/nm-device.c index 578ccb0892..096eed7daf 100644 --- a/src/devices/nm-device.c +++ b/src/devices/nm-device.c @@ -188,7 +188,7 @@ typedef struct { NMDeviceStateReason state_reason; QueuedState queued_state; guint queued_ip_config_id; - guint pending_actions; + GArray *pending_actions; char * udi; char * path; @@ -394,6 +394,7 @@ nm_device_init (NMDevice *self) priv->rfkill_type = RFKILL_TYPE_UNKNOWN; priv->autoconnect = DEFAULT_AUTOCONNECT; priv->available_connections = g_hash_table_new_full (g_direct_hash, g_direct_equal, g_object_unref, NULL); + priv->pending_actions = g_array_sized_new (FALSE, TRUE, sizeof (GQuark), 4); } static void @@ -5335,6 +5336,8 @@ finalize (GObject *object) if (priv->fw_manager) g_object_unref (priv->fw_manager); + g_array_free (priv->pending_actions, TRUE); + g_free (priv->udi); g_free (priv->path); g_free (priv->iface); @@ -5935,38 +5938,46 @@ nm_device_get_firmware_missing (NMDevice *self) return NM_DEVICE_GET_PRIVATE (self)->firmware_missing; } +#define QUEUED_PREFIX "queued state change to " + static const char * -state_to_string (NMDeviceState state) +queued_state_to_string (NMDeviceState state) { switch (state) { case NM_DEVICE_STATE_UNMANAGED: - return "unmanaged"; + return QUEUED_PREFIX "unmanaged"; case NM_DEVICE_STATE_UNAVAILABLE: - return "unavailable"; + return QUEUED_PREFIX "unavailable"; case NM_DEVICE_STATE_DISCONNECTED: - return "disconnected"; + return QUEUED_PREFIX "disconnected"; case NM_DEVICE_STATE_PREPARE: - return "prepare"; + return QUEUED_PREFIX "prepare"; case NM_DEVICE_STATE_CONFIG: - return "config"; + return QUEUED_PREFIX "config"; case NM_DEVICE_STATE_NEED_AUTH: - return "need-auth"; + return QUEUED_PREFIX "need-auth"; case NM_DEVICE_STATE_IP_CONFIG: - return "ip-config"; + return QUEUED_PREFIX "ip-config"; case NM_DEVICE_STATE_IP_CHECK: - return "ip-check"; + return QUEUED_PREFIX "ip-check"; case NM_DEVICE_STATE_SECONDARIES: - return "secondaries"; + return QUEUED_PREFIX "secondaries"; case NM_DEVICE_STATE_ACTIVATED: - return "activated"; + return QUEUED_PREFIX "activated"; case NM_DEVICE_STATE_DEACTIVATING: - return "deactivating"; + return QUEUED_PREFIX "deactivating"; case NM_DEVICE_STATE_FAILED: - return "failed"; + return QUEUED_PREFIX "failed"; default: break; } - return "unknown"; + return QUEUED_PREFIX "unknown"; +} + +static const char * +state_to_string (NMDeviceState state) +{ + return queued_state_to_string (state) + strlen (QUEUED_PREFIX); } static const char * @@ -6334,7 +6345,7 @@ queued_set_state (gpointer user_data) nm_device_queued_state_clear (self); nm_device_state_changed (self, new_state, new_reason); - nm_device_remove_pending_action (self, "queued state change"); + nm_device_remove_pending_action (self, queued_state_to_string (new_state)); } else { g_warn_if_fail (priv->queued_state.state == NM_DEVICE_STATE_UNKNOWN); g_warn_if_fail (priv->queued_state.reason == NM_DEVICE_STATE_REASON_NONE); @@ -6353,6 +6364,12 @@ nm_device_queue_state (NMDevice *self, priv = NM_DEVICE_GET_PRIVATE (self); + /* "lock" the pending actions so that if there was a previously + * queued action that's about to be cleared, that doesn't drop + * the pending actions to 0 before we add the new pending action. + */ + nm_device_add_pending_action (self, "queued state lock"); + /* We should only ever have one delayed state transition at a time */ if (priv->queued_state.id) { if (priv->queued_state.state == state) @@ -6367,7 +6384,9 @@ nm_device_queue_state (NMDevice *self, priv->queued_state.state = state; priv->queued_state.reason = reason; priv->queued_state.id = g_idle_add (queued_set_state, self); - nm_device_add_pending_action (self, "queued state change"); + nm_device_add_pending_action (self, queued_state_to_string (state)); + + nm_device_remove_pending_action (self, "queued state lock"); nm_log_dbg (LOGD_DEVICE, "(%s): queued state change to %s due to %s (id %d)", nm_device_get_iface (self), state_to_string (state), reason_to_string (reason), @@ -6395,7 +6414,7 @@ nm_device_queued_state_clear (NMDevice *self) nm_log_dbg (LOGD_DEVICE, "(%s): clearing queued state transition (id %d)", nm_device_get_iface (self), priv->queued_state.id); g_source_remove (priv->queued_state.id); - nm_device_remove_pending_action (self, "queued state change"); + nm_device_remove_pending_action (self, queued_state_to_string (priv->queued_state.state)); } memset (&priv->queued_state, 0, sizeof (priv->queued_state)); } @@ -7106,30 +7125,79 @@ nm_device_set_hw_addr (NMDevice *device, const guint8 *addr, return success; } +/** + * nm_device_add_pending_action(): + * @device: the #NMDevice to add the pending action to + * @action: a static string that identifies the action + * + * Adds a pending action to the device. + */ void nm_device_add_pending_action (NMDevice *device, const char *action) { NMDevicePrivate *priv = NM_DEVICE_GET_PRIVATE (device); + GQuark qaction; + guint i; - priv->pending_actions++; - nm_log_dbg (LOGD_DEVICE, "(%s): add_pending_action (%d): %s", - nm_device_get_iface (device), priv->pending_actions, action); + qaction = g_quark_from_static_string (action); - if (priv->pending_actions == 1) + /* Shouldn't ever add the same pending action twice */ + for (i = 0; i < priv->pending_actions->len; i++) { + if (qaction == g_array_index (priv->pending_actions, GQuark, i)) { + nm_log_warn (LOGD_DEVICE, "(%s): add_pending_action (%d): '%s' already added", + nm_device_get_iface (device), + priv->pending_actions->len, + action); + g_warn_if_reached (); + return; + } + } + + g_array_append_val (priv->pending_actions, qaction); + nm_log_dbg (LOGD_DEVICE, "(%s): add_pending_action (%d): '%s'", + nm_device_get_iface (device), + priv->pending_actions->len, + action); + + if (priv->pending_actions->len == 1) g_object_notify (G_OBJECT (device), NM_DEVICE_HAS_PENDING_ACTION); } +/** + * nm_device_remove_pending_action(): + * @device: the #NMDevice to remove the pending action from + * @action: a static string that identifies the action + * + * Removes a pending action previously added by nm_device_add_pending_action(). + */ void nm_device_remove_pending_action (NMDevice *device, const char *action) { NMDevicePrivate *priv = NM_DEVICE_GET_PRIVATE (device); + GQuark qaction; + guint i; - priv->pending_actions--; - nm_log_dbg (LOGD_DEVICE, "(%s): remove_pending_action (%d): %s", - nm_device_get_iface (device), priv->pending_actions, action); + qaction = g_quark_from_static_string (action); - if (priv->pending_actions == 0) - g_object_notify (G_OBJECT (device), NM_DEVICE_HAS_PENDING_ACTION); + /* Shouldn't ever add the same pending action twice */ + for (i = 0; i < priv->pending_actions->len; i++) { + if (qaction == g_array_index (priv->pending_actions, GQuark, i)) { + g_array_remove_index (priv->pending_actions, i); + nm_log_dbg (LOGD_DEVICE, "(%s): remove_pending_action (%d): '%s'", + nm_device_get_iface (device), + priv->pending_actions->len, + action); + + if (priv->pending_actions->len == 0) + g_object_notify (G_OBJECT (device), NM_DEVICE_HAS_PENDING_ACTION); + return; + } + } + + nm_log_warn (LOGD_DEVICE, "(%s): remove_pending_action (%d): '%s' never added", + nm_device_get_iface (device), + priv->pending_actions->len, + action); } gboolean @@ -7137,7 +7205,7 @@ nm_device_has_pending_action (NMDevice *device) { NMDevicePrivate *priv = NM_DEVICE_GET_PRIVATE (device); - return priv->pending_actions > 0; + return priv->pending_actions->len > 0; } const char * From 61463ed2ab6ce61f8640bb4f871697a29f3a0639 Mon Sep 17 00:00:00 2001 From: Dan Williams Date: Mon, 9 Dec 2013 16:32:36 -0600 Subject: [PATCH 2/3] core: delay startup complete until carrier is found or timeout (rh #1034921) (rh #1030583) Carrier state is only valid if the network interface is IFF_UP, because drivers are not required to do carrier detection if the device is not up. Thus, if NM is the first process to set the interface IFF_UP, there may be a short delay while the driver performs carrier detection. NetworkManager must suppress "startup complete" during this delay to ensure that the carrier state is known before making startup property decisions. Previously, when NetworkManager set the interface IFF_UP, the interface would not have a carrier for a few seconds until the driver's carrier detection was done. Since the interface had no carrier, NetworkManager could not begin connection activation on the interface, and the interface would not suppress the "startup complete" transition. Thus, NetworkManager would declare that startup was complete prematurely and anything depending on startup network connectivity would fail as no interfaces were active. https://bugzilla.redhat.com/show_bug.cgi?id=1034921 https://bugzilla.redhat.com/show_bug.cgi?id=1030583 --- src/devices/nm-device.c | 37 +++++++++++++++++++++++++++++++++++++ 1 file changed, 37 insertions(+) diff --git a/src/devices/nm-device.c b/src/devices/nm-device.c index 096eed7daf..e471f5775a 100644 --- a/src/devices/nm-device.c +++ b/src/devices/nm-device.c @@ -228,6 +228,7 @@ typedef struct { guint link_disconnected_id; guint carrier_defer_id; gboolean carrier; + guint carrier_wait_id; gboolean ignore_carrier; /* Generic DHCP stuff */ @@ -1159,6 +1160,12 @@ nm_device_set_carrier (NMDevice *device, gboolean carrier) priv->carrier_defer_id = 0; } klass->carrier_changed (device, TRUE); + + if (priv->carrier_wait_id) { + g_source_remove (priv->carrier_wait_id); + priv->carrier_wait_id = 0; + nm_device_remove_pending_action (device, "carrier wait"); + } } else if (state <= NM_DEVICE_STATE_DISCONNECTED) { nm_log_info (LOGD_DEVICE, "(%s): link disconnected", iface); klass->carrier_changed (device, FALSE); @@ -5115,9 +5122,20 @@ nm_device_start_ip_check (NMDevice *self) /****************************************************************/ +static gboolean +carrier_wait_timeout (gpointer user_data) +{ + NMDevice *self = NM_DEVICE (user_data); + + NM_DEVICE_GET_PRIVATE (self)->carrier_wait_id = 0; + nm_device_remove_pending_action (self, "carrier wait"); + return G_SOURCE_REMOVE; +} + gboolean nm_device_bring_up (NMDevice *self, gboolean block, gboolean *no_firmware) { + NMDevicePrivate *priv = NM_DEVICE_GET_PRIVATE (self); gboolean success; guint32 tries = 0; @@ -5143,6 +5161,20 @@ nm_device_bring_up (NMDevice *self, gboolean block, gboolean *no_firmware) return FALSE; } + /* Devices that support carrier detect must be IFF_UP to report carrier + * changes; so after setting the device IFF_UP we must suppress startup + * complete (via a pending action) until either the carrier turns on, or + * a timeout is reached. + */ + if (device_has_capability (self, NM_DEVICE_CAP_CARRIER_DETECT)) { + if (priv->carrier_wait_id) { + g_source_remove (priv->carrier_wait_id); + nm_device_remove_pending_action (self, "carrier wait"); + } + priv->carrier_wait_id = g_timeout_add_seconds (5, carrier_wait_timeout, self); + nm_device_add_pending_action (self, "carrier wait"); + } + out: /* Can only get HW address of some devices when they are up */ nm_device_update_hw_address (self); @@ -5306,6 +5338,11 @@ dispose (GObject *object) priv->cp_updated_id = 0; } + if (priv->carrier_wait_id) { + g_source_remove (priv->carrier_wait_id); + priv->carrier_wait_id = 0; + } + g_hash_table_unref (priv->available_connections); priv->available_connections = NULL; From 2556aa32ed03a2e8bf731364764288d53271fa86 Mon Sep 17 00:00:00 2001 From: Dan Williams Date: Tue, 10 Dec 2013 22:11:09 -0600 Subject: [PATCH 3/3] core: ensure 'activation' pending action encompasses full activation process The NMActiveConnection class tracks the full activation request, and internal activation requests go through the same process as external ones, including some authentication. Sometimes that means activation is scheduled, control returns to the mainloop, and then the activation proceeds from an idle handler. Unfortunately, that means that adding a pending "activation" action from nm-device.c doesn't always work, since there is a short window between when the activation is started in nm-manager.c (in nm_manager_activate_connection()) and when the device actually changes state. Inside that window, the pending actions may drop to zero, and startup will be declared complete before the device actually starts activating. Instead, ensure that the pending action is added when the internal activation is actually started (eg, when NMActiveConnection receives the NMDevice object). --- src/devices/nm-device.c | 15 --------------- src/nm-active-connection.c | 8 ++++++++ 2 files changed, 8 insertions(+), 15 deletions(-) diff --git a/src/devices/nm-device.c b/src/devices/nm-device.c index e471f5775a..1c1497a4c4 100644 --- a/src/devices/nm-device.c +++ b/src/devices/nm-device.c @@ -6135,13 +6135,6 @@ reason_to_string (NMDeviceStateReason reason) return "unknown"; } -static inline gboolean -state_implies_pending_action (NMDeviceState state) -{ - return ( state >= NM_DEVICE_STATE_PREPARE - && state < NM_DEVICE_STATE_ACTIVATED); -} - static void notify_ip_properties (NMDevice *device) { @@ -6183,10 +6176,6 @@ nm_device_state_changed (NMDevice *device, priv->state = state; priv->state_reason = reason; - if ( state_implies_pending_action (state) - && !state_implies_pending_action (old_state)) - nm_device_add_pending_action (device, "activation"); - nm_log_info (LOGD_DEVICE, "(%s): device state change: %s -> %s (reason '%s') [%d %d %d]", nm_device_get_iface (device), state_to_string (old_state), @@ -6352,10 +6341,6 @@ nm_device_state_changed (NMDevice *device, if (req) g_object_unref (req); - if ( state_implies_pending_action (old_state) - && !state_implies_pending_action (state)) - nm_device_remove_pending_action (device, "activation"); - priv->in_state_changed = FALSE; } diff --git a/src/nm-active-connection.c b/src/nm-active-connection.c index 6a825bc0d7..34f438c0fb 100644 --- a/src/nm-active-connection.c +++ b/src/nm-active-connection.c @@ -139,6 +139,12 @@ nm_active_connection_set_state (NMActiveConnection *self, (guint64) time (NULL), TRUE); } + if (priv->device) { + if ( old_state < NM_ACTIVE_CONNECTION_STATE_ACTIVATED + && new_state >= NM_ACTIVE_CONNECTION_STATE_ACTIVATED) + nm_device_remove_pending_action (priv->device, "activation"); + } + if (priv->state == NM_ACTIVE_CONNECTION_STATE_DEACTIVATED) { /* Device is no longer relevant when deactivated; emit property change * notification so clients re-read the value, which will be NULL due to @@ -352,6 +358,8 @@ nm_active_connection_set_device (NMActiveConnection *self, NMDevice *device) "state-changed", G_CALLBACK (device_state_changed), self); + + nm_device_add_pending_action (device, "activation"); } return TRUE; }