WL1837MOD: Hardware recovery triggered by large disturbances

Hi Mattias,

Before we look at the other post, can you share the logs you are seeing? What kernel version and wl18xx FW version are you using?

Could you also describe the test and goal you are trying to accomplish? What is the goal of injecting this signal?

Hi

We are running kernel version 5.10.72 and we have tried 5.15.71. Both from Freescales Yocto trees, with some of yours patches applied. Firmware version is 8.9.1.0.0, we have also tried your latest. We are running your wpa_supplicant version, 2.10.

This if from a customer site that is severely affected. As you can see from the count of firmware recoveries and the uptime in the log there is a recovery every ~5 seconds.

[11289.623780] wlcore: WARNING Unable to flush all TX buffers, timed out (timeout 500 ms
[11290.173743] wlcore: WARNING Unable to flush all TX buffers, timed out (timeout 500 ms
[11290.200866] br0: port 3(wlan0_mesh) entered disabled state
[11290.816459] wlcore: ERROR SW watchdog interrupt received! starting recovery.
[11290.823628] ------------[ cut here ]------------
[11290.828393] WARNING: CPU: 0 PID: 146 at drivers/net/wireless/ti/wlcore/main.c:870 wl12xx_queue_recovery_work+0x5c/0x60 [wlcore]
[11290.840022] Modules linked in: iptable_filter iptable_nat nf_nat nf_conntrack nf_defrag_ipv6 libcrc32c nf_defrag_ipv4 ip_tables x_tables wlcore_sdio wl18xx wlcore mac80211 cfg80211
[11290.856333] CPU: 0 PID: 146 Comm: irq/196-wl18xx Tainted: G        W         5.10.72-garo-10 #1
[11290.865045] Hardware name: Freescale i.MX6 Ultralite (Device Tree)
[11290.871276] [<8010edfc>] (unwind_backtrace) from [<8010a308>] (show_stack+0x10/0x14)
[11290.879050] [<8010a308>] (show_stack) from [<80b5b804>] (dump_stack+0x98/0xac)
[11290.886305] [<80b5b804>] (dump_stack) from [<80b57988>] (__warn+0xc0/0xd8)
[11290.893211] [<80b57988>] (__warn) from [<80b57a04>] (warn_slowpath_fmt+0x64/0xc8)
[11290.900801] [<80b57a04>] (warn_slowpath_fmt) from [<7f0dafe4>] (wl12xx_queue_recovery_work+0x5c/0x60 [wlcore])
[11290.910943] [<7f0dafe4>] (wl12xx_queue_recovery_work [wlcore]) from [<7f0db738>] (wlcore_irq+0xd0/0x1b0 [wlcore])
[11290.921291] [<7f0db738>] (wlcore_irq [wlcore]) from [<8017bb2c>] (irq_thread_fn+0x1c/0x78)
[11290.929590] [<8017bb2c>] (irq_thread_fn) from [<8017be48>] (irq_thread+0x134/0x200)
[11290.937280] [<8017be48>] (irq_thread) from [<8014e65c>] (kthread+0x150/0x190)
[11290.944448] [<8014e65c>] (kthread) from [<80100148>] (ret_from_fork+0x14/0x2c)
[11290.951686] Exception stack(0x84c67fb0 to 0x84c67ff8)
[11290.956756] 7fa0:                                     00000000 00000000 00000000 00000000
[11290.964954] 7fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[11290.973149] 7fe0: 00000000 00000000 00000000 00000000 00000013 00000000
[11290.980008] ---[ end trace 6192ce2e2b4a183d ]---
[11290.990418] wlcore: Hardware recovery in progress. FW ver: Rev 8.9.1.0.0
[11291.010290] wlcore: pc: 0x107e76, hint_sts: 0x00000000 count: 2059
[11291.024069] wlcore: down
[11291.028299] wlcore: down
[11291.037310] ieee80211 phy0: Hardware restart was requested
[11291.534083] wlcore: PHY firmware version: Rev 8.2.0.0.246
[11291.595654] wlcore: firmware booted (Rev 8.9.1.0.0)
[11292.703647] wlcore: WARNING Unable to flush all TX buffers, timed out (timeout 500 ms
[11293.233808] wlcore: WARNING Unable to flush all TX buffers, timed out (timeout 500 ms
[11293.763577] wlcore: WARNING Unable to flush all TX buffers, timed out (timeout 500 ms
[11295.783626] wlcore: ERROR command complete timeout
[11295.789028] ------------[ cut here ]------------
[11295.795353] WARNING: CPU: 0 PID: 17914 at drivers/net/wireless/ti/wlcore/main.c:870 wl12xx_queue_recovery_work+0x5c/0x60 [wlcore]
[11295.811227] Modules linked in: iptable_filter iptable_nat nf_nat nf_conntrack nf_defrag_ipv6 libcrc32c nf_defrag_ipv4 ip_tables x_tables wlcore_sdio wl18xx wlcore mac80211 cfg80211
[11295.828362] CPU: 0 PID: 17914 Comm: hostapd Tainted: G        W         5.10.72-garo-10 #1
[11295.836644] Hardware name: Freescale i.MX6 Ultralite (Device Tree)
[11295.842865] [<8010edfc>] (unwind_backtrace) from [<8010a308>] (show_stack+0x10/0x14)
[11295.850631] [<8010a308>] (show_stack) from [<80b5b804>] (dump_stack+0x98/0xac)
[11295.857879] [<80b5b804>] (dump_stack) from [<80b57988>] (__warn+0xc0/0xd8)
[11295.864774] [<80b57988>] (__warn) from [<80b57a04>] (warn_slowpath_fmt+0x64/0xc8)
[11295.872353] [<80b57a04>] (warn_slowpath_fmt) from [<7f0dafe4>] (wl12xx_queue_recovery_work+0x5c/0x60 [wlcore])
[11295.882448] [<7f0dafe4>] (wl12xx_queue_recovery_work [wlcore]) from [<7f0de8a8>] (wlcore_cmd_send_failsafe+0x33c/0x524 [wlcore])
[11295.894099] [<7f0de8a8>] (wlcore_cmd_send_failsafe [wlcore]) from [<7f0dfd44>] (wlcore_cmd_configure_failsafe+0x54/0xe8 [wlcore])
[11295.905836] [<7f0dfd44>] (wlcore_cmd_configure_failsafe [wlcore]) from [<7f0dfdec>] (wl1271_cmd_configure+0x14/0x20 [wlcore])
[11295.917222] [<7f0dfdec>] (wl1271_cmd_configure [wlcore]) from [<7f0e6888>] (wl1271_acx_tx_power+0x70/0xdc [wlcore])
[11295.927741] [<7f0e6888>] (wl1271_acx_tx_power [wlcore]) from [<7f0d6570>] (wl1271_op_config+0xb8/0x198 [wlcore])
[11295.938144] [<7f0d6570>] (wl1271_op_config [wlcore]) from [<7f04fbf8>] (ieee80211_hw_config+0x5c/0x330 [mac80211])
[11295.948683] [<7f04fbf8>] (ieee80211_hw_config [mac80211]) from [<7f08bee8>] (ieee80211_free_chanctx+0xa0/0xfc [mac80211])
[11295.959816] [<7f08bee8>] (ieee80211_free_chanctx [mac80211]) from [<7f08e3a0>] (__ieee80211_vif_release_channel+0xfc/0x140 [mac80211])
[11295.972062] [<7f08e3a0>] (__ieee80211_vif_release_channel [mac80211]) from [<7f08ec44>] (ieee80211_vif_release_channel+0x50/0x60 [mac80211])
[11295.984831] [<7f08ec44>] (ieee80211_vif_release_channel [mac80211]) from [<7f06c914>] (ieee80211_stop_ap+0x1ec/0x2cc [mac80211])
[11295.996598] [<7f06c914>] (ieee80211_stop_ap [mac80211]) from [<7f03581c>] (__cfg80211_stop_ap+0x4c/0xf0 [cfg80211])
[11296.007175] [<7f03581c>] (__cfg80211_stop_ap [cfg80211]) from [<7f0358f0>] (cfg80211_stop_ap+0x30/0x44 [cfg80211])
[11296.017602] [<7f0358f0>] (cfg80211_stop_ap [cfg80211]) from [<80a359b4>] (genl_rcv_msg+0x188/0x368)
[11296.026671] [<80a359b4>] (genl_rcv_msg) from [<80a3353c>] (netlink_rcv_skb+0xc0/0x120)
[11296.034604] [<80a3353c>] (netlink_rcv_skb) from [<80a33cb0>] (genl_rcv+0x24/0x34)
[11296.042100] [<80a33cb0>] (genl_rcv) from [<80a32c7c>] (netlink_unicast+0x1ac/0x258)
[11296.049774] [<80a32c7c>] (netlink_unicast) from [<80a32ef8>] (netlink_sendmsg+0x1d0/0x410)
[11296.058058] [<80a32ef8>] (netlink_sendmsg) from [<809cbcf8>] (____sys_sendmsg+0x1b4/0x248)
[11296.066342] [<809cbcf8>] (____sys_sendmsg) from [<809cd664>] (___sys_sendmsg+0x70/0xa4)
[11296.074364] [<809cd664>] (___sys_sendmsg) from [<809cda58>] (__sys_sendmsg+0x54/0x98)
[11296.082213] [<809cda58>] (__sys_sendmsg) from [<80100060>] (ret_fast_syscall+0x0/0x54)
[11296.090136] Exception stack(0x84e9dfa8 to 0x84e9dff0)
[11296.095203] dfa0:                   016b5d40 016b41c0 00000005 7ebf8af8 00000000 00000000
[11296.103394] dfc0: 016b5d40 016b41c0 76f8e4d0 00000128 7ebf8af8 00000004 7ebf8b78 00000000
[11296.111580] dfe0: 00000128 7ebf8aa8 76cc277f 76c42d16
[11296.130688] ---[ end trace 6192ce2e2b4a183e ]---
[11296.136616] wlcore: WARNING CONFIGURE command NOK
[11296.143594] wlcore: WARNING configure of tx power failed: -110
[11297.103353] wlcore: Hardware recovery in progress. FW ver: Rev 8.9.1.0.0
[11297.134209] wlcore: pc: 0x107e76, hint_sts: 0x00000220 count: 2060
[11297.150449] wlcore: down
[11297.166630] wlcore: down
[11297.183943] ieee80211 phy0: Hardware restart was requested
[11297.678797] wlcore: PHY firmware version: Rev 8.2.0.0.246
[11297.752896] wlcore: firmware booted (Rev 8.9.1.0.0)
[11297.790554] wlcore: down
[11299.537474] br0: port 3(wlan0_mesh) entered blocking state
[11299.543053] br0: port 3(wlan0_mesh) entered forwarding state
[11301.093397] wlcore: WARNING Unable to flush all TX buffers, timed out (timeout 500 ms
[11301.633402] wlcore: WARNING Unable to flush all TX buffers, timed out (timeout 500 ms
[11301.653344] br0: port 3(wlan0_mesh) entered disabled state
[11302.389675] wlcore: ERROR SW watchdog interrupt received! starting recovery.
[11302.396902] ------------[ cut here ]------------
[11302.401691] WARNING: CPU: 0 PID: 146 at drivers/net/wireless/ti/wlcore/main.c:870 wl12xx_queue_recovery_work+0x5c/0x60 [wlcore]
[11302.413303] Modules linked in: iptable_filter iptable_nat nf_nat nf_conntrack nf_defrag_ipv6 libcrc32c nf_defrag_ipv4 ip_tables x_tables wlcore_sdio wl18xx wlcore mac80211 cfg80211
[11302.429650] CPU: 0 PID: 146 Comm: irq/196-wl18xx Tainted: G        W         5.10.72-garo-10 #1
[11302.438368] Hardware name: Freescale i.MX6 Ultralite (Device Tree)
[11302.444614] [<8010edfc>] (unwind_backtrace) from [<8010a308>] (show_stack+0x10/0x14)
[11302.452403] [<8010a308>] (show_stack) from [<80b5b804>] (dump_stack+0x98/0xac)
[11302.459670] [<80b5b804>] (dump_stack) from [<80b57988>] (__warn+0xc0/0xd8)
[11302.466589] [<80b57988>] (__warn) from [<80b57a04>] (warn_slowpath_fmt+0x64/0xc8)
[11302.474205] [<80b57a04>] (warn_slowpath_fmt) from [<7f0dafe4>] (wl12xx_queue_recovery_work+0x5c/0x60 [wlcore])
[11302.484389] [<7f0dafe4>] (wl12xx_queue_recovery_work [wlcore]) from [<7f0db738>] (wlcore_irq+0xd0/0x1b0 [wlcore])
[11302.494766] [<7f0db738>] (wlcore_irq [wlcore]) from [<8017bb2c>] (irq_thread_fn+0x1c/0x78)
[11302.503077] [<8017bb2c>] (irq_thread_fn) from [<8017be48>] (irq_thread+0x134/0x200)
[11302.510779] [<8017be48>] (irq_thread) from [<8014e65c>] (kthread+0x150/0x190)
[11302.517961] [<8014e65c>] (kthread) from [<80100148>] (ret_from_fork+0x14/0x2c)
[11302.525204] Exception stack(0x84c67fb0 to 0x84c67ff8)
[11302.530284] 7fa0:                                     00000000 00000000 00000000 00000000
[11302.538492] 7fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[11302.546696] 7fe0: 00000000 00000000 00000000 00000000 00000013 00000000
[11302.553483] ---[ end trace 6192ce2e2b4a183f ]---
[11302.565415] wlcore: Hardware recovery in progress. FW ver: Rev 8.9.1.0.0
[11302.579500] wlcore: pc: 0x107e76, hint_sts: 0x00000000 count: 2061
[11302.603794] wlcore: down
[11302.606402] wlcore: down
[11302.614757] ieee80211 phy0: Hardware restart was requested
[11303.130573] wlcore: PHY firmware version: Rev 8.2.0.0.246
[11303.193574] wlcore: firmware booted (Rev 8.9.1.0.0)
[11304.223585] wlcore: WARNING Unable to flush all TX buffers, timed out (timeout 500 ms
[11304.753174] wlcore: WARNING Unable to flush all TX buffers, timed out (timeout 500 ms
[11304.804901] wlcore: ERROR SW watchdog interrupt received! starting recovery.
[11304.812063] ------------[ cut here ]------------
[11304.816956] WARNING: CPU: 0 PID: 146 at drivers/net/wireless/ti/wlcore/main.c:870 wl12xx_queue_recovery_work+0x5c/0x60 [wlcore]
[11304.828551] Modules linked in: iptable_filter iptable_nat nf_nat nf_conntrack nf_defrag_ipv6 libcrc32c nf_defrag_ipv4 ip_tables x_tables wlcore_sdio wl18xx wlcore mac80211 cfg80211
[11304.844954] CPU: 0 PID: 146 Comm: irq/196-wl18xx Tainted: G        W         5.10.72-garo-10 #1
[11304.853677] Hardware name: Freescale i.MX6 Ultralite (Device Tree)
[11304.859918] [<8010edfc>] (unwind_backtrace) from [<8010a308>] (show_stack+0x10/0x14)
[11304.867703] [<8010a308>] (show_stack) from [<80b5b804>] (dump_stack+0x98/0xac)
[11304.874970] [<80b5b804>] (dump_stack) from [<80b57988>] (__warn+0xc0/0xd8)
[11304.881889] [<80b57988>] (__warn) from [<80b57a04>] (warn_slowpath_fmt+0x64/0xc8)
[11304.889501] [<80b57a04>] (warn_slowpath_fmt) from [<7f0dafe4>] (wl12xx_queue_recovery_work+0x5c/0x60 [wlcore])
[11304.899687] [<7f0dafe4>] (wl12xx_queue_recovery_work [wlcore]) from [<7f0db738>] (wlcore_irq+0xd0/0x1b0 [wlcore])
[11304.910066] [<7f0db738>] (wlcore_irq [wlcore]) from [<8017bb2c>] (irq_thread_fn+0x1c/0x78)
[11304.918380] [<8017bb2c>] (irq_thread_fn) from [<8017be48>] (irq_thread+0x134/0x200)
[11304.926084] [<8017be48>] (irq_thread) from [<8014e65c>] (kthread+0x150/0x190)
[11304.933264] [<8014e65c>] (kthread) from [<80100148>] (ret_from_fork+0x14/0x2c)
[11304.940508] Exception stack(0x84c67fb0 to 0x84c67ff8)
[11304.945586] 7fa0:                                     00000000 00000000 00000000 00000000
[11304.953796] 7fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[11304.961999] 7fe0: 00000000 00000000 00000000 00000000 00000013 00000000
[11304.968745] ---[ end trace 6192ce2e2b4a1840 ]---
[11304.983290] wlcore: Hardware recovery in progress. FW ver: Rev 8.9.1.0.0
[11304.992946] wlcore: pc: 0x107e76, hint_sts: 0x00000000 count: 2062
[11305.001994] wlcore: down
[11305.005022] wlcore: down
[11305.007816] ieee80211 phy0: Hardware restart was requested
[11305.679267] wlcore: PHY firmware version: Rev 8.2.0.0.246
[11305.721402] wlcore: firmware booted (Rev 8.9.1.0.0)
[11305.761693] wlcore: down
[11307.502880] br0: port 3(wlan0_mesh) entered blocking state
[11307.508495] br0: port 3(wlan0_mesh) entered forwarding state

The reason we are recreating this in our lab with a signal is we have measured a similar disturbance at another customer site with the same problem.

Kind regards

Mattias

Hi Mattias,

So to confirm, this issue is only created by other RF sources in the environment?

It seems that if you apply RF disturbance, then you are blocking wifi channel and thus WL18xx will never be able to transmit.

Hi

It seems like it happens when there are other RF sources strong enough to degrade or make the WiFi completely unusable.

We can not tell customers to not have random RF sources. This crashes products in the field.

What can we do to make the WL18xx firmware to not trigger a recovery?

Can we change some settings in wl18xx-conf.bin to make this less likely to happen?

What was the offline discussion from the other thread?

Kind regards

Mattias

Mattias Fjällström said:

What was the offline discussion from the other thread?

I don't have the record for this conversation so I'm not certain of the resolution, if there was any.

Mattias Fjällström said:

It seems like it happens when there are other RF sources strong enough to degrade or make the WiFi completely unusable.

Do you happen to know the source of the RF noise? Because I'm not sure we can do much if some other device is constantly eating up the WiFi channel. Perhaps this intruding device is also breaking the power certifications. 

After recovery, is the WL18xx operational for a short time, or does it just never work at the time of power on?

If you are using the WL18xx device in AP mode, then you could change the channel and see if it improves. 

We do not know the source of the noise. It will be different sources depending on the customer I guess. But when we recreate in our lab we use the tracking generator of a spectrum analyzer to transmit. When we do it we most certainly break the power limits for the channel. But I do not think that the chip should do a recovery.

Yes the WL18xx is operational after a recovery. But at one customer site it does a recovery about every 5 seconds. At that site it is not possible to connect to the AP and change the settings.

Yes if we change channel to a one that is unaffected by the noise the WL18xx will stop doing recoveries. But as mentioned above that is not possible on some sites where there is a recovery roughly every 5 seconds.

Do you have any ideas of why it would do recoveries? Is there any idea to start changing some settings in wl18xx-conf.bin? What setting would that be?

For what it's worth, on an entirely different radio (different silicon vendor) we ran into a similar problem at certain customer sites.  Turns out the issue was the presence detection hardware (5GHz) in the lighting system emitting on a frequency and exposed a bug in radio calibration logic causing the device to hang. 

Agreed, the device should not hang in the presence of an external transmitter.  It may not be able to transmit (blocking transmission is a requirement in various cases) but it should not crash.