[BUG][IPC3] Header reply size is empty when running audio playback/capture test on ADLP/TGLU Zephyr platforms

[keqiaozhang]

Describe the bug
We observed this issue on ADLP/TGLU Zephyr platforms and only SSP and SDW modes are affected. From the logs, this failure only happens when testing playback or capture with S32_LE audio format. Not sure whether it's a coincidence or not.
This is more like a warning, audio still can work after this error. CI test ID:10681

[   31.569323] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: empty reply received, expected 12 bytes

To Reproduce
$ ./sof-test/test-case/check-playback.sh -d 3 -l 1 -r 1 -F
or
$ ./sof-test/test-case/check-capture.sh -d 3 -l 1 -r 1 -F

Reproduction Rate
almost 100%

Expected behavior
No IPC errors

Impact
No functional impact. audio still can work after this error.

Environment

1. Branch name and commit hash of the 2 repositories: sof (firmware/topology) and linux (kernel driver).
   • Kernel: sof-dev/23824cb1eeb4
   • SOF: main/0b537cba4d36
2. Name of the platform(s) on which the bug is observed.
   • Platform: All ADLP/TGLU zephyr platforms with SSP or SDW mode.

Screenshots or console output

2022-03-02 22:33:49 UTC [REMOTE_COMMAND] aplay   -Dhw:0,5 -r 48000 -c 2 -f S32_LE -d 3 /dev/zero -v -q
Hardware PCM card 0 'sof-rt5682' device 5 subdevice 0
Its setup is:
  stream       : PLAYBACK
  access       : RW_INTERLEAVED
  format       : S32_LE
  subformat    : STD
  channels     : 2
  rate         : 48000
  exact rate   : 48000 (48000/1)
  msbits       : 32
  buffer_size  : 8192
  period_size  : 2048
  period_time  : 42666
  tstamp_mode  : NONE
  tstamp_type  : MONOTONIC
  period_step  : 1
  avail_min    : 2048
  period_event : 0
  start_threshold  : 8192
  stop_threshold   : 8192
  silence_threshold: 0
  silence_size : 0
  boundary     : 4611686018427387904
  appl_ptr     : 0
  hw_ptr       : 0
declare -- cmd="journalctl_cmd --since=@1646260368"
journalctl_cmd is a function
journalctl_cmd () 
{ 
    sudo journalctl -k -q --no-pager --utc --output=short-monotonic --no-hostname "$@"
}
2022-03-02 22:33:53 UTC [ERROR] Caught kernel log error
===========================>>
[   31.569323] kernel: sof-audio-pci-intel-tgl 0000:00:1f.3: empty reply received, expected 12 bytes
<<===========================

No obverse errors in demsg or trace.
dmesg.txt
trace.txt

[keqiaozhang]

This error blocks CI test, so set the priority to P1

[lgirdwood]

Trace shows what looks like an attempt to use DMA instead of timer scheduling

[       25515.832319] (         403.124969) c1 zll-schedule       src/schedule/zephyr_ll.c:527  ERROR zephyr_ll_scheduler_init(): unsupported domain 2

This should return an error to host, not an empty message.

@kv2019i fyi.

[kv2019i]

@lgirdwood This is a known issue, caused by following call in sof/src/init/init.c:secondary_core_init():
scheduler_init_ll(dma_domain_get());
I filed a separate issue to track this -> #5480

I'll continue to investigate the rootcause of the invalid IPC messages.

[lgirdwood]

@lgirdwood This is a known issue, caused by following call in sof/src/init/init.c:secondary_core_init():
scheduler_init_ll(dma_domain_get());
I filed a separate issue to track this -> #5480

ok, I think we need a ifdef around the DMA LL init with Zephyr.

[kv2019i]

The unexpected IPC irq is seen when booting the DSP from D3 and while host is waiting for FW_READY. Example log:

[ 8944.463682] sof-audio-pci-intel-tgl 0000:00:1f.3: Firmware download successful, booting...
[ 8944.476909] sof-audio-pci-intel-tgl 0000:00:1f.3: empty reply received, expected 12 bytes
[ 8944.476921] sof-audio-pci-intel-tgl 0000:00:1f.3: no reply expected, received 0x0, will be ignored
[ 8944.477713] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc rx: 0x70000000: FW_READY
[ 8944.477725] sof-audio-pci-intel-tgl 0000:00:1f.3: ipc: DSP is ready 0x70000000 offset 0x81000

This is somewhat sporadic, but I suspect it's related to the how DSP enters D3 when secondary cores have been used.