[BUG] IPC timeout on BDW #2096
Description
Describe the bug
When try to playback on BDW platform, ipc timeout happen at TRIG_START
To Reproduce
aplay on BDW paltform and dmesg shwo ipc timeout
Reproduction Rate
4/4
Expected behavior
aplay should we with no ipc timeout.
Impact
What impact does this issue have on your progress (e.g., annoyance, showstopper)
Environment
Test with #2095 with sof-bdw-nocodec.tplg
or
Test with thesofproject/linux#1484 and #2095 with sof-bdw-rt286.tplg
Screenshots or console output
dmesg
[ 99.874778] sof-audio-acpi INT3438:00: pcm: open stream 0 dir 0
[ 99.874784] sof-audio-acpi INT3438:00: period min 192 max 16384 bytes
[ 99.874787] sof-audio-acpi INT3438:00: period count 2 max 16
[ 99.874790] sof-audio-acpi INT3438:00: buffer max 65536 bytes
[ 100.049301] sof-audio-acpi INT3438:00: rate_min: 48000 rate_max: 48000
[ 100.049304] sof-audio-acpi INT3438:00: channels_min: 2 channels_max: 2
[ 100.084524] sof-audio-acpi INT3438:00: rate_min: 48000 rate_max: 48000
[ 100.084529] sof-audio-acpi INT3438:00: channels_min: 2 channels_max: 2
[ 100.085179] sof-audio-acpi INT3438:00: rate_min: 48000 rate_max: 48000
[ 100.085184] sof-audio-acpi INT3438:00: channels_min: 2 channels_max: 2
[ 100.085193] sof-audio-acpi INT3438:00: pcm: hw params stream 0 dir 0
[ 100.085200] sof-audio-acpi INT3438:00: generating page table for 000000000e0ae6ec size 0xffc0 pages 16
[ 100.085204] sof-audio-acpi INT3438:00: stream_tag 0
[ 100.085214] sof-audio-acpi INT3438:00: ipc tx: 0x60010000: GLB_STREAM_MSG: PCM_PARAMS
[ 100.085666] sof-audio-acpi INT3438:00: ipc tx succeeded: 0x60010000: GLB_STREAM_MSG: PCM_PARAMS
[ 100.085675] sof-audio-acpi INT3438:00: pcm: stream dir 0, posn mailbox offset is 649728
[ 100.087212] sof-audio-acpi INT3438:00: pcm: trigger stream 0 dir 0 cmd 1
[ 100.087218] sof-audio-acpi INT3438:00: ipc tx: 0x60040000: GLB_STREAM_MSG: TRIG_START
[ 100.591396] sof-audio-acpi INT3438:00: error: ipc timed out for 0x60040000 size 12
[ 100.591401] sof-audio-acpi INT3438:00: info: preventing DSP entering D3 state to preserve context
[ 100.591470] sof-audio-acpi INT3438:00: error: unexpected fault 0x00000000 trace 0x00000800
[ 100.591474] sof-audio-acpi INT3438:00: error: ipc host -> DSP: pending no complete no raw 0x00000800
[ 100.591476] sof-audio-acpi INT3438:00: error: mask host: pending no complete no raw 0x7fff0000
[ 100.591478] sof-audio-acpi INT3438:00: error: ipc DSP -> host: pending no complete no raw 0x00000000
[ 100.591481] sof-audio-acpi INT3438:00: error: mask DSP: pending yes complete no raw 0x7f9e0002
[ 100.591483] sof-audio-acpi INT3438:00: error: waking up any trace sleepers
[ 100.591487] Low Latency: ASoC: trigger FE cmd: 1 failed: -110dma trace
$ sudo ./sof-logger -l sof-bdw.ldc -t
CORE LEVEL COMP_ID TIMESTAMP DELTA FILE_NAME CONTENT
0 2 SCHEDULE_LL 61867304.166667 61867304.000000 edule/timer_domain.c:47 timer_domain_register()
0 2 IPC 64610050.520833 2742746.250000 src/ipc/handler.c:918 ipc: hdr 0x30010000 tx (76) > rx (28)
0 2 IPC 64610083.802083 33.281250 src/ipc/handler.c:921 ipc: pipe 1 comp 0 -> new (type 1)
0 2 HOST 64610135.677083 51.875000 src/audio/host.c:349 host_new()
0 2 DMA 64610391.927083 256.250000 src/lib/dma.c:128 dma_get() ID 1 sref = 3 busy channels 1
0 2 IPC 64635568.802083 25176.875000 src/ipc/handler.c:918 ipc: hdr 0x30010000 tx (84) > rx (28)
0 2 IPC 64635602.083333 33.281250 src/ipc/handler.c:921 ipc: pipe 1 comp 1 -> new (type 5)
0 2 VOLUME 64635654.062500 51.979168 udio/volume/volume.c:144 volume_new()
0 2 VOLUME 1.1 64635947.864583 293.802094 udio/volume/volume.c:222 vol->initial_ramp = 250, vol->ramp = 0, vol->min_value = 0, vol->max_value = 65536
0 2 IPC 64671959.010417 36011.144531 src/ipc/handler.c:918 ipc: hdr 0x30010000 tx (84) > rx (28)
0 2 IPC 64671992.291667 33.281250 src/ipc/handler.c:921 ipc: pipe 1 comp 2 -> new (type 5)
0 2 VOLUME 64672045.520833 53.229168 udio/volume/volume.c:144 volume_new()
0 2 VOLUME 1.2 64672339.322917 293.802094 udio/volume/volume.c:222 vol->initial_ramp = 250, vol->ramp = 0, vol->min_value = 0, vol->max_value = 65536
0 2 IPC 64673266.770833 927.447937 src/ipc/handler.c:918 ipc: hdr 0x30010000 tx (64) > rx (28)
0 2 IPC 64673300.052083 33.281250 src/ipc/handler.c:921 ipc: pipe 1 comp 3 -> new (type 6)
0 2 MIXER 64673350.677083 50.625000 src/audio/mixer.c:128 mixer_new()
0 2 IPC 64674333.802083 983.125000 src/ipc/handler.c:951 ipc: pipe 1 buffer 4 -> new (0x300 bytes)
0 2 BUFFER 64674376.354167 42.552082 src/audio/buffer.c:64 buffer_new()
0 2 BUFFER 64674411.302083 34.947918 src/audio/buffer.c:24 buffer_alloc()
0 2 IPC 64675543.385417 1132.083374 src/ipc/handler.c:951 ipc: pipe 1 buffer 5 -> new (0x300 bytes)
0 2 BUFFER 64675587.239583 43.854168 src/audio/buffer.c:64 buffer_new()
0 2 BUFFER 64675622.187500 34.947918 src/audio/buffer.c:24 buffer_alloc()
0 2 IPC 64676681.093750 1058.906250 src/ipc/handler.c:951 ipc: pipe 1 buffer 6 -> new (0x300 bytes)
0 2 BUFFER 64676726.250000 45.156250 src/audio/buffer.c:64 buffer_new()
0 2 BUFFER 64676761.197917 34.947918 src/audio/buffer.c:24 buffer_alloc()
0 2 IPC 64678027.968750 1266.770874 src/ipc/handler.c:951 ipc: pipe 1 buffer 7 -> new (0x300 bytes)
0 2 BUFFER 64678074.427083 46.458332 src/audio/buffer.c:64 buffer_new()
0 2 BUFFER 64678109.375000 34.947918 src/audio/buffer.c:24 buffer_alloc()
0 2 IPC 64679391.041667 1281.666626 src/ipc/handler.c:918 ipc: hdr 0x30010000 tx (80) > rx (28)
0 2 IPC 64679424.322917 33.281250 src/ipc/handler.c:921 ipc: pipe 1 comp 8 -> new (type 2)
0 2 DAI 64679478.229167 53.906250 src/audio/dai.c:143 dai_new()
0 2 DAI 64679702.291667 224.062500 src/lib/dai.c:70 dai_get(), d = 0x4023e8, sref = 2
0 2 DMA 64679744.114583 41.822918 src/lib/dma.c:128 dma_get() ID 1 sref = 4 busy channels 1
0 2 IPC 64680602.812500 858.697937 src/ipc/handler.c:979 ipc: pipe 1 -> new
0 2 PIPE 64680673.750000 70.937500 src/audio/pipeline.c:49 pipeline_new()
0 2 IPC 64681389.218750 715.468750 src/ipc/handler.c:654 ipc: pm core mask 0x1 -> enable
0 2 IPC 64695015.104167 13625.885742 src/ipc/handler.c:918 ipc: hdr 0x30010000 tx (76) > rx (28)
0 2 IPC 64695048.385417 33.281250 src/ipc/handler.c:921 ipc: pipe 2 comp 11 -> new (type 1)
0 2 HOST 64695112.604167 64.218750 src/audio/host.c:349 host_new()
0 2 DMA 64695368.854167 256.250000 src/lib/dma.c:128 dma_get() ID 1 sref = 5 busy channels 1
0 2 IPC 64696415.677083 1046.822876 src/ipc/handler.c:918 ipc: hdr 0x30010000 tx (84) > rx (28)
0 2 IPC 64696448.958333 33.281250 src/ipc/handler.c:921 ipc: pipe 2 comp 12 -> new (type 5)
0 2 VOLUME 64696513.593750 64.635414 udio/volume/volume.c:144 volume_new()
0 2 VOLUME 2.12 64696807.500000 293.906250 udio/volume/volume.c:222 vol->initial_ramp = 250, vol->ramp = 0, vol->min_value = 0, vol->max_value = 413542
0 2 IPC 64697676.093750 868.593750 src/ipc/handler.c:951 ipc: pipe 2 buffer 13 -> new (0x300 bytes)
0 2 BUFFER 64697728.802083 52.708332 src/audio/buffer.c:64 buffer_new()
0 2 BUFFER 64697763.750000 34.947918 src/audio/buffer.c:24 buffer_alloc()
0 2 IPC 64698924.843750 1161.093750 src/ipc/handler.c:951 ipc: pipe 2 buffer 14 -> new (0x300 bytes)
0 2 BUFFER 64698978.854167 54.010418 src/audio/buffer.c:64 buffer_new()
0 2 BUFFER 64699013.802083 34.947918 src/audio/buffer.c:24 buffer_alloc()
0 2 IPC 64700249.791667 1235.989624 src/ipc/handler.c:918 ipc: hdr 0x30010000 tx (80) > rx (28)
0 2 IPC 64700283.072917 33.281250 src/ipc/handler.c:921 ipc: pipe 2 comp 15 -> new (type 2)
0 2 DAI 64700344.531250 61.458332 src/audio/dai.c:143 dai_new()
0 2 DAI 64700568.697917 224.166672 src/lib/dai.c:70 dai_get(), d = 0x4023e8, sref = 3
0 2 DMA 64700610.520833 41.822918 src/lib/dma.c:128 dma_get() ID 1 sref = 6 busy channels 1
0 2 IPC 64701662.447917 1051.927124 src/ipc/handler.c:979 ipc: pipe 2 -> new
0 2 PIPE 64701753.645833 91.197914 src/audio/pipeline.c:49 pipeline_new()
0 2 IPC 64702458.802083 705.156250 src/ipc/handler.c:654 ipc: pm core mask 0x1 -> enable
0 2 IPC 64703308.854167 850.052063 src/ipc/handler.c:918 ipc: hdr 0x30010000 tx (76) > rx (28)
0 2 IPC 64703342.135417 33.281250 src/ipc/handler.c:921 ipc: pipe 3 comp 18 -> new (type 1)
0 2 HOST 64703413.906250 71.770836 src/audio/host.c:349 host_new()
0 2 DMA 64703670.052083 256.145844 src/lib/dma.c:128 dma_get() ID 1 sref = 7 busy channels 1
0 2 IPC 64704661.927083 991.875000 src/ipc/handler.c:918 ipc: hdr 0x30010000 tx (84) > rx (28)
0 2 IPC 64704695.208333 33.281250 src/ipc/handler.c:921 ipc: pipe 3 comp 19 -> new (type 5)
0 2 VOLUME 64704767.395833 72.187500 udio/volume/volume.c:144 volume_new()
0 2 VOLUME 3.19 64705061.093750 293.697906 udio/volume/volume.c:222 vol->initial_ramp = 250, vol->ramp = 0, vol->min_value = 0, vol->max_value = 65536
0 2 IPC 64705871.562500 810.468750 src/ipc/handler.c:918 ipc: hdr 0x30010000 tx (76) > rx (28)
0 2 IPC 64705904.843750 33.281250 src/ipc/handler.c:921 ipc: pipe 3 comp 20 -> new (type 8)
0 2 SRC 64705977.552083 72.708336 src/audio/src/src.c:519 src_new()
0 2 IPC 64706902.968750 925.416687 src/ipc/handler.c:951 ipc: pipe 3 buffer 21 -> new (0xc00 bytes)
0 2 BUFFER 64706964.479167 61.510418 src/audio/buffer.c:64 buffer_new()
0 2 BUFFER 64706999.427083 34.947918 src/audio/buffer.c:24 buffer_alloc()
0 2 IPC 64709045.885417 2046.458374 src/ipc/handler.c:951 ipc: pipe 3 buffer 22 -> new (0xc00 bytes)
0 2 BUFFER 64709108.697917 62.812500 src/audio/buffer.c:64 buffer_new()
0 2 BUFFER 64709143.645833 34.947918 src/audio/buffer.c:24 buffer_alloc()
0 2 IPC 64711097.760417 1954.114624 src/ipc/handler.c:951 ipc: pipe 3 buffer 23 -> new (0xc00 bytes)
0 2 BUFFER 64711161.875000 64.114586 src/audio/buffer.c:64 buffer_new()
0 2 BUFFER 64711196.822917 34.947918 src/audio/buffer.c:24 buffer_alloc()
0 2 IPC 64713244.062500 2047.239624 src/ipc/handler.c:979 ipc: pipe 3 -> new
0 2 PIPE 64713342.500000 98.437500 src/audio/pipeline.c:49 pipeline_new()
0 2 IPC 64714031.302083 688.802063 src/ipc/handler.c:654 ipc: pm core mask 0x1 -> enable
0 2 IPC 64715698.750000 1667.447876 src/ipc/handler.c:1018 ipc: comp sink 4, source 0 -> connect
0 2 PIPE 64715745.833333 47.083332 src/audio/pipeline.c:75 pipeline: connect comp 0 and buffer 4
0 2 IPC 64716436.041667 690.208313 src/ipc/handler.c:1018 ipc: comp sink 1, source 4 -> connect
0 2 PIPE 64716484.114583 48.072918 src/audio/pipeline.c:75 pipeline: connect comp 1 and buffer 4
0 2 IPC 64717132.083333 647.968750 src/ipc/handler.c:1018 ipc: comp sink 5, source 1 -> connect
0 2 PIPE 64717181.718750 49.635418 src/audio/pipeline.c:75 pipeline: connect comp 1 and buffer 5
0 2 IPC 64717836.458333 654.739563 src/ipc/handler.c:1018 ipc: comp sink 3, source 5 -> connect
0 2 PIPE 64717888.333333 51.875000 src/audio/pipeline.c:75 pipeline: connect comp 3 and buffer 5
0 2 IPC 64718503.750000 615.416687 src/ipc/handler.c:1018 ipc: comp sink 6, source 3 -> connect
0 2 PIPE 64718590.000000 86.250000 src/audio/pipeline.c:75 pipeline: connect comp 3 and buffer 6
0 2 IPC 64719233.333333 643.333313 src/ipc/handler.c:1018 ipc: comp sink 2, source 6 -> connect
0 2 PIPE 64719284.322917 50.989582 src/audio/pipeline.c:75 pipeline: connect comp 2 and buffer 6
0 2 IPC 64719909.375000 625.052063 src/ipc/handler.c:1018 ipc: comp sink 7, source 2 -> connect
0 2 PIPE 64719961.927083 52.552082 src/audio/pipeline.c:75 pipeline: connect comp 2 and buffer 7
0 2 IPC 64720677.500000 715.572937 src/ipc/handler.c:1018 ipc: comp sink 11, source 14 -> connect
0 2 PIPE 64720747.500000 70.000000 src/audio/pipeline.c:75 pipeline: connect comp 11 and buffer 14
0 2 IPC 64721457.083333 709.583313 src/ipc/handler.c:1018 ipc: comp sink 14, source 12 -> connect
0 2 PIPE 64721528.593750 71.510414 src/audio/pipeline.c:75 pipeline: connect comp 12 and buffer 14
0 2 IPC 64722136.250000 607.656250 src/ipc/handler.c:1018 ipc: comp sink 12, source 13 -> connect
0 2 PIPE 64722206.197917 69.947914 src/audio/pipeline.c:75 pipeline: connect comp 12 and buffer 13
0 2 IPC 64722860.625000 654.427063 src/ipc/handler.c:1018 ipc: comp sink 8, source 7 -> connect
0 2 PIPE 64722920.625000 60.000000 src/audio/pipeline.c:75 pipeline: connect comp 8 and buffer 7
0 2 IPC 64723546.250000 625.625000 src/ipc/handler.c:1018 ipc: comp sink 13, source 15 -> connect
0 2 PIPE 64723620.312500 74.062500 src/audio/pipeline.c:75 pipeline: connect comp 15 and buffer 13
0 2 IPC 64724243.541667 623.229187 src/ipc/handler.c:1018 ipc: comp sink 21, source 18 -> connect
0 2 PIPE 64724328.854167 85.312500 src/audio/pipeline.c:75 pipeline: connect comp 18 and buffer 21
0 2 IPC 64724932.083333 603.229187 src/ipc/handler.c:1018 ipc: comp sink 19, source 21 -> connect
0 2 PIPE 64725018.385417 86.302086 src/audio/pipeline.c:75 pipeline: connect comp 19 and buffer 21
0 2 IPC 64725712.291667 693.906250 src/ipc/handler.c:1018 ipc: comp sink 22, source 19 -> connect
0 2 PIPE 64725800.156250 87.864586 src/audio/pipeline.c:75 pipeline: connect comp 19 and buffer 22
0 2 IPC 64726440.000000 639.843750 src/ipc/handler.c:1018 ipc: comp sink 20, source 22 -> connect
0 2 PIPE 64726528.854167 88.854164 src/audio/pipeline.c:75 pipeline: connect comp 20 and buffer 22
0 2 IPC 64729205.833333 2676.979248 src/ipc/handler.c:1018 ipc: comp sink 23, source 20 -> connect
0 2 PIPE 64729296.250000 90.416664 src/audio/pipeline.c:75 pipeline: connect comp 20 and buffer 23
0 2 IPC 64730003.958333 707.708313 src/ipc/handler.c:1018 ipc: comp sink 3, source 23 -> connect
0 2 PIPE 64730075.156250 71.197914 src/audio/pipeline.c:75 pipeline: connect comp 3 and buffer 23
0 2 IPC 64730885.052083 809.895813 src/ipc/handler.c:537 ipc: dai 1,0 -> config
0 2 DAI 64730921.666667 36.614582 src/lib/dai.c:70 dai_get(), d = 0x4023e8, sref = 4
0 2 SSP 64730958.697917 37.031250 /intel/haswell/ssp.c:93 ssp_set_config()
0 2 SSP 64731058.697917 100.000000 /intel/haswell/ssp.c:402 ssp_set_config(), done
0 2 DAI 64731094.375000 35.677082 src/lib/dai.c:95 dai_put(), dai = 0x4023e8, sref = 3
0 2 DAI 1.8 64731145.833333 51.458332 src/audio/dai.c:684 config comp 8 pipe 1 dai 0 type 1
0 2 DMA 64731184.218750 38.385418 src/drivers/dw/dma.c:136 dw_dma_channel_get(): dma 1 request channel 0
0 2 DAI 2.15 64731237.916667 53.697918 src/audio/dai.c:684 config comp 15 pipe 2 dai 0 type 1
0 2 DMA 64731276.302083 38.385418 src/drivers/dw/dma.c:136 dw_dma_channel_get(): dma 1 request channel 0
0 2 IPC 64732974.166667 1697.864624 src/ipc/handler.c:1005 ipc: pipe 24 -> complete
0 2 PIPE 3.24 64733103.281250 129.114578 src/audio/pipeline.c:155 pipeline_complete()
0 2 MEM 64733157.187500 53.906250 src/lib/alloc.c:1004 heap: buffer status
0 2 MEM 64733190.937500 33.750000 src/lib/alloc.c:975 heap: 0x41ec00 size 521216 blocks 1 caps 0x61
0 2 MEM 64733223.333333 32.395832 src/lib/alloc.c:977 used 26112 free 495104
0 2 MEM 64733257.187500 33.854168 src/lib/alloc.c:1006 heap: runtime status
0 2 MEM 64733290.989583 33.802082 src/lib/alloc.c:975 heap: 0x414000 size 44032 blocks 7 caps 0x61
0 2 MEM 64733323.385417 32.395832 src/lib/alloc.c:977 used 7296 free 36736
0 2 MEM 64733355.885417 32.500000 src/lib/alloc.c:988 block 1 base 0x414c00 size 32
0 2 MEM 64733387.864583 31.979166 src/lib/alloc.c:991 count 128 free 128
0 2 MEM 64733420.364583 32.500000 src/lib/alloc.c:988 block 2 base 0x415c00 size 64
0 2 MEM 64733452.343750 31.979166 src/lib/alloc.c:991 count 64 free 64
0 2 MEM 64733484.843750 32.500000 src/lib/alloc.c:988 block 3 base 0x416c00 size 128
0 2 MEM 64733516.822917 31.979166 src/lib/alloc.c:991 count 64 free 50
0 2 MEM 64733549.322917 32.500000 src/lib/alloc.c:988 block 4 base 0x418c00 size 256
0 2 MEM 64733581.302083 31.979166 src/lib/alloc.c:991 count 64 free 44
0 2 MEM 64733613.802083 32.500000 src/lib/alloc.c:988 block 5 base 0x41cc00 size 512
0 2 MEM 64733645.781250 31.979166 src/lib/alloc.c:991 count 8 free 8
0 2 MEM 64733678.281250 32.500000 src/lib/alloc.c:988 block 6 base 0x41dc00 size 1024
0 2 MEM 64733710.260417 31.979166 src/lib/alloc.c:991 count 4 free 4
0 2 IPC 64734408.750000 698.489563 src/ipc/handler.c:1005 ipc: pipe 16 -> complete
0 2 PIPE 2.16 64734494.114583 85.364586 src/audio/pipeline.c:155 pipeline_complete()
0 2 IPC 64735111.250000 617.135437 src/ipc/handler.c:1005 ipc: pipe 9 -> complete
0 2 PIPE 1.9 64735174.375000 63.125000 src/audio/pipeline.c:155 pipeline_complete()
0 2 IPC 64736812.968750 1638.593750 src/ipc/handler.c:857 ipc: hdr 0x50020000 tx (108) > rx (92)
0 2 IPC 64736845.208333 32.239582 src/ipc/handler.c:859 ipc: comp 19 -> cmd 0
0 2 VOLUME 3.19 64736903.697917 58.489582 udio/volume/volume.c:528 volume_cmd()
0 2 VOLUME 3.19 64736937.708333 34.010418 udio/volume/volume.c:498 volume_ctrl_get_cmd(), SOF_CTRL_CMD_VOLUME / SOF_CTRL_CMD_SWITCH, cdata->comp_id = 19
0 2 VOLUME 3.19 64736970.937500 33.229168 udio/volume/volume.c:505 volume_ctrl_get_cmd(), channel = 0, value = 65536
0 2 VOLUME 3.19 64737004.427083 33.489582 udio/volume/volume.c:505 volume_ctrl_get_cmd(), channel = 1, value = 65536
0 2 IPC 64738063.593750 1059.166626 src/ipc/handler.c:857 ipc: hdr 0x50020000 tx (108) > rx (92)
0 2 IPC 64738095.833333 32.239582 src/ipc/handler.c:859 ipc: comp 12 -> cmd 0
0 2 VOLUME 2.12 64738146.770833 50.937500 udio/volume/volume.c:528 volume_cmd()
0 2 VOLUME 2.12 64738180.781250 34.010418 udio/volume/volume.c:498 volume_ctrl_get_cmd(), SOF_CTRL_CMD_VOLUME / SOF_CTRL_CMD_SWITCH, cdata->comp_id = 12
0 2 VOLUME 2.12 64738214.010417 33.229168 udio/volume/volume.c:505 volume_ctrl_get_cmd(), channel = 0, value = 65536
0 2 VOLUME 2.12 64738247.500000 33.489582 udio/volume/volume.c:505 volume_ctrl_get_cmd(), channel = 1, value = 65536
0 2 IPC 64739279.843750 1032.343750 src/ipc/handler.c:857 ipc: hdr 0x50020000 tx (108) > rx (92)
0 2 IPC 64739312.083333 32.239582 src/ipc/handler.c:859 ipc: comp 2 -> cmd 0
0 2 VOLUME 1.2 64739351.614583 39.531250 udio/volume/volume.c:528 volume_cmd()
0 2 VOLUME 1.2 64739385.625000 34.010418 udio/volume/volume.c:498 volume_ctrl_get_cmd(), SOF_CTRL_CMD_VOLUME / SOF_CTRL_CMD_SWITCH, cdata->comp_id = 2
0 2 VOLUME 1.2 64739418.854167 33.229168 udio/volume/volume.c:505 volume_ctrl_get_cmd(), channel = 0, value = 65536
0 2 VOLUME 1.2 64739452.343750 33.489582 udio/volume/volume.c:505 volume_ctrl_get_cmd(), channel = 1, value = 65536
0 2 IPC 64740561.302083 1108.958374 src/ipc/handler.c:857 ipc: hdr 0x50020000 tx (108) > rx (92)
0 2 IPC 64740593.541667 32.239582 src/ipc/handler.c:859 ipc: comp 1 -> cmd 0
0 2 VOLUME 1.1 64740631.822917 38.281250 udio/volume/volume.c:528 volume_cmd()
0 2 VOLUME 1.1 64740665.833333 34.010418 udio/volume/volume.c:498 volume_ctrl_get_cmd(), SOF_CTRL_CMD_VOLUME / SOF_CTRL_CMD_SWITCH, cdata->comp_id = 1
0 2 VOLUME 1.1 64740699.062500 33.229168 udio/volume/volume.c:505 volume_ctrl_get_cmd(), channel = 0, value = 65536
0 2 VOLUME 1.1 64740732.552083 33.489582 udio/volume/volume.c:505 volume_ctrl_get_cmd(), channel = 1, value = 65536
0 2 IPC 65707026.979167 966294.437500 src/ipc/handler.c:857 ipc: hdr 0x50010000 tx (108) > rx (92)
0 2 IPC 65707060.156250 33.177082 src/ipc/handler.c:859 ipc: comp 1 -> cmd 0
0 2 VOLUME 1.1 65707099.375000 39.218750 udio/volume/volume.c:528 volume_cmd()error trace
$ sudo ./sof-logger -l sof-bdw.ldc
CORE LEVEL COMP_ID TIMESTAMP DELTA FILE_NAME CONTENT
0 2 PIPE 1.9 1668112435.312500 nan src/audio/pipeline.c:658 pipeline_trigger()
0 2 IPC 1668112397.708333 nan src/ipc/handler.c:459 ipc: comp 1 -> trigger cmd 0x40000