[BUG][SDW]IO transfer timed out occurred when run suspend/resume stress test.

Describe the bug
IO transfer timed out occurred when run suspend/resume with aplay stress test. Run 300 times, error info start showing at 26th/27th time, but aplay function will not be effected.

To Reproduce

Run "aplay -Dhw:0,0 -r48000 -c2 -fs16_le /dev/zero & sudo ./stress-s3.sh 300 1 1"

Reproduced rate
Run 300 times, failed 26th/27th time

Expected result
No error occurred during stress test

Actual result
IO transfer timed out occurred when run suspend/resume with aplay stress test.

dmesg

[ 1372.645565] PM: suspend exit
[ 1373.091463] sof-audio-pci 0000:00:1f.3: ipc rx: 0x90020000: GLB_TRACE_MSG
[ 1373.091630] sof-audio-pci 0000:00:1f.3: ipc rx done: 0x90020000: GLB_TRACE_MSG
[ 1373.591405] sof-audio-pci 0000:00:1f.3: ipc rx: 0x90020000: GLB_TRACE_MSG
[ 1373.591567] sof-audio-pci 0000:00:1f.3: ipc rx done: 0x90020000: GLB_TRACE_MSG
[ 1374.044938] asix 1-6.1:1.0 enx000ec6c686d3: link up, 100Mbps, full-duplex, lpa 0x41E1
[ 1374.624624] intel-sdw sdw-master-1: IO transfer timed out
[ 1374.624641] intel-sdw sdw-master-1: SDW Slave Addr: 20025d130800
[ 1374.624647] intel-sdw sdw-master-1: SDW Slave class_id 0, part_id 1308, mfg_id 25d, unique_id 0, version 2
[ 1374.624651] intel-sdw sdw-master-1: in sdw_assign_device_num
[ 1374.624654] intel-sdw sdw-master-1: in sdw_assign_device_num
[ 1374.624659] intel-sdw sdw-master-1: Slave already registered, reusing dev_num:1

s3_test_27_logger_all.log
test_26.log
test_27.log
s3_test_26_logger_all.log

Will retest it with #1451 to check if it can fix the issue.

Only run suspend/resume stress test sill can reproduce the issue. Run 100 times, failed at 24th/25th time.

s3_test_24_logger_all.log
s3_test_25_logger_all.log
test_24.log
test_25.log

@bardliao

@bardliao
Issue still can be reproduced with latest-soundwire(413de1e ) + #1451

Run 300 times, failed at 13th/14th/28th time

13th time

[  212.378163] sof-audio-pci 0000:00:1f.3: FW Poll Status: reg=0x14001e successful
[  212.378166] sof-audio-pci 0000:00:1f.3: ipc tx: 0x60040000: GLB_STREAM_MSG: TRIG_START
[  212.378394] sof-audio-pci 0000:00:1f.3: ipc tx succeeded: 0x60040000: GLB_STREAM_MSG: TRIG_START
[  212.416820] PM: suspend exit
[  212.857612] sof-audio-pci 0000:00:1f.3: ipc rx: 0x90020000: GLB_TRACE_MSG
[  212.857710] sof-audio-pci 0000:00:1f.3: ipc rx done: 0x90020000: GLB_TRACE_MSG
[  213.357568] sof-audio-pci 0000:00:1f.3: ipc rx: 0x90020000: GLB_TRACE_MSG
[  213.357664] sof-audio-pci 0000:00:1f.3: ipc rx done: 0x90020000: GLB_TRACE_MSG
[  214.418427] intel-sdw sdw-master-1: IO transfer timed out

28th time

[  500.408930] PM: suspend exit
[  500.855157] sof-audio-pci 0000:00:1f.3: ipc rx: 0x90020000: GLB_TRACE_MSG
[  500.855343] sof-audio-pci 0000:00:1f.3: ipc rx done: 0x90020000: GLB_TRACE_MSG
[  501.354939] sof-audio-pci 0000:00:1f.3: ipc rx: 0x90020000: GLB_TRACE_MSG
[  501.355121] sof-audio-pci 0000:00:1f.3: ipc rx done: 0x90020000: GLB_TRACE_MSG
[  502.367887] intel-sdw sdw-master-1: IO transfer timed out
[  502.367906] intel-sdw sdw-master-1: SDW Slave Addr: 0
[  502.367912] intel-sdw sdw-master-1: SDW Slave class_id 0, part_id 0, mfg_id 0, unique_id 0, version 0
[  502.367917] intel-sdw sdw-master-1: Slave Entry not found
[  502.367924] intel-sdw sdw-master-1: SDW Slave Addr: 0
[  502.367929] intel-sdw sdw-master-1: SDW Slave class_id 0, part_id 0, mfg_id 0, unique_id 0, version 0
[  502.367932] intel-sdw sdw-master-1: Slave Entry not found

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

test_13.log
test_14.log
test_28.log
s3_test_13_logger_all.log
s3_test_14_logger_all.log
s3_test_28_logger_all.log

Are those issues seen with MSI? What if MSI is disabled (along with the I2C kconfigs to avoid the I2C issues in legacy mode)

The IO transfer timed out are not happened on the active device (rt711/master 0). I will try using thread on sdw_intel_thread() to prevent the transfer from one master is blocked by another master's event.

Using thread on sdw_intel_thread() doesn't work. After adding some trace, I found that intel_suspend_runtime could be triggered between mutex_lock(&bus->msg_lock); and mutex_unlock(&bus->msg_lock); in sdw_transfer(), and we will disable interrupt in intel_suspend_runtime. I guess it is the root cause of this issue.

Issue can be reproduced with Legacy IRQ mode.

@YvonneYang2

@YvonneYang2 Could you retest it with #1496?

soundwire: intel: fix race condition on system resume

CHROMIUM: soundwire: intel: fix race condition on system resume

soundwire: intel: fix race condition on system resume

Navigation Menu

Repository navigation

[BUG][SDW]IO transfer timed out occurred when run suspend/resume stress test. #1482

130 remaining items

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

[BUG][SDW]IO transfer timed out occurred when run suspend/resume stress test. #1482

Description

Activity

YvonneYang2 commented on Nov 14, 2019

YvonneYang2 commented on Nov 14, 2019

YvonneYang2 commented on Nov 14, 2019

plbossart commented on Nov 14, 2019

bardliao commented on Nov 15, 2019

bardliao commented on Nov 15, 2019

YvonneYang2 commented on Nov 15, 2019

bardliao commented on Nov 15, 2019

130 remaining items

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions