Skip to content

[BUG[IPC4] ipc error 9 for msg 0x45010002|0x10003 MOD_BIND on TGLU_UP_HDA_IPC4ZPH #6213

Closed
Closed
[BUG[IPC4] ipc error 9 for msg 0x45010002|0x10003 MOD_BIND on TGLU_UP_HDA_IPC4ZPH#6213
Assignees
kv2019i
Labels
IPC errorIPC error is observedIPC4Issues observed with IPC4 (same IPC as Windows)P1Blocker bugs or important featuresbugSomething isn't working as expected
Milestone
v2.4

Description

@keqiaozhang
keqiaozhang
opened on Aug 30, 2022

Describe the bug
We observed this issue in our CI test, this issue happens on TGLU_UP_HDA_IPC4ZPH when testing
'simultaneous-playback-capture-25', It fails after several iterations. The reproduction is 100%.

[   76.013310] kernel: snd_sof:sof_ipc4_route_setup: sof-audio-pci-intel-tgl 0000:00:1f.3: bind mixin.4.1 -> mixout.3.1
[   76.013312] kernel: snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx      : 0x45010002|0x10003: MOD_BIND
[   76.013445] kernel: snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx reply: 0x65000009|0x10003: MOD_BIND
[   76.013447] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: FW reported error: 9 - Specified resource not found
[   76.013457] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc error for msg 0x45010002|0x10003
[   76.013459] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: sof_ipc4_route_setup: failed to bind modules mixin.4.1 -> mixout.3.1
[   76.013463] kernel: snd_sof:sof_widget_free: sof-audio-pci-intel-tgl 0000:00:1f.3: widget copier.HDA.4.1 freed
[   76.013465] kernel: snd_sof:sof_widget_free: sof-audio-pci-intel-tgl 0000:00:1f.3: widget gain.4.1 freed

To Reproduce
TPLG=/lib/firmware/intel/avs-tplg/cavs-mixin-mixout-hda.tplg MODEL=TGLU_UP_HDA_IPC4ZPH ~/sof-test/test-case/simultaneous-playback-capture.sh -l 25

Reproduction Rate
100%

dmesg
image

Environment

  1. Branch name and commit hash of the 2 repositories: sof (firmware/topology) and linux (kernel driver).
    Kernel Branch: topic/sof-dev
    Kernel Commit: 4e6ca75f7357
    SOF Branch: main
    SOF Commit: 1044e004e4ec
    Zephyr Commit:
    zephyr-v3.1.0-3042-g8e55e59c5917
  2. Name of the topology file
    • Topology: cavs-mixin-mixout-hda.tplg
  3. Name of the platform(s) on which the bug is observed.
    • Platform: TGLU_UP_HDA_IPC4ZPH

console output

2022-08-29 21:52:31 UTC [REMOTE_INFO] ===== Testing: (Loop: 10/25) =====
2022-08-29 21:52:31 UTC [REMOTE_COMMAND] aplay -D hw:0,0 -c 2 -r 48000 -f S16_LE /dev/zero -q &
2022-08-29 21:52:31 UTC [REMOTE_COMMAND] arecord -D hw:0,0 -c 2 -r 48000 -f S16_LE /dev/null -q &
2022-08-29 21:52:31 UTC [REMOTE_INFO] Preparing to sleep for 5
arecord: set_params:1432: Unable to install hw params:
ACCESS:  RW_INTERLEAVED
FORMAT:  S16_LE
SUBFORMAT:  STD
SAMPLE_BITS: 16
FRAME_BITS: 32
CHANNELS: 2
RATE: 48000
PERIOD_TIME: (85333 85334)
PERIOD_SIZE: 4096
PERIOD_BYTES: 16384
PERIODS: 4
BUFFER_TIME: (341333 341334)
BUFFER_SIZE: 16384
BUFFER_BYTES: 65536
TICK_TIME: 0
2022-08-29 21:52:36 UTC [REMOTE_INFO] check pipeline after 5s
/home/ubuntu/sof-test/test-case/simultaneous-playback-capture.sh: line 107: kill: (2078) - No such process
2022-08-29 21:52:36 UTC [REMOTE_ERROR] Error in arecord process after sleep.
/home/ubuntu/sof-test/test-case/simultaneous-playback-capture.sh: line 67: kill: (2078) - No such process

dmesg.txt

Activity

  1. keqiaozhang
    added
    bugSomething isn't working as expected
    IPC errorIPC error is observed
    IPC4Issues observed with IPC4 (same IPC as Windows)
    on Aug 30, 2022
  2. kfrydryx
    added
    P1Blocker bugs or important features
    on Aug 30, 2022
  3. kv2019i
    changed the title [-][BUG[IPC4] ipc error for msg 0x45010002|0x10003 MOD_BIND on TGLU_UP_HDA_IPC4ZPH[/-] [+][BUG[IPC4] ipc error 9 for msg 0x45010002|0x10003 MOD_BIND on TGLU_UP_HDA_IPC4ZPH[/+] on Sep 15, 2022

  4. keqiaozhang commented on Sep 16, 2022

    @keqiaozhang
    keqiaozhang
    on Sep 16, 2022
    CollaboratorAuthor

    Observed another type of IPC error 104 for msg 0x40030004|0x30015: MOD_INIT_INSTANCE on TGLU_UP_HDA_IPC4ZPH.

    [  464.272868] kernel: snd_sof:sof_widget_setup: sof-audio-pci-intel-tgl 0000:00:1f.3: widget gain.3.1 setup complete
[  464.272869] kernel: snd_sof:sof_ipc4_widget_setup: sof-audio-pci-intel-tgl 0000:00:1f.3: Create widget copier.host.3.1 instance 3 - pipe 3 - core 0
[  464.272870] kernel: snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx      : 0x40030004|0x30015: MOD_INIT_INSTANCE [data size: 84]
[  464.273158] kernel: snd_sof:sof_ipc4_log_header: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx reply: 0x60000068|0x30015: MOD_INIT_INSTANCE
[  464.273160] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: FW reported error: 104 - Other failure of module instance initialization request
[  464.273168] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: ipc error for msg 0x40030004|0x30015
[  464.273170] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: failed to create module copier.host.3.1
[  464.273172] kernel: snd_sof:sof_widget_free: sof-audio-pci-intel-tgl 0000:00:1f.3: widget gain.3.1 freed
  5. lgirdwood
    added this to the v2.4 milestone on Sep 16, 2022
  6. kv2019i
    self-assigned this
    on Oct 4, 2022

  7. kv2019i commented on Oct 4, 2022

    @kv2019i
    kv2019i
    on Oct 4, 2022
    Collaborator

    With #6318 merged, I now hit this exact case on TGL nocodec topology configuration (with pending fixes to #6220 applied locally).

  8. kv2019i commented on Oct 4, 2022

    @kv2019i
    kv2019i
    on Oct 4, 2022
    Collaborator

    Kernel logs shows:

    [  250.273037] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx reply: 0x60000068|0x70015: MOD_INIT_INSTANCE
[  250.273039] sof-audio-pci-intel-tgl 0000:00:1f.3: FW reported error: 104 - Other failure of module instance initialization request
[  250.273048] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc error for msg 0x40010004|0x70015
[  250.273052] sof-audio-pci-intel-tgl 0000:00:1f.3: failed to create module copier.host.7.1
[  250.273055] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx      : 0x12070000|0x0: GLB_DELETE_PIPELINE
[  250.273213] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx reply: 0x32000000|0x0: GLB_DELETE_PIPELINE
[  250.273225] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc tx done : 0x12070000|0x0: GLB_DELETE_PIPELINE
[  250.273227] sof-audio-pci-intel-tgl 0000:00:1f.3: widget pipeline.7 freed
[  250.273228] sof-audio-pci-intel-tgl 0000:00:1f.3: widget gain.7.1 freed

    FW log

    [    9.624000] <inf> pipe: pipeline new pipe_id 7 priority 0
[    9.624000] <inf> module_adapter: module_init() start
[    9.624000] <inf> module_adapter: module_init() done
[    9.624000] <inf> ipc: buffer new size 0x0 id 7.0 flags 0x0
[    9.624000] <err> buffer: buffer_alloc(): new size = 0 is invalid
[    9.624000] <err> copier: unenable to create host
[    9.624000] <err> ipc: error: failed to init module 4 : 1
[    9.624000] <err> ipc: ipc4: 1 failed err 104

    So it seems create_endpoint_buffer() is passed invalid configuration. "copier_cfg->base.obs" must be zero in this case. Assigning to myself for further debug.

  9. kv2019i commented on Oct 7, 2022

    @kv2019i
    kv2019i
    on Oct 7, 2022
    Collaborator

    Curious finding today. I can hit this error with "sof-test/test-case/check-capture.sh -d 1 -l 100 -r 1".
    UPDATE: this was done with #6318 included (has been since been reverted in mainline). so mixers and gains were used in the topology for nocodec.

    When built with XCC, I observe 1/10 failures (1/1000 reproduction rate, 10100 runs)
    When built with gcc (Zephyr SDK 0.15), passrate is 100%. I've let the gcc test run for 20    100 iterations and still no errors.

    This may be related to timing as XCC creates faster code (e.g. hifi enabled), but curious finding nevertheless.

  10. keqiaozhang commented on Oct 24, 2022

    @keqiaozhang
    keqiaozhang
    on Oct 24, 2022
    CollaboratorAuthor

    This issue is not reproducible in CI for days. Closing this one.

  11. keqiaozhang
    closed this as completedon Oct 24, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

Labels

IPC errorIPC error is observedIPC4Issues observed with IPC4 (same IPC as Windows)P1Blocker bugs or important featuresbugSomething isn't working as expected

Type

No type

Projects

No projects

    Milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions