[mavlink] Use separate mutex for event buffer to prevent deadlock #22225
Conversation
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This prevents the mavlink transmit loop from waiting on the module mutex thus not stopping transmissions when the mutex is already taken. This can happen when calling `mavlink status` from the mavlink shell, where `Mavlink::get_status_all_instances()` takes the mutex and then prints the status via pipes to the mavlink transmit buffer. If that pipe cannot be emptied a deadlock happens. Since the MavlinkReceiver thread also waits on the module mutex, both reception and transmission of Mavlink packets are then prevented thus disabling communications entirely.
niklaut
force-pushed
the
APX4-3439-refactor-mutex-use-in-mavlink-to-prevent-deadlock
branch
from
75ac1ec to
e28ccb9
Compare
dagar
approved these changes
Oct 17, 2023
niklaut
deleted the
APX4-3439-refactor-mutex-use-in-mavlink-to-prevent-deadlock
branch
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
This prevents a deadlock when calling mavlink status from the mavlink shell.
Solved Problem
The coredump presents the following deadlock situation: Both mavlink transmit (
mavlink_if0) and receive (mavlink_rcv_if0) tasks are waiting on themavlink_module_mutex, which is held by themavlinktask executing themavlink statuscommand launched from taskmavlink_shell.Why is
mavlink_if0not making progress?modules__mavlink_unity.cpp:4841related to this code in theMavlink::task_main()function, where the mavlink_module_mutex needs to be taken first, so the thread is waiting until the mutex is available.Why is
mavlink_rcv_if0not making progress?modules__mavlink_unity.cpp:4841related to this code in theMavlink::forward_message()function, where the mavlink_module_mutex needs to be taken first, so the thread is waiting until the mutex is available.LockGuard lg{mavlink_module_mutex}; for (Mavlink *inst : mavlink_module_instances) { if (inst && (inst != self) && (inst->_forwarding_on)) { // Pass message only if target component was seen before if (inst->_receiver.component_was_seen(target_system_id, target_component_id)) { inst->pass_message(msg); } } }Why is mavlink_shell not making progress?
The
mavlink_shelltask spawned a new thread to execute themavlink statuscommand that came in via Mavlink Shell. It is waiting on the exit semaphore of the mavlink thread to be posted inside nx_waitpid()`.Why is
mavlinknot making progress?The
mavlink statuscommand calls theMavlink::get_status_all_instances()function, which looks like this:We can see that the
mavlink_module_mutexis taken first, and then a bunch of printf functions are called. This task is waiting inside a printf statement on a semaphore0x2005e660to be posted. This is because the printf output is redirected away from stdout to mavlink via pipe0:We can inspect the pipe device via the
i_private*pointer, pipe1 contains themavlink statuscommand, with the buffer already read and no task waiting on them.However, the pipe0 is waiting on the write semaphore, because the write buffer is full:
You can see that the buffer content
"st: :190, Total: 94 (lost: 47)\n\t sysid: 1, compid: 51, Total: 16 (lo"correlated exactly the with the stuck printf statement in the mavlink thread from functionMavlinkReceiver::print_detailed_rx_stats():Circular dependencies
So we have the following dependency graph:
mavlink_if0waits onmavlink_module_mutexin the main loop, and therefore does not send any mavlink messages anymore.mavlink_rcv_if0also waits on themavlink_module_mutexand therefore does not process incoming messages anymore.mavlink_shellwaits for themavlink statuscommand to finish (that’s fine).mavlinkwaits on the output buffer to be read, so that it can continue to printf its mavlink status output, but the buffer is never read because it already took themavlink_module_mutexand thereforemavlink_if0never reads the output buffer.=> Deadlock
Solution
Remove any blocking attempts to lock
mavlink_module_mutexto in the transmit thread.It's not great that the receive thread is also getting blocked while mavlink status is executing, but at least it won't deadlock anything.
Changelog Entry
For release notes:
Alternatives
We could also increase the pipe buffer size, however, the status output is quite large and scales with the number of mavlink instances, so the buffer would have to be very large. Then it may become problematic to allocate such a large chunk of data and it's not guaranteed that it's really large enough to prevent the deadlock.
Test coverage
LockGuard lg{mavlink_module_mutex};into the main loop.LockGuard lg{mavlink_event_buffer_mutex};instead.