You are not logged in.

#1 2014-07-02 16:08:33

JamesLens
Member
Registered: 2014-04-03
Posts: 17

NetworkManager sporadically doesn't connect to wireless

Hi fellow Arch users,

When using NetworkManager, whether it connects to the wireless network or not is completely at random. For example, at the moment it is working, but when I try to change the settings in order for it to use Google's DNS, or even open the settings page, it will disconnect and fail to reconnect. If I revert the DNS to the original, it will once again fail to connect, and keep doing so for an unspecified number of system restarts. What seems to reset it without fail is restarting the router. The connection itself is flawless on any other device.

I have attached the journalctl of a failed and successful attempt below.

Hardware:

Laptop: Dell N5110
Linux arch 3.15.2-1-ARCH
$ lspci | grep -i net
05:00.0 Ethernet controller: Realtek Semiconductor Co., Ltd. RTL8101E/RTL8102E PCI Express Fast Ethernet controller (rev 05)
09:00.0 Network controller: Qualcomm Atheros AR9285 Wireless Network Adapter (PCI-Express) (rev 01)

Failed attempt:

Jul 02 17:39:22 arch NetworkManager[652]: <info> Activation (wlp9s0) Stage 2 of 5 (Device Configure) starting...
Jul 02 17:39:22 arch NetworkManager[652]: <info> (wlp9s0): device state change: prepare -> config (reason 'none') [40 50 0]
Jul 02 17:39:22 arch NetworkManager[652]: <info> Activation (wlp9s0/wireless): connection 'Auto VM868536-2G' has security, and secrets exist.  No new secrets needed.
Jul 02 17:39:22 arch NetworkManager[652]: <info> Config: added 'ssid' value 'VM868536-2G'
Jul 02 17:39:22 arch NetworkManager[652]: <info> Config: added 'scan_ssid' value '1'
Jul 02 17:39:22 arch NetworkManager[652]: <info> Config: added 'key_mgmt' value 'WPA-PSK'
Jul 02 17:39:22 arch NetworkManager[652]: <info> Config: added 'auth_alg' value 'OPEN'
Jul 02 17:39:22 arch NetworkManager[652]: <info> Config: added 'psk' value '<omitted>'
Jul 02 17:39:22 arch NetworkManager[652]: <info> Activation (wlp9s0) Stage 2 of 5 (Device Configure) complete.
Jul 02 17:39:22 arch NetworkManager[652]: <info> Config: set interface ap_scan to 1
Jul 02 17:39:22 arch NetworkManager[652]: <info> (wlp9s0): supplicant interface state: inactive -> scanning
Jul 02 17:39:23 arch NetworkManager[652]: <info> (wlp9s0): supplicant interface state: scanning -> authenticating
Jul 02 17:39:24 arch NetworkManager[652]: <info> (wlp9s0): supplicant interface state: authenticating -> disconnected
Jul 02 17:39:24 arch NetworkManager[652]: <info> (wlp9s0): supplicant interface state: disconnected -> scanning
Jul 02 17:39:47 arch NetworkManager[652]: <warn> Activation (wlp9s0/wireless): association took too long, failing activation.
Jul 02 17:39:47 arch NetworkManager[652]: <info> (wlp9s0): device state change: config -> failed (reason 'SSID not found') [50 120 53]
Jul 02 17:39:47 arch NetworkManager[652]: <info> NetworkManager state is now DISCONNECTED
Jul 02 17:39:47 arch NetworkManager[652]: <warn> Activation (wlp9s0) failed for connection 'Auto VM868536-2G'
Jul 02 17:39:47 arch NetworkManager[652]: <warn> Couldn't disconnect supplicant interface: This interface is not connected.
Jul 02 17:39:47 arch NetworkManager[652]: <info> (wlp9s0): device state change: failed -> disconnected (reason 'none') [120 30 0]
Jul 02 17:39:47 arch NetworkManager[652]: <info> (wlp9s0): deactivating device (reason 'none') [0]
Jul 02 17:39:47 arch NetworkManager[652]: <warn> Couldn't disconnect supplicant interface: This interface is not connected.
Jul 02 17:39:48 arch NetworkManager[652]: <info> (wlp9s0): supplicant interface state: scanning -> inactive

Successful attempt:

Jul 02 17:45:18 arch NetworkManager[652]: <info> (wlp9s0): device state change: disconnected -> unavailable (reason 'none') [30 20 0]
Jul 02 17:45:18 arch NetworkManager[652]: <info> (wlp9s0): deactivating device (reason 'none') [0]
Jul 02 17:45:18 arch NetworkManager[652]: <info> (wlp9s0): taking down device.
Jul 02 17:45:18 arch NetworkManager[652]: <info> WiFi hardware radio set disabled
Jul 02 17:45:18 arch NetworkManager[652]: <info> WiFi now disabled by radio killswitch
Jul 02 17:45:19 arch NetworkManager[652]: <info> (wlp9s0): bringing up device.
Jul 02 17:45:19 arch NetworkManager[652]: <info> WiFi hardware radio set enabled
Jul 02 17:45:19 arch NetworkManager[652]: <info> WiFi now enabled by radio killswitch
Jul 02 17:45:19 arch NetworkManager[652]: <info> (wlp9s0): bringing up device.
Jul 02 17:45:19 arch NetworkManager[652]: <info> (wlp9s0) supports 4 scan SSIDs
Jul 02 17:45:19 arch NetworkManager[652]: <info> (wlp9s0): supplicant interface state: starting -> ready
Jul 02 17:45:19 arch NetworkManager[652]: <info> (wlp9s0): device state change: unavailable -> disconnected (reason 'supplicant-available') [20 30 42]
Jul 02 17:45:19 arch NetworkManager[652]: <warn> Trying to remove a non-existant call id.
Jul 02 17:45:19 arch NetworkManager[652]: <info> (wlp9s0): supplicant interface state: ready -> disconnected
Jul 02 17:45:19 arch NetworkManager[652]: <info> (wlp9s0) supports 4 scan SSIDs
Jul 02 17:45:20 arch NetworkManager[652]: <info> (wlp9s0): supplicant interface state: disconnected -> inactive
Jul 02 17:45:22 arch NetworkManager[652]: <info> Activation (wlp9s0) starting connection 'Auto VM868536-2G'
Jul 02 17:45:22 arch NetworkManager[652]: <info> (wlp9s0): device state change: disconnected -> prepare (reason 'none') [30 40 0]
Jul 02 17:45:22 arch NetworkManager[652]: <info> NetworkManager state is now CONNECTING
Jul 02 17:45:22 arch NetworkManager[652]: <info> Activation (wlp9s0) Stage 1 of 5 (Device Prepare) scheduled...
Jul 02 17:45:22 arch NetworkManager[652]: <info> Activation (wlp9s0) Stage 1 of 5 (Device Prepare) started...
Jul 02 17:45:22 arch NetworkManager[652]: <info> Activation (wlp9s0) Stage 2 of 5 (Device Configure) scheduled...
Jul 02 17:45:22 arch NetworkManager[652]: <info> Activation (wlp9s0) Stage 1 of 5 (Device Prepare) complete.
Jul 02 17:45:22 arch NetworkManager[652]: <info> Activation (wlp9s0) Stage 2 of 5 (Device Configure) starting...
Jul 02 17:45:22 arch NetworkManager[652]: <info> (wlp9s0): device state change: prepare -> config (reason 'none') [40 50 0]
Jul 02 17:45:22 arch NetworkManager[652]: <info> Activation (wlp9s0/wireless): access point 'Auto VM868536-2G' has security, but secrets are required.
Jul 02 17:45:22 arch NetworkManager[652]: <info> (wlp9s0): device state change: config -> need-auth (reason 'none') [50 60 0]
Jul 02 17:45:22 arch NetworkManager[652]: <info> Activation (wlp9s0) Stage 2 of 5 (Device Configure) complete.
Jul 02 17:45:22 arch NetworkManager[652]: <info> Activation (wlp9s0) Stage 1 of 5 (Device Prepare) scheduled...
Jul 02 17:45:22 arch NetworkManager[652]: <info> Activation (wlp9s0) Stage 1 of 5 (Device Prepare) started...
Jul 02 17:45:22 arch NetworkManager[652]: <info> (wlp9s0): device state change: need-auth -> prepare (reason 'none') [60 40 0]
Jul 02 17:45:22 arch NetworkManager[652]: <info> Activation (wlp9s0) Stage 2 of 5 (Device Configure) scheduled...
Jul 02 17:45:22 arch NetworkManager[652]: <info> Activation (wlp9s0) Stage 1 of 5 (Device Prepare) complete.
Jul 02 17:45:22 arch NetworkManager[652]: <info> Activation (wlp9s0) Stage 2 of 5 (Device Configure) starting...
Jul 02 17:45:22 arch NetworkManager[652]: <info> (wlp9s0): device state change: prepare -> config (reason 'none') [40 50 0]
Jul 02 17:45:22 arch NetworkManager[652]: <info> Activation (wlp9s0/wireless): connection 'Auto VM868536-2G' has security, and secrets exist.  No new secrets needed.
Jul 02 17:45:22 arch NetworkManager[652]: <info> Config: added 'ssid' value 'VM868536-2G'
Jul 02 17:45:22 arch NetworkManager[652]: <info> Config: added 'scan_ssid' value '1'
Jul 02 17:45:22 arch NetworkManager[652]: <info> Config: added 'key_mgmt' value 'WPA-PSK'
Jul 02 17:45:22 arch NetworkManager[652]: <info> Config: added 'auth_alg' value 'OPEN'
Jul 02 17:45:22 arch NetworkManager[652]: <info> Config: added 'psk' value '<omitted>'
Jul 02 17:45:22 arch NetworkManager[652]: <info> Activation (wlp9s0) Stage 2 of 5 (Device Configure) complete.
Jul 02 17:45:22 arch NetworkManager[652]: <info> Config: set interface ap_scan to 1
Jul 02 17:45:22 arch NetworkManager[652]: <info> (wlp9s0): supplicant interface state: inactive -> authenticating
Jul 02 17:45:22 arch NetworkManager[652]: <info> (wlp9s0): supplicant interface state: authenticating -> associating
Jul 02 17:45:22 arch NetworkManager[652]: <info> (wlp9s0): supplicant interface state: associating -> associated
Jul 02 17:45:22 arch NetworkManager[652]: <info> (wlp9s0): supplicant interface state: associated -> 4-way handshake
Jul 02 17:45:22 arch NetworkManager[652]: <info> (wlp9s0): supplicant interface state: 4-way handshake -> completed
Jul 02 17:45:22 arch NetworkManager[652]: <info> Activation (wlp9s0/wireless) Stage 2 of 5 (Device Configure) successful.  Connected to wireless network 'VM868536-2G'.
Jul 02 17:45:22 arch NetworkManager[652]: <info> Activation (wlp9s0) Stage 3 of 5 (IP Configure Start) scheduled.
Jul 02 17:45:22 arch NetworkManager[652]: <info> Activation (wlp9s0) Stage 3 of 5 (IP Configure Start) started...
Jul 02 17:45:22 arch NetworkManager[652]: <info> (wlp9s0): device state change: config -> ip-config (reason 'none') [50 70 0]
Jul 02 17:45:22 arch NetworkManager[652]: <info> Activation (wlp9s0) Beginning DHCPv4 transaction (timeout in 45 seconds)
Jul 02 17:45:22 arch NetworkManager[652]: <info> dhcpcd started with pid 738
Jul 02 17:45:22 arch NetworkManager[652]: <info> Activation (wlp9s0) Beginning IP6 addrconf.
Jul 02 17:45:22 arch NetworkManager[652]: <info> Activation (wlp9s0) Stage 3 of 5 (IP Configure Start) complete.
Jul 02 17:45:22 arch dhcpcd[738]: version 6.4.0 starting
Jul 02 17:45:22 arch dhcpcd[738]: DUID 00:01:00:01:1b:45:c5:61:cc:af:78:8c:33:45
Jul 02 17:45:22 arch dhcpcd[738]: wlp9s0: IAID 78:8c:33:45
Jul 02 17:45:22 arch NetworkManager[652]: <info> (wlp9s0): DHCPv4 state changed nbi -> preinit
Jul 02 17:45:22 arch dhcpcd[738]: wlp9s0: rebinding lease of 192.168.0.12
Jul 02 17:45:23 arch dhcpcd[738]: wlp9s0: NAK: from 192.168.0.1
Jul 02 17:45:23 arch dhcpcd[738]: wlp9s0: soliciting a DHCP lease
Jul 02 17:45:23 arch NetworkManager[652]: <info> (wlp9s0): DHCPv4 state changed preinit -> (null)
Jul 02 17:45:23 arch dhcpcd[738]: wlp9s0: soliciting an IPv6 router
Jul 02 17:45:25 arch dhcpcd[738]: wlp9s0: offered 192.168.0.7 from 192.168.0.1
Jul 02 17:45:30 arch dhcpcd[738]: wlp9s0: leased 192.168.0.7 for 86400 seconds
Jul 02 17:45:30 arch dhcpcd[738]: wlp9s0: adding route to 192.168.0.0/24
Jul 02 17:45:30 arch NetworkManager[652]: <info> (wlp9s0): DHCPv4 state changed (null) -> bound
Jul 02 17:45:30 arch NetworkManager[652]: <info>   address 192.168.0.7
Jul 02 17:45:30 arch NetworkManager[652]: <info>   prefix 24 (255.255.255.0)
Jul 02 17:45:30 arch NetworkManager[652]: <info>   gateway 192.168.0.1
Jul 02 17:45:30 arch NetworkManager[652]: <info>   hostname 'arch'
Jul 02 17:45:30 arch NetworkManager[652]: <info>   nameserver '192.168.0.1'
Jul 02 17:45:30 arch NetworkManager[652]: <info> Activation (wlp9s0) Stage 5 of 5 (IPv4 Configure Commit) scheduled...
Jul 02 17:45:30 arch NetworkManager[652]: <info> Activation (wlp9s0) Stage 5 of 5 (IPv4 Commit) started...
Jul 02 17:45:31 arch dhcpcd[738]: wlp9s0: removing route to 192.168.0.0/24
Jul 02 17:45:31 arch NetworkManager[652]: <info> (wlp9s0): device state change: ip-config -> secondaries (reason 'none') [70 90 0]
Jul 02 17:45:31 arch NetworkManager[652]: <info> Activation (wlp9s0) Stage 5 of 5 (IPv4 Commit) complete.
Jul 02 17:45:31 arch NetworkManager[652]: <info> (wlp9s0): device state change: secondaries -> activated (reason 'none') [90 100 0]
Jul 02 17:45:32 arch NetworkManager[652]: <info> NetworkManager state is now CONNECTED_GLOBAL
Jul 02 17:45:32 arch NetworkManager[652]: <info> Policy set 'Auto VM868536-2G' (wlp9s0) as default for IPv4 routing and DNS.
Jul 02 17:45:32 arch NetworkManager[652]: <info> Writing DNS information to /usr/bin/resolvconf
Jul 02 17:45:32 arch NetworkManager[652]: <info> Activation (wlp9s0) successful, device activated.
Jul 02 17:45:35 arch dhcpcd[738]: wlp9s0: no IPv6 Routers available
Jul 02 17:45:42 arch NetworkManager[652]: <info> (wlp9s0): IP6 addrconf timed out or failed.
Jul 02 17:45:42 arch NetworkManager[652]: <info> Activation (wlp9s0) Stage 4 of 5 (IPv6 Configure Timeout) scheduled...
Jul 02 17:45:42 arch NetworkManager[652]: <info> Activation (wlp9s0) Stage 4 of 5 (IPv6 Configure Timeout) started...
Jul 02 17:45:42 arch NetworkManager[652]: <info> Activation (wlp9s0) Stage 4 of 5 (IPv6 Configure Timeout) complete.

