All of lore.kernel.org
 help / color / mirror / Atom feed
* Dealing with wifi driver crash that doesn't remove wlan interface
@ 2025-07-15 17:28 Bryce Johnson
  2025-07-22 13:11 ` James Prestwood
  0 siblings, 1 reply; 3+ messages in thread
From: Bryce Johnson @ 2025-07-15 17:28 UTC (permalink / raw)
  To: iwd

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...

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

^ permalink raw reply	[flat|nested] 3+ messages in thread

* Re: Dealing with wifi driver crash that doesn't remove wlan interface
  2025-07-15 17:28 Dealing with wifi driver crash that doesn't remove wlan interface Bryce Johnson
@ 2025-07-22 13:11 ` James Prestwood
  2025-07-22 13:36   ` Bryce Johnson
  0 siblings, 1 reply; 3+ messages in thread
From: James Prestwood @ 2025-07-22 13:11 UTC (permalink / raw)
  To: Bryce Johnson, iwd

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
>

^ permalink raw reply	[flat|nested] 3+ messages in thread

* Re: Dealing with wifi driver crash that doesn't remove wlan interface
  2025-07-22 13:11 ` James Prestwood
@ 2025-07-22 13:36   ` Bryce Johnson
  0 siblings, 0 replies; 3+ messages in thread
From: Bryce Johnson @ 2025-07-22 13:36 UTC (permalink / raw)
  To: James Prestwood; +Cc: iwd

Hi James,
Thanks for the response.
>
> 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
>
Yeah I'm on watchdog v2 and thought it covered everything, but looks
like I need to add some more checks for this more rare case. (Only
seen once or twice so far)  For the most part I don't have direct
access to the devices, so I just get the logs, need to try a fix and
see if that reduces the issues.

Bryce

^ permalink raw reply	[flat|nested] 3+ messages in thread

end of thread, other threads:[~2025-07-22 13:36 UTC | newest]

Thread overview: 3+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2025-07-15 17:28 Dealing with wifi driver crash that doesn't remove wlan interface Bryce Johnson
2025-07-22 13:11 ` James Prestwood
2025-07-22 13:36   ` Bryce Johnson

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.