Skip to content

[BUG][SDW]Shows ipc timed out for 0x30010000 size 76 when run system boot up stress test. #1395

Closed
Closed
[BUG][SDW]Shows ipc timed out for 0x30010000 size 76 when run system boot up stress test.#1395
Assignees
bardliao
Labels
CMLApplies to Comet Lake platformMSIIssues observed only in MSI modeP1Blocker bugs or important featuresSDWApplies to SoundWire bus for codec connectionSDW_DEVSDW bug reproduced by developers, fix WIPbugSomething isn't working

Description

@YvonneYang2
YvonneYang2
opened on Oct 30, 2019

Describe the bug
Shows ipc timed out for 0x30010000 size 76 when run system reboot stress test. Failed at 22nd time.

To Reproduce

  1. Run reboot stress test via "./test-reboot.sh 100"

frequency
Run 100 times, failed at 22nd time.

Expected result
System boot up without any error

Actual result
System bootup with ipc timed out for 0x30010000 size 76

kernel: https://github.com/thesofproject/linux/tree/integration/soundwire-latest commit: 661d261 + PR1359
FW: https://github.com/thesofproject/sof/commits/master commit: 0e8cf66
tplg: https://github.com/bardliao/sof/commits/soundwire-tplg (commit: 0408153), sof-cml-rt711-rt1308-rt715.tplg
platform: CML SDW Laptop with ALC711+ ALC1308+ ALC715

dmesg

[    2.918676] rt715 sdw:3:25d:715:0: [rt715_sdw_write] 4c1d <= 00d0
[    2.918715] rt715 sdw:3:25d:715:0: [rt715_sdw_write] 4d1d <= 0011
[    3.424814] sof-audio-pci 0000:00:1f.3: error: ipc timed out for 0x30010000 size 76
[    3.424817] sof-audio-pci 0000:00:1f.3: info: preventing DSP entering D3 state to preserve context
[    3.424821] sof-audio-pci 0000:00:1f.3: status: fw entered - code 00000005
[    3.425074] sof-audio-pci 0000:00:1f.3: error: unexpected fault 0x00000000 trace 0x00004000
[    3.425079] sof-audio-pci 0000:00:1f.3: error: hda irq intsts 0x80000000 intlctl 0xc0000001 rirb 00
[    3.425080] sof-audio-pci 0000:00:1f.3: error: dsp irq ppsts 0x80000000 adspis 0x00000001
[    3.425083] sof-audio-pci 0000:00:1f.3: error: host status 0x80000000 dsp status 0x00000000 mask 0x00000003
[    3.425084] sof-audio-pci 0000:00:1f.3: error: waking up any trace sleepers
[    3.425087] sof-audio-pci 0000:00:1f.3: error: DSP failed to add widget id 0 type 24 name : PCM1C stream Passthrough Capture 1 reply 0
[    3.425090] sof-audio-pci 0000:00:1f.3: ASoC: failed to load widget PCM1C
[    3.425095] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x1010f0f successful
[    3.425098] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x1000f0f successful
[    3.425100] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 0 : core_mask 1
[    3.425102] sof-audio-pci 0000:00:1f.3: error: tplg component load failed -110
[    3.425107] sof-audio-pci 0000:00:1f.3: error: failed to load DSP topology -22
[    3.425108] sof-audio-pci 0000:00:1f.3: ASoC: failed to probe component -22
[    3.425119] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: ASoC: failed to instantiate card -22
[    3.425133] rt711 sdw:0:25d:711:0: rt711_set_jack_detect hw_init not ready yet
[    3.425176] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: snd_soc_register_card failed -22
[    3.425181] sdw_rt711_rt1308_rt715: probe of sdw_rt711_rt1308_rt715 failed with error -22
[    4.930394] rfkill: input handler disabled
[    4.968778] intel-sdw sdw-master-3: IO transfer timed out
[    4.968785] rt715 sdw:3:25d:715:0: [rt715_sdw_write] 4e1d <= 00a1
[    4.968792] intel-sdw sdw-master-0: IO transfer timed out
[    4.968796] rt711 sdw:0:25d:711:0: [rt711_sdw_write] 7520 85a0 7420 84a0 <= 004a 201b
[    5.032778] intel-sdw sdw-master-1: SCP Msg trf timed out
[    7.017775] intel-sdw sdw-master-0: IO transfer timed out
[    7.017782] intel-sdw sdw-master-3: IO transfer timed out
[    7.017785] rt715 sdw:3:25d:715:0: [rt715_sdw_write] 4f1d <= 0081
[    7.080779] intel-sdw sdw-master-1: SCP Msg trf timed out
[    9.064823] intel-sdw sdw-master-3: IO transfer timed out
[    9.064831] rt715 sdw:3:25d:715:0: [rt715_sdw_write] 4c29 <= 00d1

dmesg_failed_22.log

Activity

  1. YvonneYang2
    changed the title [-]ipc[/-] [+][BUG][SDW]Shows ipc timed out for 0x30010000 size 76 when run system boot up stress test.[/+] on Oct 30, 2019
  2. YvonneYang2
    added
    bugSomething isn't working
    CMLApplies to Comet Lake platform
    SDWApplies to SoundWire bus for codec connection
    on Oct 30, 2019
  3. plbossart
    added
    SDW_DEVSDW bug reproduced by developers, fix WIP
    on Oct 30, 2019

  4. plbossart commented on Oct 30, 2019

    @plbossart
    plbossart
    on Oct 30, 2019
    Member

    @YvonneYang2 can you try with MSI disabled?

  5. YvonneYang2 commented on Oct 31, 2019

    @YvonneYang2
    YvonneYang2
    on Oct 31, 2019
    Author

    Test it 100 times with MSI disabled, issue cannot be reproduced.

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

  6. plbossart commented on Oct 31, 2019

    @plbossart
    plbossart
    on Oct 31, 2019
    Member

    Thanks @YvonneYang2 this helps. @bardliao I think this is an indication we do need to have a single handler for the shared interrupt, we still have 3 (IPC, stream, soundwire).

  7. YvonneYang2 commented on Nov 1, 2019

    @YvonneYang2
    YvonneYang2
    on Nov 1, 2019
    Author

    @plbossart
    Test it 45 times with MSI disabled again on Ubuntu19.04, issue is reproduced once at 20th time. I Will test more times on Ubuntu18.04 next week.

    Add options snd_sof_intel_hda_common use_msi=0 in /etc/modprobe.d/alsa-base.conf to disable MSI.

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

    dmesg 
    [    2.788612] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[    2.788632] rt715 sdw:3:25d:715:0: [rt715_sdw_write] 4e13 <= 00a1
[    2.788670] rt715 sdw:3:25d:715:0: [rt715_sdw_write] 4f13 <= 0081
[    2.955667] urandom_read: 5 callbacks suppressed
[    2.955669] random: unattended-upgr: uninitialized urandom read (24 bytes read)
[    3.010336] random: plymouthd: uninitialized urandom read (8 bytes read)
[    3.079915] asix 1-6.1:1.0 eth0: register 'asix' at usb-0000:00:14.0-6.1, ASIX AX88772 USB 2.0 Ethernet, 00:0e:c6:b7:2c:3c
[    3.079942] usbcore: registered new interface driver asix
[    3.089022] asix 1-6.1:1.0 enx000ec6b72c3c: renamed from eth0
[    3.296352] sof-audio-pci 0000:00:1f.3: error: ipc timed out for 0x30010000 size 76
[    3.296361] sof-audio-pci 0000:00:1f.3: info: preventing DSP entering D3 state to preserve context
[    3.296371] sof-audio-pci 0000:00:1f.3: status: fw entered - code 00000005
[    3.296628] sof-audio-pci 0000:00:1f.3: error: unexpected fault 0x00000000 trace 0x00004000
[    3.296638] sof-audio-pci 0000:00:1f.3: error: hda irq intsts 0x80000000 intlctl 0xc0000001 rirb 00
[    3.296642] sof-audio-pci 0000:00:1f.3: error: dsp irq ppsts 0x80000000 adspis 0x00000001
[    3.296649] sof-audio-pci 0000:00:1f.3: error: host status 0x80000000 dsp status 0x00000000 mask 0x00000003
[    3.296652] sof-audio-pci 0000:00:1f.3: error: waking up any trace sleepers
[    3.296662] sof-audio-pci 0000:00:1f.3: error: DSP failed to add widget id 0 type 24 name : PCM1C stream Passthrough Capture 1 reply 0
[    3.296672] sof-audio-pci 0000:00:1f.3: ASoC: failed to load widget PCM1C
[    3.296685] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x1010f0f successful
[    3.296692] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f successful
[    3.296696] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 0 : core_mask 1
[    3.296704] sof-audio-pci 0000:00:1f.3: error: tplg component load failed -110
[    3.296721] sof-audio-pci 0000:00:1f.3: error: failed to load DSP topology -22
[    3.296725] sof-audio-pci 0000:00:1f.3: ASoC: failed to probe component -22
[    3.296760] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: ASoC: failed to instantiate card -22
[    3.296797] rt711 sdw:0:25d:711:0: rt711_set_jack_detect hw_init not ready yet
[    3.296940] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: snd_soc_register_card failed -22
[    3.296951] sdw_rt711_rt1308_rt715: probe of sdw_rt711_rt1308_rt715 failed with error -22
[    4.234039] random: crng init done
[    4.298149] broken atomic modeset userspace detected, disabling atomic
[    4.840038] intel-sdw sdw-master-3: IO transfer timed out
[    4.840045] rt715 sdw:3:25d:715:0: [rt715_sdw_write] 4c1d <= 00d0
[    4.840051] intel-sdw sdw-master-0: IO transfer timed out
[    4.840054] rt711 sdw:0:25d:711:0: [rt711_sdw_write] 7309 8389 <= 6080
[    4.904091] intel-sdw sdw-master-1: SCP Msg trf timed out
[    6.476229] rfkill: input handler disabled
[    6.888045] intel-sdw sdw-master-0: IO transfer timed out
[    6.888056] intel-sdw sdw-master-3: IO transfer timed out
[    6.888059] rt715 sdw:3:25d:715:0: [rt715_sdw_write] 4d1d <= 0011
[    6.952073] intel-sdw sdw-master-1: SCP Msg trf timed out
[    8.936348] intel-sdw sdw-master-3: IO transfer timed out
[    8.936366] rt715 sdw:3:25d:715:0: [rt715_sdw_write] 4e1d <= 00a1

    dmesg_failed_20.log

  8. YvonneYang2 commented on Nov 5, 2019

    @YvonneYang2
    YvonneYang2
    on Nov 5, 2019
    Author

    Tested it 53 times with MSI interrupt mode, occurred "error: ipc timed out for 0x90030000 size 80", then occurred "ipc timed out for 0x30010000 size 76". Error dmesg is as below :

    MSI interrupt mode error dmesg 
    [    3.004132] intel-sdw sdw-master-1: in sdw_assign_device_num
[    3.004132] intel-sdw sdw-master-1: in sdw_assign_device_num, writing dev_num 1
[    3.247067] asix 1-6.1:1.0 eth0: register 'asix' at usb-0000:00:14.0-6.1, ASIX AX88772 USB 2.0 Ethernet, 00:0e:c6:b7:2c:3c
[    3.247161] usbcore: registered new interface driver asix
[    3.254287] asix 1-6.1:1.0 enx000ec6b72c3c: renamed from eth0
[    3.311596] systemd-udevd (278) used greatest stack depth: 11816 bytes left
[    3.511668] sof-audio-pci 0000:00:1f.3: error: ipc timed out for 0x90030000 size 80
[    3.511671] sof-audio-pci 0000:00:1f.3: info: preventing DSP entering D3 state to preserve context
[    3.511676] sof-audio-pci 0000:00:1f.3: status: fw entered - code 00000005
[    3.511962] sof-audio-pci 0000:00:1f.3: error: unexpected fault 0x00000000 trace 0x00004000
[    3.511973] sof-audio-pci 0000:00:1f.3: error: hda irq intsts 0x80000000 intlctl 0xc0000000 rirb 00
[    3.511974] sof-audio-pci 0000:00:1f.3: error: dsp irq ppsts 0x80000000 adspis 0x00000001
[    3.511980] sof-audio-pci 0000:00:1f.3: error: host status 0x80000000 dsp status 0x00000000 mask 0x00000003
[    3.511981] sof-audio-pci 0000:00:1f.3: error: can't set params for DMA for trace -110
[    3.511991] sof-audio-pci 0000:00:1f.3: warning: failed to initialize trace -110
[    3.511995] sof-audio-pci 0000:00:1f.3: ASoC: dai register 0000:00:1f.3 #14
[    3.511996] sof-audio-pci 0000:00:1f.3: ASoC: dynamically register DAI 0000:00:1f.3
[    3.511997] sof-audio-pci 0000:00:1f.3: ASoC: Registered DAI 'SSP0 Pin'
[    3.511997] sof-audio-pci 0000:00:1f.3: ASoC: dynamically register DAI 0000:00:1f.3
[    3.511998] sof-audio-pci 0000:00:1f.3: ASoC: Registered DAI 'SSP1 Pin'
[    3.511999] sof-audio-pci 0000:00:1f.3: ASoC: dynamically register DAI 0000:00:1f.3
[    3.511999] sof-audio-pci 0000:00:1f.3: ASoC: Registered DAI 'SSP2 Pin'
[    3.512000] sof-audio-pci 0000:00:1f.3: ASoC: dynamically register DAI 0000:00:1f.3
[    3.512000] sof-audio-pci 0000:00:1f.3: ASoC: Registered DAI 'SSP3 Pin'
[    3.512001] sof-audio-pci 0000:00:1f.3: ASoC: dynamically register DAI 0000:00:1f.3
[    3.512001] sof-audio-pci 0000:00:1f.3: ASoC: Registered DAI 'SSP4 Pin'
[    3.512002] sof-audio-pci 0000:00:1f.3: ASoC: dynamically register DAI 0000:00:1f.3
[    3.512002] sof-audio-pci 0000:00:1f.3: ASoC: Registered DAI 'SSP5 Pin'
[    3.512003] sof-audio-pci 0000:00:1f.3: ASoC: dynamically register DAI 0000:00:1f.3
[    3.512004] sof-audio-pci 0000:00:1f.3: ASoC: Registered DAI 'DMIC01 Pin'
[    3.512004] sof-audio-pci 0000:00:1f.3: ASoC: dynamically register DAI 0000:00:1f.3
[    3.512005] sof-audio-pci 0000:00:1f.3: ASoC: Registered DAI 'DMIC16k Pin'
[    3.512005] sof-audio-pci 0000:00:1f.3: ASoC: dynamically register DAI 0000:00:1f.3
[    3.512006] sof-audio-pci 0000:00:1f.3: ASoC: Registered DAI 'iDisp1 Pin'
[    3.512006] sof-audio-pci 0000:00:1f.3: ASoC: dynamically register DAI 0000:00:1f.3
[    3.512007] sof-audio-pci 0000:00:1f.3: ASoC: Registered DAI 'iDisp2 Pin'
[    3.512007] sof-audio-pci 0000:00:1f.3: ASoC: dynamically register DAI 0000:00:1f.3
[    3.512008] sof-audio-pci 0000:00:1f.3: ASoC: Registered DAI 'iDisp3 Pin'
[    3.512009] sof-audio-pci 0000:00:1f.3: ASoC: dynamically register DAI 0000:00:1f.3
[    3.512011] sof-audio-pci 0000:00:1f.3: ASoC: Registered DAI 'Analog CPU DAI'
[    3.512011] sof-audio-pci 0000:00:1f.3: ASoC: dynamically register DAI 0000:00:1f.3
[    3.512012] sof-audio-pci 0000:00:1f.3: ASoC: Registered DAI 'Digital CPU DAI'
[    3.512012] sof-audio-pci 0000:00:1f.3: ASoC: dynamically register DAI 0000:00:1f.3
[    3.512013] sof-audio-pci 0000:00:1f.3: ASoC: Registered DAI 'Alt Analog CPU DAI'
[    3.512057] sof-audio-pci 0000:00:1f.3: created machine sdw_rt711_rt1308_rt715
[    3.512058] sof-audio-pci 0000:00:1f.3: Completing SOF PCI probe
[    3.513830] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: Entry mc_probe
[    3.513836] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: info: override BE DAI link SDW0-Playback
[    3.513836] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: info: override BE DAI link SDW0-Capture
[    3.513837] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: info: override BE DAI link SDW1-Playback
[    3.513838] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: info: override BE DAI link SDW3-Capture
[    3.513838] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: info: override BE DAI link iDisp1
[    3.513839] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: info: override BE DAI link iDisp2
[    3.513839] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: info: override BE DAI link iDisp3
[    3.513841] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: ASoC: binding SDW0-Playback
[    3.513852] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: ASoC: binding SDW0-Capture
[    3.513857] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: ASoC: binding SDW1-Playback
[    3.513862] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: ASoC: binding SDW3-Capture
[    3.513866] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: ASoC: binding iDisp1
[    3.513870] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: ASoC: binding iDisp2
[    3.513874] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: ASoC: binding iDisp3
[    3.513906] rt711 sdw:0:25d:711:0: ASoC: adding DP3 Playback widget
[    3.513907] rt711 sdw:0:25d:711:0: ASoC: adding DP4 Capture widget
[    3.513908] rt711 sdw:0:25d:711:0: ASoC: adding DP2 Capture widget
[    3.513926] sof-audio-pci 0000:00:1f.3: loading topology:intel/sof-tplg/sof-cml-rt711-rt1308-mono-rt715.tplg
[    3.514661] sof-audio-pci 0000:00:1f.3: Topology: ABI 3:11:0 Kernel ABI 3:11:0
[    3.514663] sof-audio-pci 0000:00:1f.3: ASoC: adding 6 DAPM widgets
[    3.514665] sof-audio-pci 0000:00:1f.3: ASoC: creating DAPM widget PCM0P id 11
[    3.514667] sof-audio-pci 0000:00:1f.3: tplg: ready widget id 0 pipe 1 type 23 name : PCM0P stream Passthrough Playback 0
[    3.514668] sof-audio-pci 0000:00:1f.3: loaded host PCM0P
[    3.514669] sof-audio-pci 0000:00:1f.3:  config: periods snk 2 src 0 fmt 0
[    3.514673] sof-audio-pci 0000:00:1f.3: ipc tx: 0x30010000: GLB_TPLG_MSG: COMP_NEW
[    4.015659] sof-audio-pci 0000:00:1f.3: error: ipc timed out for 0x30010000 size 76
[    4.015663] sof-audio-pci 0000:00:1f.3: info: preventing DSP entering D3 state to preserve context
[    4.015668] sof-audio-pci 0000:00:1f.3: status: fw entered - code 00000005
[    4.015973] sof-audio-pci 0000:00:1f.3: error: unexpected fault 0x00000000 trace 0x00004000
[    4.015984] sof-audio-pci 0000:00:1f.3: error: hda irq intsts 0x80000000 intlctl 0xc0000000 rirb 00
[    4.015985] sof-audio-pci 0000:00:1f.3: error: dsp irq ppsts 0x80000000 adspis 0x00000001
[    4.015991] sof-audio-pci 0000:00:1f.3: error: host status 0x80000000 dsp status 0x90020000 mask 0x00000003
[    4.015994] sof-audio-pci 0000:00:1f.3: error: DSP failed to add widget id 0 type 23 name : PCM0P stream Passthrough Playback 0 reply 0
[    4.015998] sof-audio-pci 0000:00:1f.3: ASoC: failed to load widget PCM0P
[    4.015999] sof-audio-pci 0000:00:1f.3: error: tplg component load failed -110
[    4.016004] sof-audio-pci 0000:00:1f.3: error: failed to load DSP topology -22
[    4.016006] sof-audio-pci 0000:00:1f.3: ASoC: failed to probe component -22
[    4.016016] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: ASoC: failed to instantiate card -22
[    4.016030] rt711 sdw:0:25d:711:0: rt711_set_jack_detect hw_init not ready yet
[    4.016072] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: snd_soc_register_card failed -22
[    4.016076] sdw_rt711_rt1308_rt715: probe of sdw_rt711_rt1308_rt715 failed with error -22
[    5.032618] intel-sdw sdw-master-1: IO transfer timed out
[    5.032624] intel-sdw sdw-master-0: IO transfer timed out
[    5.170870] rfkill: input handler disabled
[    6.714481] intel-sdw sdw-master-1: intel_suspend_runtime start

    logs:
    dmesg_failed_53.log

    Tested it 300 times with MSI disabled mode, original issue didn't occur. But occurred " platform regulatory.0: Direct firmware load for regulatory.db failed with error -2 ". Failed at 141th and 203th time. Reproduced rate is 2/300. Error dmesg is as below:

    MSI disabled error dmesg 
    [    0.913333] printk: console [netcon0] enabled
[    0.913333] netconsole: network logging started
[    0.913361] cfg80211: Loading compiled-in X.509 certificates for regulatory database
[    0.914635] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
[    0.914662] platform regulatory.0: Direct firmware load for regulatory.db failed with error -2
[    0.914662] cfg80211: failed to load regulatory.db
[    1.072605] nvme nvme0: missing or invalid SUBNQN field.
[    1.074475] nvme nvme0: 8/0/0 default/read/poll queues
[    1.077015]  nvme0n1: p1 p2
[    1.077629] Freeing unused kernel image memory: 1308K
[    1.086186] Write protecting the kernel read-only data: 18432k
[    1.086583] Freeing unused kernel image memory: 2008K
[    1.086742] Freeing unused kernel image memory: 1124K
[    1.086744] Run /init as init process
[    1.127264] udevadm (165) used greatest stack depth: 13776 bytes left
[    1.132127] xhci_hcd 0000:00:14.0: xHCI Host Controller
[    1.132166] xhci_hcd 0000:00:14.0: new USB bus registered, assigned bus number 1
[    1.133259] xhci_hcd 0000:00:14.0: hcc params 0x200077c1 hci version 0x110 quirks 0x0000000000009810
[    1.133264] xhci_hcd 0000:00:14.0: cache line size of 64 is not supported
[    1.133523] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.04
[    1.133524] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    1.133526] usb usb1: Product: xHCI Host Controller
[    1.133527] usb usb1: Manufacturer: Linux 5.4.0-rc4-sdw-validation-20191104-olyp-v2-0-0e6065c xhci-hcd
[    1.133528] usb usb1: SerialNumber: 0000:00:14.0
[    1.133694] hub 1-0:1.0: USB hub found
[    1.133711] hub 1-0:1.0: 12 ports detected
[    1.134950] xhci_hcd 0000:00:14.0: xHCI Host Controller
[    1.134988] xhci_hcd 0000:00:14.0: new USB bus registered, assigned bus number 2

    logs:
    dmesg_failed_141.log
    logger_failed_203.log

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

  9. plbossart commented on Nov 5, 2019

    @plbossart
    plbossart
    on Nov 5, 2019
    Member

    Thanks @YvonneYang2

    I think we can assume for now that the MSI mode is still problematic. The issue with MSI disabled has nothing to do with SOF so we can ignore it.

    @bardliao can you work with @YvonneYang2 to see if your interrupt rework works better with MSI enabled? Thanks!

  10. YvonneYang2 commented on Nov 6, 2019

    @YvonneYang2
    YvonneYang2
    on Nov 6, 2019
    Author

    Tested it with latest integration/soundwire-latest + #1412 , issue can still be reproduced.

    Tested it 300 times, original issue occurred 4 times.

    ipc timed out for 0x30010000 size 84 dmesg log 
    [    3.270400] asix 1-6.1:1.0 eth0: register 'asix' at usb-0000:00:14.0-6.1, ASIX AX88772 USB 2.0 Ethernet, 00:0e:c6:b7:2c:3c
[    3.270422] usbcore: registered new interface driver asix
[    3.271950] asix 1-6.1:1.0 enx000ec6b72c3c: renamed from eth0
[    3.528375] sof-audio-pci 0000:00:1f.3: error: ipc timed out for 0x30010000 size 84
[    3.528378] sof-audio-pci 0000:00:1f.3: info: preventing DSP entering D3 state to preserve context
[    3.528382] sof-audio-pci 0000:00:1f.3: status: fw entered - code 00000005
[    3.528635] sof-audio-pci 0000:00:1f.3: error: unexpected fault 0x00000000 trace 0x00004000
[    3.528641] sof-audio-pci 0000:00:1f.3: error: hda irq intsts 0x80000000 intlctl 0xc0000001 rirb 00
[    3.528642] sof-audio-pci 0000:00:1f.3: error: dsp irq ppsts 0x80000000 adspis 0x00000001
[    3.528645] sof-audio-pci 0000:00:1f.3: error: host status 0x80000000 dsp status 0x00000000 mask 0x00000003
[    3.528646] sof-audio-pci 0000:00:1f.3: error: waking up any trace sleepers
[    3.528648] sof-audio-pci 0000:00:1f.3: error: DSP failed to add widget id 0 type 6 name : PGA2.0 stream none reply 0
[    3.528651] sof-audio-pci 0000:00:1f.3: ASoC: failed to load widget PGA2.0
[    3.528657] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x1010f0f successful
[    3.528660] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x1000f0f successful
[    3.528662] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 0 : core_mask 1
[    3.528664] sof-audio-pci 0000:00:1f.3: error: tplg component load failed -110
[    3.528669] sof-audio-pci 0000:00:1f.3: error: failed to load DSP topology -22
[    3.528670] sof-audio-pci 0000:00:1f.3: ASoC: failed to probe component -22
[    3.528680] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: ASoC: failed to instantiate card -22
[    3.528695] rt711 sdw:0:25d:711:0: rt711_set_jack_detect hw_init not ready yet
[    3.528737] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: snd_soc_register_card failed -22
[    3.528742] sdw_rt711_rt1308_rt715: probe of sdw_rt711_rt1308_rt715 failed with error -22
[    3.529604] systemd-udevd (268) used greatest stack depth: 12280 bytes left
[    3.530243] systemd-udevd (269) used greatest stack depth: 11608 bytes left
[    5.031401] intel-sdw sdw-master-0: IO transfer timed out
[    5.126618] rfkill: input handler disabled
[    5.159346] intel-sdw sdw-master-1: SCP Msg trf timed out
[    6.716006] intel-sdw sdw-master-3: intel_suspend_runtime start
[    6.716018] intel-sdw sdw-master-3: intel_suspend_runtime done
[    7.079448] intel-sdw sdw-master-0: IO transfer timed out

    dmesg_failed_54.log

    Beside, occurred 3 times "ipc timed out for 0x30200000 size 36"

    ipc timed out for 0x30200000 size 36 dmesg log 
    [    3.277592] asix 1-6.1:1.0 eth0: register 'asix' at usb-0000:00:14.0-6.1, ASIX AX88772 USB 2.0 Ethernet, 00:0e:c6:b7:2c:3c
[    3.277629] usbcore: registered new interface driver asix
[    3.279548] asix 1-6.1:1.0 enx000ec6b72c3c: renamed from eth0
[    3.550745] sof-audio-pci 0000:00:1f.3: error: ipc timed out for 0x30200000 size 36
[    3.550754] sof-audio-pci 0000:00:1f.3: info: preventing DSP entering D3 state to preserve context
[    3.550763] sof-audio-pci 0000:00:1f.3: status: fw entered - code 00000005
[    3.551020] sof-audio-pci 0000:00:1f.3: error: unexpected fault 0x00000000 trace 0x00004000
[    3.551030] sof-audio-pci 0000:00:1f.3: error: hda irq intsts 0x80000000 intlctl 0xc0000001 rirb 00
[    3.551034] sof-audio-pci 0000:00:1f.3: error: dsp irq ppsts 0x80000000 adspis 0x00000001
[    3.551041] sof-audio-pci 0000:00:1f.3: error: host status 0x80000000 dsp status 0x00000000 mask 0x00000003
[    3.551045] sof-audio-pci 0000:00:1f.3: error: waking up any trace sleepers
[    3.551051] sof-audio-pci 0000:00:1f.3: error: buffer BUF1.0 load failed
[    3.551058] sof-audio-pci 0000:00:1f.3: error: DSP failed to add widget id 0 type 31 name : BUF1.0 stream none reply 0
[    3.551067] sof-audio-pci 0000:00:1f.3: ASoC: failed to load widget BUF1.0
[    3.551075] sof-audio-pci 0000:00:1f.3: error: tplg component load failed -110
[    3.551091] sof-audio-pci 0000:00:1f.3: error: failed to load DSP topology -22
[    3.551095] sof-audio-pci 0000:00:1f.3: ASoC: failed to probe component -22
[    3.551129] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: ASoC: failed to instantiate card -22
[    3.551167] rt711 sdw:0:25d:711:0: rt711_set_jack_detect hw_init not ready yet
[    3.551314] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: snd_soc_register_card failed -22
[    3.551325] sdw_rt711_rt1308_rt715: probe of sdw_rt711_rt1308_rt715 failed with error -22
[    3.554367] systemd-udevd (279) used greatest stack depth: 12280 bytes left
[    3.555067] systemd-udevd (282) used greatest stack depth: 11576 bytes left
[    4.961855] rfkill: input handler disabled
[    5.094460] intel-sdw sdw-master-3: IO transfer timed out
[    5.094467] rt715 sdw:3:25d:715:0: [rt715_sdw_write] 4e29 <= 00a1
[    5.094476] intel-sdw sdw-master-0: IO transfer timed out
[    5.158462] intel-sdw sdw-master-1: SCP Msg trf timed out
[    7.142501] intel-sdw sdw-master-0: IO transfer timed out
[    7.142511] intel-sdw sdw-master-3: IO transfer timed out

    dmesg_failed_115.log

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

  11. bardliao
    self-assigned this
    on Nov 6, 2019
  12. mengdonglin
    added
    MSIIssues observed only in MSI mode
    on Nov 13, 2019

  13. YvonneYang2 commented on Nov 13, 2019

    @YvonneYang2
    YvonneYang2
    on Nov 13, 2019
    Author

    Issue cannot be reproduced in 120 times test-reboot stress test with #1451

    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

  14. mengdonglin
    added
    P1Blocker bugs or important features
    on Nov 20, 2019

  15. mengdonglin commented on Nov 25, 2019

    @mengdonglin
    mengdonglin
    on Nov 25, 2019

    @YvonneYang2 Please verify latest ttps://github.com/thesofproject/linux/tree/integration/soundwire-latest

    PR #1451 was replaced by PR #1483, and PR #1483 was merged by integration/soundwire-latest

  16. YvonneYang2 commented on Nov 25, 2019

    @YvonneYang2
    YvonneYang2
    on Nov 25, 2019
    Author

    Ipc timed out for 0x30010000 issue can still be reproduced after #1483 merged.

    Run 100 times, failed at 75th time.

    Dmesg

    [    3.234395] usbcore: registered new interface driver asix
[    3.238337] asix 1-6.1:1.0 enx000ec6c686d3: renamed from eth0
[    3.274670] systemd-udevd (274) used greatest stack depth: 11176 bytes left
[    3.326875] sof-audio-pci 0000:00:1f.3: error: ipc timed out for 0x30010000 size 76
[    3.326879] sof-audio-pci 0000:00:1f.3: info: preventing DSP entering D3 state to preserve context
[    3.326885] sof-audio-pci 0000:00:1f.3: status: fw entered - code 00000005
[    3.327127] sof-audio-pci 0000:00:1f.3: error: unexpected fault 0x00000000 trace 0x00004000
[    3.327133] sof-audio-pci 0000:00:1f.3: error: hda irq intsts 0x80000000 intlctl 0xc0000001 rirb 00
[    3.327134] sof-audio-pci 0000:00:1f.3: error: dsp irq ppsts 0x80000000 adspis 0x00000001
[    3.327138] sof-audio-pci 0000:00:1f.3: error: host status 0x80000000 dsp status 0x00000000 mask 0x00000003
[    3.327139] sof-audio-pci 0000:00:1f.3: error: waking up any trace sleepers
[    3.327143] sof-audio-pci 0000:00:1f.3: error: DSP failed to add widget id 0 type 23 name : PCM5P stream Passthrough Playback 5 reply 0
[    3.327146] sof-audio-pci 0000:00:1f.3: ASoC: failed to load widget PCM5P
[    3.327156] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x1010f0f successful
[    3.327159] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x1000f0f successful
[    3.327161] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 0 : core_mask 1
[    3.327166] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f successful
[    3.327170] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0xf0f successful
[    3.327171] sof-audio-pci 0000:00:1f.3: DSP core(s) enabled? 0 : core_mask 1

    Test recipe:
    kernel: https://github.com/thesofproject/linux/tree/integration/soundwire-latest commit: 68cadd8
    FW: https://github.com/thesofproject/sof/commits/master commit: 9b5dc8c
    tplg: Same with FW branch, sof-cml-rt711-rt1308-mono-rt715.tplg
    platform: CML Laptop with ALC711+ ALC1308+ ALC715

    dmesg_failed_75.log

  17. bardliao commented on Nov 25, 2019

    @bardliao
    bardliao
    on Nov 25, 2019
    Collaborator

    @YvonneYang2 Could you retest it with #1543?

  18. YvonneYang2 commented on Nov 25, 2019

    @YvonneYang2
    YvonneYang2
    on Nov 25, 2019
    Author

    Run reboot stress test 300 times with #1543 in MSI IRQ mode, issue cannot be reproduced.

    Test recipe:
    kernel: https://github.com/thesofproject/linux/tree/integration/soundwire-latest commit: 68cadd8 + #1543
    FW: https://github.com/thesofproject/sof/commits/master commit: d6fe2b1
    tplg: Same with FW branch, sof-cml-rt711-rt1308-mono-rt715.tplg
    platform: CML Laptop with ALC711+ ALC1308+ ALC715

  19. plbossart commented on Nov 25, 2019

    @plbossart
    plbossart
    on Nov 25, 2019
    Member

    @bardliao @YvonneYang2 I wonder if in MSI mode we need to avoid disabling interrupts?

    @lyakh suggested we don't, and I suggested an update here:

    1cce7a3

  20. bardliao commented on Nov 26, 2019

    @bardliao
    bardliao
    on Nov 26, 2019
    Collaborator

    @bardliao @YvonneYang2 I wonder if in MSI mode we need to avoid disabling interrupts?

    @lyakh suggested we don't, and I suggested an update here:

    1cce7a3

    @plbossart I just tested #1476 with interrupt not disabled, but it didn't work while #1547 works on the same issue

  21. YvonneYang2 commented on Nov 27, 2019

    @YvonneYang2
    YvonneYang2
    on Nov 27, 2019
    Author

    Tested it 500 times with #1548 , issue cannot be reproduced.

    kernel: https://github.com/thesofproject/linux/tree/integration/soundwire-latest commit: a370cb0 + #1548
    FW: https://github.com/thesofproject/sof/commits/master commit: db7671a
    tplg: Same with FW branch, sof-cml-rt711-rt1308-mono-rt715.tplg
    platform: CML Laptop with ALC711+ ALC1308+ ALC715 in SDW mode

  22. YvonneYang2 commented on Nov 28, 2019

    @YvonneYang2
    YvonneYang2
    on Nov 28, 2019
    Author

    Tested it 500 times after #1538 merged into integration/soundwire-latest , issue cannot be reproduced. Close the bug, track other reboot issue in #1558

    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 FW branch, sof-cml-rt711-rt1308-mono-rt715.tplg
    platform: CML Laptop with ALC711+ ALC1308+ ALC715 in SDW mode

  23. YvonneYang2
    closed this as completedon Nov 28, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

Labels

CMLApplies to Comet Lake platformMSIIssues observed only in MSI modeP1Blocker bugs or important featuresSDWApplies to SoundWire bus for codec connectionSDW_DEVSDW bug reproduced by developers, fix WIPbugSomething isn't working

Type

No type

Projects

No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions