Skip to content

[SDW][BUG]IO transfer timed out occurred during multi-pipline stress test #1555

New issue
New issue
Closed
Closed
[SDW][BUG]IO transfer timed out occurred during multi-pipline stress test#1555
Assignees
bardliao
Labels
CMLApplies to Comet Lake platformMSIIssues observed only in MSI modeSDWApplies to SoundWire bus for codec connectionbugSomething isn't working

Description

@YvonneYang2
YvonneYang2
opened on Nov 27, 2019

Describe the bug
Occurred IO transfer timed out when run multi-pipline stress test.

To Reproduce

  1. Boot up
  2. Run with comman "./multiplex_pipeline-test_update.sh pcm0p pcm2p pcm5p pcm1c pcm4c"

script:
multiplex_pipeline-test_update.sh.txt

Reproduced rate
Round1 : Run 300 times, failed at 171th time.
Round2: Run 300 times, failed at 132th time.

Expected result
Run multi-pipline stress test successfully

Actual result
Occurred IO transfer timeed out during multi-pipline stress test

Dmesg

[ 1853.884397] intel-sdw sdw-master-0: intel_startup: SDW0 Pin2: start
[ 1853.884401] intel-sdw sdw-master-0: intel_startup: SDW0 Pin2: done
[ 1853.884403]  Headphone: ASoC: open FE Headphone
[ 1853.884406] sof-audio-pci 0000:00:1f.3: pcm: open stream 0 dir 0
[ 1853.884407] sof-audio-pci 0000:00:1f.3: period min 192 max 16384 bytes
[ 1853.884408] sof-audio-pci 0000:00:1f.3: period count 2 max 16
[ 1853.884408] sof-audio-pci 0000:00:1f.3: buffer max 65536 bytes
[ 1853.884532]  SDW0-Playback: ASoC: hw_params BE SDW0-Playback
[ 1853.884535] rt711 sdw:0:25d:711:0: rt711_pcm_hw_params rt711-aif1
[ 1855.910857] intel-sdw sdw-master-0: IO transfer timed out
[ 1857.959011] intel-sdw sdw-master-0: IO transfer timed out
[ 1857.959191] rt711 sdw:0:25d:711:0: [rt711_sdw_write] 7203 8283 <= 0031
[ 1860.007068] intel-sdw sdw-master-0: IO transfer timed out

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

Logs:
failed_multipipeline_test_171_dmesg.log
failed_multipipeline_test_171_all_logger.log
multipipeline_test_132_all_logger.log
multipipeline_test_132_dmesg.log

Activity

  1. YvonneYang2
    added
    CMLApplies to Comet Lake platform
    SDWApplies to SoundWire bus for codec connection
    bugSomething isn't working
    MSIIssues observed only in MSI mode
    on Nov 27, 2019

  2. bardliao commented on Nov 27, 2019

    @bardliao
    bardliao
    on Nov 27, 2019
    Collaborator

    @YvonneYang2 Could you test it with bardliao@690b151 ?

  3. YvonneYang2 commented on Nov 28, 2019

    @YvonneYang2
    YvonneYang2
    on Nov 28, 2019
    Author

    Tested it 300 times, issue can still be reproduced with latest integration/soundwire-latest + bardliao@690b151

    Run 500 times, failed at 243th time.

    Dmesg:

    [ 2656.934491] intel-sdw sdw-master-1: intel_suspend_runtime start
[ 2656.934501] intel-sdw sdw-master-0: intel_suspend_runtime start
[ 2656.934638] intel-sdw sdw-master-1: intel_suspend_runtime done
[ 2656.935155] intel-sdw sdw-master-0: Link power down failed: -11
[ 2656.982207] intel-sdw sdw-master-3: intel_suspend_runtime start
[ 2656.982284] intel-sdw sdw-master-3: intel_suspend_runtime done
[ 2658.982463]  HDMI1: ASoC: pop wq checking: Playback status: inactive waiting: yes
[ 2658.982533]  Headphone: ASoC: pop wq checking: Playback status: inactive waiting: yes
[ 2658.982595]  SDW1-speakers: ASoC: pop wq checking: Playback status: inactive waiting: yes
[ 2661.140283]  Headphone: ASoC: found 0 audio playback paths
[ 2661.140285]  Headphone: ASoC: Headphone no valid playback route
[ 2661.140287] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: ASoC: find BE for widget ALH2.OUT
[ 2661.140288] sdw_rt711_rt1308_rt715 sdw_rt711_rt1308_rt715: ASoC: try BE : ALH2.OUT
[ 2661.140289]  Headphone: connected new DPCM playback path Headphone -> SDW0-Playback
[ 2661.140295]  Headphone: ASoC: found 1 new BE paths
[ 2661.140296]  SDW0-Playback: ASoC: open playback BE SDW0-Playback
[ 2661.140302] intel-sdw sdw-master-0: intel_startup: SDW0 Pin2: start
[ 2661.140306] intel-sdw sdw-master-0: intel_startup: SDW0 Pin2: done
[ 2661.140308]  Headphone: ASoC: open FE Headphone
[ 2661.140311] sof-audio-pci 0000:00:1f.3: pcm: open stream 0 dir 0
[ 2661.140312] sof-audio-pci 0000:00:1f.3: period min 192 max 16384 bytes
[ 2661.140313] sof-audio-pci 0000:00:1f.3: period count 2 max 16
[ 2661.140314] sof-audio-pci 0000:00:1f.3: buffer max 65536 bytes
[ 2661.140438]  SDW0-Playback: ASoC: hw_params BE SDW0-Playback
[ 2661.140440] rt711 sdw:0:25d:711:0: rt711_pcm_hw_params rt711-aif1
[ 2663.142438] intel-sdw sdw-master-0: IO transfer timed out
[ 2665.190452] intel-sdw sdw-master-0: IO transfer timed out
[ 2665.190473] rt711 sdw:0:25d:711:0: [rt711_sdw_write] 7203 8283 <= 0031
[ 2667.238473] intel-sdw sdw-master-0: IO transfer timed out
[ 2669.286264] intel-sdw sdw-master-0: IO transfer timed out
[ 2669.286285] rt711 sdw:0:25d:711:0: [rt711_sdw_write] 7209 8289 <= 0031

    failed_multipipeline_test_243_all_logger.log
    failed_multipipeline_test_243_dmesg.log

  4. bardliao
    self-assigned this
    on Nov 28, 2019

  5. bardliao commented on Nov 29, 2019

    @bardliao
    bardliao
    on Nov 29, 2019
    Collaborator

    Look like "Link power down failed: -11" can be seen on all the error dmesg log. Let's fix it first. @YvonneYang2 Could you test it with 0001-soundiwre-Intel-set-link_control-bits-again-when-it-.patch.txt?

    patch 
    diff --git a/drivers/soundwire/intel.c b/drivers/soundwire/intel.c
index 63931cda51ab..91bd6fe550fc 100644
--- a/drivers/soundwire/intel.c
+++ b/drivers/soundwire/intel.c
@@ -407,6 +407,7 @@ static int intel_link_power_down(struct sdw_intel *sdw)
 	unsigned int link_id = sdw->instance;
 	void __iomem *shim = sdw->link_res->shim;
 	u16 ioctl;
+	int retry = 3;
 
 	/* Glue logic */
 	ioctl = intel_readw(shim, SDW_SHIM_IOCTL(link_id));
@@ -424,6 +425,12 @@ static int intel_link_power_down(struct sdw_intel *sdw)
 	link_control &=  spa_mask;
 
 	ret = intel_clear_bit(shim, SDW_SHIM_LCTL, link_control, cpa_mask);
