Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

SoundWire: msg ignored during BTP transfer with pm_runtime enabled (dspless mode) #4784

Closed
plbossart opened this issue Jan 16, 2024 · 21 comments
Labels
SDW Applies to SoundWire bus for codec connection won't fix This will not be worked on atm (e.g. a bug closed for lack of user request, hardware etc)

Comments

@plbossart
Copy link
Member

plbossart commented Jan 16, 2024

When doing a BPT transfer without the DSP, we ALWAYS see an error

[  461.872854] IO error in rt711_sdca_headset_detect, ret -61

This is very odd because the SAME device 6 replies to BPT commands without any errors. @shumingfan @bardliao any idea why this might fail?

full sequence:

[  461.112081] soundwire_bus:set_command: rt711-sdca sdw:0:0:025d:0711:01: command: write
[  461.112108] soundwire_bus:set_command_type: rt711-sdca sdw:0:0:025d:0711:01: command type: BRA
[  461.112125] soundwire_bus:set_start_address: rt711-sdca sdw:0:0:025d:0711:01: start address 0x44010000
[  461.112144] soundwire_bus:set_num_bytes: rt711-sdca sdw:0:0:025d:0711:01: number of bytes 524288
[  461.132347] snd_sof:snd_sof_pci_update_bits_unlocked: sof-audio-pci-intel-lnl 0000:00:1f.3: Debug PCIR: 00000000 at  00000044
[  461.132359] snd_sof:snd_sof_pci_update_bits_unlocked: sof-audio-pci-intel-lnl 0000:00:1f.3: Debug PCIR: 00000000 at  00000048
[  461.135901] snd_sof_intel_hda:hda_codec_detect_mask: sof-audio-pci-intel-lnl 0000:00:1f.3: codec_mask = 0x0
[  461.135942] snd_sof:snd_sof_pci_update_bits_unlocked: sof-audio-pci-intel-lnl 0000:00:1f.3: Debug PCIR: 00000000 at  00000048
[  461.135947] snd_sof:snd_sof_pci_update_bits_unlocked: sof-audio-pci-intel-lnl 0000:00:1f.3: Debug PCIW: 00000040 at  00000048
[  461.135955] snd_sof_intel_hda_common:hda_dsp_state_log: sof-audio-pci-intel-lnl 0000:00:1f.3: Current DSP power state: D0I0
[  461.135958] snd_sof:sof_set_fw_state: sof-audio-pci-intel-lnl 0000:00:1f.3: fw_state change: 0 -> 1
[  461.136014] soundwire_intel:intel_shim_vs_set_clock_source: soundwire_intel soundwire_intel.link.0: clock source 0 LVSCTL 0x0
[  461.136017] soundwire_intel:intel_link_power_up: soundwire_intel soundwire_intel.link.0: first link up, programming SYNCPRD
[  461.136048] soundwire_bus:sdw_modify_slave_status: rt711-sdca sdw:0:0:025d:0711:01: initializing enumeration and init completion for Slave 6
[  461.136056] soundwire_cadence:cdns_init_clock_ctrl: soundwire_intel soundwire_intel.link.0: mclk 19200000 max 4800000 row 50 col 4
[  461.137598] soundwire_cadence:cdns_update_slave_status_work: soundwire_intel soundwire_intel.link.0: Slave status change: 0x2
[  461.137617] soundwire_bus:sdw_handle_slave_status: soundwire sdw-master-0-0: Slave attached, programming device number
[  461.137803] soundwire_bus:sdw_extract_slave_id: soundwire sdw-master-0-0: SDW Slave Addr: 30025d071101
[  461.137805] soundwire_bus:sdw_extract_slave_id: soundwire sdw-master-0-0: SDW Slave class_id 0x01, mfg_id 0x025d, part_id 0x0711, unique_id 0x0, version 0x3
[  461.137807] soundwire_bus:sdw_assign_device_num: soundwire sdw-master-0-0: Slave already registered, reusing dev_num:6
[  461.138220] soundwire_cadence:cdns_fill_msg_resp: soundwire_intel soundwire_intel.link.0: Msg ignored for Slave 0
[  461.138222] soundwire_bus:sdw_program_device_num: soundwire sdw-master-0-0: No more devices to enumerate
[  461.138313] soundwire_cadence:cdns_update_slave_status_work: soundwire_intel soundwire_intel.link.0: Slave status change: 0x2000001
[  461.138332] soundwire_bus:sdw_modify_slave_status: rt711-sdca sdw:0:0:025d:0711:01: signaling enumeration completion for Slave 6
[  461.138830] soundwire_bus:sdw_slave_set_frequency: rt711-sdca sdw:0:0:025d:0711:01: Configured bus base 1, scale 3, mclk 19200000, curr_freq 4800000
[  461.337736] snd_soc_rt711_sdca:rt711_sdca_calibration: rt711-sdca sdw:0:0:025d:0711:01: rt711_sdca_calibration calibration complete, ret=0
[  461.348882] snd_soc_rt711_sdca:rt711_sdca_jack_init: rt711-sdca sdw:0:0:025d:0711:01: in rt711_sdca_jack_init enable
[  461.348885] snd_soc_rt711_sdca:rt711_sdca_io_init: rt711-sdca sdw:0:0:025d:0711:01: rt711_sdca_io_init hw_init complete
[  461.348886] soundwire_bus:sdw_handle_slave_status: rt711-sdca sdw:0:0:025d:0711:01: signaling initialization completion for Slave 6
[  461.369195] soundwire_bus:cmd_go: rt711-sdca sdw:0:0:025d:0711:01: starting command
[  461.369199] soundwire_intel:intel_ace2x_bpt_send_async: soundwire_intel soundwire_intel.link.0: BPT Transfer start
[  461.372258] soundwire_intel:intel_ace2x_bpt_open_stream: soundwire_intel soundwire_intel.link.0: Message len 524288 transferred in 65536 frames (8 per frame)
[  461.372262] soundwire_intel:intel_ace2x_bpt_open_stream: soundwire_intel soundwire_intel.link.0: sizes pdi0 2359296 pdi1 524288 tx_bandwidth 13824000 rx_bandwidth 3072000
[  461.372264] snd_sof_intel_hda_sdw_bpt:hda_sdw_bpt_dma_prepare: sof-audio-pci-intel-lnl 0000:00:1f.3: direction 0 format_val 1842
[  461.372446] snd_sof_intel_hda_common:hda_dsp_stream_hw_params: sof-audio-pci-intel-lnl 0000:00:1f.3: FW Poll Status: reg[0x1e0]=0x40000 successful
[  461.372463] snd_sof_intel_hda_common:hda_dsp_stream_hw_params: sof-audio-pci-intel-lnl 0000:00:1f.3: FW Poll Status: reg[0x1e0]=0x40000 successful
[  461.372468] snd_sof_intel_hda_common:hda_dsp_stream_setup_bdl: sof-audio-pci-intel-lnl 0000:00:1f.3: period_bytes:0x0
[  461.372470] snd_sof_intel_hda_common:hda_dsp_stream_setup_bdl: sof-audio-pci-intel-lnl 0000:00:1f.3: periods:1
[  461.372483] snd_sof_intel_hda_sdw_bpt:hda_sdw_bpt_dma_prepare: sof-audio-pci-intel-lnl 0000:00:1f.3: direction 1 format_val 1840
[  461.372532] snd_sof_intel_hda_common:hda_dsp_stream_hw_params: sof-audio-pci-intel-lnl 0000:00:1f.3: FW Poll Status: reg[0x80]=0x40000 successful
[  461.373671] snd_sof_intel_hda_common:hda_dsp_stream_hw_params: sof-audio-pci-intel-lnl 0000:00:1f.3: FW Poll Status: reg[0x80]=0x40000 successful
[  461.373676] snd_sof_intel_hda_common:hda_dsp_stream_setup_bdl: sof-audio-pci-intel-lnl 0000:00:1f.3: period_bytes:0x0
[  461.373678] snd_sof_intel_hda_common:hda_dsp_stream_setup_bdl: sof-audio-pci-intel-lnl 0000:00:1f.3: periods:1
[  461.379098] soundwire_intel:intel_ace2x_bpt_send_async: soundwire_intel soundwire_intel.link.0: intel_ace2x_bpt_send_async: done
[  461.379101] soundwire_bus:do_bpt_sequence: rt711-sdca sdw:0:0:025d:0711:01: send_async done
[  461.379103] soundwire_intel:intel_ace2x_bpt_wait: soundwire_intel soundwire_intel.link.0: BPT Transfer wait
[  461.839695] soundwire_cadence:cdns_update_slave_status_work: soundwire_intel soundwire_intel.link.0: Slave status change: 0x4000000
[  461.840774] snd_soc_rt711_sdca:rt711_sdca_interrupt_callback: rt711-sdca sdw:0:0:025d:0711:01: rt711_sdca_interrupt_callback control_port_stat=4, sdca_cascade=1
[  461.842449] soundwire_cadence:cdns_update_slave_status_work: soundwire_intel soundwire_intel.link.0: Slave status change: 0x2000000
[  461.872530] rt711_sdca_headset_detect: trying to read from address 0x40600490
[  461.872853] soundwire_cadence:cdns_fill_msg_resp: soundwire_intel soundwire_intel.link.0: Msg ignored for Slave 6
[  461.872854] IO error in rt711_sdca_headset_detect, ret -61
[  462.393165] rfkill: input handler enabled
[  462.745031] snd_sof_intel_hda_common:hda_dsp_stream_trigger: sof-audio-pci-intel-lnl 0000:00:1f.3: FW Poll Status: reg[0x80]=0x20140000 successful
[  462.745038] snd_sof_intel_hda_common:hda_dsp_stream_trigger: sof-audio-pci-intel-lnl 0000:00:1f.3: FW Poll Status: reg[0x1e0]=0x140000 successful
[  462.748441] soundwire_intel:intel_ace2x_bpt_wait: soundwire_intel soundwire_intel.link.0: BPT Transfer done
[  462.751480] soundwire_bus:do_bpt_sequence: rt711-sdca sdw:0:0:025d:0711:01: wait done
[  462.751661] soundwire_bus:cmd_go: rt711-sdca sdw:0:0:025d:0711:01: command completed, status 0, time 1382 ms
[  466.502279] soundwire_bus:sdw_bus_wait_for_clk_prep_deprep: soundwire sdw-master-0-0: clock stop prepare done slave:15
[  466.502767] snd_sof:snd_sof_pci_update_bits_unlocked: sof-audio-pci-intel-lnl 0000:00:1f.3: Debug PCIR: 00000000 at  00000044
[  466.502774] snd_sof:snd_sof_pci_update_bits_unlocked: sof-audio-pci-intel-lnl 0000:00:1f.3: Debug PCIW: 00000010 at  00000044
[  466.503573] snd_sof_intel_hda_common:hda_dsp_state_log: sof-audio-pci-intel-lnl 0000:00:1f.3: Current DSP power state: D3
[  466.503578] snd_sof:sof_set_fw_state: sof-audio-pci-intel-lnl 0000:00:1f.3: fw_state change: 1 -> 0
@plbossart
Copy link
Member Author

plbossart commented Jan 16, 2024

This does NOT happen with an audio playback, only when resuming to do a BPT transfer.

[  950.740801] snd_sof:snd_sof_pci_update_bits_unlocked: sof-audio-pci-intel-lnl 0000:00:1f.3: Debug PCIR: 00000000 at  00000044
[  950.740811] snd_sof:snd_sof_pci_update_bits_unlocked: sof-audio-pci-intel-lnl 0000:00:1f.3: Debug PCIR: 00000000 at  00000048
[  950.743898] snd_sof_intel_hda:hda_codec_detect_mask: sof-audio-pci-intel-lnl 0000:00:1f.3: codec_mask = 0x0
[  950.743935] snd_sof:snd_sof_pci_update_bits_unlocked: sof-audio-pci-intel-lnl 0000:00:1f.3: Debug PCIR: 00000000 at  00000048
[  950.743938] snd_sof:snd_sof_pci_update_bits_unlocked: sof-audio-pci-intel-lnl 0000:00:1f.3: Debug PCIW: 00000040 at  00000048
[  950.743943] snd_sof_intel_hda_common:hda_dsp_state_log: sof-audio-pci-intel-lnl 0000:00:1f.3: Current DSP power state: D0I0
[  950.743945] snd_sof:sof_set_fw_state: sof-audio-pci-intel-lnl 0000:00:1f.3: fw_state change: 0 -> 1
[  950.743994] soundwire_intel:intel_shim_vs_set_clock_source: soundwire_intel soundwire_intel.link.0: clock source 0 LVSCTL 0x0
[  950.743997] soundwire_intel:intel_link_power_up: soundwire_intel soundwire_intel.link.0: first link up, programming SYNCPRD
[  950.744026] soundwire_bus:sdw_modify_slave_status: rt711-sdca sdw:0:0:025d:0711:01: initializing enumeration and init completion for Slave 6
[  950.744033] soundwire_cadence:cdns_init_clock_ctrl: soundwire_intel soundwire_intel.link.0: mclk 19200000 max 4800000 row 50 col 4
[  950.745794] soundwire_cadence:cdns_update_slave_status_work: soundwire_intel soundwire_intel.link.0: Slave status change: 0x2
[  950.745814] soundwire_bus:sdw_handle_slave_status: soundwire sdw-master-0-0: Slave attached, programming device number
[  950.746326] soundwire_bus:sdw_extract_slave_id: soundwire sdw-master-0-0: SDW Slave Addr: 30025d071101
[  950.746329] soundwire_bus:sdw_extract_slave_id: soundwire sdw-master-0-0: SDW Slave class_id 0x01, mfg_id 0x025d, part_id 0x0711, unique_id 0x0, version 0x3
[  950.746331] soundwire_bus:sdw_assign_device_num: soundwire sdw-master-0-0: Slave already registered, reusing dev_num:6
[  950.747819] soundwire_cadence:cdns_fill_msg_resp: soundwire_intel soundwire_intel.link.0: Msg ignored for Slave 0
[  950.747823] soundwire_bus:sdw_program_device_num: soundwire sdw-master-0-0: No more devices to enumerate
[  950.748033] soundwire_cadence:cdns_update_slave_status_work: soundwire_intel soundwire_intel.link.0: Slave status change: 0x2000001
[  950.748051] soundwire_bus:sdw_modify_slave_status: rt711-sdca sdw:0:0:025d:0711:01: signaling enumeration completion for Slave 6
[  950.749087] soundwire_bus:sdw_slave_set_frequency: rt711-sdca sdw:0:0:025d:0711:01: Configured bus base 1, scale 3, mclk 19200000, curr_freq 4800000
[  950.969396] snd_soc_rt711_sdca:rt711_sdca_calibration: rt711-sdca sdw:0:0:025d:0711:01: rt711_sdca_calibration calibration complete, ret=0
[  950.991136] snd_soc_rt711_sdca:rt711_sdca_jack_init: rt711-sdca sdw:0:0:025d:0711:01: in rt711_sdca_jack_init enable
[  950.991149] snd_soc_rt711_sdca:rt711_sdca_io_init: rt711-sdca sdw:0:0:025d:0711:01: rt711_sdca_io_init hw_init complete
[  950.991155] soundwire_bus:sdw_handle_slave_status: rt711-sdca sdw:0:0:025d:0711:01: signaling initialization completion for Slave 6
[  951.051053] snd_sof:sof_pcm_open: sof-audio-pci-intel-lnl 0000:00:1f.3: pcm: open stream 0 dir 0
[  951.051073] snd_sof:sof_pcm_open: sof-audio-pci-intel-lnl 0000:00:1f.3: period min 192 max 16384 bytes
[  951.051083] snd_sof:sof_pcm_open: sof-audio-pci-intel-lnl 0000:00:1f.3: period count 2 max 16
[  951.051091] snd_sof:sof_pcm_open: sof-audio-pci-intel-lnl 0000:00:1f.3: buffer max 65536 bytes
[  951.052109] snd_soc_rt711_sdca:rt711_sdca_pcm_hw_params: rt711-sdca sdw:0:0:025d:0711:01: rt711_sdca_pcm_hw_params rt711-sdca-aif1
[  951.054288] snd_sof_intel_hda_common:generic_calc_stream_format: sof-audio-pci-intel-lnl 0000:00:1f.3: format_val=0x41, rate=48000, ch=2, format=10
[  951.054317] snd_sof:sof_pcm_hw_params: sof-audio-pci-intel-lnl 0000:00:1f.3: pcm: hw params stream 0 dir 0
[  951.054328] snd_sof_intel_hda_common:hda_dsp_stream_hw_params: sof-audio-pci-intel-lnl 0000:00:1f.3: FW Poll Status: reg[0x1e0]=0x40000 successful
[  951.054355] snd_sof_intel_hda_common:hda_dsp_stream_hw_params: sof-audio-pci-intel-lnl 0000:00:1f.3: FW Poll Status: reg[0x1e0]=0x40000 successful
[  951.054363] snd_sof_intel_hda_common:hda_dsp_stream_setup_bdl: sof-audio-pci-intel-lnl 0000:00:1f.3: period_bytes:0x4000
[  951.054368] snd_sof_intel_hda_common:hda_dsp_stream_setup_bdl: sof-audio-pci-intel-lnl 0000:00:1f.3: periods:4
[  951.054402] snd_sof:sof_widget_setup_unlocked: sof-audio-pci-intel-lnl 0000:00:1f.3: widget alh-copier.SDW0-Playback.0 setup complete
[  951.058543] snd_sof:sof_pcm_trigger: sof-audio-pci-intel-lnl 0000:00:1f.3: pcm: trigger stream 0 dir 0 cmd 1
[  951.058571] snd_sof_intel_hda_common:hda_dsp_stream_trigger: sof-audio-pci-intel-lnl 0000:00:1f.3: FW Poll Status: reg[0x1e0]=0x14001e successful
[  951.061558] snd_sof_intel_hda_common:hda_dai_trigger: soundwire_intel soundwire_intel.link.0: cmd=1 dai SDW0 Pin2 direction 0
[  951.480061] soundwire_cadence:cdns_update_slave_status_work: soundwire_intel soundwire_intel.link.0: Slave status change: 0x4000000
[  951.483371] snd_soc_rt711_sdca:rt711_sdca_interrupt_callback: rt711-sdca sdw:0:0:025d:0711:01: rt711_sdca_interrupt_callback control_port_stat=4, sdca_cascade=1
[  951.486531] soundwire_cadence:cdns_update_slave_status_work: soundwire_intel soundwire_intel.link.0: Slave status change: 0x2000000
[  951.516788] rt711_sdca_headset_detect: trying to read from address 0x40600490
[  951.518023] rt711_sdca_headset_detect: done reading from address 0x40600490
[  951.518869] snd_soc_rt711_sdca:rt711_sdca_headset_detect: rt711-sdca sdw:0:0:025d:0711:01: rt711_sdca_headset_detect, detected_mode=0x3
[  951.518887] snd_soc_rt711_sdca:rt711_sdca_jack_detect_handler: rt711-sdca sdw:0:0:025d:0711:01: in rt711_sdca_jack_detect_handler, jack_type=0x1
[  951.518895] snd_soc_rt711_sdca:rt711_sdca_jack_detect_handler: rt711-sdca sdw:0:0:025d:0711:01: in rt711_sdca_jack_detect_handler, btn_type=0x0
[  951.518902] snd_soc_rt711_sdca:rt711_sdca_jack_detect_handler: rt711-sdca sdw:0:0:025d:0711:01: in rt711_sdca_jack_detect_handler, scp_sdca_stat1=0x1, scp_sdca_stat2=0x0
[  961.086983] snd_sof_intel_hda_common:hda_dai_trigger: soundwire_intel soundwire_intel.link.0: cmd=0 dai SDW0 Pin2 direction 0
[  961.092331] snd_sof:sof_pcm_trigger: sof-audio-pci-intel-lnl 0000:00:1f.3: pcm: trigger stream 0 dir 0 cmd 0
[  961.092358] snd_sof_intel_hda_common:hda_dsp_stream_trigger: sof-audio-pci-intel-lnl 0000:00:1f.3: FW Poll Status: reg[0x1e0]=0x140000 successful
[  961.092655] snd_sof:sof_pcm_hw_free: sof-audio-pci-intel-lnl 0000:00:1f.3: pcm: free stream 0 dir 0
[  961.092710] snd_sof:sof_widget_free_unlocked: sof-audio-pci-intel-lnl 0000:00:1f.3: widget alh-copier.SDW0-Playback.0 freed
[  961.101499] snd_sof:sof_pcm_close: sof-audio-pci-intel-lnl 0000:00:1f.3: pcm: close stream 0 dir 0

@plbossart
Copy link
Member Author

The main difference is that BPT resumes the PCI device but not the card. I don't know ASoC enough but I suspect there's some magic for jack detection coming from the card.

@plbossart
Copy link
Member Author

forcing a pm_runtime resume manually works fine,

cd /sys/bus/pci/devices/0000:00:1f.3/soundwire_intel.link.0/sdw-master-0-0/sdw:0:0:025d:0711:01/power
echo on > control
[10149.894059] soundwire_bus:sdw_handle_slave_status: rt711-sdca sdw:0:0:025d:0711:01: signaling initialization completion for Slave 6
[10150.377913] soundwire_cadence:cdns_update_slave_status_work: soundwire_intel soundwire_intel.link.0: Slave status change: 0x4000000
[10150.380378] snd_soc_rt711_sdca:rt711_sdca_interrupt_callback: rt711-sdca sdw:0:0:025d:0711:01: rt711_sdca_interrupt_callback control_port_stat=4, sdca_cascade=1
[10150.384941] soundwire_cadence:cdns_update_slave_status_work: soundwire_intel soundwire_intel.link.0: Slave status change: 0x2000000
[10150.415072] rt711_sdca_headset_detect: trying to read from address 0x40600490
[10150.416204] rt711_sdca_headset_detect: done reading from address 0x40600490

