You are not logged in.
Hello!
I've recently started having network problems at my co-working space, which has been working fine for years. Both wireless and ethernet connections will try to connect but eventually fail. Eventually a connection will succeed, but I'm not sure why (or how to fix the problem).
Here's some dmesg output that ends in a stable connection:
[ 3.143456] iwlwifi 0000:01:00.0: loaded firmware version 17.3216344376.0 op_mode iwlmvm
[ 3.415957] iwlwifi 0000:01:00.0: Detected Intel(R) Dual Band Wireless AC 7260, REV=0x144
[ 3.439594] iwlwifi 0000:01:00.0: base HW address: 6c:29:95:72:0b:fa
[ 3.722376] iwlwifi 0000:01:00.0 wlp1s0: renamed from wlan0
[ 10.288603] wlp1s0: authenticate with 84:b2:61:46:eb:e0
[ 10.296484] wlp1s0: send auth to 84:b2:61:46:eb:e0 (try 1/3)
[ 10.297748] wlp1s0: authenticated
[ 10.299213] wlp1s0: associate with 84:b2:61:46:eb:e0 (try 1/3)
[ 10.301132] wlp1s0: RX AssocResp from 84:b2:61:46:eb:e0 (capab=0x111 status=0 aid=7)
[ 10.302743] wlp1s0: associated
[ 10.439184] IPv6: ADDRCONF(NETDEV_CHANGE): wlp1s0: link becomes ready
[ 43.028801] wlp1s0: deauthenticating from 84:b2:61:46:eb:e0 by local choice (Reason: 3=DEAUTH_LEAVING)
[ 48.712507] wlp1s0: authenticate with 84:b2:61:46:eb:e0
[ 48.717426] wlp1s0: send auth to 84:b2:61:46:eb:e0 (try 1/3)
[ 48.721452] wlp1s0: authenticated
[ 48.722650] wlp1s0: associate with 84:b2:61:46:eb:e0 (try 1/3)
[ 48.724961] wlp1s0: RX AssocResp from 84:b2:61:46:eb:e0 (capab=0x111 status=0 aid=7)
[ 48.727169] wlp1s0: associated
[ 48.737139] IPv6: ADDRCONF(NETDEV_CHANGE): wlp1s0: link becomes ready
[ 80.029930] wlp1s0: deauthenticating from 84:b2:61:46:eb:e0 by local choice (Reason: 3=DEAUTH_LEAVING)
[ 85.729720] wlp1s0: authenticate with 84:b2:61:46:eb:e0
[ 85.734706] wlp1s0: send auth to 84:b2:61:46:eb:e0 (try 1/3)
[ 85.736170] wlp1s0: authenticated
[ 85.739270] wlp1s0: associate with 84:b2:61:46:eb:e0 (try 1/3)
[ 85.742455] wlp1s0: RX AssocResp from 84:b2:61:46:eb:e0 (capab=0x111 status=0 aid=7)
[ 85.744372] wlp1s0: associated
[ 85.752791] IPv6: ADDRCONF(NETDEV_CHANGE): wlp1s0: link becomes ready
[ 118.030127] wlp1s0: deauthenticating from 84:b2:61:46:eb:e0 by local choice (Reason: 3=DEAUTH_LEAVING)
[ 123.756640] wlp1s0: authenticate with 84:b2:61:46:eb:e0
[ 123.761531] wlp1s0: send auth to 84:b2:61:46:eb:e0 (try 1/3)
[ 123.763645] wlp1s0: authenticated
[ 123.766530] wlp1s0: associate with 84:b2:61:46:eb:e0 (try 1/3)
[ 123.768826] wlp1s0: RX AssocResp from 84:b2:61:46:eb:e0 (capab=0x111 status=0 aid=7)
[ 123.782563] wlp1s0: associated
[ 123.792108] IPv6: ADDRCONF(NETDEV_CHANGE): wlp1s0: link becomes ready
[ 155.036732] wlp1s0: deauthenticating from 84:b2:61:46:eb:e0 by local choice (Reason: 3=DEAUTH_LEAVING)
[ 457.875010] wlp1s0: authenticate with 84:b2:61:46:eb:e0
[ 457.878880] wlp1s0: send auth to 84:b2:61:46:eb:e0 (try 1/3)
[ 457.880523] wlp1s0: authenticated
[ 457.882566] wlp1s0: associate with 84:b2:61:46:eb:e0 (try 1/3)
[ 457.883965] wlp1s0: RX AssocResp from 84:b2:61:46:eb:e0 (capab=0x111 status=0 aid=15)
[ 457.886016] wlp1s0: associated
[ 457.895278] IPv6: ADDRCONF(NETDEV_CHANGE): wlp1s0: link becomes ready
I've read that "deauthentication from [...] by local choice" might be indicative of aggressive power-saving, so I've created /etc/modprobe.d/iwlwifi.conf to disable power saving (and have confirmed with lspci):
lspci -vv | grep iwl
Kernel driver in use: iwlwifi
Kernel modules: iwlwifi
orion% ls
orion% lsmod | grep iw
iwlmvm 442368 0
mac80211 991232 1 iwlmvm
iwlwifi 376832 1 iwlmvm
cfg80211 851968 3 iwlmvm,iwlwifi,mac80211
orion%
orion% systool -v -m iwlwifi
Module = "iwlwifi"
Attributes:
coresize = "376832"
initsize = "0"
initstate = "live"
refcnt = "1"
srcversion = "C38569D1B8677DC1BA28553"
taint = ""
uevent = <store method only>
Parameters:
11n_disable = "0"
amsdu_size = "0"
antenna_coupling = "0"
bt_coex_active = "Y"
debug = "0"
disable_11ac = "N"
disable_11ax = "N"
enable_ini = "N"
fw_monitor = "N"
fw_restart = "Y"
lar_disable = "N"
led_mode = "0"
nvm_file = "(null)"
power_level = "0"
power_save = "N"
remove_when_gone = "N"
swcrypto = "0"
uapsd_disable = "3"
Sections:
Unfortunately this doesn't seem to resolve the problem.
I've read that NetworkManager can conflict with wpa_supplicant, but it seems like the NetworkManager service is the one starting the wpa_supplicant service?
$ systemctl list-unit-files --state=enabled
UNIT FILE STATE
autovt@.service enabled
dbus-org.freedesktop.nm-dispatcher.service enabled
display-manager.service enabled
gdm.service enabled
getty@.service enabled
NetworkManager-dispatcher.service enabled
NetworkManager-wait-online.service enabled
NetworkManager.service enabled
oasis.service enabled
remote-fs.target enabled
10 unit files listed.
When I stop the wpa_supplicant service and restart NetworkManager, the wpa_supplicant service seems to be restarted as well. For what it's worth, I was having problems with my previous installation so I reinstalled Arch, but the problem persists. I don't have network problems on any other network that I've tried, and I'm the only person on this network (with many people) who has this problem. Anything I can do to help debug?
Last edited by christianbundy (2020-01-03 18:59:17)
Offline
Probably useful, here's my journalctl output. I'm suspicious of the ip-config-unavailable but searching the web I've found tons of conflicting solutions to the problem. I'll update if any of my troubleshooting is useful:
Jan 03 10:34:57 orion NetworkManager[351]: <info> [1578076497.1771] device (wlp1s0): Activation: starting connection 'Hatch' (8746c68a-d3ef-43fe-b49e-411e49e71c46)
Jan 03 10:34:57 orion NetworkManager[351]: <info> [1578076497.1773] audit: op="connection-activate" uuid="8746c68a-d3ef-43fe-b49e-411e49e71c46" name="Hatch" pid=834 uid=1000 result="success"
Jan 03 10:34:57 orion NetworkManager[351]: <info> [1578076497.1774] device (wlp1s0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Jan 03 10:34:57 orion NetworkManager[351]: <info> [1578076497.1779] manager: NetworkManager state is now CONNECTING
Jan 03 10:34:57 orion audit[351]: USYS_CONFIG pid=351 uid=0 auid=4294967295 ses=4294967295 msg='op=connection-activate uuid=8746c68a-d3ef-43fe-b49e-411e49e71c46 name="Hatch" pid=834 uid=1000 result=success exe="/usr/bin/NetworkManager" hostname=? addr=? terminal=? res=success'
Jan 03 10:34:57 orion kernel: audit: type=1111 audit(1578076497.173:159): pid=351 uid=0 auid=4294967295 ses=4294967295 msg='op=connection-activate uuid=8746c68a-d3ef-43fe-b49e-411e49e71c46 name="Hatch" pid=834 uid=1000 result=success exe="/usr/bin/NetworkManager" hostname=? addr=? terminal=? res=success'
Jan 03 10:34:57 orion NetworkManager[351]: <info> [1578076497.1806] device (wlp1s0): set-hw-addr: reset MAC address to 6C:29:95:72:0B:FA (preserve)
Jan 03 10:34:57 orion NetworkManager[351]: <info> [1578076497.1833] device (wlp1s0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Jan 03 10:34:57 orion NetworkManager[351]: <info> [1578076497.1838] device (wlp1s0): Activation: (wifi) access point 'Hatch' has security, but secrets are required.
Jan 03 10:34:57 orion NetworkManager[351]: <info> [1578076497.1838] device (wlp1s0): state change: config -> need-auth (reason 'none', sys-iface-state: 'managed')
Jan 03 10:34:57 orion NetworkManager[351]: <info> [1578076497.1866] device (wlp1s0): state change: need-auth -> prepare (reason 'none', sys-iface-state: 'managed')
Jan 03 10:34:57 orion NetworkManager[351]: <info> [1578076497.1871] device (wlp1s0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Jan 03 10:34:57 orion NetworkManager[351]: <info> [1578076497.1875] device (wlp1s0): Activation: (wifi) connection 'Hatch' has security, and secrets exist. No new secrets needed.
Jan 03 10:34:57 orion NetworkManager[351]: <info> [1578076497.1875] Config: added 'ssid' value 'Hatch'
Jan 03 10:34:57 orion NetworkManager[351]: <info> [1578076497.1875] Config: added 'scan_ssid' value '1'
Jan 03 10:34:57 orion NetworkManager[351]: <info> [1578076497.1876] Config: added 'bgscan' value 'simple:30:-70:86400'
Jan 03 10:34:57 orion NetworkManager[351]: <info> [1578076497.1876] Config: added 'key_mgmt' value 'WPA-PSK WPA-PSK-SHA256 FT-PSK'
Jan 03 10:34:57 orion NetworkManager[351]: <info> [1578076497.1876] Config: added 'psk' value '<hidden>'
Jan 03 10:34:57 orion NetworkManager[351]: <info> [1578076497.2245] device (wlp1s0): supplicant interface state: disconnected -> scanning
Jan 03 10:34:57 orion NetworkManager[351]: <info> [1578076497.2245] device (p2p-dev-wlp1s0): supplicant management interface state: disconnected -> scanning
Jan 03 10:35:00 orion wpa_supplicant[461]: wlp1s0: SME: Trying to authenticate with 84:b2:61:46:eb:e0 (SSID='Hatch' freq=5825 MHz)
Jan 03 10:35:00 orion kernel: wlp1s0: authenticate with 84:b2:61:46:eb:e0
Jan 03 10:35:00 orion NetworkManager[351]: <info> [1578076500.0495] device (wlp1s0): supplicant interface state: scanning -> authenticating
Jan 03 10:35:00 orion NetworkManager[351]: <info> [1578076500.0495] device (p2p-dev-wlp1s0): supplicant management interface state: scanning -> authenticating
Jan 03 10:35:00 orion wpa_supplicant[461]: wlp1s0: Trying to associate with 84:b2:61:46:eb:e0 (SSID='Hatch' freq=5825 MHz)
Jan 03 10:35:00 orion kernel: wlp1s0: send auth to 84:b2:61:46:eb:e0 (try 1/3)
Jan 03 10:35:00 orion kernel: wlp1s0: authenticated
Jan 03 10:35:00 orion NetworkManager[351]: <info> [1578076500.0506] device (wlp1s0): supplicant interface state: authenticating -> associating
Jan 03 10:35:00 orion NetworkManager[351]: <info> [1578076500.0507] device (p2p-dev-wlp1s0): supplicant management interface state: authenticating -> associating
Jan 03 10:35:00 orion kernel: wlp1s0: associate with 84:b2:61:46:eb:e0 (try 1/3)
Jan 03 10:35:00 orion kernel: wlp1s0: RX AssocResp from 84:b2:61:46:eb:e0 (capab=0x111 status=0 aid=15)
Jan 03 10:35:00 orion wpa_supplicant[461]: wlp1s0: Associated with 84:b2:61:46:eb:e0
Jan 03 10:35:00 orion wpa_supplicant[461]: wlp1s0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
Jan 03 10:35:00 orion kernel: wlp1s0: associated
Jan 03 10:35:00 orion NetworkManager[351]: <info> [1578076500.0608] device (wlp1s0): supplicant interface state: associating -> 4-way handshake
Jan 03 10:35:00 orion NetworkManager[351]: <info> [1578076500.0608] device (p2p-dev-wlp1s0): supplicant management interface state: associating -> 4-way handshake
Jan 03 10:35:00 orion wpa_supplicant[461]: wlp1s0: WPA: Key negotiation completed with 84:b2:61:46:eb:e0 [PTK=CCMP GTK=TKIP]
Jan 03 10:35:00 orion wpa_supplicant[461]: wlp1s0: CTRL-EVENT-CONNECTED - Connection to 84:b2:61:46:eb:e0 completed [id=0 id_str=]
Jan 03 10:35:00 orion kernel: IPv6: ADDRCONF(NETDEV_CHANGE): wlp1s0: link becomes ready
Jan 03 10:35:00 orion NetworkManager[351]: <info> [1578076500.0673] device (wlp1s0): supplicant interface state: 4-way handshake -> completed
Jan 03 10:35:00 orion NetworkManager[351]: <info> [1578076500.0674] device (wlp1s0): Activation: (wifi) Stage 2 of 5 (Device Configure) successful. Connected to wireless network "Hatch"
Jan 03 10:35:00 orion NetworkManager[351]: <info> [1578076500.0674] device (p2p-dev-wlp1s0): supplicant management interface state: 4-way handshake -> completed
Jan 03 10:35:00 orion NetworkManager[351]: <info> [1578076500.0676] device (wlp1s0): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed')
Jan 03 10:35:00 orion NetworkManager[351]: <info> [1578076500.0680] dhcp4 (wlp1s0): activation: beginning transaction (timeout in 45 seconds)
Jan 03 10:35:00 orion NetworkManager[351]: <info> [1578076500.0739] dhcp4 (wlp1s0): state changed unknown -> fail
Jan 03 10:35:00 orion wpa_supplicant[461]: wlp1s0: CTRL-EVENT-SIGNAL-CHANGE above=1 signal=-64 noise=9999 txrate=144400
Jan 03 10:35:13 orion dbus-daemon[348]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.1' (uid=0 pid=351 comm="/usr/bin/NetworkManager --no-daemon ")
Jan 03 10:35:13 orion systemd[1]: Starting Network Manager Script Dispatcher Service...
Jan 03 10:35:13 orion dbus-daemon[348]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Jan 03 10:35:13 orion systemd[1]: Started Network Manager Script Dispatcher Service.
Jan 03 10:35:13 orion audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jan 03 10:35:13 orion kernel: audit: type=1130 audit(1578076513.853:160): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jan 03 10:35:23 orion systemd[1]: NetworkManager-dispatcher.service: Succeeded.
Jan 03 10:35:23 orion audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jan 03 10:35:23 orion kernel: audit: type=1131 audit(1578076523.813:161): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jan 03 10:35:31 orion NetworkManager[351]: <info> [1578076531.8071] device (wlp1s0): state change: ip-config -> failed (reason 'ip-config-unavailable', sys-iface-state: 'managed')
Jan 03 10:35:31 orion NetworkManager[351]: <info> [1578076531.8081] manager: NetworkManager state is now DISCONNECTED
Jan 03 10:35:31 orion NetworkManager[351]: <warn> [1578076531.8115] device (wlp1s0): Activation: failed for connection 'Hatch'
Jan 03 10:35:31 orion NetworkManager[351]: <info> [1578076531.8122] device (wlp1s0): state change: failed -> disconnected (reason 'none', sys-iface-state: 'managed')
Jan 03 10:35:31 orion NetworkManager[351]: <info> [1578076531.8337] dhcp4 (wlp1s0): canceled DHCP transaction
Jan 03 10:35:31 orion NetworkManager[351]: <info> [1578076531.8338] dhcp4 (wlp1s0): state changed fail -> done
Jan 03 10:35:31 orion kernel: wlp1s0: deauthenticating from 84:b2:61:46:eb:e0 by local choice (Reason: 3=DEAUTH_LEAVING)
Jan 03 10:35:31 orion NetworkManager[351]: <info> [1578076531.8462] device (wlp1s0): set-hw-addr: set MAC address to 3A:16:20:DF:59:01 (scanning)
Jan 03 10:35:31 orion wpa_supplicant[461]: wlp1s0: CTRL-EVENT-DISCONNECTED bssid=84:b2:61:46:eb:e0 reason=3 locally_generated=1
Jan 03 10:35:31 orion wpa_supplicant[461]: dbus: wpa_dbus_property_changed: no property SessionLength in object /fi/w1/wpa_supplicant1/Interfaces/2
Jan 03 10:35:31 orion NetworkManager[351]: <warn> [1578076531.8561] sup-iface[0x558c3f374310,wlp1s0]: connection disconnected (reason -3)
Jan 03 10:35:31 orion NetworkManager[351]: <info> [1578076531.8562] device (wlp1s0): supplicant interface state: completed -> disconnected
Jan 03 10:35:31 orion NetworkManager[351]: <info> [1578076531.8563] device (p2p-dev-wlp1s0): supplicant management interface state: completed -> disconnected
Jan 03 10:35:31 orion dbus-daemon[348]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.1' (uid=0 pid=351 comm="/usr/bin/NetworkManager --no-daemon ")
Jan 03 10:35:31 orion systemd[1]: Starting Network Manager Script Dispatcher Service...
Jan 03 10:35:31 orion dbus-daemon[348]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Jan 03 10:35:31 orion systemd[1]: Started Network Manager Script Dispatcher Service.
Jan 03 10:35:31 orion audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jan 03 10:35:31 orion kernel: audit: type=1130 audit(1578076531.860:162): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jan 03 10:35:31 orion wpa_supplicant[461]: wlp1s0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD
Offline
it seems like the NetworkManager service is the one starting the wpa_supplicant service?
Looks like it, yes. Confirm with
systemd-cgls
Have you tried https://wiki.archlinux.org/index.php/Wireless#iwlwifi? You should really explicitly state your hardware btw.
Offline
There are some hiccups with networkmanager's internal dhcp client currently, try to swap that out: https://wiki.archlinux.org/index.php/Ne … HCP_client
Last edited by V1del (2020-01-03 18:53:40)
Offline
Thanks a lot v1del, that was the problem. The solution was:
sudo pacman -S dhcpclient
sudo sh -c 'printf "[main]\ndhcp=dhclient\n" > /etc/NetworkManager/conf.d/dhcp-client.conf'
sudo systemctl restart NetworkManager
Would it be helpful (or possible) for me to help report this bug in NetworkManager, or should I just stick with the workaround and retry the internal DHCP client in a few months?
Offline
It seems to be known and is likely fixed in the next release: https://gitlab.freedesktop.org/NetworkM … issues/310
Offline
Thanks a lot v1del, that was the problem. The solution was:
sudo pacman -S dhcpclient sudo sh -c 'printf "[main]\ndhcp=dhclient\n" > /etc/NetworkManager/conf.d/dhcp-client.conf' sudo systemctl restart NetworkManager
Would it be helpful (or possible) for me to help report this bug in NetworkManager, or should I just stick with the workaround and retry the internal DHCP client in a few months?
Awesome!!!!!!
I was facing same issue and that did the trick, also learnt how to send command to file through sh -c!!!
I used dhcpcd instead!
Thank you!
Offline
It seems to be known and is likely fixed in the next release: https://gitlab.freedesktop.org/NetworkM … issues/310
It looks like a fix is being worked on already, but in my case the bizarre thing is that networkmanager 1.22.2-1 works at my office for all connections (wired and wireless), but at home only for wireless. At my home location, I have two separate routers (different brands, etc.) on separate networks, none of them works when wired. But both of them work wireless.
Offline