[BUG] SofIpcErrorResponseException HDA-DMA Error code: -16

[wszypelt]

Describe the bug
wave file is valid
Bug:
ERROR:Exception SofIpcErrorResponseException occurred at 'C:\work\tools\pyexecnetcache\cavs_scripts-py\utilities\ipc_driver.py':734 FW replied with error. Error code: -16 0x00000005 0x00000000 0x00004000

was found in tests:

02_20_TestPtpCaptureStreamStopStartOperation8000Hz16b16b8ch
02_20_TestPtpCaptureStreamStopStartOperation16000Hz24b32b4ch
02_20_TestPtpCaptureStreamStopStartOperation24000Hz16b16b4ch
02_20_TestPtpCaptureStreamStopStartOperation24000Hz24b32b2ch
02_20_TestPtpCaptureStreamStopStartOperation24000Hz32b32b2ch
02_20_TestPtpCaptureStreamStopStartOperation24000Hz32b32b8ch
02_20_TestPtpCaptureStreamStopStartOperation48000Hz32b32b8ch
02_20_TestPtpCaptureStreamStopStartOperation48000Hz16b16b2ch

Topology

                pipe_plb
                +--------------------+
+----------+    | +------+   +-----+ |   +----+
| Host plb |----->|Buffer|-->| Dai |---->|SSPx|
+----------+    | +------+   +-----+ |   +----+
                +--------------------+    |  |
                pipe_cap                  |  |
                +--------------------+    |  |
+----------+    | +------+   +-----+ |   +----+
| Host cap |<-----|Buffer|<--| Dai |---->|SSPx|
+----------+    | +------+   +-----+ |   +----+
                +--------------------+

Simultaneous playback and capture on external loopback (same SSP).
While pipelines are working pause, stop and start operation are done on capture stream.

To Reproduce
Run test with Diagnostic driver 02_20_TestPtpCaptureStreamStopStartOperation48000Hz16b16b2ch

Reproduction Rate
100%

Environment

1. Branch name and commit hash of the 2 repositories: sof (firmware/topology) and linux (kernel driver).
   • SOF BRANCH: main HASH: 1ef769d
2. Name of the platform(s) on which the bug is observed.
   Platform: ICL RVP, WHL RVP, APL RVP,
3. Test environment:
   BRANCH: master HASH: 539c1929909ea3041e3f9a15c6e589598ef69f79

Last working build
Master-2747 4c3aafe

Screenshots or console output

