Skip to content

[EHL][APL][JSL] suspend-resume with playback/capture test failure with 'rtcwake return value error' #2433

New issue
New issue
Closed
Closed
[EHL][APL][JSL] suspend-resume with playback/capture test failure with 'rtcwake return value error'#2433
Labels
APLApplies to ApolloLake platformCI blockerIssues can can block CI test, maybe 3rd partyCMLApplies to Comet Lake platformEHLApplies to Elkhart LakeJSLJasper Lake platform issuesP2Critical bugs or normal featuresbugSomething isn't workingsuspend resumeIssues related to suspend resume (e.g. rtcwake)won't fixThis will not be worked on atm (e.g. a bug closed for lack of user request, hardware etc)

Description

@mengdonglin
mengdonglin
opened on Sep 15, 2020

This error was reported by CI in daily test on 2020-09-13. Suspend and resume test with playback/capture failed within 25 iterations. dmesg shows "rtcwake return value error". But before these 2 failed test cases, CI runs check-suspend-resume-50.sh (w/o playback or capture, 50 iterations) successfully, the error cannot be reproduced in that case.

2 failed cases:
check-suspend-resume-with-playback-25.sh
check-suspend-resume-with-capture-25.sh

Test recipe:
Start Time: 2020-09-13 21:26:28 UTC
End Time: 2020-09-14 01:08:25 UTC
Kernel Branch: topic/sof-dev
Kernel Commit: 02293e7
SOF Branch: master
SOF Commit:46e49cc3

OS: Ubuntu 20.04
Platform: EHL RVP w/ codec in I2S mode

Dmesg when error happens:

...
2020-09-13 23:59:58 UTC Sub-Test: [REMOTE_COMMAND] sleep for 5
2020-09-14 00:00:03 UTC Sub-Test: [REMOTE_INFO] Check for the kernel log status
2020-09-14 00:00:03 UTC Sub-Test: [REMOTE_INFO] ===== Round(14/15) =====
2020-09-14 00:00:03 UTC Sub-Test: [REMOTE_COMMAND] Run the command: rtcwake -m mem -s 5
rtcwake: wakeup from "mem" using /dev/rtc0 at Mon Sep 14 00:00:09 2020
2020-09-14 00:00:11 UTC Sub-Test: [REMOTE_COMMAND] sleep for 5
2020-09-14 00:00:16 UTC Sub-Test: [REMOTE_INFO] Check for the kernel log status
2020-09-14 00:00:16 UTC Sub-Test: [REMOTE_INFO] ===== Round(15/15) =====
2020-09-14 00:00:16 UTC Sub-Test: [REMOTE_COMMAND] Run the command: rtcwake -m mem -s 5
rtcwake: wakeup from "mem" using /dev/rtc0 at Mon Sep 14 00:00:22 2020
rtcwake: write error
2020-09-14 00:00:22 UTC Sub-Test: [REMOTE_ERROR] rtcwake return value error
2020-09-14 00:00:22 UTC Sub-Test: [REMOTE_ERROR] Starting func_exit_handler(), exit status=1, FUNCNAME stack:
2020-09-14 00:00:22 UTC Sub-Test: [REMOTE_ERROR]  die()  @  /home/ubuntu/sof-test/test-case/../case-lib/lib.sh
2020-09-14 00:00:22 UTC Sub-Test: [REMOTE_ERROR]  main()  @  /home/ubuntu/sof-test/test-case/check-suspend-resume.sh:80
2020-09-14 00:00:22 UTC Sub-Test: [REMOTE_INFO] Test Result: FAIL!
2020-09-14 00:00:22 UTC [REMOTE_ERROR] suspend resume failed
2020-09-14 00:00:22 UTC [REMOTE_ERROR] Starting func_exit_handler(), exit status=1, FUNCNAME stack:
2020-09-14 00:00:22 UTC [REMOTE_ERROR]  main()  @  /home/ubuntu/sof-test/test-case/check-suspend-resume-with-audio.sh
2020-09-14 00:00:24 UTC [REMOTE_WARNING] Process(es) started by /home/ubuntu/sof-test/test-case/check-suspend-resume-with-audio.sh are still active, kill these process(es):
2020-09-14 00:00:24 UTC [REMOTE_WARNING] Catch pid: 86606 aplay -Dhw:0,6 -r 48000 -c 2 -f S16_LE /dev/zero -q
2020-09-14 00:00:24 UTC [REMOTE_WARNING] Kill cmd:'aplay -Dhw:0,6 -r 48000 -c 2 -f S16_LE /dev/zero -q' by kill -9
2020-09-14 00:00:24 UTC [REMOTE_INFO] Test Result: FAIL!

Activity

  1. mengdonglin
    added
    bugSomething isn't working
    EHLApplies to Elkhart Lake
    P2Critical bugs or normal features
    I2S
    on Sep 15, 2020
  2. mengdonglin
    assigned
    libinyang
    on Sep 15, 2020
  3. mengdonglin
    added
    APLApplies to ApolloLake platform
    on Sep 15, 2020

  4. mengdonglin commented on Sep 15, 2020

    @mengdonglin
    mengdonglin
    on Sep 15, 2020
    Author

    @marc-hb The same failure can also be reproduced on APL_UP2_NOCODEC in CI daily test on 2020-09-11.

    Recipe:
    Start Time: 2020-09-11 21:25:38 UTC
    End Time: 2020-09-12 01:11:18 UTC
    Kernel Branch: topic/sof-dev
    Kernel Commit: 02293e7
    SOF Branch: master
    SOF Commit:64a1657b

  5. mengdonglin
    changed the title [-][EHL] suspend-resume with playback/capture test failure with 'rtcwake return value error'[/-] [+][EHL][APL] suspend-resume with playback/capture test failure with 'rtcwake return value error'[/+] on Sep 15, 2020

  6. libinyang commented on Sep 15, 2020

    @libinyang
    libinyang
    on Sep 15, 2020

    I have found such issue for weeks, which randomly happens in such test cases: check-suspend-resume-50.sh, check-suspend-resume-with-playback-25.sh, check-suspend-resume-with-capture-25.sh. And the root cause seems to be the same:
    “rtcwake return value error”

    And the case check-suspend-resume-50.sh only runs suspend/resume, without any audio operations. So I suppose this is a none sof related issue. I manually test such cases with run-all-tests.sh on both EHL RVP and CRB several times, and I can’t reproduce this issue.

  7. keqiaozhang
    changed the title [-][EHL][APL] suspend-resume with playback/capture test failure with 'rtcwake return value error'[/-] [+][EHL][APL][JSL] suspend-resume with playback/capture test failure with 'rtcwake return value error'[/+] on Sep 22, 2020
  8. mengdonglin
    added
    JSLJasper Lake platform issues
    CMLApplies to Comet Lake platform
    suspend resumeIssues related to suspend resume (e.g. rtcwake)
    on Sep 24, 2020

  9. mengdonglin commented on Sep 24, 2020

    @mengdonglin
    mengdonglin
    on Sep 24, 2020
    Author

    Same error also happens on CML Notebook with HD-A codec in stress test check-suspend-resume-500.sh

  10. mengdonglin
    added
    CI blockerIssues can can block CI test, maybe 3rd party
    on Sep 24, 2020

  11. 5 remaining items

  12. mengdonglin commented on Oct 10, 2020

    @mengdonglin
    mengdonglin
    on Oct 10, 2020
    Author

    This issue can no longer be reproduced in daily test since 09/14, report ID 402. Seems to be fixed by upstream.

    Start Time: 2020-09-14 21:28:11 UTC
    End Time: 2020-09-15 01:10:00 UTC
    Kernel Branch: topic/sof-dev
    Kernel Commit: 02293e7
    SOF Branch: master
    SOF Commit: 63fe935

  13. libinyang commented on Oct 12, 2020

    @libinyang
    libinyang
    on Oct 12, 2020

    Still find the issue of "rtcwake: write error" on 10-12 daily test on EHL.
    And I found this issue can only be found on sh-ehl-rvp-i2s-01. sh-ehl-rvp-i2s-09 never meets such issue.

  14. marc-hb commented on Oct 12, 2020

    @marc-hb
    marc-hb
    on Oct 12, 2020
    Collaborator

    And I found this issue can only be found on sh-ehl-rvp-i2s-01. sh-ehl-rvp-i2s-09 never meets such issue.

    At the risk of stating the obvious: can you please compare the hardware and firmware configurations of both?

  15. marc-hb
    reopened this on Oct 12, 2020
  16. fredoh9
    removed
    won't fixThis will not be worked on atm (e.g. a bug closed for lack of user request, hardware etc)
    on Oct 12, 2020
  17. mengdonglin
    added
    won't fixThis will not be worked on atm (e.g. a bug closed for lack of user request, hardware etc)
    on Oct 19, 2020

  18. marc-hb commented on Oct 20, 2020

    @marc-hb
    marc-hb
    on Oct 20, 2020
    Collaborator

    No error message in https://sof-ci.01.org/linuxpr/PR2308/build4717/devicetest/ but the test timed out while waiting for on jf-apl-up2-nocodec-2 to wake up after aplay -Dhw:0,5 -r 48000 -c 2 -f S16_LE /dev/zero -q. Previous -Dhw,0,x worked fine.

  19. marc-hb
    added a commit that references this issue on Oct 20, 2020

    check-suspend-resume-with-audio: don't discard stderr

    f61ddd8
  20. xiulipan
    added a commit that references this issue on Oct 21, 2020

    check-suspend-resume-with-audio: don't discard stderr

    c2ed492

  21. libinyang commented on Oct 22, 2020

    @libinyang
    libinyang
    on Oct 22, 2020

    At the risk of stating the obvious: can you please compare the hardware and firmware configurations of both?

    They are different board, 09 is CRB, 01 is RVP.

  22. marc-hb commented on Oct 22, 2020

    @marc-hb
    marc-hb
    on Oct 22, 2020
    Collaborator

    Another rtcwake: write error error in check-suspend-resume-5.sh at https://sof-ci.01.org/linuxpr/PR2508/build4748/devicetest/ on sh-icl-rvp-hda-06 but that's only AFTER some previous suspend/resume failure in a previous test.

  23. plbossart commented on Nov 16, 2020

    @plbossart
    plbossart
    on Nov 16, 2020
    Member

    we saw this error today in two reports of daily tests #755

    I will start a hypothesis that when we see an 'rtcwake: write error', then we can also see in dmesg an error message with
    "Freezing of tasks aborted after 4+ seconds (1 tasks refusing to freeze, wq_busy=0): "

    All the tests I've looked at confirm this hypothesis, can folks double-check this?

    kernel: [ 9088.559221] sof-audio-pci 0000:00:1f.3: ipc rx done: 0x90020000: GLB_TRACE_MSG
kernel: [ 9092.055851] 
kernel: [ 9092.055866] Freezing of tasks aborted after 4.435 seconds (1 tasks refusing to freeze, wq_busy=0):
kernel: [ 9092.055935] 
kernel: [ 9092.055941] OOM killer enabled.
kernel: [ 9092.055947] Restarting tasks ... done.
kernel: [ 9092.060873] sof-audio-pci 0000:00:1f.3: hda: prepare stream dir 0
kernel: [ 9092.060913] sof-audio-pci 0000:00:1f.3: ipc tx: 0x80010000: GLB_DAI_MSG: CONFIG
kernel: [ 9092.061557] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x80010000: GLB_DAI_MSG: CONFIG
kernel: [ 9092.061588] sof-audio-pci 0000:00:1f.3: format_val=49, rate=48000, ch=2, format=10
kernel: [ 9092.061667] sof-audio-pci 0000:00:1f.3: pcm: prepare stream 3 dir 0
kernel: [ 9092.061670] sof-audio-pci 0000:00:1f.3: pcm: hw params stream 3 dir 0
kernel: [ 9092.061674] sof-audio-pci 0000:00:1f.3: generating page table for 00000000b306b912 size 0x10000 pages 16
kernel: [ 9092.061730] video LNXVIDEO:00: Restoring backlight state
kernel: [ 9092.061753] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x140000 successful
kernel: [ 9092.061793] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x40000 successful
kernel: [ 9092.061800] sof-audio-pci 0000:00:1f.3: period_bytes:0x4000
kernel: [ 9092.061803] sof-audio-pci 0000:00:1f.3: periods:4
kernel: [ 9092.061826] sof-audio-pci 0000:00:1f.3: stream_tag 1
kernel: [ 9092.061839] sof-audio-pci 0000:00:1f.3: ipc tx: 0x60010000: GLB_STREAM_MSG: PCM_PARAMS
kernel: [ 9092.062050] PM: suspend exit

  24. mengdonglin commented on May 13, 2021

    @mengdonglin
    mengdonglin
    on May 13, 2021
    Author

    Close as won't fix.

  25. mengdonglin
    closed this as completedon May 13, 2021

  26. marc-hb commented on May 13, 2021

    @marc-hb
    marc-hb
    on May 13, 2021
    Collaborator

    Are we going to skip this test then?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    APLApplies to ApolloLake platformCI blockerIssues can can block CI test, maybe 3rd partyCMLApplies to Comet Lake platformEHLApplies to Elkhart LakeJSLJasper Lake platform issuesP2Critical bugs or normal featuresbugSomething isn't workingsuspend resumeIssues related to suspend resume (e.g. rtcwake)won't fixThis will not be worked on atm (e.g. a bug closed for lack of user request, hardware etc)

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions