Skip to content

FW reported error: 113 - Invalid destination queue (pin) ID provided following nocodec topology change 6318 #6367

Closed
Closed
FW reported error: 113 - Invalid destination queue (pin) ID provided following nocodec topology change 6318#6367
Assignees
RanderWang
Labels
P2Critical bugs or normal features

Description

@greg-intel
greg-intel
opened on Oct 4, 2022

Describe the bug
#6318 seems to have caused a major regression found in daily 15919?model=TGLU_RVP_NOCODEC_CAVSIPC4&testcase=check-playback-100sec, most tests are failing.

From /var/log/syslog (/var/log/journal/ has been entirely deleted on that system?!?)

Oct  3 21:34:24 sh-tglu-rvp-nocodec-ci-02 kernel: [  149.541660] snd_sof:sof_ipc4_route_setup: sof-audio-pci-intel-tgl 0000:00:1f.3: bind gain.7.1:0 -> copier.host.7.1:0
Oct  3 21:34:24 sh-tglu-rvp-nocodec-ci-02 kernel: [  149.541663] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx      : 0x45000006|0x10004: MOD_BIND
Oct  3 21:34:24 sh-tglu-rvp-nocodec-ci-02 kernel: [  149.541906] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx reply: 0x65000000|0x10004: MOD_BIND
Oct  3 21:34:24 sh-tglu-rvp-nocodec-ci-02 kernel: [  149.541944] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx done : 0x45000006|0x10004: MOD_BIND
Oct  3 21:34:24 sh-tglu-rvp-nocodec-ci-02 kernel: [  149.541951] snd_sof:sof_ipc4_route_setup: sof-audio-pci-intel-tgl 0000:00:1f.3: bind copier.SSP.8.1:0 -> gain.7.1:0
Oct  3 21:34:24 sh-tglu-rvp-nocodec-ci-02 kernel: [  149.541955] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx      : 0x45000004|0x6: MOD_BIND
Oct  3 21:34:24 sh-tglu-rvp-nocodec-ci-02 kernel: [  149.542162] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx reply: 0x65000071|0x6: MOD_BIND
Oct  3 21:34:24 sh-tglu-rvp-nocodec-ci-02 kernel: [  149.542165] sof-audio-pci-intel-tgl 0000:00:1f.3: FW reported error: 113 - Invalid destination queue (pin) ID provided
Oct  3 21:34:24 sh-tglu-rvp-nocodec-ci-02 kernel: [  149.542230] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc error for msg 0x45000004|0x6
Oct  3 21:34:24 sh-tglu-rvp-nocodec-ci-02 kernel: [  149.542237] sof-audio-pci-intel-tgl 0000:00:1f.3: sof_ipc4_route_setup: failed to bind modules copier.SSP.8.1 -> gain.7.1
Oct  3 21:34:24 sh-tglu-rvp-nocodec-ci-02 kernel: [  149.542245] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx      : 0x12000000|0x0: GLB_DELETE_PIPELINE
Oct  3 21:34:24 sh-tglu-rvp-nocodec-ci-02 kernel: [  149.542652] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx reply: 0x32000000|0x0: GLB_DELETE_PIPELINE
Oct  3 21:34:24 sh-tglu-rvp-nocodec-ci-02 kernel: [  149.542677] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx done : 0x12000000|0x0: GLB_DELETE_PIPELINE
Oct  3 21:34:24 sh-tglu-rvp-nocodec-ci-02 kernel: [  149.542681] snd_sof:sof_widget_free: sof-audio-pci-intel-tgl 0000:00:1f.3: widget pipeline.8 freed
Oct  3 21:34:24 sh-tglu-rvp-nocodec-ci-02 kernel: [  149.542683] snd_sof:sof_widget_free: sof-audio-pci-intel-tgl 0000:00:1f.3: widget copier.SSP.8.1 freed
Oct  3 21:34:24 sh-tglu-rvp-nocodec-ci-02 kernel: [  149.542685] snd_sof:sof_ipc4_route_free: sof-audio-pci-intel-tgl 0000:00:1f.3: unbind modules gain.7.1:0 -> copier.host.7.1:0
Oct  3 21:34:24 sh-tglu-rvp-nocodec-ci-02 kernel: [  149.542688] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx      : 0x46000006|0x10004: MOD_UNBIND
Oct  3 21:34:24 sh-tglu-rvp-nocodec-ci-02 kernel: [  149.542907] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx reply: 0x66000000|0x10004: MOD_UNBIND
Oct  3 21:34:24 sh-tglu-rvp-nocodec-ci-02 kernel: [  149.542944] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx done : 0x46000006|0x10004: MOD_UNBIND
Oct  3 21:34:24 sh-tglu-rvp-nocodec-ci-02 kernel: [  149.542948] snd_sof:sof_widget_free: sof-audio-pci-intel-tgl 0000:00:1f.3: widget gain.7.1 freed
Oct  3 21:34:24 sh-tglu-rvp-nocodec-ci-02 kernel: [  149.542951] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx      : 0x12010000|0x0: GLB_DELETE_PIPELINE
Oct  3 21:34:24 sh-tglu-rvp-nocodec-ci-02 kernel: [  149.543393] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx reply: 0x32000000|0x0: GLB_DELETE_PIPELINE
Oct  3 21:34:24 sh-tglu-rvp-nocodec-ci-02 kernel: [  149.543454] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx done : 0x12010000|0x0: GLB_DELETE_PIPELINE
Oct  3 21:34:24 sh-tglu-rvp-nocodec-ci-02 kernel: [  149.543461] snd_sof:sof_widget_free: sof-audio-pci-intel-tgl 0000:00:1f.3: widget pipeline.7 freed
Oct  3 21:34:24 sh-tglu-rvp-nocodec-ci-02 kernel: [  149.543463] snd_sof:sof_widget_free: sof-audio-pci-intel-tgl 0000:00:1f.3: widget copier.host.7.1 freed
Oct  3 21:34:24 sh-tglu-rvp-nocodec-ci-02 kernel: [  149.543467] sof-audio-pci-intel-tgl 0000:00:1f.3: error: failed widget list set up for pcm 0 dir 1
Oct  3 21:34:24 sh-tglu-rvp-nocodec-ci-02 kernel: [  149.543472] sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at snd_soc_pcm_component_hw_params on 0000:00:1f.3: -22
Oct  3 21:34:24 sh-tglu-rvp-nocodec-ci-02 kernel: [  149.543488]  Port0: ASoC: error at __soc_pcm_hw_params on Port0: -22
Oct  3 21:34:24 sh-tglu-rvp-nocodec-ci-02 kernel: [  149.543495]  Port0: ASoC: error at dpcm_fe_dai_hw_params on Port0: -22
Oct  3 21:34:24 sh-tglu-rvp-nocodec-ci-02 kernel: [  149.543501] snd_sof:sof_pcm_hw_free: sof-audio-pci-intel-tgl 0000:00:1f.3: pcm: free stream 0 dir 1
Oct  3 21:34:24 sh-tglu-rvp-nocodec-ci-02 kernel: [  149.543692] snd-soc-dummy snd-soc-dummy: Runtime PM usage count underflow!
Oct  3 21:34:24 sh-tglu-rvp-nocodec-ci-02 kernel: [  149.543695] snd_sof:sof_pcm_close: sof-audio-pci-intel-tgl 0000:00:1f.3: pcm: close stream 0 dir 1
Oct  3 21:34:24 sh-tglu-rvp-nocodec-ci-02 kernel: [  149.543707] snd-soc-dummy snd-soc-dummy: Runtime PM usage count underflow!
Oct  3 21:34:24 sh-tglu-rvp-nocodec-ci-02 ubuntu: ktime=149 sof-test PID=2904: ending
Oct  3 21:34:27 sh-tglu-rvp-nocodec-ci-02 kernel: [  151.865854] snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx      : 0x44000000|0x3060004c: MOD_LARGE_CONFIG_SET [data size: 76]

