Skip to content

[BUG][ADLP] ipc tx timed out for 0x60060000(TRIG_PAUSE)when testing multiple-pause-resume on ADLP Chrome device #5850

@keqiaozhang

Description

@keqiaozhang

Describe the bug
CI detected this issue in today's daily test ID:12812. but failed to reproduced it again. IPC timed out when TRIG_PAUSE and there're some XRUNs detected in DMA trace.

[ 4182.403813] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: pcm: trigger stream 99 dir 1 cmd 3
[ 4182.403847] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx: 0x60060000: GLB_STREAM_MSG: TRIG_PAUSE
[ 4182.911354] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx timed out for 0x60060000 (msg/reply size: 12/12)
[ 4182.911388] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: preventing DSP entering D3 state to preserve context
[ 4182.911396] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ------------[ IPC dump start ]------------
[ 4182.911421] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: hda irq intsts 0x00000000 intlctl 0xc0000083 rirb 00
[ 4182.911434] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: dsp irq ppsts 0x00000000 adspis 0x00000000
[ 4182.911455] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: error: host status 0x00000000 dsp status 0x00000000 mask 0x00000003
[ 4182.911464] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ------------[ IPC dump end ]------------
[ 4182.911473] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ------------[ DSP dump start ]------------
[ 4182.911480] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: IPC timeout
[ 4182.911488] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: fw_state: SOF_FW_BOOT_COMPLETE (6)
[ 4182.911508] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: status: fw entered - code 00000005
[ 4182.911646] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: unexpected fault 0x00000000 trace 0x00004000
[ 4182.911658] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ------------[ DSP dump end ]------------

DMA-trace

[     2482386.099276] (          23.229166) c1 dmic-dai     2.0   ....../intel/dmic/dmic.c:418  INFO dmic_stop(), dmic_active_fifos_mask = 0x1

[     2482423.026357] (          28.281248) c1 zll-schedule       src/schedule/zephyr_ll.c:69   INFO task complete 0xbe093a00 pipe-task [     2482394.745108] (           8.645833) c0 hda-dma            ..../intel/hda/hda-dma.c:948  ERROR hda_dma_link_check_xrun(): underrun detected
[     2482443.234690] (          20.208332) c1 zll-schedule       src/schedule/zephyr_ll.c:71   INFO num_tasks 2 total_num_tasks 4
[     2482462.661772] (          19.427082) c1 zll-schedule       src/schedule/zephyr_ll.c:69   INFO task complete 0x9e087808 dmic-work <59c87728-d8f9-42f6-b89d-5870a87b0e1e>
[     2482479.745105] (          17.083332) c1 zll-schedule       src/schedule/zephyr_ll.c:71   INFO num_tasks 1 total_num_tasks 3
[     2482500.213854] (          20.468750) c1 zll-schedule       ......../zephyr_domain.c:210  INFO zephyr_domain_unregister domain->type 1 domain->clk 4
[     2491369.744752] (        8869.531250) c0 ipc                  src/ipc/ipc3/handler.c:1605 INFO ipc: new cmd 0x60060000
[     2491403.807251] (          34.062500) c0 pipe         8.43  ....../pipeline-stream.c:270  INFO pipe trigger cmd 2
[     2492383.703045] (         979.895813) c0 zll-schedule       src/schedule/zephyr_ll.c:69   INFO task complete 0xbe093f80 pipe-task 
[     2492402.817627] (          19.114582) c0 zll-schedule       src/schedule/zephyr_ll.c:71   INFO num_tasks 2 total_num_tasks 2
[     2492844.119693] (         441.302063) c0 ipc                  src/ipc/ipc3/handler.c:1605 INFO ipc: new cmd 0x80010000
[     2492873.338442] (          29.218748) c0 ipc                  src/ipc/ipc3/handler.c:595  INFO ipc: dai 3.3 -> config 
[     2492894.484275] (          21.145832) c0 dai                           src/lib/dai.c:166  INFO dai_get type 3 index 3 new sref 2
[     2492915.161357] (          20.677082) c0 hda-dai      3.3   /drivers/intel/hda/hda.c:42   INFO hda_set_config(): channels 2 rate 48000
[     2492935.421773] (          20.260416) c0 dai                           src/lib/dai.c:190  INFO dai_put type 3 index 3 new sref 1
[     2492955.890522] (          20.468750) c0 ipc                      src/ipc/ipc3/dai.c:185  INFO ipc_comp_dai_config() dai type = 3 index = 3
[     2492996.567604] (          40.677082) c0 dai          8.42        src/ipc/ipc3/dai.c:279  INFO dai_config() dai type = 3 index = 3 dd 0x9e089680
[     2493123.755099] (         127.187492) c1 ipc                  src/ipc/ipc3/handler.c:595  INFO ipc: dai 3.3 -> config 
[     2493144.223848] (          20.468750) c1 ipc                      src/ipc/ipc3/dai.c:185  INFO ipc_comp_dai_config() dai type = 3 index = 3
[     2494861.255030] (        1717.031128) c0 ipc                  src/ipc/ipc3/handler.c:1605 INFO ipc: new cmd 0x60070000
[     2494895.213362] (          33.958332) c0 pipe         8.43  ....../pipeline-stream.c:270  INFO pipe trigger cmd 8
[     2494923.702944] (          28.489582) c0 zll-schedule       src/schedule/zephyr_ll.c:289  INFO task add 0xbe093f80 pipe-task  priority 0 flags 0x0




[     2528776.149515] (         140.312500) c0 ipc                  src/ipc/ipc3/handler.c:1605 INFO ipc: new cmd 0x60070000
[     2528870.784928] (          94.635414) c1 pipe         10.51 ....../pipeline-stream.c:270  INFO pipe trigger cmd 8
[     2528907.034927] (          36.250000) c1 zll-schedule       src/schedule/zephyr_ll.c:289  INFO task add 0xbe093a00 pipe-task 
[     2512452.452247] (       17528.750000) c0 hda-dma            ..../intel/hda/hda-dma.c:948  ERROR hda_dma_link_check_xrun(): underrun detected
[     2514490.525083] (        2038.072876) c0 hda-dma            ..../intel/hda/hda-dma.c:948  ERROR hda_dma_link_check_xrun(): underrun detected
[     2516491.983337] (        2001.458252) c0 hda-dma            ..../intel/hda/hda-dma.c:948  ERROR hda_dma_link_check_xrun(): underrun detected
[     2528635.837021] (       12143.853516) c0 hda-dma            ..../intel/hda/hda-dma.c:948  ERROR hda_dma_link_check_xrun(): underrun detected priority 0 flags 0x0
[     2528945.524509] (          38.489582) c1 zll-schedule       ......../zephyr_domain.c:180  INFO zephyr_domain_register domain->type 1 domain->clk 4 domain->ticks_per_ms 38400 period 1000

To Reproduce
~/sof-test/test-case/multiple-pause-resume.sh -r 50

Reproduction Rate
This issue is reproducible. I reproduced this issue once in 5 rounds of tests.

Environment
Kernel Branch: topic/sof-dev
Kernel Commit: 0b48f05d38c9

SOF Branch: main
SOF Commit: 9611d12

Zephyr Commit:
70dbf7e695d2

TPLG:sof-adl-max98390-rt5682.tplg
image

Platform: ADLP Chrome device Gimble-I2S with Zephyr.

dmesg.txt
logger.txt

Metadata

Metadata

Assignees

No one assigned

    Labels

    ADLApplies to Alder Lake platformIPC timeoutIPC timeout observedP2Critical bugs or normal featuresZephyrIssues only observed with Zephyr integratedbugSomething 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