[BUG][SDW]"IO error in rt711_jack_detect_handler, ret -16" occurred when plug in or unplug headphone

[YvonneYang2]

Describe the bug
With sof and master pm runtime disabled, unplug/plug in headphone dmesg will show "IO error in rt711_jack_detect_handler, ret -16"

To Reproduce

1. Disable master and sof runtime PM status via add sof-pci-debug=1 and sdw_md_flags=0x01000001, then reboot to make it work.
2. Open one terminal and run command "dmesg -w"
3. Plug in/unlug headphone, and check in terminal

Reproduced rate
100%

Expected result
Should not show error info

Actual result
Dmesg shows "IO error in rt711_jack_detect_handler, ret -16" after unplug or plug in headphone

Dmesg

[   88.204121] intel-sdw sdw-master-0: Slave 1 status attached, was alert, ignoring
[   88.204122] intel-sdw sdw-master-0: Updating Slave 1 status
[   88.204123] intel-sdw sdw-master-0: sdw_handle_slave_status: Updating Slave 1 status done
[   88.204125] intel-sdw sdw-master-0: sdw_handle_slave_status: end
[   88.455320] IO error in rt711_jack_detect_handler, ret -16
[   91.519314] intel-sdw sdw-master-0: Slave status change
[   91.519324] intel-sdw sdw-master-0: sdw_handle_slave_status: start
[   91.519485] rt711 sdw:0:25d:711:0: Slave impl defined interrupt
[   91.519491] rt711 sdw:0:25d:711:0: rt711_interrupt_callback control_port_stat=4
[   91.519693] intel-sdw sdw-master-0: Updating Slave 1 status
[   91.519703] intel-sdw sdw-master-0: sdw_handle_slave_status: Updating Slave 1 status done
[   91.519708] intel-sdw sdw-master-0: sdw_handle_slave_status: end
[   91.519740] intel-sdw sdw-master-0: Slave status change
[   91.519745] intel-sdw sdw-master-0: sdw_handle_slave_status: start

IO_error.log

Test recipe:
kernel: https://github.com/thesofproject/linux/tree/integration/soundwire-latest commit: add887e
FW: https://github.com/thesofproject/sof/commits/master commit: 65de27d
tplg: Same with FW branch, sof-cml-rt711-rt1308-mono-rt715.tplg
platform: CML-U Laptop with codec ALC711, RT1308, RT715 in SDW mode

[YvonneYang2]

Tested it with #1589 ,issue cannot be reproduced.

[YvonneYang2]

Tested it with integration/soundwire-latest(d64c4a3) + #1586, issue cannot be reproduced.

[plbossart]

@YvonneYang2 @bardliao @RanderWang @shumingfan I can reproduce these warnings with the udpated PR #1586

when doing very fast jack insertion/removal, on removal the codec driver seems to issue a ton of commands which don't seem to complete before the codec suspend routine quicks in

[  184.035071] rt711 sdw:0:25d:711:0: [rt711_sdw_read] 7520 85a0 9c20 aca0 => 00000404
[  184.045885] rt711 sdw:0:25d:711:0: [rt711_sdw_read] 7520 85a0 9c20 aca0 => 00000404
[  184.056884] rt711 sdw:0:25d:711:0: [rt711_sdw_read] 7520 85a0 9c20 aca0 => 00000404
[  184.067823] rt711 sdw:0:25d:711:0: [rt711_sdw_read] 7520 85a0 9c20 aca0 => 00000404
[  184.078824] rt711 sdw:0:25d:711:0: [rt711_sdw_read] 7520 85a0 9c20 aca0 => 00000404
[  184.089928] rt711 sdw:0:25d:711:0: [rt711_sdw_read] 7520 85a0 9c20 aca0 => 00000404
[  184.100949] rt711 sdw:0:25d:711:0: [rt711_sdw_read] 7520 85a0 9c20 aca0 => 00000404
[  184.111990] rt711 sdw:0:25d:711:0: [rt711_sdw_read] 7520 85a0 9c20 aca0 => 00000404
[  184.121175] rt711 sdw:0:25d:711:0: rt711_dev_suspend start
[  184.121183] rt711 sdw:0:25d:711:0: rt711_dev_suspend end
[  184.121205] Failed to get private value: 752046 => 0000 ret=-16
[  184.121214] IO error in rt711_headset_detect, ret -16
[  184.121221] IO error in rt711_jack_detect_handler, ret -16

dmesg_hs_removal.log

If I take my time between insertion and removal no issues

This is with only the option

options snd-sof-intel-hda-common sdw_clock_stop_quirks=0x8

and pm_runtime remains enabled

[shumingfan]

@YvonneYang2 Could you test with PR #1605 when doing fast jack insertion/removal?
@plbossart I think the jack is removed during the jack type detection. So, I added the pin sense check in the detection loop.

[YvonneYang2]

@plbossart
I tested it with options snd-sof-intel-hda-common sdw_clock_stop_quirks=0x8 and updated #1586 , but seems can not reproduce the issue as you mentioned. Tried to do very fast jack insertion/removal, but dmesg always shows normal.
@bardliao
Could you test it on your side and help to reproduce it ? Thanks ~

Test recipe:
kernel: https://github.com/thesofproject/linux/tree/integration/soundwire-latest commit: b036eac + PR1586
FW: https://github.com/thesofproject/sof/commits/master commit: 65de27d
tplg: Same with FW branch, sof-cml-rt711-rt1308-mono-rt715.tplg
platform: CML-U Laptop with codec ALC711, RT1308, RT715 in SDW mode

[RanderWang]

@YvonneYang2 @bardliao @RanderWang @shumingfan I can reproduce these warnings with the udpated PR #1586

when doing very fast jack insertion/removal, on removal the codec driver seems to issue a ton of commands which don't seem to complete before the codec suspend routine quicks in

[  184.035071] rt711 sdw:0:25d:711:0: [rt711_sdw_read] 7520 85a0 9c20 aca0 => 00000404
[  184.045885] rt711 sdw:0:25d:711:0: [rt711_sdw_read] 7520 85a0 9c20 aca0 => 00000404
[  184.056884] rt711 sdw:0:25d:711:0: [rt711_sdw_read] 7520 85a0 9c20 aca0 => 00000404
[  184.067823] rt711 sdw:0:25d:711:0: [rt711_sdw_read] 7520 85a0 9c20 aca0 => 00000404
[  184.078824] rt711 sdw:0:25d:711:0: [rt711_sdw_read] 7520 85a0 9c20 aca0 => 00000404
[  184.089928] rt711 sdw:0:25d:711:0: [rt711_sdw_read] 7520 85a0 9c20 aca0 => 00000404
[  184.100949] rt711 sdw:0:25d:711:0: [rt711_sdw_read] 7520 85a0 9c20 aca0 => 00000404
[  184.111990] rt711 sdw:0:25d:711:0: [rt711_sdw_read] 7520 85a0 9c20 aca0 => 00000404
[  184.121175] rt711 sdw:0:25d:711:0: rt711_dev_suspend start
[  184.121183] rt711 sdw:0:25d:711:0: rt711_dev_suspend end
[  184.121205] Failed to get private value: 752046 => 0000 ret=-16
[  184.121214] IO error in rt711_headset_detect, ret -16
[  184.121221] IO error in rt711_jack_detect_handler, ret -16

dmesg_hs_removal.log

If I take my time between insertion and removal no issues

This is with only the option

options snd-sof-intel-hda-common sdw_clock_stop_quirks=0x8

and pm_runtime remains enabled

Customer also reported a issue on HDA device that fast plug-unplug headphone can't be detected. @Kailang. He said codec need time to detect the change. And customer closed this bug for they consider it as a unusual operation. @shumingfan , can you help to check why codec spend so much time to read register ? Thanks!

[YvonneYang2]

Update the comments #1602 (comment) .
With options snd-sof-intel-hda-common sdw_clock_stop_quirks=0x8, can reproduce the issue 100% with test steps as below:

1. Open a terminal and run command "dmesg -w"
2. Plug in headphone then unplug it immediately, better unplug it in 0.5 second.
3. Wait that dmesg finished printing, and you could see issue occurred.

@shumingfan
Tested it with #1605 , issue cannot be reproduced.

[bardliao]

@bardliao
Could you test it on your side and help to reproduce it ? Thanks ~

Looks like you can reproduce it already :)

[YvonneYang2]

Since PR1605 has been merged into integration/soundwire-latest , retested it again, issue cannot be reproduced on integration/soundwire-latest(e375909) + #1586 with options snd-sof-intel-hda-common sdw_clock_stop_quirks=0x8.

[YvonneYang2]

Issue cannot be reproduced with latest integration/soundwire-latest( cf2660a ) and cml-010-drop-stable (5e5f69e). Close it.