[MTL][SDW] rt1316-sdca sdw:2:025d:1316:01: SDW_SCP_INT1 (BUS_CLASH) read failed:-61

[keqiaozhang]

Describe the bug
Observed this issue on a new MTL-SDW RVP platform: Realtek GEN3.1 AIOC is connected for SDW rt711/rt714/rt1316.
TPLG file is:sof-mtl-rt711-l0-rt1316-l23-rt714-l1.tplg
This issue happens when testing suspend/resume with audio. The reproduction rate is almost 100%.

dmesg error

[ 5626.468134] kernel: soundwire_bus:sdw_modify_slave_status: rt1316-sdca sdw:2:025d:1316:01: initializing enumeration and init completion for Slave 1
[ 5626.468441] kernel: soundwire_bus:sdw_handle_slave_status: soundwire sdw-master-2: Slave attached, programming device number
[ 5626.468609] kernel: soundwire_bus:sdw_extract_slave_id: soundwire sdw-master-2: SDW Slave Addr: 33025d131601
[ 5626.468613] kernel: soundwire_bus:sdw_extract_slave_id: soundwire sdw-master-2: SDW Slave class_id 0x01, mfg_id 0x025d, part_id 0x1316, unique_id 0x3, version 0x3
[ 5626.468616] kernel: soundwire_bus:sdw_assign_device_num: soundwire sdw-master-2: Slave already registered, reusing dev_num:1
[ 5626.468859] kernel: soundwire_cadence:cdns_fill_msg_resp: soundwire_intel soundwire_intel.link.2: Msg ignored for Slave 0
[ 5626.468863] kernel: soundwire_bus:sdw_program_device_num: soundwire sdw-master-2: No more devices to enumerate
[ 5626.468941] kernel: soundwire_bus:sdw_modify_slave_status: rt1316-sdca sdw:2:025d:1316:01: signaling enumeration completion for Slave 1
[ 5626.469127] kernel: soundwire_bus:sdw_slave_set_frequency: rt1316-sdca sdw:2:025d:1316:01: Configured bus base 1, scale 3, mclk 19200000, curr_freq 4800000
[ 5626.469190] kernel: soundwire_cadence:cdns_fill_msg_resp: soundwire_intel soundwire_intel.link.2: Msg ignored for Slave 1
[ 5626.469194] kernel: rt1316-sdca sdw:2:025d:1316:01: SDW_SCP_INT1 (BUS_CLASH) read failed:-61
[ 5626.469230] kernel: rt1316-sdca sdw:2:025d:1316:01: Slave 1 initialization failed: -61
[ 5626.469357] kernel: soundwire_intel soundwire_intel.link.2: Program SCP Ack not received
[ 5626.469384] kernel: soundwire_intel soundwire_intel.link.2: Program SCP Ack not received
[ 5626.469498] kernel: soundwire_cadence:cdns_program_scp_addr: soundwire_intel soundwire_intel.link.2: SCP_addrpage ignored for Slave 1
[ 5626.469501] kernel: soundwire sdw-master-2: trf on Slave 1 failed:-5 write addr c000 count 0
[ 5626.469604] kernel: soundwire_intel soundwire_intel.link.2: Program SCP Ack not received
[ 5626.469631] kernel: soundwire_intel soundwire_intel.link.2: Program SCP Ack not received
[ 5626.469659] kernel: soundwire_cadence:cdns_program_scp_addr: soundwire_intel soundwire_intel.link.2: SCP_addrpage ignored for Slave 1
[ 5626.469661] kernel: soundwire sdw-master-2: trf on Slave 1 failed:-5 write addr c710 count 0
[ 5626.469693] kernel: snd_soc_rt1316_sdw:rt1316_io_init: rt1316-sdca sdw:2:025d:1316:01: rt1316_io_init hw_init complete
[ 5626.469697] kernel: soundwire_bus:sdw_handle_slave_status: rt1316-sdca sdw:2:025d:1316:01: signaling initialization completion for Slave 1
[ 5626.469719] kernel: soundwire_cadence:cdns_update_slave_status_work: soundwire_intel soundwire_intel.link.2: Device0 detected after clearing status, iteration 1
[ 5626.469753] kernel: rt1316-sdca sdw:2:025d:1316:01: Slave 1 state check1: UNATTACHED, status was 1
[ 5626.469756] kernel: soundwire_bus:sdw_modify_slave_status: rt1316-sdca sdw:2:025d:1316:01: initializing enumeration and init completion for Slave 1
[ 5626.469761] kernel: soundwire_bus:sdw_handle_slave_status: soundwire sdw-master-2: Slave attached, programming device number
[ 5626.469924] kernel: soundwire_bus:sdw_extract_slave_id: soundwire sdw-master-2: SDW Slave Addr: 33025d131601
[ 5626.469928] kernel: soundwire_bus:sdw_extract_slave_id: soundwire sdw-master-2: SDW Slave class_id 0x01, mfg_id 0x025d, part_id 0x1316, unique_id 0x3, version 0x3
[ 5626.469932] kernel: soundwire_bus:sdw_assign_device_num: soundwire sdw-master-2: Slave already registered, reusing dev_num:1
[ 5626.470174] kernel: soundwire_cadence:cdns_fill_msg_resp: soundwire_intel soundwire_intel.link.2: Msg ignored for Slave 0
[ 5626.470178] kernel: soundwire_bus:sdw_program_device_num: soundwire sdw-master-2: No more devices to enumerate
[ 5626.470270] kernel: soundwire_bus:sdw_modify_slave_status: rt1316-sdca sdw:2:025d:1316:01: signaling enumeration completion for Slave 1
[ 5626.470457] kernel: soundwire_bus:sdw_slave_set_frequency: rt1316-sdca sdw:2:025d:1316:01: Configured bus base 1, scale 3, mclk 19200000, curr_freq 4800000
[ 5626.479153] kernel: snd_soc_rt1316_sdw:rt1316_io_init: rt1316-sdca sdw:2:025d:1316:01: rt1316_io_init hw_init complete
[ 5626.479158] kernel: soundwire_bus:sdw_handle_slave_status: rt1316-sdca sdw:2:025d:1316:01: signaling initialization completion for Slave 1
[ 5626.733546] kernel: rt1316-sdca sdw:2:025d:1316:01: Slave 1 state check1: UNATTACHED, status was 1
[ 5626.733559] kernel: soundwire_bus:sdw_modify_slave_status: rt1316-sdca sdw:2:025d:1316:01: initializing enumeration and init completion for Slave 1
[ 5626.733712] kernel: soundwire_bus:sdw_handle_slave_status: soundwire sdw-master-2: Slave attached, programming device number
[ 5626.733891] kernel: soundwire_bus:sdw_extract_slave_id: soundwire sdw-master-2: SDW Slave Addr: 33025d131601
[ 5626.733896] kernel: soundwire_bus:sdw_extract_slave_id: soundwire sdw-master-2: SDW Slave class_id 0x01, mfg_id 0x025d, part_id 0x1316, unique_id 0x3, version 0x3
[ 5626.733901] kernel: soundwire_bus:sdw_assign_device_num: soundwire sdw-master-2: Slave already registered, reusing dev_num:1
[ 5626.734140] kernel: soundwire_cadence:cdns_fill_msg_resp: soundwire_intel soundwire_intel.link.2: Msg ignored for Slave 0
[ 5626.734145] kernel: soundwire_bus:sdw_program_device_num: soundwire sdw-master-2: No more devices to enumerate
[ 5626.734211] kernel: soundwire_bus:sdw_modify_slave_status: rt1316-sdca sdw:2:025d:1316:01: signaling enumeration completion for Slave 1
[ 5626.734403] kernel: soundwire_bus:sdw_slave_set_frequency: rt1316-sdca sdw:2:025d:1316:01: Configured bus base 1, scale 3, mclk 19200000, curr_freq 4800000
[ 5626.743177] kernel: snd_soc_rt1316_sdw:rt1316_io_init: rt1316-sdca sdw:2:025d:1316:01: rt1316_io_init hw_init complete
[ 5626.743184] kernel: soundwire_bus:sdw_handle_slave_status: rt1316-sdca sdw:2:025d:1316:01: signaling initialization completion for Slave 1
[ 5626.747173] kernel: asix 3-5.1:1.0 enx000ec63abe21: Link is Up - 100Mbps/Full - flow control off
[ 5627.471155] kernel: rt1316-sdca sdw:2:025d:1316:01: Slave 1 state check1: UNATTACHED, status was 1
[ 5627.471168] kernel: soundwire_bus:sdw_modify_slave_status: rt1316-sdca sdw:2:025d:1316:01: initializing enumeration and init completion for Slave 1
[ 5627.471401] kernel: soundwire_bus:sdw_handle_slave_status: soundwire sdw-master-2: Slave attached, programming device number
[ 5627.471578] kernel: soundwire_bus:sdw_extract_slave_id: soundwire sdw-master-2: SDW Slave Addr: 33025d131601
[ 5627.471582] kernel: soundwire_bus:sdw_extract_slave_id: soundwire sdw-master-2: SDW Slave class_id 0x01, mfg_id 0x025d, part_id 0x1316, unique_id 0x3, version 0x3
[ 5627.471588] kernel: soundwire_bus:sdw_assign_device_num: soundwire sdw-master-2: Slave already registered, reusing dev_num:1
[ 5627.471856] kernel: soundwire_cadence:cdns_fill_msg_resp: soundwire_intel soundwire_intel.link.2: Msg ignored for Slave 0
[ 5627.471861] kernel: soundwire_bus:sdw_program_device_num: soundwire sdw-master-2: No more devices to enumerate
[ 5627.471930] kernel: soundwire_bus:sdw_modify_slave_status: rt1316-sdca sdw:2:025d:1316:01: signaling enumeration completion for Slave 1
[ 5627.472005] kernel: rt1316-sdca sdw:2:025d:1316:01: SDW_SCP_BUS_CLOCK_BASE write failed:-61
[ 5627.472045] kernel: rt1316-sdca sdw:2:025d:1316:01: Slave 1 initialization failed: -61
[ 5627.472169] kernel: soundwire_intel soundwire_intel.link.2: Program SCP Ack not received
[ 5627.472199] kernel: soundwire_intel soundwire_intel.link.2: Program SCP Ack not received
[ 5627.472228] kernel: soundwire_cadence:cdns_program_scp_addr: soundwire_intel soundwire_intel.link.2: SCP_addrpage ignored for Slave 1
[ 5627.472232] kernel: soundwire sdw-master-2: trf on Slave 1 failed:-5 write addr c000 count 0
[ 5627.472355] kernel: soundwire_intel soundwire_intel.link.2: Program SCP Ack not received
[ 5627.472387] kernel: soundwire_intel soundwire_intel.link.2: Program SCP Ack not received
[ 5627.472417] kernel: soundwire_cadence:cdns_program_scp_addr: soundwire_intel soundwire_intel.link.2: SCP_addrpage ignored for Slave 1
[ 5627.472420] kernel: soundwire sdw-master-2: trf on Slave 1 failed:-5 write addr c710 count 0
[ 5627.472457] kernel: snd_soc_rt1316_sdw:rt1316_io_init: rt1316-sdca sdw:2:025d:1316:01: rt1316_io_init hw_init complete

To Reproduce
~/sof-test/test-case/check-suspend-resume-with-audio.sh -l 5 -m capture

Reproduction Rate
100%

Environment

1. Branch name and commit hash of the 2 repositories: sof (firmware/topology) and linux (kernel driver).
   • Kernel: {57639beab964}
   • SOF: {df460c8c6b18}
2. Name of the topology file
   • Topology: sof-mtl-rt711-l0-rt1316-l23-rt714-l1.tplg
3. Name of the platform(s) on which the bug is observed.
   • Platform: MTL_SDW_AIOC (sh-mtlp-rvp-sdw-04)

dmesg.txt
mtrace.txt

[plbossart]

@keqiaozhang can you check what happens if you just wait 10s between two playbacks/capture and let the links go to pm_runtime suspend.
This looks like a fundamental issue where the link power is probably not turned on, or the IP is not configured correctly with the AC controls not quite right. if the codec cannot handle a simple command then something major is happening.

[plbossart]

also the dmesg excerpt and file don't match, what I see as the first error is this:

[ 5626.469190] kernel: soundwire_cadence:cdns_fill_msg_resp: soundwire_intel soundwire_intel.link.2: Msg ignored for Slave 1
[ 5626.469194] kernel: rt1316-sdca sdw:2:025d:1316:01: SDW_SCP_INT1 (BUS_CLASH) read failed:-61
[ 5626.469230] kernel: rt1316-sdca sdw:2:025d:1316:01: Slave 1 initialization failed: -61
[ 5626.469357] kernel: soundwire_intel soundwire_intel.link.2: Program SCP Ack not received
[ 5626.469384] kernel: soundwire_intel soundwire_intel.link.2: Program SCP Ack not received

[keqiaozhang]

@plbossart Sorry for late response.
This issue still can be reproduced even with 10s+ delay between each cycle.

[mengdonglin]

We cannot reproduce this issue on GEN4 AIOC today. Will double check tomorrow @plbossart