Skip to content

[BUG] cl_dsp_init: timeout for HIPCIE done #1472

Closed

Description

@aiChaoSONG

Bug Description
run sudo rtcwake -s 5 -m mem, after the machine sleep back, check dmesg, you can see cl_dsp_init: timeout for HIPCIE done error

To Reproduce

  1. reboot
  2. run sudo rtcwake -s 5 -m mem

Reproduction Rate
5/5

Impact
no functional impact, just error messages

Platform & Environment
Kernel: topic/sof-dev: f55db62e
SOF: master: 835d876b
Tplg: sof-cml-rt1011-rt5682
Platform: ASUS CML Chromebook with RT5682 codec

[  112.521166] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f0e0e successful
[  112.521173] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f0e0e successful
[  112.521174] sof-audio-pci 0000:00:1f.3: unstall/run core: core_mask = 1
[  112.521176] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 1 : core_mask 1
[  113.021457] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x0 timedout
[  113.021461] sof-audio-pci 0000:00:1f.3: error: cl_dsp_init: timeout for HIPCIE done
[  113.021468] sof-audio-pci 0000:00:1f.3: unknown ROM status value ffffffff
[  113.021472] sof-audio-pci 0000:00:1f.3: error: status = 0xffffffff panic = 0xffffffff
[  113.021476] sof-audio-pci 0000:00:1f.3: unknown ROM status value ffffffff
[  113.021482] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f0f0f successful
[  113.021487] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f successful
[  113.021491] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 0 : core_mask f
[  113.021495] sof-audio-pci 0000:00:1f.3: error: Error code=0xffffffff: FW status=0xffffffff
[  113.021498] sof-audio-pci 0000:00:1f.3: error: iteration 0 of Core En/ROM load failed: -110
[  113.021502] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f0f0f successful
[  113.021511] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f0f0e successful
[  113.021514] sof-audio-pci 0000:00:1f.3: unstall/run core: core_mask = 1
[  113.021519] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 1 : core_mask 1

sof_trace.log
dmesg.log

Activity

  1. ranj063 commented on Nov 13, 2019

    @ranj063
    Collaborator

    @aiChaoSONG Can you please check if this problem is solved by reverting 0e1a961

  2. aiChaoSONG commented on Nov 13, 2019

    @aiChaoSONG
    Author

    @ranj063 reverting 0e1a961 helps with this issue. @keyonjie we may need to rethink, and deal with code_loading beautifully.

  3. dengyangchao commented on Nov 13, 2019

    @dengyangchao

    Issue also can reproduce on CML Chrome with onboard codec RT5682 in I2S mode when run Soix_test.sh.

    Firmware: 835d876 https://github.com/thesofproject/sof/commits/master
    Kernel: f55db62 https://github.com/thesofproject/linux/commits/topic/sof-dev
    Topology: file: tools/topology/sof-cml-rt5682-max98357a.tplg same as firmware

    [  150.682581] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x40010000: GLB_PM_MSG: CTX_SAVE
    [  150.714112] sd 1:0:0:0: [sda] Synchronizing SCSI cache
    [  150.714792] sd 1:0:0:0: [sda] Stopping disk
    [  151.011104] ACPI: EC: interrupt blocked
    [  154.750672] ACPI: EC: interrupt unblocked
    [  154.778797] sd 1:0:0:0: [sda] Starting disk
    [  155.012978] sof-audio-pci 0000:00:1f.3: loading firmware
    [  155.012992] sof-audio-pci 0000:00:1f.3: Debug PCIR: 00000002 at  00000048
    [  155.012999] sof-audio-pci 0000:00:1f.3: Debug PCIW: 00000000 at  00000048
    [  155.013008] sof-audio-pci 0000:00:1f.3: Debug PCIR: 00000000 at  00000044
    [  155.013014] sof-audio-pci 0000:00:1f.3: Debug PCIW: 00000004 at  00000044
    [  155.013017] sof-audio-pci 0000:00:1f.3: booting DSP firmware
    [  155.013116] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x40000 successful
    [  155.013141] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x40000 successful
    [  155.013150] sof-audio-pci 0000:00:1f.3: period_bytes:0x0
    [  155.013153] sof-audio-pci 0000:00:1f.3: periods:1
    [  155.013292] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f0e0e successful
    [  155.013304] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f0e0e successful
    [  155.013310] sof-audio-pci 0000:00:1f.3: unstall/run core: core_mask = 1
    [  155.013317] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 1 : core_mask 1
    [  155.083963] ata2: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
    [  155.086036] ata2.00: configured for UDMA/133
    [  155.513496] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x0 timedout
    [  155.513501] sof-audio-pci 0000:00:1f.3: error: cl_dsp_init: timeout for HIPCIE done
    [  155.513511] sof-audio-pci 0000:00:1f.3: unknown ROM status value ffffffff
    [  155.513518] sof-audio-pci 0000:00:1f.3: error: status = 0xffffffff panic = 0xffffffff
    [  155.513523] sof-audio-pci 0000:00:1f.3: unknown ROM status value ffffffff
    [  155.513534] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f0f0f successful
    [  155.513542] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f successful
    [  155.513548] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 0 : core_mask f
    [  155.513555] sof-audio-pci 0000:00:1f.3: error: Error code=0xffffffff: FW status=0xffffffff
    [  155.513558] sof-audio-pci 0000:00:1f.3: error: iteration 0 of Core En/ROM load failed: -110
    [  155.513565] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f0f0f successful
    [  155.513578] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f0f0e successful
    [  155.513584] sof-audio-pci 0000:00:1f.3: unstall/run core: core_mask = 1
    [  155.513591] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 1 : core_mask 1
    

    test_0_fail.log

  4. added
    bugSomething isn't working
    CMLApplies to Comet Lake platform
    on Nov 13, 2019
  5. dengyangchao commented on Nov 13, 2019

    @dengyangchao

    Also can reproduce on
    ICL RVP with onboard codec ALC700 in HDA mode(s2idle)
    GLK Chrome with onboard codec DA7219 in I2S mode(s2idle)

    And checked on CFL-S RVP ALC700 in HDA mode(deep), issue can't reproduce
    so issue only can reproduce on s2idle mode, and related with #1387

  6. added
    CFLApplies to Coffee Lake platform
    GLKApplies to Gemini Lake
    ICLApplies to Icelake platform
    on Nov 13, 2019
  7. changed the title [-][BUG][CML] cl_dsp_init: timeout for HIPCIE done[/-] [+][BUG] cl_dsp_init: timeout for HIPCIE done[/+] on Nov 13, 2019
  8. YvonneYang2 commented on Nov 13, 2019

    @YvonneYang2

    Issue can be reproduced on CML SDW Laptop with ALC711+ ALC1308+ ALC715 mode.

    kernel: https://github.com/thesofproject/linux/tree/integration/soundwire-latest commit: fb40b85 + #1451
    FW: https://github.com/thesofproject/sof/commits/master commit: 835d876
    tplg: same path as FW branch, sof-cml-rt711-rt1308-mono-rt715.tplg
    platform: CML SDW Laptop with ALC711+ ALC1308+ ALC715

  9. keyonjie commented on Nov 13, 2019

    @keyonjie

    Thanks for reporting this, if we go through the dmesg log, we can find the 1st try in cl_dsp_init() failed and the subsequent try succeed, this is interesting @ranj063

  10. keyonjie commented on Nov 13, 2019

    @keyonjie

    I root caused what happens there, will provide a update fix soon. @plbossart @ranj063

  11. keyonjie commented on Nov 13, 2019

    @keyonjie

    @ranj063 @plbossart after applied the fix from PR #1479, the issue is disappear even with commit 0e1a961 applied, that is consistent with what @dengyangchao observed, thank you.

    @ranj063 @plbossart @aiChaoSONG I feel happy that the clean up commit actually helped us to export potential hidden issues. :-)

  12. 12 remaining items

  13. mengdonglin commented on Nov 22, 2019

    @mengdonglin

    Remove P1 label since there is no functional impact, just error messages. And assigned to @keyonjie

  14. keyonjie commented on Nov 22, 2019

    @keyonjie

    #1524 will fix this.

  15. dengyangchao commented on Dec 4, 2019

    @dengyangchao

    Tried #1524 on ICL RVP with onboard codec ALC700 in HDA mode (s2idle)
    issue can't reproduce.
    Tried two scenarios in s2idle:

    1. suspend&resume via command"sudo rtcwake -m mem -s 10" without playback.
    2. suspend&resume via command"sudo rtcwake -m mem -s 10" with playback.

    dmesg.log

  16. mengdonglin commented on Dec 25, 2019

    @mengdonglin

    To be fixed by PR #1631 by Ranjani

  17. YvonneYang2 commented on Dec 25, 2019

    @YvonneYang2

    Tested it with latest topic/sof-dev(7fde475) + #1631 , issue cannot be reproduced on CML laptop with HDA ALC3204.

  18. dengyangchao commented on Dec 25, 2019

    @dengyangchao

    Tested it with latest topic/sof-dev(7fde475) + #1631 , issue cannot be reproduced on
    CML Chrome with I2S RT5682
    GLK Chrome with I2S DA7219

  19. sinahuang commented on Dec 25, 2019

    @sinahuang

    Check this issue with latest sof-dev(7fde475) + #1631 on TGL-U RVP with codec ALC711 in HDA mode, issue can't be reproduced.

  20. xiulipan commented on Dec 26, 2019

    @xiulipan

    @Bin-QA Please help to check if our test scripts can identify such issue.
    @ranj063 @keyonjie If we have retry logic here, maybe we can change the logs into warning instead of error?

  21. Bin-QA commented on Dec 26, 2019

    @Bin-QA

    I think this PR can identify the issue like this: thesofproject/sof-test#16

  22. dengyangchao commented on Jan 14, 2020

    @dengyangchao

    Since #1631 merged, issue can't be reproduced, close.

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

Metadata

Metadata

Assignees

Labels

CFLApplies to Coffee Lake platformCMLApplies to Comet Lake platformGLKApplies to Gemini LakeICLApplies to Icelake platformTGLApplies to Tiger Lake platformbugSomething isn't workingsuspend resumeIssues related to suspend resume (e.g. rtcwake)

Type

No type

Projects

No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions