From bdc9e85488c4c9fe0e30684f40cc4de052a97e48 Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Tue, 6 Oct 2015 14:27:03 +0200 Subject: device/logging: refactor logging for activation-stage Instead of hand-craft logging lines after each time we call activation_source_schedule(), do it in activation_source_schedule(). This also gives us the exact same logging line and provides more debugging-information (like the source-id that was scheduled). --- src/devices/nm-device.c | 98 +++++++++++++------------------------------------ 1 file changed, 26 insertions(+), 72 deletions(-) diff --git a/src/devices/nm-device.c b/src/devices/nm-device.c index a709380516..573a1d9d24 100644 --- a/src/devices/nm-device.c +++ b/src/devices/nm-device.c @@ -2833,8 +2833,7 @@ activation_source_clear (NMDevice *self, int family) static void activation_source_handle_cb (NMDevice *self, int family) { - ActivationHandleData *act_data; - ActivationHandleFunc func; + ActivationHandleData *act_data, a; g_return_if_fail (NM_IS_DEVICE (self)); @@ -2843,13 +2842,16 @@ activation_source_handle_cb (NMDevice *self, int family) g_return_if_fail (act_data->id); g_return_if_fail (act_data->func); - func = act_data->func; + a = *act_data; - _LOGt (LOGD_DEVICE, "activation-stage: invoke %p/%d (id %u)", act_data->func, family, act_data->id); act_data->func = NULL; act_data->id = 0; - func (self); + _LOGD (LOGD_DEVICE, "activation-stage: invoke %p/%d (id %u)", a.func, family, a.id); + + a.func (self); + + _LOGD (LOGD_DEVICE, "activation-stage: complete %p/%d (id %u)", a.func, family, a.id); } static void @@ -2870,9 +2872,9 @@ _activation_source_schedule (NMDevice *self, ActivationHandleFunc func, int fami new_id = g_idle_add (source_func, self); if (act_data->id) - _LOGE (LOGD_DEVICE, "activation stage already scheduled"); + _LOGE (LOGD_DEVICE, "activation-stage: already scheduled (%s)", s_func); - _LOGt (LOGD_DEVICE, "activation-stage: schedule %s/%s (%p/%d) (id %u -> %u)", + _LOGD (LOGD_DEVICE, "activation-stage: schedule %s/%s (%p/%d) (id %u -> %u)", s_func, s_family, func, family, act_data->id, new_id); if (new_id) { @@ -2972,25 +2974,21 @@ nm_device_activate_stage1_device_prepare (NMDevice *self) /* Notify the new ActiveConnection along with the state change */ g_object_notify (G_OBJECT (self), NM_DEVICE_ACTIVE_CONNECTION); - _LOGD (LOGD_DEVICE, "Activation: Stage 1 of 5 (Device Prepare) started..."); nm_device_state_changed (self, NM_DEVICE_STATE_PREPARE, NM_DEVICE_STATE_REASON_NONE); /* Assumed connections were already set up outside NetworkManager */ if (!nm_active_connection_get_assumed (active)) { ret = NM_DEVICE_GET_CLASS (self)->act_stage1_prepare (self, &reason); if (ret == NM_ACT_STAGE_RETURN_POSTPONE) { - goto out; + return; } else if (ret == NM_ACT_STAGE_RETURN_FAILURE) { nm_device_state_changed (self, NM_DEVICE_STATE_FAILED, reason); - goto out; + return; } g_assert (ret == NM_ACT_STAGE_RETURN_SUCCESS); } nm_device_activate_schedule_stage2_device_config (self); - -out: - _LOGD (LOGD_DEVICE, "Activation: Stage 1 of 5 (Device Prepare) complete."); } @@ -3011,8 +3009,6 @@ nm_device_activate_schedule_stage1_device_prepare (NMDevice *self) g_return_if_fail (priv->act_request); activation_source_schedule (self, nm_device_activate_stage1_device_prepare, AF_INET); - - _LOGD (LOGD_DEVICE, "Activation: Stage 1 of 5 (Device Prepare) scheduled..."); } static NMActStageReturn @@ -3039,7 +3035,6 @@ nm_device_activate_stage2_device_config (NMDevice *self) NMActiveConnection *active = NM_ACTIVE_CONNECTION (priv->act_request); GSList *iter; - _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); /* Assumed connections were already set up outside NetworkManager */ @@ -3049,15 +3044,15 @@ nm_device_activate_stage2_device_config (NMDevice *self) nm_device_state_changed (self, NM_DEVICE_STATE_FAILED, NM_DEVICE_STATE_REASON_FIRMWARE_MISSING); else nm_device_state_changed (self, NM_DEVICE_STATE_FAILED, NM_DEVICE_STATE_REASON_CONFIG_FAILED); - goto out; + return; } ret = NM_DEVICE_GET_CLASS (self)->act_stage2_config (self, &reason); if (ret == NM_ACT_STAGE_RETURN_POSTPONE) - goto out; + return; else if (ret == NM_ACT_STAGE_RETURN_FAILURE) { nm_device_state_changed (self, NM_DEVICE_STATE_FAILED, reason); - goto out; + return; } g_assert (ret == NM_ACT_STAGE_RETURN_SUCCESS); } @@ -3074,12 +3069,7 @@ nm_device_activate_stage2_device_config (NMDevice *self) nm_device_queue_recheck_assume (info->slave); } - _LOGD (LOGD_DEVICE, "Activation: Stage 2 of 5 (Device Configure) successful."); - nm_device_activate_schedule_stage3_ip_config_start (self); - -out: - _LOGD (LOGD_DEVICE, "Activation: Stage 2 of 5 (Device Configure) complete."); } @@ -3125,8 +3115,6 @@ nm_device_activate_schedule_stage2_device_config (NMDevice *self) } activation_source_schedule (self, nm_device_activate_stage2_device_config, AF_INET); - - _LOGD (LOGD_DEVICE, "Activation: Stage 2 of 5 (Device Configure) scheduled..."); } /* @@ -5547,7 +5535,6 @@ nm_device_activate_stage3_ip_config_start (NMDevice *self) priv->ip4_state = priv->ip6_state = IP_WAIT; - _LOGD (LOGD_DEVICE, "Activation: Stage 3 of 5 (IP Configure Start) started..."); nm_device_state_changed (self, NM_DEVICE_STATE_IP_CONFIG, NM_DEVICE_STATE_REASON_NONE); /* Device should be up before we can do anything with it */ @@ -5571,21 +5558,18 @@ nm_device_activate_stage3_ip_config_start (NMDevice *self) nm_connection_get_id (nm_device_get_applied_connection (self)), master_device ? nm_device_get_iface (master_device) : "(unknown)"); } - goto out; + return; } /* IPv4 */ if (!nm_device_activate_stage3_ip4_start (self)) - goto out; + return; /* IPv6 */ if (!nm_device_activate_stage3_ip6_start (self)) - goto out; + return; nm_device_check_ip_failed (self, TRUE); - -out: - _LOGD (LOGD_DEVICE, "Activation: Stage 3 of 5 (IP Configure Start) complete."); } @@ -5614,10 +5598,8 @@ fw_change_zone_cb (NMFirewallManager *firewall_manager, if (priv->state == NM_DEVICE_STATE_IP_CHECK) nm_device_start_ip_check (self); - else { + else 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."); - } } /* @@ -5650,7 +5632,6 @@ 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, AF_INET); - _LOGD (LOGD_DEVICE, "Activation: Stage 3 of 5 (IP Configure Start) scheduled."); return; } @@ -5687,23 +5668,18 @@ nm_device_activate_ip4_config_timeout (NMDevice *self) NMActStageReturn ret = NM_ACT_STAGE_RETURN_FAILURE; NMDeviceStateReason reason = NM_DEVICE_STATE_REASON_NONE; - _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); if (ret == NM_ACT_STAGE_RETURN_POSTPONE) - goto out; + return; else if (ret == NM_ACT_STAGE_RETURN_FAILURE) { nm_device_state_changed (self, NM_DEVICE_STATE_FAILED, reason); - goto out; + return; } - g_assert (ret == NM_ACT_STAGE_RETURN_SUCCESS); + g_assert (ret == NM_ACT_STAGE_RETURN_SUCCESS); priv->ip4_state = IP_FAIL; nm_device_check_ip_failed (self, FALSE); - -out: - _LOGD (LOGD_DEVICE | LOGD_IP4, "Activation: Stage 4 of 5 (IPv4 Configure Timeout) complete."); } @@ -5724,8 +5700,6 @@ nm_device_activate_schedule_ip4_config_timeout (NMDevice *self) g_return_if_fail (priv->act_request); activation_source_schedule (self, nm_device_activate_ip4_config_timeout, AF_INET); - - _LOGD (LOGD_DEVICE | LOGD_IP4, "Activation: Stage 4 of 5 (IPv4 Configure Timeout) scheduled..."); } @@ -5754,23 +5728,18 @@ nm_device_activate_ip6_config_timeout (NMDevice *self) NMActStageReturn ret = NM_ACT_STAGE_RETURN_FAILURE; NMDeviceStateReason reason = NM_DEVICE_STATE_REASON_NONE; - _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); if (ret == NM_ACT_STAGE_RETURN_POSTPONE) - goto out; - else if (ret == NM_ACT_STAGE_RETURN_FAILURE) { + return; + if (ret == NM_ACT_STAGE_RETURN_FAILURE) { nm_device_state_changed (self, NM_DEVICE_STATE_FAILED, reason); - goto out; + return; } g_assert (ret == NM_ACT_STAGE_RETURN_SUCCESS); priv->ip6_state = IP_FAIL; nm_device_check_ip_failed (self, FALSE); - -out: - _LOGD (LOGD_DEVICE | LOGD_IP6, "Activation: Stage 4 of 5 (IPv6 Configure Timeout) complete."); } @@ -5791,8 +5760,6 @@ nm_device_activate_schedule_ip6_config_timeout (NMDevice *self) g_return_if_fail (priv->act_request); activation_source_schedule (self, nm_device_activate_ip6_config_timeout, AF_INET6); - - _LOGD (LOGD_DEVICE | LOGD_IP6, "Activation: Stage 4 of 5 (IPv6 Configure Timeout) scheduled..."); } static gboolean @@ -6008,8 +5975,6 @@ nm_device_activate_ip4_config_commit (NMDevice *self) NMDeviceStateReason reason = NM_DEVICE_STATE_REASON_NONE; int ip_ifindex; - _LOGD (LOGD_DEVICE, "Activation: Stage 5 of 5 (IPv4 Commit) started..."); - req = nm_device_get_act_request (self); g_assert (req); connection = nm_act_request_get_applied_connection (req); @@ -6027,7 +5992,7 @@ nm_device_activate_ip4_config_commit (NMDevice *self) if (!ip4_config_merge_and_apply (self, NULL, TRUE, &reason)) { _LOGD (LOGD_DEVICE | LOGD_IP4, "Activation: Stage 5 of 5 (IPv4 Commit) failed"); nm_device_state_changed (self, NM_DEVICE_STATE_FAILED, reason); - goto out; + return; } /* Start IPv4 sharing if we need it */ @@ -6037,7 +6002,7 @@ nm_device_activate_ip4_config_commit (NMDevice *self) if (!start_sharing (self, priv->ip4_config)) { _LOGW (LOGD_SHARING, "Activation: Stage 5 of 5 (IPv4 Commit) start sharing failed."); nm_device_state_changed (self, NM_DEVICE_STATE_FAILED, NM_DEVICE_STATE_REASON_SHARED_START_FAILED); - goto out; + return; } } @@ -6066,9 +6031,6 @@ nm_device_activate_ip4_config_commit (NMDevice *self) if (nm_device_get_state (self) == NM_DEVICE_STATE_IP_CONFIG) nm_device_state_changed (self, NM_DEVICE_STATE_IP_CHECK, NM_DEVICE_STATE_REASON_NONE); - -out: - _LOGD (LOGD_DEVICE, "Activation: Stage 5 of 5 (IPv4 Commit) complete."); } static void @@ -6102,8 +6064,6 @@ nm_device_activate_schedule_ip4_config_result (NMDevice *self, NMIP4Config *conf nm_device_queued_ip_config_change_clear (self); activation_source_schedule (self, nm_device_activate_ip4_config_commit, AF_INET); - - _LOGD (LOGD_DEVICE | LOGD_IP4, "Activation: Stage 5 of 5 (IPv4 Configure Commit) scheduled..."); } gboolean @@ -6129,8 +6089,6 @@ nm_device_activate_ip6_config_commit (NMDevice *self) NMDeviceStateReason reason = NM_DEVICE_STATE_REASON_NONE; int ip_ifindex; - _LOGD (LOGD_DEVICE, "Activation: Stage 5 of 5 (IPv6 Commit) started..."); - req = nm_device_get_act_request (self); g_assert (req); connection = nm_act_request_get_applied_connection (req); @@ -6173,8 +6131,6 @@ nm_device_activate_ip6_config_commit (NMDevice *self) _LOGW (LOGD_DEVICE | LOGD_IP6, "Activation: Stage 5 of 5 (IPv6 Commit) failed"); nm_device_state_changed (self, NM_DEVICE_STATE_FAILED, reason); } - - _LOGD (LOGD_DEVICE, "Activation: Stage 5 of 5 (IPv6 Commit) complete."); } void @@ -6191,8 +6147,6 @@ nm_device_activate_schedule_ip6_config_result (NMDevice *self) priv->ip6_state = IP_CONF; activation_source_schedule (self, nm_device_activate_ip6_config_commit, AF_INET6); - - _LOGD (LOGD_DEVICE | LOGD_IP6, "Activation: Stage 5 of 5 (IPv6 Commit) scheduled..."); } gboolean -- cgit v1.2.1