Skip to content

[BUG][SDW][TGL]Dmesg shows "failed to reset HDA controller gctl 0x1" when doing suspend & resume without playback stress test. #1556

New issue
New issue
Closed
Closed
[BUG][SDW][TGL]Dmesg shows "failed to reset HDA controller gctl 0x1" when doing suspend & resume without playback stress test.#1556
Labels
Legacy IRQIssues observed only in legacy IRQ modeMSIIssues observed only in MSI modeSDWApplies to SoundWire bus for codec connectionTGLApplies to Tiger Lake platformbugSomething isn't working

Description

@sinahuang
sinahuang
opened on Nov 27, 2019

Describe the bug
Dmesg shows "failed to reset HDA controller gctl 0x1" info, and then occured "error: ipc timed out for 0x40010000 size 76" when doing suspend & resume without playback stress test.

To Reproduce
1.Boot up system;
2.Run "sudo ./stress_s3.sh 300 1 0";

Scripts:
stress-s3.txt

Reproduce rate
Test for 300 times, failed at 127th time.

Expected result
No error occured during testing.

Actual result
"error: ipc timed out for 0x40010000 size 76" occured during suspeand & resume without playback stress test.

dmesg error log 
[ 2095.225044] sof-audio-pci 0000:00:1f.3: sof_send_pm_ctx_ipc
[ 2095.225075] sof-audio-pci 0000:00:1f.3: ipc tx: 0x40010000: GLB_PM_MSG: CTX_SAVE
[ 2095.225600] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x40010000: GLB_PM_MSG: CTX_SAVE
[ 2095.225632] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x1010f0f successful
[ 2095.225646] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x1000f0f successful
[ 2095.225650] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 0 : core_mask 1
[ 2095.225733] sof-audio-pci 0000:00:1f.3: Debug PCIR: 00000010 at  00000044
[ 2095.426067] sof-audio-pci 0000:00:1f.3: error: failed to reset HDA controller gctl 0x1
[ 2095.426073] sof-audio-pci 0000:00:1f.3: error: failed to reset controller during suspend
[ 2095.426075] sof-audio-pci 0000:00:1f.3: error: failed to power down DSP during suspend -5
[ 2095.426081] sof-audio-pci 0000:00:1f.3: can't suspend (snd_sof_runtime_suspend [snd_sof] returned -5)
[ 2099.697279] PM: suspend entry (s2idle)
[ 2099.697707] Filesystems sync: 0.000 seconds
[ 2099.697920] Freezing user space processes ... (elapsed 0.001 seconds) done.
[ 2099.699181] OOM killer disabled.
[ 2099.699182] Freezing remaining freezable tasks ... (elapsed 0.000 seconds) done.
[ 2099.700152] printk: Suspending console(s) (use no_console_suspend to debug)
[ 2099.700350] intel-sdw sdw-master-0: intel_suspend start
[ 2099.700352] intel-sdw sdw-master-0: intel_suspend: pm_runtime status: suspended
[ 2099.715904] sof-audio-pci 0000:00:1f.3: snd_sof_suspend
[ 2099.715906] sof-audio-pci 0000:00:1f.3: sof_suspend
[ 2099.715908] sof-audio-pci 0000:00:1f.3: sof_send_pm_ctx_ipc
[ 2099.715912] sof-audio-pci 0000:00:1f.3: ipc tx: 0x40010000: GLB_PM_MSG: CTX_SAVE
[ 2100.219416] sof-audio-pci 0000:00:1f.3: error: ipc timed out for 0x40010000 size 76
[ 2100.219418] sof-audio-pci 0000:00:1f.3: info: preventing DSP entering D3 state to preserve context
[ 2100.219437] sof-audio-pci 0000:00:1f.3: unknown ROM status value 01009701
[ 2100.219770] sof-audio-pci 0000:00:1f.3: error: unexpected fault 0x001d003c trace 0x00000000
[ 2100.219794] sof-audio-pci 0000:00:1f.3: error: hda irq intsts 0x00000000 intlctl 0x00000000 rirb 00
[ 2100.219795] sof-audio-pci 0000:00:1f.3: error: dsp irq ppsts 0x00000000 adspis 0x00000000
[ 2100.219823] sof-audio-pci 0000:00:1f.3: error: host status 0x00000000 dsp status 0x00040000 mask 0x00000000
[ 2100.219825] sof-audio-pci 0000:00:1f.3: ctx_save ipc error -110, proceeding with suspend
[ 2100.239389] ACPI: EC: interrupt blocked
[ 2105.378251] ACPI: EC: interrupt unblocked
[ 2105.439068] sof-audio-pci 0000:00:1f.3: snd_sof_resume
[ 2105.439070] sof-audio-pci 0000:00:1f.3: sof_resume
[ 2105.439072] sof-audio-pci 0000:00:1f.3: loading firmware
[ 2105.439076] sof-audio-pci 0000:00:1f.3: Debug PCIR: 00000002 at  00000048
[ 2105.439081] sof-audio-pci 0000:00:1f.3: Debug PCIW: 00000000 at  00000048
[ 2105.439087] sof-audio-pci 0000:00:1f.3: Debug PCIR: 00000000 at  00000044
[ 2105.439091] sof-audio-pci 0000:00:1f.3: Debug PCIW: 00000004 at  00000044
[ 2105.439092] sof-audio-pci 0000:00:1f.3: booting DSP firmware
[ 2105.439118] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x40000 successful
[ 2105.439924] sof-audio-pci 0000:00:1f.3: error: stream reset failed
[ 2105.439925] sof-audio-pci 0000:00:1f.3: error: hdac prepare failed: ffffff92
[ 2105.439932] sof-audio-pci 0000:00:1f.3: error: dma prepare for fw loading err: ffffff92
[ 2105.439933] sof-audio-pci 0000:00:1f.3: error: failed to reset DSP
[ 2105.439934] sof-audio-pci 0000:00:1f.3: error: failed to boot DSP firmware after resume -110
[ 2105.439939] PM: dpm_run_callback(): pci_pm_resume+0x0/0xa0 returns -110
[ 2105.439940] PM: Device 0000:00:1f.3 failed to resume: error -110
[ 2105.442000] serial 00:03: activated
[ 2105.468997] intel-sdw sdw-master-0: intel_resume start
[ 2105.468998] intel-sdw sdw-master-0: intel_resume: pm_runtime status was suspended, forcing active
[ 2105.469596] rt711 sdw:0:25d:711:0: sdw_modify_slave_status: initializing completion for Slave 1
[ 2105.469610] intel-sdw sdw-master-0: intel_resume done
[ 2105.469616] rt711_rt1308 rt711_rt1308: ASoC: Scheduling resume work
[ 2105.469620] rt711_rt1308 rt711_rt1308: ASoC: starting resume work
[ 2105.471519] rt711_rt1308 rt711_rt1308: ASoC: resume work completed
[ 2105.672234] atkbd serio0: Failed to deactivate keyboard on isa0060/serio0

Test recipe

Kernel:https://github.com/thesofproject/linux/tree/integration/soundwire-latest commit: d6078f9
FW: https://github.com/thesofproject/sof/commits/master commit: d740a3e
Tplg: Same with TGL FW branch commit: sof-tgl-rt711-rt1308-nohdmi.tplg rename to sof-tgl-rt711-rt1308.tplg
Platform:TGL RVP with onboard ACL711 in SDW mod and ALC1308 in I2S mode.

s3_test_127_logger_all.log
test_127.log

Activity

  1. sinahuang
    changed the title [-][BUG][SDW][TGL]Dmesg shows "failed to reset HDA controller gctl 0x1" info then occured "error: ipc timed out for 0x40010000 size 76" when doing suspeand & resume without playback stress test.[/-] [+][BUG][SDW][TGL]Dmesg shows "failed to reset HDA controller" info then occured " ipc timed out for 0x40010000 size 76" when doing suspend & resume without playback stress test.[/+] on Nov 27, 2019
  2. sinahuang
    changed the title [-][BUG][SDW][TGL]Dmesg shows "failed to reset HDA controller" info then occured " ipc timed out for 0x40010000 size 76" when doing suspend & resume without playback stress test.[/-] [+][BUG][SDW][TGL]" Ipc timed out for 0x40010000 size 76" when doing suspend & resume without playback stress test.[/+] on Nov 27, 2019
  3. sinahuang
    changed the title [-][BUG][SDW][TGL]" Ipc timed out for 0x40010000 size 76" when doing suspend & resume without playback stress test.[/-] [+][BUG][SDW][TGL]Dmesg shows "failed to reset HDA controller gctl 0x1" then occured" ipc timed out for 0x40010000 size 76" when doing suspend & resume without playback stress test.[/+] on Nov 27, 2019
  4. sinahuang
    added
    TGLApplies to Tiger Lake platform
    bugSomething isn't working
    SDWApplies to SoundWire bus for codec connection
    and removed
    TGLApplies to Tiger Lake platform
    on Nov 27, 2019

  5. sinahuang commented on Nov 27, 2019

    @sinahuang
    sinahuang
    on Nov 27, 2019
    Author

    This issue might be related to issue #1399

  6. sinahuang
    added
    MSIIssues observed only in MSI mode
    Legacy IRQIssues observed only in legacy IRQ mode
    on Nov 27, 2019
  7. mengdonglin
    changed the title [-][BUG][SDW][TGL]Dmesg shows "failed to reset HDA controller gctl 0x1" then occured" ipc timed out for 0x40010000 size 76" when doing suspend & resume without playback stress test.[/-] [+][BUG][SDW][TGL]Dmesg shows "failed to reset HDA controller gctl 0x1" when doing suspend & resume without playback stress test.[/+] on Nov 27, 2019

  8. plbossart commented on Dec 2, 2019

    @plbossart
    plbossart
    on Dec 2, 2019
    Member

    @sinahuang can you try to revert the patch 'ASoC: SOF: Intel: hda-ctrl: add reset cycle before parsing capabilities' to see if this solves the issue on TGL?

  9. sinahuang commented on Dec 3, 2019

    @sinahuang
    sinahuang
    on Dec 3, 2019
    Author

    Issue still can be reproduced after reverting the patch 'ASoC: SOF: Intel: hda-ctrl: add reset cycle before parsing capabilities' on TGL RVP.

    Test for 500 times, failed at 122th time.

    dmesg error log 
    [ 2015.641351] intel-sdw sdw-master-0: intel_suspend_runtime start
