Skip to content

"DSP panic" when ALSA XRUN recovery #19

Closed
Closed
"DSP panic" when ALSA XRUN recovery#19
Assignees
tlauda
Labels
bugSomething isn't working as expected
Milestone
1.2

Description

@xiulipan
xiulipan
opened on Jun 26, 2018

When ALSA detect a xrun, a stop/start pattern for the recovery is send to firmware. This pattern is not supported now and will cause the DSP to have some error.

Activity

  1. lgirdwood
    assigned
    xiulipan
    on Jun 26, 2018
  2. lgirdwood
    added
    bugSomething isn't working as expected
    on Jun 26, 2018
  3. lgirdwood
    added this to the 1.2 milestone on Jun 26, 2018
  4. lgirdwood
    changed the title [-]ALSA XRUN recovery not support by firmware[/-] [+]ALSA XRUN recovery not working[/+] on Jun 26, 2018

  5. lgirdwood commented on Jun 26, 2018

    @lgirdwood
    lgirdwood
    on Jun 26, 2018
    Member

    Please detail the trace logs when this happens in both FW and driver.

  6. ghost changed the title [-]ALSA XRUN recovery not working[/-] [+]"DSP panic" when ALSA XRUN recovery[/+] on Jul 12, 2018
  7. keqiaozhang
    assigned
    tlauda
    and
    lbetlej
    and unassigned
    xiulipan
    and
    tlauda
    on Jul 12, 2018
  8. jocelyn-li
    assigned
    tlauda
    and unassigned
    lbetlej
    on Jul 12, 2018

  9. tlauda commented on Jul 12, 2018

    @tlauda
    tlauda
    on Jul 12, 2018
    Contributor

    Please provide dmesg log from driver.

  10. xiulipan commented on Jul 12, 2018

    @xiulipan
    xiulipan
    on Jul 12, 2018
    ContributorAuthor

    @tlauda
    The reproduce steps are easy:

    1. aplay on one PCM eg. PCM 0 on CARD0
    2. inject a alas XRUN or wait for one to happen (may take long time on UP2 and always happen on GP)
      echo 1 > /proc/asound/card0/pcm0p/sub0/xrun_injection
      This may need CONFIG_SND_PCM_XRUN_DEBUG=y in config

  11. tlauda commented on Jul 12, 2018

    @tlauda
    tlauda
    on Jul 12, 2018
    Contributor

    @xiulipan
    Actually one more question. What do you mean by saying that xrun always happens on GP? I didn't hear about such issue.

  12. 8 remaining items

  13. tlauda commented on Jul 13, 2018

    @tlauda
    tlauda
    on Jul 13, 2018
    Contributor

    @zhigang-wu But with xcc we don't have panic. From what we've seen with @xiulipan, hang on xcc is due to the wrong state machine, after trying to stop the ppl during xrun recovery. I'm not sure how big are the default interrupt stacks in xtos and how they are handled with multiple irqs execution at once, but maybe the panic is due to tha stack overflow. Xrun recovery is done on some software interrupt level and the function itself is recursive. In the same time GPDMA and IPC interrupts are triggered. I think that we should have different handling mechanism for the xruns, which doesn't involve endless retriggering.

  15. lgirdwood commented on Jul 14, 2018

    @lgirdwood
    lgirdwood
    on Jul 14, 2018
    Member

    @zhigang-wu if you suspect infinite recursion, then put a limit on the call depth of this function. Does the problem go away or is different ?

  17. lgirdwood commented on Jul 16, 2018

    @lgirdwood
    lgirdwood
    on Jul 16, 2018
    Member

    @zhigang-wu I'm not proposing a solution, I'm asking a question about a potential problem you have raised and you never answered. Is this related to infinite recursion or not ?

  19. plbossart commented on Jul 16, 2018

    @plbossart
    plbossart
    on Jul 16, 2018
    Member

    There is an even easier way to reproduce the issue on Up^2: start one playback, hit Control-z to suspend the app, restart with fg. The timeout and panic errors are not recoverable without removing/reloading kernel modules.

    root@ubilinux4:~# speaker-test -Dhw:0,0 -c2 -r48000 -FS32_LE -t sine

    speaker-test 1.1.3

    Playback device is hw:0,0
    Stream parameters are 48000Hz, S32_LE, 2 channels
    Sine wave rate is 440.0000Hz
    Rate set to 48000Hz (requested 48000Hz)
    Buffer size range from 384 to 8064
    Period size range from 192 to 1920
    Using max buffer size 8064
    Periods = 4
    was set period_size = 1728
    was set buffer_size = 8064
    0 - Front Left
    1 - Front Right
    ^Z
    [1]+ Stopped speaker-test -Dhw:0,0 -c2 -r48000 -FS32_LE -t sine
    root@ubilinux4:# fg
    speaker-test -Dhw:0,0 -c2 -r48000 -FS32_LE -t sine
    Write error: -32,Broken pipe
    Write error: -5,Input/output error
    xrun_recovery failed: -5,Input/output error
    Transfer failed: Input/output error
    root@ubilinux4:    # speaker-test -Dhw:0,0 -c2 -r48000 -FS32_LE -t sine

    speaker-test 1.1.3

    Playback device is hw:0,0
    Stream parameters are 48000Hz, S32_LE, 2 channels
    Sine wave rate is 440.0000Hz
    Rate set to 48000Hz (requested 48000Hz)
    Buffer size range from 384 to 8064
    Period size range from 192 to 1920
    Using max buffer size 8064
    Periods = 4
    Unable to set hw params for playback: Connection timed out
    Setting of hwparams failed: Connection timed out
    root@ubilinux4:~# speaker-test -Dhw:0,0 -c2 -r48000 -FS32_LE -t sine

    speaker-test 1.1.3

    Playback device is hw:0,0
    Stream parameters are 48000Hz, S32_LE, 2 channels
    Sine wave rate is 440.0000Hz
    Rate set to 48000Hz (requested 48000Hz)
    Buffer size range from 384 to 8064
    Period size range from 192 to 1920
    Using max buffer size 8064
    Periods = 4
    Unable to set hw params for playback: Connection timed out
    Setting of hwparams failed: Connection timed out

    root@ubilinux4:# rmbox -t &> log.txt
    root@ubilinux4:    # more log.txt
    using 19.20MHz timestamp clock
    0x0 [0.040034] delta [0.040034] pipe ScI
    0x10 [0.040040] delta [0.000006] pm ini
    0x20 [0.040310] delta [0.000270] sa ini
    0x30 [0.040313] delta [0.000003] value 0x0000000000d97010
    0x40 [0.040321] delta [0.000009] ipc IPI
    0x50 [0.040522] delta [0.000200] dmic pro
    0x60 [0.040529] delta [0.000008] buffer dtn
    0x70 [0.044928] delta [0.004399] ipc Cmd
    0x80 [0.044931] delta [0.000003] ipc Idn
    0x90 [0.044933] delta [0.000002] ipc DA1
    0xa0 [0.044934] delta [0.000002] ipc DAp
    0xb0 [0.044936] delta [0.000002] host Dgt
    0xc0 [0.044985] delta [0.000048] host Dsc
    0xd0 [0.045023] delta [0.000039] host DEn
    0xe0 [0.245659] delta [0.200636] ipc Cmd
    0xf0 [0.245661] delta [0.000002] ipc tcn
    0x100 [0.245664] delta [0.000003] host new
    0x110 [0.245803] delta [0.000138] ipc Cmd
    0x120 [0.245805] delta [0.000002] ipc tcn
    0x130 [0.245807] delta [0.000002] volume new
    0x140 [0.247808] delta [0.002000] ipc Cmd
    0x150 [0.247810] delta [0.000002] ipc Ibn
    0x160 [0.247812] delta [0.000002] buffer new
    0x170 [0.247927] delta [0.000115] ipc Cmd
    0x180 [0.247929] delta [0.000002] ipc Ibn
    0x190 [0.247931] delta [0.000002] buffer new
    0x1a0 [0.249819] delta [0.001888] ipc Cmd
    0x1b0 [0.249821] delta [0.000002] ipc tcn
    0x1c0 [0.249824] delta [0.000003] dai new
    0x1d0 [0.249832] delta [0.000008] dma Dgt
    0x1e0 [0.249933] delta [0.000101] ipc Cmd
    0x1f0 [0.249936] delta [0.000003] ipc Ipn
    0x200 [0.249939] delta [0.000003] pipe new
    0x210 [0.250028] delta [0.000089] ipc Cmd
    0x220 [0.250030] delta [0.000002] ipc Icn
    0x230 [0.250033] delta [0.000002] pipe cnc
    0x240 [0.250090] delta [0.000057] ipc Cmd
    0x250 [0.250092] delta [0.000002] ipc Icn
    0x260 [0.250094] delta [0.000002] pipe cbc
    0x270 [0.250145] delta [0.000051] ipc Cmd
    0x280 [0.250147] delta [0.000002] ipc Icn
    0x290 [0.250149] delta [0.000002] pipe cnc
    0x2a0 [0.250201] delta [0.000052] ipc Cmd
    0x2b0 [0.250204] delta [0.000002] ipc Icn
    0x2c0 [0.250206] delta [0.000002] pipe cbc
    0x2d0 [0.250310] delta [0.000104] ipc Cmd
    0x2e0 [0.250313] delta [0.000003] ipc DsF
    0x2f0 [0.250315] delta [0.000002] ssp cos
    0x300 [0.250317] delta [0.000001] value 0x0000000000004001
    0x310 [0.250319] delta [0.000002] value 0x0000000000004001
    0x320 [0.250322] delta [0.000003] ssp coe
    0x330 [0.250324] delta [0.000002] value 0x00000000c1d00777
    0x340 [0.250325] delta [0.000001] value 0x00000000d0700000
    0x350 [0.250326] delta [0.000001] value 0x0000000000000000
    0x360 [0.250328] delta [0.000001] value 0x000000000a200010
    0x370 [0.250329] delta [0.000001] value 0x0000000000000003
    0x380 [0.250330] delta [0.000001] value 0x0000000000000003
    0x390 [0.250332] delta [0.000001] value 0x0000000000004002
    0x3a0 [0.250333] delta [0.000001] value 0x0000000000000000
    0x3b0 [0.250334] delta [0.000001] value 0x0000000007070000
    0x3c0 [0.250336] delta [0.000001] value 0x0000000000000030
    0x3d0 [0.250396] delta [0.000060] ipc Cmd
    0x3e0 [0.250398] delta [0.000002] ipc Ipc
    0x3f0 [0.250400] delta [0.000002] pipe com
    0x400 [0.250402] delta [0.000001] value 0x0000000000000001
    0x410 [0.413489] delta [0.163087] ipc Cmd
    0x420 [0.413492] delta [0.000003] ipc VoG
    0x430 [0.413494] delta [0.000002] volume cmd
    0x440 [0.413495] delta [0.000002] volume vst
    0x450 [0.413497] delta [0.000001] value 0x0000000000000001
    0x460 [0.413498] delta [0.000002] value 0x0000000000000000
    0x470 [0.413500] delta [0.000001] value 0x0000000000001455
    0x480 [0.413501] delta [0.000002] value 0x0000000000000001
    0x490 [0.413503] delta [0.000001] value 0x0000000000001455
    0x4a0 [0.550402] delta [0.136899] ipc Cmd
    0x4b0 [0.550404] delta [0.000003] ipc VoG
    0x4c0 [0.550406] delta [0.000002] volume cmd
    0x4d0 [0.550408] delta [0.000002] volume vst
    0x4e0 [0.550409] delta [0.000001] value 0x0000000000000001
    0x4f0 [0.550410] delta [0.000001] value 0x0000000000000000
    0x500 [0.550412] delta [0.000001] value 0x0000000000001455
    0x510 [0.550413] delta [0.000002] value 0x0000000000000001
    0x520 [0.550415] delta [0.000001] value 0x0000000000001455
    0x530 [212.401910] delta [211.851495] ipc Cmd
    0x540 [212.401913] delta [0.000003] ipc SAl
    0x550 [212.401915] delta [0.000002] pipe Par
    0x560 [212.401918] delta [0.000003] host par
    0x570 [212.401925] delta [0.000007] host Dgt
    0x580 [212.401927] delta [0.000002] host Dsc
    0x590 [212.401930] delta [0.000003] volume par
    0x5a0 [212.401932] delta [0.000002] dai par
    0x5b0 [212.401938] delta [0.000006] pipe pre
    0x5c0 [212.401940] delta [0.000002] host pre
    0x5d0 [212.401943] delta [0.000003] volume pre
    0x5e0 [212.401946] delta [0.000004] dai pre
    0x5f0 [212.405432] delta [0.003486] ipc Cmd
    0x600 [212.405435] delta [0.000002] ipc tri
    0x610 [212.405437] delta [0.000002] pipe cmd
    0x620 [212.405439] delta [0.000002] host trg
    0x630 [212.405441] delta [0.000002] host DEn
    0x640 [212.405476] delta [0.000035] volume trg
    0x650 [212.405478] delta [0.000002] dai trg
    0x660 [212.405483] delta [0.000005] ssp tri
    0x670 [212.405485] delta [0.000002] ssp sta

  20. tlauda commented on Jul 18, 2018

    @tlauda
    tlauda
    on Jul 18, 2018
    Contributor

    Please verify with 4ba4aa8.

  21. xiulipan commented on Jul 20, 2018

    @xiulipan
    xiulipan
    on Jul 20, 2018
    ContributorAuthor

    @tlauda
    With xcc, both single play/capture did not enter any pipeline recovery. No error then.
    @keqiaozhang
    With gcc, single play seems to be fine please confirm with more stress test.
    single capture will enter pipeline xrun recovery and end in a panic after stress test.
    We may still have some potential risk with GCC and capture pipeline.

  22. xiulipan commented on Jul 20, 2018

    @xiulipan
    xiulipan
    on Jul 20, 2018
    ContributorAuthor

    dmesg:

    [ 216.321335] sof-audio sof-audio: error : DSP panic!
    [ 216.321349] sof-audio sof-audio: panic: dsp_oops_offset 788480 offset 788480
    [ 216.321356] sof-audio sof-audio: status: fw entered - code 00000005
    [ 216.321379] sof-audio sof-audio: error: runtime exception
    [ 216.321384] sof-audio sof-audio: error: trace point 00004000
    [ 216.321389] sof-audio sof-audio: error: DSP Firmware Oops
    [ 216.321395] sof-audio sof-audio: error: Exception Cause: LoadStorePIFDataErrorCause, Synchronous PIF data error during LoadStore access
    [ 216.321402] sof-audio sof-audio: EXCCAUSE 0x0000000d EXCVADDR 0x0957467d PS 0x00070025 SAR 0x00000020
    [ 216.321408] sof-audio sof-audio: EPC1 0xbe01c598 EPC2 0xbe01c58f EPC3 0xbe010c09 EPC4 0x00000000
    [ 216.321414] sof-audio sof-audio: EPC5 0xbe01c58f EPC6 0x00000000 EPC7 0x00000000 DEPC 0x00000000
    [ 216.321419] sof-audio sof-audio: EPS2 0x00060520 EPS3 0x00060520 EPS4 0x00000000 EPS5 0x00060520
    [ 216.321425] sof-audio sof-audio: EPS6 0x00000000 EPS7 0x00000000 INTENABL 0x000101d8 INTERRU 0x00000222
    [ 216.321430] sof-audio sof-audio: stack dump from 0xbe07ff40
    [ 216.321437] sof-audio sof-audio: 0xbe07ff40: 0xbe01c598 0x00000000 0x00000020 0x00000000
    [ 216.321443] sof-audio sof-audio: 0xbe07ff44: 0xbe044024 0x00000000 0x09574645 0x00000000
    [ 216.321449] sof-audio sof-audio: 0xbe07ff48: 0x0000000d 0x00000000 0xbe022bce 0xbe022be4
    [ 216.321455] sof-audio sof-audio: 0xbe07ff4c: 0xf3e6db9f 0x00000000 0xbe044024 0x00000000
    [ 216.321461] sof-audio sof-audio: 0xbe07ff50: 0x00000001 0x00000000 0xbe046928 0x00000000
    [ 216.321467] sof-audio sof-audio: 0xbe07ff54: 0x7e0104c6 0x00000000 0x00004000 0x00000000
    [ 216.321473] sof-audio sof-audio: 0xbe07ff58: 0x09574645 0x00000000 0xedff0080 0xbe041dd4
    [ 216.321479] sof-audio sof-audio: 0xbe07ff5c: 0x00000000 0x00000000 0x01000000 0x00000000
    [ 216.321484] sof-audio sof-audio: error: waking up any trace sleepers
    [ 216.758536] sof-audio sof-audio: pcm: trigger stream 0 dir 1 cmd 0

    rmbox
    0x0 [196.852839] delta [196.852839] dai xro
    0x10 [196.852862] delta [0.000023] pipe pxr
    0x20 [197.709120] delta [0.856257] dai xro
    0x30 [197.709146] delta [0.000026] pipe pxr
    0x40 [201.289393] delta [3.580247] dai xro
    0x50 [201.289415] delta [0.000023] pipe pxr
    0x60 [208.666940] delta [7.377525] dai xro
    0x70 [208.666966] delta [0.000026] pipe pxr
    0x80 [212.617633] delta [3.950667] dai xro
    0x90 [212.617659] delta [0.000026] pipe pxr
    0xa0 [213.123601] delta [0.505942] dai xro
    0xb0 [213.123623] delta [0.000022] pipe pxr

    It seems we still get into dai xrun in capture start/stop pattern and need pipeline recovery,

  23. xiulipan commented on Jul 20, 2018

    @xiulipan
    xiulipan
    on Jul 20, 2018
    ContributorAuthor

    Test with DMIC capture and SSP playback on APL with DMIC test topology

    Still get panic when inject XRUN into capture

    [ 900.643956] sof-audio sof-audio: ipc: send 0x60040000
    [ 900.644122] sof-audio sof-audio: ipc: 0x60040000 succeeded
    [ 900.644134] sof-audio sof-audio: PCM: stream 6 dir 1 DMA position 384 DAI position 939840
    [ 900.645657] sof-audio sof-audio: error : DSP panic!
    [ 900.645663] sof-audio sof-audio: panic: dsp_oops_offset 788480 offset 788480
    [ 900.645667] sof-audio sof-audio: status: fw entered - code 00000005
    [ 900.645686] sof-audio sof-audio: error: runtime exception
    [ 900.645688] sof-audio sof-audio: error: trace point 00004000
    [ 900.645691] sof-audio sof-audio: error: DSP Firmware Oops
    [ 900.645694] sof-audio sof-audio: error: Exception Cause: LoadStorePIFDataErrorCause, Synchronous PIF data error during LoadStore access
    [ 900.645697] sof-audio sof-audio: EXCCAUSE 0x0000000d EXCVADDR 0x00000040 PS 0x00070025 SAR 0x00000010
    [ 900.645700] sof-audio sof-audio: EPC1 0xbe01c460 EPC2 0xbe01c45d EPC3 0xbe01d613 EPC4 0x00000000
    [ 900.645702] sof-audio sof-audio: EPC5 0xbe01d613 EPC6 0x00000000 EPC7 0x00000000 DEPC 0x00000000
    [ 900.645705] sof-audio sof-audio: EPS2 0x00060120 EPS3 0x00060d22 EPS4 0x00000000 EPS5 0x00060d22
    [ 900.645708] sof-audio sof-audio: EPS6 0x00000000 EPS7 0x00000000 INTENABL 0x000101d8 INTERRU 0x00000222
    [ 900.645710] sof-audio sof-audio: stack dump from 0xbe07ff40
    [ 900.645713] sof-audio sof-audio: 0xbe07ff40: 0xbe01c460 0x00000000 0x00000010 0x00000000
    [ 900.645716] sof-audio sof-audio: 0xbe07ff44: 0xbe044024 0x00000000 0x00000008 0x00000000
    [ 900.645718] sof-audio sof-audio: 0xbe07ff48: 0x0000000d 0x00000000 0xbe022079 0xbe02207f
    [ 900.645721] sof-audio sof-audio: 0xbe07ff4c: 0xbe010bf3 0x00000000 0xbe046aa4 0x00000000
    [ 900.645724] sof-audio sof-audio: 0xbe07ff50: 0x00000001 0x00000000 0xbe046928 0x00000000
    [ 900.645727] sof-audio sof-audio: 0xbe07ff54: 0x7e0104c6 0x00000000 0x00004000 0x00000000
    [ 900.645729] sof-audio sof-audio: 0xbe07ff58: 0x00000008 0x00000000 0xedff0080 0xbe041dd4
    [ 900.645732] sof-audio sof-audio: 0xbe07ff5c: 0x00000000 0x00000000 0x01000000 0x00000000
    [ 900.645735] sof-audio sof-audio: error: waking up any trace sleepers
    [ 901.168912] sof-audio sof-audio: pcm: trigger stream 6 dir 1 cmd 0

    0x3c0 [887.325593] delta [3.172558] dai xro
    0x3d0 [887.325609] delta [0.000016] pipe pxr
    0x3e0 [890.766056] delta [3.440447] dai xro
    0x3f0 [890.766071] delta [0.000015] pipe pxr
    0x400 [891.471485] delta [0.705413] dai xro
    0x410 [891.471500] delta [0.000016] pipe pxr
    0x420 [892.325566] delta [0.854066] dai xro
    0x430 [892.325582] delta [0.000016] pipe pxr
    0x440 [897.324683] delta [4.999101] dai xro
    0x450 [897.324699] delta [0.000016] pipe pxr
    0x460 [897.324865] delta [0.000166] pipe pxr
    0x470 [897.324870] delta [0.000005] comp CEs
    0x480 [897.324871] delta [0.000001] value 0x0000000000000003
    0x490 [897.324873] delta [0.000002] pipe eOp
    0x4a0 [897.324874] delta [0.000001] ipc pc0
    0x4b0 [897.324875] delta [0.000001] value 0x000000000000004a
    0x4c0 [897.324876] delta [0.000001] value 0x0000000000000008
    0x4d0 [897.324878] delta [0.000001] pipe px0
    0x4e0 [897.325014] delta [0.000136] volume xro
    0x4f0 [897.325023] delta [0.000009] pipe ePU
    0x500 [897.325024] delta [0.000001] value 0x0000000000000004
    0x510 [897.325026] delta [0.000001] pipe pxr

    It seems this bug is non related to ssp driver.
    We can focus on scheduler.

  24. xiulipan commented on Jul 20, 2018

    @xiulipan
    xiulipan
    on Jul 20, 2018
    ContributorAuthor

    PR fixes for this bug is #124 #125

  25. tlauda commented on Jul 24, 2018

    @tlauda
    tlauda
    on Jul 24, 2018
    Contributor

    @xiulipan
    Capture xrun should be fixed on top of c65d733.

  26. keqiaozhang commented on Jul 27, 2018

    @keqiaozhang
    keqiaozhang
    on Jul 27, 2018
    Collaborator

    Confirmed that this issue is fixed in sof-master.

  27. keqiaozhang
    closed this as completedon Jul 27, 2018
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

Labels

bugSomething isn't working as expected

Type

No type

Projects

No projects

    Milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions