Skip to content

ipc4: Unify component ID logging format across various IPC and pipeline logs #8970

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
lgirdwood merged 4 commits into from
Apr 15, 2024
Merged

ipc4: Unify component ID logging format across various IPC and pipeline logs #8970

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
4 commits
Select commit Hold shift + click to select a range
894c829
ipc4: helper: Use hex format for component IDs in ipc-helper logs
tmleman Mar 20, 2024
06d13b7
pipeline: params: Display component IDs in hex format in pipeline logs
tmleman Mar 20, 2024
c231822
ipc4: helper: Convert component ID logs to hexadecimal format
tmleman Mar 20, 2024
79c129c
pipeline: graph: Use hex format for component IDs in graph logs
tmleman Mar 20, 2024
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
6 changes: 3 additions & 3 deletions src/audio/pipeline/pipeline-graph.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -252,7 +252,7 @@ static int pipeline_comp_complete(struct comp_dev *current,
{
struct pipeline_data *ppl_data = ctx->comp_data;

pipe_dbg(ppl_data->p, "pipeline_comp_complete(), current->comp.id = %u, dir = %u",
pipe_dbg(ppl_data->p, "pipeline_comp_complete(), current->comp.id = 0x%x, dir = %u",
dev_comp_id(current), dir);

if (!comp_is_single_pipeline(current, ppl_data->start)) {
Expand Down Expand Up @@ -327,7 +327,7 @@ static int pipeline_comp_reset(struct comp_dev *current,
int is_same_sched = pipeline_is_same_sched_comp(p_current, p);
int err;

pipe_dbg(p_current, "pipeline_comp_reset(), current->comp.id = %u, dir = %u",
pipe_dbg(p_current, "pipeline_comp_reset(), current->comp.id = 0x%x, dir = %u",
dev_comp_id(current), dir);

/*
Expand Down Expand Up @@ -377,7 +377,7 @@ int pipeline_reset(struct pipeline *p, struct comp_dev *host)

ret = walk_ctx.comp_func(host, NULL, &walk_ctx, host->direction);
if (ret < 0) {
pipe_err(p, "pipeline_reset(): ret = %d, host->comp.id = %u",
pipe_err(p, "pipeline_reset(): ret = %d, host->comp.id = 0x%x",
ret, dev_comp_id(host));
} else {
/* pipeline is reset to default state */
Expand Down
16 changes: 8 additions & 8 deletions src/audio/pipeline/pipeline-params.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -32,7 +32,7 @@ static int pipeline_comp_params_neg(struct comp_dev *current,
struct pipeline_data *ppl_data = ctx->comp_data;
int err = 0;

pipe_dbg(current->pipeline, "pipeline_comp_params_neg(), current->comp.id = %u, dir = %u",
pipe_dbg(current->pipeline, "pipeline_comp_params_neg(), current->comp.id = 0x%x, dir = %u",
dev_comp_id(current), dir);

/* check if 'current' is already configured */
Expand Down Expand Up @@ -82,7 +82,7 @@ static int pipeline_comp_params(struct comp_dev *current,
int stream_direction = ppl_data->params->params.direction;
int err;

pipe_dbg(current->pipeline, "pipeline_comp_params(), current->comp.id = %u, dir = %u",
pipe_dbg(current->pipeline, "pipeline_comp_params(), current->comp.id = 0x%x, dir = %u",
dev_comp_id(current), dir);

/* Don't propagate to pipelines in the opposite direction */
Expand Down Expand Up @@ -132,7 +132,7 @@ static int pipeline_comp_hw_params(struct comp_dev *current,
struct pipeline_data *ppl_data = ctx->comp_data;
int ret;

pipe_dbg(current->pipeline, "pipeline_comp_hw_params(), current->comp.id = %u, dir = %u",
pipe_dbg(current->pipeline, "pipeline_comp_hw_params(), current->comp.id = 0x%x, dir = %u",
dev_comp_id(current), dir);

ret = pipeline_for_each_comp(current, ctx, dir);
Expand Down Expand Up @@ -227,14 +227,14 @@ int pipeline_params(struct pipeline *p, struct comp_dev *host,

ret = hw_param_ctx.comp_func(host, NULL, &hw_param_ctx, dir);
if (ret < 0) {
pipe_err(p, "pipeline_params(): ret = %d, dev->comp.id = %u",
pipe_err(p, "pipeline_params(): ret = %d, dev->comp.id = 0x%x",
ret, dev_comp_id(host));
return ret;
}

ret = buf_param_ctx.comp_func(host, NULL, &buf_param_ctx, dir);
if (ret < 0) {
pipe_err(p, "pipeline_params(): ret = %d, dev->comp.id = %u",
pipe_err(p, "pipeline_params(): ret = %d, dev->comp.id = 0x%x",
ret, dev_comp_id(host));
return ret;
}
Expand All @@ -245,7 +245,7 @@ int pipeline_params(struct pipeline *p, struct comp_dev *host,

ret = param_ctx.comp_func(host, NULL, &param_ctx, dir);
if (ret < 0) {
pipe_err(p, "pipeline_params(): ret = %d, host->comp.id = %u",
pipe_err(p, "pipeline_params(): ret = %d, host->comp.id = 0x%x",
ret, dev_comp_id(host));
}

Expand All @@ -263,7 +263,7 @@ static int pipeline_comp_prepare(struct comp_dev *current,
struct pipeline_data *ppl_data = ctx->comp_data;
int err;

pipe_dbg(current->pipeline, "pipeline_comp_prepare(), current->comp.id = %u, dir = %u",
pipe_dbg(current->pipeline, "pipeline_comp_prepare(), current->comp.id = 0x%x, dir = %u",
dev_comp_id(current), dir);

if (!comp_is_single_pipeline(current, ppl_data->start)) {
Expand Down Expand Up @@ -308,7 +308,7 @@ int pipeline_prepare(struct pipeline *p, struct comp_dev *dev)

ret = walk_ctx.comp_func(dev, NULL, &walk_ctx, dev->direction);
if (ret < 0) {
pipe_err(p, "pipeline_prepare(): ret = %d, dev->comp.id = %u",
pipe_err(p, "pipeline_prepare(): ret = %d, dev->comp.id = 0x%x",
ret, dev_comp_id(dev));
return ret;
}
Expand Down
14 changes: 7 additions & 7 deletions src/ipc/ipc-helper.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -205,7 +205,7 @@ int ipc_pipeline_complete(struct ipc *ipc, uint32_t comp_id)
/* check whether pipeline exists */
ipc_pipe = ipc_get_pipeline_by_id(ipc, comp_id);
if (!ipc_pipe) {
tr_err(&ipc_tr, "ipc: ipc_pipeline_complete looking for pipe component id %d failed",
tr_err(&ipc_tr, "ipc: ipc_pipeline_complete looking for pipe component id 0x%x failed",
Copy link
Collaborator

@lyakh lyakh Mar 21, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

should we use %#x?

Copy link
Collaborator

@kv2019i kv2019i Mar 21, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@lyakh I think the problem has been that sof-logger/IPC3 doesn't handle this. We've had some usage (e.g. in pipeline-trace.h) but so far only in IPC4 only code.

That's also the reason why this cleanup has not been done yet in generic code, as you end up in some complicated compromises to make (as the many of these ids are bitmasks in IPC4 while there are unique integers in IPC3, so there's no single best represention of the numbers).

Copy link
Collaborator

@marc-hb marc-hb Mar 21, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think the problem has been that sof-logger/IPC3 doesn't handle this.

Doesn't handle what? sof-logger supports any format string as long as the arguments are between 0 and 4 and all 32bits wides. It merely invokes fprintf() in print_entry_params()

Copy link
Collaborator

@kv2019i kv2019i Mar 22, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Emphasis "I think". If "%#x" works, by all means let's go with that, but someone needs to ack it works with sof-logger.

Copy link
Collaborator

@marc-hb marc-hb Apr 8, 2024 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

%x is already in use in many places:

git grep -E 'tr_.*%.{0,3}x'
git grep -E 'comp_.*%.{0,3}x'

If only one of these statements is a frequent one, then verifying it works it's just the matter of looking at stable-v2.2 test results in any recent sof-test or linux Pull Request:

https://github.com/thesofproject/sof-test/pulls
https://github.com/thesofproject/linux/pulls

Copy link
Collaborator

@marc-hb marc-hb Apr 8, 2024 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

If "%#x" works

BTW %#x is less obvious and readable than 0x%x for near-zero advantage?

https://pubs.opengroup.org/onlinepubs/9699919799/functions/printf.html

comp_id);
return -EINVAL;
}
Expand Down Expand Up @@ -233,14 +233,14 @@ int ipc_pipeline_complete(struct ipc *ipc, uint32_t comp_id)
/* find the scheduling component */
icd = ipc_get_comp_by_id(ipc, p->sched_id);
if (!icd) {
tr_warn(&ipc_tr, "ipc_pipeline_complete(): no scheduling component specified, use comp %d",
tr_warn(&ipc_tr, "ipc_pipeline_complete(): no scheduling component specified, use comp 0x%x",
ipc_ppl_sink->id);

icd = ipc_ppl_sink;
}

if (icd->core != ipc_pipe->core) {
tr_err(&ipc_tr, "ipc_pipeline_complete(): icd->core (%d) != ipc_pipe->core (%d) for pipeline scheduling component icd->id %d",
tr_err(&ipc_tr, "ipc_pipeline_complete(): icd->core (%d) != ipc_pipe->core (%d) for pipeline scheduling component icd->id 0x%x",
icd->core, ipc_pipe->core, icd->id);
return -EINVAL;
}
Expand All @@ -249,7 +249,7 @@ int ipc_pipeline_complete(struct ipc *ipc, uint32_t comp_id)

pipeline_id = ipc_pipe->pipeline->pipeline_id;

tr_dbg(&ipc_tr, "ipc: pipe %d -> complete on comp %d", pipeline_id,
tr_dbg(&ipc_tr, "ipc: pipe %d -> complete on comp 0x%x", pipeline_id,
comp_id);

return pipeline_complete(ipc_pipe->pipeline, ipc_ppl_source->cd,
Expand All @@ -265,7 +265,7 @@ int ipc_comp_free(struct ipc *ipc, uint32_t comp_id)
/* check whether component exists */
icd = ipc_get_comp_by_id(ipc, comp_id);
if (!icd) {
tr_err(&ipc_tr, "ipc_comp_free(): comp id: %d is not found",
tr_err(&ipc_tr, "ipc_comp_free(): comp id: 0x%x is not found",
comp_id);
return -ENODEV;
}
Expand All @@ -276,7 +276,7 @@ int ipc_comp_free(struct ipc *ipc, uint32_t comp_id)

/* check state */
if (icd->cd->state != COMP_STATE_READY) {
tr_err(&ipc_tr, "ipc_comp_free(): comp id: %d state is %d cannot be freed",
tr_err(&ipc_tr, "ipc_comp_free(): comp id: 0x%x state is %d cannot be freed",
comp_id, icd->cd->state);
return -EINVAL;
}
Expand All @@ -291,7 +291,7 @@ int ipc_comp_free(struct ipc *ipc, uint32_t comp_id)
* leak on error. Bug-free host drivers won't do
* this, this was found via fuzzing.
*/
tr_err(&ipc_tr, "ipc_comp_free(): uninitialized buffer lists on comp %d\n",
tr_err(&ipc_tr, "ipc_comp_free(): uninitialized buffer lists on comp 0x%x\n",
icd->id);
return -EINVAL;
}
Expand Down
6 changes: 3 additions & 3 deletions src/ipc/ipc4/helper.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -107,7 +107,7 @@ struct comp_dev *comp_new_ipc4(struct ipc4_module_init_instance *module_init)
return NULL;

if (ipc4_get_comp_dev(comp_id)) {
tr_err(&ipc_tr, "comp %d exists", comp_id);
tr_err(&ipc_tr, "comp 0x%x exists", comp_id);
return NULL;
}

Expand All @@ -129,7 +129,7 @@ struct comp_dev *comp_new_ipc4(struct ipc4_module_init_instance *module_init)
ipc_config.proc_domain = COMP_PROCESSING_DOMAIN_LL;
#else /* CONFIG_ZEPHYR_DP_SCHEDULER */
if (module_init->extension.r.proc_domain) {
tr_err(&ipc_tr, "ipc: DP scheduling is disabled, cannot create comp %d", comp_id);
tr_err(&ipc_tr, "ipc: DP scheduling is disabled, cannot create comp 0x%x", comp_id);
return NULL;
}
ipc_config.proc_domain = COMP_PROCESSING_DOMAIN_LL;
Expand Down Expand Up @@ -1031,7 +1031,7 @@ int ipc4_add_comp_dev(struct comp_dev *dev)
icd->core = dev->ipc_config.core;
icd->id = dev->ipc_config.id;

tr_dbg(&ipc_tr, "ipc4_add_comp_dev add comp %x", icd->id);
tr_dbg(&ipc_tr, "ipc4_add_comp_dev add comp 0x%x", icd->id);
/* add new component to the list */
list_item_append(&icd->list, &ipc->comp_list);

Expand Down