[ 2015.641442] intel-sdw sdw-master-0: intel_suspend_runtime done
[ 2015.641451] sof-audio-pci 0000:00:1f.3: snd_sof_runtime_idle
[ 2015.641458] sof-audio-pci 0000:00:1f.3: snd_sof_runtime_suspend
[ 2015.641461] sof-audio-pci 0000:00:1f.3: sof_suspend
[ 2015.642277] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x20140000 successful
[ 2015.699100] sof-audio-pci 0000:00:1f.3: sof_send_pm_ctx_ipc
[ 2015.699216] sof-audio-pci 0000:00:1f.3: ipc tx: 0x40010000: GLB_PM_MSG: CTX_SAVE
[ 2015.699919] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x40010000: GLB_PM_MSG: CTX_SAVE
[ 2015.699952] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x1010f0f successful
[ 2015.699965] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f successful
[ 2015.699972] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 0 : core_mask 1
[ 2015.700077] sof-audio-pci 0000:00:1f.3: Debug PCIR: 00000010 at  00000044
[ 2015.831200] sof-audio-pci 0000:00:1f.3: error: failed to reset HDA controller gctl 0x1
[ 2015.831207] sof-audio-pci 0000:00:1f.3: error: failed to reset controller during suspend
[ 2015.831209] sof-audio-pci 0000:00:1f.3: error: failed to power down DSP during suspend -5
[ 2015.831215] sof-audio-pci 0000:00:1f.3: can't suspend (snd_sof_runtime_suspend [snd_sof] returned -5)
[ 2020.535285] PM: suspend entry (s2idle)
[ 2020.535969] Filesystems sync: 0.000 seconds
[ 2020.536226] Freezing user space processes ... (elapsed 0.001 seconds) done.
[ 2020.537969] OOM killer disabled.
[ 2020.537970] Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done.
[ 2020.539146] printk: Suspending console(s) (use no_console_suspend to debug)
[ 2020.539387] intel-sdw sdw-master-0: intel_suspend start
[ 2020.539389] intel-sdw sdw-master-0: intel_suspend: pm_runtime status: suspended
[ 2020.554904] sof-audio-pci 0000:00:1f.3: snd_sof_suspend
[ 2020.554906] sof-audio-pci 0000:00:1f.3: sof_suspend
[ 2020.554907] sof-audio-pci 0000:00:1f.3: sof_send_pm_ctx_ipc
[ 2020.554912] sof-audio-pci 0000:00:1f.3: ipc tx: 0x40010000: GLB_PM_MSG: CTX_SAVE
[ 2021.059565] sof-audio-pci 0000:00:1f.3: error: ipc timed out for 0x40010000 size 76
[ 2021.059568] sof-audio-pci 0000:00:1f.3: info: preventing DSP entering D3 state to preserve context
[ 2021.059586] sof-audio-pci 0000:00:1f.3: unknown ROM status value 01009701
[ 2021.059900] sof-audio-pci 0000:00:1f.3: error: unexpected fault 0x001d003c trace 0x00000000
[ 2021.059925] sof-audio-pci 0000:00:1f.3: error: hda irq intsts 0x00000000 intlctl 0x00000000 rirb 00
[ 2021.059926] sof-audio-pci 0000:00:1f.3: error: dsp irq ppsts 0x00000000 adspis 0x00000000
[ 2021.059951] sof-audio-pci 0000:00:1f.3: error: host status 0x00000000 dsp status 0x00040000 mask 0x00000000
[ 2021.059953] sof-audio-pci 0000:00:1f.3: ctx_save ipc error -110, proceeding with suspend
[ 2021.079517] ACPI: EC: interrupt blocked
[ 2027.218196] ACPI: EC: interrupt unblocked
[ 2027.283430] sof-audio-pci 0000:00:1f.3: snd_sof_resume
[ 2027.283432] sof-audio-pci 0000:00:1f.3: sof_resume
[ 2027.283434] sof-audio-pci 0000:00:1f.3: loading firmware
[ 2027.283438] sof-audio-pci 0000:00:1f.3: Debug PCIR: 00000002 at  00000048
[ 2027.283443] sof-audio-pci 0000:00:1f.3: Debug PCIW: 00000000 at  00000048
[ 2027.283449] sof-audio-pci 0000:00:1f.3: Debug PCIR: 00000000 at  00000044
[ 2027.283453] sof-audio-pci 0000:00:1f.3: Debug PCIW: 00000004 at  00000044
[ 2027.283454] sof-audio-pci 0000:00:1f.3: booting DSP firmware
[ 2027.283484] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x40000 successful
[ 2027.284306] sof-audio-pci 0000:00:1f.3: error: stream reset failed
[ 2027.284307] sof-audio-pci 0000:00:1f.3: error: hdac prepare failed: ffffff92
[ 2027.284319] sof-audio-pci 0000:00:1f.3: error: dma prepare for fw loading err: ffffff92
[ 2027.284319] sof-audio-pci 0000:00:1f.3: error: failed to reset DSP
[ 2027.284320] sof-audio-pci 0000:00:1f.3: error: failed to boot DSP firmware after resume -110
[ 2027.284324] PM: dpm_run_callback(): pci_pm_resume+0x0/0xa0 returns -110
[ 2027.284326] PM: Device 0000:00:1f.3 failed to resume: error -110
[ 2027.289365] serial 00:03: activated
[ 2027.311776] intel-sdw sdw-master-0: intel_resume start
[ 2027.311777] intel-sdw sdw-master-0: intel_resume: pm_runtime status was suspended, forcing active
[ 2027.312356] rt711 sdw:0:25d:711:0: sdw_modify_slave_status: initializing completion for Slave 1
[ 2027.312371] intel-sdw sdw-master-0: intel_resume done
[ 2027.312404] rt711_rt1308 rt711_rt1308: ASoC: Scheduling resume work
[ 2027.312408] rt711_rt1308 rt711_rt1308: ASoC: starting resume work
[ 2027.314038] rt711_rt1308 rt711_rt1308: ASoC: resume work completed
[ 2027.515940] atkbd serio0: Failed to deactivate keyboard on isa0060/serio0
[ 2027.741208] OOM killer enabled.
[ 2027.741209] Restarting tasks ... done.
[ 2027.749798] rfkill: input handler enabled
[ 2027.780786] video LNXVIDEO:00: Restoring backlight state
[ 2027.780813] PM: suspend exit
[ 2027.823172] rfkill: input handler disabled
[ 2027.899926] atkbd serio0: Failed to enable keyboard on isa0060/serio0
[ 2029.712843] asix 3-8:1.0 enx000ec6caa0a8: link up, 100Mbps, full-duplex, lpa 0x41E1

    s3_test_122_logger_all.log
    test_122.log

  10. sinahuang
    closed this as completedon Dec 3, 2019

  11. sinahuang commented on Dec 3, 2019

    @sinahuang
    sinahuang
    on Dec 3, 2019
    Author

    sorry for wrong operation, open it.

  12. sinahuang
    reopened this on Dec 3, 2019

  13. plbossart commented on Dec 3, 2019

    @plbossart
    plbossart
    on Dec 3, 2019
    Member

    seems like we've lost a comment:

    Verified this issue on TGL RVP with soundwire-latest (commit: b4f9bfa+PR #1580), issue cannot be reproduced, so PR #1580 seems can fix this issue.

    Test recipe

    Kernel:https://github.com/thesofproject/linux/tree/integration/soundwire-latest commit: b4f9bfa+PR #1580
    FW: https://github.com/thesofproject/sof/commits/master commit: feb9e2b
    Tplg: Same with TGL FW branch commit: sof-tgl-rt711-rt1308-nohdmi.tplg rename to sof-tgl-rt711-rt1308.tplg
    Platform:TGL RVP with onboard ACL711 in SDW mod and ALC1308 in I2S mode.

  14. sinahuang commented on Dec 4, 2019

    @sinahuang
    sinahuang
    on Dec 4, 2019
    Author

    Above comments is that I tested this issue with "options soundwire_intel sdw_md_flags=0x01000001" and "options snd_sof_pci sof_pci_debug=1" enabled in alsa-base.conf.
    PR #1580 is not for this issue. I think the test environment is not same with original issue. So I delete it.

  15. sinahuang commented on Dec 20, 2019

    @sinahuang
    sinahuang
    on Dec 20, 2019
    Author

    Check this issue on TGL-U RVP with soudwire-latest (commit: 121c751), test for 500 times issue cannot be produced, so closed it.

  16. sinahuang
    closed this as completedon Dec 20, 2019
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

    Legacy IRQIssues observed only in legacy IRQ modeMSIIssues observed only in MSI modeSDWApplies to SoundWire bus for codec connectionTGLApplies to Tiger Lake platformbugSomething isn't working

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions