Repository navigation
[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
Activity
xiulipan commentedon Nov 14, 2019
With arecord the error log is different
$ sudo ./sof-logger -l sof-bdw.ldc CORE LEVEL COMP_ID TIMESTAMP DELTA FILE_NAME CONTENT 0 2 PIPE 2.16 23163051377.812500 nan src/audio/pipeline.c:658 pipeline_trigger() 0 2 IPC 23163051309.427086 nan src/ipc/handler.c:459 ipc: comp 1 -> trigger cmd 0x40000 0 2 SSP 23163051708.229168 398.802094 /intel/haswell/ssp.c:417 ssp_start() 0 2 SCHEDULE_LL 23163051805.625000 97.395836 _multi_chan_domain.c:105 dma_multi_chan_domain_register()lgirdwood commentedon Nov 15, 2019
@xiulipan let me list some differences to check comapred to BYT.
It does look like IPC, scheduling, WFI, topology is all working based on above, so I'm suspecting it's SSP, DMAC.
xiulipan commentedon Nov 22, 2019
@lgirdwood Thanks for the hint, I will try to add some log to check if the BDW hits these issues.
IPC is working with TPLG load.
Volume change is always working.
DMA trace is working.
Only playback is not working, seems to be SSP DAI driver issue.
lgirdwood commentedon Nov 22, 2019
@xiulipan ok, I'll send you some SSP configs that might help.