Systemctl active services:

UNIT                         LOAD   ACTIVE SUB     DESCRIPTION
accounts-daemon.service      loaded active running Accounts Service
colord.service               loaded active running Manage, Install and Generate 
dbus.service                 loaded active running D-Bus System Message Bus
getty@tty1.service           loaded active running Getty on tty1
kmod-static-nodes.service    loaded active exited  Create list of required stati
NetworkManager.service       loaded active running Network Manager
polkit.service               loaded active running Authorization Manager
rtkit-daemon.service         loaded active running RealtimeKit Scheduling Policy
systemd-backlight@backlight:acpi_video0.service loaded active exited  Load/Save Screen Backlight Br
systemd-backlight@backlight:acpi_video1.service loaded active exited  Load/Save Screen Backlight Br
systemd-backlight@backlight:intel_backlight.service loaded active exited  Load/Save Screen Backlight Br
systemd-fsck@dev-disk-by\x2duuid-8ff521da\x2db33a\x2d4ca9\x2d8b49\x2dc3d404870fe7.service loaded active exited  File System Check on /dev/dis
systemd-journald.service     loaded active running Journal Service
systemd-logind.service       loaded active running Login Service
systemd-random-seed.service  loaded active exited  Load/Save Random Seed
systemd-remount-fs.service   loaded active exited  Remount Root and Kernel File 
systemd-rfkill@rfkill0.service loaded active exited  Load/Save RF Kill Switch Stat
systemd-sysctl.service       loaded active exited  Apply Kernel Variables
systemd-timesyncd.service    loaded active running Network Time Synchronization
systemd-tmpfiles-setup-dev.service loaded active exited  Create Static Device Nodes in
systemd-tmpfiles-setup.service loaded active exited  Create Volatile Files and Dir
systemd-udev-trigger.service loaded active exited  udev Coldplug all Devices
systemd-udevd.service        loaded active running udev Kernel Device Manager
systemd-update-utmp.service  loaded active exited  Update UTMP about System Boot
systemd-user-sessions.service loaded active exited  Permit User Sessions
systemd-vconsole-setup.service loaded active exited  Setup Virtual Console
udisks2.service              loaded active running Disk Manager
upower.service               loaded active running Daemon for power management
user@1000.service            loaded active running User Manager for UID 1000
wpa_supplicant.service       loaded active running WPA supplicant

Is the wpa_supplicant service supposed to be running at the same time as NetworkManager? Activating NetworkManager.service seems to also activate wpa_supplicant.service for me and I am unable to stop it.

Any help greatly appreciated.

Edit: I installed wicd and it seems to work just fine, which is annoying because I prefer the interface of networkmanager. Is there anything that can be done? Not sure why networkmanager would not work.

Last edited by JamesLens (2014-07-02 22:29:39)

Offline

Board footer

Powered by FluxBB