[     4182254.739583] (       41999.949219) c0 pipe         1.3   ....../pipeline-stream.c:460  WARN pipeline_get_timestamp(): DAI position update failed
[     4224254.791667] (       42000.050781) c0 pipe         1.3   ....../pipeline-stream.c:460  WARN pipeline_get_timestamp(): DAI position update failed
[     4266254.635417] (       41999.843750) c0 pipe         1.3   ....../pipeline-stream.c:460  WARN pipeline_get_timestamp(): DAI position update failed
[     4308254.791667] (       42000.156250) c0 pipe         1.3   ....../pipeline-stream.c:460  WARN pipeline_get_timestamp(): DAI position update failed
[     4350254.635417] (       41999.843750) c0 pipe         1.3   ....../pipeline-stream.c:460  WARN pipeline_get_timestamp(): DAI position update failed
[     4350264.270833] (           9.635417) c0 host         1.0   ....../pipeline-stream.c:177  perf comp_copy peak plat 307 cpu 6400
[     4392255.000000] (       41990.730469) c0 pipe         1.3   ....../pipeline-stream.c:460  WARN pipeline_get_timestamp(): DAI position update failed
[     4434254.687500] (       41999.687500) c0 pipe         1.3   ....../pipeline-stream.c:460  WARN pipeline_get_timestamp(): DAI position update failed
[     4476254.791667] (       42000.105469) c0 pipe         1.3   ....../pipeline-stream.c:460  WARN pipeline_get_timestamp(): DAI position update failed
[     4500281.093750] (       24026.302734) c0 ipc                  src/ipc/ipc3/handler.c:1555 ipc: new cmd 0x60040000
[     4500287.656250] (           6.562500) c0 pipe         2.7   ....../pipeline-stream.c:310  pipe trigger cmd 9
[     4500294.531250] (           6.875000) c0 ll-schedule        ./schedule/ll_schedule.c:391  task add 0xbe052e00 pipe-task <f11818eb-e92e-4082-82a3-dc54c604ebb3>
[     4500299.479167] (           4.947917) c0 ll-schedule        ./schedule/ll_schedule.c:395  task params pri 0 flags 0 start 0 period 1000
[     4500308.125000] (           8.645833) c0 ll-schedule        ./schedule/ll_schedule.c:307  new added task->start 95888712 at 95871064
[     4500312.864583] (           4.739583) c0 ll-schedule        ./schedule/ll_schedule.c:310  num_tasks 4 total_num_tasks 4
[     4501273.750000] (         960.885437) c0 ssp-dai      1.0   /drivers/intel/ssp/ssp.c:1093 ssp_trigger() cmd 9
[     4501279.375000] (           5.625000) c0 ssp-dai      1.0   /drivers/intel/ssp/ssp.c:885  ssp_pre_start()
[     4501285.052083] (           5.677083) c0 ssp-dai      1.0   /drivers/intel/ssp/ssp.c:978  ssp_early_start(): SSE set for SSP0
[     4501291.666667] (           6.614583) c0 hda-dma            ..../intel/hda/hda-dma.c:614  ERROR hda-dmac: 4 channel 0 busy. dgcs 0x84800820 status 5
[     4501296.770833] (           5.104167) c0 host         2.4           src/audio/host.c:491  ERROR host_trigger(): dma_start() failed, ret = 4294967280
[     4501301.458333] (           4.687500) c0 pipe         2.7   ....../pipeline-stream.c:398  ERROR pipeline_trigger(): ret = -16, host->comp.id = 4, cmd = 9
[     4501306.041667] (           4.583333) c0 pipe         2.7   ..../pipeline-schedule.c:92   ERROR pipeline_task(): failed to trigger components: -16
[     4501312.916667] (           6.875000) c0 ll-schedule        ./schedule/ll_schedule.c:115  task complete 0xbe052e00 pipe-task <f11818eb-e92e-4082-82a3-dc54c604ebb3>
[     4501317.395833] (           4.479167) c0 ll-schedule        ./schedule/ll_schedule.c:118  num_tasks 3 total_num_tasks 3
[     4518255.625000] (       16938.228516) c0 pipe         1.3   ....../pipeline-stream.c:460  WARN pipeline_get_timestamp(): DAI position update failed
[     4518265.104167] (           9.479167) c0 host         1.0   ....../pipeline-stream.c:177  perf comp_copy peak plat 322 cpu 6712
[     4560255.052083] (       41989.949219) c0 pipe         1.3   ....../pipeline-stream.c:460  WARN pipeline_get_timestamp(): DAI position update failed
[     4602254.791667] (       41999.738281) c0 pipe         1.3   ....../pipeline-stream.c:460  WARN pipeline_get_timestamp(): DAI position update failed
[     4644254.791667] (       42000.000000) c0 pipe         1.3   ....../pipeline-stream.c:460  WARN pipeline_get_timestamp(): DAI position update failed
[     4686254.843750] (       42000.050781) c0 pipe         1.3   ....../pipeline-stream.c:460  WARN pipeline_get_timestamp(): DAI position update failed
[     4728254.791667] (       41999.949219) c0 pipe         1.3   ....../pipeline-stream.c:460  WARN pipeline_get_timestamp(): DAI position update failed

Logs
02_20_TestPtpCaptureStreamStopStartOperation.zip

[bkokoszx]

@wszypelt Can you perform bisect in order to check which commit introduce the problem?

[wszypelt]

@bkokoszx It looks like the error came with the pull #4844
last working commit: e3b6a32
first commit with error: 2774464

[bkokoszx]

Hi @ranj063, could you take a look?

[lgirdwood]

@bkokoszx this now aligns the HDA programming sequence to Windows flow and is meant to also work with the old flow too. I'm wondering if the CI needs to use the new flow ? @ranj063 any inputs here.

[github-actions]

This issue has been marked as stale because it has been open (more than) 60 days with no activity. Remove the stale label or add a comment saying that you would like to have the label removed otherwise this issue will automatically be closed in 14 days. Note, that you can always re-open a closed issue at any time.