Skip to content

[stress-test]: Simultaneous playback and capture will fail at stress test. #743

Closed
Closed
[stress-test]: Simultaneous playback and capture will fail at stress test.#743
Assignees
abonislawski
Labels
APLApplies to Apollolake platformGLKApplies to Gemini Lake platformP1Blocker bugs or important featuresbugSomething isn't working as expected

Description

@keyonjie
keyonjie
opened on Dec 18, 2018

Environment:
APL or GLK
Linux: topic/sof-dev
SOF: master
topology: with any topology file has 2 playback and 1 capture PCMs.

How to reproduce:

  1. get the stress test scripts from qa: add simultaneous playback/capture stress test scripts #742;
  2. run ./stress_test.sh
  3. we will find kinds of issues randomly, and see IPC timeout in driver dmesg.

Activity

  1. keyonjie
    assigned
    abonislawski
    on Dec 18, 2018

  2. keyonjie commented on Dec 18, 2018

    @keyonjie
    keyonjie
    on Dec 18, 2018
    ContributorAuthor

    add a panic dmesg and lst file.

    dsp_panic_at_2400s.txt
    sof-apl.lst.txt

  3. keyonjie commented on Dec 18, 2018

    @keyonjie
    keyonjie
    on Dec 18, 2018
    ContributorAuthor

    add more logs for fail cases.

    dsp_hang.log.txt
    pipe_copy_stop.txt
    sa_panic.log.txt

  4. keyonjie
    added
    APLApplies to Apollolake platform
    GLKApplies to Gemini Lake platform
    P2Critical bugs or normal features
    on Dec 18, 2018

  5. abonislawski commented on Dec 18, 2018

    @abonislawski
    abonislawski
    on Dec 18, 2018
    Member

    3. we will find kinds of issues randomly, and see IPC timeout in driver dmesg.

    Immediately or after X iterations in your case? I see no problem after 400+

  6. wenqingfu commented on Dec 18, 2018

    @wenqingfu
    wenqingfu
    on Dec 18, 2018

    link with #345

  7. wenqingfu commented on Dec 18, 2018

    @wenqingfu
    wenqingfu
    on Dec 18, 2018

    anchor to thesofproject/linux#266

  8. keyonjie commented on Dec 19, 2018

    @keyonjie
    keyonjie
    on Dec 19, 2018
    ContributorAuthor
    1. we will find kinds of issues randomly, and see IPC timeout in driver dmesg.

    Immediately or after X iterations in your case? I see no problem after 400+

    Randomly, usually it happens < 300 on my side.

  9. lgirdwood commented on Dec 19, 2018

    @lgirdwood
    lgirdwood
    on Dec 19, 2018
    Member

    @keyonjie @abonislawski

    [ 2418.681877] sof-audio sof-audio: ipc tx: 0x60050000: GLB_STREAM_MSG: TRIG_STOP
[ 2418.682348] sof-audio sof-audio: ipc: firmware response, msg:0x60050000, msg_ext:0x0
[ 2418.682450] sof-audio sof-audio: ipc tx succeeded: 0x60050000: GLB_STREAM_MSG: TRIG_STOP
[ 2418.682510] sof-audio sof-audio: pcm: free stream 1 dir 1
[ 2418.682540] sof-audio sof-audio: ipc tx: 0x60030000: GLB_STREAM_MSG: PCM_FREE
[ 2418.682636] sof-audio sof-audio: ipc: firmware initiated, msg:0xdead00a, msg_ext:0x40800
[ 2418.682644] sof-audio sof-audio: error : DSP panic!
[ 2418.682658] sof-audio sof-audio: panic: dsp_oops_offset 788480 offset 788480
[ 2418.682665] sof-audio sof-audio: status: fw entered - code 00000005
[ 2418.682810] sof-audio sof-audio: error: invalid wait state
[ 2418.682816] sof-audio sof-audio: error: trace point 00004000
[ 2418.682823] sof-audio sof-audio: error: panic happen at /home/keyon/hdd/github/keyonjie/soun:1853190003
[ 2418.682829] sof-audio sof-audio: error: DSP Firmware Oops
[ 2418.682836] sof-audio sof-audio: error: Exception Cause: Level1InterruptCause, Level-1 interrupt as indicated by set level-1 bits in the INTERRUPT register
[ 2418.682844] sof-audio sof-audio: EXCCAUSE 0x00000004 EXCVADDR 0x00000000 PS       0x00060122 SAR     0x00000000
[ 2418.682852] sof-audio sof-audio: EPC1     0xbe012630 EPC2     0xbe012625 EPC3     0xbe01a8c6 EPC4    0x00000000
[ 2418.682859] sof-audio sof-audio: EPC5     0xbe02a444 EPC6     0x00000000 EPC7     0x00000000 DEPC    0x00000000
[ 2418.682866] sof-audio sof-audio: EPS2     0x00060720 EPS3     0x00060022 EPS4     0x00000000 EPS5    0x00050023
[ 2418.682873] sof-audio sof-audio: EPS6     0x00000000 EPS7     0x00000000 INTENABL 0x00010198 INTERRU 0x0000023a
[ 2418.682879] sof-audio sof-audio: stack dump from 0xbe07ef10
[ 2418.682887] sof-audio sof-audio: 0xbe07ef10: 0x00000000 0x0000000a 0x6d6f682f 0x656b2f65
[ 2418.682895] sof-audio sof-audio: 0xbe07ef14: 0x2f6e6f79 0x2f646468 0x68746967 0x6b2f6275
[ 2418.682902] sof-audio sof-audio: 0xbe07ef18: 0x6e6f7965 0x2f65696a 0x6e756f73 0x706f2d64
[ 2418.682910] sof-audio sof-audio: 0xbe07ef1c: 0x662d6e65 0x776d7269 0x2f657261 0x2f637273
[ 2418.682917] sof-audio sof-audio: 0xbe07ef20: 0x68637261 0x6574782f 0x2f61736e 0x6c636e69
[ 2418.682924] sof-audio sof-audio: 0xbe07ef24: 0x2f656475 0x68637261 0x6961772f 0x00682e74
[ 2418.682932] sof-audio sof-audio: 0xbe07ef28: 0xbe01209b 0xbe07efa0 0xbe04c250 0x00000001
[ 2418.682940] sof-audio sof-audio: 0xbe07ef2c: 0x08020006 0x00003200 0x00004180 0x00000080
[ 2418.682948] sof-audio sof-audio: error: waking up any trace sleepers

    Which means we are attempting to wait when IRQ level > 0. i.e. some code running in IRQ
    context is attempting to sleep.

  10. lgirdwood
    changed the title [-][stress-test]: Simultaneous playback and capture will cause IPC timed out[/-] [+][stress-test]: Simultaneous playback and capture will cause FW to wait in IRQ context [/+] on Dec 19, 2018
  11. lgirdwood
    added
    P1Blocker bugs or important features
    and removed
    P2Critical bugs or normal features
    on Dec 19, 2018

  12. keyonjie commented on Dec 20, 2018

    @keyonjie
    keyonjie
    on Dec 20, 2018
    ContributorAuthor

    @keyonjie @abonislawski
    Which means we are attempting to wait when IRQ level > 0. i.e. some code running in IRQ
    context is attempting to sleep.

    Yes, what really confuse me is that we have actually only one wait_for_interrupt() calling(in audio.c: the while(1) main loop) after grepping the whole code.

  13. lgirdwood commented on Dec 20, 2018

    @lgirdwood
    lgirdwood
    on Dec 20, 2018
    Member

    @keyonjie grep the dissasembly for "waiti". Also check the stack trace using the dump tool

    grep -rn waiti src/arch/xtensa/sof-apl.lst 
1123:		asm volatile("waiti 0");
1124:be01098e:	007000               	waiti	0
2876:	asm volatile("waiti 0");
2877:be011430:	007000               	waiti	0
2903:	asm volatile("waiti 0");
2904:be01144a:	007000               	waiti	0
11892:be014c73:	007500               	waiti	5

    Looks like extra waits in slave core, are you running in SMP or UP mode ? and are we sure these functions / waits not being called on master core ?

  14. keyonjie commented on Dec 21, 2018

    @keyonjie
    keyonjie
    on Dec 21, 2018
    ContributorAuthor

    yes, I believe SMP is not compiled out cleanly yet, after change the build arch from xtensa-smp to xtensa, this issue is fixed on my side, it can pass 1000 iterations(before that it can never pass 250 iterations).

  15. lgirdwood commented on Dec 21, 2018

    @lgirdwood
    lgirdwood
    on Dec 21, 2018
    Member

    @keyonjie the non master cores should be idle (given the testing topology). @akloniex what happened to your PR that added more data/regs to the crash dump. This should also include core ID too.

  16. keyonjie commented on Dec 28, 2018

    @keyonjie
    keyonjie
    on Dec 28, 2018
    ContributorAuthor

    just catched another kind of issue with UP today:

    Sync_PIF_error_dmesg.txt
    Sync_PIF_error_etrace.txt

  17. mengdonglin
    added
    bugSomething isn't working as expected
    on Dec 29, 2018

  18. lgirdwood commented on Dec 30, 2018

    @lgirdwood
    lgirdwood
    on Dec 30, 2018
    Member

    just catched another kind of issue with UP today:

    @keyonjie if it's another issue then it should be an new issue OR is it a different error caused by the same test ?

    Sync_PIF_error_dmesg.txt
    Sync_PIF_error_etrace.txt

    Please copy and paste the crash excerpts from the logs, also please run the coredump logger and paste here to.

  19. keyonjie commented on Jan 4, 2019

    @keyonjie
    keyonjie
    on Jan 4, 2019
    ContributorAuthor

    @lgirdwood it is different error caused by the same test.

    we tried coredump logger, but it doesn't work, do you have readme about how to use it?

  20. wenqingfu commented on Jan 9, 2019

    @wenqingfu
    wenqingfu
    on Jan 9, 2019

    just catched another kind of issue with UP today:

    the error log below looks like #800. If people agree this is a new issue compared with the SMP vs UP in early posts, we should open a new bug for "another kind of issue with UP" and the conversation there.

    Sync_PIF_error_dmesg.txt
    Sync_PIF_error_etrace.txt

  21. lgirdwood commented on Jan 9, 2019

    @lgirdwood
    lgirdwood
    on Jan 9, 2019
    Member

    @keyonjie did you open a new issue as @wenqingfu suggested ? Your error

    17019.132465] sof-audio sof-audio: ipc tx: 0x60010000: GLB_STREAM_MSG: PCM_PARAMS
