Skip to content

[BUG] IPC error on TRIGGER_PAUSE when multiple pause-resume on CML_SKU0983_SDW #4919

@ghost

Description

Describe the bug
IPC error on TRIGGER_PAUSE when multiple pause-resume on CML_SKU0983_SDW.
Happened on daily test 7618?model=CML_SKU0983_SDW&testcase=multiple-pause-resume-25.

To Reproduce
TPLG=/lib/firmware/intel/sof-tplg/sof-cml-rt711-rt1308-mono-rt715.tplg ~/sof-test/test-case/multiple-pause-resume.sh -r 25

Reproduction Rate
Only once in the daily test, didn't reproduce with 100 rounds pause-resume and 5 loop iterations manually.

Environment
Kernel Branch: topic/sof-dev
Kernel Commit: thesofproject/linux@6b090e61
SOF Branch: main
SOF Commit: 1ef769dd8761
Topology: sof-cml-rt711-rt1308-mono-rt715.tplg
Platform: CML_SKU0983_SDW

Screenshots or console output

dmesg:

[ 3422.884359] kernel: sof-audio-pci-intel-cnl 0000:00:1f.3: FW Poll Status: reg[0x160]=0x20140000 successful
[ 3422.884370] kernel: sof-audio-pci-intel-cnl 0000:00:1f.3: In hda_link_pcm_trigger cmd=3
[ 3422.884396] kernel: sof-audio-pci-intel-cnl 0000:00:1f.3: In hda_link_pcm_trigger cmd=4
[ 3422.884402] kernel: sof-audio-pci-intel-cnl 0000:00:1f.3: pcm: trigger stream 6 dir 0 cmd 4
[ 3422.885026] kernel: sof-audio-pci-intel-cnl 0000:00:1f.3: FW Poll Status: reg[0x160]=0x2014001e successful
[ 3422.885040] kernel: sof-audio-pci-intel-cnl 0000:00:1f.3: ipc tx: 0x60070000: GLB_STREAM_MSG: TRIG_RELEASE
[ 3422.885849] kernel: sof-audio-pci-intel-cnl 0000:00:1f.3: ipc tx succeeded: 0x60070000: GLB_STREAM_MSG: TRIG_RELEASE
[ 3422.940205] kernel: sof-audio-pci-intel-cnl 0000:00:1f.3: pcm: trigger stream 7 dir 0 cmd 3
[ 3422.940238] kernel: sof-audio-pci-intel-cnl 0000:00:1f.3: ipc tx: 0x60060000: GLB_STREAM_MSG: TRIG_PAUSE
[ 3422.940510] kernel: sof-audio-pci-intel-cnl 0000:00:1f.3: ipc tx error for 0x60060000 (msg/reply size: 12/12): -16
[ 3422.940548] kernel: sof-audio-pci-intel-cnl 0000:00:1f.3: FW Poll Status: reg[0x180]=0x20240000 successful
[ 3422.940564] kernel: sof-audio-pci-intel-cnl 0000:00:1f.3: ASoC: error at soc_component_trigger on 0000:00:1f.3: -16
[ 3422.940580] kernel:  HDMI 3: ASoC: trigger FE cmd: 3 failed: -16
[ 3422.940596] kernel: sof-audio-pci-intel-cnl 0000:00:1f.3: pcm: trigger stream 7 dir 0 cmd 4
[ 3422.940612] kernel: sof-audio-pci-intel-cnl 0000:00:1f.3: FW Poll Status: reg[0x180]=0x2024001e successful
[ 3422.940632] kernel: sof-audio-pci-intel-cnl 0000:00:1f.3: ipc tx: 0x60070000: GLB_STREAM_MSG: TRIG_RELEASE
[ 3422.941868] kernel: sof-audio-pci-intel-cnl 0000:00:1f.3: ipc tx error for 0x60070000 (msg/reply size: 12/12): -16
[ 3422.941897] kernel: sof-audio-pci-intel-cnl 0000:00:1f.3: ASoC: error at soc_component_trigger on 0000:00:1f.3: -16
[ 3422.941912] kernel:  HDMI 3: ASoC: trigger FE cmd: 4 failed: -16
[ 3422.942516] kernel: sof-audio-pci-intel-cnl 0000:00:1f.3: pcm: trigger stream 7 dir 0 cmd 3
[ 3422.942542] kernel: sof-audio-pci-intel-cnl 0000:00:1f.3: ipc tx: 0x60060000: GLB_STREAM_MSG: TRIG_PAUSE
[ 3422.942951] kernel: sof-audio-pci-intel-cnl 0000:00:1f.3: ipc tx succeeded: 0x60060000: GLB_STREAM_MSG: TRIG_PAUSE
[ 3422.942978] kernel: sof-audio-pci-intel-cnl 0000:00:1f.3: FW Poll Status: reg[0x180]=0x20240000 successful

sof-logger:

[    78880755.407227] (       65610.312500) c0 ipc                  src/ipc/ipc3/handler.c:1555 INFO ipc: new cmd 0x60060000
[    78880769.625977] (          14.218749) c0 pipe         8.43  ....../pipeline-stream.c:310  INFO pipe trigger cmd 2



[    78881341.136370] (         529.479126) c0 ipc                  src/ipc/ipc3/handler.c:1555 INFO ipc: new cmd 0x60070000
[    78881354.782203] (          13.645833) c0 pipe         8.43  ....../pipeline-stream.c:310  INFO pipe trigger cmd 10



[    78882505.355074] (          13.958333) c0 ll-schedule        ./schedule/ll_schedule.c:115  INFO task complete 0xbe1b02c0 pipe-task 
[    78813898.586967] (        2064.635254) c0 hda-dma            ..../intel/hda/hda-dma.c:950  ERROR hda_dma_link_check_xrun(): underrun detected
[    78815145.097334] (        1246.510376) c0 hda-dma            ..../intel/hda/hda-dma.c:950  ERROR hda_dma_link_check_xrun(): underrun detected
[    78880787.230142] (          17.604166) c0 hda-dma            ..../intel/hda/hda-dma.c:674  ERROR hda-dmac: 7 channel 1 not idle after stop
[    78880800.146809] (          12.916666) c0 pipe         8.43  ....../pipeline-stream.c:368  ERROR pipeline_trigger_run(): ret = -16, host->comp.id = 38, cmd = 2
[    78880811.657225] (          11.510416) c0 ipc                  src/ipc/ipc3/handler.c:469  ERROR ipc: comp 38 trigger 0x60000 failed -16
[    78882468.219659] (        1113.437500) c0 hda-dma            ..../intel/hda/hda-dma.c:614  ERROR hda-dmac: 7 channel 1 busy. dgcs 0x800900 status 5
[    78882480.407159] (          12.187499) c0 pipe         8.43  ....../pipeline-stream.c:398  ERROR pipeline_trigger(): ret = -16, host->comp.id = 38, cmd = 10
[    78882491.396741] (          10.989583) c0 pipe         8.43  ..../pipeline-schedule.c:92   ERROR pipeline_task(): failed to trigger components: -16
[    78882515.980074] (          10.625000) c0 ll-schedule        ./schedule/ll_schedule.c:118  INFO num_tasks 3 total_num_tasks 3
[    78883642.490446] (        1126.510376) c0 ipc                  src/ipc/ipc3/handler.c:1555 INFO ipc: new cmd 0x60060000
[    78883656.396695] (          13.906249) c0 pipe         8.43  ....../pipeline-stream.c:310  INFO pipe trigger cmd 2
[    78883823.323772] (         166.927078) c0 ll-schedule        ./schedule/ll_schedule.c:517  INFO task cancel 0xbe1b02c0 pipe-task 
[    78909161.916515] (       25338.591797) c0 ipc                  src/ipc/ipc3/handler.c:1555 INFO ipc: new cmd 0x60070000
[    78909176.031098] (          14.114583) c0 pipe         8.43  ....../pipeline-stream.c:310  INFO pipe trigger cmd 10
[    78909190.666514] (          14.635416) c0 ll-schedule        ./schedule/ll_schedule.c:391  INFO task add 0xbe1b02c0 pipe-task 
[    78909201.447763] (          10.781250) c0 ll-schedule        ./schedule/ll_schedule.c:395  INFO task params pri 0 flags 0 start 0 period 1000
[    78909218.166513] (          16.718750) c0 ll-schedule        ./schedule/ll_schedule.c:307  INFO new added task->start 1930264339 at 1930250816
[    78909228.999846] (          10.833333) c0 ll-schedule        ./schedule/ll_schedule.c:310  INFO num_tasks 4 total_num_tasks 4

full_dmesg.txt
full_slogger.txt

Metadata

Metadata

Assignees

No one assigned

    Labels

    CMLApplies to Comet Lake platformIntel Linux Daily testsThis issue can be found in internal Linux daily testsbugSomething isn't working as expected

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions