Re: Dealing with wifi driver crash that doesn't remove wlan interface

[James Prestwood <prestwoj@gmail.com>]

Hi Bryce,

On 7/15/25 10:28 AM, Bryce Johnson wrote:
> Hi All,
> Long shot if there is something I can do with iwd, but I figured I'd
> ask... We are dealing with an occasional wifi-driver crash on silabs
> wf200 that silabs hasn't been able to fix... so we had implemented a
> workaround that seems to be working fairly well up until now.
>
>  From our wifi provisioning application, we query a few params over
> dbus periodically and log them:
> mac_address: "70:c5:9c:xx:xx:xx"
> ssid: "xxxxxxxx"
> freq: 2412
> rssi: -32
> security: "WPA2-Personal"
>
> If our dbus path fails in our application it will trigger the
> wifi-driver to be restarted.  That fixes many of the issues, but we
> ran into an issue at a friendly customer site, where the driver
> failed, but apparently left enough up where the wlan0 was up and iwd
> was just getting stale data from it.
>
> The correct answer is for silabs to fix the driver, but I was
> wondering if there were any other additional workarounds I could try
> in the meantime...

I'm not sure there is much within IWD that can be done. I've run into 
similar problems and about all you can do is implement some kind of 
watchdog which monitors for these conditions (which sounds like you've 
done). The difficult part is detecting these conditions. I've even 
monitored journalctl and scraped IWD logs to gain more state info about 
IWD than what is advertised on DBus. This is actually why I added the 
l_notice "events" to IWD, the idea being that they are a consistently 
formatted, tool parse-able lines containing additional information, e.g.

event: roam-info, bss: aa:bb:cc:dd:ee:ff, signal: -41, load: 9/255

Hope this helps,

- James

>
> This in on iwd 3.4, Here is a snip of the iwd log with debug enabled:
>
> at ~2025-07-14 18:45: the driver crashed:
> dmesg: [ 3253.325450] wfx-spi spi0.0: firmware exception
>
> at ~2025-07-15 16:20 we manually restarted the driver
> dmesg: [80768.916153] wlan0: deauthenticating from 90:09:d0:42:07:56
> by local choice (Reason: 3=DEAUTH_LEAVING)
>
>
> 2025-07-14 17:58:11.565200658  src/station.c:station_print_scan_bss()
> Processing BSS '38:70:0c:41:d2:b8' with SSID: ROBBY, freq: 2462, rank:
> 37, strength: -8500, data_rate: 5.5
> 2025-07-14 17:58:11.566580887  src/station.c:station_print_scan_bss()
> Processing BSS '18:90:88:2e:88:05' with SSID: , freq: 2412, rank: 13,
> strength: -8800, data_rate: 2.0
> 2025-07-14 17:58:11.566801362  src/station.c:station_add_seen_bss()
> BSS has hidden SSID
> 2025-07-14 17:58:11.566967170  src/station.c:station_print_scan_bss()
> Processing BSS '64:51:06:db:a5:ae' with SSID: HP-Print-AE-Photosmart
> 6520, freq: 2412, rank: 13, strength: -8800, data_rate: 2.0
> 2025-07-14 17:58:11.569713212  src/station.c:station_print_scan_bss()
> Processing BSS '76:54:25:16:80:39' with SSID: , freq: 2462, rank: 13,
> strength: -9100, data_rate: 2.0
> 2025-07-14 17:58:11.569950527  src/station.c:station_add_seen_bss()
> BSS has hidden SSID
> 2025-07-14 17:58:11.570111448  src/station.c:station_print_scan_bss()
> Processing BSS '1c:39:29:02:b4:c5' with SSID:
> AT_401_WIN_056905_WW_b4c5, freq: 2462, rank: 13, strength: -9200,
> data_rate: 2.0
> 2025-07-14 17:58:11.573726453  src/wiphy.c:wiphy_radio_work_done()
> Work item 4 done
> 2025-07-14 17:58:11.575809796  src/netdev.c:netdev_link_notify() event
> 16 on ifindex 2
> 2025-07-14 17:58:17.677447209  src/netdev.c:netdev_link_notify() event
> 16 on ifindex 6
> 2025-07-14 17:58:17.677731675  src/netdev.c:netdev_link_notify() event
> 16 on ifindex 5
> 2025-07-14 17:59:23.451727924  src/netdev.c:netdev_link_notify() event
> 16 on ifindex 5
> 2025-07-14 17:59:23.463000704  src/netdev.c:netdev_link_notify() event
> 16 on ifindex 5
> 2025-07-14 17:59:23.482318002  src/netdev.c:netdev_link_notify() event
> 16 on ifindex 5
> 2025-07-14 17:59:23.483857888  src/netdev.c:netdev_link_notify() event
> 17 on ifindex 5
> 2025-07-14 17:59:23.485664308  src/netdev.c:netdev_link_notify() event
> 16 on ifindex 4
> 2025-07-14 17:59:23.487021309  src/netdev.c:netdev_link_notify() event
> 17 on ifindex 5
> 2025-07-14 17:59:31.211091899  src/netdev.c:netdev_link_notify() event
> 16 on ifindex 8
> 2025-07-14 17:59:31.213708170  src/netdev.c:netdev_link_notify() event
> 16 on ifindex 8
> 2025-07-14 17:59:31.276263723  src/netdev.c:netdev_link_notify() event
> 16 on ifindex 8
> 2025-07-14 17:59:31.283333624  src/netdev.c:netdev_link_notify() event
> 16 on ifindex 8
> 2025-07-14 17:59:31.285134352  src/netdev.c:netdev_link_notify() event
> 16 on ifindex 8
> 2025-07-14 17:59:31.286224134  src/netdev.c:netdev_link_notify() event
> 16 on ifindex 4
> 2025-07-14 17:59:31.288634631  src/netdev.c:netdev_link_notify() event
> 16 on ifindex 8
> 2025-07-14 17:59:31.289996567  src/netdev.c:netdev_link_notify() event
> 16 on ifindex 8
> 2025-07-14 17:59:31.339801875  src/netdev.c:netdev_link_notify() event
> 16 on ifindex 8
> 2025-07-14 17:59:31.340068480  src/netdev.c:netdev_link_notify() event
> 16 on ifindex 8
> 2025-07-14 17:59:31.341316514  src/netdev.c:netdev_link_notify() event
> 16 on ifindex 8
> 2025-07-14 17:59:46.764125543  src/netdev.c:netdev_link_notify() event
> 16 on ifindex 8
> 2025-07-14 18:45:50.472050964  src/netdev.c:netdev_unicast_notify()
> Unicast notification Control Port Frame(129)
> 2025-07-14 18:45:50.472323982  src/netdev.c:netdev_control_port_frame_event()
> 2025-07-14 18:45:50.489657876  src/eapol.c:eapol_handle_gtk_1_of_2() ifindex=2
> 2025-07-14 18:45:50.503031733  src/netdev.c:netdev_set_gtk() ifindex=2 key_idx=2
> 2025-07-14 18:45:50.526112177  src/netdev.c:netdev_new_group_key_cb()
> ifindex: 2, err: 0
> 2025-07-14 18:45:50.527560761  src/netdev.c:try_handshake_complete()
> ptk_installed: 1, gtk_installed: 1, igtk_installed: 1
> 2025-07-14 18:45:50.528956809  src/netdev.c:try_handshake_complete()
> nhs->complete: 1
> 2025-07-14 18:45:50.559356169  src/netdev.c:netdev_mlme_notify() MLME
> notification Control Port TX Status(139)
> 2025-07-15 16:20:46.865790966  src/netdev.c:netdev_mlme_notify() MLME
> notification Notify CQM(64)
> 2025-07-15 16:20:46.866248149  src/station.c:station_packets_lost()
> Packets lost event: 50
> 2025-07-15 16:20:46.866559823  src/station.c:station_start_roam()
> Requesting neighbor report for roam
> 2025-07-15 16:20:49.674634613  src/netdev.c:netdev_link_notify() event
> 16 on ifindex 2
> 2025-07-15 16:20:49.689872602  src/netdev.c:netdev_link_notify() event
> 16 on ifindex 2
> 2025-07-15 16:20:49.690157914
> src/station.c:station_neighbor_report_cb() ifindex: 2, error:
> -107(Transport endpoint is not connected)
> 2025-07-15 16:20:49.690321414
> src/station.c:station_neighbor_report_cb() no neighbor report results
> or known freqs
> 2025-07-15 16:20:49.690755567  src/station.c:station_roam_failed() 2
> 2025-07-15 16:20:49.690928478  src/station.c:station_free()
> 2025-07-15 16:20:49.691063826  src/netconfig.c:netconfig_destroy()
> 2025-07-15 16:20:49.694320325
> src/netconfig.c:netconfig_event_handler() l_netconfig event 2
> 2025-07-15 16:20:49.696345663
> src/netconfig-commit.c:netconfig_commit_print_addrs() removing
> address: 192.168.1.100
> 2025-07-15 16:20:52.482746720  resolve: /sbin/resolvconf exited with
> status (36096).
> 2025-07-15 16:20:52.483011183  src/station.c:station_roam_state_clear() 2
> 2025-07-15 16:20:52.520806556  src/netdev.c:netdev_link_notify() event
> 17 on ifindex 2
> 2025-07-15 16:20:52.522040814  src/netdev.c:netdev_free() Freeing
> netdev wlan0[2]
> 2025-07-15 16:20:52.524139481  src/device.c:device_free()
> 2025-07-15 16:20:52.526958891  Removing scan context for wdev 1
>