SMP: power down cores only if all pipelines running on it have been stopped

Currently implement of sof_widget_unload has a issue of powerdown the core immediately after the snd_soc_dapm_scheduler swidget is removed.
At least this need check if all the pipeline in the core are all removed.

@zhuyingjiang

@zhuyingjiang your issue is borderline useless at this point without explanation, logs, context, etc. Please be more specific on what you are seeing and describe the effects

@zhuyingjiang

@zhuyingjiang I think this is a valid issue. I am guessing you hit the issue during module unload.
And I think this is the root cause for all the ipc timeouts that we are seeing during module unload.

Basically, we should add a usage counter for the core and when a pipeline widget is unloaded, we need to decrement the core's usage counter. And only when it hits 0, we should power it down. Can you fix this please?

And also maybe we need to keep core 0 alive all the time until the call to snd_sof_dsp_remove() takes care of it.

@ranj063

@ranj063 Yes, I can do that, but since I am now taking AL, the respond maybe slow.

@zhuyingjiang

@zhuyingjiang no problem. ENjoy your vacation. I'll take care of it.

On 1/25/19 6:56 PM, Ranjani Sridharan wrote: @zhuyingjiang <https://github.com/zhuyingjiang> I think this is a valid issue. I am guessing you hit the issue during module unload. And I think this is the root cause for all the ipc timeouts that we are seeing during module unload. Basically, we should add a usage counter for the core and when a pipeline widget is unloaded, we need to decrement the core's usage counter. And only when it hits 0, we should power it down. Can you fix this please?

I still don't get how we can even try to remove a module while it's being used? can someone provide a test script showing how to reproduce this?

…

@plbossart

@plbossart On the up2 with Ubuntu installed and pulseaudio enabled, you will hit this issue with the sof_bootloop.sh on the very second iteration.

On 1/28/19 1:02 PM, Ranjani Sridharan wrote: @plbossart <https://github.com/plbossart> On the up2 with Ubuntu installed and pulseaudio enabled, you will hit this issue with the sof_bootloop.sh on the very second iteration.

This is too system dependent, I don't have this problem on Ubilinux. and in some cases pulseaudio is only started if you use the UI, if you use SSH as root it's not started at all. Bottom line we need a script with aplay/speaker-test. When I try with the legacy driver on Up2 w/ speaker-test, I get this: root@ubilinux4:~# rmmod snd-hda-intel rmmod: ERROR: Module snd_hda_intel is in use If I look at the following sysfs file, one can see clearly the difference between the case where audio is playing and the case where it's not. root@ubilinux4:/sys/bus/pci/drivers/snd_hda_intel# more module/refcnt 1 root@ubilinux4:/sys/bus/pci/drivers/snd_hda_intel# more module/refcnt 0 One can only remove the snd-hda-intel module when the refcount is zero. If you try with SOF, you will get the following report: root@ubilinux4:/# more /sys/bus/pci/drivers/sof-audio-pci/module/refcnt 0 root@ubilinux4:/# more /sys/bus/pci/drivers/sof-audio-pci/module/refcnt 0 In short, the device model we have for SOF isn't quite right. There is also something fishy about module dependency. This is what you see on startup: snd_sof 94208 4 snd_sof_intel_hda_common,snd_sof_intel_byt,sof_pci_dev and if I rmmod sof-pci-dev I get this: snd_sof 94208 2 snd_sof_intel_hda_common,snd_sof_intel_byt so somehow we have a bad refcount for module usage.

@plbossart

@plbossart thanks for the analysis. I'll take a look at the module dependency and refcounts today.

But leaving the module load/unload case apart, does it logically make sense to power down the core only if all the pipelines running on it have been unloaded?

On 1/28/19 2:55 PM, Ranjani Sridharan wrote: @plbossart <https://github.com/plbossart> thanks for the analysis. I'll take a look at the module dependency and refcounts today. But leaving the module load/unload case apart, does it logically make sense to power down the core only if all the pipelines running on it have been unloaded?

I don't know to be honest, I have already too many questions on IPC, PM and suspend/resume to look at this for now.

the dsp core ref count probably can be fixed together with #557

@zhuyingjiang

@zhuyingjiang can you verify if this bug is still valid? please post your test procedure so that others can reproduce the bug.

@wenqingfu

@wenqingfu OK, will do it today.

The issue still exists.
The test steps are:(on up2 or some platform else, this is a general issue)

run aplay to play some wave to make the pipeline work:
aplay -D hw:0,0 xxx.wav
remove the widget by doing unload the module:
rmmod sof_pci_dev
or using the sof_remove.sh
This will hit a kernel oops:

[ +0.027628] Port5: ASoC: trigger FE failed -22
[ +0.000194] BUG: unable to handle kernel NULL pointer dereference at 0000000000000088
[ +0.000011] PGD 163105067 P4D 163105067 PUD 1775b1067 PMD 0
[ +0.000008] Oops: 0000 [#1] SMP NOPTI
[ +0.000006] CPU: 2 PID: 2528 Comm: aplay Not tainted 4.20.0+ #39
[ +0.000003] Hardware name: AAEON UP-APL01/UP-APL01, BIOS UPA1AM36 04/10/2018
[ +0.000014] RIP: 0010:soc_pcm_hw_free+0x17d/0x1b0 [snd_soc_core]
[ +0.000004] Code: 48 8b 80 88 00 00 00 48 8b 80 80 00 00 00 48 85 c0 74 08 4c 89 e7 e8 a2 bf 36 f7 83 c5 01 39 ab 38 06 00 00 77 c3 49 8b 45 18 <48> 8b 80 88 00 00 00 48 8b 80 80 00 00 00 48 85 c0 74 0b 4c 89 ee
[ +0.000003] RSP: 0018:ffffa376814f7e00 EFLAGS: 00010246
[ +0.000004] RAX: 0000000000000000 RBX: ffff8c5b3853d000 RCX: ffff8c5b39cf6d00
[ +0.000003] RDX: ffff8c5b374b2b40 RSI: ffff8c5b3ab3dd80 RDI: ffffffffc0382840
[ +0.000003] RBP: 0000000000000001 R08: 0000000000000000 R09: 0000000000000000
[ +0.000003] R10: ffff8c5b3abb2d10 R11: 00000000003264f1 R12: ffff8c5b3859f000
[ +0.000003] R13: ffff8c5b375fc480 R14: ffff8c5b3853d018 R15: 0000000000000000
[ +0.000003] FS: 00007fdcaa948700(0000) GS:ffff8c5b3bb00000(0000) knlGS:0000000000000000
[ +0.000004] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ +0.000003] CR2: 0000000000000088 CR3: 0000000165a82000 CR4: 00000000003406e0
[ +0.000002] Call Trace:
[ +0.000015] dpcm_fe_dai_hw_free+0x6c/0xe0 [snd_soc_core]
[ +0.000009] snd_pcm_release_substream.part.50+0x3f/0xa0 [snd_pcm]
[ +0.000007] snd_pcm_release+0x9b/0xb0 [snd_pcm]
[ +0.000007] __fput+0xd5/0x1d0
[ +0.000008] task_work_run+0x79/0xa0
[ +0.000007] exit_to_usermode_loop+0x91/0xa0
[ +0.000004] do_syscall_64+0xdb/0xf0
[ +0.000007] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[ +0.000005] RIP: 0033:0x7fdca9d50747
[ +0.000004] Code: 2c 00 f7 d8 64 89 02 48 c7 c0 ff ff ff ff eb 95 48 8b 15 44 27 2c 00 f7 d8 64 89 02 e9 63 ff ff ff 66 90 b8 0b 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 21 27 2c 00 f7 d8 64 89 01 48
[ +0.000003] RSP: 002b:00007ffc48c6e688 EFLAGS: 00000206 ORIG_RAX: 000000000000000b
[ +0.000003] RAX: 0000000000000000 RBX: 0000000001a8eb40 RCX: 00007fdca9d50747
[ +0.000003] RDX: 0000000000000010 RSI: 0000000000001000 RDI: 00007fdcaa95a000
[ +0.000003] RBP: 0000000001a8eb40 R08: 00007fdcaa2fb960 R09: 00000000ffffffed
[ +0.000003] R10: 0000000000000557 R11: 0000000000000206 R12: 0000000001a8eb40
[ +0.000003] R13: 0000000000000000 R14: 0000000000000002 R15: 0000000000000000
[ +0.000004] Modules linked in: snd_soc_sst_bxt_pcm512x snd_soc_hdac_hdmi snd_soc_dmic x86_pkg_temp_thermal sof_pci_dev(-) snd_sof_intel_hda_common snd_soc_hdac_hda snd_sof_intel_hda snd_sof_intel_byt snd_sof_xtensa_dsp snd_sof snd_sof_nocodec snd_soc_acpi_intel_match snd_soc_acpi intel_lpss_pci snd_hda_ext_core intel_lpss mfd_core snd_hda_codec snd_hwdep snd_hda_core snd_soc_pcm512x_i2c snd_soc_pcm512x snd_soc_core snd_pcm efivarfs mmc_block sdhci_pci cqhci sdhci xhci_pci xhci_hcd
[ +0.000030] CR2: 0000000000000088
[ +0.000005] ---[ end trace 334cad95d5b631b5 ]---
[ +0.000009] RIP: 0010:soc_pcm_hw_free+0x17d/0x1b0 [snd_soc_core]
[ +0.000003] Code: 48 8b 80 88 00 00 00 48 8b 80 80 00 00 00 48 85 c0 74 08 4c 89 e7 e8 a2 bf 36 f7 83 c5 01 39 ab 38 06 00 00 77 c3 49 8b 45 18 <48> 8b 80 88 00 00 00 48 8b 80 80 00 00 00 48 85 c0 74 0b 4c 89 ee
[ +0.000003] RSP: 0018:ffffa376814f7e00 EFLAGS: 00010246
[ +0.000004] RAX: 0000000000000000 RBX: ffff8c5b3853d000 RCX: ffff8c5b39cf6d00
[ +0.000003] RDX: ffff8c5b374b2b40 RSI: ffff8c5b3ab3dd80 RDI: ffffffffc0382840
[ +0.000002] RBP: 0000000000000001 R08: 0000000000000000 R09: 0000000000000000
[ +0.000003] R10: ffff8c5b3abb2d10 R11: 00000000003264f1 R12: ffff8c5b3859f000
[ +0.000003] R13: ffff8c5b375fc480 R14: ffff8c5b3853d018 R15: 0000000000000000
[ +0.000004] FS: 00007fdcaa948700(0000) GS:ffff8c5b3bb00000(0000) knlGS:0000000000000000
[ +0.000003] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ +0.000003] CR2: 0000000000000088 CR3: 0000000165a82000 CR4: 00000000003406e0

As Pierre has analyzed above, there should be a fail message unload the module while playing is in progress, like the HDA driver do.

root@ubilinux4:~# rmmod snd-hda-intel
rmmod: ERROR: Module snd_hda_intel is in use

So we may need increase the refcount of sof_pci_dev during playing and decrease it when play stopped.

when do a diff of the lsmod result not play and playing,

There is only snd_soc_sst_bxt_pcm512x and snd_pcm ref count changes

lsmod_playing.txt
lsmod_not_play.txt

I can reproduce this as well on my UP2. Patch seems to exist already in #707

@zhuyingjiang

run aplay to play some wave to make the pipeline work:
aplay -D hw:0,0 xxx.wav

remove the widget by doing unload the module:
rmmod sof_pci_dev
or using the sof_remove.sh
This will hit a kernel oops:

fixed by #785 #786 #788 ? @zhuyingjiang can you please retest?

@wenqingfu

@wenqingfu OK, will check it today.

@wenqingfu

@wenqingfu @ranj063 Yes, when playing a music and try to remove the module, it will return "module is in use". good job , Ranjani!

fixed by #785 #786 #788

Navigation Menu

Repository navigation

SMP: power down cores only if all pipelines running on it have been stopped #597

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

SMP: power down cores only if all pipelines running on it have been stopped #597

Description

Activity

plbossart commented on Jan 25, 2019

ranj063 commented on Jan 26, 2019

zhuyingjiang commented on Jan 27, 2019

ranj063 commented on Jan 27, 2019

plbossart commented on Jan 28, 2019

ranj063 commented on Jan 28, 2019

plbossart commented on Jan 28, 2019

ranj063 commented on Jan 28, 2019

plbossart commented on Jan 28, 2019

wenqingfu commented on Feb 7, 2019

wenqingfu commented on Feb 27, 2019

zhuyingjiang commented on Feb 28, 2019

zhuyingjiang commented on Feb 28, 2019

zhuyingjiang commented on Feb 28, 2019

kv2019i commented on Mar 21, 2019

wenqingfu commented on Apr 5, 2019

zhuyingjiang commented on Apr 8, 2019

zhuyingjiang commented on Apr 8, 2019

wenqingfu commented on Apr 18, 2019

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions