Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Firmware crash when attempting playback on UP^2 #7

Closed
lgirdwood opened this issue Jun 22, 2018 · 18 comments
Closed

Firmware crash when attempting playback on UP^2 #7

lgirdwood opened this issue Jun 22, 2018 · 18 comments
Assignees
Labels
APL Applies to Apollolake platform CNL Applies to Cannonlake platform
Milestone

Comments

@lgirdwood
Copy link
Member

Audio playback seems to be broken on my up squared due to the this
commit: 7c281d3.

I get "unable to install hw_params" error when I start aplay.

Please find attached the dmesg log below.

[ 30.124183] sof-audio sof-audio: pfn i 15 idx 37 pfn 17dc7f
[ 30.124203] sof-audio sof-audio: period_bytes:0x3f00
[ 30.124210] sof-audio sof-audio: stream_tag 1
[ 30.432301] sof-audio sof-audio: error: ipc timed out for 0x60010000
size 0x60
[ 30.432755] sof-audio sof-audio: status: fw entered - code 00000005
[ 30.433101] sof-audio sof-audio: error: runtime exception
[ 30.433386] sof-audio sof-audio: error: trace point 00004000
[ 30.433684] sof-audio sof-audio: error: DSP Firmware Oops
[ 30.433970] sof-audio sof-audio: error: Exception Cause:
LoadStorePIFDataErrorCause, Synchronous PIF data error during LoadStore
access
[ 30.434600] sof-audio sof-audio: EXCCAUSE 0x0000000d EXCVADDR
0x00000040 PS 0x00070025 SAR 0x00000010
[ 30.435123] sof-audio sof-audio: EPC1 0xbe01afc0
EPC2 0xbe01afbd EPC3 0xbe010b5e EPC4 0x00000000
[ 30.435645] sof-audio sof-audio: EPC5 0xbe01afbd
EPC6 0x00000000 EPC7 0x00000000 DEPC 0x00000000
[ 30.436168] sof-audio sof-audio: EPS2 0x00060120
EPS3 0x00060520 EPS4 0x00000000 EPS5 0x00060120
[ 30.436691] sof-audio sof-audio: EPS6 0x00000000
EPS7 0x00000000 INTENABL 0x000101d8 INTERRU 0x00000222
[ 30.437214] sof-audio sof-audio: stack dump from 0xbe07ff40
[ 30.437509] sof-audio sof-audio: 0xbe07ff40: 0xbe01afc0 0x00000000
0x00000010 0x00000000
[ 30.437951] sof-audio sof-audio: 0xbe07ff44: 0xbe044024 0x00000000
0x00000008 0x00000000
[ 30.438372] sof-audio sof-audio: 0xbe07ff48: 0x0000000d 0x00000000
0xbe020ae9 0xbe020aef
[ 30.438794] sof-audio sof-audio: 0xbe07ff4c: 0xbe010b5b 0x00000000
0xbe046aa4 0x00000000
[ 30.439216] sof-audio sof-audio: 0xbe07ff50: 0x00000001 0x00000000
0x00000002 0x00000000
[ 30.439638] sof-audio sof-audio: 0xbe07ff54: 0x7e0104c6 0x00000000
0x00004000 0x00000000
[ 30.440059] sof-audio sof-audio: 0xbe07ff58: 0x00000008 0x00000000
0xbe041d64 0xbe051800
[ 30.440482] sof-audio sof-audio: 0xbe07ff5c: 0x00000000 0x00000000
0x01000000 0x00000000
[ 30.440903] sof-audio sof-audio: error: waking up any trace sleepers
[ 30.441289] sof-audio sof-audio: error: got wrong posn offset
0xffffffff for PCM -110
[ 30.441714] sof-audio sof-audio: ASoC: sof-audio hw params failed:
-110
[ 30.442367] sof-audio sof-audio: pcm: free stream 0 dir 0
[ 30.752315] sof-audio sof-audio: error: ipc timed out for 0x60030000
size 0xc
[ 30.752752] sof-audio sof-audio: status: fw entered - code 00000005
[ 30.753098] sof-audio sof-audio: error: runtime exception
[ 30.753384] sof-audio sof-audio: error: trace point 00004000
[ 30.753683] sof-audio sof-audio: error: DSP Firmware Oops
[ 30.753968] sof-audio sof-audio: error: Exception Cause:
LoadStorePIFDataErrorCause, Synchronous PIF data error during LoadStore
access
[ 30.754617] sof-audio sof-audio: EXCCAUSE 0x0000000d EXCVADDR
0x00000040 PS 0x00070025 SAR 0x00000010
[ 30.755141] sof-audio sof-audio: EPC1 0xbe01afc0
EPC2 0xbe01afbd EPC3 0xbe010b5e EPC4 0x00000000
[ 30.755664] sof-audio sof-audio: EPC5 0xbe01afbd
EPC6 0x00000000 EPC7 0x00000000 DEPC 0x00000000
[ 30.756187] sof-audio sof-audio: EPS2 0x00060120
EPS3 0x00060520 EPS4 0x00000000 EPS5 0x00060120
[ 30.756711] sof-audio sof-audio: EPS6 0x00000000
EPS7 0x00000000 INTENABL 0x000101d8 INTERRU 0x00000222
[ 30.757234] sof-audio sof-audio: stack dump from 0xbe07ff40
[ 30.757529] sof-audio sof-audio: 0xbe07ff40: 0xbe01afc0 0x00000000
0x00000010 0x00000000
[ 30.757951] sof-audio sof-audio: 0xbe07ff44: 0xbe044024 0x00000000
0x00000008 0x00000000
[ 30.758373] sof-audio sof-audio: 0xbe07ff48: 0x0000000d 0x00000000
0xbe020ae9 0xbe020aef
[ 30.758795] sof-audio sof-audio: 0xbe07ff4c: 0xbe010b5b 0x00000000
0xbe046aa4 0x00000000
[ 30.759217] sof-audio sof-audio: 0xbe07ff50: 0x00000001 0x00000000
0x00000002 0x00000000
[ 30.759639] sof-audio sof-audio: 0xbe07ff54: 0x7e0104c6 0x00000000
0x00004000 0x00000000
[ 30.760061] sof-audio sof-audio: 0xbe07ff58: 0x00000008 0x00000000
0xbe041d64 0xbe051800
[ 30.760484] sof-audio sof-audio: 0xbe07ff5c: 0x00000000 0x00000000
0x01000000 0x00000000
[ 30.760906] sof-audio sof-audio: error: waking up any trace sleepers
[ 30.761550] sof-audio sof-audio: pcm: close stream 0 dir 0

@lgirdwood lgirdwood added bug Something isn't working as expected APL Applies to Apollolake platform labels Jun 22, 2018
@lgirdwood lgirdwood added this to the 1.2 milestone Jun 22, 2018
@lgirdwood
Copy link
Member Author

Bisected to commit 14ca1fa

@keqiaozhang
Copy link
Collaborator

This regression also happens on CNL-RVP.

@xiulipan
Copy link
Contributor

Got different dmesg message
[ 58.942186] sof-audio sof-audio: ipc: 0x60010000 succeeded
[ 58.944289] sof-audio sof-audio: pcm: trigger stream 0 dir 0 cmd 1
[ 58.944309] sof-audio sof-audio: ipc: send 0x60040000
[ 58.944477] sof-audio sof-audio: ipc: 0x60040000 succeeded
[ 58.947580] sof-audio sof-audio: posn mailbox: posn offset is 0xc1000
[ 58.947584] sof-audio sof-audio: posn XRUN: host 180 comp 4 size -192
[ 58.947586] sof-audio sof-audio: ipc rx: 0x60090000 done
[ 59.556828] sof-audio sof-audio: PCM: stream 0 dir 0 DMA position 0 DAI position 0
[ 60.064495] sof-audio sof-audio: pcm: trigger stream 0 dir 0 cmd 0
[ 60.064522] sof-audio sof-audio: ipc: send 0x60050000
[ 60.384298] sof-audio sof-audio: error: ipc timed out for 0x60050000 size 0xc
[ 60.384317] sof-audio sof-audio: status: fw entered - code 00000005
[ 60.384342] sof-audio sof-audio: error: runtime exception
[ 60.384348] sof-audio sof-audio: error: trace point 00004000
[ 60.384355] sof-audio sof-audio: error: DSP Firmware Oops
[ 60.384361] sof-audio sof-audio: error: Exception Cause: LoadStorePIFDataErrorCause, Synchronous PIF data error during LoadStore access
[ 60.384369] sof-audio sof-audio: EXCCAUSE 0x0000000d EXCVADDR 0x00000040 PS 0x00070025 SAR 0x00000010
[ 60.384377] sof-audio sof-audio: EPC1 0xbe01b1ac EPC2 0xbe01b1a9 EPC3 0xbe010b56 EPC4 0x00000000
[ 60.384384] sof-audio sof-audio: EPC5 0xbe01b1a9 EPC6 0x00000000 EPC7 0x00000000 DEPC 0x00000000
[ 60.384392] sof-audio sof-audio: EPS2 0x00060120 EPS3 0x00060520 EPS4 0x00000000 EPS5 0x00060120
[ 60.384399] sof-audio sof-audio: EPS6 0x00000000 EPS7 0x00000000 INTENABL 0x000101d8 INTERRU 0x00000222
[ 60.384405] sof-audio sof-audio: stack dump from 0xbe07ff40
[ 60.384413] sof-audio sof-audio: 0xbe07ff40: 0xbe01b1ac 0x00000000 0x00000010 0x00000000
[ 60.384421] sof-audio sof-audio: 0xbe07ff44: 0xbe044024 0x00000000 0x00000008 0x00000000
[ 60.384428] sof-audio sof-audio: 0xbe07ff48: 0x0000000d 0x00000000 0xbe020db9 0xbe020dbf
[ 60.384435] sof-audio sof-audio: 0xbe07ff4c: 0xbe010b53 0x00000000 0xbe046aa4 0x00000000
[ 60.384443] sof-audio sof-audio: 0xbe07ff50: 0x00000001 0x00000000 0xbe046928 0x00000000
[ 60.384467] sof-audio sof-audio: 0xbe07ff54: 0x7e0104c6 0x00000000 0x00004000 0x00000000
[ 60.384470] sof-audio sof-audio: 0xbe07ff58: 0x00000008 0x00000000 0x00000005 0xbe041d64
[ 60.384473] sof-audio sof-audio: 0xbe07ff5c: 0x00000000 0x00000000 0x01000000 0x00000000
[ 60.384475] sof-audio sof-audio: error: waking up any trace sleepers
[ 60.384487] Passthrough: ASoC: trigger FE failed -110
[ 60.384511] sof-audio sof-audio: pcm: free stream 0 dir 0
[ 60.384526] sof-audio sof-audio: ipc: send 0x60030000

@xiulipan
Copy link
Contributor

The rmbox log is here:
0x0 [53.891054] delta [53.891054] dai xru
0x10 [53.891885] delta [0.000831] dai xru
0x20 [53.891895] delta [0.000011] pipe pxr
0x30 [53.889751] delta [********] value 0x17707574
0x40 [53.890408] delta [0.000657] value 0x17707574
0x50 [53.891054] delta [0.000646] dai xru
0x60 [53.891056] delta [0.000002] comp Xun
0x70 [53.891058] delta [0.000002] value 0x0000000000040000
0x80 [53.891059] delta [0.000001] value 0x00000000000000c0
0x90 [53.891066] delta [0.000007] pipe tsk
0xa0 [53.891885] delta [0.000819] dai xru
0xb0 [53.891886] delta [0.000002] comp Xun
0xc0 [53.891887] delta [0.000001] value 0x0000000000040000
0xd0 [53.891889] delta [0.000001] value 0x00000000000000c0
0xe0 [53.891895] delta [0.000006] pipe pxr
0xf0 [53.891897] delta [0.000001] pipe cmd
0x100 [53.891898] delta [0.000002] host trg
0x110 [53.891901] delta [0.000002] host DDi
0x120 [53.891903] delta [0.000002] volume trg
0x130 [53.891905] delta [0.000002] dai trg
0x140 [53.892884] delta [0.000979] ssp tri
0x150 [53.892887] delta [0.000003] ssp Ss1
0x160 [53.892888] delta [0.000002] ssp Ss2
0x170 [53.892899] delta [0.000010] dma LSo
0x180 [53.892912] delta [0.000013] pipe pre
0x190 [53.892914] delta [0.000002] host pre
0x1a0 [53.892916] delta [0.000002] volume pre
0x1b0 [53.892918] delta [0.000003] dai pre
0x1c0 [53.892938] delta [0.000020] pipe cmd
0x1d0 [53.892940] delta [0.000002] host trg
0x1e0 [53.892942] delta [0.000002] host DEn
0x1f0 [53.892945] delta [0.000003] volume trg
0x200 [53.892947] delta [0.000002] dai trg
0x210 [53.892950] delta [0.000004] ssp tri
0x220 [53.892952] delta [0.000002] ssp sta
0x230 [53.892956] delta [0.000003] pipe tsk

@xiulipan
Copy link
Contributor

After adding some debug trace patch the panic disappear.
It seems we have some potential memory issues.
I remember we have such a regression mouths later and disappear with some new add patches. Need to root cause it now.

@lgirdwood lgirdwood added regression CNL Applies to Cannonlake platform and removed bug Something isn't working as expected labels Jun 22, 2018
@xiulipan
Copy link
Contributor

xiulipan commented Jun 22, 2018

in etrace (sudo rmbox) and dma trace (sudo rmbox -t)
value 0x17707574
shows only with the patch 14ca1fa

But this patch did not add any trace_value in the commit.
After revert this patch this strange trace value also disappear.
There is definitely some error with this patch.
Hope this info can have some help.

Thanks

@lgirdwood
Copy link
Member Author

ranj063 can you try on your UP^2 and confirm.

@xiulipan
Copy link
Contributor

confirmed work on my UP2
but still see unknown
trace value 0x17707574

0xaf80 [86.264330] delta [0.001000] value 0x17707574
0xaf90 [86.265330] delta [0.001000] value 0x17707574
0xafa0 [86.266330] delta [0.001000] value 0x17707574
0xafb0 [86.267330] delta [0.001000] value 0x17707574

@tlauda
Copy link
Contributor

tlauda commented Jun 23, 2018

0x17 means it is pm_runtime trace message. You just don't have it defined in rmbox.

@ranj063
Copy link
Collaborator

ranj063 commented Jun 24, 2018

It doesnt work quite as expected
Audio plays only for about 10 seconds and then I get "underrun!!!" with aplay. Here's the dmesg log:
[ 47.096639] sof-audio sof-audio: PCM: stream 0 dir 0 DMA position 10560 DAI position 1653024
[ 47.180437] sof-audio sof-audio: posn mailbox: posn offset is 0xc104c
[ 47.180446] sof-audio sof-audio: posn : host 0xe400 dai 0x656280 wall 0x13cd394c
[ 47.180461] sof-audio sof-audio: PCM: stream 0 dir 0 DMA position 14592 DAI position 1661088
[ 47.180486] sof-audio sof-audio: ipc rx: 0x600a0000 done
[ 47.180969] sof-audio sof-audio: PCM: stream 0 dir 0 DMA position 14592 DAI position 1661088
[ 47.215346] sof-audio sof-audio: pstream 0 status 0x24
[ 47.264436] sof-audio sof-audio: posn mailbox: posn offset is 0xc104c
[ 47.264446] sof-audio sof-audio: posn : host 0x2400 dai 0x65e080 wall 0x13e5d54d
[ 47.264461] sof-audio sof-audio: PCM: stream 0 dir 0 DMA position 2304 DAI position 1669152
[ 47.264485] sof-audio sof-audio: ipc rx: 0x600a0000 done
[ 47.264591] sof-audio sof-audio: PCM: stream 0 dir 0 DMA position 2304 DAI position 1669152
[ 47.348435] sof-audio sof-audio: posn mailbox: posn offset is 0xc104c
[ 47.348445] sof-audio sof-audio: posn : host 0x6300 dai 0x665e80 wall 0x13fe714c
[ 47.348459] sof-audio sof-audio: PCM: stream 0 dir 0 DMA position 6336 DAI position 1677216
[ 47.348485] sof-audio sof-audio: ipc rx: 0x600a0000 done
[ 47.348593] sof-audio sof-audio: PCM: stream 0 dir 0 DMA position 6336 DAI position 1677216
[ 47.432432] sof-audio sof-audio: posn mailbox: posn offset is 0xc104c
[ 47.432442] sof-audio sof-audio: posn : host 0xa200 dai 0x66dc80 wall 0x14170d4b
[ 47.432457] sof-audio sof-audio: PCM: stream 0 dir 0 DMA position 10368 DAI position 1685280
[ 47.432481] sof-audio sof-audio: ipc rx: 0x600a0000 done
[ 47.432584] sof-audio sof-audio: PCM: stream 0 dir 0 DMA position 10368 DAI position 1685280
[ 47.507140] sof-audio sof-audio: error: DSP trace buffer overflow 3824 bytes. Total messages 28284
[ 47.517230] sof-audio sof-audio: ipc rx: 0x90020000 done
[ 47.555342] sof-audio sof-audio: pstream 0 status 0x24
[ 47.895376] sof-audio sof-audio: pstream 0 status 0x24
[ 47.895485] sof-audio sof-audio: posn mailbox: posn offset is 0xc104c
[ 47.895492] sof-audio sof-audio: posn : host 0xde00 dai 0x695280 wall 0x1492194c
[ 47.895507] sof-audio sof-audio: PCM: stream 0 dir 0 DMA position 14208 DAI position 1725600
[ 47.895523] sof-audio sof-audio: pcm: trigger stream 0 dir 0 cmd 0
[ 47.895557] sof-audio sof-audio: ipc: send 0x60050000
[ 47.896336] sof-audio sof-audio: ipc: 0x60050000 succeeded
[ 47.896383] sof-audio sof-audio: ipc rx: 0x600a0000 done
[ 47.897580] sof-audio sof-audio: pcm: trigger stream 0 dir 0 cmd 1
[ 47.897619] sof-audio sof-audio: ipc: send 0x60040000
[ 47.897758] sof-audio sof-audio: ipc: 0x60040000 succeeded
[ 47.900639] sof-audio sof-audio: cstream 0 status 0x4
[ 47.900664] sof-audio sof-audio: error : DSP panic!
[ 47.906153] sof-audio sof-audio: panic: dsp_oops_offset 788480 offset 788480
[ 47.906166] sof-audio sof-audio: status: fw entered - code 00000005
[ 47.913252] sof-audio sof-audio: error: runtime exception
[ 47.919292] sof-audio sof-audio: error: trace point 00004000
[ 47.925631] sof-audio sof-audio: error: DSP Firmware Oops
[ 47.931671] sof-audio sof-audio: error: Exception Cause: LoadStorePIFDataErrorCause, Synchronous PIF data error during LoadStore access
[ 47.945284] sof-audio sof-audio: EXCCAUSE 0x0000000d EXCVADDR 0x00000040 PS 0x00070025 SAR 0x00000010
[ 47.956568] sof-audio sof-audio: EPC1 0xbe01b018 EPC2 0xbe01b015 EPC3 0xbe010b5e EPC4 0x00000000
[ 47.967850] sof-audio sof-audio: EPC5 0xbe01b015 EPC6 0x00000000 EPC7 0x00000000 DEPC 0x00000000
[ 47.979121] sof-audio sof-audio: EPS2 0x00060120 EPS3 0x00060520 EPS4 0x00000000 EPS5 0x00060120
[ 47.990402] sof-audio sof-audio: EPS6 0x00000000 EPS7 0x00000000 INTENABL 0x000101d8 INTERRU 0x00000222
[ 48.001681] sof-audio sof-audio: stack dump from 0xbe07ff40
[ 48.007914] sof-audio sof-audio: 0xbe07ff40: 0xbe01b018 0x00000000 0x00000010 0x00000000
[ 48.016961] sof-audio sof-audio: 0xbe07ff44: 0xbe044024 0x00000000 0x00000008 0x00000000
[ 48.026001] sof-audio sof-audio: 0xbe07ff48: 0x0000000d 0x00000000 0xbe020b49 0xbe020b4f
[ 48.035056] sof-audio sof-audio: 0xbe07ff4c: 0xbe010b5b 0x00000000 0xbe046aa4 0x00000000
[ 48.044096] sof-audio sof-audio: 0xbe07ff50: 0x00000001 0x00000000 0x00000002 0x00000000
[ 48.053140] sof-audio sof-audio: 0xbe07ff54: 0x7e0104c6 0x00000000 0x00004000 0x00000000
[ 48.062190] sof-audio sof-audio: 0xbe07ff58: 0x00000008 0x00000000 0x00030082 0xbe051800
[ 48.071246] sof-audio sof-audio: 0xbe07ff5c: 0x00000000 0x00000000 0x01000000 0x00000000
[ 48.080296] sof-audio sof-audio: error: waking up any trace sleepers
[ 48.508274] sof-audio sof-audio: PCM: stream 0 dir 0 DMA position 14208 DAI position 1725600
[ 48.508728] sof-audio sof-audio: PCM: stream 0 dir 0 DMA position 14208 DAI position 1725600
[ 48.508760] sof-audio sof-audio: PCM: stream 0 dir 0 DMA position 14208 DAI position 1725600
[ 48.508783] sof-audio sof-audio: PCM: stream 0 dir 0 DMA position 14208 DAI position 1725600
[ 49.117187] sof-audio sof-audio: PCM: stream 0 dir 0 DMA position 14208 DAI position 1725600
[ 49.625667] sof-audio sof-audio: pcm: trigger stream 0 dir 0 cmd 0
[ 49.625733] sof-audio sof-audio: ipc: send 0x60050000
[ 49.945784] sof-audio sof-audio: error: ipc timed out for 0x60050000 size 0xc
[ 49.953776] sof-audio sof-audio: status: fw entered - code 00000005
[ 49.960797] sof-audio sof-audio: error: runtime exception
[ 49.966830] sof-audio sof-audio: error: trace point 00004000
[ 49.973155] sof-audio sof-audio: error: DSP Firmware Oops
[ 49.979189] sof-audio sof-audio: error: Exception Cause: LoadStorePIFDataErrorCause, Synchronous PIF data error during LoadStore access
[ 49.992798] sof-audio sof-audio: EXCCAUSE 0x0000000d EXCVADDR 0x00000040 PS 0x00070025 SAR 0x00000010
[ 50.004079] sof-audio sof-audio: EPC1 0xbe01b018 EPC2 0xbe01b015 EPC3 0xbe010b5e EPC4 0x00000000
[ 50.015355] sof-audio sof-audio: EPC5 0xbe01b015 EPC6 0x00000000 EPC7 0x00000000 DEPC 0x00000000
[ 50.026633] sof-audio sof-audio: EPS2 0x00060120 EPS3 0x00060520 EPS4 0x00000000 EPS5 0x00060120
[ 50.037909] sof-audio sof-audio: EPS6 0x00000000 EPS7 0x00000000 INTENABL 0x000101d8 INTERRU 0x00000222
[ 50.049186] sof-audio sof-audio: stack dump from 0xbe07ff40
[ 50.055415] sof-audio sof-audio: 0xbe07ff40: 0xbe01b018 0x00000000 0x00000010 0x00000000
[ 50.064464] sof-audio sof-audio: 0xbe07ff44: 0xbe044024 0x00000000 0x00000008 0x00000000
[ 50.073508] sof-audio sof-audio: 0xbe07ff48: 0x0000000d 0x00000000 0xbe020b49 0xbe020b4f
[ 50.082553] sof-audio sof-audio: 0xbe07ff4c: 0xbe010b5b 0x00000000 0xbe046aa4 0x00000000
[ 50.091598] sof-audio sof-audio: 0xbe07ff50: 0x00000001 0x00000000 0x00000002 0x00000000
[ 50.100643] sof-audio sof-audio: 0xbe07ff54: 0x7e0104c6 0x00000000 0x00004000 0x00000000
[ 50.109689] sof-audio sof-audio: 0xbe07ff58: 0x00000008 0x00000000 0x00030082 0xbe051800
[ 50.118734] sof-audio sof-audio: 0xbe07ff5c: 0x00000000 0x00000000 0x01000000 0x00000000
[ 50.127779] sof-audio sof-audio: error: waking up any trace sleepers
[ 50.140803] sof-audio sof-audio: pcm: free stream 0 dir 0
[ 50.458331] sof-audio sof-audio: error: ipc timed out for 0x60030000 size 0xc
[ 50.466324] sof-audio sof-audio: status: fw entered - code 00000005
[ 50.473345] sof-audio sof-audio: error: runtime exception
[ 50.479379] sof-audio sof-audio: error: trace point 00004000
[ 50.485702] sof-audio sof-audio: error: DSP Firmware Oops
[ 50.491735] sof-audio sof-audio: error: Exception Cause: LoadStorePIFDataErrorCause, Synchronous PIF data error during LoadStore access
[ 50.505345] sof-audio sof-audio: EXCCAUSE 0x0000000d EXCVADDR 0x00000040 PS 0x00070025 SAR 0x00000010
[ 50.516625] sof-audio sof-audio: EPC1 0xbe01b018 EPC2 0xbe01b015 EPC3 0xbe010b5e EPC4 0x00000000
[ 50.527905] sof-audio sof-audio: EPC5 0xbe01b015 EPC6 0x00000000 EPC7 0x00000000 DEPC 0x00000000
[ 50.539184] sof-audio sof-audio: EPS2 0x00060120 EPS3 0x00060520 EPS4 0x00000000 EPS5 0x00060120
[ 50.550459] sof-audio sof-audio: EPS6 0x00000000 EPS7 0x00000000 INTENABL 0x000101d8 INTERRU 0x00000222
[ 50.561736] sof-audio sof-audio: stack dump from 0xbe07ff40
[ 50.567965] sof-audio sof-audio: 0xbe07ff40: 0xbe01b018 0x00000000 0x00000010 0x00000000
[ 50.577007] sof-audio sof-audio: 0xbe07ff44: 0xbe044024 0x00000000 0x00000008 0x00000000
[ 50.586047] sof-audio sof-audio: 0xbe07ff48: 0x0000000d 0x00000000 0xbe020b49 0xbe020b4f
[ 50.595087] sof-audio sof-audio: 0xbe07ff4c: 0xbe010b5b 0x00000000 0xbe046aa4 0x00000000
[ 50.604128] sof-audio sof-audio: 0xbe07ff50: 0x00000001 0x00000000 0x00000002 0x00000000
[ 50.613168] sof-audio sof-audio: 0xbe07ff54: 0x7e0104c6 0x00000000 0x00004000 0x00000000
[ 50.622209] sof-audio sof-audio: 0xbe07ff58: 0x00000008 0x00000000 0x00030082 0xbe051800
[ 50.631250] sof-audio sof-audio: 0xbe07ff5c: 0x00000000 0x00000000 0x01000000 0x00000000
[ 50.640292] sof-audio sof-audio: error: waking up any trace sleepers
[ 50.647617] sof-audio sof-audio: pcm: close stream 0 dir 0

@tlauda
Copy link
Contributor

tlauda commented Jun 25, 2018

What is the format you are playing?
Are you sure the issue is still related to the commit 14ca1fa?

@ranj063
Copy link
Collaborator

ranj063 commented Jun 26, 2018

I am playing 16-bit format with a volume pipeline and output format is 24-bit
let me confirm if the issue is due to that commit still

@tlauda
Copy link
Contributor

tlauda commented Jun 26, 2018

@ranj063 Any updates? Still visible on top of the master? From what I'm seeing in the log, it looks like maybe issue #17.

@ranj063
Copy link
Collaborator

ranj063 commented Jun 26, 2018

@tlauda sorry I didnt time to check this yesterday. I will update today.

@ranj063
Copy link
Collaborator

ranj063 commented Jun 27, 2018

@tlauda , I've just tested my UP2 and the problem no longer exists and the playback is clean without distortion as well.

But, I cant play more than a few seconds of audio likely due to #17.

@xiulipan
Copy link
Contributor

@ranj063 Can you check the 0xbe01b018 in you sof-apl.lst
Where the panic happens?

@keqiaozhang
Copy link
Collaborator

I have tested this issue on my UP2 board, this issue is no longer exists with nocodec tplg and codec tplg.
For nocodec topology, the ssp waveform is normal with different input frequency of sine.
For codec topology, the sound is clean without errors, but #17 trace buffer overflow issue is still exists.
Test env:
sof-dev: cb05347d9f85e18b414098d512c8287c297933d2
sof-master:599e1800bab31883cf1f9e845279d079d4950c58
soft-master:
For nocodec tplg: reset to 308cf3d and use test-ssp5-I2S-volume-s16le-s16le-48k-24576k-nocodec.tplg
For codec tplg: f756455 and use test-ssp5-mclk-0-I2S-volume-s16le-s16le-48k-24576k-codec.tplg

@xiulipan
Copy link
Contributor

fixed by #23

RDharageswari pushed a commit to RDharageswari/sof that referenced this issue Jun 6, 2020
This BUG halt was reported a while back, but the patch somehow got
missed:

PID: 2879   TASK: c16adaa0  CPU: 1   COMMAND: "sctpn"
 #0 [f418dd28] crash_kexec at c04a7d8c
 thesofproject#1 [f418dd7c] oops_end at c0863e02
 thesofproject#2 [f418dd90] do_invalid_op at c040aaca
 thesofproject#3 [f418de28] error_code (via invalid_op) at c08631a5
    EAX: f34baac0  EBX: 00000090  ECX: f418deb0  EDX: f5542950  EBP: 00000000
    DS:  007b      ESI: f34ba800  ES:  007b      EDI: f418dea0  GS:  00e0
    CS:  0060      EIP: c046fa5e  ERR: ffffffff  EFLAGS: 00010286
 thesofproject#4 [f418de5c] add_timer at c046fa5e
 thesofproject#5 [f418de68] sctp_do_sm at f8db8c77 [sctp]
 thesofproject#6 [f418df30] sctp_primitive_SHUTDOWN at f8dcc1b5 [sctp]
 thesofproject#7 [f418df48] inet_shutdown at c080baf9
 thesofproject#8 [f418df5c] sys_shutdown at c079eedf
 thesofproject#9 [f418df70] sys_socketcall at c079fe88
    EAX: ffffffda  EBX: 0000000d  ECX: bfceea90  EDX: 0937af98
    DS:  007b      ESI: 0000000c  ES:  007b      EDI: b7150ae4
    SS:  007b      ESP: bfceea7c  EBP: bfceeaa8  GS:  0033
    CS:  0073      EIP: b775c424  ERR: 00000066  EFLAGS: 00000282

It appears that the side effect that starts the shutdown timer was processed
multiple times, which can happen as multiple paths can trigger it.  This of
course leads to the BUG halt in add_timer getting called.

Fix seems pretty straightforward, just check before the timer is added if its
already been started.  If it has mod the timer instead to min(current
expiration, new expiration)

Its been tested but not confirmed to fix the problem, as the issue has only
occured in production environments where test kernels are enjoined from being
installed.  It appears to be a sane fix to me though.  Also, recentely,
Jere found a reproducer posted on list to confirm that this resolves the
issues

Signed-off-by: Neil Horman <nhorman@tuxdriver.com>
CC: Vlad Yasevich <vyasevich@gmail.com>
CC: "David S. Miller" <davem@davemloft.net>
CC: jere.leppanen@nokia.com
CC: marcelo.leitner@gmail.com
CC: netdev@vger.kernel.org
Acked-by: Marcelo Ricardo Leitner <marcelo.leitner@gmail.com>
Signed-off-by: David S. Miller <davem@davemloft.net>
nashif added a commit to nashif/sof that referenced this issue May 7, 2021
rimage: remove ext/rimage and add manifest header
marc-hb added a commit to marc-hb/sof that referenced this issue Feb 27, 2024
As discussed in the alternative approach
zephyrproject-rtos/zephyr#68494, k_panic() in
POSIX mode has various shortcomings that do not provide a useful
trace. Useless pointers to signal handlers or other cleanup routines are
printed instead. Leverage our already existing
k_sys_fatal_error_handler() and dereference a NULL pointer there when in
POSIX mode. This "fails fast" and provides a complete and relevant stack
trace in CI when fuzzing or when using some other static
analyzer. Example of how fuzzing failure thesofproject#8832 would have looked like in
CI results thanks to this commit:

```
./build-fuzz/zephyr/zephyr.exe: Running 1 inputs 1 time(s) each.
Running: ./rballoc_align_fuzz_crash
*** Booting Zephyr OS build zephyr-v3.5.0-3971-ge07de4e0a167 ***
[00:00:00.000,000] <inf> main: SOF on native_posix
[00:00:00.000,000] <inf> main: SOF initialized
@ WEST_TOPDIR/sof/zephyr/lib/alloc.c:391
[00:00:00.000,000] <err> os: >>> ZEPHYR FATAL ERROR 4: Kernel panic
[00:00:00.000,000] <err> os: Current thread: 0x891f8a0 (unknown)
[00:00:00.000,000] <err> zephyr: Halting emulation
AddressSanitizer:DEADLYSIGNAL
=================================================================
==1784402==ERROR: AddressSanitizer: SEGV on unknown address 0x00000000
==1784402==The signal is caused by a WRITE memory access.
==1784402==Hint: address points to the zero page.
    #0 0x829a77d in k_sys_fatal_error_handler zephyr/wrapper.c:352:19
    #1 0x829b8c0 in rballoc_align zephyr/lib/alloc.c:391:3
    thesofproject#2 0x8281438 in buffer_alloc src/audio/buffer.c:58:16
    thesofproject#3 0x826a60a in buffer_new src/ipc/ipc-helper.c:48:11
    thesofproject#4 0x8262107 in ipc_buffer_new src/ipc/ipc3/helper.c:459:11
    thesofproject#5 0x825944d in ipc_glb_tplg_buffer_new src/ipc/ipc3/handler.c:1305:8
    thesofproject#6 0x8257036 in ipc_cmd src/ipc/ipc3/handler.c:1651:9
    thesofproject#7 0x8272e59 in ipc_platform_do_cmd src/platform/posix/ipc.c:162:2
    thesofproject#8 0x826a2ac in ipc_do_cmd src/ipc/ipc-common.c:328:9
    thesofproject#9 0x829b0ab in task_run zephyr/include/rtos/task.h:94:9
    thesofproject#10 0x829abd8 in edf_work_handler zephyr/edf_schedule.c:32:16
    thesofproject#11 0x83560f7 in work_queue_main zephyr/kernel/work.c:688:3
    thesofproject#12 0x82244c2 in z_thread_entry zephyr/lib/os/thread_entry.c:48:2
```

Signed-off-by: Marc Herbert <marc.herbert@intel.com>
marc-hb added a commit to marc-hb/sof that referenced this issue Feb 27, 2024
As discussed in the alternative approach
zephyrproject-rtos/zephyr#68494, k_panic() in
POSIX mode has various shortcomings that do not provide a useful
trace. Useless pointers to signal handlers or other cleanup routines are
printed instead. Leverage our already existing
k_sys_fatal_error_handler() and dereference a NULL pointer there when in
POSIX mode. This "fails fast" and provides a complete and relevant stack
trace in CI when fuzzing or when using some other static
analyzer. Example of how fuzzing failure thesofproject#8832 would have looked like in
CI results thanks to this commit:

```
./build-fuzz/zephyr/zephyr.exe: Running 1 inputs 1 time(s) each.
Running: ./rballoc_align_fuzz_crash
*** Booting Zephyr OS build zephyr-v3.5.0-3971-ge07de4e0a167 ***
[00:00:00.000,000] <inf> main: SOF on native_posix
[00:00:00.000,000] <inf> main: SOF initialized
@ WEST_TOPDIR/sof/zephyr/lib/alloc.c:391
[00:00:00.000,000] <err> os: >>> ZEPHYR FATAL ERROR 4: Kernel panic
[00:00:00.000,000] <err> os: Current thread: 0x891f8a0 (unknown)
[00:00:00.000,000] <err> zephyr: Halting emulation
AddressSanitizer:DEADLYSIGNAL
=================================================================
==1784402==ERROR: AddressSanitizer: SEGV on unknown address 0x00000000
==1784402==The signal is caused by a WRITE memory access.
==1784402==Hint: address points to the zero page.
    #0 0x829a77d in k_sys_fatal_error_handler zephyr/wrapper.c:352:19
    #1 0x829b8c0 in rballoc_align zephyr/lib/alloc.c:391:3
    thesofproject#2 0x8281438 in buffer_alloc src/audio/buffer.c:58:16
    thesofproject#3 0x826a60a in buffer_new src/ipc/ipc-helper.c:48:11
    thesofproject#4 0x8262107 in ipc_buffer_new src/ipc/ipc3/helper.c:459:11
    thesofproject#5 0x825944d in ipc_glb_tplg_buffer_new src/ipc/ipc3/handler.c:1305:8
    thesofproject#6 0x8257036 in ipc_cmd src/ipc/ipc3/handler.c:1651:9
    thesofproject#7 0x8272e59 in ipc_platform_do_cmd src/platform/posix/ipc.c:162:2
    thesofproject#8 0x826a2ac in ipc_do_cmd src/ipc/ipc-common.c:328:9
    thesofproject#9 0x829b0ab in task_run zephyr/include/rtos/task.h:94:9
    thesofproject#10 0x829abd8 in edf_work_handler zephyr/edf_schedule.c:32:16
    thesofproject#11 0x83560f7 in work_queue_main zephyr/kernel/work.c:688:3
    thesofproject#12 0x82244c2 in z_thread_entry zephyr/lib/os/thread_entry.c:48:2
```

Signed-off-by: Marc Herbert <marc.herbert@intel.com>
lgirdwood pushed a commit that referenced this issue Feb 28, 2024
As discussed in the alternative approach
zephyrproject-rtos/zephyr#68494, k_panic() in
POSIX mode has various shortcomings that do not provide a useful
trace. Useless pointers to signal handlers or other cleanup routines are
printed instead. Leverage our already existing
k_sys_fatal_error_handler() and dereference a NULL pointer there when in
POSIX mode. This "fails fast" and provides a complete and relevant stack
trace in CI when fuzzing or when using some other static
analyzer. Example of how fuzzing failure #8832 would have looked like in
CI results thanks to this commit:

```
./build-fuzz/zephyr/zephyr.exe: Running 1 inputs 1 time(s) each.
Running: ./rballoc_align_fuzz_crash
*** Booting Zephyr OS build zephyr-v3.5.0-3971-ge07de4e0a167 ***
[00:00:00.000,000] <inf> main: SOF on native_posix
[00:00:00.000,000] <inf> main: SOF initialized
@ WEST_TOPDIR/sof/zephyr/lib/alloc.c:391
[00:00:00.000,000] <err> os: >>> ZEPHYR FATAL ERROR 4: Kernel panic
[00:00:00.000,000] <err> os: Current thread: 0x891f8a0 (unknown)
[00:00:00.000,000] <err> zephyr: Halting emulation
AddressSanitizer:DEADLYSIGNAL
=================================================================
==1784402==ERROR: AddressSanitizer: SEGV on unknown address 0x00000000
==1784402==The signal is caused by a WRITE memory access.
==1784402==Hint: address points to the zero page.
    #0 0x829a77d in k_sys_fatal_error_handler zephyr/wrapper.c:352:19
    #1 0x829b8c0 in rballoc_align zephyr/lib/alloc.c:391:3
    #2 0x8281438 in buffer_alloc src/audio/buffer.c:58:16
    #3 0x826a60a in buffer_new src/ipc/ipc-helper.c:48:11
    #4 0x8262107 in ipc_buffer_new src/ipc/ipc3/helper.c:459:11
    #5 0x825944d in ipc_glb_tplg_buffer_new src/ipc/ipc3/handler.c:1305:8
    #6 0x8257036 in ipc_cmd src/ipc/ipc3/handler.c:1651:9
    #7 0x8272e59 in ipc_platform_do_cmd src/platform/posix/ipc.c:162:2
    #8 0x826a2ac in ipc_do_cmd src/ipc/ipc-common.c:328:9
    #9 0x829b0ab in task_run zephyr/include/rtos/task.h:94:9
    #10 0x829abd8 in edf_work_handler zephyr/edf_schedule.c:32:16
    #11 0x83560f7 in work_queue_main zephyr/kernel/work.c:688:3
    #12 0x82244c2 in z_thread_entry zephyr/lib/os/thread_entry.c:48:2
```

Signed-off-by: Marc Herbert <marc.herbert@intel.com>
jsarha pushed a commit to jsarha/sof that referenced this issue Oct 16, 2024
The fuzzer engine has produced crash caused by NULL pointer read that
originated from ipc_stream_pcm_free(). The crash happens when the
pipeline of the found comp_dev does not have a source_comp and
pipeline_reset() is called for it. This commit simply adds a test
for such a situation and bails out if it is found.

Here is the call stack from the situation:

    #0 0x81e9317 in dev_comp_pipe_id sof/sof/src/include/sof/audio/component.h:646:25
    thesofproject#1 0x81e8015 in pipeline_comp_reset sof/sof/src/audio/pipeline/pipeline-graph.c:326:22
    thesofproject#2 0x81e7d1d in pipeline_reset sof/sof/src/audio/pipeline/pipeline-graph.c:393:8
    thesofproject#3 0x820d7ea in ipc_stream_pcm_free sof/sof/src/ipc/ipc3/handler.c:398:8
    thesofproject#4 0x8208969 in ipc_cmd sof/sof/src/ipc/ipc3/handler.c:1689:9
    thesofproject#5 0x81cbed8 in ipc_platform_do_cmd sof/sof/src/platform/posix/ipc.c:162:2
    thesofproject#6 0x81d10db in ipc_do_cmd sof/sof/src/ipc/ipc-common.c:330:9
    thesofproject#7 0x81f87e9 in task_run sof/sof/zephyr/include/rtos/task.h:94:9
    thesofproject#8 0x81f8308 in edf_work_handler sof/sof/zephyr/edf_schedule.c:31:16
    thesofproject#9 0x82b4b32 in work_queue_main sof/zephyr/kernel/work.c:668:3
    thesofproject#10 0x8193ec2 in z_thread_entry sof/zephyr/lib/os/thread_entry.c:36:2
    thesofproject#11 0x815f639 in __asan::AsanThread::ThreadStart(unsigned long long) /src/llvm-project/compiler-rt/lib/asan/asan_thread.cpp:277:25

Signed-off-by: Jyri Sarha <jyri.sarha@linux.intel.com>
jsarha pushed a commit to jsarha/sof that referenced this issue Oct 17, 2024
The fuzzer engine has produced crash caused by NULL pointer read that
originated from ipc_stream_pcm_free(). The crash happens when the
pipeline of the found comp_dev does not have a source_comp and
pipeline_reset() is called for it. This commit simply adds a test
for such a situation and bails out if it is found.

Here is the call stack from the situation:

    #0 0x81e9317 in dev_comp_pipe_id sof/sof/src/include/sof/audio/component.h:646:25
    thesofproject#1 0x81e8015 in pipeline_comp_reset sof/sof/src/audio/pipeline/pipeline-graph.c:326:22
    thesofproject#2 0x81e7d1d in pipeline_reset sof/sof/src/audio/pipeline/pipeline-graph.c:393:8
    thesofproject#3 0x820d7ea in ipc_stream_pcm_free sof/sof/src/ipc/ipc3/handler.c:398:8
    thesofproject#4 0x8208969 in ipc_cmd sof/sof/src/ipc/ipc3/handler.c:1689:9
    thesofproject#5 0x81cbed8 in ipc_platform_do_cmd sof/sof/src/platform/posix/ipc.c:162:2
    thesofproject#6 0x81d10db in ipc_do_cmd sof/sof/src/ipc/ipc-common.c:330:9
    thesofproject#7 0x81f87e9 in task_run sof/sof/zephyr/include/rtos/task.h:94:9
    thesofproject#8 0x81f8308 in edf_work_handler sof/sof/zephyr/edf_schedule.c:31:16
    thesofproject#9 0x82b4b32 in work_queue_main sof/zephyr/kernel/work.c:668:3
    thesofproject#10 0x8193ec2 in z_thread_entry sof/zephyr/lib/os/thread_entry.c:36:2
    thesofproject#11 0x815f639 in __asan::AsanThread::ThreadStart(unsigned long long) /src/llvm-project/compiler-rt/lib/asan/asan_thread.cpp:277:25

Signed-off-by: Jyri Sarha <jyri.sarha@linux.intel.com>
jsarha pushed a commit to jsarha/sof that referenced this issue Oct 18, 2024
The fuzzer engine has produced crash caused by NULL pointer read
that originated from ipc3 ipc_stream_pcm_free(). The crash happens
when the pipeline of the found comp_dev does not have a
source_comp and pipeline_reset() is called for it. This commit
adds check to pipeline_comp_test() for this situation and bails
out if it is found.

Here is the call stack from the situation:

    #0 0x81e9317 in dev_comp_pipe_id sof/sof/src/include/sof/audio/component.h:646:25
    thesofproject#1 0x81e8015 in pipeline_comp_reset sof/sof/src/audio/pipeline/pipeline-graph.c:326:22
    thesofproject#2 0x81e7d1d in pipeline_reset sof/sof/src/audio/pipeline/pipeline-graph.c:393:8
    thesofproject#3 0x820d7ea in ipc_stream_pcm_free sof/sof/src/ipc/ipc3/handler.c:398:8
    thesofproject#4 0x8208969 in ipc_cmd sof/sof/src/ipc/ipc3/handler.c:1689:9
    thesofproject#5 0x81cbed8 in ipc_platform_do_cmd sof/sof/src/platform/posix/ipc.c:162:2
    thesofproject#6 0x81d10db in ipc_do_cmd sof/sof/src/ipc/ipc-common.c:330:9
    thesofproject#7 0x81f87e9 in task_run sof/sof/zephyr/include/rtos/task.h:94:9
    thesofproject#8 0x81f8308 in edf_work_handler sof/sof/zephyr/edf_schedule.c:31:16
    thesofproject#9 0x82b4b32 in work_queue_main sof/zephyr/kernel/work.c:668:3
    thesofproject#10 0x8193ec2 in z_thread_entry sof/zephyr/lib/os/thread_entry.c:36:2
    thesofproject#11 0x815f639 in __asan::AsanThread::ThreadStart(unsigned long long) /src/llvm-project/compiler-rt/lib/asan/asan_thread.cpp:277:25

Signed-off-by: Jyri Sarha <jyri.sarha@linux.intel.com>
lgirdwood pushed a commit that referenced this issue Oct 21, 2024
The fuzzer engine has produced crash caused by NULL pointer read
that originated from ipc3 ipc_stream_pcm_free(). The crash happens
when the pipeline of the found comp_dev does not have a
source_comp and pipeline_reset() is called for it. This commit
adds check to pipeline_comp_test() for this situation and bails
out if it is found.

Here is the call stack from the situation:

    #0 0x81e9317 in dev_comp_pipe_id sof/sof/src/include/sof/audio/component.h:646:25
    #1 0x81e8015 in pipeline_comp_reset sof/sof/src/audio/pipeline/pipeline-graph.c:326:22
    #2 0x81e7d1d in pipeline_reset sof/sof/src/audio/pipeline/pipeline-graph.c:393:8
    #3 0x820d7ea in ipc_stream_pcm_free sof/sof/src/ipc/ipc3/handler.c:398:8
    #4 0x8208969 in ipc_cmd sof/sof/src/ipc/ipc3/handler.c:1689:9
    #5 0x81cbed8 in ipc_platform_do_cmd sof/sof/src/platform/posix/ipc.c:162:2
    #6 0x81d10db in ipc_do_cmd sof/sof/src/ipc/ipc-common.c:330:9
    #7 0x81f87e9 in task_run sof/sof/zephyr/include/rtos/task.h:94:9
    #8 0x81f8308 in edf_work_handler sof/sof/zephyr/edf_schedule.c:31:16
    #9 0x82b4b32 in work_queue_main sof/zephyr/kernel/work.c:668:3
    #10 0x8193ec2 in z_thread_entry sof/zephyr/lib/os/thread_entry.c:36:2
    #11 0x815f639 in __asan::AsanThread::ThreadStart(unsigned long long) /src/llvm-project/compiler-rt/lib/asan/asan_thread.cpp:277:25

Signed-off-by: Jyri Sarha <jyri.sarha@linux.intel.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
APL Applies to Apollolake platform CNL Applies to Cannonlake platform
Projects
None yet
Development

No branches or pull requests

7 participants