Skip to content

[BUG][MTL]rt1316-sdca: DPN_PortCtrl register write failed for port 2 #4567

Description

@keqiaozhang

Describe the bug
Observed this bug on MTL-SDW with Realtek GEN4.1 AIOC for SDW rt711/rt714/rt1316. It happens when conducting a stress test for capture.

dmesg

[12041.412844] kernel: snd_sof:sof_widget_setup_unlocked: sof-audio-pci-intel-mtl 0000:00:1f.3: widget host-copier.3.capture setup complete
[12041.412847] kernel: snd_sof:sof_ipc4_route_setup: sof-audio-pci-intel-mtl 0000:00:1f.3: bind alh-copier.SDW2-Capture.0:0 -> host-copier.3.capture:0
[12041.412851] kernel: snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-mtl 0000:00:1f.3: ipc tx      : 0x45000004|0x10004: MOD_BIND
[12041.413865] kernel: snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-mtl 0000:00:1f.3: ipc tx reply: 0x65000000|0x10004: MOD_BIND
[12041.413881] kernel: snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-mtl 0000:00:1f.3: ipc tx done : 0x45000004|0x10004: MOD_BIND
[12041.414040] kernel: soundwire_cadence:cdns_update_slave_status_work: soundwire_intel soundwire_intel.link.2: Slave status change: 0x2
[12041.414042] kernel: soundwire_cadence:cdns_fill_msg_resp: soundwire_intel soundwire_intel.link.2: Msg ignored for Slave 1
[12041.414049] kernel: rt1316-sdca sdw:2:025d:1316:01: DPN_PortCtrl register write failed for port 2
[12041.414088] kernel: soundwire sdw-master-2: Program transport params failed: -61
[12041.414111] kernel: soundwire sdw-master-2: Program params failed: -61
[12041.414131] kernel:  SDW2-Capture: ASoC: error at snd_soc_link_prepare on SDW2-Capture: -61
[12041.414134] kernel: soundwire_bus:sdw_handle_slave_status: soundwire sdw-master-2: Slave attached, programming device number
[12041.414156] kernel:  SDW2-Capture: ASoC: error at __soc_pcm_prepare on SDW2-Capture: -61
[12041.414181] kernel:  Amp feedback: ASoC: error at dpcm_be_dai_prepare on Amp feedback: -61
[12041.414206] kernel:  Amp feedback: ASoC: error at dpcm_fe_dai_prepare on Amp feedback: -61
[12041.414349] kernel: soundwire_bus:sdw_extract_slave_id: soundwire sdw-master-2: SDW Slave Addr: 31025d131601

To Reproduce
~/sof-test/test-case/check-capture.sh -d 3 -l 1 -r 300
or
~/sof-test/test-case/multiple-pause-resume.sh -r 100

Reproduction Rate
Can be reproduced manually under stress testing.

Environment

  1. Branch name and commit hash of the 2 repositories: sof (firmware/topology) and linux (kernel driver).
  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: model MTLP_SDW_AIOC-ace1_0-ipc4,
    • device: sh-mtlp-rvp-sdw-04 (w/o F14 rework, using RT711 on RVP mother board on link0, external 2x RT1316 and RT714 on Gen4 AIOC)
      dmesg.txt
      mtrace.txt

Activity

  1. added
    bugSomething isn't working
    codecCodec HW or driver restriction
    SDWApplies to SoundWire bus for codec connection
    MTLApplies to Meteor Lake platform.
    on Sep 5, 2023
  2. added
    P1Blocker bugs or important features
    on Sep 5, 2023
  3. changed the title [-][BUG][MTL] rt1316-sdca: DPN_PortCtrl register write failed for port 2[/-] [+][BUG][MTL][v2.7] rt1316-sdca: DPN_PortCtrl register write failed for port 2[/+] on Sep 5, 2023
  4. changed the title [-][BUG][MTL][v2.7] rt1316-sdca: DPN_PortCtrl register write failed for port 2[/-] [+][BUG][MTL]rt1316-sdca: DPN_PortCtrl register write failed for port 2[/+] on Sep 5, 2023
  5. bardliao commented on Sep 5, 2023

    @bardliao
    Collaborator

    The issue seems to be a corner case where slave unattached right before pcm open, and sdw_prepare_stream() is called before the slave attached.

    [12041.407762] kernel: soundwire_cadence:cdns_update_slave_status_work: soundwire_intel soundwire_intel.link.2: Slave status change: 0x10
    [12041.407801] kernel: rt1316-sdca sdw:2:025d:1316:01: Slave 1 state check1: UNATTACHED, status was 1
    [12041.407806] kernel: soundwire_bus:sdw_modify_slave_status: rt1316-sdca sdw:2:025d:1316:01: initializing enumeration and init completion for Slave 1
    [12041.409486] kernel: soundwire_cadence:cdns_update_slave_status_work: soundwire_intel soundwire_intel.link.3: Slave status change: 0x10
    [12041.409507] kernel: rt1316-sdca sdw:3:025d:1316:01: Slave 1 state check1: UNATTACHED, status was 1
    [12041.409509] kernel: soundwire_bus:sdw_modify_slave_status: rt1316-sdca sdw:3:025d:1316:01: initializing enumeration and init completion for Slave 1
    [12041.411025] kernel: snd_sof:sof_pcm_open: sof-audio-pci-intel-mtl 0000:00:1f.3: pcm: open stream 3 dir 1
    
    [12041.414040] kernel: soundwire_cadence:cdns_update_slave_status_work: soundwire_intel soundwire_intel.link.2: Slave status change: 0x2
    [12041.414042] kernel: soundwire_cadence:cdns_fill_msg_resp: soundwire_intel soundwire_intel.link.2: Msg ignored for Slave 1
    [12041.414049] kernel: rt1316-sdca sdw:2:025d:1316:01: DPN_PortCtrl register write failed for port 2
    [12041.414088] kernel: soundwire sdw-master-2: Program transport params failed: -61
    [12041.414111] kernel: soundwire sdw-master-2: Program params failed: -61
    [12041.414131] kernel:  SDW2-Capture: ASoC: error at snd_soc_link_prepare on SDW2-Capture: -61
    [12041.414134] kernel: soundwire_bus:sdw_handle_slave_status: soundwire sdw-master-2: Slave attached, programming device number
    

    We probably need to wait for slave->initialization_complete before program slave port params. What do you think? @plbossart

  6. plbossart commented on Sep 5, 2023

    @plbossart
    Member

    I think you still have issues with the AIC connection, a codec is not supposed to become UNATTACHED. When it does everything goes boink.

  7. bardliao commented on Sep 6, 2023

    @bardliao
    Collaborator

    I think you still have issues with the AIC connection, a codec is not supposed to become UNATTACHED. When it does everything goes boink.

    But the UNATTACHED doesn't happen randomly. It happens about 3 seconds after clock stopped.

    [12038.676436] kernel: soundwire_bus:sdw_bus_wait_for_clk_prep_deprep: soundwire sdw-master-3: clock stop prep/de-prep done slave:15
    [12038.676455] kernel: soundwire_bus:sdw_bus_wait_for_clk_prep_deprep: soundwire sdw-master-2: clock stop prep/de-prep done slave:15
    ...
    [12041.407801] kernel: rt1316-sdca sdw:2:025d:1316:01: Slave 1 state check1: UNATTACHED, status was 1
    [12041.407806] kernel: soundwire_bus:sdw_modify_slave_status: rt1316-sdca sdw:2:025d:1316:01: initializing enumeration and init completion for Slave 1
    [12041.409486] kernel: soundwire_cadence:cdns_update_slave_status_work: soundwire_intel soundwire_intel.link.3: Slave status change: 0x10
    [12041.409507] kernel: rt1316-sdca sdw:3:025d:1316:01: Slave 1 state check1: UNATTACHED, status was 1
    [12041.409509] kernel: soundwire_bus:sdw_modify_slave_status: rt1316-sdca sdw:3:025d:1316:01: initializing enumeration and init completion for Slave 1
    
  8. bardliao commented on Sep 6, 2023

    @bardliao
    Collaborator

    @plbossart I didn't get the reason yet, but rt1316 always unattach after previous pcm close in my test even if I add 500 ms delay before and after calling snd_sof_pcm_platform_close in sof_pcm_close.

    [   95.710758] snd_sof:sof_pcm_close: sof-audio-pci-intel-mtl 0000:00:1f.3: pcm: close stream 1 dir 1
    [   95.710762] sof-audio-pci-intel-mtl 0000:00:1f.3: sof_pcm_close wait before calling snd_sof_pcm_platform_close
    [   96.214472] sof-audio-pci-intel-mtl 0000:00:1f.3: sof_pcm_close wait after calling snd_sof_pcm_platform_close
    [   96.740477] soundwire_cadence:cdns_update_slave_status_work: soundwire_intel soundwire_intel.link.2: Slave status change: 0x10
    [   96.740496] rt1316-sdca sdw:2:025d:1316:01: Slave 1 state check1: UNATTACHED, status was 1
    [   96.740501] soundwire_bus:sdw_modify_slave_status: rt1316-sdca sdw:2:025d:1316:01: initializing enumeration and init completion for Slave 1
    [   96.742465] soundwire_cadence:cdns_update_slave_status_work: soundwire_intel soundwire_intel.link.3: Slave status change: 0x10
    [   96.742491] rt1316-sdca sdw:3:025d:1316:01: Slave 1 state check1: UNATTACHED, status was 1
    [   96.742494] soundwire_bus:sdw_modify_slave_status: rt1316-sdca sdw:3:025d:1316:01: initializing enumeration and init completion for Slave 1
    

    Note that the previous pcm is rt711 capture, not the same pcm as the rt1316 feedback.

    @keqiaozhang Can you test with #4572?

  9. plbossart commented on Sep 6, 2023

    @plbossart
    Member

    @bardliao we need to figure out the root cause. I don't understand how a codec can report as UNATTACHED if the clock is already stopped, and if it reports UNATTACHED while we are in the process of stopping the clock then it's an error we want to ignore.

  10. mengdonglin commented on Sep 9, 2023

    @mengdonglin

    @plbossart @bardliao This issue was reproduced in v2.7-rc1 stress test https://sof-ci.ostc.intel.com/#/result/planresultdetail/31509
    2 cases failed on MTL RVP with GEN4 AIOC, device jf-mtlp-rvp-nocodec-4:
    check-capture-300rounds.sh
    multiple-pause-resume-100.sh

  11. bardliao commented on Sep 12, 2023

    @bardliao
    Collaborator

    It looks like there are some interactions between the on board rt711 and the AIOC rt1316.

    I tested it on 4 MTL RVPs, 2 with rework and 2 without rework, and the issue happens only on the non-reworked MTL RVP.
    The difference between reworked and non-reworked MTL RVP is that the non-reworked MTL RVP uses the on board rt711 combine with the AIOC rt1316 and rt714, and the reworked MTL RVP uses AIOC's rt711 instead. I.e. All rt711, rt1316, and rt714 are on the AIOC.

    Besides, I can reproduce the UNATTACH log with below command.
    arecord -Dhw:0,3 -fs32_le -r48000 -c4 /tmp/test.wav -vv -d3; arecord -Dhw:0,1 -fs32_le -r48000 -c2 /tmp/test.wav -vv -d3; arecord -Dhw:0,3 -fs32_le -r48000 -c4 /tmp/test.wav -vv -d3

    but not

    arecord -Dhw:0,3 -fs32_le -r48000 -c4 /tmp/test.wav -vv -d3; arecord -Dhw:0,4 -fs32_le -r48000 -c2 /tmp/test.wav -vv -d3; arecord -Dhw:0,3 -fs32_le -r48000 -c4 /tmp/test.wav -vv -d3

    IOW, only rt711 is involved in the arecord test can reproduce the rt1316 UNATTACH issue.

  12. plbossart commented on Sep 12, 2023

    @plbossart
    Member

    Good catch @bardliao. because of tight timing, all devices have to be close, if the rt711 on the motheboard is on the same link as as an add-in card the link cannot possibly work reliably. Either all devices are on the motherboard, or they are all on the add-in board. Mixed configurations are not supported by Intel.

  13. bardliao commented on Sep 13, 2023

    @bardliao
    Collaborator

    Good catch @bardliao. because of tight timing, all devices have to be close, if the rt711 on the motheboard is on the same link as as an add-in card the link cannot possibly work reliably. Either all devices are on the motherboard, or they are all on the add-in board. Mixed configurations are not supported by Intel.

    @plbossart They are on different sdw links. I.e. rt711 is on link 0, rt1316s are on link 2 and 3, and rt714 is on link 1.

  14. plbossart commented on Sep 13, 2023

    @plbossart
    Member

    even if you have multiple links, using the same AC timing for all links will not work if the links have a completely different topology. One of the devices is going to see a weird signal and at some point lose sync.

  15. bardliao commented on Sep 14, 2023

    @bardliao
    Collaborator

    @plbossart Thanks to @keqiaozhang @aiChaoSONG, we found that the rt1316 power jumper is open on the AIOC. IOW, there is no required power support for the rt1316. That can explain why the rt1316 is so unstable. The issue is gone after connected the jumpers. And we can reproduce the issue if we open the jumpers on a different MTL RVP and AIOC which can't reproduce the issue before. So, I think it is the root cause.
    I will wait for @fredoh9 to check the AIOC in JF to see if the AIOC has the same wrong configuration before closing the issue.
    BTW, even the power jumpers are open, the rt1316 can still be attached. I think there is another power path to rt1316, but that is definitely not enough.

  16. keqiaozhang commented on Sep 15, 2023

    @keqiaozhang
    Author

    @fredoh9 please help to close this bug after you confirm/adjust the jumper settings on AIOC G4.1 board.

  17. fredoh9 commented on Sep 18, 2023

    @fredoh9
    Collaborator

    The power jumper setting for rt1316 in AIOC in JF was wrong, fixed the jumper settings. But I can't still hear sound from the speakers. Will work with Keqiao to sort of jumper settings.

  18. bardliao commented on Sep 18, 2023

    @bardliao
    Collaborator

    I confirmed the issue is gone on the MTL RVP in JF. The rt1316 silence issue is likely jumper/connection issue and not related to this issue. Let's close this issue.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

Labels

MTLApplies to Meteor Lake platform.P1Blocker bugs or important featuresSDWApplies to SoundWire bus for codec connectionbugSomething isn't workingcodecCodec HW or driver restrictionsof v2.7

Type

No type

Projects

No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions