* hot busy loop inside ath11k
@ 2024-11-01 21:39 Yury Vostrikov
2024-11-07 14:36 ` Kalle Valo
0 siblings, 1 reply; 3+ messages in thread
From: Yury Vostrikov @ 2024-11-01 21:39 UTC (permalink / raw)
To: Kalle Valo; +Cc: ath11k
Hi Kalle,
It seems there is problem with busy wait inside
ath11k_debugfs_fw_stats_request. I have a laptop with QCNFA765 WiFi
controller. It is running vanilla v6.11.4 with the following fw:
> [ 3.934078] ath11k_pci 0000:01:00.0: wcn6855 hw2.1
> [ 4.801624] ath11k_pci 0000:01:00.0: chip_id 0x12 chip_family 0xb board_id 0xff soc_id 0x400c1211
> [ 4.802469] ath11k_pci 0000:01:00.0: fw_version 0x11088c35 fw_build_timestamp 2024-04-17 08:34 fw_build_id WLAN.HSP.1.1-03125-QCAHSPSWPL_V1_V2_SILICONZ_LITE-3.6510.41
Sometimes after device wakes up, the system becomes
sluggish and burns CPU. A assume it is because of a firmware bug, but driver
should not waste CPU regardless.
According to perf, the most time is spent in busy waitin inside ath11k_debugfs_fw_stats_request:
94.60% 0.00% i3status [kernel.kallsyms] [k] do_syscall_64
|
--94.60%--do_syscall_64
|
--94.55%--__sys_sendmsg
___sys_sendmsg
____sys_sendmsg
netlink_sendmsg
netlink_unicast
genl_rcv
netlink_rcv_skb
genl_rcv_msg
|
--94.55%--genl_family_rcv_msg_dumpit
__netlink_dump_start
netlink_dump
genl_dumpit
nl80211_dump_station
|
--94.55%--ieee80211_dump_station
sta_set_sinfo
|
--94.55%--ath11k_mac_op_sta_statistics
ath11k_debugfs_get_fw_stats
|
--94.55%--ath11k_debugfs_fw_stats_request
|
|--41.73%--_raw_spin_lock_bh
|
|--22.74%--__local_bh_enable_ip
|
|--9.22%--_raw_spin_unlock_bh
|
--6.66%--srso_alias_safe_ret
If I'm reading the code correctly, then ath11k_debugfs_fw_stats_request has 3 second timeout:
> timeout = jiffies + msecs_to_jiffies(3 * 1000);
however, it only waits for 1 second:
> time_left = wait_for_completion_timeout(&ar->fw_stats_complete, 1 * HZ);
the rest (2 seconds) is spent inside busy loop
> for (;;) {
> if (time_after(jiffies, timeout))
> break;
>
> spin_lock_bh(&ar->data_lock);
> if (ar->fw_stats_done) {
> spin_unlock_bh(&ar->data_lock);
> break;
> }
> spin_unlock_bh(&ar->data_lock);
> }
spinning for 2 seconds seems excessive to me. What do you think?
Also, if you happen to know how & where to report firmware bugs, I'd
appreciate any pointers.
thanks
^ permalink raw reply [flat|nested] 3+ messages in thread
* Re: hot busy loop inside ath11k
2024-11-01 21:39 hot busy loop inside ath11k Yury Vostrikov
@ 2024-11-07 14:36 ` Kalle Valo
2024-11-11 0:37 ` Baochen Qiang
0 siblings, 1 reply; 3+ messages in thread
From: Kalle Valo @ 2024-11-07 14:36 UTC (permalink / raw)
To: Yury Vostrikov; +Cc: ath11k
"Yury Vostrikov" <mon@unformed.ru> writes:
> Hi Kalle,
>
> It seems there is problem with busy wait inside
> ath11k_debugfs_fw_stats_request. I have a laptop with QCNFA765 WiFi
> controller. It is running vanilla v6.11.4 with the following fw:
>
>> [ 3.934078] ath11k_pci 0000:01:00.0: wcn6855 hw2.1
>> [ 4.801624] ath11k_pci 0000:01:00.0: chip_id 0x12 chip_family 0xb board_id 0xff soc_id 0x400c1211
>> [ 4.802469] ath11k_pci 0000:01:00.0: fw_version 0x11088c35 fw_build_timestamp 2024-04-17 08:34 fw_build_id WLAN.HSP.1.1-03125-QCAHSPSWPL_V1_V2_SILICONZ_LITE-3.6510.41
>
> Sometimes after device wakes up, the system becomes
> sluggish and burns CPU. A assume it is because of a firmware bug, but driver
> should not waste CPU regardless.
>
> According to perf, the most time is spent in busy waitin inside ath11k_debugfs_fw_stats_request:
>
> 94.60% 0.00% i3status [kernel.kallsyms] [k] do_syscall_64
> |
> --94.60%--do_syscall_64
> |
> --94.55%--__sys_sendmsg
> ___sys_sendmsg
> ____sys_sendmsg
> netlink_sendmsg
> netlink_unicast
> genl_rcv
> netlink_rcv_skb
> genl_rcv_msg
> |
> --94.55%--genl_family_rcv_msg_dumpit
> __netlink_dump_start
> netlink_dump
> genl_dumpit
> nl80211_dump_station
> |
> --94.55%--ieee80211_dump_station
> sta_set_sinfo
> |
> --94.55%--ath11k_mac_op_sta_statistics
> ath11k_debugfs_get_fw_stats
> |
> --94.55%--ath11k_debugfs_fw_stats_request
> |
> |--41.73%--_raw_spin_lock_bh
> |
> |--22.74%--__local_bh_enable_ip
> |
> |--9.22%--_raw_spin_unlock_bh
> |
> --6.66%--srso_alias_safe_ret
>
> If I'm reading the code correctly, then ath11k_debugfs_fw_stats_request has 3 second timeout:
>
>> timeout = jiffies + msecs_to_jiffies(3 * 1000);
>
> however, it only waits for 1 second:
>
>> time_left = wait_for_completion_timeout(&ar->fw_stats_complete, 1 * HZ);
>
> the rest (2 seconds) is spent inside busy loop
>
>> for (;;) {
>> if (time_after(jiffies, timeout))
>> break;
>>
>> spin_lock_bh(&ar->data_lock);
>> if (ar->fw_stats_done) {
>> spin_unlock_bh(&ar->data_lock);
>> break;
>> }
>> spin_unlock_bh(&ar->data_lock);
>> }
>
>
> spinning for 2 seconds seems excessive to me. What do you think?
Oh wow, excessive is an understatement :) That's horrible, I don't know
how we missed that. And an unlimited loop like that is a big no-no in
kernel, every loop should have a some kind of maximum limit. Can someone
send a patch?
> Also, if you happen to know how & where to report firmware bugs, I'd
> appreciate any pointers.
I recommend filing to bugzilla:
https://wireless.docs.kernel.org/en/latest/en/users/drivers/ath11k/bugreport.html
Though we are overwhelmed with everything right now so don't expect a
quick response :/
--
https://patchwork.kernel.org/project/linux-wireless/list/
https://wireless.wiki.kernel.org/en/developers/documentation/submittingpatches
^ permalink raw reply [flat|nested] 3+ messages in thread
* Re: hot busy loop inside ath11k
2024-11-07 14:36 ` Kalle Valo
@ 2024-11-11 0:37 ` Baochen Qiang
0 siblings, 0 replies; 3+ messages in thread
From: Baochen Qiang @ 2024-11-11 0:37 UTC (permalink / raw)
To: ath11k, Kalle Valo
On 11/7/2024 10:36 PM, Kalle Valo wrote:
> "Yury Vostrikov" <mon@unformed.ru> writes:
>
>> Hi Kalle,
>>
>> It seems there is problem with busy wait inside
>> ath11k_debugfs_fw_stats_request. I have a laptop with QCNFA765 WiFi
>> controller. It is running vanilla v6.11.4 with the following fw:
>>
>>> [ 3.934078] ath11k_pci 0000:01:00.0: wcn6855 hw2.1
>>> [ 4.801624] ath11k_pci 0000:01:00.0: chip_id 0x12 chip_family 0xb board_id 0xff soc_id 0x400c1211
>>> [ 4.802469] ath11k_pci 0000:01:00.0: fw_version 0x11088c35 fw_build_timestamp 2024-04-17 08:34 fw_build_id WLAN.HSP.1.1-03125-QCAHSPSWPL_V1_V2_SILICONZ_LITE-3.6510.41
>>
>> Sometimes after device wakes up, the system becomes
>> sluggish and burns CPU. A assume it is because of a firmware bug, but driver
>> should not waste CPU regardless.
>>
>> According to perf, the most time is spent in busy waitin inside ath11k_debugfs_fw_stats_request:
>>
>> 94.60% 0.00% i3status [kernel.kallsyms] [k] do_syscall_64
>> |
>> --94.60%--do_syscall_64
>> |
>> --94.55%--__sys_sendmsg
>> ___sys_sendmsg
>> ____sys_sendmsg
>> netlink_sendmsg
>> netlink_unicast
>> genl_rcv
>> netlink_rcv_skb
>> genl_rcv_msg
>> |
>> --94.55%--genl_family_rcv_msg_dumpit
>> __netlink_dump_start
>> netlink_dump
>> genl_dumpit
>> nl80211_dump_station
>> |
>> --94.55%--ieee80211_dump_station
>> sta_set_sinfo
>> |
>> --94.55%--ath11k_mac_op_sta_statistics
>> ath11k_debugfs_get_fw_stats
>> |
>> --94.55%--ath11k_debugfs_fw_stats_request
>> |
>> |--41.73%--_raw_spin_lock_bh
>> |
>> |--22.74%--__local_bh_enable_ip
>> |
>> |--9.22%--_raw_spin_unlock_bh
>> |
>> --6.66%--srso_alias_safe_ret
>>
>> If I'm reading the code correctly, then ath11k_debugfs_fw_stats_request has 3 second timeout:
>>
>>> timeout = jiffies + msecs_to_jiffies(3 * 1000);
>>
>> however, it only waits for 1 second:
>>
>>> time_left = wait_for_completion_timeout(&ar->fw_stats_complete, 1 * HZ);
>>
>> the rest (2 seconds) is spent inside busy loop
>>
>>> for (;;) {
>>> if (time_after(jiffies, timeout))
>>> break;
>>>
>>> spin_lock_bh(&ar->data_lock);
>>> if (ar->fw_stats_done) {
>>> spin_unlock_bh(&ar->data_lock);
>>> break;
>>> }
>>> spin_unlock_bh(&ar->data_lock);
>>> }
>>
>>
>> spinning for 2 seconds seems excessive to me. What do you think?
>
> Oh wow, excessive is an understatement :) That's horrible, I don't know
> how we missed that. And an unlimited loop like that is a big no-no in
> kernel, every loop should have a some kind of maximum limit. Can someone
> send a patch?
Hi Kalle, I already sent an internal patch to fix this.
>
>> Also, if you happen to know how & where to report firmware bugs, I'd
>> appreciate any pointers.
>
> I recommend filing to bugzilla:
>
> https://wireless.docs.kernel.org/en/latest/en/users/drivers/ath11k/bugreport.html
>
> Though we are overwhelmed with everything right now so don't expect a
> quick response :/
>
^ permalink raw reply [flat|nested] 3+ messages in thread
end of thread, other threads:[~2024-11-11 0:37 UTC | newest]
Thread overview: 3+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2024-11-01 21:39 hot busy loop inside ath11k Yury Vostrikov
2024-11-07 14:36 ` Kalle Valo
2024-11-11 0:37 ` Baochen Qiang
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox