Closed ClarexZhou closed 5 years ago
Error occurred twice (2nd time reload and the 34th reload)during modules reload test on cml laptop. Error logger
CORE LEVEL COMP_ID TIMESTAMP DELTA FILE_NAME CONTENT
0 1 DMA 12974929.583333 12974930.000000 intel/cavs/hda-dma.c:616 hda-dmac: 5 invalid channel -1
[ 109.766051] sof-audio-pci 0000:00:1f.3: ipc tx: 0x50020000: GLB_COMP_MSG: GET_VALUE
[ 109.766327] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x50020000: GLB_COMP_MSG: GET_VALUE
[ 109.766336] sof-audio-pci 0000:00:1f.3: error: volume get failed to idle -16
[ 110.749197] sof-audio-pci 0000:00:1f.3: ipc rx: 0x90020000: GLB_TRACE_MSG
[ 110.749231] sof-audio-pci 0000:00:1f.3: ipc rx done: 0x90020000: GLB_TRACE_MSG
[ 112.498123] sof-audio-pci 0000:00:1f.3: pcm: open stream 0 dir 0
[ 112.498130] sof-audio-pci 0000:00:1f.3: period min 192 max 16384 bytes
[ 112.498134] sof-audio-pci 0000:00:1f.3: period count 2 max 16
[ 112.498138] sof-audio-pci 0000:00:1f.3: buffer max 65536 bytes
[ 112.498447] sof-audio-pci 0000:00:1f.3: ipc tx: 0x80010000: GLB_DAI_MSG: CONFIG
[ 112.800134] sof-audio-pci 0000:00:1f.3: error: ipc timed out for 0x80010000 size 120
[ 112.800153] sof-audio-pci 0000:00:1f.3: status: fw entered - code 00000005
[ 112.800384] sof-audio-pci 0000:00:1f.3: error: unexpected fault 0x00000000 trace 0x00004000
[ 112.800393] sof-audio-pci 0000:00:1f.3: error: host status 0x80000000 dsp status 0x00000000 mask 0x00000003
[ 112.800398] sof-audio-pci 0000:00:1f.3: error: waking up any trace sleepers
[ 112.800405] sof-audio-pci 0000:00:1f.3: error: failed to set dai config for Analog Playback and Capture
[ 112.800412] sof-audio-pci 0000:00:1f.3: ASoC: can't set Analog CPU DAI hw params: -110
[ 112.800428] Analog Playback and Capture: ASoC: hw_params BE failed -110
[ 112.800433] HDA Analog: ASoC: hw_params BE failed -110
[ 112.800449] sof-audio-pci 0000:00:1f.3: pcm: free stream 0 dir 0
[ 112.800458] sof-audio-pci 0000:00:1f.3: ipc tx: 0x60030000: GLB_STREAM_MSG: PCM_FREE
[ 113.104123] sof-audio-pci 0000:00:1f.3: error: ipc timed out for 0x60030000 size 12
[ 113.104150] sof-audio-pci 0000:00:1f.3: status: fw entered - code 00000005
[ 113.104389] sof-audio-pci 0000:00:1f.3: error: unexpected fault 0x00000000 trace 0x00004000
[ 113.104411] sof-audio-pci 0000:00:1f.3: error: host status 0x80000000 dsp status 0x00000000 mask 0x00000003
[ 113.104417] sof-audio-pci 0000:00:1f.3: error: waking up any trace sleepers
[ 113.104593] sof-audio-pci 0000:00:1f.3: ipc tx: 0x80010000: GLB_DAI_MSG: CONFIG
[ 113.408068] sof-audio-pci 0000:00:1f.3: error: ipc timed out for 0x80010000 size 120
[ 113.408098] sof-audio-pci 0000:00:1f.3: status: fw entered - code 00000005
[ 113.408406] sof-audio-pci 0000:00:1f.3: error: unexpected fault 0x00000000 trace 0x00004000
[ 113.408433] sof-audio-pci 0000:00:1f.3: error: host status 0x80000000 dsp status 0x90020000 mask 0x00000003
[ 113.408439] sof-audio-pci 0000:00:1f.3: error: waking up any trace sleepers
[ 113.408447] sof-audio-pci 0000:00:1f.3: error: failed to set dai config for Analog Playback and Capture
[ 113.408456] sof-audio-pci 0000:00
@ClarexZhou Please retest without #1354 applied.
Error occurred once when do reboot stress test 53 times on CFL.
ENV Rander UCM https://github.com/RanderWang/intel-UCM Kernel repo:9494607 https://github.com/thesofproject/linux/tree/release/sof-v5.0 Firmware repo: b73b9a6 https://github.com/thesofproject/sof/commits/master +PR1354 Topology: https://github.com/thesofproject/sof/commits/master . Same as above SOF repo file: tools/topology/sof-hda-generic.m4, sof-hda-generic-2ch.tplg platform: CFL laptop with ALC3254 codec
Error logger
[ 122.913383] sof-audio-pci 0000:00:1f.3: period min 192 max 16384 bytes
[ 122.913387] sof-audio-pci 0000:00:1f.3: period count 2 max 16
[ 122.913391] sof-audio-pci 0000:00:1f.3: buffer max 65536 bytes
[ 122.913932] sof-audio-pci 0000:00:1f.3: pcm: close stream 0 dir 0
[ 126.221919] HDMI HDA Codec ehdaudio0D2: hdac_hdmi_present_sense: disconnect for pin:port 6:0
[ 126.238728] HDMI HDA Codec ehdaudio0D2: hdac_hdmi_present_sense: disconnect for pin:port 5:0
[ 164.086554] HDMI HDA Codec ehdaudio0D2: hdac_hdmi_present_sense: disconnect for pin:port 6:0
[ 194.456910] sof-audio-pci 0000:00:1f.3: pcm: open stream 0 dir 1
[ 194.456917] sof-audio-pci 0000:00:1f.3: period min 192 max 16384 bytes
[ 194.456922] sof-audio-pci 0000:00:1f.3: period count 2 max 16
[ 194.456925] sof-audio-pci 0000:00:1f.3: buffer max 65536 bytes
[ 194.457196] sof-audio-pci 0000:00:1f.3: ipc tx: 0x80010000: GLB_DAI_MSG: CONFIG
[ 194.774433] sof-audio-pci 0000:00:1f.3: error: ipc timed out for 0x80010000 size 120
[ 194.774448] sof-audio-pci 0000:00:1f.3: status: fw entered - code 00000005
[ 194.774707] sof-audio-pci 0000:00:1f.3: error: unexpected fault 0x00000000 trace 0x00004000
[ 194.774730] sof-audio-pci 0000:00:1f.3: error: host status 0x80000000 dsp status 0x00000000 mask 0x00000003
[ 194.774735] sof-audio-pci 0000:00:1f.3: error: waking up any trace sleepers
[ 194.774741] sof-audio-pci 0000:00:1f.3: error: failed to set dai config for Analog Playback and Capture
[ 194.774748] sof-audio-pci 0000:00:1f.3: ASoC: can't set Analog CPU DAI hw params: -110
[ 194.774761] Analog Playback and Capture: ASoC: hw_params BE failed -110
[ 194.774765] HDA Analog: ASoC: hw_params BE failed -110
[ 194.774777] sof-audio-pci 0000:00:1f.3: pcm: free stream 0 dir 1
[ 194.774785] sof-audio-pci 0000:00:1f.3: ipc tx: 0x60030000: GLB_STREAM_MSG: PCM_FREE
[ 195.085576] sof-audio-pci 0000:00:1f.3: error: ipc timed out for 0x60030000 size 12
[ 195.085591] sof-audio-pci 0000:00:1f.3: status: fw entered - code 00000005
[ 195.085857] sof-audio-pci 0000:00:1f.3: error: unexpected fault 0x00000000 trace 0x00004000
[ 195.085881] sof-audio-pci 0000:00:1f.3: error: host status 0x80000000 dsp status 0x00000000 mask 0x00000003
[ 195.085886] sof-audio-pci 0000:00:1f.3: error: waking up any trace sleepers
[ 195.086037] sof-audio-pci 0000:00:1f.3: ipc tx: 0x80010000: GLB_DAI_MSG: CONFIG
[ 195.395553] sof-audio-pci 0000:00:1f.3: error: ipc timed out for 0x80010000 size 120
[ 195.395568] sof-audio-pci 0000:00:1f.3: status: fw entered - code 00000005
[ 195.395832] sof-audio-pci 0000:00:1f.3: error: unexpected fault 0x00000000 trace 0x00004000
[ 195.395847] sof-audio-pci 0000:00:1f.3: error: host status 0x80000000 dsp status 0x90020000 mask 0x00000003
[ 195.395852] sof-audio-pci 0000:00:1f.3: error: waking up any trace sleepers
[ 195.395859] sof-audio-pci 0000:00:1f.3: error: failed to set dai config for Analog Playback and Capture
[ 195.395866] sof-audio-pci 0000:00:1f.3: ASoC: can't set Analog CPU DAI hw params: -110
[ 195.395878] Analog Playback and Capture: ASoC: hw_params BE failed -110
[ 195.395882] HDA Analog: ASoC: hw_params BE failed -110
[ 195.395894] sof-audio-pci 0000:00:1f.3: pcm: free stream 0 dir 1
[ 195.395901] sof-audio-pci 0000:00:1f.3: ipc tx: 0x60030000: GLB_STREAM_MSG: PCM_FREE
[ 195.703172] sof-audio-pci 0000:00:1f.3: error: ipc timed out for 0x60030000 size 12
[ 195.703191] sof-audio-pci 0000:00:1f.3: status: fw entered - code 00000005
[ 195.703484] sof-audio-pci 0000:00:1f.3: error: unexpected fault 0x00000000 trace 0x00004000
[ 195.703506] sof-audio-pci 0000:00:1f.3: error: host status 0x80000000 dsp status 0x90020000 mask 0x00000003
[ 195.703511] sof-audio-pci 0000:00:1f.3: error: waking up any trace sleepers
[ 195.703645] sof-audio-pci 0000:00:1f.3: ipc tx: 0x80010000: GLB_DAI_MSG: CONFIG
[ 196.014322] sof-audio-pci 0000:00:1f.3: error: ipc timed out for 0x80010000 size 120
[ 196.014339] sof-audio-pci 0000:00:1f.3: status: fw entered - code 00000005
@ClarexZhou @YvonneYang2 the recipe used for this issue is incorrect. You cannot use FW PR 1354 without taking kernel PR 895. Please repeat this test by either taking both or removing both.
@mengdonglin can we also retest with trace disabled here too.
0x80010000: GLB_DAI_MSG: CONFIG ipc timed out occurred during aplay -d 1 stress test. System response very slow then ipc timed out.
Environment disable CONFIG_SND_SOC_SOF_DEBUG_ENABLE_DEBUGFS_CACHE in kernel config. Kernel: https://github.com/lyakh/linux/tree/ipc-timeout commit 5969756 ASoC: SOF: hda: couple host and link DMA during FE hw_free , PR 895 FW: https://github.com/lyakh/sof/tree/ipc-timeout commit: b527fd7 dai: assign/free link DMA channel during dai_config() , PR1354
wasp_aplay_dmesg_18.log wasp_aplay_errorlogger_18.log wasp_aplay_soflogger_18.log
[ 977.918121] sof-audio-pci 0000:00:1f.3: ipc tx: 0x60030000: GLB_STREAM_MSG: PCM_FREE
[ 977.918242] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x60030000: GLB_STREAM_MSG: PCM_FREE
[ 977.918255] sof-audio-pci 0000:00:1f.3: ipc tx: 0x80010000: GLB_DAI_MSG: CONFIG
[ 977.918390] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x80010000: GLB_DAI_MSG: CONFIG
[ 977.918441] sof-audio-pci 0000:00:1f.3: pcm: close stream 0 dir 0
[ 978.825222] sof-audio-pci 0000:00:1f.3: ipc rx: 0x90020000: GLB_TRACE_MSG
[ 978.825249] sof-audio-pci 0000:00:1f.3: ipc rx done: 0x90020000: GLB_TRACE_MSG
[ 1058.761508] sof-audio-pci 0000:00:1f.3: pcm: open stream 0 dir 0
[ 1058.761516] sof-audio-pci 0000:00:1f.3: period min 192 max 16384 bytes
[ 1058.761521] sof-audio-pci 0000:00:1f.3: period count 2 max 16
[ 1058.761525] sof-audio-pci 0000:00:1f.3: buffer max 65536 bytes
[ 1058.762286] sof-audio-pci 0000:00:1f.3: ipc tx: 0x80010000: GLB_DAI_MSG: CONFIG
[ 1059.067585] sof-audio-pci 0000:00:1f.3: error: ipc timed out for 0x80010000 size 120
[ 1059.067609] sof-audio-pci 0000:00:1f.3: error: ipc fatal error - code 0000002d
[ 1059.067859] sof-audio-pci 0000:00:1f.3: error: unexpected fault 0x0000017a trace 0x0000017a
[ 1059.067876] sof-audio-pci 0000:00:1f.3: error: host status 0x80000000 dsp status 0x00000000 mask 0x00000003
[ 1059.067883] sof-audio-pci 0000:00:1f.3: error: waking up any trace sleepers
[ 1059.067893] sof-audio-pci 0000:00:1f.3: error: failed to set dai config for Analog Playback and Capture
[ 1059.067903] sof-audio-pci 0000:00:1f.3: ASoC: can't set Analog CPU DAI hw params: -110
[ 1059.067922] Analog Playback and Capture: ASoC: hw_params BE failed -110
[ 1059.067929] HDA Analog: ASoC: hw_params BE failed -110
[ 1059.067950] sof-audio-pci 0000:00:1f.3: pcm: free stream 0 dir 0
[ 1059.067961] sof-audio-pci 0000:00:1f.3: ipc tx: 0x60030000: GLB_STREAM_MSG: PCM_FREE
[ 1059.371464] sof-audio-pci 0000:00:1f.3: error: ipc timed out for 0x60030000 size 12
[ 1059.371483] sof-audio-pci 0000:00:1f.3: error: base fw not found - code 0000002b
[ 1059.371741] sof-audio-pci 0000:00:1f.3: error: unexpected fault 0x0000017b trace 0x0000017b
[ 1059.371751] sof-audio-pci 0000:00:1f.3: error: host status 0x80000000 dsp status 0x90020000 mask 0x00000003
[ 1059.371756] sof-audio-pci 0000:00:1f.3: error: waking up any trace sleepers
[ 1059.372057] sof-audio-pci 0000:00:1f.3: pcm: close stream 0 dir 0
CORE LEVEL COMP_ID TIMESTAMP DELTA FILE_NAME CONTENT
0 1 DMA 17231117036.354168 nan intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17231125653.177086 8616.823242 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17231125921.875000 268.697906 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17231126155.520836 233.645828 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17231126381.614586 226.093750 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17231126903.854168 522.239563 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17231127067.395836 163.541672 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17231127215.208336 147.812500 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17231127356.458336 141.250000 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17231127504.583336 148.125000 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17232460046.250000 1332541.625000 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17232468830.937500 8784.687500 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17232469404.270836 573.333313 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17232469607.656250 203.385422 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17232469875.833336 268.177094 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17232470565.781250 689.947937 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17232470797.708336 231.927078 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17232471049.635418 251.927078 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17232471301.927086 252.291672 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17232471486.041668 184.114578 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17233803359.635418 1331873.625000 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17233803705.156250 345.520844 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17233804438.125000 732.968750 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17233812683.593750 8245.468750 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17233813366.041668 682.447937 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17233814612.395836 1246.354126 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17233815068.802086 456.406250 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17233815327.864586 259.062500 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17233815573.333336 245.468750 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17233815868.802086 295.468750 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17236402182.135418 2586313.250000 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17236402553.489586 371.354156 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17236411310.156250 8756.666992 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17236411529.635418 219.479172 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17236411676.354168 146.718750 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17236412277.291668 600.937500 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17236412491.458336 214.166672 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17236412712.395836 220.937500 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17236412857.031250 144.635422 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17236413076.458336 219.427078 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17237748104.375000 1335027.875000 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17237748306.197918 201.822922 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17237748453.385418 147.187500 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17237749046.250000 592.864563 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17237756480.729168 7434.479004 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17237756912.552086 431.822906 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17237757173.229168 260.677094 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17237757385.625000 212.395828 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17237757532.760418 147.135422 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17237757681.979168 149.218750 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17240347025.885418 2589344.000000 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17240347471.666668 445.781250 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17240347814.635418 342.968750 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17241610386.562500 1262571.875000 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17241610966.458336 579.895813 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17241618768.593750 7802.135254 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17241619114.947918 346.354156 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17241619324.687500 209.739578 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17241619521.510418 196.822922 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17241619801.093750 279.583344 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17248049130.000000 6429329.000000 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17248049542.343750 412.343750 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17248058556.770836 9014.426758 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17248058777.864586 221.093750 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17248059161.145836 383.281250 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17248059769.270836 608.125000 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17248059988.437500 219.166672 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17248060139.687500 151.250000 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17248060286.354168 146.666672 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17248060545.104168 258.750000 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17250645664.531250 2585119.500000 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17250645864.843750 200.312500 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17250646394.062500 529.218750 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17250653910.989586 7516.927246 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17250654073.854168 162.864578 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17250654508.958336 435.104156 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17250654742.968750 234.010422 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17250654898.125000 155.156250 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17250655043.072918 144.947922 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17250655189.791668 146.718750 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17365036831.041668 114381640.000000 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17365037494.427086 663.385437 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17365038129.427086 635.000000 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17365038742.708336 613.281250 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17365039326.510418 583.802063 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17365047444.531250 8118.020996 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17365047715.937500 271.406250 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17365047865.833336 149.895828 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17365048073.072918 207.239578 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17365048213.125000 140.052078 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17579060657.083336 214012448.000000 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17589095550.937500 10034894.000000 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17589096083.281250 532.343750 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17589096389.322918 306.041656 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17589096668.333336 279.010406 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17589098232.343750 1564.010376 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17589098608.854168 376.510406 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17589099118.333336 509.479156 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17589099416.458336 298.125000 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17589099742.604168 326.145844 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17803108759.895836 214009024.000000 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17813138180.208336 10029420.000000 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17813138899.375000 719.166687 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17813139403.437500 504.062500 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17813139793.125000 389.687500 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17813141373.489586 1580.364624 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17813141823.750000 450.260406 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17813142149.166668 325.416656 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17813142616.145836 466.979156 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 17813142900.104168 283.958344 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 18037327988.177086 224185088.000000 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 18037328635.468750 647.291687 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 18037329106.979168 471.510406 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 18037329405.104168 298.125000 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 18037329708.437500 303.333344 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 18037331228.333336 1519.895874 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 18037331793.177086 564.843750 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 18037332179.427086 386.250000 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 18037332458.385418 278.958344 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 18037332714.895836 256.510406 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
0 1 DMA 18140039371.666668 102706656.000000 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
wasp_aplay_dmesg_18.log wasp_aplay_errorlogger_18.log wasp_aplay_soflogger_18.log
@lyakh I think we have another race here. The pattern I see in my tests with aplay stress test is that the with successive DAI_CONFIG IPC's sent, one of them at some point times out. I also think this ipc timeout might be related to the the one seen in https://github.com/thesofproject/linux/issues/958.
this is the patter I'm noticing with the aplay -d 1 stress test. For all the iterations that pass, pcm open happens right after the previous aplay closes. But when the failure occurs, there's a long delay between when the previous stream closes and the next one begins. Here's an example taken from the above logs: [ 977.918441] sof-audio-pci 0000:00:1f.3: pcm: close stream 0 dir 0 [ 978.825222] sof-audio-pci 0000:00:1f.3: ipc rx: 0x90020000: GLB_TRACE_MSG [ 978.825249] sof-audio-pci 0000:00:1f.3: ipc rx done: 0x90020000: GLB_TRACE_MSG ----> a delay of almost 80s. looks like the system hung here. [ 1058.761508] sof-audio-pci 0000:00:1f.3: pcm: open stream 0 dir 0 [ 1058.761516] sof-audio-pci 0000:00:1f.3: period min 192 max 16384 bytes [ 1058.761521] sof-audio-pci 0000:00:1f.3: period count 2 max 16 [ 1058.761525] sof-audio-pci 0000:00:1f.3: buffer max 65536 bytes [ 1058.762286] sof-audio-pci 0000:00:1f.3: ipc tx: 0x80010000: GLB_DAI_MSG: CONFIG [ 1059.067585] sof-audio-pci 0000:00:1f.3: error: ipc timed out for 0x80010000 size 120
@ranj063 can you paste the sof-logger log and dmesg log for the previous(the one at 978.xx second) iteration? It might already has something failed there.
Finally, I have a glimmer of hope here, disabling runtime PM for the HDA codec device ehdaudio0D0 allows me to run the test successfully for 1K iterations
Error occurred at 6th S3 with playback stress test. Also add previous log
Environment Kernel: 9453da1 https://github.com/lyakh/linux/tree/ipc-timeout (with PR895) FW:b527fd7 https://github.com/lyakh/sof/tree/ipc-timeout (with PR1354) Topology:Same as above FW repo, file: tools/topology/sof-hda-generic.m4, sof-hda-generic-2ch.tplg kconfig: unset CONFIG_SND_SOC_SOF_DEBUG_ENABLE_FIRMWARE_TRACE unset CONFIG_SND_SOC_SOF_DEBUG_ENABLE_DEBUGFS_CACHE
6th error logger
CORE LEVEL COMP_ID TIMESTAMP DELTA FILE_NAME CONTENT
0 1 DMA 145754355.677083 145754352.000000 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
6th dmesg
[ 150.988195] PM: suspend entry (s2idle)
[ 150.988197] PM: Syncing filesystems ... done.
[ 150.989448] Freezing user space processes ...
[ 153.875978] sof-audio-pci 0000:00:1f.3: hda: prepare stream dir 0
[ 153.875996] sof-audio-pci 0000:00:1f.3: ipc tx: 0x80010000: GLB_DAI_MSG: CONFIG
[ 154.178021] sof-audio-pci 0000:00:1f.3: error: ipc timed out for 0x80010000 size 120
[ 154.178038] sof-audio-pci 0000:00:1f.3: unknown ROM status value 00000021
[ 154.178421] sof-audio-pci 0000:00:1f.3: error: unexpected fault 0x00000080 trace 0x00000080
[ 154.178437] sof-audio-pci 0000:00:1f.3: error: host status 0x80000000 dsp status 0x00000000 mask 0x00000003
[ 154.178443] sof-audio-pci 0000:00:1f.3: error: failed to set dai config for Analog Playback and Capture
[ 154.178448] sof-audio-pci 0000:00:1f.3: ASoC: cpu DAI prepare error: -110
[ 154.178452] Analog Playback and Capture: ASoC: backend prepare failed -110
[ 154.181380] (elapsed 3.191 seconds) done.
[ 154.181387] OOM killer disabled.
[ 154.181388] Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done.
[ 154.182946] printk: Suspending console(s) (use no_console_suspend to debug)
[ 192.690032] PM: Some devices failed to suspend, or early wake event detected
[ 192.690106] HDMI HDA Codec ehdaudio0D2: hdac_hdmi_present_sense: disconnect for pin:port 5:0
[ 192.690144] HDMI HDA Codec ehdaudio0D2: hdac_hdmi_present_sense: disconnect for pin:port 6:0
[ 192.690158] HDMI HDA Codec ehdaudio0D2: hdac_hdmi_present_sense: disconnect for pin:port 7:0
[ 192.893501] iwlwifi 0000:00:14.3: BIOS contains WGDS but no WRDS
[ 256.266939] OOM killer enabled.
[ 256.266940] Restarting tasks ...
[ 256.268836] sof-audio-pci 0000:00:1f.3: pcm: free stream 0 dir 0
[ 256.268847] sof-audio-pci 0000:00:1f.3: ipc tx: 0x60030000: GLB_STREAM_MSG: PCM_FREE
[ 256.269862] done.
[ 256.342102] PM: suspend exit
[ 256.570017] sof-audio-pci 0000:00:1f.3: error: ipc timed out for 0x60030000 size 12
5th dmesg and no error logger
[ 136.989536] PM: suspend entry (s2idle)
[ 136.989539] PM: Syncing filesystems ... done.
[ 136.992447] Freezing user space processes ... (elapsed 0.002 seconds) done.
[ 136.994916] OOM killer disabled.
[ 136.994917] Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done.
[ 136.995975] printk: Suspending console(s) (use no_console_suspend to debug)
[ 137.098573] sof-audio-pci 0000:00:1f.3: pcm: trigger stream 0 dir 0 cmd 5
[ 137.098584] sof-audio-pci 0000:00:1f.3: ipc tx: 0x60050000: GLB_STREAM_MSG: TRIG_STOP
[ 137.098728] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x60050000: GLB_STREAM_MSG: TRIG_STOP
[ 137.098736] sof-audio-pci 0000:00:1f.3: ipc tx: 0x60030000: GLB_STREAM_MSG: PCM_FREE
[ 137.098952] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x60030000: GLB_STREAM_MSG: PCM_FREE
[ 137.098955] sof-audio-pci 0000:00:1f.3: In hda_link_pcm_trigger cmd=5
[ 137.098959] sof-audio-pci 0000:00:1f.3: ipc tx: 0x80010000: GLB_DAI_MSG: CONFIG
[ 137.099122] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x80010000: GLB_DAI_MSG: CONFIG
[ 137.112525] sof-audio-pci 0000:00:1f.3: ipc tx: 0x40010000: GLB_PM_MSG: CTX_SAVE
[ 137.112707] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x40010000: GLB_PM_MSG: CTX_SAVE
[ 137.112756] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x1010f0f successful
[ 137.112762] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x1000f0f successful
[ 137.112765] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 0 : core_mask f
[ 137.112814] sof-audio-pci 0000:00:1f.3: Debug PCIR: 00000010 at 00000044
[ 137.129032] sd 0:0:0:0: [sda] Synchronizing SCSI cache
[ 137.129130] sd 0:0:0:0: [sda] Stopping disk
[ 139.172771] nvme 0000:3b:00.0: Refused to change power state, currently in D3
[ 139.314362] sd 0:0:0:0: [sda] Starting disk
[ 139.414331] nvme nvme0: 8/0/0 default/read/poll queues
[ 139.504626] iwlwifi 0000:00:14.3: BIOS contains WGDS but no WRDS
[ 139.625050] ata1: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
[ 139.662102] sof-audio-pci 0000:00:1f.3: Debug PCIR: 00000000 at 00000044
[ 139.662110] sof-audio-pci 0000:00:1f.3: Debug PCIR: 00000040 at 00000048
[ 139.662117] sof-audio-pci 0000:00:1f.3: Debug PCIW: 00000000 at 00000048
[ 139.665005] sof-audio-pci 0000:00:1f.3: Debug PCIR: 00000000 at 00000048
[ 139.665011] sof-audio-pci 0000:00:1f.3: Debug PCIW: 00000040 at 00000048
[ 139.665016] sof-audio-pci 0000:00:1f.3: Debug PCIR: 00000040 at 00000048
[ 139.665021] sof-audio-pci 0000:00:1f.3: Debug PCIW: 00000000 at 00000048
[ 139.665026] sof-audio-pci 0000:00:1f.3: Debug PCIR: 00000000 at 00000048
[ 139.665031] sof-audio-pci 0000:00:1f.3: Debug PCIW: 00000040 at 00000048
[ 139.665107] sof-audio-pci 0000:00:1f.3: loading firmware
[ 139.665112] sof-audio-pci 0000:00:1f.3: Debug PCIR: 00000002 at 00000048
[ 139.665117] sof-audio-pci 0000:00:1f.3: Debug PCIW: 00000000 at 00000048
[ 139.665124] sof-audio-pci 0000:00:1f.3: Debug PCIR: 00000000 at 00000044
[ 139.665128] sof-audio-pci 0000:00:1f.3: Debug PCIW: 00000004 at 00000044
[ 139.665130] sof-audio-pci 0000:00:1f.3: booting DSP firmware
[ 139.665298] sof-audio-pci 0000:00:1f.3: period_bytes:0x0
[ 139.665301] sof-audio-pci 0000:00:1f.3: periods:1
[ 139.665771] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f0f0f successful
[ 139.665789] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f0f0e successful
[ 139.665793] sof-audio-pci 0000:00:1f.3: unstall/run core: core_mask = 1
[ 139.665800] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 1 : core_mask 1
[ 139.666377] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x80000000 successful
[ 139.666385] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf010e0e successful
[ 139.666487] sof-audio-pci 0000:00:1f.3: error: no reply expected, received 0x0
[ 139.762382] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x5000001 successful
[ 139.775409] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x5 successful
[ 139.775428] sof-audio-pci 0000:00:1f.3: Firmware download successful, booting...
[ 139.783305] sof-audio-pci 0000:00:1f.3: ipc rx: 0x70000000: FW_READY
[ 139.783310] sof-audio-pci 0000:00:1f.3: ipc: DSP is ready 0x70000000 offset 0x81000
[ 139.783319] sof-audio-pci 0000:00:1f.3: ipc rx done: 0x70000000: FW_READY
[ 139.783367] sof-audio-pci 0000:00:1f.3: firmware boot complete
[ 139.783381] sof-audio-pci 0000:00:1f.3: Debug PCIR: 00000000 at 00000048
[ 139.783386] sof-audio-pci 0000:00:1f.3: Debug PCIW: 00000002 at 00000048
[ 139.783394] sof-audio-pci 0000:00:1f.3: Debug PCIR: 00000004 at 00000044
[ 139.783399] sof-audio-pci 0000:00:1f.3: Debug PCIW: 00000000 at 00000044
[ 139.783409] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.783526] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.783533] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.783642] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.783653] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30200000: GLB_TPLG_MSG: BUFFER_NEW
[ 139.783759] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30200000: GLB_TPLG_MSG: BUFFER_NEW
[ 139.783765] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30200000: GLB_TPLG_MSG: BUFFER_NEW
[ 139.783985] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30200000: GLB_TPLG_MSG: BUFFER_NEW
[ 139.783995] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.784220] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.784228] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30100000: GLB_TPLG_MSG: PIPE_NEW
[ 139.784401] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30100000: GLB_TPLG_MSG: PIPE_NEW
[ 139.784407] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 1 : core_mask 1
[ 139.784412] sof-audio-pci 0000:00:1f.3: ipc tx: 0x40070000: GLB_PM_MSG: CORE_ENABLE
[ 139.784567] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x40070000: GLB_PM_MSG: CORE_ENABLE
[ 139.784578] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.784683] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.784694] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.784848] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.784855] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30200000: GLB_TPLG_MSG: BUFFER_NEW
[ 139.785007] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30200000: GLB_TPLG_MSG: BUFFER_NEW
[ 139.785015] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30200000: GLB_TPLG_MSG: BUFFER_NEW
[ 139.785230] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30200000: GLB_TPLG_MSG: BUFFER_NEW
[ 139.785240] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.785428] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.785434] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30100000: GLB_TPLG_MSG: PIPE_NEW
[ 139.785609] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30100000: GLB_TPLG_MSG: PIPE_NEW
[ 139.785616] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 1 : core_mask 1
[ 139.785620] sof-audio-pci 0000:00:1f.3: ipc tx: 0x40070000: GLB_PM_MSG: CORE_ENABLE
[ 139.785713] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x40070000: GLB_PM_MSG: CORE_ENABLE
[ 139.785723] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.785965] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.785975] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.786199] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.786207] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30200000: GLB_TPLG_MSG: BUFFER_NEW
[ 139.786393] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30200000: GLB_TPLG_MSG: BUFFER_NEW
[ 139.786400] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30200000: GLB_TPLG_MSG: BUFFER_NEW
[ 139.786586] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30200000: GLB_TPLG_MSG: BUFFER_NEW
[ 139.786596] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.786708] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.786719] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30100000: GLB_TPLG_MSG: PIPE_NEW
[ 139.786862] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30100000: GLB_TPLG_MSG: PIPE_NEW
[ 139.786872] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 1 : core_mask 1
[ 139.786876] sof-audio-pci 0000:00:1f.3: ipc tx: 0x40070000: GLB_PM_MSG: CORE_ENABLE
[ 139.786995] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x40070000: GLB_PM_MSG: CORE_ENABLE
[ 139.787005] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.787174] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.787184] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.787296] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.787301] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30200000: GLB_TPLG_MSG: BUFFER_NEW
[ 139.787406] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30200000: GLB_TPLG_MSG: BUFFER_NEW
[ 139.787411] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30200000: GLB_TPLG_MSG: BUFFER_NEW
[ 139.787517] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30200000: GLB_TPLG_MSG: BUFFER_NEW
[ 139.787527] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.787640] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.787650] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30100000: GLB_TPLG_MSG: PIPE_NEW
[ 139.787828] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30100000: GLB_TPLG_MSG: PIPE_NEW
[ 139.787838] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 1 : core_mask 1
[ 139.787843] sof-audio-pci 0000:00:1f.3: ipc tx: 0x40070000: GLB_PM_MSG: CORE_ENABLE
[ 139.787962] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x40070000: GLB_PM_MSG: CORE_ENABLE
[ 139.787972] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.788085] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.788093] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.788208] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.788214] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30200000: GLB_TPLG_MSG: BUFFER_NEW
[ 139.788321] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30200000: GLB_TPLG_MSG: BUFFER_NEW
[ 139.788326] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30200000: GLB_TPLG_MSG: BUFFER_NEW
[ 139.788433] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30200000: GLB_TPLG_MSG: BUFFER_NEW
[ 139.788442] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.788558] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.788569] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30100000: GLB_TPLG_MSG: PIPE_NEW
[ 139.788679] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30100000: GLB_TPLG_MSG: PIPE_NEW
[ 139.788684] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 1 : core_mask 1
[ 139.788688] sof-audio-pci 0000:00:1f.3: ipc tx: 0x40070000: GLB_PM_MSG: CORE_ENABLE
[ 139.788841] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x40070000: GLB_PM_MSG: CORE_ENABLE
[ 139.788851] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.788966] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.788974] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.789088] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.789093] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30200000: GLB_TPLG_MSG: BUFFER_NEW
[ 139.789203] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30200000: GLB_TPLG_MSG: BUFFER_NEW
[ 139.789208] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30200000: GLB_TPLG_MSG: BUFFER_NEW
[ 139.789320] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30200000: GLB_TPLG_MSG: BUFFER_NEW
[ 139.789330] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.789446] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.789456] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30100000: GLB_TPLG_MSG: PIPE_NEW
[ 139.789571] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30100000: GLB_TPLG_MSG: PIPE_NEW
[ 139.789578] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 1 : core_mask 1
[ 139.789582] sof-audio-pci 0000:00:1f.3: ipc tx: 0x40070000: GLB_PM_MSG: CORE_ENABLE
[ 139.789665] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x40070000: GLB_PM_MSG: CORE_ENABLE
[ 139.789674] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.789856] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.789866] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.789986] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.789995] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30200000: GLB_TPLG_MSG: BUFFER_NEW
[ 139.790098] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30200000: GLB_TPLG_MSG: BUFFER_NEW
[ 139.790103] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30200000: GLB_TPLG_MSG: BUFFER_NEW
[ 139.790213] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30200000: GLB_TPLG_MSG: BUFFER_NEW
[ 139.790224] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.790342] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.790353] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30100000: GLB_TPLG_MSG: PIPE_NEW
[ 139.790470] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30100000: GLB_TPLG_MSG: PIPE_NEW
[ 139.790475] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 1 : core_mask 1
[ 139.790479] sof-audio-pci 0000:00:1f.3: ipc tx: 0x40070000: GLB_PM_MSG: CORE_ENABLE
[ 139.790565] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x40070000: GLB_PM_MSG: CORE_ENABLE
[ 139.790575] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.790688] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.790699] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.790869] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.790876] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30200000: GLB_TPLG_MSG: BUFFER_NEW
[ 139.790992] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30200000: GLB_TPLG_MSG: BUFFER_NEW
[ 139.790999] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30200000: GLB_TPLG_MSG: BUFFER_NEW
[ 139.791105] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30200000: GLB_TPLG_MSG: BUFFER_NEW
[ 139.791115] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.791250] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.791261] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30100000: GLB_TPLG_MSG: PIPE_NEW
[ 139.791382] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30100000: GLB_TPLG_MSG: PIPE_NEW
[ 139.791387] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 1 : core_mask 1
[ 139.791391] sof-audio-pci 0000:00:1f.3: ipc tx: 0x40070000: GLB_PM_MSG: CORE_ENABLE
[ 139.791476] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x40070000: GLB_PM_MSG: CORE_ENABLE
[ 139.791486] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.791601] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.791610] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.791737] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.791742] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30200000: GLB_TPLG_MSG: BUFFER_NEW
[ 139.791856] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30200000: GLB_TPLG_MSG: BUFFER_NEW
[ 139.791862] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30200000: GLB_TPLG_MSG: BUFFER_NEW
[ 139.791975] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30200000: GLB_TPLG_MSG: BUFFER_NEW
[ 139.791985] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.792105] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[ 139.792115] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30100000: GLB_TPLG_MSG: PIPE_NEW
[ 139.792241] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30100000: GLB_TPLG_MSG: PIPE_NEW
[ 139.792246] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 1 : core_mask 1
[ 139.792250] sof-audio-pci 0000:00:1f.3: ipc tx: 0x40070000: GLB_PM_MSG: CORE_ENABLE
[ 139.792335] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x40070000: GLB_PM_MSG: CORE_ENABLE
[ 139.792340] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.792448] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.792454] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.792562] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.792567] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.792676] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.792682] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.792859] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.792866] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.792979] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.792983] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.793092] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.793097] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.793206] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.793212] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.793324] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.793329] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.793415] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.793420] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.793506] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.793511] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.793597] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.793603] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.793692] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.793696] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.793851] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.793858] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.793950] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.793955] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.794046] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.794051] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.794144] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.794149] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.794241] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.794247] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.794340] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.794345] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.794441] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.794445] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.794538] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.794543] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.794640] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.794645] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.794744] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.794748] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.794846] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.794851] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.794952] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.794958] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.795059] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.795064] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.795174] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.795180] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.795284] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.795289] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.795395] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.795399] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.795506] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.795511] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.795597] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.795602] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.795694] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.795698] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.795858] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.795865] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.795962] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.795966] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.796067] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.796072] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.796181] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.796185] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.796290] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30030000: GLB_TPLG_MSG: COMP_CONNECT
[ 139.796301] sof-audio-pci 0000:00:1f.3: ipc tx: 0x80010000: GLB_DAI_MSG: CONFIG
[ 139.796411] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x80010000: GLB_DAI_MSG: CONFIG
[ 139.796421] sof-audio-pci 0000:00:1f.3: ipc tx: 0x80010000: GLB_DAI_MSG: CONFIG
[ 139.796533] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x80010000: GLB_DAI_MSG: CONFIG
[ 139.796543] sof-audio-pci 0000:00:1f.3: ipc tx: 0x80010000: GLB_DAI_MSG: CONFIG
[ 139.796655] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x80010000: GLB_DAI_MSG: CONFIG
[ 139.796664] sof-audio-pci 0000:00:1f.3: ipc tx: 0x80010000: GLB_DAI_MSG: CONFIG
[ 139.796780] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x80010000: GLB_DAI_MSG: CONFIG
[ 139.796789] sof-audio-pci 0000:00:1f.3: ipc tx: 0x80010000: GLB_DAI_MSG: CONFIG
[ 139.796901] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x80010000: GLB_DAI_MSG: CONFIG
[ 139.796911] sof-audio-pci 0000:00:1f.3: ipc tx: 0x80010000: GLB_DAI_MSG: CONFIG
[ 139.797023] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x80010000: GLB_DAI_MSG: CONFIG
[ 139.797033] sof-audio-pci 0000:00:1f.3: ipc tx: 0x80010000: GLB_DAI_MSG: CONFIG
[ 139.797145] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x80010000: GLB_DAI_MSG: CONFIG
[ 139.797155] sof-audio-pci 0000:00:1f.3: ipc tx: 0x80010000: GLB_DAI_MSG: CONFIG
[ 139.797365] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x80010000: GLB_DAI_MSG: CONFIG
[ 139.797376] sof-audio-pci 0000:00:1f.3: ipc tx: 0x80010000: GLB_DAI_MSG: CONFIG
[ 139.797662] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x80010000: GLB_DAI_MSG: CONFIG
[ 139.797666] sof-audio-pci 0000:00:1f.3: tplg: complete pipeline PIPELINE.11.DMIC1.IN id 71
[ 139.797670] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30130000: GLB_TPLG_MSG: PIPE_COMPLETE
[ 139.797937] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30130000: GLB_TPLG_MSG: PIPE_COMPLETE
[ 139.797943] sof-audio-pci 0000:00:1f.3: tplg: complete pipeline PIPELINE.10.DMIC0.IN id 65
[ 139.797947] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30130000: GLB_TPLG_MSG: PIPE_COMPLETE
[ 139.798147] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30130000: GLB_TPLG_MSG: PIPE_COMPLETE
[ 139.798151] sof-audio-pci 0000:00:1f.3: tplg: complete pipeline PIPELINE.9.HDA6.OUT id 58
[ 139.798154] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30130000: GLB_TPLG_MSG: PIPE_COMPLETE
[ 139.798346] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30130000: GLB_TPLG_MSG: PIPE_COMPLETE
[ 139.798349] sof-audio-pci 0000:00:1f.3: tplg: complete pipeline PIPELINE.8.HDA5.OUT id 50
[ 139.798353] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30130000: GLB_TPLG_MSG: PIPE_COMPLETE
[ 139.798464] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30130000: GLB_TPLG_MSG: PIPE_COMPLETE
[ 139.798467] sof-audio-pci 0000:00:1f.3: tplg: complete pipeline PIPELINE.7.HDA4.OUT id 42
[ 139.798471] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30130000: GLB_TPLG_MSG: PIPE_COMPLETE
[ 139.798575] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30130000: GLB_TPLG_MSG: PIPE_COMPLETE
[ 139.798578] sof-audio-pci 0000:00:1f.3: tplg: complete pipeline PIPELINE.4.HDA3.IN id 30
[ 139.798582] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30130000: GLB_TPLG_MSG: PIPE_COMPLETE
[ 139.798683] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30130000: GLB_TPLG_MSG: PIPE_COMPLETE
[ 139.798686] sof-audio-pci 0000:00:1f.3: tplg: complete pipeline PIPELINE.3.HDA2.OUT id 22
[ 139.798690] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30130000: GLB_TPLG_MSG: PIPE_COMPLETE
[ 139.798838] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30130000: GLB_TPLG_MSG: PIPE_COMPLETE
[ 139.798843] sof-audio-pci 0000:00:1f.3: tplg: complete pipeline PIPELINE.2.HDA1.IN id 14
[ 139.798848] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30130000: GLB_TPLG_MSG: PIPE_COMPLETE
[ 139.798979] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30130000: GLB_TPLG_MSG: PIPE_COMPLETE
[ 139.798985] sof-audio-pci 0000:00:1f.3: tplg: complete pipeline PIPELINE.1.HDA0.OUT id 6
[ 139.798989] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30130000: GLB_TPLG_MSG: PIPE_COMPLETE
[ 139.799079] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x30130000: GLB_TPLG_MSG: PIPE_COMPLETE
[ 139.799089] sof-audio-pci 0000:00:1f.3: ipc tx: 0x50010000: GLB_COMP_MSG: SET_VALUE
[ 139.799282] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x50010000: GLB_COMP_MSG: SET_VALUE
[ 139.799292] sof-audio-pci 0000:00:1f.3: ipc tx: 0x50010000: GLB_COMP_MSG: SET_VALUE
[ 139.799494] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x50010000: GLB_COMP_MSG: SET_VALUE
[ 139.799504] sof-audio-pci 0000:00:1f.3: ipc tx: 0x50010000: GLB_COMP_MSG: SET_VALUE
[ 139.799703] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x50010000: GLB_COMP_MSG: SET_VALUE
[ 139.799714] sof-audio-pci 0000:00:1f.3: ipc tx: 0x50010000: GLB_COMP_MSG: SET_VALUE
[ 139.799954] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x50010000: GLB_COMP_MSG: SET_VALUE
[ 139.799965] sof-audio-pci 0000:00:1f.3: ipc tx: 0x50010000: GLB_COMP_MSG: SET_VALUE
[ 139.800159] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x50010000: GLB_COMP_MSG: SET_VALUE
[ 139.800169] sof-audio-pci 0000:00:1f.3: ipc tx: 0x50010000: GLB_COMP_MSG: SET_VALUE
[ 139.800364] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x50010000: GLB_COMP_MSG: SET_VALUE
[ 139.800374] sof-audio-pci 0000:00:1f.3: ipc tx: 0x50010000: GLB_COMP_MSG: SET_VALUE
[ 139.800569] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x50010000: GLB_COMP_MSG: SET_VALUE
[ 139.800579] sof-audio-pci 0000:00:1f.3: ipc tx: 0x50010000: GLB_COMP_MSG: SET_VALUE
[ 139.800835] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x50010000: GLB_COMP_MSG: SET_VALUE
[ 139.800847] sof-audio-pci 0000:00:1f.3: ipc tx: 0x50010000: GLB_COMP_MSG: SET_VALUE
[ 139.801078] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x50010000: GLB_COMP_MSG: SET_VALUE
[ 139.801088] sof-audio-pci 0000:00:1f.3: ipc tx: 0x40020000: GLB_PM_MSG: CTX_RESTORE
[ 139.801176] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x40020000: GLB_PM_MSG: CTX_RESTORE
[ 139.801269] HDMI HDA Codec ehdaudio0D2: hdac_hdmi_present_sense: disconnect for pin:port 5:0
[ 139.801307] HDMI HDA Codec ehdaudio0D2: hdac_hdmi_present_sense: disconnect for pin:port 6:0
[ 139.801320] HDMI HDA Codec ehdaudio0D2: hdac_hdmi_present_sense: disconnect for pin:port 7:0
[ 141.070111] ata1.00: configured for UDMA/100
[ 145.849005] OOM killer enabled.
[ 145.849007] Restarting tasks ... done.
[ 145.923103] PM: suspend exit
s3_test_5_dmesg.log s3_test_6_dmesg.log s3_test_6_logger_error.log
Error still occurred after merge https://github.com/thesofproject/linux/pull/977
Environment Kernel: 9453da1 https://github.com/lyakh/linux/tree/ipc-timeout (with PR895) +PR977 FW:b527fd7 https://github.com/lyakh/sof/tree/ipc-timeout (with PR1354) Topology:Same as above FW repo, file: tools/topology/sof-hda-generic.m4, sof-hda-generic-2ch.tplg kconfig: unset CONFIG_SND_SOC_SOF_DEBUG_ENABLE_FIRMWARE_TRACE unset CONFIG_SND_SOC_SOF_DEBUG_ENABLE_DEBUGFS_CACHE
CORE LEVEL COMP_ID TIMESTAMP DELTA FILE_NAME CONTENT
0 1 DMA 13106377.135417 13106377.000000 intel/cavs/hda-dma.c:639 hda-dmac: 5 invalid channel -1
[ 111.942839] PM: suspend entry (s2idle)
[ 111.942842] PM: Syncing filesystems ... done.
[ 111.945863] Freezing user space processes ...
[ 115.089982] Freezing of tasks aborted after 3.144 seconds (1 tasks refusing to freeze, wq_busy=0):
[ 115.089995] OOM killer enabled.
[ 115.089997] Restarting tasks ... done.
[ 115.125056] PM: suspend exit
[ 115.857025] sof-audio-pci 0000:00:1f.3: hda: prepare stream dir 0
[ 115.857056] sof-audio-pci 0000:00:1f.3: ipc tx: 0x80010000: GLB_DAI_MSG: CONFIG
[ 116.160124] sof-audio-pci 0000:00:1f.3: error: ipc timed out for 0x80010000 size 120
[ 116.160145] sof-audio-pci 0000:00:1f.3: unknown ROM status value 00000021
[ 116.160453] sof-audio-pci 0000:00:1f.3: error: unexpected fault 0x00000080 trace 0x00000080
[ 116.160468] sof-audio-pci 0000:00:1f.3: error: host status 0x80000000 dsp status 0x00000000 mask 0x00000003
[ 116.160476] sof-audio-pci 0000:00:1f.3: error: failed to set dai config for Analog Playback and Capture
[ 116.160482] sof-audio-pci 0000:00:1f.3: ASoC: cpu DAI prepare error: -110
[ 116.160488] Analog Playback and Capture: ASoC: backend prepare failed -110
[ 116.160952] sof-audio-pci 0000:00:1f.3: pcm: free stream 0 dir 0
[ 116.160962] sof-audio-pci 0000:00:1f.3: ipc tx: 0x60030000: GLB_STREAM_MSG: PCM_FREE
[ 116.464129] sof-audio-pci 0000:00:1f.3: error: ipc timed out for 0x60030000 size 12
[ 116.464149] sof-audio-pci 0000:00:1f.3: unknown ROM status value 0000001c
[ 116.464457] sof-audio-pci 0000:00:1f.3: error: unexpected fault 0x00000081 trace 0x00000081
[ 116.464472] sof-audio-pci 0000:00:1f.3: error: host status 0x80000000 dsp status 0x00000000 mask 0x00000003
[ 116.464520] sof-audio-pci 0000:00:1f.3: ipc tx: 0x80010000: GLB_DAI_MSG: CONFIG
[ 116.768134] sof-audio-pci 0000:00:1f.3: error: ipc timed out for 0x80010000 size 120
[ 116.768154] sof-audio-pci 0000:00:1f.3: unknown ROM status value 0000001c
[ 116.768483] sof-audio-pci 0000:00:1f.3: error: unexpected fault 0x00000081 trace 0x00000081
[ 116.768498] sof-audio-pci 0000:00:1f.3: error: host status 0x80000000 dsp status 0x00000000 mask 0x00000003
[ 116.768505] sof-audio-pci 0000:00:1f.3: error: failed to set dai config for Analog Playback and Capture
[ 116.768711] sof-audio-pci 0000:00:1f.3: pcm: close stream 0 dir 0
occurred again during S3 with playback stress test in 8th.
@ranj063 @kv2019i @lyakh I see this in every test from @ClarexZhou
[ 116.160468] sof-audio-pci 0000:00:1f.3: error: host status 0x80000000 dsp status 0x00000000 mask 0x00000003
Even when TRACE is OFF.
But the it looks like IPC dump is invalid for CAVS 1.8
void hda_ipc_dump(struct snd_sof_dev *sdev)
{
u32 hipcie;
u32 hipct;
u32 hipcctl;
/* read IPC status */
hipcie = snd_sof_dsp_read(sdev, HDA_DSP_BAR, HDA_DSP_REG_HIPCIE);
hipct = snd_sof_dsp_read(sdev, HDA_DSP_BAR, HDA_DSP_REG_HIPCT);
hipcctl = snd_sof_dsp_read(sdev, HDA_DSP_BAR, HDA_DSP_REG_HIPCCTL);
/* dump the IPC regs */
/* TODO: parse the raw msg */
dev_err(sdev->dev,
"error: host status 0x%8.8x dsp status 0x%8.8x mask 0x%8.8x\n",
hipcie, hipct, hipcctl);
}
Since the registers are different between APL and CML. The dump code above is for APL.
@lgirdwood We have different for cavs1.8 in cnl.c
@ranj063's Kernel PR https://github.com/thesofproject/linux/pull/977 fixed this issue for me.
@xiulipan ok great, thanks for checking. It is probably worth a comment in the generically named version to state it's for 1.5 only.
@lgirdwood Yes, the hda.c is actually a very misleading file name. We need some comments inline to identify what these files actually for.
@xiulipan agreed, we do have differences in IP between version 1.5, 1.8 and 2.x so having some comments to describe which version that file/function is for would avoid any confusion going onwards. Can you create a feature request for this ?
@lgirdwood @plbossart Done with https://github.com/thesofproject/linux/issues/987 We need some explanation about what is the mapping.
not reproducible after the thesofproject/linux#1013 et al.
Describe the bug sudo reboot to do system reboot, ipc timed out for 0x80010000: GLB_DAI_MSG: CONFIG after system boot up.
To Reproduce sudo reboot to do system reboot
Expected behavior Bootup without any issues.
Impact IPC timed out.
Environment platform: CML laptop with ALC3204 codec Rander UCM https://github.com/RanderWang/intel-UCM Kernel repo:9494607 https://github.com/thesofproject/linux/tree/release/sof-v5.0 Firmware repo: b73b9a6 https://github.com/thesofproject/sof/commits/master +PR1354 Topology: https://github.com/thesofproject/sof/commits/master . Same as above SOF repo file: tools/topology/sof-hda-generic.m4, sof-hda-generic-2ch.tplg
Error sof-logger:
Dmesg:
ipcTimedoutBootUp_dmesg.log ipcTimedOut_Logger.log