On Wed, 2017-05-24 at 18:22 +0000, Matthew Starr wrote:
> > -----Original Message-----
> > From: Dan Williams [mailto:[email protected]]
> > Sent: Wednesday, May 24, 2017 12:48 PM
> > To: Matthew Starr; [email protected]
> > Subject: Re: Network Manager 1.0.X Wi-Fi Autoconnect Issues
> >
> > On Thu, 2017-05-18 at 22:25 +0000, Matthew Starr wrote:
> > > > -----Original Message-----
> > > > From: Dan Williams [mailto:[email protected]]
> > > > Sent: Thursday, May 18, 2017 4:55 PM
> > > > To: Matthew Starr; [email protected]
> > > > Subject: Re: Network Manager 1.0.X Wi-Fi Autoconnect Issues
> > > >
> > > > On Thu, 2017-05-18 at 20:23 +0000, Matthew Starr wrote:
> > > > > > -----Original Message-----
> > > > > > From: Dan Williams [mailto:[email protected]]
> > > > > > Sent: Thursday, May 18, 2017 2:24 PM
> > > > > > To: Matthew Starr; [email protected]
> > > > > > Subject: Re: Network Manager 1.0.X Wi-Fi Autoconnect Issues
> > > > > >
> > > > > > On Thu, 2017-05-18 at 18:43 +0000, Matthew Starr wrote:
> > > > > > > > -----Original Message-----
> > > > > > > > From: Dan Williams [mailto:[email protected]]
> > > > > > > > Sent: Thursday, May 18, 2017 1:31 PM
> > > > > > > > To: Matthew Starr; [email protected]
> > > > > > > > Subject: Re: Network Manager 1.0.X Wi-Fi Autoconnect
> > > > > > > > Issues
> > > > > > > >
> > > > > > > > On Thu, 2017-05-18 at 15:54 +0000, Matthew Starr wrote:
> > > > > > > > > I have tried using NetworkManager 1.0.0 and 1.0.12 on
> > > > > > > > > an
> > > > > > > > > embedded device built with buildroot that has
> > > > > > > > > Ethernet
> > > > > > > > > (eth0), Wi-Fi client (mlan0), Wi-Fi Access Point
> > > > > > > > > (uap0),
> > > > > > > > > and Cellular interfaces
> > > > > > > > > (ttyACM0
> > > > > > > > > and ppp0). The Wi-Fi AP (uap0) interface is ignored
> > > > > > > > > by
> > > > > > > > > Network Manager based on my NetworkManager.conf file.
> > > > > > > > > I am
> > > > > > > > > able to boot the device and Network Manager will
> > > > > > > > > automatically configure and connect with Ethernet,
> > > > > > > > > Wi-Fi
> > > > > > > > > Client, and Cellular interfaces every time.
> > > > > > > > >
> > > > > > > > > If I move out of range of the Wi-Fi access point the
> > > > > > > > > device will disconnect and if I move back into range
> > > > > > > > > in
> > > > > > > > > under an hour, NetworkManager will reestablish the
> > > > > > > > > connection. If I wait multiple hours before moving
> > > > > > > > > back
> > > > > > > > > into range of the Wi-Fi access point, Network Manager
> > > > > > > > > will
> > > > > > > > > not reestablish a connection automatically with the
> > > > > > > > > access
> > > > > > > > > point (I waited hours with the AP within range and
> > > > > > > > > visible
> > > > > > > > > in Wi-Fi scan results).
> > > > > > > > > When Network Manager is not automatically
> > > > > > > > > reestablishing a
> > > > > > > > > connection to the access point I can use nmcli to
> > > > > > > > > bring up
> > > > > > > > > the profile associated with the access point and it
> > > > > > > > > connects immediately.
> > > > > > > > >
> > > > > > > > > Why is Network Manager not able to auto connect to a
> > > > > > > > > Wi-
> > > > > > > > > Fi AP after a longer period of time of not seeing the
> > > > > > > > > AP?
> > > > > > > > > Is there a timeout within Network Manager? Is this a
> > > > > > > > > bug?
> > > > > > > >
> > > > > > > > Like you say, it does look like NM is trying to auto-
> > > > > > > > activate the connection, but it's not doing it
> > > > > > > > correctly.
> > > > > > > > The most likely thing happening is that it does try to
> > > > > > > > activate, but it's not able to find the "best"
> > > > > > > > connection
> > > > > > > > for the device.
> > > > > > > > Somehow the existing WiFi connection profile isn't
> > > > > > > > matching.
> > > > > > > >
> > > > > > > > Can you run 'nmcli con show <name of connection you
> > > > > > > > expect
> > > > > > > > to
> > > > > > > > start>'?
> > > > > > >
> > > > > > > Dan,
> > > > > > >
> > > > > > > This issue has occurred on several different access point
> > > > > > > I
> > > > > > > have attempted to connect to all from different vendors
> > > > > > > (Linksys, Ubiquiti, D-link).
> > > > > >
> > > > > > Ok, that doesn't ellucidate anything. Are you able to
> > > > > > apply a
> > > > > > debugging patch to NetworkManager and rebuild it?
> > > > > > Alternatively, you could use 'gdb' to step through the code
> > > > > > and
> > > > > > see where it's not proceeding with the activation in
> > > > > > nm-policy.c.
> > > > > >
> > > > > > Dan
> > > > > >
> > > > >
> > > > > Some additional testing I just finished shows that version
> > > > > 1.6.2
> > > > > exhibits the exact same behavior.
> > > > >
> > > > > I am able to apply patches easily and rebuild. I could run
> > > > > gdb
> > > > > but it is not quite as easy on my current setup.
> > > >
> > > > Which version do you prefer patches for?
> > > >
> > > > Dan
> > >
> > > My more immediate need is with the 1.0.12 version, but I plan to
> > > do a
> > > release within the next 6 months with the 1.6.X or 1.8.X version.
> >
> > Patch against upstream 1.0.12 attached. Hopefully applies to your
> > version. It
> > should log the right stuff without touching the logging level or
> > domains. Run
> > with this patch, reproduce the issue, and lets see what the logs
> > say.
> >
> > Dan
>
> I was able to cleanly apply the patch, but shortly after starting
> Network Manager it seems to seg fault (verified by using the -n
> option to not run as a daemon). I don't see any error messages in the
> logs. Here is where the logs left off:
You've probably got some hidden-SSID APs, and I didn't account for
that. Can you back out the previous patch, and try the latest attached
one?
Dan
> May 24 18:16:28 canect2 daemon.info NetworkManager[499]: <info> ####
> (mlan0) [wifi compat] not wifi
> May 24 18:16:28 canect2 daemon.info NetworkManager[499]: <info> ####
> (mlan0) [device] incompatible with device
> May 24 18:16:28 canect2 daemon.info NetworkManager[499]: <info> ####
> (mlan0) [wifi compat] checking AP '17107020874-Endurance'
> May 24 18:16:28 canect2 daemon.info NetworkManager[499]: <info> ####
> (mlan0) [wifi compat] AP '17107020874-Endurance' incompatible
> with connection
> May 24 18:16:28 canect2 daemon.info NetworkManager[499]: <info> ####
> (mlan0) [wifi compat] checking AP 'linksys-hed-test'
> May 24 18:16:28 canect2 daemon.info NetworkManager[499]: <info> ####
> (mlan0) [wifi compat] AP 'linksys-hed-test' incompatible with
> connection
> May 24 18:16:28 canect2 daemon.info NetworkManager[499]: <info> ####
> (mlan0) [wifi compat] checking AP '17107020873-Endurance'
> May 24 18:16:28 canect2 daemon.info NetworkManager[499]: <info> ####
> (mlan0) [wifi compat] AP '17107020873-Endurance' incompatible
> with connection
> May 24 18:16:28 canect2 daemon.info NetworkManager[499]: <info> ####
> (mlan0) [wifi compat] checking AP 'BrettSalesDemo'
> May 24 18:16:28 canect2 daemon.info NetworkManager[499]: <info> ####
> (mlan0) [wifi compat] AP 'BrettSalesDemo' incompatible with
> connection
> May 24 18:16:28 canect2 daemon.info NetworkManager[499]: <info> ####
> (mlan0) [wifi compat] checking AP '17107020875-Endurance'
> May 24 18:16:28 canect2 daemon.info NetworkManager[499]: <info> ####
> (mlan0) [wifi compat] AP '17107020875-Endurance' incompatible
> with connection
> May 24 18:16:28 canect2 daemon.info NetworkManager[499]: <info> ####
> (mlan0) [wifi compat] checking AP 'CANect-16307046638'
> May 24 18:16:28 canect2 daemon.info NetworkManager[499]: <info> ####
> (mlan0) [wifi compat] AP 'CANect-16307046638' incompatible
> with connection
> May 24 18:16:28 canect2 daemon.info NetworkManager[499]: <info> ####
> (mlan0) [wifi compat] checking AP 'CANect-11195067846'
> May 24 18:16:28 canect2 daemon.info NetworkManager[499]: <info> ####
> (mlan0) [wifi compat] AP 'CANect-11195067846' incompatible
> with connection
> May 24 18:16:28 canect2 daemon.info NetworkManager[499]: <info> ####
> (mlan0) [wifi compat] checking AP '17107020876-Endurance'
> May 24 18:16:28 canect2 daemon.info NetworkManager[499]: <info> ####
> (mlan0) [wifi compat] AP '17107020876-Endurance' incompatible
> with connection
> May 24 18:16:28 canect2 daemon.info NetworkManager[499]: <info> ####
> (mlan0) [wifi compat] checking AP 'HED.Inc.Wifi'
> May 24 18:16:28 canect2 daemon.info NetworkManager[499]: <info> ####
> (mlan0) [wifi compat] AP 'HED.Inc.Wifi' compatible
> May 24 18:16:28 canect2 daemon.info NetworkManager[499]: <info> ####
> (mlan0) [wifi compat] parent fail
> May 24 18:16:28 canect2 daemon.info NetworkManager[499]: <info> ####
> (mlan0) [device] incompatible with device
> May 24 18:16:28 canect2 daemon.info NetworkManager[499]: <info> ####
> (mlan0) [wifi compat] parent fail
> May 24 18:16:28 canect2 daemon.info NetworkManager[499]: <info> ####
> (mlan0) [device] incompatible with device
> May 24 18:16:28 canect2 daemon.info NetworkManager[499]: <info> ####
> (mlan0) [wifi compat] not wifi
> May 24 18:16:28 canect2 daemon.info NetworkManager[499]: <info> ####
> (mlan0) [device] incompatible with device
> May 24 18:16:28 canect2 daemon.info NetworkManager[499]: <info> ####
> (mlan0) [wifi compat] not wifi
> May 24 18:16:28 canect2 daemon.info NetworkManager[499]: <info> ####
> (mlan0) [device] incompatible with device
> May 24 18:16:28 canect2 daemon.info NetworkManager[499]: <info> ####
> (mlan0) [wifi compat] not wifi
> May 24 18:16:28 canect2 daemon.info NetworkManager[499]: <info> ####
> (mlan0) [device] incompatible with device
>
> -Matt
diff --git a/src/devices/nm-device.c b/src/devices/nm-device.c
index bc7ebcb..423cc74 100644
--- a/src/devices/nm-device.c
+++ b/src/devices/nm-device.c
@@ -2150,7 +2150,10 @@ can_auto_connect (NMDevice *self,
s_con = nm_connection_get_setting_connection (connection);
if (!nm_setting_connection_get_autoconnect (s_con))
+{
+ nm_log_info (LOGD_DEVICE, "#### (%s) [device] not autoconnect", nm_device_get_iface (self));
return FALSE;
+}
return nm_device_check_connection_available (self, connection, NM_DEVICE_CHECK_CON_AVAILABLE_NONE, NULL);
}
@@ -7765,24 +7768,40 @@ nm_device_check_connection_available (NMDevice *self,
const char *specific_object)
{
NMDeviceState state;
+ gboolean avail;
state = nm_device_get_state (self);
if (state < NM_DEVICE_STATE_UNMANAGED)
+{
+ nm_log_info (LOGD_DEVICE, "#### (%s) [device] < unmanaged", nm_device_get_iface (self));
return FALSE;
+}
if ( state < NM_DEVICE_STATE_UNAVAILABLE
&& nm_device_get_unmanaged_flag (self, NM_UNMANAGED_ALL & ~NM_UNMANAGED_DEFAULT))
+{
+ nm_log_info (LOGD_DEVICE, "#### (%s) [device] < unavailable", nm_device_get_iface (self));
return FALSE;
+}
if ( state < NM_DEVICE_STATE_DISCONNECTED
&& ( ( !NM_FLAGS_HAS (flags, _NM_DEVICE_CHECK_CON_AVAILABLE_FOR_USER_REQUEST_WAITING_CARRIER)
&& !nm_device_is_available (self, NM_DEVICE_CHECK_DEV_AVAILABLE_NONE))
|| ( NM_FLAGS_HAS (flags, _NM_DEVICE_CHECK_CON_AVAILABLE_FOR_USER_REQUEST_WAITING_CARRIER)
&& !nm_device_is_available (self, NM_DEVICE_CHECK_DEV_AVAILABLE_IGNORE_CARRIER))))
+{
+ nm_log_info (LOGD_DEVICE, "#### (%s) [device] < disconnected", nm_device_get_iface (self));
return FALSE;
+}
if (!nm_device_check_connection_compatible (self, connection))
+{
+ nm_log_info (LOGD_DEVICE, "#### (%s) [device] incompatible with device", nm_device_get_iface (self));
return FALSE;
+}
- return NM_DEVICE_GET_CLASS (self)->check_connection_available (self, connection, flags, specific_object);
+ avail = NM_DEVICE_GET_CLASS (self)->check_connection_available (self, connection, flags, specific_object);
+ if (!avail)
+ nm_log_info (LOGD_DEVICE, "#### (%s) [device] connection not available", nm_device_get_iface (self));
+ return avail;
}
static void
diff --git a/src/devices/wifi/nm-device-wifi.c b/src/devices/wifi/nm-device-wifi.c
index 0f7fb6e..0dc53b9 100644
--- a/src/devices/wifi/nm-device-wifi.c
+++ b/src/devices/wifi/nm-device-wifi.c
@@ -777,53 +777,84 @@ check_connection_compatible (NMDevice *device, NMConnection *connection)
const char *perm_hw_addr;
if (!NM_DEVICE_CLASS (nm_device_wifi_parent_class)->check_connection_compatible (device, connection))
+{
+ nm_log_info (LOGD_DEVICE, "#### (%s) [wifi compat] parent fail", nm_device_get_iface (device));
return FALSE;
+}
s_con = nm_connection_get_setting_connection (connection);
g_assert (s_con);
if (strcmp (nm_setting_connection_get_connection_type (s_con), NM_SETTING_WIRELESS_SETTING_NAME))
+{
+ nm_log_info (LOGD_DEVICE, "#### (%s) [wifi compat] not wifi", nm_device_get_iface (device));
return FALSE;
+}
s_wireless = nm_connection_get_setting_wireless (connection);
if (!s_wireless)
+{
+ nm_log_info (LOGD_DEVICE, "#### (%s) [wifi compat] no wireless setting", nm_device_get_iface (device));
return FALSE;
+}
perm_hw_addr = nm_device_get_permanent_hw_address (device);
mac = nm_setting_wireless_get_mac_address (s_wireless);
if (perm_hw_addr) {
if (mac && !nm_utils_hwaddr_matches (mac, -1, perm_hw_addr, -1))
+{
+ nm_log_info (LOGD_DEVICE, "#### (%s) [wifi compat] mac mismatch", nm_device_get_iface (device));
return FALSE;
+}
/* Check for MAC address blacklist */
mac_blacklist = nm_setting_wireless_get_mac_address_blacklist (s_wireless);
for (i = 0; mac_blacklist[i]; i++) {
if (!nm_utils_hwaddr_valid (mac_blacklist[i], ETH_ALEN)) {
g_warn_if_reached ();
+ nm_log_info (LOGD_DEVICE, "#### (%s) [wifi compat] mac blacklist entry invalid", nm_device_get_iface (device));
return FALSE;
}
if (nm_utils_hwaddr_matches (mac_blacklist[i], -1, perm_hw_addr, -1))
+{
+ nm_log_info (LOGD_DEVICE, "#### (%s) [wifi compat] mac blacklisted", nm_device_get_iface (device));
return FALSE;
+}
}
} else if (mac)
+{
+ nm_log_info (LOGD_DEVICE, "#### (%s) [wifi compat] mac required; no permaddr", nm_device_get_iface (device));
return FALSE;
+}
if (is_adhoc_wpa (connection))
+{
+ nm_log_info (LOGD_DEVICE, "#### (%s) [wifi compat] adhoc wpa", nm_device_get_iface (device));
return FALSE;
+}
/* Early exit if supplicant or device doesn't support requested mode */
mode = nm_setting_wireless_get_mode (s_wireless);
if (g_strcmp0 (mode, NM_SETTING_WIRELESS_MODE_ADHOC) == 0) {
if (!(priv->capabilities & NM_WIFI_DEVICE_CAP_ADHOC))
+{
+ nm_log_info (LOGD_DEVICE, "#### (%s) [wifi compat] adhoc unsupported", nm_device_get_iface (device));
return FALSE;
+}
} else if (g_strcmp0 (mode, NM_SETTING_WIRELESS_MODE_AP) == 0) {
if (!(priv->capabilities & NM_WIFI_DEVICE_CAP_AP))
+{
+ nm_log_info (LOGD_DEVICE, "#### (%s) [wifi compat] ap unsupported", nm_device_get_iface (device));
return FALSE;
+}
if (priv->sup_iface) {
if (nm_supplicant_interface_get_ap_support (priv->sup_iface) == AP_SUPPORT_NO)
+{
+ nm_log_info (LOGD_DEVICE, "#### (%s) [wifi compat] supplicant ap unsupported", nm_device_get_iface (device));
return FALSE;
+}
}
}
@@ -856,7 +887,14 @@ check_connection_available (NMDevice *device,
NMAccessPoint *ap;
ap = get_ap_by_path (NM_DEVICE_WIFI (device), specific_object);
- return ap ? nm_ap_check_compatible (ap, connection) : FALSE;
+ if (ap) {
+ gboolean compat = nm_ap_check_compatible (ap, connection);
+if (!compat)
+ nm_log_info (LOGD_DEVICE, "#### (%s) [wifi compat] specific object AP incompat with connection", nm_device_get_iface (device));
+ return compat;
+ }
+ nm_log_info (LOGD_DEVICE, "#### (%s) [wifi avail] specific object not found", nm_device_get_iface (device));
+ return FALSE;
}
/* Ad-Hoc and AP connections are always available because they may be
@@ -880,10 +918,20 @@ check_connection_available (NMDevice *device,
/* check if its visible */
for (ap_iter = priv->ap_list; ap_iter; ap_iter = g_slist_next (ap_iter)) {
+ const GByteArray *ssid = nm_ap_get_ssid (NM_AP (ap_iter->data));
+ char *tmp = ssid ? nm_utils_ssid_to_utf8 (ssid->data, ssid->len) : "<none>";
+
+ nm_log_info (LOGD_DEVICE, "#### (%s) [wifi compat] checking AP '%s'", nm_device_get_iface (device), tmp);
if (nm_ap_check_compatible (NM_AP (ap_iter->data), connection))
+{
+ nm_log_info (LOGD_DEVICE, "#### (%s) [wifi compat] AP '%s' compatible", nm_device_get_iface (device), tmp);
+g_free (tmp);
return TRUE;
+}
+ nm_log_info (LOGD_DEVICE, "#### (%s) [wifi compat] AP '%s' incompatible with connection", nm_device_get_iface (device), tmp);
}
+ nm_log_info (LOGD_DEVICE, "#### (%s) [wifi compat] no compatible AP found", nm_device_get_iface (device));
return FALSE;
}
@@ -1140,7 +1188,10 @@ can_auto_connect (NMDevice *device,
guint64 timestamp = 0;
if (!NM_DEVICE_CLASS (nm_device_wifi_parent_class)->can_auto_connect (device, connection, specific_object))
+{
+nm_log_info (LOGD_DEVICE, "#### (%s) [wifi] parent can_auto_connect() fail", nm_device_get_iface (device));
return FALSE;
+}
s_wifi = nm_connection_get_setting_wireless (connection);
g_return_val_if_fail (s_wifi, FALSE);
@@ -1160,19 +1211,29 @@ can_auto_connect (NMDevice *device,
*/
if (nm_settings_connection_get_timestamp (NM_SETTINGS_CONNECTION (connection), ×tamp)) {
if (timestamp == 0)
+{
+nm_log_info (LOGD_DEVICE, "#### (%s) [wifi] zero timestamp", nm_device_get_iface (device));
return FALSE;
+}
}
for (ap_iter = priv->ap_list; ap_iter; ap_iter = g_slist_next (ap_iter)) {
NMAccessPoint *ap = NM_AP (ap_iter->data);
+ const GByteArray *ssid = nm_ap_get_ssid (ap);
+ char *tmp = ssid ? nm_utils_ssid_to_utf8 (ssid->data, ssid->len) : "<none>";
+nm_log_info (LOGD_DEVICE, "#### (%s) [wifi] (checking %s)", nm_device_get_iface (device), tmp);
if (nm_ap_check_compatible (ap, connection)) {
/* All good; connection is usable */
*specific_object = (char *) nm_ap_get_dbus_path (ap);
+ g_free (tmp);
return TRUE;
}
+nm_log_info (LOGD_DEVICE, "#### (%s) [wifi] (%s incompatible with connection)", nm_device_get_iface (device), tmp);
+ g_free (tmp);
}
+nm_log_info (LOGD_DEVICE, "#### (%s) [wifi] no compatible AP", nm_device_get_iface (device));
return FALSE;
}
diff --git a/src/nm-policy.c b/src/nm-policy.c
index fc2a9bf..cb886f0 100644
--- a/src/nm-policy.c
+++ b/src/nm-policy.c
@@ -650,16 +650,24 @@ auto_activate_device (gpointer user_data)
data->autoactivate_id = 0;
+ nm_log_info (LOGD_DEVICE, "#### (%s) autoactivate attempt", nm_device_get_iface (data->device));
+
// FIXME: if a device is already activating (or activated) with a connection
// but another connection now overrides the current one for that device,
// deactivate the device and activate the new connection instead of just
// bailing if the device is already active
if (nm_device_get_act_request (data->device))
+{
+ nm_log_info (LOGD_DEVICE, "#### (%s) autoactivate fail; already activating", nm_device_get_iface (data->device));
goto out;
+}
connection_list = nm_manager_get_activatable_connections (priv->manager);
if (!connection_list)
+{
+ nm_log_info (LOGD_DEVICE, "#### (%s) autoactivate fail; no activatable connections", nm_device_get_iface (data->device));
goto out;
+}
connections = _nm_utils_copy_slist_to_array (connection_list, NULL, NULL);
g_slist_free (connection_list);
@@ -668,17 +676,29 @@ auto_activate_device (gpointer user_data)
* with same priority are still sorted by last-connected-timestamp. */
g_ptr_array_sort (connections, (GCompareFunc) nm_utils_cmp_connection_by_autoconnect_priority);
+if (!nm_device_autoconnect_allowed (data->device))
+ nm_log_info (LOGD_DEVICE, "#### (%s) autoactivate fail; device autoconnect blocked", nm_device_get_iface (data->device));
+
/* Find the first connection that should be auto-activated */
best_connection = NULL;
for (i = 0; i < connections->len; i++) {
NMSettingsConnection *candidate = NM_SETTINGS_CONNECTION (connections->pdata[i]);
+ nm_log_info (LOGD_DEVICE, "#### (%s) autoactivate candidate '%s'", nm_device_get_iface (data->device), nm_connection_get_id (NM_CONNECTION (candidate)));
+
if (!nm_settings_connection_can_autoconnect (candidate))
+{
+ nm_log_info (LOGD_DEVICE, "#### (%s) not auto-activate", nm_device_get_iface (data->device));
continue;
+}
if (nm_device_can_auto_connect (data->device, (NMConnection *) candidate, &specific_object)) {
+ nm_log_info (LOGD_DEVICE, "#### (%s) BEST", nm_device_get_iface (data->device));
best_connection = (NMConnection *) candidate;
break;
}
+else {
+ nm_log_info (LOGD_DEVICE, "#### (%s) can't autoconnect", nm_device_get_iface (data->device));
+}
}
g_ptr_array_free (connections, TRUE);
@@ -703,6 +723,8 @@ auto_activate_device (gpointer user_data)
}
g_object_unref (subject);
}
+else
+ nm_log_info (LOGD_DEVICE, "#### (%s) autoactivate fail; no best connection", nm_device_get_iface (data->device));
out:
activate_data_free (data);
_______________________________________________
networkmanager-list mailing list
[email protected]
https://mail.gnome.org/mailman/listinfo/networkmanager-list
