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: delayed logging can access memory after it's unmapped #9371

Closed
lyakh opened this issue Aug 16, 2024 · 5 comments · Fixed by zephyrproject-rtos/zephyr#77289
Closed
Labels
bug Something isn't working as expected
Milestone

Comments

@lyakh
Copy link
Collaborator

lyakh commented Aug 16, 2024

Describe the bug
If an LLEXT module is unloaded "very soon" after it has used logging, the logging thread can try to access that module's memory, which by that time is unmapped. That leads to invalid memory access and to a DSP exception.

To Reproduce
This first was discovered with logging was used in module clean-up functions and lead to commit ccd41ba Then it also turned out that with the speaker-test pipelines are created and destroyed rapidly and in those cases logging during module initialisation or configuration can cause such invalid access too. That lead to 09e7a8f

Reproduction Rate
Currently those paths aren't present in "main," but the latter commit is just a work-around, it should be replaced with a proper solution. Without that work-around or with logs during module clean-up, reproduction rate is 100%

Expected behavior
Ideally Logging should be possible from LLEXT modules without limitations, in which cases memory unmapping should be delayed respectively. This however might be too difficult. Alternative approaches could be making sure, that logging from modules doesn't access module memory, or dropping logs if memory is unmapped.

Impact
If not addressed, this is a show-stopper, with current work-arounds it's a significant inconvenience

@lyakh lyakh added the bug Something isn't working as expected label Aug 16, 2024
@lgirdwood
Copy link
Member

@lyakh can you describe what the logging thread does with module memory ? IIUC, calling LOG() would copy local module data to logging data storage as a one time operation ?

@lyakh
Copy link
Collaborator Author

lyakh commented Aug 19, 2024

@lyakh can you describe what the logging thread does with module memory ? IIUC, calling LOG() would copy local module data to logging data storage as a one time operation ?

@lgirdwood I think the logging context, created by LOG_MODULE_REGISTER() is accessed by the logging thread

@lgirdwood
Copy link
Member

@lyakh best to work with @teburd on a solution.

@lgirdwood lgirdwood added this to the v2.11 milestone Aug 21, 2024
@lyakh
Copy link
Collaborator Author

lyakh commented Aug 22, 2024

@lyakh best to work with @teburd on a solution.

@lgirdwood sure, already doing that. But the zephyrproject-rtos/zephyr#77289 PR is now stuck waiting for the assignee @nordic-krch

@lyakh
Copy link
Collaborator Author

lyakh commented Aug 30, 2024

fixed by zephyrproject-rtos/zephyr#77289 , SOF now needs to update its manifest, and that's been done by #9319 now too

@lyakh lyakh closed this as completed Aug 30, 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
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants