Repository navigation
[CFL][HDA] "load fw failed ret: -110" after arecord several times. #969
Description
Summary
'IPC timed out for 0x60010000: GLB_STREAM_MSG: PCM_PARAMS' after attempt to arecord around 10 times.
To reproduce
- arecord -Dhw:0,0 -f dat /dev/null
- interrupt capture via 'ctrl + c'
- repeat 1-2 near than 10 times
Actual Result
aplay: set_params:1363: Unable to install hw params:
Playback/Capture cannot be recovered when error occurred until reboot device.
Test Recipe
date: 2019-05-22
sof (master): 3e423f4
linux (topic/sof-dev): e3ec7cf
topology: sof-hda-generic.tplg
dmesg log
[ 101.505674] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 1 : core_mask 1
[ 101.506529] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x80000000 successful
[ 101.506541] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf010e0e successful
[ 101.506551] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x6000021 successful
[ 101.506649] sof-audio-pci 0000:00:1f.3: error: no reply expected, received 0x0
[ 104.507030] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x5000001 timedout
[ 104.507043] sof-audio-pci 0000:00:1f.3: error: load fw failed ret: -110
[ 104.507073] sof-audio-pci 0000:00:1f.3: unknown ROM status value 05000001
[ 104.507081] sof-audio-pci 0000:00:1f.3: error: status = 0x00000000 panic = 0x00000000
[ 104.507088] sof-audio-pci 0000:00:1f.3: unknown ROM status value 05000001
[ 104.507093] sof-audio-pci 0000:00:1f.3: error: failed to reset DSP
[ 104.507097] sof-audio-pci 0000:00:1f.3: error: failed to boot DSP firmware after resume -110
[ 104.507117] sof-audio-pci 0000:00:1f.3: pcm: open stream 0 dir 1
[ 104.507121] sof-audio-pci 0000:00:1f.3: period min 192 max 16384 bytes
[ 104.507124] sof-audio-pci 0000:00:1f.3: period count 2 max 16
[ 104.507126] sof-audio-pci 0000:00:1f.3: buffer max 65536 bytes
[ 104.507517] sof-audio-pci 0000:00:1f.3: format_val=49, rate=48000, ch=2, format=10
[ 104.507530] sof-audio-pci 0000:00:1f.3: pcm: hw params stream 0 dir 1
[ 104.507535] sof-audio-pci 0000:00:1f.3: generating page table for 000000000ab2be2b size 0xffc0 pages 16
[ 104.507571] sof-audio-pci 0000:00:1f.3: period_bytes:0x3fc0
[ 104.507573] sof-audio-pci 0000:00:1f.3: periods:4
[ 104.507598] sof-audio-pci 0000:00:1f.3: stream_tag 1
[ 104.507610] sof-audio-pci 0000:00:1f.3: ipc tx: 0x60010000: GLB_STREAM_MSG: PCM_PARAMS
[ 104.809219] sof-audio-pci 0000:00:1f.3: error: ipc timed out for 0x60010000 size 108
[ 104.809229] sof-audio-pci 0000:00:1f.3: unknown ROM status value 01009701
[ 104.809234] sof-audio-pci 0000:00:1f.3: error: status = 0x001c003c panic = 0x00000001
[ 104.809237] sof-audio-pci 0000:00:1f.3: unknown ROM status value 01009701
[ 104.809244] sof-audio-pci 0000:00:1f.3: error: host status 0x00000000 dsp status 0x00040000 mask 0x00000000
[ 104.809245] sof-audio-pci 0000:00:1f.3: error: hw params ipc failed for stream 1
[ 104.809247] sof-audio-pci 0000:00:1f.3: ASoC: 0000:00:1f.3 hw params failed: -110
[ 104.809250] HDA Analog: ASoC: hw_params FE failed -110
[ 104.809265] sof-audio-pci 0000:00:1f.3: pcm: free stream 0 dir 1
[ 104.809267] sof-audio-pci 0000:00:1f.3: ipc tx: 0x60030000: GLB_STREAM_MSG: PCM_FREE
[ 105.113061] sof-audio-pci 0000:00:1f.3: error: ipc timed out for 0x60030000 size 12
[ 105.113078] sof-audio-pci 0000:00:1f.3: unknown ROM status value 01009701
[ 105.113088] sof-audio-pci 0000:00:1f.3: error: status = 0x001c003c panic = 0x00000001
[ 105.113096] sof-audio-pci 0000:00:1f.3: unknown ROM status value 01009701
[ 105.113106] sof-audio-pci 0000:00:1f.3: error: host status 0x00000000 dsp status 0x00040000 mask 0x00000000
[ 105.113438] sof-audio-pci 0000:00:1f.3: pcm: close stream 0 dir 1
Activity
ClarexZhou commentedon May 22, 2019
Error occurred on CML during aplay -d 1 stress tests, error occurred after 148 times.
Environment
Firmware: 5fa2426 https://github.com/thesofproject/sof/tree/master
Kernel: b58f448 https://github.com/thesofproject/linux/tree/release/sof-v5.0
Topology: file: tools/topology/sof-hda-generic.tplg, sof-hda-generic-2ch.tplg same as firmware
Kconfig: https://sof-ci-storage.sh.intel.com/daily/20190521/release/linux/topic/sof-dev/901cd2a5-2/config-daily-hda-20190521.txt
aplay_timedout_dmesg.log
aplay_timedout_logger.log
keyonjie commentedon May 27, 2019
@ClarexZhou @stevyan can you try if @ranj063's PR #977 help to fix this issue? I ran aplay -d 1 stress test with that applied on my cml, i passed 1000 iterations.
stevyan commentedon May 28, 2019
This error still can be reproduced after 12 times tries based on CFL RVP HDA.
Test Recipe
date: 2019-05-28
sof (master): 63cb86f1
linux (topic/sof-dev): PR#977
topology: sof-hda-generic.tplg
dmesg log
stevyan commentedon May 28, 2019
@keyonjie
aplaycan work without this issue based on daily build or PR#977, butarecordwill be failed.ranj063 commentedon May 28, 2019
Folks, please do not classify all issues as IPC timeouts by looking at the last error message. The problem here is due to a FW load failure that occurred much earlier than the IPC timeout
[-][CFL][HDA] 'IPC timed out for 0x60010000: GLB_STREAM_MSG: PCM_PARAMS' after arecord several times.[/-][+][CFL][HDA] "load fw failed ret: -110" after arecord several times.[/+]ClarexZhou commentedon Jun 3, 2019
Error occurred during S3 without playback stress test.
Error always occurred when do stress test with USB hub Ethernet network.
Error not occurred when do stress test without network.
FW load failed then CTX_save ipc timed out at 95th time. Can't enter S3 anymore and headset type selection query pops up.
Test Recipe
Kernel :98972d https://github.com/lyakh/linux/commits/cnl-rc1
FW: 47dc14d https://github.com/lyakh/sof/tree/ipc-timeout
Topology: Same with FW.
test_95.log
ClarexZhou commentedon Jun 13, 2019
Error occurred during S3 without playback stress test.
FW load failed then CTX_save ipc timed out at 109th time. Can't enter S3 anymore and headset type selection query pops up.
Test Recipe
Kernel sof-dev : 96033e6 +PR1003
FW: 47dc14d https://github.com/lyakh/sof/tree/ipc-timeout
Topology: Same with FW.
dmesg:
ClarexZhou commentedon Jun 13, 2019
@lyakh kernel is using latest https://github.com/thesofproject/linux/commits/topic/sof-dev [Top commit: 96033e6 ] + PR1003
kv2019i commentedon Jun 13, 2019
This looks different from any IPC timeout cases. Here the failure comes from polling the FW, so we are not relying on IRQs at all here. It also looks strange that the FW does send some replies, so it's not completely head:
[ 1673.713732] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x6000021 successful
[ 1673.713864] sof-audio-pci 0000:00:1f.3: error: no reply expected, received 0x0
... so here FW is still alive.
[ 1676.713999] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x6000010 timedout
But then we time out,
130usec3sec and 130usec later (UPDATE). So the ROM is stuck or the DMA programming for FW load has failed (or both).19 remaining items
keyonjie commentedon Jul 15, 2019
This is not easy to be reproduced on my side, I run 300 iterations with FW(master) and driver(topic/sof-dev) today's commits on wasp, but failed to reproduce it.
keyonjie commentedon Jul 15, 2019
But it hints to me that maybe it worth to considering bring Xun's PR back for discussion, #916
keyonjie commentedon Jul 16, 2019
I tried 1000 iterations last overnight but failed to reproduce the issue.
ClarexZhou commentedon Jul 17, 2019
Error occurred at 1006th in S3 without playback test on a CML HD-A notebook.
Dmesg
test_1006.txt
kernel: topic/sof-dev 04b9bfe
sof: cml-hda-dmic-001-drop-stable 6cc8da10
tplg: sof-hda-generic.tplg
ClarexZhou commentedon Jul 17, 2019
@keyonjie error is easier to be reproduced when changing suspend and timed wake time to 1s.
keyonjie commentedon Jul 17, 2019
@ClarexZhou can you please help check if #1089 can help on this?
ClarexZhou commentedon Jul 18, 2019
@keyonjie Error not occurred with #1089 after run 2k interactions s3 without playback stress test on both ICL HD-A RVP and CFL HD-A notebook.
Kernel: topic/sof-dev: 04b9bfe + PR#1089
keyonjie commentedon Jul 18, 2019
@ClarexZhou Thanks for the validation.
ClarexZhou commentedon Jul 23, 2019
Similar issue occurred on ICL-RVP on sof-dev with merged PR#1089. Failed at 198th during S3 without playback test.
Suspend and wakeup time is to 1s-16s as below in test scripts.
Dmesg
test_198.txt
linux (topic/sof-dev) f745362
sof (master)： a513ac7
topology： sof-hda-generic-2ch.tpl
keyonjie commentedon Jul 23, 2019
This "reg=0x2000012 timedout" is a new error type, looks we are still waiting for csme validation. Maybe we can try longer timeout value and do more test with it.
ClarexZhou commentedon Jul 24, 2019
Error not occurred again after run 2535 times same S3 without playback stress test on ICL-RVP on sof-dev with merged PR#1089
linux (topic/sof-dev) f745362
sof (master)： a513ac7
topology： sof-hda-generic-2ch.tplg
ClarexZhou commentedon Jul 24, 2019
Close this issue and track new "reg=0x2000012 timedout" issue in #1094
misc: fastrpc: Add missing lock before accessing find_vma()