Skip to content

Nullpointer deref in redpine driver breaks Wifi

What problem did you encounter

NetworkManager (or wpa_supplicant) Becomes unresponsive after connecting to wifi.

What is the actual behaviour?

After connecting to wifi with nmtui, commands like: ip addr that depend on NetworkManager sometimes don't respond. Also the wifi connection doesn't seem to actually connect after reboot.

What is the expected behaviour?

After connecting wifi, connections should work after reboot, and ip addr and other commands should print expected results.

How to reproduce

  • Run through the steps to flash the main image here: https://developer.puri.sm/Librem5/Development_Environment/Boards/imx8.html
  • Once the flash is complete reboot with ethernet, HDMI, and USB attached
  • Connect to the device over USB with picocom as documented in the above linked documentation.
  • Test ip addr get an expected response, also ping a known domain to test connectivity. Everything looks good at this point.
  • Update with apt update then apt upgrade
  • Reboot with reboot button
  • Once again Connect over USB and test ip addr get an expected response, also ping a known domain to test connectivity. Everything still looks good.
  • Use nmtui to connect to a wifi access point.
  • Reboot with reboot button
  • Try ip addr no response given, in fact ctrl-c won't quit the process.
  • Reboot with reboot button
  • Try nmcli d s devices are listed wifi is shown as disconnected
  • nmcli d wifi list won't list any access points
  • nmcli d wifi rescan returns Error: Scanning not allowed while already scanning.
  • nmtui shows no wifi access points either.
  • Pinging a domain returns no response and ctrl-c will not exit the process.
  • Reboot with reboot button.
  • Once the Reboot button is pressed the the GUI shell leaves the screen, but does not reboot. The three lights above the battery are all solid green.
  • Unplug / Remove battery & Replug USB
  • Try nmcli d s Response: Error: Could not create NMClient object: Timeout was reached.
  • Run systemctl status NetworkManager results (included below) include a warning about "sup-iface" though the full warning is cut off
  • Run journalctl -xe results (included below) include errors related to NetworkManager and wpa_supplicant
  • At this point if I reboot I still have network access through ethernet, upon reboot I can look at nmtui which intermittently doesn't load at all or loats with no wifi access points, or loads claiming it's connected to my access point.
  • With ethernet disconnected, if I ping an ip address it responds as unreachable, even when nmtui claims it's connected to an access point.
  • Also booting with ethernet disconnected takes much longer than without. (at least once I've tried to connect to an access point) With ethernet connected The boot process is within 5-10 seconds until the GUI shows on the monitor. With ethernet disconnected, the boot process sits with the 4 penguins on the screen for just over 2 minutes. I'm assuming this is while it's attempting to find a network.

What hardware are you running on?

Librem5 devkit

Relevant OS information

Which kernel are you using?

Linux pureos 4.18.11-g59f358aa #1 SMP PREEMPT Tue Dec 18 13:54:35 PST 2018 aarch64 GNU/Linux

Which OS are you using?

PRETTY_NAME="Debian GNU/Linux buster/sid" NAME="Debian GNU/Linux" ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/"

Any other information that may be helpful?

Depending on the nature of the issue, you may consider adding the output of:

  • lsblk (for mounting issues)
  • lsusb (for usb attachment issues)
# systemctl status NetworkManager

● NetworkManager.service - Network Manager
   Loaded: loaded (/lib/systemd/system/NetworkManager.service; enabled; vendor p
   Active: active (running) since Sun 2018-12-23 03:02:48 UTC; 2min 25s ago
     Docs: man:NetworkManager(8)
 Main PID: 2339 (NetworkManager)
    Tasks: 3 (limit: 3216)
   Memory: 10.4M
   CGroup: /system.slice/NetworkManager.service
           └─2339 /usr/sbin/NetworkManager --no-daemon

Dec 23 03:03:12 pureos dhclient[2793]: bound to 192.168.43.3 -- renewal in 1554 
Dec 23 03:03:12 pureos NetworkManager[2339]: <info>  [1545534192.4146] policy: s
Dec 23 03:03:12 pureos NetworkManager[2339]: <info>  [1545534192.4178] device (w
Dec 23 03:03:12 pureos NetworkManager[2339]: <info>  [1545534192.4273] manager: 
Dec 23 03:03:15 pureos NetworkManager[2339]: <info>  [1545534195.5804] supplican
Dec 23 03:03:15 pureos NetworkManager[2339]: <info>  [1545534195.5806] device (w
Dec 23 03:03:15 pureos NetworkManager[2339]: <warn>  [1545534195.5954] sup-iface
Dec 23 03:03:15 pureos NetworkManager[2339]: <info>  [1545534195.5964] device (w
Dec 23 03:03:15 pureos NetworkManager[2339]: <info>  [1545534195.6012] dhcp4 (wl
Dec 23 03:03:15 pureos NetworkManager[2339]: <info>  [1545534195.6013] dhcp4 (wl
  • any journalctl logs that look suspicious
# journalctl -xe

-- Unit UNIT has finished starting up.
-- 
-- The start-up result is RESULT.
Dec 23 03:03:09 pureos systemd[2764]: Startup finished in 164ms.
-- Subject: User manager start-up is now complete
-- Defined-By: systemd
-- Support: https://www.debian.org/support
-- 
-- The user manager instance for user 0 has been started. All services queued
-- for starting have been started. Note that other services might still be start
-- up or be started at any later time.
-- 
-- Startup of the manager took 164551 microseconds.
Dec 23 03:03:10 pureos login[2776]: ROOT LOGIN  on '/dev/ttyGS0'
Dec 23 03:03:10 pureos systemd[2764]: Started D-Bus User Message Bus.
-- Subject: Unit UNIT has finished start-up
-- Defined-By: systemd
-- Support: https://www.debian.org/support
-- 
-- Unit UNIT has finished starting up.
-- 
-- The start-up result is RESULT.
Dec 23 03:03:10 pureos wpa_supplicant[2328]: wlan0: CTRL-EVENT-REGDOM-CHANGE ini
Dec 23 03:03:11 pureos wpa_supplicant[2328]: wlan0: SME: Trying to authenticate 
Dec 23 03:03:11 pureos kernel: wlan0: authenticate with 02:1a:11:f7:78:9b
Dec 23 03:03:11 pureos kernel: wlan0: send auth to 02:1a:11:f7:78:9b (try 1/3)
Dec 23 03:03:11 pureos wpa_supplicant[2328]: wlan0: Trying to associate with 02:
Dec 23 03:03:11 pureos kernel: wlan0: authenticated
Dec 23 03:03:11 pureos kernel: wlan0: associate with 02:1a:11:f7:78:9b (try 1/3)
Dec 23 03:03:11 pureos wpa_supplicant[2328]: wlan0: Associated with 02:1a:11:f7:
Dec 23 03:03:11 pureos wpa_supplicant[2328]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPD
Dec 23 03:03:11 pureos kernel: wlan0: RX AssocResp from 02:1a:11:f7:78:9b (capab
Dec 23 03:03:11 pureos kernel: wlan0: associated
Dec 23 03:03:11 pureos NetworkManager[2339]: <info>  [1545534191.8545] device (w
Dec 23 03:03:11 pureos NetworkManager[2339]: <info>  [1545534191.8628] device (w
Dec 23 03:03:11 pureos kernel: wlan0: Limiting TX power to 30 (30 - 0) dBm as ad
Dec 23 03:03:11 pureos wpa_supplicant[2328]: wlan0: CTRL-EVENT-SIGNAL-CHANGE abo
Dec 23 03:03:12 pureos NetworkManager[2339]: <info>  [1545534192.0038] device (w
Dec 23 03:03:12 pureos kernel: rsi_91x: EAPOL 4 confirm
Dec 23 03:03:12 pureos kernel: rsi_91x: rsi_hal_key_config: Cipher 0xfac04 key_t
Dec 23 03:03:12 pureos kernel: rsi_91x: rsi_mac80211_set_key: RSI set_key
Dec 23 03:03:12 pureos wpa_supplicant[2328]: wlan0: WPA: Key negotiation complet
Dec 23 03:03:12 pureos wpa_supplicant[2328]: wlan0: CTRL-EVENT-CONNECTED - Conne
Dec 23 03:03:12 pureos systemd-networkd[2267]: wlan0: Gained carrier
Dec 23 03:03:12 pureos kernel: rsi_91x: rsi_hal_key_config: Cipher 0xfac04 key_t
Dec 23 03:03:12 pureos kernel: rsi_91x: rsi_mac80211_set_key: RSI set_key
Dec 23 03:03:12 pureos kernel: IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link become
Dec 23 03:03:12 pureos NetworkManager[2339]: <info>  [1545534192.0382] device (w
Dec 23 03:03:12 pureos NetworkManager[2339]: <info>  [1545534192.0383] device (w
Dec 23 03:03:12 pureos NetworkManager[2339]: <info>  [1545534192.0402] device (w
Dec 23 03:03:12 pureos NetworkManager[2339]: <info>  [1545534192.0428] dhcp4 (wl
Dec 23 03:03:12 pureos NetworkManager[2339]: <info>  [1545534192.0482] dhcp4 (wl
Dec 23 03:03:12 pureos dhclient[2793]: DHCPREQUEST for 192.168.43.3 on wlan0 to 
Dec 23 03:03:12 pureos dhclient[2793]: DHCPACK of 192.168.43.3 from 192.168.43.1
Dec 23 03:03:12 pureos NetworkManager[2339]: <info>  [1545534192.3899] dhcp4 (wl
Dec 23 03:03:12 pureos NetworkManager[2339]: <info>  [1545534192.3902] dhcp4 (wl
Dec 23 03:03:12 pureos NetworkManager[2339]: <info>  [1545534192.3903] dhcp4 (wl
Dec 23 03:03:12 pureos NetworkManager[2339]: <info>  [1545534192.3903] dhcp4 (wl
Dec 23 03:03:12 pureos NetworkManager[2339]: <info>  [1545534192.3904] dhcp4 (wl
Dec 23 03:03:12 pureos NetworkManager[2339]: <info>  [1545534192.3904] dhcp4 (wl
Dec 23 03:03:12 pureos NetworkManager[2339]: <info>  [1545534192.3904] dhcp4 (wl
Dec 23 03:03:12 pureos NetworkManager[2339]: <info>  [1545534192.3971] device (w
Dec 23 03:03:12 pureos NetworkManager[2339]: <info>  [1545534192.4004] device (w
Dec 23 03:03:12 pureos NetworkManager[2339]: <info>  [1545534192.4013] device (w
Dec 23 03:03:12 pureos dhclient[2793]: bound to 192.168.43.3 -- renewal in 1554 
Dec 23 03:03:12 pureos NetworkManager[2339]: <info>  [1545534192.4146] policy: s
Dec 23 03:03:12 pureos NetworkManager[2339]: <info>  [1545534192.4178] device (w
Dec 23 03:03:12 pureos gsd-sharing[2551]: Failed to StopUnit service: GDBus.Erro
Dec 23 03:03:12 pureos gsd-sharing[2551]: Failed to StopUnit service: GDBus.Erro
Dec 23 03:03:12 pureos gsd-sharing[2551]: Failed to StopUnit service: GDBus.Erro
Dec 23 03:03:12 pureos gsd-sharing[2551]: Failed to StopUnit service: GDBus.Erro
Dec 23 03:03:12 pureos dbus-daemon[2311]: [system] Activating via systemd: servi
Dec 23 03:03:12 pureos NetworkManager[2339]: <info>  [1545534192.4273] manager: 
Dec 23 03:03:12 pureos systemd[1]: Starting Network Manager Script Dispatcher Se
-- Subject: Unit NetworkManager-dispatcher.service has begun start-up
-- Defined-By: systemd
-- Support: https://www.debian.org/support
-- 
-- Unit NetworkManager-dispatcher.service has begun starting up.
Dec 23 03:03:12 pureos wpa_supplicant[2328]: wlan0: CTRL-EVENT-SIGNAL-CHANGE abo
Dec 23 03:03:12 pureos dbus-daemon[2311]: [system] Successfully activated servic
Dec 23 03:03:12 pureos systemd[1]: Started Network Manager Script Dispatcher Ser
-- Subject: Unit NetworkManager-dispatcher.service has finished start-up
-- Defined-By: systemd
-- Support: https://www.debian.org/support
-- 
-- Unit NetworkManager-dispatcher.service has finished starting up.
-- 
-- The start-up result is RESULT.
Dec 23 03:03:12 pureos nm-dispatcher[2803]: req:1 'up' [wlan0]: new request (1 s
Dec 23 03:03:12 pureos nm-dispatcher[2803]: req:1 'up' [wlan0]: start running or
Dec 23 03:03:12 pureos nm-dispatcher[2803]: req:2 'connectivity-change': new req
Dec 23 03:03:12 pureos nm-dispatcher[2803]: req:2 'connectivity-change': start r
Dec 23 03:03:13 pureos systemd-networkd[2267]: wlan0: Gained IPv6LL
Dec 23 03:03:15 pureos wpa_supplicant[2328]: wlan0: CTRL-EVENT-SIGNAL-CHANGE abo
Dec 23 03:03:15 pureos kernel: Unable to handle kernel NULL pointer dereference 
Dec 23 03:03:15 pureos kernel: Mem abort info:
Dec 23 03:03:15 pureos kernel:   ESR = 0x96000004
Dec 23 03:03:15 pureos kernel:   Exception class = DABT (current EL), IL = 32 bi
Dec 23 03:03:15 pureos kernel:   SET = 0, FnV = 0
Dec 23 03:03:15 pureos kernel:   EA = 0, S1PTW = 0
Dec 23 03:03:15 pureos kernel: Data abort info:
Dec 23 03:03:15 pureos kernel:   ISV = 0, ISS = 0x00000004
Dec 23 03:03:15 pureos kernel:   CM = 0, WnR = 0
Dec 23 03:03:15 pureos kernel: user pgtable: 4k pages, 48-bit VAs, pgdp = 000000
Dec 23 03:03:15 pureos kernel: [00000000000000d0] pgd=0000000000000000
Dec 23 03:03:15 pureos kernel: Internal error: Oops: 96000004 [#1] PREEMPT SMP
Dec 23 03:03:15 pureos kernel: Modules linked in: aes_ce_ccm qmi_wwan cdc_wdm us
Dec 23 03:03:15 pureos kernel: CPU: 2 PID: 2328 Comm: wpa_supplicant Not tainted
Dec 23 03:03:15 pureos kernel: Hardware name: Purism Librem 5 devkit (DT)
Dec 23 03:03:15 pureos kernel: pstate: 20000005 (nzCv daif -PAN -UAO)
Dec 23 03:03:15 pureos kernel: pc : rsi_send_probe_request+0x16c/0x328 [rsi_91x]
Dec 23 03:03:15 pureos kernel: lr : rsi_send_probe_request+0x158/0x328 [rsi_91x]
Dec 23 03:03:15 pureos kernel: sp : ffff8000a1eaf7e0
Dec 23 03:03:15 pureos kernel: x29: ffff8000a1eaf7e0 x28: ffff80008c9c8bb8 
Dec 23 03:03:15 pureos kernel: x27: ffff8000a73c30c8 x26: ffff80008c9c8bb8 
Dec 23 03:03:15 pureos kernel: x25: ffff8000a73c23d9 x24: 0000000000000000 
Dec 23 03:03:15 pureos kernel: x23: 000000000000007a x22: ffff8000a1f92c40 
Dec 23 03:03:15 pureos kernel: x21: 0000000000000001 x20: ffff8000a73c2000 
Dec 23 03:03:15 pureos kernel: x19: 000000000000000e x18: ffff000008b76000 
Dec 23 03:03:15 pureos kernel: x17: 0000000000000000 x16: 0000000000000000 
Dec 23 03:03:15 pureos kernel: x15: ffff8000a1f92c00 x14: 0100000000000000 
Dec 23 03:03:15 pureos kernel: x13: 00000000ff01006e x12: 1a2d6c6048302418 
Dec 23 03:03:15 pureos kernel: x11: 120c080100000000 x10: 0000000000000100 
Dec 23 03:03:15 pureos kernel: x9 : 0000000000000000 x8 : 0000ff01006e1a2d 
Dec 23 03:03:15 pureos kernel: x7 : 6c60483004322418 x6 : ffff8000a73c242b 
Dec 23 03:03:15 pureos kernel: x5 : ffff8000abf85e30 x4 : 0000000000000008 
Dec 23 03:03:15 pureos kernel: x3 : 0000000000000000 x2 : ffffffffffffffca 
Dec 23 03:03:15 pureos kernel: x1 : ffff8000a1f92e4a x0 : ffff8000a73c23d9 
Dec 23 03:03:15 pureos kernel: Process wpa_supplicant (pid: 2328, stack limit = 
Dec 23 03:03:15 pureos kernel: Call trace:
Dec 23 03:03:15 pureos kernel:  rsi_send_probe_request+0x16c/0x328 [rsi_91x]
Dec 23 03:03:15 pureos kernel:  rsi_mac80211_hw_scan_start+0x168/0x200 [rsi_91x]
Dec 23 03:03:15 pureos kernel:  __ieee80211_start_scan+0x260/0x818
Dec 23 03:03:15 pureos kernel:  ieee80211_request_scan+0x34/0x58
Dec 23 03:03:15 pureos kernel:  ieee80211_scan+0x58/0xd0
Dec 23 03:03:15 pureos kernel:  nl80211_trigger_scan+0x5ac/0x820
Dec 23 03:03:15 pureos kernel:  genl_family_rcv_msg+0x248/0x368
Dec 23 03:03:15 pureos kernel:  genl_rcv_msg+0x60/0xa8
Dec 23 03:03:15 pureos kernel:  netlink_rcv_skb+0xf0/0x138
Dec 23 03:03:15 pureos kernel:  genl_rcv+0x3c/0x50
Dec 23 03:03:15 pureos kernel:  netlink_unicast+0x198/0x218
Dec 23 03:03:15 pureos kernel:  netlink_sendmsg+0x274/0x340
Dec 23 03:03:15 pureos kernel:  sock_sendmsg+0x34/0x50
Dec 23 03:03:15 pureos kernel:  ___sys_sendmsg+0x28c/0x2b8
Dec 23 03:03:15 pureos kernel:  __sys_sendmsg+0x78/0xd0
Dec 23 03:03:15 pureos kernel:  sys_sendmsg+0x38/0x48
Dec 23 03:03:15 pureos kernel:  el0_svc_naked+0x30/0x34
Dec 23 03:03:15 pureos kernel: Code: 54fffba1 110062f7 7101e2ff 540002c9 (f9406b
Dec 23 03:03:15 pureos kernel: ---[ end trace 15322be8d420ef7f ]---
Dec 23 03:03:15 pureos systemd[1]: wpa_supplicant.service: Main process exited, 
Dec 23 03:03:15 pureos systemd[1]: wpa_supplicant.service: Failed with result 's
Dec 23 03:03:15 pureos NetworkManager[2339]: <info>  [1545534195.5804] supplican
Dec 23 03:03:15 pureos NetworkManager[2339]: <info>  [1545534195.5806] device (w
Dec 23 03:03:15 pureos NetworkManager[2339]: <warn>  [1545534195.5954] sup-iface
Dec 23 03:03:15 pureos NetworkManager[2339]: <info>  [1545534195.5964] device (w
Dec 23 03:03:15 pureos NetworkManager[2339]: <info>  [1545534195.6012] dhcp4 (wl
Dec 23 03:03:15 pureos NetworkManager[2339]: <info>  [1545534195.6013] dhcp4 (wl
Edited by Guido Gunther