[17019.132596] sof-audio sof-audio: error : DSP panic!
[17019.132603] sof-audio sof-audio: panic: dsp_oops_offset 788480 offset 788480
[17019.132607] sof-audio sof-audio: status: fw entered - code 00000005
[17019.132747] sof-audio sof-audio: error: runtime exception
[17019.132749] sof-audio sof-audio: error: trace point 00004000
[17019.132752] sof-audio sof-audio: error: panic happen at :0
[17019.132754] sof-audio sof-audio: error: DSP Firmware Oops
[17019.132757] sof-audio sof-audio: error: Exception Cause: LoadStorePIFDataErrorCause, Synchronous PIF data error during LoadStore access
[17019.132760] sof-audio sof-audio: EXCCAUSE 0x0000000d EXCVADDR 0x00002340 PS       0x00060025 SAR     0x0000001d
[17019.132763] sof-audio sof-audio: EPC1     0xbe025e51 EPC2     0xbe01193d EPC3     0xbe013458 EPC4    0x00000000
[17019.132766] sof-audio sof-audio: EPC5     0xbe01193d EPC6     0x00000000 EPC7     0x00000000 DEPC    0x00000000
[17019.132768] sof-audio sof-audio: EPS2     0x00060720 EPS3     0x00060722 EPS4     0x00000000 EPS5    0x00060720
[17019.132771] sof-audio sof-audio: EPS6     0x00000000 EPS7     0x00000000 INTENABL 0x000101d0 INTERRU 0x00000222
[17019.132774] sof-audio sof-audio: stack dump from 0xbe07fc80
[17019.132776] sof-audio sof-audio: 0xbe07fc80: 0xbe025e51 0x00060535 0x0000001d 0x2000c190
[17019.132779] sof-audio sof-audio: 0xbe07fc84: 0xbe0434e8 0xffffffed 0x9e060978 0xbe04350c
[17019.132782] sof-audio sof-audio: 0xbe07fc88: 0x0000000d 0x00000000 0xbe028d55 0xbe028d5b
[17019.132785] sof-audio sof-audio: 0xbe07fc8c: 0x00000005 0xffffffed 0x0000004c 0x2000822c
[17019.132788] sof-audio sof-audio: 0xbe07fc90: 0xbe02138a 0xbe07fd20 0xbe069400 0xbe069500
[17019.132791] sof-audio sof-audio: 0xbe07fc94: 0x00ffffff 0x0f2d4952 0x0000004c 0x20007ecc
[17019.132794] sof-audio sof-audio: 0xbe07fc98: 0x00011003 0x0f2d4904 0x0000004c 0x20008aa0
[17019.132796] sof-audio sof-audio: 0xbe07fc9c: 0xbe021a2b 0xbe07fd40 0xbe07fd60 0xbe069400
[17019.132799] sof-audio sof-audio: error: waking up any trace sleepers

    Is a deref at 0x2340 is near the HDA DMA phy address and I've seen this value before.

  22. keyonjie
    changed the title [-][stress-test]: Simultaneous playback and capture will cause FW to wait in IRQ context [/-] [+][stress-test]: Simultaneous playback and capture will fail at stress test.[/+] on Jan 11, 2019

  23. keyonjie commented on Jan 11, 2019

    @keyonjie
    keyonjie
    on Jan 11, 2019
    ContributorAuthor

    @lgirdwood @wenqingfu I created this issue aim to trace all issues found by this simultaneous playback/capture scripts, we can create sub-issues for every different error logs and different root cause, but I prefer to keep this one(just rename the title of it).

  24. lgirdwood commented on Jan 11, 2019

    @lgirdwood
    lgirdwood
    on Jan 11, 2019
    Member

    @keyonjie please just use one issue for this error, it may show different outcomes but the use case is always the same. Please mark other issues as duplicates and close them or mark this as duplicate and close. Having multiple issues makes this really hard to follow for the same use case error.

  25. wenqingfu commented on Jan 11, 2019

    @wenqingfu
    wenqingfu
    on Jan 11, 2019

    but I prefer to keep this one(just rename the title of it).

    No, there is no personal preference here. We ask "one report, one issue". Please follow. You can use title renaming trick to better summarize the issue as time goes, but it need to be the same issue. When the topic changes, a new one is required.

    When more than one issues make up a super issue, you can optionally use Github task lists to point them to sub-issues.

    Never mixed conversation together, it won't give your the "one stop to go" convenience you expect. Thanks!

  26. wenqingfu commented on Jan 11, 2019

    @wenqingfu
    wenqingfu
    on Jan 11, 2019

    Close this bug as a dup of #766 (SMP vs UP). new issue after this post moves to #800

  27. wenqingfu
    closed this as completedon Jan 11, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

Labels

APLApplies to Apollolake platformGLKApplies to Gemini Lake platformP1Blocker bugs or important featuresbugSomething isn't working as expected

Type

No type

Projects

No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions