[BUG] delay reporting starts goes out of sync and host position overtakes link position #9418
Comments
kv2019i
added
bug
|
FYI @ujfalusi with whom I've already debugged this. Suspicion is that start_offset calculation has a bug and/or there is FW buffering that is not accounted. Logs show that delay reporting is correct at first, but in some test runs, the reported decreases in 1ms steps multiple times, and finally the values kernel sees wrap around leading to invalid values reported to application. |
|
Tested FW fast_mode, did not help. |
|
What I have observed is that the LDP (host pointer) and LLP (Link pointer) starts to converge and over time LLP overtakes LDP. It is always there when the distance changes between the two pointer - which translates to delay values. Furthermore, I can observe a small audible tick/tock when this happens when playing a 1KHz sine wav file. I cannot hear it with real music, but that is expected. So far I have been able to reproduce this on: TGL HDA, TGL SSP, LNL SSP. This is not related to the link type and the DMA servicing it. |
The fast mode would not copy if |
kv2019i
added
I2S
|
I think I have found something interesting in logs. Added print for the host side before every Most of the time the In any case, with this patch: diff --git a/src/audio/host-zephyr.c b/src/audio/host-zephyr.c
index ac1751059eb5..bc7e52dfb9bb 100644
--- a/src/audio/host-zephyr.c
+++ b/src/audio/host-zephyr.c
@@ -372,8 +372,10 @@ static uint32_t host_get_copy_bytes_normal(struct host_data *hd, struct comp_dev
uint32_t free_samples;
uint32_t dma_sample_bytes;
uint32_t dma_copy_bytes;
+ bool retry = false;
int ret;
+again:
/* get data sizes from DMA */
ret = dma_get_status(hd->chan->dma->z_dev, hd->chan->index, &dma_stat);
if (ret < 0) {
@@ -403,9 +405,17 @@ static uint32_t host_get_copy_bytes_normal(struct host_data *hd, struct comp_dev
if (!(hd->ipc_host.feature_mask & BIT(IPC4_COPIER_FAST_MODE)))
dma_copy_bytes = MIN(hd->period_bytes, dma_copy_bytes);
- if (!dma_copy_bytes)
- comp_info(dev, "no bytes to copy, available samples: %d, free_samples: %d",
- avail_samples, free_samples);
+ if (!dma_copy_bytes) {
+ if (!retry && dma_stat.pending_length == 0 && hd->partial_size == 0) {
+ comp_info(dev, "no bytes to copy, retry");
+ k_usleep(5);
+ retry = true;
+ goto again;
+ }
+
+ comp_info(dev, "no bytes to copy, available samples: %d, free_samples: %d, pending_length: %d, partial_size: %d",
+ avail_samples, free_samples, dma_stat.pending_length, hd->partial_size);
+ }
/* dma_copy_bytes should be aligned to minimum possible chunk of
* data to be copied by dma.The issue goes away. I can see occasional prints about the retry, but on second try with a short delay all is good, we have data available.... |
|
Ack @ujfalusi , I think we have a problem with DMA status reporting. If I dump DMA status history of previous LL ticks when the avail_zero happens, this is seen: D: 0 iter 51968 pending 768 rp 384 wp 1152 reload 384 ... so the BufferEmpty bit is for some reason set even though clearly there is data in the buffer (based on only 384 bytes read out via reload since last 1ms tick). I will try the retry logic and see how it changes the reporting. |
kv2019i
added a commit
to kv2019i/zephyr
that referenced
this issue
Sep 2, 2024
The ringbuffer availability check is subject to race with regards to update of BF (Buffer Full) and BNE (Buffer Not Empty) bits in DGCS register, and status of RP (Read Position) and WP (Write Position). Following sequence is observed without this patch when calling dma_get_status() on multiple Intel ADSP platforms: iter 154 pending 1536 RP 768 WP 768, BNE 1, BF 1 -> dma_reload for 384 iter 155 pending 1536 RP 1152 WP 1152, BNE 1, BF 1 -> dma_reload for 384 iter 156 pending 0 RP 0 WP 0, BNE 1, BF 0 Value of pending is not expected to go from 1536 to zero if only 384 bytes have been consumed via dma_reload() since last call to dma_get_status(). Change the logic to read DGCS register later, after the WP and RP have been already read, and only check the BNE bit if Read and Write Positions are equal. Link: thesofproject/sof#9418 Signed-off-by: Kai Vehmanen <[email protected]> Co-developed-by: Peter Ujfalusi <[email protected]> Signed-off-by: Peter Ujfalusi <[email protected]>
|
Could this be related to? |
kv2019i
added
P2
carlescufi
pushed a commit
to zephyrproject-rtos/zephyr
that referenced
this issue
Sep 4, 2024
The ringbuffer availability check is subject to race with regards to update of BF (Buffer Full) and BNE (Buffer Not Empty) bits in DGCS register, and status of RP (Read Position) and WP (Write Position). Following sequence is observed without this patch when calling dma_get_status() on multiple Intel ADSP platforms: iter 154 pending 1536 RP 768 WP 768, BNE 1, BF 1 -> dma_reload for 384 iter 155 pending 1536 RP 1152 WP 1152, BNE 1, BF 1 -> dma_reload for 384 iter 156 pending 0 RP 0 WP 0, BNE 1, BF 0 Value of pending is not expected to go from 1536 to zero if only 384 bytes have been consumed via dma_reload() since last call to dma_get_status(). Change the logic to read DGCS register later, after the WP and RP have been already read, and only check the BNE bit if Read and Write Positions are equal. Link: thesofproject/sof#9418 Signed-off-by: Kai Vehmanen <[email protected]> Co-developed-by: Peter Ujfalusi <[email protected]> Signed-off-by: Peter Ujfalusi <[email protected]>
coreboot-bot
pushed a commit
to coreboot/zephyr-cros
that referenced
this issue
Sep 5, 2024
The ringbuffer availability check is subject to race with regards to update of BF (Buffer Full) and BNE (Buffer Not Empty) bits in DGCS register, and status of RP (Read Position) and WP (Write Position). Following sequence is observed without this patch when calling dma_get_status() on multiple Intel ADSP platforms: iter 154 pending 1536 RP 768 WP 768, BNE 1, BF 1 -> dma_reload for 384 iter 155 pending 1536 RP 1152 WP 1152, BNE 1, BF 1 -> dma_reload for 384 iter 156 pending 0 RP 0 WP 0, BNE 1, BF 0 Value of pending is not expected to go from 1536 to zero if only 384 bytes have been consumed via dma_reload() since last call to dma_get_status(). Change the logic to read DGCS register later, after the WP and RP have been already read, and only check the BNE bit if Read and Write Positions are equal. (cherry picked from commit 81977f2) Original-Link: thesofproject/sof#9418 Original-Signed-off-by: Kai Vehmanen <[email protected]> Original-Co-developed-by: Peter Ujfalusi <[email protected]> Original-Signed-off-by: Peter Ujfalusi <[email protected]> GitOrigin-RevId: 81977f2 Cr-Build-Id: 8737732657120454561 Cr-Build-Url: https://cr-buildbucket.appspot.com/build/8737732657120454561 Copybot-Job-Name: zephyr-main-copybot-downstream Change-Id: Ib4dbcd2fa7376c0f812c23160d3ceac3de487912 Reviewed-on: https://chromium-review.googlesource.com/c/chromiumos/third_party/zephyr/+/5836426 Reviewed-by: Yuval Peress <[email protected]> Tested-by: ChromeOS Prod (Robot) <[email protected]> Tested-by: Yuval Peress <[email protected]> Commit-Queue: Yuval Peress <[email protected]>
|
Fixed via #9437 |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Describe the bug
Delay reporting stops working after some time of streaming.
To Reproduce
Play video to a HDA codec on Intel TGL platform with e.g. "mpv".
Reproduction Rate
Not 100% but high
Expected behavior
Delay reporting keeps working
Impact
Can cause lip sync to fail with certain video plays that rely on ALSA delay reporting interfaces
Environment
Screenshots or console output
Notes
Related but not same as issue #8779
The text was updated successfully, but these errors were encountered: