Airplane Mode is instantly reverted

SavageButcher · 2022-04-02 12:42:56

Hi guys, i'm running Arch on a HP ProBook 440 G8 laptop.
When pressing the multimedia key for Airplane Mode (fn+f11), wifi and bluetooth get correctly disabled for a second, then they get instantly re-enabled again.
I don't get it, i'm not sure but it seems like networkmanager is getting in the way and re-enabling it; the behaviour is the same even when NetworkManager.service is disabled though.
You got any ideas on why this is happening?

Thanks a lot!

`rfkill event` is showing this:

2022-04-02 14:09:33,272522+02:00: idx 0 type 2 op 2 soft 1 hard 0
2022-04-02 14:09:33,300981+02:00: idx 1 type 1 op 2 soft 1 hard 0
2022-04-02 14:09:33,490946+02:00: idx 0 type 2 op 2 soft 0 hard 0
2022-04-02 14:09:33,490990+02:00: idx 1 type 1 op 2 soft 0 hard 0

dmesg:

[275139.757877] atkbd serio0: Unknown key pressed (translated set 2, code 0xf8 on isa0060/serio0).
[275139.757889] atkbd serio0: Use 'setkeycodes e078 <keycode>' to make it known.
[275139.761419] wlp0s20f3: deauthenticating from 00:15:6d:9c:0f:9d by local choice (Reason: 3=DEAUTH_LEAVING)
[275139.772203] audit: type=1130 audit(1648901627.793:749): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-rfkill comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[275139.800878] audit: type=1130 audit(1648901627.823:750): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[275139.807199] atkbd serio0: Unknown key released (translated set 2, code 0xf8 on isa0060/serio0).
[275139.807202] atkbd serio0: Use 'setkeycodes e078 <keycode>' to make it known.
[275143.441464] wlp0s20f3: authenticate with 00:15:6d:9c:0f:9d
[275143.444150] wlp0s20f3: send auth to 00:15:6d:9c:0f:9d (try 1/3)
[275143.483449] wlp0s20f3: authenticated
[275143.486170] wlp0s20f3: associate with 00:15:6d:9c:0f:9d (try 1/3)
[275143.490132] wlp0s20f3: RX AssocResp from 00:15:6d:9c:0f:9d (capab=0x411 status=0 aid=5)
[275143.507112] wlp0s20f3: associated
[275143.569618] IPv6: ADDRCONF(NETDEV_CHANGE): wlp0s20f3: link becomes ready
[275144.982586] audit: type=1131 audit(1648901633.003:751): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-rfkill comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[275149.809171] audit: type=1131 audit(1648901637.830:752): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'

journalctl:

Apr 02 14:21:00 tommy-labs systemd[1]: Starting Load/Save RF Kill Switch Status...
Apr 02 14:21:00 tommy-labs kernel: atkbd serio0: Unknown key pressed (translated set 2, code 0xf8 on isa0060/serio0).
Apr 02 14:21:00 tommy-labs kernel: atkbd serio0: Use 'setkeycodes e078 <keycode>' to make it known.
Apr 02 14:21:00 tommy-labs NetworkManager[577]: <info>  [1648902060.6306] manager: rfkill: Wi-Fi now disabled by radio killswitch
Apr 02 14:21:00 tommy-labs NetworkManager[577]: <info>  [1648902060.6308] device (wlp0s20f3): state change: activated -> unavailable (reason 'none', sys-iface-state: 'managed')
Apr 02 14:21:00 tommy-labs NetworkManager[577]: <info>  [1648902060.6310] dhcp4 (wlp0s20f3): canceled DHCP transaction
Apr 02 14:21:00 tommy-labs NetworkManager[577]: <info>  [1648902060.6310] dhcp4 (wlp0s20f3): activation: beginning transaction (timeout in 45 seconds)
Apr 02 14:21:00 tommy-labs NetworkManager[577]: <info>  [1648902060.6310] dhcp4 (wlp0s20f3): state changed no lease
Apr 02 14:21:00 tommy-labs kernel: wlp0s20f3: deauthenticating from 00:15:6d:9c:0f:9d by local choice (Reason: 3=DEAUTH_LEAVING)
Apr 02 14:21:00 tommy-labs systemd[1]: Started Load/Save RF Kill Switch Status.
Apr 02 14:21:00 tommy-labs audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-rfkill comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Apr 02 14:21:00 tommy-labs wpa_supplicant[650]: wlp0s20f3: CTRL-EVENT-DISCONNECTED bssid=00:15:6d:9c:0f:9d reason=3 locally_generated=1
Apr 02 14:21:00 tommy-labs kernel: audit: type=1130 audit(1648902060.634:753): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-rfkill comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Apr 02 14:21:00 tommy-labs wpa_supplicant[650]: rfkill: WLAN soft blocked
Apr 02 14:21:00 tommy-labs wpa_supplicant[650]: rfkill: WLAN soft blocked
Apr 02 14:21:00 tommy-labs NetworkManager[577]: <info>  [1648902060.6581] device (wlp0s20f3): set-hw-addr: set MAC address to D6:75:06:9E:04:01 (scanning)
Apr 02 14:21:00 tommy-labs NetworkManager[577]: <info>  [1648902060.6585] manager: NetworkManager state is now DISCONNECTED
Apr 02 14:21:00 tommy-labs wpa_supplicant[650]: p2p-dev-wlp0s20: CTRL-EVENT-DSCP-POLICY clear_all
Apr 02 14:21:00 tommy-labs wpa_supplicant[650]: p2p-dev-wlp0s20: CTRL-EVENT-DSCP-POLICY clear_all
Apr 02 14:21:00 tommy-labs wpa_supplicant[650]: nl80211: deinit ifname=p2p-dev-wlp0s20 disabled_11b_rates=0
Apr 02 14:21:00 tommy-labs dbus-daemon[565]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.3' (uid=0 pid=577 comm="/usr/bin/NetworkManager --no-daemon")
Apr 02 14:21:00 tommy-labs systemd[1]: Starting Network Manager Script Dispatcher Service...
Apr 02 14:21:00 tommy-labs dbus-daemon[565]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Apr 02 14:21:00 tommy-labs systemd[1]: Started Network Manager Script Dispatcher Service.
Apr 02 14:21:00 tommy-labs 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'
Apr 02 14:21:00 tommy-labs kernel: audit: type=1130 audit(1648902060.661:754): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Apr 02 14:21:00 tommy-labs kernel: atkbd serio0: Unknown key released (translated set 2, code 0xf8 on isa0060/serio0).
Apr 02 14:21:00 tommy-labs kernel: atkbd serio0: Use 'setkeycodes e078 <keycode>' to make it known.
Apr 02 14:21:00 tommy-labs wpa_supplicant[650]: wlp0s20f3: CTRL-EVENT-DSCP-POLICY clear_all
Apr 02 14:21:00 tommy-labs NetworkManager[577]: <info>  [1648902060.6795] device (p2p-dev-wlp0s20f3): state change: disconnected -> unavailable (reason 'supplicant-failed', sys-iface-state: 'managed')
Apr 02 14:21:00 tommy-labs wpa_supplicant[650]: wlp0s20f3: CTRL-EVENT-DSCP-POLICY clear_all
Apr 02 14:21:00 tommy-labs wpa_supplicant[650]: nl80211: deinit ifname=wlp0s20f3 disabled_11b_rates=0
Apr 02 14:21:00 tommy-labs NetworkManager[577]: <info>  [1648902060.8458] manager: rfkill: Wi-Fi now enabled by radio killswitch
Apr 02 14:21:01 tommy-labs NetworkManager[577]: <info>  [1648902061.0898] device (wlp0s20f3): supplicant interface state: internal-starting -> disconnected
Apr 02 14:21:01 tommy-labs NetworkManager[577]: <info>  [1648902061.0899] device (p2p-dev-wlp0s20f3): state change: unavailable -> unmanaged (reason 'removed', sys-iface-state: 'removed')
Apr 02 14:21:01 tommy-labs NetworkManager[577]: <info>  [1648902061.0905] Wi-Fi P2P device controlled by interface wlp0s20f3 created
Apr 02 14:21:01 tommy-labs NetworkManager[577]: <info>  [1648902061.0910] manager: (p2p-dev-wlp0s20f3): new 802.11 Wi-Fi P2P device (/org/freedesktop/NetworkManager/Devices/40)
Apr 02 14:21:01 tommy-labs NetworkManager[577]: <info>  [1648902061.0913] device (p2p-dev-wlp0s20f3): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'external')
Apr 02 14:21:01 tommy-labs NetworkManager[577]: <info>  [1648902061.0920] device (wlp0s20f3): state change: unavailable -> disconnected (reason 'supplicant-available', sys-iface-state: 'managed')
Apr 02 14:21:01 tommy-labs NetworkManager[577]: <info>  [1648902061.0926] device (p2p-dev-wlp0s20f3): state change: unavailable -> disconnected (reason 'none', sys-iface-state: 'managed')
Apr 02 14:21:04 tommy-labs wpa_supplicant[650]: wlp0s20f3: CTRL-EVENT-REGDOM-CHANGE init=DRIVER type=COUNTRY alpha2=IT
Apr 02 14:21:04 tommy-labs NetworkManager[577]: <info>  [1648902064.5188] policy: auto-activating connection 'MYWIFI' (85c0663a-29e5-4d1a-8baf-10945fa243a3)
Apr 02 14:21:04 tommy-labs NetworkManager[577]: <info>  [1648902064.5190] device (wlp0s20f3): Activation: starting connection 'MYWIFI' (85c0663a-29e5-4d1a-8baf-10945fa243a3)
Apr 02 14:21:04 tommy-labs NetworkManager[577]: <info>  [1648902064.5191] device (wlp0s20f3): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Apr 02 14:21:04 tommy-labs NetworkManager[577]: <info>  [1648902064.5192] manager: NetworkManager state is now CONNECTING
Apr 02 14:21:04 tommy-labs NetworkManager[577]: <info>  [1648902064.5236] device (wlp0s20f3): set-hw-addr: reset MAC address to F4:26:79:F8:B5:6F (preserve)
Apr 02 14:21:04 tommy-labs NetworkManager[577]: <info>  [1648902064.5243] device (wlp0s20f3): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Apr 02 14:21:04 tommy-labs NetworkManager[577]: <info>  [1648902064.5244] device (wlp0s20f3): Activation: (wifi) access point 'MYWIFI' has security, but secrets are required.
Apr 02 14:21:04 tommy-labs NetworkManager[577]: <info>  [1648902064.5244] device (wlp0s20f3): state change: config -> need-auth (reason 'none', sys-iface-state: 'managed')
Apr 02 14:21:04 tommy-labs NetworkManager[577]: <info>  [1648902064.5249] device (wlp0s20f3): state change: need-auth -> prepare (reason 'none', sys-iface-state: 'managed')
Apr 02 14:21:04 tommy-labs NetworkManager[577]: <info>  [1648902064.5250] device (wlp0s20f3): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Apr 02 14:21:04 tommy-labs NetworkManager[577]: <info>  [1648902064.5251] device (wlp0s20f3): Activation: (wifi) connection 'MYWIFI' has security, and secrets exist.  No new secrets needed.
Apr 02 14:21:04 tommy-labs NetworkManager[577]: <info>  [1648902064.5251] Config: added 'ssid' value 'MYWIFI'
Apr 02 14:21:04 tommy-labs NetworkManager[577]: <info>  [1648902064.5251] Config: added 'scan_ssid' value '1'
Apr 02 14:21:04 tommy-labs NetworkManager[577]: <info>  [1648902064.5251] Config: added 'bgscan' value 'simple:30:-70:86400'
Apr 02 14:21:04 tommy-labs NetworkManager[577]: <info>  [1648902064.5251] Config: added 'key_mgmt' value 'WPA-PSK WPA-PSK-SHA256 FT-PSK SAE FT-SAE'
Apr 02 14:21:04 tommy-labs NetworkManager[577]: <info>  [1648902064.5251] Config: added 'auth_alg' value 'OPEN'
Apr 02 14:21:04 tommy-labs NetworkManager[577]: <info>  [1648902064.5251] Config: added 'psk' value '<hidden>'
Apr 02 14:21:04 tommy-labs NetworkManager[577]: <info>  [1648902064.5675] device (wlp0s20f3): supplicant interface state: disconnected -> inactive
Apr 02 14:21:04 tommy-labs NetworkManager[577]: <info>  [1648902064.5676] device (p2p-dev-wlp0s20f3): supplicant management interface state: disconnected -> inactive
Apr 02 14:21:04 tommy-labs wpa_supplicant[650]: wlp0s20f3: SME: Trying to authenticate with 00:15:6d:9c:0f:9d (SSID='MYWIFI' freq=2437 MHz)
Apr 02 14:21:04 tommy-labs kernel: wlp0s20f3: authenticate with 00:15:6d:9c:0f:9d
Apr 02 14:21:04 tommy-labs kernel: wlp0s20f3: send auth to 00:15:6d:9c:0f:9d (try 1/3)
Apr 02 14:21:04 tommy-labs NetworkManager[577]: <info>  [1648902064.5779] device (wlp0s20f3): supplicant interface state: inactive -> authenticating
Apr 02 14:21:04 tommy-labs NetworkManager[577]: <info>  [1648902064.5780] device (p2p-dev-wlp0s20f3): supplicant management interface state: inactive -> authenticating
Apr 02 14:21:04 tommy-labs wpa_supplicant[650]: wlp0s20f3: Trying to associate with 00:15:6d:9c:0f:9d (SSID='MYWIFI' freq=2437 MHz)
Apr 02 14:21:04 tommy-labs NetworkManager[577]: <info>  [1648902064.6134] device (wlp0s20f3): supplicant interface state: authenticating -> associating
Apr 02 14:21:04 tommy-labs NetworkManager[577]: <info>  [1648902064.6134] device (p2p-dev-wlp0s20f3): supplicant management interface state: authenticating -> associating
Apr 02 14:21:04 tommy-labs kernel: wlp0s20f3: authenticated
Apr 02 14:21:04 tommy-labs kernel: wlp0s20f3: associate with 00:15:6d:9c:0f:9d (try 1/3)
Apr 02 14:21:04 tommy-labs kernel: wlp0s20f3: RX AssocResp from 00:15:6d:9c:0f:9d (capab=0x411 status=0 aid=5)
Apr 02 14:21:04 tommy-labs wpa_supplicant[650]: wlp0s20f3: Associated with 00:15:6d:9c:0f:9d
Apr 02 14:21:04 tommy-labs wpa_supplicant[650]: wlp0s20f3: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
Apr 02 14:21:04 tommy-labs kernel: wlp0s20f3: associated
Apr 02 14:21:04 tommy-labs NetworkManager[577]: <info>  [1648902064.6427] device (wlp0s20f3): supplicant interface state: associating -> associated
Apr 02 14:21:04 tommy-labs NetworkManager[577]: <info>  [1648902064.6428] device (p2p-dev-wlp0s20f3): supplicant management interface state: associating -> associated
Apr 02 14:21:04 tommy-labs NetworkManager[577]: <info>  [1648902064.6584] device (wlp0s20f3): supplicant interface state: associated -> 4way_handshake
Apr 02 14:21:04 tommy-labs NetworkManager[577]: <info>  [1648902064.6585] device (p2p-dev-wlp0s20f3): supplicant management interface state: associated -> 4way_handshake
Apr 02 14:21:04 tommy-labs wpa_supplicant[650]: wlp0s20f3: WPA: Key negotiation completed with 00:15:6d:9c:0f:9d [PTK=CCMP GTK=TKIP]
Apr 02 14:21:04 tommy-labs wpa_supplicant[650]: wlp0s20f3: CTRL-EVENT-CONNECTED - Connection to 00:15:6d:9c:0f:9d completed [id=0 id_str=]
Apr 02 14:21:04 tommy-labs kernel: IPv6: ADDRCONF(NETDEV_CHANGE): wlp0s20f3: link becomes ready
Apr 02 14:21:04 tommy-labs NetworkManager[577]: <info>  [1648902064.7048] device (wlp0s20f3): supplicant interface state: 4way_handshake -> completed
Apr 02 14:21:04 tommy-labs NetworkManager[577]: <info>  [1648902064.7049] device (wlp0s20f3): Activation: (wifi) Stage 2 of 5 (Device Configure) successful. Connected to wireless network "MYWIFI"
Apr 02 14:21:04 tommy-labs wpa_supplicant[650]: wlp0s20f3: CTRL-EVENT-SIGNAL-CHANGE above=0 signal=-50 noise=9999 txrate=52000
Apr 02 14:21:04 tommy-labs NetworkManager[577]: <info>  [1648902064.7049] device (p2p-dev-wlp0s20f3): supplicant management interface state: 4way_handshake -> completed
Apr 02 14:21:04 tommy-labs NetworkManager[577]: <info>  [1648902064.7049] device (wlp0s20f3): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed')
Apr 02 14:21:04 tommy-labs NetworkManager[577]: <info>  [1648902064.7051] dhcp4 (wlp0s20f3): activation: beginning transaction (timeout in 45 seconds)
Apr 02 14:21:04 tommy-labs NetworkManager[577]: <info>  [1648902064.7299] dhcp4 (wlp0s20f3): state changed new lease, address=192.168.0.85
Apr 02 14:21:04 tommy-labs NetworkManager[577]: <info>  [1648902064.7326] device (wlp0s20f3): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'managed')
Apr 02 14:21:04 tommy-labs NetworkManager[577]: <info>  [1648902064.7340] device (wlp0s20f3): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'managed')
Apr 02 14:21:04 tommy-labs NetworkManager[577]: <info>  [1648902064.7341] device (wlp0s20f3): state change: secondaries -> activated (reason 'none', sys-iface-state: 'managed')
Apr 02 14:21:04 tommy-labs NetworkManager[577]: <info>  [1648902064.7342] manager: NetworkManager state is now CONNECTED_LOCAL
Apr 02 14:21:04 tommy-labs NetworkManager[577]: <info>  [1648902064.7364] manager: NetworkManager state is now CONNECTED_SITE
Apr 02 14:21:04 tommy-labs NetworkManager[577]: <info>  [1648902064.7364] policy: set 'MYWIFI' (wlp0s20f3) as default for IPv4 routing and DNS
Apr 02 14:21:04 tommy-labs NetworkManager[577]: <info>  [1648902064.7379] device (wlp0s20f3): Activation: successful, device activated.
Apr 02 14:21:04 tommy-labs NetworkManager[577]: <info>  [1648902064.8749] manager: NetworkManager state is now CONNECTED_GLOBAL
Apr 02 14:21:05 tommy-labs systemd[1]: systemd-rfkill.service: Deactivated successfully.
Apr 02 14:21:05 tommy-labs audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-rfkill comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Apr 02 14:21:05 tommy-labs kernel: audit: type=1131 audit(1648902065.847:755): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-rfkill comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'

ewaller · 2022-04-02 16:11:00

Could you please post the output of ls /etc/systemd/system
Are you running Gnome? Plasma?

SavageButcher · 2022-04-03 08:02:42

ewaller wrote:

Could you please post the output of ls /etc/systemd/system

Here:

dbus-org.freedesktop.nm-dispatcher.service  dbus-org.freedesktop.timesync1.service  getty.target.wants  multi-user.target.wants  network-online.target.wants  sysinit.target.wants  timers.target.wants

ewaller wrote:

Are you running Gnome? Plasma?

I'm running sway.

ewaller · 2022-04-03 15:43:16

Sway is good. It does not posses invisible hands that reach out and help you

Your systemd configuration looks okay, but I have never used nm-dispatcher.service. Usually I would just enable NetworkManager.service. I am suspicious as the stated goal of nm-dispatcher.service is to try to maintain a network connection at all times. I wonder if that means to the point of turning off airplane mode. (Pure speculation)

SavageButcher · 2022-04-03 20:08:07

ewaller wrote:

Sway is good. It does not posses invisible hands that reach out and help you

I know right? Love it <3

ewaller wrote:

Your systemd configuration looks okay, but I have never used nm-dispatcher.service. Usually I would just enable NetworkManager.service. I am suspicious as the stated goal of nm-dispatcher.service is to try to maintain a network connection at all times. I wonder if that means to the point of turning off airplane mode. (Pure speculation)

I'm not actually sure how nm-dispatcher.service got there; i tried disabling it anyway but the behaviour is the same.
The weird thing is that if instead i manually disable radios using `rfkill block all` it does not gets reverted, working as expected.

Arch Linux

#1 2022-04-02 12:42:56

Airplane Mode is instantly reverted

#2 2022-04-02 16:11:00

Re: Airplane Mode is instantly reverted

#3 2022-04-03 08:02:42

Re: Airplane Mode is instantly reverted

#4 2022-04-03 15:43:16

Re: Airplane Mode is instantly reverted

#5 2022-04-03 20:08:07

Re: Airplane Mode is instantly reverted

Board footer