From 2794093d18175f78439009c1b0b0b750e711b1b2 Mon Sep 17 00:00:00 2001 From: Beniamino Galvani Date: Sun, 6 Oct 2019 11:01:12 +0200 Subject: core: add better logging for autoconnect with a new log domain Sometimes users report problems about profiles not autoconnecting and with the current logging it's difficult to understand where the problem is. Since all profiles must be evaluated when a device becomes available for autoconnection, adding by default a log message for each of them would be probably too verbose, even for TRACE level. Add a new 'autoconnect' log domain that is disabled by default and is useful to debug autoconnect problems, and use it to log why profiles can't autoconnect. --- clients/cli/general.c | 2 +- man/NetworkManager.conf.xml | 7 +++-- shared/nm-glib-aux/nm-logging-fwd.h | 2 ++ src/devices/bluetooth/nm-device-bt.c | 13 ++++++--- src/devices/nm-device.c | 12 +++++--- src/devices/nm-device.h | 6 ++-- src/devices/wifi/nm-device-iwd.c | 20 +++++++++++--- src/devices/wifi/nm-device-wifi.c | 14 ++++++++-- src/nm-logging.c | 3 +- src/nm-policy.c | 53 +++++++++++++++++++++++++++++------- 10 files changed, 100 insertions(+), 32 deletions(-) diff --git a/clients/cli/general.c b/clients/cli/general.c index e246d2828d..144c97dc22 100644 --- a/clients/cli/general.c +++ b/clients/cli/general.c @@ -793,7 +793,7 @@ do_general_logging (NmCli *nmc, int argc, char **argv) "AGENTS", "SETTINGS", "SUSPEND", "CORE", "DEVICE", "OLPC", "INFINIBAND", "FIREWALL", "ADSL", "BOND", "VLAN", "BRIDGE", "DBUS_PROPS", "TEAM", "CONCHECK", "DCB", "DISPATCH", "AUDIT", - "SYSTEMD", "VPN_PLUGIN", "PROXY", "TC", NULL); + "SYSTEMD", "VPN_PLUGIN", "PROXY", "TC", "AUTOCONNECT", NULL); } domains = *argv; } else { diff --git a/man/NetworkManager.conf.xml b/man/NetworkManager.conf.xml index e56de21022..c9fbe6f1e1 100644 --- a/man/NetworkManager.conf.xml +++ b/man/NetworkManager.conf.xml @@ -543,7 +543,7 @@ unmanaged-devices=mac:00:22:68:1c:59:b1;mac:00:1E:65:30:D1:C4;interface-name:eth AGENTS, SETTINGS, SUSPEND, CORE, DEVICE, OLPC, WIMAX, INFINIBAND, FIREWALL, ADSL, BOND, VLAN, BRIDGE, DBUS_PROPS, TEAM, CONCHECK, DCB, DISPATCH, AUDIT, SYSTEMD, VPN_PLUGIN, - PROXY. + PROXY, AUTOCONNECT. In addition, these special domains can be used: NONE, ALL, DEFAULT, DHCP, IP. You can specify per-domain log level overrides by @@ -590,8 +590,9 @@ unmanaged-devices=mac:00:22:68:1c:59:b1;mac:00:1E:65:30:D1:C4;interface-name:eth DISPATCH : Dispatcher scripts AUDIT : Audit records SYSTEMD : Messages from internal libsystemd - VPN_PLUGIN : logging messages from VPN plugins - PROXY : logging messages for proxy handling + VPN_PLUGIN : Messages from VPN plugins + PROXY : Proxy handling + AUTOCONNECT : Autoconnect operations NONE : when given by itself logging is disabled ALL : all log domains diff --git a/shared/nm-glib-aux/nm-logging-fwd.h b/shared/nm-glib-aux/nm-logging-fwd.h index eecba8bead..3363989563 100644 --- a/shared/nm-glib-aux/nm-logging-fwd.h +++ b/shared/nm-glib-aux/nm-logging-fwd.h @@ -49,6 +49,7 @@ typedef enum { /*< skip >*/ LOGD_SYSTEMD = (1LL << 35), LOGD_VPN_PLUGIN = (1LL << 36), LOGD_PROXY = (1LL << 37), + LOGD_AUTOCONNECT= (1LL << 38), __LOGD_MAX, LOGD_ALL = (((__LOGD_MAX - 1LL) << 1) - 1LL), @@ -56,6 +57,7 @@ typedef enum { /*< skip >*/ LOGD_DBUS_PROPS | LOGD_WIFI_SCAN | LOGD_VPN_PLUGIN | + LOGD_AUTOCONNECT | 0), /* aliases: */ diff --git a/src/devices/bluetooth/nm-device-bt.c b/src/devices/bluetooth/nm-device-bt.c index 497810c36f..a58a522570 100644 --- a/src/devices/bluetooth/nm-device-bt.c +++ b/src/devices/bluetooth/nm-device-bt.c @@ -166,7 +166,8 @@ get_generic_capabilities (NMDevice *device) static gboolean can_auto_connect (NMDevice *device, NMSettingsConnection *sett_conn, - char **specific_object) + char **specific_object, + GError **error) { NMDeviceBt *self = NM_DEVICE_BT (device); NMDeviceBtPrivate *priv = NM_DEVICE_BT_GET_PRIVATE (self); @@ -174,19 +175,23 @@ can_auto_connect (NMDevice *device, nm_assert (!specific_object || !*specific_object); - if (!NM_DEVICE_CLASS (nm_device_bt_parent_class)->can_auto_connect (device, sett_conn, NULL)) + if (!NM_DEVICE_CLASS (nm_device_bt_parent_class)->can_auto_connect (device, sett_conn, NULL, error)) return FALSE; if (!get_connection_bt_type_check (self, nm_settings_connection_get_connection (sett_conn), &bt_type, - NULL)) + error)) return FALSE; /* Can't auto-activate a DUN connection without ModemManager */ if ( bt_type == NM_BT_CAPABILITY_DUN - && priv->mm_running == FALSE) + && priv->mm_running == FALSE) { + nm_utils_error_set_literal (error, + NM_UTILS_ERROR_CONNECTION_AVAILABLE_TEMPORARY, + "bluetooth DUN connection requires ModemManager"); return FALSE; + } return TRUE; } diff --git a/src/devices/nm-device.c b/src/devices/nm-device.c index bd6a84ee0e..8f41c73a7f 100644 --- a/src/devices/nm-device.c +++ b/src/devices/nm-device.c @@ -5502,7 +5502,8 @@ nm_device_autoconnect_allowed (NMDevice *self) static gboolean can_auto_connect (NMDevice *self, NMSettingsConnection *sett_conn, - char **specific_object) + char **specific_object, + GError **error) { nm_assert (!specific_object || !*specific_object); return TRUE; @@ -5515,6 +5516,7 @@ can_auto_connect (NMDevice *self, * @specific_object: (out) (transfer full): on output, the path of an * object associated with the returned connection, to be passed to * nm_manager_activate_connection(), or %NULL. + * @error: location to store error, or %NULL * * Checks if @sett_conn can be auto-activated on @self right now. * This requires, at a minimum, that the connection be compatible with @@ -5528,11 +5530,13 @@ can_auto_connect (NMDevice *self, gboolean nm_device_can_auto_connect (NMDevice *self, NMSettingsConnection *sett_conn, - char **specific_object) + char **specific_object, + GError **error) { g_return_val_if_fail (NM_IS_DEVICE (self), FALSE); g_return_val_if_fail (NM_IS_SETTINGS_CONNECTION (sett_conn), FALSE); g_return_val_if_fail (!specific_object || !*specific_object, FALSE); + g_return_val_if_fail (!error || !*error, FALSE); /* the caller must ensure that nm_device_autoconnect_allowed() returns * TRUE as well. This is done, because nm_device_can_auto_connect() @@ -5547,10 +5551,10 @@ nm_device_can_auto_connect (NMDevice *self, nm_settings_connection_get_connection (sett_conn), NM_DEVICE_CHECK_CON_AVAILABLE_NONE, NULL, - NULL)) + error)) return FALSE; - if (!NM_DEVICE_GET_CLASS (self)->can_auto_connect (self, sett_conn, specific_object)) + if (!NM_DEVICE_GET_CLASS (self)->can_auto_connect (self, sett_conn, specific_object, error)) return FALSE; return TRUE; diff --git a/src/devices/nm-device.h b/src/devices/nm-device.h index df8777b720..ce15ad95dc 100644 --- a/src/devices/nm-device.h +++ b/src/devices/nm-device.h @@ -319,7 +319,8 @@ typedef struct _NMDeviceClass { gboolean (* can_auto_connect) (NMDevice *self, NMSettingsConnection *sett_conn, - char **specific_object); + char **specific_object, + GError **error); guint32 (*get_configured_mtu) (NMDevice *self, NMDeviceMtuSource *out_source); @@ -558,7 +559,8 @@ gboolean nm_device_master_update_slave_connection (NMDevice *master, gboolean nm_device_can_auto_connect (NMDevice *self, NMSettingsConnection *sett_conn, - char **specific_object); + char **specific_object, + GError **error); gboolean nm_device_complete_connection (NMDevice *device, NMConnection *connection, diff --git a/src/devices/wifi/nm-device-iwd.c b/src/devices/wifi/nm-device-iwd.c index 8e3aafda12..9a94cd613c 100644 --- a/src/devices/wifi/nm-device-iwd.c +++ b/src/devices/wifi/nm-device-iwd.c @@ -923,7 +923,8 @@ get_autoconnect_allowed (NMDevice *device) static gboolean can_auto_connect (NMDevice *device, NMSettingsConnection *sett_conn, - char **specific_object) + char **specific_object, + GError **error) { NMDeviceIwd *self = NM_DEVICE_IWD (device); NMDeviceIwdPrivate *priv = NM_DEVICE_IWD_GET_PRIVATE (self); @@ -935,7 +936,7 @@ can_auto_connect (NMDevice *device, nm_assert (!specific_object || !*specific_object); - if (!NM_DEVICE_CLASS (nm_device_iwd_parent_class)->can_auto_connect (device, sett_conn, NULL)) + if (!NM_DEVICE_CLASS (nm_device_iwd_parent_class)->can_auto_connect (device, sett_conn, NULL, error)) return FALSE; connection = nm_settings_connection_get_connection (sett_conn); @@ -947,16 +948,24 @@ can_auto_connect (NMDevice *device, * Note the wpa_supplicant backend has the opposite policy. */ mode = nm_setting_wireless_get_mode (s_wifi); - if (mode && g_strcmp0 (mode, NM_SETTING_WIRELESS_MODE_INFRA) != 0) + if (mode && g_strcmp0 (mode, NM_SETTING_WIRELESS_MODE_INFRA) != 0) { + nm_utils_error_set_literal (error, + NM_UTILS_ERROR_CONNECTION_AVAILABLE_INCOMPATIBLE, + "only infrastructure mode connections can autoconnect"); return FALSE; + } /* Don't autoconnect to networks that have been tried at least once * but haven't been successful, since these are often accidental choices * from the menu and the user may not know the password. */ if (nm_settings_connection_get_timestamp (sett_conn, ×tamp)) { - if (timestamp == 0) + if (timestamp == 0) { + nm_utils_error_set_literal (error, + NM_UTILS_ERROR_CONNECTION_AVAILABLE_TEMPORARY, + "connection never activated successfully"); return FALSE; + } } ap = nm_wifi_aps_find_first_compatible (&priv->aps_lst_head, connection); @@ -966,6 +975,9 @@ can_auto_connect (NMDevice *device, return TRUE; } + nm_utils_error_set_literal (error, + NM_UTILS_ERROR_CONNECTION_AVAILABLE_TEMPORARY, + "no compatible AP found"); return FALSE; } diff --git a/src/devices/wifi/nm-device-wifi.c b/src/devices/wifi/nm-device-wifi.c index 04c90058a1..21d74cddc6 100644 --- a/src/devices/wifi/nm-device-wifi.c +++ b/src/devices/wifi/nm-device-wifi.c @@ -955,7 +955,8 @@ get_autoconnect_allowed (NMDevice *device) static gboolean can_auto_connect (NMDevice *device, NMSettingsConnection *sett_conn, - char **specific_object) + char **specific_object, + GError **error) { NMDeviceWifi *self = NM_DEVICE_WIFI (device); NMDeviceWifiPrivate *priv = NM_DEVICE_WIFI_GET_PRIVATE (self); @@ -968,7 +969,7 @@ can_auto_connect (NMDevice *device, nm_assert (!specific_object || !*specific_object); - if (!NM_DEVICE_CLASS (nm_device_wifi_parent_class)->can_auto_connect (device, sett_conn, NULL)) + if (!NM_DEVICE_CLASS (nm_device_wifi_parent_class)->can_auto_connect (device, sett_conn, NULL, error)) return FALSE; connection = nm_settings_connection_get_connection (sett_conn); @@ -997,8 +998,12 @@ can_auto_connect (NMDevice *device, * from the menu and the user may not know the password. */ if (nm_settings_connection_get_timestamp (sett_conn, ×tamp)) { - if (timestamp == 0) + if (timestamp == 0) { + nm_utils_error_set_literal (error, + NM_UTILS_ERROR_CONNECTION_AVAILABLE_TEMPORARY, + "connection never activated successfully"); return FALSE; + } } ap = nm_wifi_aps_find_first_compatible (&priv->aps_lst_head, connection); @@ -1008,6 +1013,9 @@ can_auto_connect (NMDevice *device, return TRUE; } + nm_utils_error_set_literal (error, + NM_UTILS_ERROR_CONNECTION_AVAILABLE_TEMPORARY, + "no compatible AP found"); return FALSE; } diff --git a/src/nm-logging.c b/src/nm-logging.c index add57e4726..636848f870 100644 --- a/src/nm-logging.c +++ b/src/nm-logging.c @@ -207,6 +207,7 @@ static const LogDesc domain_desc[] = { { LOGD_SYSTEMD, "SYSTEMD" }, { LOGD_VPN_PLUGIN,"VPN_PLUGIN" }, { LOGD_PROXY, "PROXY" }, + { LOGD_AUTOCONNECT, "AUTOCONNECT" }, { 0 }, }; @@ -534,7 +535,7 @@ _domains_to_string (gboolean include_level_override, return g_string_free (str, FALSE); } -static char _all_logging_domains_to_str[273]; +static char _all_logging_domains_to_str[285]; const char * nm_logging_all_domains_to_string (void) diff --git a/src/nm-policy.c b/src/nm-policy.c index d322b2efea..a7fe6d0f6b 100644 --- a/src/nm-policy.c +++ b/src/nm-policy.c @@ -1240,12 +1240,20 @@ auto_activate_device (NMPolicy *self, if (nm_device_get_act_request (device)) return; - if (!nm_device_autoconnect_allowed (device)) + if (!nm_device_autoconnect_allowed (device)) { + _LOGT (LOGD_AUTOCONNECT, + "autoconnect (%s): not allowed", + nm_device_get_iface (device)); return; + } connections = nm_manager_get_activatable_connections (priv->manager, TRUE, TRUE, &len); - if (!connections[0]) + if (!connections[0]) { + _LOGT (LOGD_AUTOCONNECT, + "autoconnect (%s): no activatable connections", + nm_device_get_iface (device)); return; + } /* Find the first connection that should be auto-activated */ best_connection = NULL; @@ -1255,30 +1263,54 @@ auto_activate_device (NMPolicy *self, NMSettingConnection *s_con; const char *permission; - if (nm_settings_connection_autoconnect_is_blocked (candidate)) + if (nm_settings_connection_autoconnect_is_blocked (candidate)) { + _LOGT (LOGD_AUTOCONNECT, + "autoconnect (%s): connection %s is blocked", + nm_device_get_iface (device), + nm_settings_connection_get_uuid (candidate)); continue; + } cand_conn = nm_settings_connection_get_connection (candidate); s_con = nm_connection_get_setting_connection (cand_conn); - if (!nm_setting_connection_get_autoconnect (s_con)) + if (!nm_setting_connection_get_autoconnect (s_con)) { + _LOGT (LOGD_AUTOCONNECT, + "autoconnect (%s): connection %s has autoconnect=no", + nm_device_get_iface (device), + nm_settings_connection_get_uuid (candidate)); continue; + } permission = nm_utils_get_shared_wifi_permission (cand_conn); if ( permission - && !nm_settings_connection_check_permission (candidate, permission)) + && !nm_settings_connection_check_permission (candidate, permission)) { + _LOGT (LOGD_AUTOCONNECT, + "autoconnect (%s): connection %s has no permission", + nm_device_get_iface (device), + nm_settings_connection_get_uuid (candidate)); continue; + } - if (nm_device_can_auto_connect (device, candidate, &specific_object)) { - best_connection = candidate; - break; + if (!nm_device_can_auto_connect (device, candidate, &specific_object, &error)) { + _LOGT (LOGD_AUTOCONNECT, + "autoconnect (%s): connection %s can't autoconnect: %s", + nm_device_get_iface (device), + nm_settings_connection_get_uuid (candidate), + error->message); + g_clear_error (&error); + continue; } + + best_connection = candidate; + break; } if (!best_connection) return; - _LOGI (LOGD_DEVICE, "auto-activating connection '%s' (%s)", + _LOGI (LOGD_DEVICE | LOGD_AUTOCONNECT, + "autoconnect: auto-activating connection '%s' (%s)", nm_settings_connection_get_id (best_connection), nm_settings_connection_get_uuid (best_connection)); @@ -1294,7 +1326,8 @@ auto_activate_device (NMPolicy *self, NM_ACTIVATION_STATE_FLAG_LIFETIME_BOUND_TO_PROFILE_VISIBILITY, &error); if (!ac) { - _LOGI (LOGD_DEVICE, "connection '%s' auto-activation failed: %s", + _LOGI (LOGD_DEVICE | LOGD_AUTOCONNECT, + "autoconnect: '%s' auto-activation failed: %s", nm_settings_connection_get_id (best_connection), error->message); nm_settings_connection_autoconnect_blocked_reason_set (best_connection, -- cgit v1.2.1