it's as if the use of DP0 causes the issue. Humm, maybe it's the interrupt register that's shared with SDCA...

@shumingfan
Copy link

shumingfan commented Jan 17, 2024

[ 461.369199] soundwire_intel:intel_ace2x_bpt_send_async: soundwire_intel soundwire_intel.link.0: BPT Transfer start
...
[ 461.379101] soundwire_bus:do_bpt_sequence: rt711-sdca sdw:0:0:025d:0711:01: send_async done
[ 461.379103] soundwire_intel:intel_ace2x_bpt_wait: soundwire_intel soundwire_intel.link.0: BPT Transfer wait
...
[ 461.872854] IO error in rt711_sdca_headset_detect, ret -61
...
[ 462.748441] soundwire_intel:intel_ace2x_bpt_wait: soundwire_intel soundwire_intel.link.0: BPT Transfer done

Sorry, I can't find the source code that prints the BPT Transfer start/wait/done.
BPT and generic read both use DP0. Have any settings of DP0 changed while BPT transfer?
I'm not sure whether the BPT transfer influences the SDCA_control read/write operation.
SDCA_Control will use the paging registers, not a single read/write operation.

@plbossart
Copy link
Member Author

The BPT protocol uses DP0, but regular command use column0. In theory they are completely orthogonal, it's perfectly fine to send a read command while doing a BPT write.

That said, there's obviously some level of interference. The code for BPT is in PR #4679

@plbossart
Copy link
Member Author

@shumingfan @bardliao I think the issue is on the codec side, I added the following diff
1.diff.txt

diff --git a/sound/soc/codecs/rt711-sdca-sdw.c b/sound/soc/codecs/rt711-sdca-sdw.c
index 34a0d9e0ce39..55b351fa75cf 100644
--- a/sound/soc/codecs/rt711-sdca-sdw.c
+++ b/sound/soc/codecs/rt711-sdca-sdw.c
@@ -328,9 +328,17 @@ static int rt711_sdca_interrupt_callback(struct sdw_slave *slave,
                        "%s scp_sdca_stat1=0x%x, scp_sdca_stat2=0x%x\n", __func__,
                        rt711->scp_sdca_stat1, rt711->scp_sdca_stat2);
 
-       if (status->sdca_cascade && !rt711->disable_irq)
+       if (status->sdca_cascade && !rt711->disable_irq) {
+
+               dev_warn(&slave->dev,
+                        "%s PLB before jack_detect_work\n", __func__);
+
                mod_delayed_work(system_power_efficient_wq,
-                       &rt711->jack_detect_work, msecs_to_jiffies(30));
+                       &rt711->jack_detect_work, msecs_to_jiffies(100));
+
+               dev_warn(&slave->dev,
+                        "%s PLB after jack_detect_work\n", __func__);
+       }
 
        mutex_unlock(&rt711->disable_irq_lock);
 
diff --git a/sound/soc/codecs/rt711-sdca.c b/sound/soc/codecs/rt711-sdca.c
index 447154cb6010..3bf8d1027967 100644
--- a/sound/soc/codecs/rt711-sdca.c
+++ b/sound/soc/codecs/rt711-sdca.c
@@ -248,12 +248,35 @@ static int rt711_sdca_headset_detect(struct rt711_sdca_priv *rt711)
        unsigned int det_mode;
        int ret;
 
+       dev_warn(&rt711->slave->dev,
+                "%s start hw_init %d\n", __func__, rt711->hw_init);
+
+       {
+               int int1;
+               int val;
+
+               int1 = sdw_read_no_pm(rt711->slave, SDW_SCP_SDCA_INT1);
+
+               dev_warn(&rt711->slave->dev,
+                        "%s int1 read %d\n", __func__, int1);
+
+               val = sdw_read_no_pm(rt711->slave,
+                                    SDW_SDCA_CTL(FUNC_NUM_JACK_CODEC,
+                                                 RT711_SDCA_ENT_GE49,
+                                                 RT711_SDCA_CTL_DETECTED_MODE, 0));
+               dev_warn(&rt711->slave->dev,
+                        "%s read %d\n", __func__, val);
+       }
[   58.459538] soundwire_cadence:cdns_update_slave_status_work: soundwire_intel soundwire_intel.link.0: Slave status change: 0x4000000
[   58.461036] snd_soc_rt711_sdca:rt711_sdca_interrupt_callback: rt711-sdca sdw:0:0:025d:0711:01: rt711_sdca_interrupt_callback control_port_stat=4, sdca_cascade=1
[   58.462654] rt711-sdca sdw:0:0:025d:0711:01: rt711_sdca_interrupt_callback PLB before jack_detect_work
[   58.462657] rt711-sdca sdw:0:0:025d:0711:01: rt711_sdca_interrupt_callback PLB after jack_detect_work
[   58.463905] soundwire_cadence:cdns_update_slave_status_work: soundwire_intel soundwire_intel.link.0: Slave status change: 0x2000000
[   58.569787] rt711-sdca sdw:0:0:025d:0711:01: rt711_sdca_headset_detect start hw_init 1
[   58.570127] rt711-sdca sdw:0:0:025d:0711:01: rt711_sdca_headset_detect int1 read 0
[   58.570497] soundwire_cadence:cdns_fill_msg_resp: soundwire_intel soundwire_intel.link.0: Msg ignored for Slave 6
[   58.570501] rt711-sdca sdw:0:0:025d:0711:01: rt711_sdca_headset_detect read -61
[   58.570915] soundwire_cadence:cdns_fill_msg_resp: soundwire_intel soundwire_intel.link.0: Msg ignored for Slave 6
[   58.570919] rt711-sdca sdw:0:0:025d:0711:01: rt711_sdca_headset_detect first regmap failed
[   58.570960] IO error in rt711_sdca_headset_detect, ret -61

So basically doing a basic read works fine, but accessing a register inside the SDCA function fails.

Could this be a first example of the 'Function Busy" where we need to repeat the reads if the function cannot provide the results?

@plbossart
Copy link
Member Author

@shuming this happens when doing a BRA transfer to address 0x44010000, so wondering if a read to the SDCA function space can happen while a BRA transfer is on-going.

@shumingfan
Copy link

@plbossart I will check this issue with our hardware engineer. If any results, I will feedback to you.

@shumingfan
Copy link

shumingfan commented Feb 5, 2024

@plbossart Could you confirm whether the MIPI-defined registers 0x48/0x49 (SCP_AddrPage1/2) are correct before the control word of SDCA control reads?
The 0x48/0x49 should be
0048 0x80
0049 0xc0

@plbossart
Copy link
Member Author

@shumingfan the calibration works when there is no BPT/BRA transfer, so my guess is that the registers are correct. The problem occurs when we resume the device for a BPT/BRA transfer, at some point the calibration kicks in and that's where we get a failed read.

I will add a trace of when we change the SCP_Addr registers.

@plbossart
Copy link
Member Author

plbossart commented Feb 5, 2024

@shumingfan here's the log you wanted. addr_page1 0x80 and addr_page2 0xc0, no issue

[   78.382778] soundwire_intel:intel_ace2x_bpt_wait: soundwire_intel soundwire_intel.link.0: BPT Transfer wait
[   78.721048] soundwire_cadence:cdns_update_slave_status_work: soundwire_intel soundwire_intel.link.0: Slave status change: 0x4000000
[   78.722396] snd_soc_rt711_sdca:rt711_sdca_interrupt_callback: rt711-sdca sdw:0:0:025d:0711:01: rt711_sdca_interrupt_callback control_port_stat=4, sdca_cascade=1
[   78.724204] rt711-sdca sdw:0:0:025d:0711:01: rt711_sdca_interrupt_callback PLB before jack_detect_work
[   78.724208] rt711-sdca sdw:0:0:025d:0711:01: rt711_sdca_interrupt_callback PLB after jack_detect_work
[   78.725206] soundwire_cadence:cdns_update_slave_status_work: soundwire_intel soundwire_intel.link.0: Slave status change: 0x2000000
[   78.829103] rt711-sdca sdw:0:0:025d:0711:01: rt711_sdca_headset_detect start hw_init 1
[   78.829339] rt711-sdca sdw:0:0:025d:0711:01: rt711_sdca_headset_detect int1 read 0
[   78.829342] rt711-sdca sdw:0:0:025d:0711:01: sdw_fill_msg: plb addr_page1 0x80 addr_page2 0xc0 page 1
[   78.829767] soundwire_cadence:cdns_fill_msg_resp: soundwire_intel soundwire_intel.link.0: Msg ignored for Slave 6
[   78.829770] rt711-sdca sdw:0:0:025d:0711:01: rt711_sdca_headset_detect read -61
[   78.829774] rt711-sdca sdw:0:0:025d:0711:01: sdw_fill_msg: plb addr_page1 0x80 addr_page2 0xc0 page 1
[   78.830218] soundwire_cadence:cdns_fill_msg_resp: soundwire_intel soundwire_intel.link.0: Msg ignored for Slave 6
[   78.830222] rt711-sdca sdw:0:0:025d:0711:01: rt711_sdca_headset_detect first regmap failed
[   78.830281] IO error in rt711_sdca_headset_detect, ret -61

@shumingfan
Copy link

@plbossart Hmm..it is hard to read back 0x48/0x49 registers before the last read command.
Could you try that the BPT stream data doesn't cross row 33 of the control word?
It means that the stream data doesn't touch read/write RegData of the control word.

@plbossart
Copy link
Member Author

@shumingfan the BPT/BRA stream uses columns 1..3, it's completely independent from the command word.

Again the issue is
a) BPT/BRA can access the SCDA registers
b) regular reads can access SDCA registers
c) when trying a) and b) concurrently, b) fails with a Command_Ignored.

Such an error can only come if

  1. the device lost sync and is no longer enumerated. That's not the case
  2. the register does not exist. That's not the case
  3. the Function is "Busy" as defined in the SDCA spec
  4. there is some sort of hardware dependency not described in the SDCA spec

My money is on 3) or 4)

@plbossart
Copy link
Member Author

More traces show the access to the Entity0::Function_Status register (Control 0x10) bit also yields a Command_Ignored value.

	        val = sdw_read_no_pm(rt711->slave,
				     SDW_SDCA_CTL(FUNC_NUM_JACK_CODEC,
						  0, 0x10, 0));

		dev_warn(&rt711->slave->dev,
			 "%s function status read %d %#x\n", __func__, val, val);
[   61.590014] rt711-sdca sdw:0:0:025d:0711:01: rt711_sdca_headset_detect start hw_init 1
[   61.590107] rt711-sdca sdw:0:0:025d:0711:01: rt711_sdca_headset_detect int1 read 0
[   61.590109] rt711-sdca sdw:0:0:025d:0711:01: sdw_fill_msg: plb addr_page1 0x80 addr_page2 0xc0 page 1
[   61.590264] soundwire_cadence:cdns_fill_msg_resp: soundwire_intel soundwire_intel.link.0: Msg ignored for Slave 7
[   61.590266] rt711-sdca sdw:0:0:025d:0711:01: rt711_sdca_headset_detect read -61
[   61.590268] rt711-sdca sdw:0:0:025d:0711:01: sdw_fill_msg: plb addr_page1 0x80 addr_page2 0x90 page 1
[   61.590424] soundwire_cadence:cdns_fill_msg_resp: soundwire_intel soundwire_intel.link.0: Msg ignored for Slave 7
[   61.590426] rt711-sdca sdw:0:0:025d:0711:01: rt711_sdca_headset_detect function status read -61 0xffffffc3
[   61.590430] rt711-sdca sdw:0:0:025d:0711:01: sdw_fill_msg: plb addr_page1 0x80 addr_page2 0xc0 page 1
[   61.590574] soundwire_cadence:cdns_fill_msg_resp: soundwire_intel soundwire_intel.link.0: Msg ignored for Slave 7
[   61.590576] rt711-sdca sdw:0:0:025d:0711:01: rt711_sdca_headset_detect first regmap failed
[   61.590636] IO error in rt711_sdca_headset_detect, ret -61

That is a BIG problem, this means the Function_Status cannot be accessed. In theory the Command_Ignored cannot happen for this sort of register, because that's what we need to read if there is a Command_Ignored reply.

So the conclusion is that 4) is the most likely problem, with a TBD dependency between control channel using paged access and Bulk.

@shumingfan
Copy link

@plbossart The ALC711-VD (rt711-sdca) just follows the SDCA v0.6 version. There is no Function_Status control inside.
I will discuss the information you shared with our engineer.

@shumingfan
Copy link

@plbossart Could you dump some settings while testing? We want to simulate this case.

  1. frame shape
  2. BRA DP0 setting :
    (1) word length (0x0003)
    (2) interval (0x0022,0x0023)
    (3) offset (0x0024, 0x0025)
    (4) hstart, hend (0x0026)
  3. BRA byte count :
    (1) bra byte count per frame
    (2) bra frame count
  4. BPT/BRA test file?

@plbossart
Copy link
Member Author

  1. frame shape

50x4, 4.8 MHz
we use 3 columns for BRA, so

settings are fixed here, you need to convert them to actual register encoding

9243784#diff-905f617727dbd063de023ac974441b3b35b35cba5e37cdd9559bf929d1ac5756R126

  1. BRA DP0 setting :
    (1) word length (0x0003)

3 (all three columns)

(2) interval (0x0022,0x0023)

4 (one entire row)

(3) offset (0x0024, 0x0025)

0

(4) hstart, hend (0x0026)

hstart 1, hstop 3

  1. BRA byte count :
    (1) bra byte count per frame

8

(2) bra frame count

doesn't matter, it's linked to the file size.

  1. BPT/BRA test file?

doesn't matter, I sent an all zero file with 32768 bytes

@shumingfan
Copy link

@plbossart The designer simulated this condition that he couldn't see the ignored response when reading SDCA registers.
However, if you access the address over 0x4401FBFF, it will reply to the ignored command.
The log shows
[ 461.112144] soundwire_bus:set_num_bytes: rt711-sdca sdw:0:0:025d:0711:01: number of bytes 524288
Please check that whether we don't access the address over 0x4401FBFF.

@plbossart
Copy link
Member Author

oh, could this be a side effect then where the BPT/BRA transfer accesses an invalid part of the memory without an error reported, but the Command_Ignored is reported during a regular read to a valid address?

Did I get this right @shumingfan ?

@shumingfan
Copy link

@plbossart Right, your test should do the BPT/BRA and a regular read at the same time.
The BPT/BRA transfer accesses an invalid address, it will affect the regular read.

@plbossart
Copy link
Member Author

Thanks @shumingfan, that helps. I'll close this issue as won't fix since it's an invalid configuration handled the wrong way, but it's invalid to start with.

@plbossart plbossart closed this as not planned Won't fix, can't repro, duplicate, stale Feb 16, 2024
@plbossart plbossart added won't fix This will not be worked on atm (e.g. a bug closed for lack of user request, hardware etc) SDW Applies to SoundWire bus for codec connection labels Feb 16, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
SDW Applies to SoundWire bus for codec connection won't fix This will not be worked on atm (e.g. a bug closed for lack of user request, hardware etc)
Projects
None yet
Development

No branches or pull requests

2 participants