[BUG][BYT][BDW] There are host position update warnings always

There are many host position update warnings from sof-logger according to recent daily test on Intel's BDW and BYT platforms:

[   291465955.814017] (          62.499996) c0 ll-schedule        ./schedule/ll_schedule.c:355  INFO num_tasks 1 total_num_tasks 1
[   292697318.629670] (     1231362.875000) c0 pipe         1.10  ....../pipeline-stream.c:473  WARN pipeline_get_timestamp(): DAI position update failed
[   294113987.635877] (     1416669.000000) c0 pipe         1.10  ....../pipeline-stream.c:473  WARN pipeline_get_timestamp(): DAI position update failed
[   295530656.277500] (     1416668.625000) c0 pipe         1.10  ....../pipeline-stream.c:473  WARN pipeline_get_timestamp(): DAI position update failed
[   296963985.022628] (     1433328.750000) c0 pipe         1.10  ....../pipeline-stream.c:473  WARN pipeline_get_timestamp(): DAI position update failed
[   298380654.133001] (     1416669.125000) c0 pipe         1.10  ....../pipeline-stream.c:473  WARN pipeline_get_timestamp(): DAI position update failed
[   299797322.774625] (     1416668.625000) c0 pipe         1.10  ....../pipeline-stream.c:473  WARN pipeline_get_timestamp(): DAI position update failed
[   301230651.623919] (     1433328.875000) c0 pipe         1.10  ....../pipeline-stream.c:473  WARN pipeline_get_timestamp(): DAI position update failed
[   302647320.525959] (     1416668.875000) c0 pipe         1.10  ....../pipeline-stream.c:473  WARN pipeline_get_timestamp(): DAI position update failed
[   304063989.271749] (     1416668.750000) c0 pipe         1.10  ....../pipeline-stream.c:473  WARN pipeline_get_timestamp(): DAI position update failed
[   305497318.121044] (     1433328.875000) c0 pipe         1.10  ....../pipeline-stream.c:473  WARN pipeline_get_timestamp(): DAI position update failed
[   306913987.127251] (     1416669.000000) c0 pipe         1.10  ....../pipeline-stream.c:473  WARN pipeline_get_timestamp(): DAI position update failed
[   308330655.664707] (     1416668.500000) c0 pipe         1.10  ....../pipeline-stream.c:473  WARN pipeline_get_timestamp(): DAI position update failed

To Reproduce
Just run any playback or capture streams on BDW/BYT, and check sof-logger logs.

Reproduction Rate
It happens in about every 500ms~2s when the stream is active

Expected behavior
We didn't have this warning previous.

Impact
Not sure if it will impact any audio quality, but this warning should be taken care anyway.

Environment

Branch name and commit hash of the 2 repositories: sof (firmware/topology) and linux (kernel driver).
- Kernel: topic/sof-dev Commit: a9c617ef
- SOF: main Commit: cd48b89
Name of the topology file
- Topology: sof-bdw-rt286.tplg on BDW and sof-byt-nocodec.tplg on BYT.
Name of the platform(s) on which the bug is observed.
- Platform: BDW/BYT.

After bisect, I found this warning is first introduced by b82e0ef, but it seems to bring the underlying issue to the surface, not the root cause.

The DMA on BYT and BDW has always had a fairly different set of issues: #4333

https://sof-ci.01.org/sofpr/PR5261/build11791/devicetest/?model=BDW_WSB_RT286&testcase=check-alsabat-headset-playback

@keyonjie

@keyonjie Which topologies trigger this warning?

IIRC the BYT topologies use the 'host' and 'dai' pipelines while BDW is more 'linear' with a single pipeline. This could be quite different in terms of pipeline walks.

@keyonjie

@keyonjie Which topologies trigger this warning?

sof-bdw-rt286.tplg and sof-byt-nocodec.tplg.

@keyonjie

@keyonjie are you able to improve this error ? IIRC we see this when a singe component returns an unexpected return code in the pipeline position walk. We could add a

trace_err("comp X has unexpected state Y when getting position");

@keyonjie

@keyonjie did we send a fix for this, IIRC there was a recent update that addressed this warning ?

still happening, see https://sof-ci.01.org/linuxpr/PR3312/build6800/devicetest/?model=BYT_MB_NOCODEC&testcase=check-kmod-load-unload-after-playback

I grepped through test results and I confirm this started to happen systematically on BYT and BDW on Oct 15 which is the exact date b82e0ef was merged.

P1 because it affects all test results.

@lyakh

Indeed the change in b82e0ef#diff-d4c9ae9324e27d2f5c74a47c27602e66eb981eec2ac459b99ad81f3277f34aacR458 seems to add those warnings.

@lyakh @lgirdwood any idea why this was needed?

This is non fatal so can be made a tr_dbg()

@lyakh

Indeed the change in b82e0ef#diff-d4c9ae9324e27d2f5c74a47c27602e66eb981eec2ac459b99ad81f3277f34aacR458 seems to add those warnings.

@lyakh @lgirdwood any idea why this was needed?

@plbossart I added that to make sure we always test error codes of pipeline_for_each_comp(). In this case it means that when getting a timestamp on a pipeline we reached an inactive component. It would be interesting to run a test with

diff --git a/src/audio/pipeline/pipeline-stream.c b/src/audio/pipeline/pipeline-stream.c
index 850fef1c6..e308f43de 100644
--- a/src/audio/pipeline/pipeline-stream.c
+++ b/src/audio/pipeline/pipeline-stream.c
@@ -459,7 +459,7 @@ static int pipeline_comp_timestamp(struct comp_dev *current,
 	struct pipeline_data *ppl_data = ctx->comp_data;
 
 	if (!comp_is_active(current)) {
-		pipe_dbg(current->pipeline, "pipeline_comp_timestamp(), current is not active");
+		comp_warn(current, "pipeline_comp_timestamp(), current is not active, state %u", current->state);
 		return 0;
 	}
 
@@ -492,7 +492,7 @@ void pipeline_get_timestamp(struct pipeline *p, struct comp_dev *host,
 
 	if (walk_ctx.comp_func(host, NULL, &walk_ctx, host->direction) !=
 	    PPL_STATUS_PATH_STOP)
-		pipe_warn(p, "pipeline_get_timestamp(): DAI position update failed");
+		pipe_dbg(p, "pipeline_get_timestamp(): DAI position update failed");
 
 	/* set timestamp resolution */
 	posn->timestamp_ns = p->period * 1000;

effectively following @lgirdwood's suggestion, to see what component that is. Then we should be able to judge better how important this is?

@lyakh

Can you submit a test PR @lyakh ? Thanks!

@lyakh

Can you submit a test PR @lyakh ? Thanks!

@plbossart #5233

Let's see whether this can disappear after #5233 got merged

@XiaoyunWu6666

@XiaoyunWu6666 are these gone now? Can this be closed?

@lyakh

@lyakh these warnings were happening in every single daily test like clockwork so it's easy to have a look.

These warnings don't exist in the current sources any more. This message is now a debug message. Debug messages aren't enabled in CI builds, are they? In any case these warnings cannot appear any more, let's close this.

I meant it's easy to have a quick look at a couple logs, hope someone did that. Because it was happening every time, I consider a few instances where it does not any more to be enough proof.

Debug messages aren't enabled in CI builds, are they?

It depends, again it's easy to have a look.

Navigation Menu

Repository navigation

[BUG][BYT][BDW] There are host position update warnings always #5017

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

[BUG][BYT][BDW] There are host position update warnings always #5017

Description

Activity

miRoox commented on Nov 22, 2021

marc-hb commented on Nov 22, 2021

plbossart commented on Nov 22, 2021

keyonjie commented on Nov 23, 2021

lgirdwood commented on Nov 23, 2021

lgirdwood commented on Dec 1, 2021

plbossart commented on Dec 4, 2021

marc-hb commented on Jan 13, 2022

plbossart commented on Jan 13, 2022

lgirdwood commented on Jan 14, 2022

lyakh commented on Jan 19, 2022

plbossart commented on Jan 19, 2022

lyakh commented on Jan 20, 2022

XiaoyunWu6666 commented on Jan 24, 2022

lyakh commented on Feb 9, 2022

marc-hb commented on Feb 9, 2022

lyakh commented on Feb 15, 2022

marc-hb commented on Feb 15, 2022

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions