Repository navigation
[BUG] sof-audio-pci-intel-mtl spends 573571us in pci_pm_suspend #8071
Description
dmesg | grep "1f.3: PM: pci_pm_suspend"
[ 451.555631] sof-audio-pci-intel-mtl 0000:00:1f.3: PM: pci_pm_suspend+0x0/0x20b returned 0 after 572713 usecs
[ 451.659567] sof-audio-pci-intel-mtl 0000:00:1f.3: PM: pci_pm_suspend_late+0x0/0x3e returned 0 after 2 usecs
[ 451.711738] sof-audio-pci-intel-mtl 0000:00:1f.3: PM: pci_pm_suspend_noirq+0x0/0x236 returned 0 after 12201 usecs
More logs:
[ 451.260063] sof-audio-pci-intel-mtl 0000:00:1f.3: FW Poll Status: reg[0x114c]=0xf successful
[ 451.260092] sof-audio-pci-intel-mtl 0000:00:1f.3: ipc tx : 0x47000000|0x0 [data size: 8]
[ 451.552578] sof-audio-pci-intel-mtl 0000:00:1f.3: ipc tx reply: 0x67000000|0x0
[ 451.552715] sof-audio-pci-intel-mtl 0000:00:1f.3: ipc tx done : 0x47000000|0x0 [data size: 8]
the tx reply takes about 300msec.
This issue is not seen with mtl-003 FW observed only wiht the
commit 9daaddc (HEAD -> dhara_v5.0.3, tag: releases/mtl/v5.0.3, ranj)
Author: Adrian Bonislawski adrian.bonislawski@intel.com
Date: Tue Jun 27 16:50:42 2023 +0200
host: do not set L1 exit if interrupt mode selected + update zephyr west
Update zephyr to c31e68329
Signed-off-by: Adrian Bonislawski <adrian.bonislawski@intel.com>
To Reproduce
suspend_stress_test -c 1
Reproduction Rate
100%
Activity
lgirdwood commentedon Aug 22, 2023
@abonislawski fyi, any idea why IPC would take long time with commit above ?
abonislawski commentedon Aug 22, 2023
Could be something with zephyr PM (its old on 005 now) or another issue with IMR context save because Dhara reported me CONFIG_ADSP_IMR_CONTEXT_SAVE=n helps here
RDharageswari commentedon Aug 22, 2023
yes, with CONFIG_ADSP_IMR_CONTEXT_SAVE=n,
[ 479.871280] sof-audio-pci-intel-mtl 0000:00:1f.3: PM: pci_pm_suspend+0x0/0x20b returned 0 after 138131 usecs
[ 479.975001] sof-audio-pci-intel-mtl 0000:00:1f.3: PM: pci_pm_suspend_late+0x0/0x3e returned 0 after 2 usecs
[ 480.026195] sof-audio-pci-intel-mtl 0000:00:1f.3: PM: pci_pm_suspend_noirq+0x0/0x236 returned 0 after 12138 usecs
plbossart commentedon Aug 22, 2023
@RDharageswari can you clarify if the device is already in D3 while doing the suspend? IIRC there is a PCI requirement to go back to D0 before doing a system suspend, so that will clearly take time. If we want to check the suspend time only we need to start from the D0 state. Thanks.
ranj063 commentedon Aug 22, 2023
@plbossart the device is in D3 before suspend but the main issue seems to be that the MOD_DX IPC during suspend takes ~300ms to be processed.
plbossart commentedon Aug 22, 2023
ok, but please make sure the D3->D0 time is not included in the analysis, otherwise we will conflate unrelated issues.
ranj063 commentedon Aug 22, 2023
@plbossart but why shouldn't we include the D3->D0 time in the analysis. Even if it normal PCI device behavior, the transition is done due to an impending system suspend isnt it?
plbossart commentedon Aug 22, 2023
it's a separate step that we don't control so you want to account for it separately - a global number will likely include more time to resume...
semihalf-kardach-stanislaw commentedon Aug 27, 2023
@plbossart It is worth remembering that whenever runtime PM is enabled in Linux, the path of triggering a runtime resume during
pci_pm_suspendwill happen very often. Indeed if I disable runtime PM in Linux for this card, I'm getting suspend times of ~124ms. So the real problem here I presume is the D3->D0 path which is mandatory to prepare foran s2idle suspend.
plbossart commentedon Aug 28, 2023
@semihalf-kardach-stanislaw that's why I asked that we split variables and make sure we have different measurements for pm_runtime D3->D0 and system suspend D0 -> D3, otherwise we can talk forever about different things.
Edit: And btw 124ms to suspend is quite large, there's probably shady things happening here.
kv2019i commentedon Aug 29, 2023
@ranj063 wrote:
This is expected as we need to save DSP memory contents to IMR and this will take time
Can I propose we disable this feature (CONFIG_ADSP_IMR_CONTEXT_SAVE=n) for Chrome builds as the feature is not really needed (in Chrome). The Linux kernel has functionality to save stream states upon suspend (and even this only happens if you have paused streams when system goes to suspend, and this is another thing that is not used in Chrome by CRAS), so we have no real need to save DSP context (and thus no need to incur the context save cost when doing suspend).
Discussed with @abonislawski @mwasko @lgirdwood and @mengdonglin about this earlier offline, but commenting on this bug as well.
serhiy-katsyuba-intel commentedon Sep 1, 2023
In the dmesg log there are 3 occurrences of sending "enter D3" IPC. Responses took 156 ms, 298 ms and 99 ms. Quite different results each time.
I tried D3 test on Windows machine. Response to "enter D3" IPC there is about 3 ms if CONFIG_ADSP_IMR_CONTEXT_SAVE=n and about 68 ms if CONFIG_ADSP_IMR_CONTEXT_SAVE=y. Note, DSP is running on lowest 38 MHz clock when processing that IPC as pipelines are not running. Results are very consistent if running test multiple times.
In order to enter D3, Zephyr scheduler must reach idle processing. Entering D3 will be postponed until any task/thread is in active state. Maybe we have some component in topology that keeps some task/thread active?
@RDharageswari , what is the topology used to reproduce the issue? Are you able to try to reproduce the issue on some other preferably much simpler topology, e.g., without Google AEC maybe (of course, if you have some other simple topology)?
Do you have firmware logs? These might also show us what is still active in firmware at a time of "enter D3" IPC processing.
RDharageswari commentedon Sep 6, 2023
i was able to repro this issue without Google AEC module itself, with the simpler topology
lgirdwood commentedon Sep 13, 2023
@RDharageswari I assume IMR context save was still enabled in your simple test ?
wszypelt commentedon Sep 15, 2023
IMR context save has been disabled, software contex save as a workaround was use. (Piority lower to P2)
@RDharageswari what is an acceptable contex save latency on the D3?
wszypelt commentedon Apr 12, 2024
@RDharageswari What are the current results for this test?
lgirdwood commentedon Apr 16, 2024
@sathya-nujella are you able to comment or close if @RDharageswari is out ?
RDharageswari commentedon Apr 16, 2024
Hi,
This issue is fixed with mtl-06 firmware. Sorry for closing the issue late.