Skip to content
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.

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

[BUG][LLEXT] Logging is impossible during module unloading #9242

Open
lyakh opened this issue Jun 19, 2024 · 2 comments
Open

[BUG][LLEXT] Logging is impossible during module unloading #9242

lyakh opened this issue Jun 19, 2024 · 2 comments
Assignees
Labels
bug Something isn't working as expected P3 Low-impact bugs or features
Milestone

Comments

@lyakh
Copy link
Collaborator

lyakh commented Jun 19, 2024

Describe the bug
When a pipeline is freed, all its components are freed too. If any of them is implemented by an LLEXT module and this is its last instance, the memory, where the module was stored in SRAM, will be unmapped. If the module performs any logging in its .reset() or .free() methods, the firmware will fail. We don't know exactly how it fails in such cases, there's no exception dump, but the GLB_DELETE_PIPELINE IPC will time out.

A likely reason is Zephyr logging subsystem accessing some of the data, registered using the LOG_MODULE_REGISTER() macro, from its low priority delayed processing thread. Supposedly modifying the logging system to only access that data during inline processing wouldn't be simple. Possible other (partial) solutions:

  1. Add comments to all those functions (simple but not very effective)
  2. Add a flag that effectively disables logging from the moment .reset() is entered (probably simple, but only partially effective, because that would affect only SOF logging functions like tr_info(), Zephyr-native logging using LOG_INF() and others would remain unaffected.

To Reproduce
Insert a logging call in an LLEXT module's .free() method and create and free a pipeline with it.

Reproduction Rate
100%.

Expected behavior
At least the firmware shouldn't crash. In the best case logging should still work, even if in some reduced form.

Impact
Currently the impact is low. It's trivial to remove all logging from those functions when converting them to modules. But it is inevitable that at some point this will be forgotten and somebody will try to print some logs in those functions, even if only during development or debugging.

Environment
Current SOF "main"

@lyakh lyakh added bug Something isn't working as expected P3 Low-impact bugs or features labels Jun 19, 2024
@lyakh lyakh self-assigned this Jun 19, 2024
@marc-hb
Copy link
Collaborator

marc-hb commented Jun 19, 2024

Shouldn't Zephyr help with that?

@pillo79
Copy link

pillo79 commented Jun 20, 2024

I have a hunch that this might be fixed by zephyrproject-rtos/zephyr#74568.
The current Zephyr does not correctly handle merged section relocations properly, and the logging subsys defines symbols in specific sections that are merged with .data/.rodata. They might therefore be linked at a wrong address, and result in this kind of issues.

@lgirdwood lgirdwood added this to the TBD milestone Jun 20, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working as expected P3 Low-impact bugs or features
Projects
None yet
Development

No branches or pull requests

4 participants