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>'? Also, 'iw dev mlan0 scan dump', find the block for the expected AP, and report that. Feel free to replace the BSSID with xs or something if you want to hide it. My best guess is a mismatch between the AP's beacon/properties and the connection somehow. Dan > Below is the debug log output when Network Manager 1.0.12 is not auto > reconnecting. The Wi-Fi client (mlan0) is scanning for access points > every 60 seconds, but the autoactivate attempt only happens every 5 > minutes but then appears to immediately remove the pending action of > autoactivate on the mlan0 interface. At the same time the cellular > connection is attempting to connect and can't connect because of bad > signal strength. > > May 18 14:33:31 canect2 daemon.info NetworkManager[245]: <debug> > [1495118011.701118] [devices/nm-device.c:7019] > nm_device_add_pending_action(): [0x213c268] (mlan0): > add_pending_action (1): 'scan' > May 18 14:33:31 canect2 daemon.info NetworkManager[245]: <debug> > [1495118011.702526] [devices/nm-device.c:7052] > nm_device_remove_pending_action(): [0x213c268] (mlan0): > remove_pending_action (0): 'scan' > May 18 14:33:31 canect2 user.alert kernel: [149885.509332] wlan: > mlan0 START SCAN > May 18 14:33:33 canect2 daemon.info ModemManager[423]: <info> Modem > /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state > changed (idle -> searching) > May 18 14:33:33 canect2 daemon.info NetworkManager[245]: <debug> > [1495118013.317075] [platform/nm-linux-platform.c:1950] > event_notification(): netlink event (type 16) for link: mlan0 (6, > family 0) > May 18 14:33:33 canect2 daemon.info NetworkManager[245]: <debug> > [1495118013.317486] [platform/nm-linux-platform.c:426] > get_kernel_object(): get_kernel_object for link: mlan0 (6, family 0) > May 18 14:33:33 canect2 daemon.info NetworkManager[245]: <debug> > [1495118013.318059] [platform/nm-linux-platform.c:1950] > event_notification(): netlink event (type 16) for link: mlan0 (6, > family 0) > May 18 14:33:33 canect2 daemon.info NetworkManager[245]: <debug> > [1495118013.318402] [platform/nm-linux-platform.c:426] > get_kernel_object(): get_kernel_object for link: mlan0 (6, family 0) > May 18 14:33:33 canect2 user.warn kernel: [149887.121037] wlan: SCAN > COMPLETED: scanned AP count=12 > May 18 14:33:33 canect2 user.err kernel: [149887.134455] Invalid > sched_scan req parameter > May 18 14:33:47 canect2 daemon.info ModemManager[423]: <info> Modem > /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state > changed (searching -> idle) > May 18 14:33:52 canect2 daemon.info ModemManager[423]: <info> Modem > /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state > changed (idle -> searching) > May 18 14:33:52 canect2 daemon.info ModemManager[423]: <info> Modem > /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state > changed (searching -> idle) > May 18 14:33:57 canect2 daemon.info ModemManager[423]: <info> Modem > /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state > changed (idle -> searching) > May 18 14:33:57 canect2 daemon.info ModemManager[423]: <info> Modem > /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state > changed (searching -> idle) > May 18 14:34:02 canect2 daemon.info ModemManager[423]: <info> Modem > /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state > changed (idle -> searching) > May 18 14:34:03 canect2 daemon.info ModemManager[423]: <info> Modem > /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state > changed (searching -> idle) > May 18 14:34:08 canect2 daemon.info ModemManager[423]: <info> Modem > /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state > changed (idle -> searching) > May 18 14:34:08 canect2 daemon.info ModemManager[423]: <info> Modem > /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state > changed (searching -> idle) > May 18 14:34:12 canect2 daemon.info NetworkManager[245]: <debug> > [1495118052.692978] [devices/nm-device.c:7019] > nm_device_add_pending_action(): [0x213c268] (mlan0): > add_pending_action (1): 'autoactivate' > May 18 14:34:12 canect2 daemon.info NetworkManager[245]: <debug> > [1495118052.693286] [devices/nm-device.c:7019] > nm_device_add_pending_action(): [0x21602f0] (ttyACM0): > add_pending_action (1): 'autoactivate' > May 18 14:34:12 canect2 daemon.info NetworkManager[245]: <debug> > [1495118052.694239] [devices/nm-device.c:7052] > nm_device_remove_pending_action(): [0x213c268] (mlan0): > remove_pending_action (0): 'autoactivate' > May 18 14:34:12 canect2 daemon.info NetworkManager[245]: > <info> Auto-activating connection 'Aeris'. > May 18 14:34:12 canect2 daemon.info NetworkManager[245]: <debug> > [1495118052.695397] [devices/nm-device.c:7019] > nm_device_add_pending_action(): [0x21602f0] (ttyACM0): > add_pending_action (2): 'activation::0x214ead8' > May 18 14:34:12 canect2 daemon.info NetworkManager[245]: <debug> > [1495118052.696054] [devices/nm-device.c:7052] > nm_device_remove_pending_action(): [0x21602f0] (ttyACM0): > remove_pending_action (1): 'autoactivate' > May 18 14:34:12 canect2 daemon.info NetworkManager[245]: > <info> (ttyACM0): Activation: starting connection 'Aeris' > May 18 14:34:12 canect2 daemon.info NetworkManager[245]: > <info> (ttyACM0): Activation: Stage 1 of 5 (Device Prepare) > scheduled... > May 18 14:34:12 canect2 daemon.info NetworkManager[245]: > <info> (ttyACM0): Activation: Stage 1 of 5 (Device Prepare) > started... > May 18 14:34:12 canect2 daemon.info NetworkManager[245]: > <info> (ttyACM0): device state change: disconnected -> prepare > (reason 'none') [30 40 0] > May 18 14:34:12 canect2 daemon.info NetworkManager[245]: > <info> NetworkManager state is now CONNECTING > May 18 14:34:12 canect2 daemon.info NetworkManager[245]: <debug> > [1495118052.703566] [nm-active-connection.c:480] > check_master_ready(): (0x214ead8): not signalling master-ready (no > master) > May 18 14:34:12 canect2 daemon.info NetworkManager[245]: <debug> > [1495118052.704510] [devices/nm-device.c:7019] > nm_device_add_pending_action(): [0x213c268] (mlan0): > add_pending_action (1): 'autoactivate' > May 18 14:34:12 canect2 daemon.info NetworkManager[245]: <debug> > [1495118052.705149] [nm-manager.c:4328] > policy_activating_device_changed(): ActivatingConnection now Aeris > May 18 14:34:12 canect2 daemon.info ModemManager[423]: <info> Simple > connect started... > May 18 14:34:12 canect2 daemon.info ModemManager[423]: <info> Simple > connect state (4/8): Wait to get fully enabled > May 18 14:34:12 canect2 daemon.info ModemManager[423]: <info> Simple > connect state (5/8): Register > May 18 14:34:12 canect2 daemon.info NetworkManager[245]: > <info> (ttyACM0): Activation: Stage 1 of 5 (Device Prepare) > complete. > May 18 14:34:12 canect2 daemon.info NetworkManager[245]: <debug> > [1495118052.719481] [devices/nm-device.c:7052] > nm_device_remove_pending_action(): [0x213c268] (mlan0): > remove_pending_action (0): 'autoactivate' > May 18 14:34:26 canect2 daemon.warn NetworkManager[245]: > <warn> (ttyACM0) failed to connect modem: Network timeout > May 18 14:34:26 canect2 daemon.info NetworkManager[245]: > <info> (ttyACM0): device state change: prepare -> failed (reason > 'gsm-registration-timeout') [40 120 32] > May 18 14:34:26 canect2 daemon.info NetworkManager[245]: > <info> NetworkManager state is now DISCONNECTED > May 18 14:34:26 canect2 daemon.info NetworkManager[245]: <debug> > [1495118066.815371] [nm-active-connection.c:476] > check_master_ready(): (0x214ead8): not signalling master-ready (not > activating) > May 18 14:34:26 canect2 daemon.info NetworkManager[245]: <debug> > [1495118066.815498] [devices/nm-device.c:7052] > nm_device_remove_pending_action(): [0x21602f0] (ttyACM0): > remove_pending_action (0): 'activation::0x214ead8' > May 18 14:34:26 canect2 daemon.info NetworkManager[245]: <debug> > [1495118066.821710] [nm-policy.c:1125] device_state_changed(): > Connection 'Aeris' failed to autoconnect; 4 tries left > May 18 14:34:26 canect2 daemon.info NetworkManager[245]: <debug> > [1495118066.823492] [nm-manager.c:4328] > policy_activating_device_changed(): ActivatingConnection now (none) > May 18 14:34:26 canect2 daemon.warn NetworkManager[245]: > <warn> (ttyACM0): Activation: failed for connection 'Aeris' > May 18 14:34:26 canect2 daemon.info NetworkManager[245]: <debug> > [1495118066.824589] [devices/nm-device.c:7019] > nm_device_add_pending_action(): [0x21602f0] (ttyACM0): > add_pending_action (1): 'queued state change to disconnected' > May 18 14:34:26 canect2 daemon.info NetworkManager[245]: <debug> > [1495118066.824887] [devices/nm-device.c:7768] > nm_device_queue_state(): [0x21602f0] (ttyACM0): queued state change > to disconnected due to none (id 100254) > May 18 14:34:26 canect2 daemon.info NetworkManager[245]: <debug> > [1495118066.830540] [devices/nm-device.c:7717] queued_set_state(): > [0x21602f0] (ttyACM0): running queued state change to disconnected > (id 100254) > May 18 14:34:26 canect2 daemon.info NetworkManager[245]: > <info> (ttyACM0): device state change: failed -> disconnected > (reason 'none') [120 30 0] > May 18 14:34:26 canect2 daemon.info NetworkManager[245]: > <info> (ttyACM0): deactivating device (reason 'none') [0] > May 18 14:34:26 canect2 daemon.info NetworkManager[245]: <debug> > [1495118066.831611] [nm-firewall-manager.c:256] > nm_firewall_manager_remove_from_zone(): (ttyACM0) firewall zone > remove skipped (not running) > May 18 14:34:26 canect2 daemon.info NetworkManager[245]: <debug> > [1495118066.831838] [devices/nm-device.c:7066] > nm_device_remove_pending_action(): [0x21602f0] (ttyACM0): > remove_pending_action (1): 'dhcp6' not pending (expected) > May 18 14:34:26 canect2 daemon.info NetworkManager[245]: <debug> > [1495118066.832001] [devices/nm-device.c:7066] > nm_device_remove_pending_action(): [0x21602f0] (ttyACM0): > remove_pending_action (1): 'autoconf6' not pending (expected) > May 18 14:34:26 canect2 daemon.info NetworkManager[245]: <debug> > [1495118066.832268] [platform/nm-linux-platform.c:2085] sysctl_set(): > sysctl: failed to open '/proc/sys/net/ipv6/conf/ttyACM0/accept_ra': > (2) No such file or directory > May 18 14:34:26 canect2 daemon.info NetworkManager[245]: <debug> > [1495118066.833005] [platform/nm-linux-platform.c:2085] sysctl_set(): > sysctl: failed to open > '/proc/sys/net/ipv6/conf/ttyACM0/use_tempaddr': (2) No such file or > directory > May 18 14:34:26 canect2 daemon.info NetworkManager[245]: <debug> > [1495118066.834941] [dns-manager/nm-dns-manager.c:1005] > nm_dns_manager_begin_updates(): (update_routing_and_dns): queueing > DNS updates (1) > May 18 14:34:26 canect2 daemon.info NetworkManager[245]: <debug> > [1495118066.835743] [dns-manager/nm-dns-manager.c:1023] > nm_dns_manager_end_updates(): (nm_dns_manager_end_updates): DNS > configuration did not change > May 18 14:34:26 canect2 daemon.info NetworkManager[245]: <debug> > [1495118066.835996] [dns-manager/nm-dns-manager.c:1027] > nm_dns_manager_end_updates(): (update_routing_and_dns): no DNS > changes to commit (0) > May 18 14:34:26 canect2 daemon.info NetworkManager[245]: <debug> > [1495118066.836210] [devices/nm-device.c:7019] > nm_device_add_pending_action(): [0x21602f0] (ttyACM0): > add_pending_action (2): 'autoactivate' > May 18 14:34:26 canect2 daemon.info NetworkManager[245]: <debug> > [1495118066.836591] [devices/nm-device.c:7052] > nm_device_remove_pending_action(): [0x21602f0] (ttyACM0): > remove_pending_action (1): 'queued state change to disconnected' > May 18 14:34:26 canect2 daemon.info NetworkManager[245]: > <info> Auto-activating connection 'Aeris'. > May 18 14:34:26 canect2 daemon.info NetworkManager[245]: <debug> > [1495118066.841524] [devices/nm-device.c:7019] > nm_device_add_pending_action(): [0x21602f0] (ttyACM0): > add_pending_action (2): 'activation::0x214ea68' > May 18 14:34:26 canect2 daemon.info NetworkManager[245]: <debug> > [1495118066.842155] [devices/nm-device.c:7052] > nm_device_remove_pending_action(): [0x21602f0] (ttyACM0): > remove_pending_action (1): 'autoactivate' > May 18 14:34:26 canect2 daemon.info NetworkManager[245]: > <info> (ttyACM0): Activation: starting connection 'Aeris' > May 18 14:34:26 canect2 daemon.info NetworkManager[245]: > <info> (ttyACM0): Activation: Stage 1 of 5 (Device Prepare) > scheduled... > May 18 14:34:26 canect2 daemon.info NetworkManager[245]: > <info> (ttyACM0): Activation: Stage 1 of 5 (Device Prepare) > started... > May 18 14:34:26 canect2 daemon.info NetworkManager[245]: > <info> (ttyACM0): device state change: disconnected -> prepare > (reason 'none') [30 40 0] > May 18 14:34:26 canect2 daemon.info NetworkManager[245]: > <info> NetworkManager state is now CONNECTING > May 18 14:34:26 canect2 daemon.info NetworkManager[245]: <debug> > [1495118066.849794] [nm-active-connection.c:480] > check_master_ready(): (0x214ea68): not signalling master-ready (no > master) > May 18 14:34:26 canect2 daemon.info NetworkManager[245]: <debug> > [1495118066.850420] [devices/nm-device.c:7019] > nm_device_add_pending_action(): [0x213c268] (mlan0): > add_pending_action (1): 'autoactivate' > May 18 14:34:26 canect2 daemon.info NetworkManager[245]: <debug> > [1495118066.851354] [nm-manager.c:4328] > policy_activating_device_changed(): ActivatingConnection now Aeris > May 18 14:34:26 canect2 daemon.info ModemManager[423]: <info> Simple > connect started... > May 18 14:34:26 canect2 daemon.info ModemManager[423]: <info> Simple > connect state (4/8): Wait to get fully enabled > May 18 14:34:26 canect2 daemon.info ModemManager[423]: <info> Simple > connect state (5/8): Register > May 18 14:34:26 canect2 daemon.info NetworkManager[245]: > <info> (ttyACM0): Activation: Stage 1 of 5 (Device Prepare) > complete. > May 18 14:34:26 canect2 daemon.info NetworkManager[245]: <debug> > [1495118066.865174] [devices/nm-device.c:7052] > nm_device_remove_pending_action(): [0x213c268] (mlan0): > remove_pending_action (0): 'autoactivate' > May 18 14:34:34 canect2 daemon.info NetworkManager[245]: <debug> > [1495118074.699024] [devices/nm-device.c:7019] > nm_device_add_pending_action(): [0x213c268] (mlan0): > add_pending_action (1): 'scan' > May 18 14:34:34 canect2 daemon.info NetworkManager[245]: <debug> > [1495118074.706568] [devices/nm-device.c:7052] > nm_device_remove_pending_action(): [0x213c268] (mlan0): > remove_pending_action (0): 'scan' > May 18 14:34:34 canect2 user.alert kernel: [149948.513688] wlan: > mlan0 START SCAN > May 18 14:34:36 canect2 daemon.info NetworkManager[245]: <debug> > [1495118076.319880] [platform/nm-linux-platform.c:1950] > event_notification(): netlink event (type 16) for link: mlan0 (6, > family 0) > May 18 14:34:36 canect2 daemon.info NetworkManager[245]: <debug> > [1495118076.320455] [platform/nm-linux-platform.c:426] > get_kernel_object(): get_kernel_object for link: mlan0 (6, family 0) > May 18 14:34:36 canect2 user.warn kernel: [149950.125867] wlan: SCAN > COMPLETED: scanned AP count=13 > May 18 14:34:36 canect2 daemon.info NetworkManager[245]: <debug> > [1495118076.323873] [platform/nm-linux-platform.c:1950] > event_notification(): netlink event (type 16) for link: mlan0 (6, > family 0) > May 18 14:34:36 canect2 daemon.info NetworkManager[245]: <debug> > [1495118076.324530] [platform/nm-linux-platform.c:426] > get_kernel_object(): get_kernel_object for link: mlan0 (6, family 0) > May 18 14:34:36 canect2 user.err kernel: [149950.149321] Invalid > sched_scan req parameter > May 18 14:34:42 canect2 daemon.warn NetworkManager[245]: > <warn> (ttyACM0) failed to connect modem: Network timeout > May 18 14:34:42 canect2 daemon.info NetworkManager[245]: > <info> (ttyACM0): device state change: prepare -> failed (reason > 'gsm-registration-timeout') [40 120 32] > May 18 14:34:42 canect2 daemon.info NetworkManager[245]: > <info> NetworkManager state is now DISCONNECTED > May 18 14:34:42 canect2 daemon.info NetworkManager[245]: <debug> > [1495118082.304548] [nm-active-connection.c:476] > check_master_ready(): (0x214ea68): not signalling master-ready (not > activating) > May 18 14:34:42 canect2 daemon.info NetworkManager[245]: <debug> > [1495118082.306184] [devices/nm-device.c:7052] > nm_device_remove_pending_action(): [0x21602f0] (ttyACM0): > remove_pending_action (0): 'activation::0x214ea68' > May 18 14:34:42 canect2 daemon.info NetworkManager[245]: <debug> > [1495118082.311499] [nm-policy.c:1125] device_state_changed(): > Connection 'Aeris' failed to autoconnect; 3 tries left > May 18 14:34:42 canect2 daemon.info NetworkManager[245]: <debug> > [1495118082.313228] [nm-manager.c:4328] > policy_activating_device_changed(): ActivatingConnection now (none) > May 18 14:34:42 canect2 daemon.warn NetworkManager[245]: > <warn> (ttyACM0): Activation: failed for connection 'Aeris' > May 18 14:34:42 canect2 daemon.info NetworkManager[245]: <debug> > [1495118082.314330] [devices/nm-device.c:7019] > nm_device_add_pending_action(): [0x21602f0] (ttyACM0): > add_pending_action (1): 'queued state change to disconnected' > May 18 14:34:42 canect2 daemon.info NetworkManager[245]: <debug> > [1495118082.314601] [devices/nm-device.c:7768] > nm_device_queue_state(): [0x21602f0] (ttyACM0): queued state change > to disconnected due to none (id 100296) > May 18 14:34:42 canect2 daemon.info NetworkManager[245]: <debug> > [1495118082.320755] [devices/nm-device.c:7717] queued_set_state(): > [0x21602f0] (ttyACM0): running queued state change to disconnected > (id 100296) > May 18 14:34:42 canect2 daemon.info NetworkManager[245]: > <info> (ttyACM0): device state change: failed -> disconnected > (reason 'none') [120 30 0] > May 18 14:34:42 canect2 daemon.info NetworkManager[245]: > <info> (ttyACM0): deactivating device (reason 'none') [0] > May 18 14:34:42 canect2 daemon.info NetworkManager[245]: <debug> > [1495118082.321522] [nm-firewall-manager.c:256] > nm_firewall_manager_remove_from_zone(): (ttyACM0) firewall zone > remove skipped (not running) > May 18 14:34:42 canect2 daemon.info NetworkManager[245]: <debug> > [1495118082.321699] [devices/nm-device.c:7066] > nm_device_remove_pending_action(): [0x21602f0] (ttyACM0): > remove_pending_action (1): 'dhcp6' not pending (expected) > May 18 14:34:42 canect2 daemon.info NetworkManager[245]: <debug> > [1495118082.322312] [devices/nm-device.c:7066] > nm_device_remove_pending_action(): [0x21602f0] (ttyACM0): > remove_pending_action (1): 'autoconf6' not pending (expected) > May 18 14:34:42 canect2 daemon.info NetworkManager[245]: <debug> > [1495118082.322615] [platform/nm-linux-platform.c:2085] sysctl_set(): > sysctl: failed to open '/proc/sys/net/ipv6/conf/ttyACM0/accept_ra': > (2) No such file or directory > May 18 14:34:42 canect2 daemon.info NetworkManager[245]: <debug> > [1495118082.322898] [platform/nm-linux-platform.c:2085] sysctl_set(): > sysctl: failed to open > '/proc/sys/net/ipv6/conf/ttyACM0/use_tempaddr': (2) No such file or > directory > May 18 14:34:42 canect2 daemon.info NetworkManager[245]: <debug> > [1495118082.325179] [dns-manager/nm-dns-manager.c:1005] > nm_dns_manager_begin_updates(): (update_routing_and_dns): queueing > DNS updates (1) > May 18 14:34:42 canect2 daemon.info NetworkManager[245]: <debug> > [1495118082.325639] [dns-manager/nm-dns-manager.c:1023] > nm_dns_manager_end_updates(): (nm_dns_manager_end_updates): DNS > configuration did not change > May 18 14:34:42 canect2 daemon.info NetworkManager[245]: <debug> > [1495118082.325856] [dns-manager/nm-dns-manager.c:1027] > nm_dns_manager_end_updates(): (update_routing_and_dns): no DNS > changes to commit (0) > May 18 14:34:42 canect2 daemon.info NetworkManager[245]: <debug> > [1495118082.326468] [devices/nm-device.c:7019] > nm_device_add_pending_action(): [0x21602f0] (ttyACM0): > add_pending_action (2): 'autoactivate' > May 18 14:34:42 canect2 daemon.info NetworkManager[245]: <debug> > [1495118082.326925] [devices/nm-device.c:7052] > nm_device_remove_pending_action(): [0x21602f0] (ttyACM0): > remove_pending_action (1): 'queued state change to disconnected' > May 18 14:34:42 canect2 daemon.info NetworkManager[245]: > <info> Auto-activating connection 'Aeris'. > May 18 14:34:42 canect2 daemon.info NetworkManager[245]: <debug> > [1495118082.331420] [devices/nm-device.c:7019] > nm_device_add_pending_action(): [0x21602f0] (ttyACM0): > add_pending_action (2): 'activation::0x214ecb0' > May 18 14:34:42 canect2 daemon.info NetworkManager[245]: <debug> > [1495118082.332443] [devices/nm-device.c:7052] > nm_device_remove_pending_action(): [0x21602f0] (ttyACM0): > remove_pending_action (1): 'autoactivate' > May 18 14:34:42 canect2 daemon.info NetworkManager[245]: > <info> (ttyACM0): Activation: starting connection 'Aeris' > May 18 14:34:42 canect2 daemon.info NetworkManager[245]: > <info> (ttyACM0): Activation: Stage 1 of 5 (Device Prepare) > scheduled... > May 18 14:34:42 canect2 daemon.info NetworkManager[245]: > <info> (ttyACM0): Activation: Stage 1 of 5 (Device Prepare) > started... > May 18 14:34:42 canect2 daemon.info NetworkManager[245]: > <info> (ttyACM0): device state change: disconnected -> prepare > (reason 'none') [30 40 0] > May 18 14:34:42 canect2 daemon.info NetworkManager[245]: > <info> NetworkManager state is now CONNECTING > May 18 14:34:42 canect2 daemon.info NetworkManager[245]: <debug> > [1495118082.339800] [nm-active-connection.c:480] > check_master_ready(): (0x214ecb0): not signalling master-ready (no > master) > May 18 14:34:42 canect2 daemon.info NetworkManager[245]: <debug> > [1495118082.340892] [devices/nm-device.c:7019] > nm_device_add_pending_action(): [0x213c268] (mlan0): > add_pending_action (1): 'autoactivate' > May 18 14:34:42 canect2 daemon.info NetworkManager[245]: <debug> > [1495118082.341418] [nm-manager.c:4328] > policy_activating_device_changed(): ActivatingConnection now Aeris > May 18 14:34:42 canect2 daemon.info ModemManager[423]: <info> Simple > connect started... > May 18 14:34:42 canect2 daemon.info ModemManager[423]: <info> Simple > connect state (4/8): Wait to get fully enabled > May 18 14:34:42 canect2 daemon.info ModemManager[423]: <info> Simple > connect state (5/8): Register > May 18 14:34:42 canect2 daemon.info NetworkManager[245]: > <info> (ttyACM0): Activation: Stage 1 of 5 (Device Prepare) > complete. > May 18 14:34:42 canect2 daemon.info NetworkManager[245]: <debug> > [1495118082.355410] [devices/nm-device.c:7052] > nm_device_remove_pending_action(): [0x213c268] (mlan0): > remove_pending_action (0): 'autoactivate' > May 18 14:34:57 canect2 daemon.warn NetworkManager[245]: > <warn> (ttyACM0) failed to connect modem: Network timeout > May 18 14:34:57 canect2 daemon.info NetworkManager[245]: > <info> (ttyACM0): device state change: prepare -> failed (reason > 'gsm-registration-timeout') [40 120 32] > May 18 14:34:57 canect2 daemon.info NetworkManager[245]: > <info> NetworkManager state is now DISCONNECTED > May 18 14:34:57 canect2 daemon.info NetworkManager[245]: <debug> > [1495118097.743190] [nm-active-connection.c:476] > check_master_ready(): (0x214ecb0): not signalling master-ready (not > activating) > May 18 14:34:57 canect2 daemon.info NetworkManager[245]: <debug> > [1495118097.743312] [devices/nm-device.c:7052] > nm_device_remove_pending_action(): [0x21602f0] (ttyACM0): > remove_pending_action (0): 'activation::0x214ecb0' > May 18 14:34:57 canect2 daemon.info NetworkManager[245]: <debug> > [1495118097.750386] [nm-policy.c:1125] device_state_changed(): > Connection 'Aeris' failed to autoconnect; 2 tries left > May 18 14:34:57 canect2 daemon.info NetworkManager[245]: <debug> > [1495118097.752532] [nm-manager.c:4328] > policy_activating_device_changed(): ActivatingConnection now (none) > May 18 14:34:57 canect2 daemon.warn NetworkManager[245]: > <warn> (ttyACM0): Activation: failed for connection 'Aeris' > May 18 14:34:57 canect2 daemon.info NetworkManager[245]: <debug> > [1495118097.753897] [devices/nm-device.c:7019] > nm_device_add_pending_action(): [0x21602f0] (ttyACM0): > add_pending_action (1): 'queued state change to disconnected' > May 18 14:34:57 canect2 daemon.info NetworkManager[245]: <debug> > [1495118097.754295] [devices/nm-device.c:7768] > nm_device_queue_state(): [0x21602f0] (ttyACM0): queued state change > to disconnected due to none (id 100317) > May 18 14:34:57 canect2 daemon.info NetworkManager[245]: <debug> > [1495118097.761287] [devices/nm-device.c:7717] queued_set_state(): > [0x21602f0] (ttyACM0): running queued state change to disconnected > (id 100317) > May 18 14:34:57 canect2 daemon.info NetworkManager[245]: > <info> (ttyACM0): device state change: failed -> disconnected > (reason 'none') [120 30 0] > May 18 14:34:57 canect2 daemon.info NetworkManager[245]: > <info> (ttyACM0): deactivating device (reason 'none') [0] > May 18 14:34:57 canect2 daemon.info NetworkManager[245]: <debug> > [1495118097.762605] [nm-firewall-manager.c:256] > nm_firewall_manager_remove_from_zone(): (ttyACM0) firewall zone > remove skipped (not running) > May 18 14:34:57 canect2 daemon.info NetworkManager[245]: <debug> > [1495118097.762945] [devices/nm-device.c:7066] > nm_device_remove_pending_action(): [0x21602f0] (ttyACM0): > remove_pending_action (1): 'dhcp6' not pending (expected) > May 18 14:34:57 canect2 daemon.info NetworkManager[245]: <debug> > [1495118097.763152] [devices/nm-device.c:7066] > nm_device_remove_pending_action(): [0x21602f0] (ttyACM0): > remove_pending_action (1): 'autoconf6' not pending (expected) > May 18 14:34:57 canect2 daemon.info NetworkManager[245]: <debug> > [1495118097.763869] [platform/nm-linux-platform.c:2085] sysctl_set(): > sysctl: failed to open '/proc/sys/net/ipv6/conf/ttyACM0/accept_ra': > (2) No such file or directory > May 18 14:34:57 canect2 daemon.info NetworkManager[245]: <debug> > [1495118097.764264] [platform/nm-linux-platform.c:2085] sysctl_set(): > sysctl: failed to open > '/proc/sys/net/ipv6/conf/ttyACM0/use_tempaddr': (2) No such file or > directory > May 18 14:34:57 canect2 daemon.info NetworkManager[245]: <debug> > [1495118097.766860] [dns-manager/nm-dns-manager.c:1005] > nm_dns_manager_begin_updates(): (update_routing_and_dns): queueing > DNS updates (1) > May 18 14:34:57 canect2 daemon.info NetworkManager[245]: <debug> > [1495118097.767372] [dns-manager/nm-dns-manager.c:1023] > nm_dns_manager_end_updates(): (nm_dns_manager_end_updates): DNS > configuration did not change > May 18 14:34:57 canect2 daemon.info NetworkManager[245]: <debug> > [1495118097.768067] [dns-manager/nm-dns-manager.c:1027] > nm_dns_manager_end_updates(): (update_routing_and_dns): no DNS > changes to commit (0) > May 18 14:34:57 canect2 daemon.info NetworkManager[245]: <debug> > [1495118097.768387] [devices/nm-device.c:7019] > nm_device_add_pending_action(): [0x21602f0] (ttyACM0): > add_pending_action (2): 'autoactivate' > May 18 14:34:57 canect2 daemon.info NetworkManager[245]: <debug> > [1495118097.768927] [devices/nm-device.c:7052] > nm_device_remove_pending_action(): [0x21602f0] (ttyACM0): > remove_pending_action (1): 'queued state change to disconnected' > May 18 14:34:57 canect2 daemon.info NetworkManager[245]: > <info> Auto-activating connection 'Aeris'. > May 18 14:34:57 canect2 daemon.info NetworkManager[245]: <debug> > [1495118097.774851] [devices/nm-device.c:7019] > nm_device_add_pending_action(): [0x21602f0] (ttyACM0): > add_pending_action (2): 'activation::0x214ed20' > May 18 14:34:57 canect2 daemon.info NetworkManager[245]: <debug> > [1495118097.775661] [devices/nm-device.c:7052] > nm_device_remove_pending_action(): [0x21602f0] (ttyACM0): > remove_pending_action (1): 'autoactivate' > May 18 14:34:57 canect2 daemon.info NetworkManager[245]: > <info> (ttyACM0): Activation: starting connection 'Aeris' > May 18 14:34:57 canect2 daemon.info NetworkManager[245]: > <info> (ttyACM0): Activation: Stage 1 of 5 (Device Prepare) > scheduled... > May 18 14:34:57 canect2 daemon.info NetworkManager[245]: > <info> (ttyACM0): Activation: Stage 1 of 5 (Device Prepare) > started... > May 18 14:34:57 canect2 daemon.info NetworkManager[245]: > <info> (ttyACM0): device state change: disconnected -> prepare > (reason 'none') [30 40 0] > May 18 14:34:57 canect2 daemon.info NetworkManager[245]: > <info> NetworkManager state is now CONNECTING > May 18 14:34:57 canect2 daemon.info NetworkManager[245]: <debug> > [1495118097.785006] [nm-active-connection.c:480] > check_master_ready(): (0x214ed20): not signalling master-ready (no > master) > May 18 14:34:57 canect2 daemon.info NetworkManager[245]: <debug> > [1495118097.786105] [devices/nm-device.c:7019] > nm_device_add_pending_action(): [0x213c268] (mlan0): > add_pending_action (1): 'autoactivate' > May 18 14:34:57 canect2 daemon.info NetworkManager[245]: <debug> > [1495118097.786794] [nm-manager.c:4328] > policy_activating_device_changed(): ActivatingConnection now Aeris > May 18 14:34:57 canect2 daemon.info ModemManager[423]: <info> Simple > connect started... > May 18 14:34:57 canect2 daemon.info ModemManager[423]: <info> Simple > connect state (4/8): Wait to get fully enabled > May 18 14:34:57 canect2 daemon.info ModemManager[423]: <info> Simple > connect state (5/8): Register > May 18 14:34:57 canect2 daemon.info NetworkManager[245]: > <info> (ttyACM0): Activation: Stage 1 of 5 (Device Prepare) > complete. > May 18 14:34:57 canect2 daemon.info NetworkManager[245]: <debug> > [1495118097.803973] [devices/nm-device.c:7052] > nm_device_remove_pending_action(): [0x213c268] (mlan0): > remove_pending_action (0): 'autoactivate' > May 18 14:35:12 canect2 daemon.warn NetworkManager[245]: > <warn> (ttyACM0) failed to connect modem: Network timeout > May 18 14:35:12 canect2 daemon.info NetworkManager[245]: > <info> (ttyACM0): device state change: prepare -> failed (reason > 'gsm-registration-timeout') [40 120 32] > May 18 14:35:12 canect2 daemon.info NetworkManager[245]: > <info> NetworkManager state is now DISCONNECTED > May 18 14:35:12 canect2 daemon.info NetworkManager[245]: <debug> > [1495118112.191531] [nm-active-connection.c:476] > check_master_ready(): (0x214ed20): not signalling master-ready (not > activating) > May 18 14:35:12 canect2 daemon.info NetworkManager[245]: <debug> > [1495118112.191884] [devices/nm-device.c:7052] > nm_device_remove_pending_action(): [0x21602f0] (ttyACM0): > remove_pending_action (0): 'activation::0x214ed20' > May 18 14:35:12 canect2 daemon.info NetworkManager[245]: <debug> > [1495118112.198446] [nm-policy.c:1125] device_state_changed(): > Connection 'Aeris' failed to autoconnect; 1 tries left > May 18 14:35:12 canect2 daemon.info NetworkManager[245]: > <info> Disabling autoconnect for connection 'Aeris'. > May 18 14:35:12 canect2 daemon.info NetworkManager[245]: <debug> > [1495118112.201007] [nm-manager.c:4328] > policy_activating_device_changed(): ActivatingConnection now (none) > May 18 14:35:12 canect2 daemon.warn NetworkManager[245]: > <warn> (ttyACM0): Activation: failed for connection 'Aeris' > May 18 14:35:12 canect2 daemon.info NetworkManager[245]: <debug> > [1495118112.202306] [devices/nm-device.c:7019] > nm_device_add_pending_action(): [0x21602f0] (ttyACM0): > add_pending_action (1): 'queued state change to disconnected' > May 18 14:35:12 canect2 daemon.info NetworkManager[245]: <debug> > [1495118112.203023] [devices/nm-device.c:7768] > nm_device_queue_state(): [0x21602f0] (ttyACM0): queued state change > to disconnected due to none (id 100339) > May 18 14:35:12 canect2 daemon.info NetworkManager[245]: <debug> > [1495118112.209650] [devices/nm-device.c:7717] queued_set_state(): > [0x21602f0] (ttyACM0): running queued state change to disconnected > (id 100339) > May 18 14:35:12 canect2 daemon.info NetworkManager[245]: > <info> (ttyACM0): device state change: failed -> disconnected > (reason 'none') [120 30 0] > May 18 14:35:12 canect2 daemon.info NetworkManager[245]: > <info> (ttyACM0): deactivating device (reason 'none') [0] > May 18 14:35:12 canect2 daemon.info NetworkManager[245]: <debug> > [1495118112.211004] [nm-firewall-manager.c:256] > nm_firewall_manager_remove_from_zone(): (ttyACM0) firewall zone > remove skipped (not running) > May 18 14:35:12 canect2 daemon.info NetworkManager[245]: <debug> > [1495118112.211233] [devices/nm-device.c:7066] > nm_device_remove_pending_action(): [0x21602f0] (ttyACM0): > remove_pending_action (1): 'dhcp6' not pending (expected) > May 18 14:35:12 canect2 daemon.info NetworkManager[245]: <debug> > [1495118112.211435] [devices/nm-device.c:7066] > nm_device_remove_pending_action(): [0x21602f0] (ttyACM0): > remove_pending_action (1): 'autoconf6' not pending (expected) > May 18 14:35:12 canect2 daemon.info NetworkManager[245]: <debug> > [1495118112.212109] [platform/nm-linux-platform.c:2085] sysctl_set(): > sysctl: failed to open '/proc/sys/net/ipv6/conf/ttyACM0/accept_ra': > (2) No such file or directory > May 18 14:35:12 canect2 daemon.info NetworkManager[245]: <debug> > [1495118112.212562] [platform/nm-linux-platform.c:2085] sysctl_set(): > sysctl: failed to open > '/proc/sys/net/ipv6/conf/ttyACM0/use_tempaddr': (2) No such file or > directory > May 18 14:35:12 canect2 daemon.info NetworkManager[245]: <debug> > [1495118112.215277] [dns-manager/nm-dns-manager.c:1005] > nm_dns_manager_begin_updates(): (update_routing_and_dns): queueing > DNS updates (1) > May 18 14:35:12 canect2 daemon.info NetworkManager[245]: <debug> > [1495118112.215712] [dns-manager/nm-dns-manager.c:1023] > nm_dns_manager_end_updates(): (nm_dns_manager_end_updates): DNS > configuration did not change > May 18 14:35:12 canect2 daemon.info NetworkManager[245]: <debug> > [1495118112.216003] [dns-manager/nm-dns-manager.c:1027] > nm_dns_manager_end_updates(): (update_routing_and_dns): no DNS > changes to commit (0) > May 18 14:35:12 canect2 daemon.info NetworkManager[245]: <debug> > [1495118112.216721] [devices/nm-device.c:7019] > nm_device_add_pending_action(): [0x21602f0] (ttyACM0): > add_pending_action (2): 'autoactivate' > May 18 14:35:12 canect2 daemon.info NetworkManager[245]: <debug> > [1495118112.217263] [devices/nm-device.c:7052] > nm_device_remove_pending_action(): [0x21602f0] (ttyACM0): > remove_pending_action (1): 'queued state change to disconnected' > May 18 14:35:12 canect2 daemon.info NetworkManager[245]: <debug> > [1495118112.221731] [devices/nm-device.c:7052] > nm_device_remove_pending_action(): [0x21602f0] (ttyACM0): > remove_pending_action (0): 'autoactivate' > May 18 14:35:17 canect2 daemon.info ModemManager[423]: <info> Modem > /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state > changed (idle -> searching) > May 18 14:35:22 canect2 daemon.info ModemManager[423]: <info> Modem > /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state > changed (searching -> idle) > May 18 14:35:27 canect2 daemon.info ModemManager[423]: <info> Modem > /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state > changed (idle -> searching) > May 18 14:35:27 canect2 daemon.info ModemManager[423]: <info> Modem > /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state > changed (searching -> idle) > May 18 14:35:32 canect2 daemon.info ModemManager[423]: <info> Modem > /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state > changed (idle -> searching) > May 18 14:35:32 canect2 daemon.info ModemManager[423]: <info> Modem > /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state > changed (searching -> idle) > May 18 14:35:37 canect2 daemon.info NetworkManager[245]: <debug> > [1495118137.696288] [devices/nm-device.c:7019] > nm_device_add_pending_action(): [0x213c268] (mlan0): > add_pending_action (1): 'scan' > May 18 14:35:37 canect2 daemon.info NetworkManager[245]: <debug> > [1495118137.704049] [devices/nm-device.c:7052] > nm_device_remove_pending_action(): [0x213c268] (mlan0): > remove_pending_action (0): 'scan' > May 18 14:35:37 canect2 user.alert kernel: [150011.510693] wlan: > mlan0 START SCAN > May 18 14:35:37 canect2 daemon.info ModemManager[423]: <info> Modem > /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state > changed (idle -> searching) > May 18 14:35:38 canect2 daemon.info ModemManager[423]: <info> Modem > /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state > changed (searching -> idle) > May 18 14:35:39 canect2 daemon.info NetworkManager[245]: <debug> > [1495118139.330325] [platform/nm-linux-platform.c:1950] > event_notification(): netlink event (type 16) for link: mlan0 (6, > family 0) > May 18 14:35:39 canect2 daemon.info NetworkManager[245]: <debug> > [1495118139.330734] [platform/nm-linux-platform.c:426] > get_kernel_object(): get_kernel_object for link: mlan0 (6, family 0) > May 18 14:35:39 canect2 daemon.info NetworkManager[245]: <debug> > [1495118139.331451] [platform/nm-linux-platform.c:1950] > event_notification(): netlink event (type 16) for link: mlan0 (6, > family 0) > May 18 14:35:39 canect2 daemon.info NetworkManager[245]: <debug> > [1495118139.331801] [platform/nm-linux-platform.c:426] > get_kernel_object(): get_kernel_object for link: mlan0 (6, family 0) > May 18 14:35:39 canect2 user.warn kernel: [150013.133087] wlan: SCAN > COMPLETED: scanned AP count=13 > > Best regards, > > Matthew Starr > Sr. Software Engineer > HED Inc. > [email protected] > http://hedonline.com > > _______________________________________________ > networkmanager-list mailing list > [email protected] > https://mail.gnome.org/mailman/listinfo/networkmanager-list _______________________________________________ networkmanager-list mailing list [email protected] https://mail.gnome.org/mailman/listinfo/networkmanager-list