+	while (ret == -EAGAIN && retry >= 0) {
+		msleep(1);
+		ret = intel_clear_bit(shim, SDW_SHIM_LCTL,
+				      link_control, cpa_mask);
+		retry--;
+	}
 	if (ret < 0)
 		return ret;

  6. YvonneYang2 commented on Nov 29, 2019

    @YvonneYang2
    YvonneYang2
    on Nov 29, 2019
    Author

    Tested it 500 times with latest integration/soundwire-latest (commit:d6078f9) +
    0001-soundiwre-Intel-set-link_control-bits-again-when-it-.patch.txt
    , IO transfer timed out issue and "Link power down failed: -11" both cannot be reproduced.

  7. bardliao commented on Nov 29, 2019

    @bardliao
    bardliao
    on Nov 29, 2019
    Collaborator

    @YvonneYang2 To double confirm. Could you check it with below patch instead?

    diff --git a/drivers/soundwire/intel.c b/drivers/soundwire/intel.c
index 63931cda51ab..686c409d66c3 100644
--- a/drivers/soundwire/intel.c
+++ b/drivers/soundwire/intel.c
@@ -150,7 +150,7 @@ static inline void intel_writew(void __iomem *base, int offset, u16 value)
 
 static int intel_clear_bit(void __iomem *base, int offset, u32 value, u32 mask)
 {
-	int timeout = 10;
+	int timeout = 100;
 	u32 reg_read;
 
 	writel(value, base + offset);

  8. YvonneYang2 commented on Nov 29, 2019

    @YvonneYang2
    YvonneYang2
    on Nov 29, 2019
    Author

    @bardliao
    Issue can still be reproduced with latest integration/soundwire-latest (commit:d6078f9) + patch as above.

    Run 300 times, failed at 175th.

    Dmesg:

    [ 1878.026234] sof-audio-pci 0000:00:1f.3: pcm: open stream 0 dir 0
[ 1878.026235] sof-audio-pci 0000:00:1f.3: period min 192 max 16384 bytes
[ 1878.026236] sof-audio-pci 0000:00:1f.3: period count 2 max 16
[ 1878.026237] sof-audio-pci 0000:00:1f.3: buffer max 65536 bytes
[ 1878.026357]  SDW0-Playback: ASoC: hw_params BE SDW0-Playback
[ 1878.026360] rt711 sdw:0:25d:711:0: rt711_pcm_hw_params rt711-aif1
[ 1880.038362] intel-sdw sdw-master-0: IO transfer timed out
[ 1882.086346] intel-sdw sdw-master-0: IO transfer timed out
[ 1882.086368] rt711 sdw:0:25d:711:0: [rt711_sdw_write] 7203 8283 <= 0031

    failed_multipipeline_test_175_all_logger.log
    failed_multipipeline_test_175_dmesg.log

  9. bardliao commented on Dec 2, 2019

    @bardliao
    bardliao
    on Dec 2, 2019
    Collaborator

    @YvonneYang2 Could you test it with #1573?

  10. plbossart commented on Dec 2, 2019

    @plbossart
    plbossart
    on Dec 2, 2019
    Member

    @bardliao what's interesting is that the only time when the error happens when the sequences for pm_runtime are interleaved:

    [ 1873.951019] intel-sdw sdw-master-1: intel_suspend_runtime start
[ 1873.951031] intel-sdw sdw-master-0: intel_suspend_runtime start
[ 1873.951108] intel-sdw sdw-master-1: intel_suspend_runtime done
[ 1873.956341] intel-sdw sdw-master-0: Link power down failed: -11
[ 1873.963366] intel-sdw sdw-master-3: intel_suspend_runtime start
[ 1873.963433] intel-sdw sdw-master-3: intel_suspend_runtime done

    so it's likely we need a mutual exclusion between links...

    And looking at the code, it's pretty clear:

    static int intel_link_power_up(struct sdw_intel *sdw)
{
	unsigned int link_id = sdw->instance;
	void __iomem *shim = sdw->link_res->shim;
	int spa_mask, cpa_mask;
	int link_control, ret;

	/* Link power up sequence */
	link_control = intel_readl(shim, SDW_SHIM_LCTL);
	spa_mask = (SDW_SHIM_LCTL_SPA << link_id);
	cpa_mask = (SDW_SHIM_LCTL_CPA << link_id);
	link_control |=  spa_mask;

	ret = intel_set_bit(shim, SDW_SHIM_LCTL, link_control, cpa_mask);
	if (ret < 0)
		return ret;

	sdw->cdns.link_up = true;
	return 0;
}

    so what happens is that we have a common register which is accessed for different fields independently. that can't be good...

  11. plbossart commented on Dec 2, 2019

    @plbossart
    plbossart
    on Dec 2, 2019
    Member

    it's even worse for power-down, we also touch the glue logic

    static int intel_link_power_down(struct sdw_intel *sdw)
{
	int link_control, spa_mask, cpa_mask, ret;
	unsigned int link_id = sdw->instance;
	void __iomem *shim = sdw->link_res->shim;
	u16 ioctl;

	/* Glue logic */
	ioctl = intel_readw(shim, SDW_SHIM_IOCTL(link_id));
	ioctl |= SDW_SHIM_IOCTL_BKE;
	ioctl |= SDW_SHIM_IOCTL_COE;
	intel_writew(shim, SDW_SHIM_IOCTL(link_id), ioctl);

	ioctl &= ~(SDW_SHIM_IOCTL_MIF);
	intel_writew(shim, SDW_SHIM_IOCTL(link_id), ioctl);

	/* Link power down sequence */
	link_control = intel_readl(shim, SDW_SHIM_LCTL);
	spa_mask = ~(SDW_SHIM_LCTL_SPA << link_id);
	cpa_mask = (SDW_SHIM_LCTL_CPA << link_id);
	link_control &=  spa_mask;

	ret = intel_clear_bit(shim, SDW_SHIM_LCTL, link_control, cpa_mask);
	if (ret < 0)
		return ret;

	sdw->cdns.link_up = false;
	return 0;
}
  12. plbossart
    added a commit that references this issue on Dec 2, 2019

    soundwire: intel: add mutex to prevent concurrent access to SHIM regi…

    4884e90

  13. 122 remaining items

  14. ranj063
    added a commit that references this issue on Jun 30, 2020

    soundwire: intel: revisit SHIM programming sequences.

    a40bba4
  15. bardliao
    added 2 commits that reference this issue on Jul 1, 2020

    soundwire: intel: revisit SHIM programming sequences.

    91781b5

    soundwire: intel: revisit SHIM programming sequences.

    6c571e5
  16. plbossart
    added a commit that references this issue on Jul 7, 2020

    soundwire: intel: revisit SHIM programming sequences.

    5e68c19
  17. kv2019i
    added 2 commits that reference this issue on Jul 10, 2020

    soundwire: intel: revisit SHIM programming sequences.

    1ec06ae

    soundwire: intel: revisit SHIM programming sequences.

    5ce0343
  18. bardliao
    added a commit that references this issue on Jul 17, 2020

    soundwire: intel: revisit SHIM programming sequences.

    1a645cc
  19. plbossart
    added 2 commits that reference this issue on Jul 17, 2020

    soundwire: intel: revisit SHIM programming sequences.

    70b9166

    soundwire: intel: revisit SHIM programming sequences.

    4a17c44
  20. bardliao
    added a commit that references this issue on Aug 18, 2020

    soundwire: intel: revisit SHIM programming sequences.

    6ba01bd
  21. akku1139
    added 3 commits that reference this issue on Dec 9, 2025

    CHROMIUM: soundwire: intel: revisit SHIM programming sequences.

    a70851d

    CHROMIUM: soundwire: intel: revisit SHIM programming sequences.

    3d87617

    CHROMIUM: soundwire: intel: revisit SHIM programming sequences.

    471e71b
  22. fkjbvfdvbnfdkjvbjfhd
    added a commit that references this issue on May 18, 2026

    soundwire: intel: revisit SHIM programming sequences.

    4f4fd75
  23. nekoshirro
    added a commit that references this issue on Jun 14, 2026

    soundwire: intel: revisit SHIM programming sequences.

    082ed6c
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 modeSDWApplies to SoundWire bus for codec connectionbugSomething isn't working

Type

No type

Projects

No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions