Skip to content

Logging: switch to delayed work - #9929

Merged
kv2019i merged 2 commits into
thesofproject:mainfrom
lyakh:log
Mar 31, 2025
Merged

kv2019i merged 2 commits into
thesofproject:mainfrom
lyakh:log

Conversation

@lyakh

@lyakh lyakh commented Mar 27, 2025

Copy link
Copy Markdown
Collaborator

Switch from an EDF task to a delayed task for logging notification IPC

Make the IPC sending work queue available to other IPC parts by
moving it to the global IPC context.

Signed-off-by: Guennadi Liakhovetski <guennadi.liakhovetski@linux.intel.com>

@kv2019i kv2019i left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

A few notes/questions, otherwise looks good.

Comment thread src/ipc/ipc4/logging.c Outdated
#define IPC4_MTRACE_AGING_TIMER_MIN_MS 100

SOF_DEFINE_REG_UUID(mtrace_task);
//SOF_DEFINE_REG_UUID(mtrace_task);

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

What's this?

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

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

@kv2019i left-over, sorry. Looks like this only was needed for logging / the EDF task - if at all? But then we'd also remove it from the UUID registry? Or is it needed for anything?

Comment thread src/ipc/ipc4/logging.c Outdated
#include <ipc4/base_fw.h>
#include <ipc4/error_status.h>
#include <ipc4/logging.h>
#include <zephyr/kernel.h>

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

Not 100% sure this is ok for all built targest. In theory IPC4 could be used with XTOS, but in practise very unlikely.

Comment thread src/ipc/ipc4/logging.c Outdated
*/
if (arch_proc_id() != MTRACE_IPC_CORE)
if (arch_proc_id() != MTRACE_IPC_CORE) {
k_mutex_unlock(&log_mutex);

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

Isn't this a double unlock as the parent call unlock as well?

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

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

argh, right, another one

Comment thread src/ipc/ipc4/logging.c
mtrace_notify_last_sent = k_uptime_get();
mtrace_bytes_pending = 0;
} else {
k_work_schedule_for_queue(&ipc_get()->ipc_send_wq, &log_work,

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

This looks good. The ipc send_wq is pinned to core 0, so this does indeed work.

Comment thread src/ipc/ipc4/logging.c
return k_uptime_ticks() + k_ms_to_ticks_ceil64(mtrace_aging_timer);
k_mutex_lock(&log_mutex, K_FOREVER);

if (k_uptime_get() - mtrace_notify_last_sent >= mtrace_aging_timer &&

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Why you need to check this? Shouldn't Zephyr's Delayable Work call this handler no sooner than a timeout?

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

.. and there is yet another check in mtrace_log_hook_unlocked(). This check look quite redundant to me too.

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

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

I think both are needed. This one is needed because it could happen that after the work was queued another log was issued and then the space was tight so an IPC got sent out and the time updated, so now the time isn't larger than the threshold. And the other one is needed for normal hook operation - if it isn't called from the delayed work, but enough time has passed since the last notification, we'll notify now.

No need for an EDF task to schedule delayed logging notification IPC,
a one-shot delayed work is enough. Also make sure to protect the hook
execution against potential preemption.

Signed-off-by: Guennadi Liakhovetski <guennadi.liakhovetski@linux.intel.com>
@lyakh

lyakh commented Mar 28, 2025

Copy link
Copy Markdown
Collaborator Author

CI:

  1. multiple-pipeline-all with an IPC timeout for GLB_DELETE_PIPELINE fix IPC timeouts #9926
  2. check-capture-all-formats with an error from the firmware when initialising TDFB
  3. check-kmod-load-unload with an "dsp is not suspended after 15s" error

@kv2019i

kv2019i commented Mar 28, 2025

Copy link
Copy Markdown
Collaborator

@lyakh

lyakh commented Mar 28, 2025

Copy link
Copy Markdown
Collaborator Author

@lyakh

lyakh commented Mar 28, 2025

Copy link
Copy Markdown
Collaborator Author

SOFCI TEST

@lyakh

lyakh commented Mar 28, 2025

Copy link
Copy Markdown
Collaborator Author

paranoia mode - re-testing after #9907 and #9926 got merged

@kv2019i

kv2019i commented Mar 28, 2025

Copy link
Copy Markdown
Collaborator

The HDA/SDW DUTs not available in https://sof-ci.01.org/sofpr/PR9929/build11893/devicetest/index.html . Let me rekick the tests once more.

@kv2019i

kv2019i commented Mar 28, 2025

Copy link
Copy Markdown
Collaborator

SOFCI TEST

@lyakh

lyakh commented Mar 31, 2025

Copy link
Copy Markdown
Collaborator Author

CI:

all known and unrelated

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

5 participants