Hi,
I'm getting a hang on resume from suspend using today's next-20210618.
It's tested on Tegra20 Acer A500 that has older BCM4329, but seems the
problem is generic.
There is this line in pstore log:
ieee80211 phy0: brcmf_netdev_start_xmit: xmit rejected state=0
Steps to reproduce:
1. Boot system
2. Connect WiFi
3. Run "rtcwake -s10 -mmem"
What's interesting is that turning WiFi off/on before suspending makes
resume to work and there are no suspicious messages in KMSG, all further
resumes work too.
This change fixes the hang:
diff --git a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/core.c
b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/core.c
index db5f8535fdb5..06d16f7776c7 100644
--- a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/core.c
+++ b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/core.c
@@ -301,7 +301,6 @@ static netdev_tx_t brcmf_netdev_start_xmit(struct
sk_buff *skb,
/* Can the device send data? */
if (drvr->bus_if->state != BRCMF_BUS_UP) {
bphy_err(drvr, "xmit rejected state=%d\n", drvr->bus_if->state);
- netif_stop_queue(ndev);
dev_kfree_skb(skb);
ret = -ENODEV;
goto done;
8<---
Comments? Suggestions? Thanks in advance.
18.06.2021 23:36, Dmitry Osipenko пишет:
> Hi,
>
> I'm getting a hang on resume from suspend using today's next-20210618.
> It's tested on Tegra20 Acer A500 that has older BCM4329, but seems the
> problem is generic.
>
> There is this line in pstore log:
>
> ieee80211 phy0: brcmf_netdev_start_xmit: xmit rejected state=0
>
> Steps to reproduce:
>
> 1. Boot system
> 2. Connect WiFi
> 3. Run "rtcwake -s10 -mmem"
>
> What's interesting is that turning WiFi off/on before suspending makes
> resume to work and there are no suspicious messages in KMSG, all further
> resumes work too.
>
> This change fixes the hang:
>
> diff --git a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/core.c
> b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/core.c
> index db5f8535fdb5..06d16f7776c7 100644
> --- a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/core.c
> +++ b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/core.c
> @@ -301,7 +301,6 @@ static netdev_tx_t brcmf_netdev_start_xmit(struct
> sk_buff *skb,
> /* Can the device send data? */
> if (drvr->bus_if->state != BRCMF_BUS_UP) {
> bphy_err(drvr, "xmit rejected state=%d\n", drvr->bus_if->state);
> - netif_stop_queue(ndev);
> dev_kfree_skb(skb);
> ret = -ENODEV;
> goto done;
> 8<---
>
> Comments? Suggestions? Thanks in advance.
>
Update:
After some more testing I found that the removal of netif_stop_queue() doesn't really help, apparently it was a coincidence.
I enabled CONFIG_BRCMDBG and added dump_stack() to the error condition of brcmf_netdev_start_xmit() and this is what it shows:
PM: suspend entry (s2idle)
Filesystems sync: 0.000 seconds
Freezing user space processes ... (elapsed 0.004 seconds) done.
OOM killer disabled.
Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done.
brcmfmac: brcmf_cfg80211_disconnect Enter. Reason code = 3
brcmfmac: brcmf_sdio_bus_txctl Enter
brcmutil: Tx Frame:
00000000: 28 00 d7 ff d1 00 00 0c 00 00 00 00 34 00 00 00 (...........4...
00000010: 0c 00 00 00 02 00 ca 00 00 00 00 00 03 00 00 00 ................
00000020: 10 7b 44 3b 36 98 31 c2 .{D;6.1.
brcmfmac: brcmf_sdio_bus_rxctl Enter
brcmfmac: brcmf_sdio_isr Enter
brcmutil: RxHdr:
00000000: 28 00 d7 ff b9 00 00 0c 00 d8 00 00 (...........
brcmutil: RxCtrl:
00000000: 28 00 d7 ff b9 00 00 0c 00 d8 00 00 34 00 00 00 (...........4...
00000010: 0c 00 00 00 00 00 ca 00 00 00 00 00 03 00 00 00 ................
00000020: 10 7b 44 3b 36 98 31 c2 .{D;6.1.
brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 28 expected 28
brcmutil: RxHdr:
00000000: 5c 00 a3 ff ba 01 06 0e 00 d8 00 00 \...........
brcmfmac: brcmf_cfg80211_disconnect Exit
brcmfmac: brcmf_cfg80211_del_key Enter
brcmfmac: brcmf_sdio_bus_txctl Enter
brcmutil: Rx Data:
00000000: 5c 00 a3 ff ba 01 06 0e 00 d8 00 00 00 00 20 00 \............. .
00000010: 00 00 e0 b9 a5 4d 8a 60 e2 b9 a5 4d 8a 60 88 6c .....M.`...M.`.l
00000020: 80 01 00 68 00 00 10 18 00 01 00 02 00 00 00 00 ...h............
00000030: 00 10 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
00000040: 00 00 10 7b 44 3b 36 98 77 6c 30 00 00 00 00 00 ...{D;6.wl0.....
00000050: 00 00 00 00 00 00 00 00 00 00 00 00 ............
brcmfmac: brcmf_fws_hdrpull enter: ifidx 0, skblen 74, sig 0
brcmutil: Rx Data:
00000000: 5c 00 a3 ff bb 01 06 0e 00 d8 00 00 00 00 20 00 \............. .
00000010: 00 00 e0 b9 a5 4d 8a 60 e2 b9 a5 4d 8a 60 88 6c .....M.`...M.`.l
00000020: 80 01 00 68 00 00 10 18 00 01 00 02 00 18 00 00 ...h............
00000030: 00 05 00 00 00 00 00 00 00 07 00 00 00 00 00 00 ................
00000040: 00 00 10 7b 44 3b 36 98 77 6c 30 00 00 00 00 00 ...{D;6.wl0.....
00000050: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
brcmfmac: brcmf_fws_hdrpull enter: ifidx 0, skblen 78, sig 0
brcmutil: Rx Data:
00000000: 5c 00 a3 ff bc 01 06 0e 00 d8 00 00 00 00 20 00 \............. .
00000010: 00 00 e0 b9 a5 4d 8a 60 e2 b9 a5 4d 8a 60 88 6c .....M.`...M.`.l
00000020: 80 01 00 68 00 00 10 18 00 01 00 02 00 18 00 00 ...h............
00000030: 00 05 00 00 00 00 00 00 00 07 00 00 00 00 00 00 ................
00000040: 00 00 10 7b 44 3b 36 98 77 6c 30 00 00 00 00 00 ...{D;6.wl0.....
00000050: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
brcmfmac: brcmf_fws_hdrpull enter: ifidx 0, skblen 78, sig 0
brcmutil: Rx Data:
00000000: 5c 00 a3 ff bd 01 06 0e 00 d8 00 00 00 00 20 00 \............. .
00000010: 00 00 e0 b9 a5 4d 8a 60 e2 b9 a5 4d 8a 60 88 6c .....M.`...M.`.l
00000020: 80 01 00 68 00 00 10 18 00 01 00 02 00 18 00 00 ...h............
00000030: 00 05 00 00 00 00 00 00 00 07 00 00 00 00 00 00 ................
00000040: 00 00 10 7b 44 3b 36 98 77 6c 30 00 00 00 00 00 ...{D;6.wl0.....
00000050: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
brcmfmac: brcmf_fws_hdrpull enter: ifidx 0, skblen 78, sig 0
brcmutil: Rx Data:
00000000: 5c 00 a3 ff be 01 06 0e 00 d8 00 00 00 00 20 00 \............. .
00000010: 00 00 e0 b9 a5 4d 8a 60 e2 b9 a5 4d 8a 60 88 6c .....M.`...M.`.l
00000020: 80 01 00 68 00 00 10 18 00 01 00 02 00 18 00 00 ...h............
00000030: 00 05 00 00 00 00 00 00 00 07 00 00 00 00 00 00 ................
00000040: 00 00 10 7b 44 3b 36 98 77 6c 30 00 00 00 00 00 ...{D;6.wl0.....
00000050: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
brcmfmac: brcmf_fws_hdrpull enter: ifidx 0, skblen 78, sig 0
brcmutil: Rx Data:
00000000: 5c 00 a3 ff bf 01 06 0e 00 d8 00 00 00 00 20 00 \............. .
00000010: 00 00 e0 b9 a5 4d 8a 60 e2 b9 a5 4d 8a 60 88 6c .....M.`...M.`.l
00000020: 80 01 00 68 00 00 10 18 00 01 00 02 00 18 00 00 ...h............
00000030: 00 05 00 00 00 00 00 00 00 07 00 00 00 00 00 00 ................
00000040: 00 00 10 7b 44 3b 36 98 77 6c 30 00 00 00 00 00 ...{D;6.wl0.....
00000050: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
brcmfmac: brcmf_fws_hdrpull enter: ifidx 0, skblen 78, sig 0
brcmutil: Rx Data:
00000000: 5c 00 a3 ff c0 01 00 0e 00 d8 00 00 00 00 20 00 \............. .
00000010: 00 00 e0 b9 a5 4d 8a 60 e2 b9 a5 4d 8a 60 88 6c .....M.`...M.`.l
00000020: 80 01 00 68 00 00 10 18 00 01 00 02 00 18 00 00 ...h............
00000030: 00 05 00 00 00 00 00 00 00 07 00 00 00 00 00 00 ................
00000040: 00 00 10 7b 44 3b 36 98 77 6c 30 00 00 00 00 00 ...{D;6.wl0.....
00000050: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
brcmfmac: brcmf_fws_hdrpull enter: ifidx 0, skblen 78, sig 0
brcmutil: RxHdr:
00000000: 5c 00 a3 ff c1 01 00 0e 00 d8 00 00 \...........
brcmutil: Rx Data:
00000000: 5c 00 a3 ff c1 01 00 0e 00 d8 00 00 00 00 20 00 \............. .
00000010: 00 00 e0 b9 a5 4d 8a 60 e2 b9 a5 4d 8a 60 88 6c .....M.`...M.`.l
00000020: 80 01 00 68 00 00 10 18 00 01 00 02 00 18 00 00 ...h............
00000030: 00 05 00 00 00 00 00 00 00 07 00 00 00 00 00 00 ................
00000040: 00 00 10 7b 44 3b 36 98 77 6c 30 00 00 00 00 00 ...{D;6.wl0.....
00000050: 00 00 00 00 00 00 00 00 00 00 00 00 ............
brcmfmac: brcmf_fws_hdrpull enter: ifidx 0, skblen 74, sig 0
brcmutil: RxHdr:
00000000: 00 00 00 00 00 00 00 00 00 00 00 00 ............
brcmfmac: brcmf_sdio_readframes processed 9 frames
brcmfmac: brcmf_sdio_isr Enter
brcmutil: Tx Frame:
00000000: c9 00 36 ff d2 00 00 0c 00 00 00 00 07 01 00 00 ..6.............
00000010: ad 00 00 00 02 00 cb 00 00 00 00 00 77 73 65 63 ............wsec
00000020: 5f 6b 65 79 00 00 00 00 00 00 00 00 00 00 00 00 _key............
[cut]
brcmfmac: brcmf_sdio_bus_rxctl Enter
brcmutil: RxHdr:
00000000: c9 00 36 ff c2 00 00 0c 00 d9 00 00 ..6.........
brcmutil: RxCtrl:
00000000: c9 00 36 ff c2 00 00 0c 00 d9 00 00 07 01 00 00 ..6.............
00000010: ad 00 00 00 00 00 cb 00 00 00 00 00 77 73 65 63 ............wsec
00000020: 5f 6b 65 79 00 00 00 00 00 00 00 00 00 00 00 00 _key............
[cut]
brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 189 expected 189
brcmfmac: brcmf_cfg80211_del_key Exit
brcmfmac: brcmf_cfg80211_del_key Enter
brcmfmac: brcmf_cfg80211_del_key Enter
brcmfmac: brcmf_sdio_bus_txctl Enter
brcmutil: RxHdr:
00000000: 00 00 00 00 00 00 00 00 00 00 00 00 ............
brcmfmac: brcmf_sdio_readframes processed 1 frames
brcmutil: Tx Frame:
00000000: c9 00 36 ff d3 00 00 0c 00 00 00 00 07 01 00 00 ..6.............
00000010: ad 00 00 00 02 00 cc 00 00 00 00 00 77 73 65 63 ............wsec
00000020: 5f 6b 65 79 00 02 00 00 00 00 00 00 00 00 00 00 _key............
[cut]
brcmfmac: brcmf_sdio_isr Enter
brcmfmac: brcmf_sdio_bus_rxctl Enter
brcmutil: RxHdr:
00000000: c9 00 36 ff c3 00 00 0c 00 da 00 00 ..6.........
brcmutil: RxCtrl:
00000000: c9 00 36 ff c3 00 00 0c 00 da 00 00 07 01 00 00 ..6.............
00000010: ad 00 00 00 00 00 cc 00 00 00 00 00 77 73 65 63 ............wsec
00000020: 5f 6b 65 79 00 02 00 00 00 00 00 00 00 00 00 00 _key............
[cut]
brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 189 expected 189
brcmutil: RxHdr:
brcmfmac: brcmf_cfg80211_del_key Exit
00000000: 00 00 00 00 00 00 00 00 00 00 00 00 ............
brcmfmac: brcmf_cfg80211_del_key Enter
brcmfmac: brcmf_cfg80211_del_key Enter
brcmfmac: brcmf_sdio_readframes processed 1 frames
brcmfmac: brcmf_cfg80211_del_key Enter
brcmfmac: brcmf_cfg80211_suspend Enter
brcmfmac: brcmf_pno_stop_sched_scan reqid=0
brcmfmac: brcmf_link_down Enter
brcmfmac: brcmf_btcoex_set_mode DHCP session ends
brcmfmac: brcmf_link_down Exit
brcmfmac: brcmf_sdio_bus_watchdog Enter
brcmfmac: brcmf_sdio_bus_watchdog Enter
brcmfmac: brcmf_sdio_bus_txctl Enter
brcmutil: Tx Frame:
00000000: 24 00 db ff d4 00 00 0c 00 00 00 00 07 01 00 00 $...............
00000010: 08 00 00 00 02 00 cd 00 00 00 00 00 6d 70 63 00 ............mpc.
00000020: 01 00 00 00 ....
brcmfmac: brcmf_sdio_isr Enter
brcmfmac: brcmf_sdio_bus_rxctl Enter
brcmutil: RxHdr:
00000000: 24 00 db ff c4 00 00 0c 00 db 00 00 $...........
brcmutil: RxCtrl:
00000000: 24 00 db ff c4 00 00 0c 00 db 00 00 07 01 00 00 $...............
00000010: 08 00 00 00 00 00 cd 00 00 00 00 00 6d 70 63 00 ............mpc.
00000020: 01 00 00 00 ....
brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 24 expected 24
brcmfmac: brcmf_set_mpc MPC : 1
brcmfmac: brcmf_cfg80211_suspend Exit
brcmutil: RxHdr:
00000000: 00 00 00 00 00 00 00 00 00 00 00 00 ............
brcmfmac: brcmf_sdio_readframes processed 1 frames
brcmfmac: brcmf_sdiod_change_state 1 -> 0
brcmfmac: brcmf_bus_change_state 1 -> 0
brcmfmac: brcmf_netdev_start_xmit Enter, bsscfgidx=0
CPU: 0 PID: 0 Comm: swapper/0 Tainted: G W 5.13.0-rc7-next-20210622-00178-g74f7ad03c152-dirty #8227
Hardware name: NVIDIA Tegra SoC (Flattened Device Tree)
[<c010ccf5>] (unwind_backtrace) from [<c0108fd5>] (show_stack+0x11/0x14)
[<c0108fd5>] (show_stack) from [<c0a6d327>] (dump_stack_lvl+0x7f/0x8c)
[<c0a6d327>] (dump_stack_lvl) from [<c065ce17>] (brcmf_netdev_start_xmit+0x1d7/0x254)
[<c065ce17>] (brcmf_netdev_start_xmit) from [<c0817e8b>] (dev_hard_start_xmit+0xbb/0x1ec)
[<c0817e8b>] (dev_hard_start_xmit) from [<c0849bef>] (sch_direct_xmit+0xab/0x1f0)
[<c0849bef>] (sch_direct_xmit) from [<c0849e33>] (__qdisc_run+0xff/0x4cc)
[<c0849e33>] (__qdisc_run) from [<c0818461>] (__dev_queue_xmit+0x419/0x690)
[<c0818461>] (__dev_queue_xmit) from [<c08973eb>] (ip_finish_output2+0x1c3/0x480)
[<c08973eb>] (ip_finish_output2) from [<c0898f39>] (__ip_queue_xmit+0xfd/0x2f8)
[<c0898f39>] (__ip_queue_xmit) from [<c08b0483>] (__tcp_transmit_skb+0x3f7/0x8ec)
[<c08b0483>] (__tcp_transmit_skb) from [<c08b13d5>] (tcp_xmit_probe_skb+0x9d/0xa8)
[<c08b13d5>] (tcp_xmit_probe_skb) from [<c08b3c87>] (tcp_keepalive_timer+0x10f/0x1f0)
[<c08b3c87>] (tcp_keepalive_timer) from [<c0185695>] (call_timer_fn+0x31/0x160)
[<c0185695>] (call_timer_fn) from [<c018593f>] (__run_timers.part.0+0x17b/0x228)
[<c018593f>] (__run_timers.part.0) from [<c0185a1b>] (run_timer_softirq+0x2f/0x50)
[<c0185a1b>] (run_timer_softirq) from [<c01013ab>] (__do_softirq+0xd3/0x2ec)
[<c01013ab>] (__do_softirq) from [<c01251d3>] (irq_exit+0xab/0xb8)
[<c01251d3>] (irq_exit) from [<c016e31d>] (handle_domain_irq+0x45/0x60)
[<c016e31d>] (handle_domain_irq) from [<c04c4a83>] (gic_handle_irq+0x6b/0x7c)
[<c04c4a83>] (gic_handle_irq) from [<c0100b65>] (__irq_svc+0x65/0xac)
Exception stack(0xc1201ed0 to 0xc1201f18)
1ec0: 00000000 00000000 2e4fd000 00000060
1ee0: 00000000 c13240a8 78813f98 ef6949f8 00000000 00000024 00000000 00000024
1f00: 02da3104 c1201f20 c074e015 c074e094 60010133 ffffffff
[<c0100b65>] (__irq_svc) from [<c074e094>] (cpuidle_enter_state+0x1ac/0x360)
[<c074e094>] (cpuidle_enter_state) from [<c074e297>] (cpuidle_enter+0x3b/0x3c)
[<c074e297>] (cpuidle_enter) from [<c014b6e1>] (do_idle+0x109/0x204)
[<c014b6e1>] (do_idle) from [<c014ba75>] (cpu_startup_entry+0x19/0x1c)
[<c014ba75>] (cpu_startup_entry) from [<c1101033>] (start_kernel+0x70b/0x734)
ieee80211 phy0: brcmf_netdev_start_xmit: xmit rejected state=0
brcmfmac: brcmf_cfg80211_resume Enter
brcmfmac: brcmf_sdio_isr Enter
brcmfmac: brcmf_sdiod_change_state 0 -> 1
brcmfmac: brcmf_bus_change_state 0 -> 1
brcmfmac: brcmf_sdio_bus_watchdog Enter
brcmfmac: brcmf_sdio_bus_watchdog Enter
OOM killer enabled.
Restarting tasks ... done.
brcmfmac: brcmf_cfg80211_dump_station Enter, idx 0
PM: suspend exit
22.06.2021 20:04, Dmitry Osipenko пишет:
> 18.06.2021 23:36, Dmitry Osipenko пишет:
>> Hi,
>>
>> I'm getting a hang on resume from suspend using today's next-20210618.
>> It's tested on Tegra20 Acer A500 that has older BCM4329, but seems the
>> problem is generic.
>>
>> There is this line in pstore log:
>>
>> ieee80211 phy0: brcmf_netdev_start_xmit: xmit rejected state=0
>>
>> Steps to reproduce:
>>
>> 1. Boot system
>> 2. Connect WiFi
>> 3. Run "rtcwake -s10 -mmem"
>>
>> What's interesting is that turning WiFi off/on before suspending makes
>> resume to work and there are no suspicious messages in KMSG, all further
>> resumes work too.
>>
>> This change fixes the hang:
>>
>> diff --git a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/core.c
>> b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/core.c
>> index db5f8535fdb5..06d16f7776c7 100644
>> --- a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/core.c
>> +++ b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/core.c
>> @@ -301,7 +301,6 @@ static netdev_tx_t brcmf_netdev_start_xmit(struct
>> sk_buff *skb,
>> /* Can the device send data? */
>> if (drvr->bus_if->state != BRCMF_BUS_UP) {
>> bphy_err(drvr, "xmit rejected state=%d\n", drvr->bus_if->state);
>> - netif_stop_queue(ndev);
>> dev_kfree_skb(skb);
>> ret = -ENODEV;
>> goto done;
>> 8<---
>>
>> Comments? Suggestions? Thanks in advance.
>>
>
> Update:
>
> After some more testing I found that the removal of netif_stop_queue() doesn't really help, apparently it was a coincidence.
>
> I enabled CONFIG_BRCMDBG and added dump_stack() to the error condition of brcmf_netdev_start_xmit() and this is what it shows:
>
> PM: suspend entry (s2idle)
> Filesystems sync: 0.000 seconds
> Freezing user space processes ... (elapsed 0.004 seconds) done.
> OOM killer disabled.
> Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done.
...
The hanging problem has been resolved by bumping Tegra SoC core voltage,
so it wasn't related to BCM.
The "xmit rejected" error is still there, but it's not fatal AFAICS.