Skip to content

[BUG][SDW]Dmesg sometimes suddenly prints repeat infomation "i2c_designware i2c_designware.1: timeout waiting for bus ready"(Random) #1455

Closed

Description

@YvonneYang2

Describe the bug
It only reproduced with deep suspend mode.
Demsg print same infomation "i2c_designware i2c_designware.1: timeout waiting for bus ready" over and over again. System cannot response till dmesg finish printing message(about 1 minute) which ended with "i2c_designware i2c_designware.1: timeout in disabling adapter".

To Reproduce Note: Do aplay still can reproduce the issue.

  1. Boot up
  2. Switch to deep suspend mode via "echo deep>/sys/power/mem_sleep"
  3. Arecord -Dhw:0,4 -r48000 -c2 -fs16_le 1.wav -vv -i
  4. Push_pause arecord, then suspend via "sudo rtcwake -m mem -s 10"
  5. Wait 10s after wake up from s3, then push_release. --> if issue not reproduced, go on step 6
  6. Switch areocrd to background, and back to foreground. ---> if issue not reproduced, terminate it then repeat step 3/4/5/6.

Reproduced rate
About 30%

Expected result
Arecord works normally after waking up from s3. Dmesg shows normally

Actual result
Arecord hang and dmesg print repeat message.

Below occurred when switch arecord background.
dmesg

Nov  8 10:57:14 ubuntu-Latitude-11111 kernel: [  198.315860] rt715 sdw:3:25d:715:0: [rt715_sdw_write] 00e0 <= 0001
Nov  8 10:57:14 ubuntu-Latitude-11111 kernel: [  198.315924] rt715 sdw:3:25d:715:0: [rt715_sdw_write] 00f0 <= 0001
Nov  8 10:57:14 ubuntu-Latitude-11111 kernel: [  198.316378] sdw_enable_stream: SDW3 Pin2-Capture: done
Nov  8 10:57:14 ubuntu-Latitude-11111 kernel: [  198.316386] intel-sdw sdw-master-3: intel_trigger: SDW3 Pin2: done
Nov  8 10:57:14 ubuntu-Latitude-11111 kernel: [  198.316393]  DMIC: ASoC: post trigger FE DMIC cmd 1
Nov  8 10:57:14 ubuntu-Latitude-11111 kernel: [  198.316400] sof-audio-pci 0000:00:1f.3: pcm: trigger stream 4 dir 1 cmd 1
Nov  8 10:57:14 ubuntu-Latitude-11111 kernel: [  198.316875] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x2024001e successful
Nov  8 10:57:14 ubuntu-Latitude-11111 kernel: [  198.316884] sof-audio-pci 0000:00:1f.3: ipc tx: 0x60040000: GLB_STREAM_MSG: TRIG_START
Nov  8 10:57:14 ubuntu-Latitude-11111 kernel: [  198.317083] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x60040000: GLB_STREAM_MSG: TRIG_START
Nov  8 10:57:14 ubuntu-Latitude-11111 kernel: [  198.668583] i2c_designware i2c_designware.1: timeout waiting for bus ready
Nov  8 10:57:14 ubuntu-Latitude-11111 kernel: [  198.677920] sof-audio-pci 0000:00:1f.3: ipc rx: 0x90020000: GLB_TRACE_MSG
Nov  8 10:57:14 ubuntu-Latitude-11111 kernel: [  198.677942] sof-audio-pci 0000:00:1f.3: ipc rx done: 0x90020000: GLB_TRACE_MSG
Nov  8 10:57:14 ubuntu-Latitude-11111 kernel: [  198.690804] i2c_designware i2c_designware.1: timeout waiting for bus ready
Nov  8 10:57:14 ubuntu-Latitude-11111 kernel: [  198.712845] i2c_designware i2c_designware.1: timeout waiting for bus ready
Nov  8 10:57:14 ubuntu-Latitude-11111 kernel: [  198.734841] i2c_designware i2c_designware.1: timeout waiting for bus ready
Nov  8 10:57:14 ubuntu-Latitude-11111 kernel: [  198.756939] i2c_designware i2c_designware.1: timeout waiting for bus ready
Nov  8 10:57:14 ubuntu-Latitude-11111 kernel: [  198.778977] i2c_designware i2c_designware.1: timeout waiting for bus ready

kern.log

Activity

  1. added
    CMLApplies to Comet Lake platform
    bugSomething isn't working
    SDWApplies to SoundWire bus for codec connection
    on Nov 8, 2019
  2. changed the title [-][BUG][SDW]Demsg print repeat infomation "i2c_designware i2c_designware.1: timeout waiting for bus ready"(Random)[/-] [+][BUG][SDW]Dmesg sometimes suddenly prints repeat infomation "i2c_designware i2c_designware.1: timeout waiting for bus ready"(Random)[/+] on Nov 8, 2019
  3. plbossart commented on Nov 8, 2019

    @plbossart
    Member

    @YvonneYang2 can you try with SOF_HDA_LINK disabled? wondering if this is i915-related.

    It's clearly not an SOF bug though

  4. RanderWang commented on Nov 11, 2019

    @RanderWang

    I checked /proc/interrupt and found i2c.designware.1 share irq with audio. Maybe it is a interrupt issue.
    I recommend to test it with MSI disabled and legacy irq enabled.

  5. YvonneYang2 commented on Nov 11, 2019

    @YvonneYang2
    Author

    Checked it with legacy interrupt mode, issue can still be reproduced.

    dmesg
    
    Sep 30 23:03:44 cml-olympic-001 kernel: [  425.576301] sof-audio-pci 0000:00:1f.3: ipc tx: 0x60030000: GLB_STREAM_MSG: PCM_FREE
    Sep 30 23:03:44 cml-olympic-001 kernel: [  425.576530] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x60030000: GLB_STREAM_MSG: PCM_FREE
    Sep 30 23:03:44 cml-olympic-001 kernel: [  425.576537]  SDW3-Capture: ASoC: trigger BE SDW3-Capture cmd 0
    Sep 30 23:03:44 cml-olympic-001 kernel: [  425.576551] intel-sdw sdw-master-3: intel_trigger: SDW3 Pin2: start
    Sep 30 23:03:44 cml-olympic-001 kernel: [  425.576566] sdw_disable_stream: SDW3 Pin2-Capture: start
    Sep 30 23:03:44 cml-olympic-001 kernel: [  425.578628] rt715 sdw:3:25d:715:0: [rt715_sdw_write] 00e0 <= 0001
    Sep 30 23:03:44 cml-olympic-001 kernel: [  425.578787] rt715 sdw:3:25d:715:0: [rt715_sdw_write] 00f0 <= 0001
    Sep 30 23:03:44 cml-olympic-001 kernel: [  425.579538] sdw_disable_stream: SDW3 Pin2-Capture: done
    Sep 30 23:03:44 cml-olympic-001 kernel: [  425.579554] intel-sdw sdw-master-3: intel_trigger: SDW3 Pin2: done
    Sep 30 23:03:44 cml-olympic-001 kernel: [  425.740328] i2c_designware i2c_designware.1: transfer terminated early - interrupt latency too high?
    Sep 30 23:03:44 cml-olympic-001 kernel: [  426.239933] sof-audio-pci 0000:00:1f.3: ipc rx: 0x90020000: GLB_TRACE_MSG
    Sep 30 23:03:44 cml-olympic-001 kernel: [  426.239955] sof-audio-pci 0000:00:1f.3: ipc rx done: 0x90020000: GLB_TRACE_MSG
    Sep 30 23:03:44 cml-olympic-001 kernel: [  426.313494] i2c_designware i2c_designware.1: timeout waiting for bus ready
    Sep 30 23:03:44 cml-olympic-001 kernel: [  426.336636] i2c_designware i2c_designware.1: timeout waiting for bus ready
    Sep 30 23:03:44 cml-olympic-001 kernel: [  426.359387] i2c_designware i2c_designware.1: timeout waiting for bus ready
    Sep 30 23:03:44 cml-olympic-001 kernel: [  426.382130] i2c_designware i2c_designware.1: timeout waiting for bus ready
    Sep 30 23:03:45 cml-olympic-001 kernel: [  426.405014] i2c_designware i2c_designware.1: timeout waiting for bus ready
    Sep 30 23:03:45 cml-olympic-001 kernel: [  426.427931] i2c_designware i2c_designware.1: timeout waiting for bus ready
    Sep 30 23:03:45 cml-olympic-001 kernel: [  426.451039] i2c_designware i2c_designware.1: timeout waiting for bus ready
    Sep 30 23:03:45 cml-olympic-001 kernel: [  426.473916] i2c_designware i2c_designware.1: timeout waiting for bus ready
    Sep 30 23:03:45 cml-olympic-001 kernel: [  426.496560] i2c_designware i2c_designware.1: timeout waiting for bus ready
    Sep 30 23:03:45 cml-olympic-001 kernel: [  426.519349] i2c_designware i2c_designware.1: timeout waiting for bus ready
    Sep 30 23:03:45 cml-olympic-001 kernel: [  426.542193] i2c_designware i2c_designware.1: timeout waiting for bus ready
    Sep 30 23:03:45 cml-olympic-001 kernel: [  426.564883] i2c_designware i2c_designware.1: timeout waiting for bus ready
    Sep 30 23:03:45 cml-olympic-001 kernel: [  426.587777] i2c_designware i2c_designware.1: timeout waiting for bus ready
    

    Test recipe:
    kernel: https://github.com/thesofproject/linux/tree/integration/soundwire-latest commit: 391b5f9
    FW: https://github.com/thesofproject/sof/commits/master commit: fb068e6-2
    tplg: same path as FW branch, sof-cml-rt711-rt1308-mono-rt715.tplg
    platform: CML SDW Laptop with ALC711+ ALC1308+ ALC715

    kern.log

  6. plbossart commented on Nov 11, 2019

    @plbossart
    Member

    @YvonneYang2 For me when I try to suspend in 'deep' mode the device reboots. I can't reproduce your sighting.

    @RanderWang can you clarify your finding, I don't see anything connected to I2S in /proc/irq

    /proc/irq/160# ls -l
    total 0
    -r--r--r-- 1 root root 0 Nov 11 17:55 affinity_hint
    dr-xr-xr-x 2 root root 0 Nov 11 17:55 AudioDSP
    dr-xr-xr-x 2 root root 0 Nov 11 17:55 AudioHDA
    -r--r--r-- 1 root root 0 Nov 11 17:55 effective_affinity
    -r--r--r-- 1 root root 0 Nov 11 17:55 effective_affinity_list
    -r--r--r-- 1 root root 0 Nov 11 17:55 node
    -rw-r--r-- 1 root root 0 Nov 11 17:54 smp_affinity
    -rw-r--r-- 1 root root 0 Nov 11 17:55 smp_affinity_list
    dr-xr-xr-x 2 root root 0 Nov 11 17:55 soundwire_intel_init
    -r--r--r-- 1 root root 0 Nov 11 17:55 spurious
    
  7. bardliao commented on Nov 12, 2019

    @bardliao
    Collaborator

    I can always see the i2c timeout on my sdw laptop even though SOF modules are not loaded. My reproduce procedures is.

    1. blacklist snd_sof_pci
    2. reboot the device
    3. echo deep>/sys/power/mem_sleep
    4. sudo rtcwake -m mem -s 5
    5. dmesg and I will see "i2c_designware i2c_designware.0: controller timed out"
  8. RanderWang commented on Nov 12, 2019

    @RanderWang

    @YvonneYang2 For me when I try to suspend in 'deep' mode the device reboots. I can't reproduce your sighting.

    @RanderWang can you clarify your finding, I don't see anything connected to I2S in /proc/irq

    oh, I am using legacy IRQ, so I got this finding

    root@dell-cml:/proc/irq/17# ls -l
    total 0
    -r--r--r-- 1 root root 0 10月 20 21:01 affinity_hint
    dr-xr-xr-x 2 root root 0 10月 20 21:01 AudioDSP
    dr-xr-xr-x 2 root root 0 10月 20 21:01 AudioHDA
    -r--r--r-- 1 root root 0 10月 20 21:01 effective_affinity
    -r--r--r-- 1 root root 0 10月 20 21:01 effective_affinity_list
    dr-xr-xr-x 2 root root 0 10月 20 21:01 i2c_designware.1
    -r--r--r-- 1 root root 0 10月 20 21:01 node
    -rw-r--r-- 1 root root 0 10月 20 21:00 smp_affinity
    -rw-r--r-- 1 root root 0 10月 20 21:01 smp_affinity_list
    dr-xr-xr-x 2 root root 0 10月 20 21:01 soundwire_intel_init
    -r--r--r-- 1 root root 0 10月 20 21:01 spurious

  9. plbossart commented on Nov 12, 2019

    @plbossart
    Member

    Thanks @RanderWang. This is very odd, we are probably missing patches related to i2C
    @andy-shev, does this I2C error message ring a bell by any chance?

  10. YvonneYang2 commented on Nov 13, 2019

    @YvonneYang2
    Author

    Issue cannot be reproduced after revert thesofproject/kconfig@925f684 in kconfig.

    Test recipe:
    kernel: https://github.com/thesofproject/linux/tree/integration/soundwire-latest commit: fb40b85 + PR1451
    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

  11. plbossart commented on Nov 13, 2019

    @plbossart
    Member

    ok, so it's not an SOF but, but unfortunately we cannot revert this in the Kconfig. The same settings will be set by Ubuntu/Fedora/others to enable the touch pad.

    I think the only solution is to make MSI work... That's what it was invented for, deal with more devices without issues with interrupt sharing.

  12. andy-shev commented on Nov 13, 2019

    @andy-shev

    @jhnikula perhaps knows more. To me it sounds like ASL might do some nasty stuff on powered on devices...

  13. added
    MSIIssues observed only in MSI mode
    SDW_DEVSDW bug reproduced by developers, fix WIP
    on Nov 13, 2019
  14. ClarexZhou commented on Nov 20, 2019

    @ClarexZhou

    Error also seen without SOF.
    Won't fix for not sof bug. Close.

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

    CMLApplies to Comet Lake platformMSIIssues observed only in MSI modeSDWApplies to SoundWire bus for codec connectionSDW_DEVSDW bug reproduced by developers, fix WIPbugSomething 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