Also from the dmesg

[  149.542165] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: FW reported error: 113 - Invalid destination queue (pin) ID provided
[  149.542230] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc error for msg 0x45000004|0x6
[  149.542237] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: sof_ipc4_route_setup: failed to bind modules copier.SSP.8.1 -> gain.7.1
[  149.542245] kernel: snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx      : 0x12000000|0x0: GLB_DELETE_PIPELINE
[  149.542652] kernel: snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx reply: 0x32000000|0x0: GLB_DELETE_PIPELINE
[  149.542677] kernel: snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx done : 0x12000000|0x0: GLB_DELETE_PIPELINE
[  149.542681] kernel: snd_sof:sof_widget_free: sof-audio-pci-intel-tgl 0000:00:1f.3: widget pipeline.8 freed
[  149.542683] kernel: snd_sof:sof_widget_free: sof-audio-pci-intel-tgl 0000:00:1f.3: widget copier.SSP.8.1 freed
[  149.542685] kernel: snd_sof:sof_ipc4_route_free: sof-audio-pci-intel-tgl 0000:00:1f.3: unbind modules gain.7.1:0 -> copier.host.7.1:0
[  149.542688] kernel: snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx      : 0x46000006|0x10004: MOD_UNBIND
[  149.542907] kernel: snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx reply: 0x66000000|0x10004: MOD_UNBIND
[  149.542944] kernel: snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx done : 0x46000006|0x10004: MOD_UNBIND
[  149.542948] kernel: snd_sof:sof_widget_free: sof-audio-pci-intel-tgl 0000:00:1f.3: widget gain.7.1 freed
[  149.542951] kernel: snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx      : 0x12010000|0x0: GLB_DELETE_PIPELINE
[  149.543393] kernel: snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx reply: 0x32000000|0x0: GLB_DELETE_PIPELINE
[  149.543454] kernel: snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx done : 0x12010000|0x0: GLB_DELETE_PIPELINE
[  149.543461] kernel: snd_sof:sof_widget_free: sof-audio-pci-intel-tgl 0000:00:1f.3: widget pipeline.7 freed
[  149.543463] kernel: snd_sof:sof_widget_free: sof-audio-pci-intel-tgl 0000:00:1f.3: widget copier.host.7.1 freed
[  149.543467] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: error: failed widget list set up for pcm 0 dir 1
[  149.543472] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ASoC: error at snd_soc_pcm_component_hw_params on 0000:00:1f.3: -22
[  149.543488] kernel:  Port0: ASoC: error at __soc_pcm_hw_params on Port0: -22
[  149.543495] kernel:  Port0: ASoC: error at dpcm_fe_dai_hw_params on Port0: -22

To Reproduce

  1. Connect to the DUT.
  2. Run TPLG=/lib/firmware/intel/avs-tplg/cavs-tgl-nocodec.tplg MODEL=TGLU_RVP_NOCODEC_CAVSIPC4 ~/sof-test/test-case/check-capture.sh -d 3 -l 1 -r 1 -F
  3. Fails

Reproduction Rate
Happens every time.

Expected behavior
Expectation is that the test will run without failure.

Impact
Causes some of the following tests to fail. Makes the test picture very clouded.

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: cavs-tgl-nocodec.tplg
  3. Name of the platform(s) on which the bug is observed.
    • Platform: sh-tglu-rvp-nocodec-ci-02.sh.intel.com

Screenshots or console output
In description
Repro case:
image

Activity

  1. greg-intel
    added
    bugSomething isn't working as expected
    on Oct 4, 2022
  2. greg-intel
    changed the title [-][BUG] WORK IN PROGRESS[/-] [+]FW reported error: 113 - Invalid destination queue (pin) ID provided following nocodec topology change 6318[/+] on Oct 4, 2022

  3. greg-intel commented on Oct 4, 2022

    @greg-intel
    greg-intel
    on Oct 4, 2022
    ContributorAuthor

    Resolution verified.

    1. git revert
    2. ./scripts/docker-run.sh ./scripts/build-tools.sh -T (on build/local machine) from sof root.
    3. Transferred cavs-tgl-nocodec.tplg to /lib/firmware/intel/avs-tplg on DUT.
    4. In /home/ubuntu/sof-test/tools/kmod ran sof_remove.sh followed by sof_insert.sh
    5. Ran the above reproduction case
    6. Passed

  4. ranj063 commented on Oct 4, 2022

    @ranj063
    ranj063
    on Oct 4, 2022
    Collaborator

    @greg-intel lets not close this issue because the revert is only a temporary solution. @RanderWang FYI. can you please look into this?

  5. ranj063
    assigned
    RanderWang
    on Oct 4, 2022

  6. RanderWang commented on Oct 10, 2022

    @RanderWang
    RanderWang
    on Oct 10, 2022
    Collaborator

    Sure. Some potential bugs would be detected with my PR as I expected

  7. RanderWang commented on Oct 11, 2022

    @RanderWang
    RanderWang
    on Oct 11, 2022
    Collaborator

    The problem is that for capture, gain module should be in the same pipeline of dai copier else FW can't find sink. The root reason is that gain module doesn't support get_sink() ops. (closed source FW, not cSOF)

  8. kfrydryx
    added
    P2Critical bugs or normal features
    on Oct 11, 2022

  9. RanderWang commented on Oct 13, 2022

    @RanderWang
    RanderWang
    on Oct 13, 2022
    Collaborator

    @greg-intel can we close it since we find root reason

  10. marc-hb commented on Oct 13, 2022

    @marc-hb
    marc-hb
    on Oct 13, 2022
    Collaborator

    We reverted a regression. @ranj063 asked to file this as a reminder to resubmit the same but fixed "feature", without the regression. Will you resubmit a fixed version or are you giving up for some reason? (because it can't be done?)

  11. ranj063 commented on Oct 13, 2022

    @ranj063
    ranj063
    on Oct 13, 2022
    Collaborator

    @marc-hb here's the resubmit (merged but with a revised version of the original) and a fix on top of it pending merge #6417

  12. marc-hb commented on Oct 13, 2022

    @marc-hb
    marc-hb
    on Oct 13, 2022
    Collaborator

    Thanks @ranj063 ! So let's close this once #6417 is merged and the next daily run is passing.

  13. marc-hb
    removed
    bugSomething isn't working as expected
    on Oct 13, 2022

  14. lgirdwood commented on Oct 19, 2022

    @lgirdwood
    lgirdwood
    on Oct 19, 2022
    Member

    Thanks @ranj063 ! So let's close this once #6417 is merged and the next daily run is passing.

    Now merged, can this be closed ?

  15. marc-hb
    closed this as completedon Oct 19, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

Labels

P2Critical bugs or normal features

Type

No type

Projects

No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions