RFR: 8349755: Fix corner case issues in async UL
Axel Boldt-Christmas
aboldtch at openjdk.org
Tue Feb 11 07:40:11 UTC 2025
On Fri, 7 Feb 2025 10:21:37 GMT, Johan Sjölen <jsjolen at openjdk.org> wrote:
> Hi,
>
> There are a few corner-cases when logging with asynchronous UL, all of which I'd like to fix with this PR.
>
> 1. If the `AsyncLogWriter` produces a log message, then it'll deadlock as it'll wait for itself to release the `AsyncLogLock`.
> 2. If a producing thread produces another log message while enqueueing, then a deadlock will occur
>
> We fix this by keeping a thread as the owner of the lock. If the lock is owned by the current thread, then we resort to synchronous logging.
>
> Note, this fix introduces a third case:
>
> 3. If an unattached thread logs then there is no identity, so we cannot check if it holds the lock. We must therefore resort to synchronous logging in this case also
>
> In UL, we have so far guaranteed Program-Order log message appearance. In other words, `log("A"); log("B");` is guaranteed to always appear in the order `AB` in the log output. For cases 1 and 3, we still keep this guarantee. However, for case 2 we break this guarantee. The recursive log message will appear before any unflushed log messages from the logging thread. As I see no simple way of fixing this, along with the fact that this is highly unlikely to ever occur (this has never been observed in production), I've decided to break that guarantee and prioritize logs not being missing.
>
> As it's preferable that we do not have recursive logging (as in case 2 and partially in case 1), I've decided to `assert` that these should not hold. In debug systems, during testing, we can find any accidental recursive logging. In production systems, we will handle this correctly by going back to synchronous logging.
>
> Testing: GHA only, so far.
>
> All the best,
> Johan
Looks good. Have a few naming and code structure suggestions.
src/hotspot/share/logging/logAsyncWriter.cpp line 96:
> 94: // This function checks for cases where continuing with asynchronous logging may lead to stability issues, such as a deadlock.
> 95: // If this returns true then we give up on logging asynchronously and do so synchronously instead.
> 96: bool AsyncLogWriter::resort_to_synchronous_logging() {
The name `resort_to_synchronous_logging` says something about what the callers of `enqueue` should do. I think something more in the line of `is_enqueue_disallowed` / `is_async_logging_disallowed` would be better. Or probably inverting the the logic, and have it be `is_enqueue_allowed`.
src/hotspot/share/logging/logAsyncWriter.cpp line 106:
> 104: is_recursively_logging || // A thread enqueuing a message has attempted to log something.
> 105: alw == nullptr || // There is no AsyncLogWriter instance yet.
> 106: this_thread == nullptr; // The current thread is unattached.
I think an early return makes this more readable. Might even be worth just having four separate if statements.
Suggestion:
if (this_thread == nullptr) {
// The current thread is unattached.
return true;
}
bool is_async_log_thread = alw == this_thread;
bool is_recursively_logging = holding_thread == this_thread;
assert(!is_recursively_logging, "Do not log while holding the Async log lock");
return is_async_log_thread || // The async log producer is attempting to log, leading to recursive logging.
is_recursively_logging || // A thread enqueuing a message has attempted to log something.
alw == nullptr; // There is no AsyncLogWriter instance yet.
Suggestion:
if (this_thread == nullptr) {
// The current thread is unattached.
return true;
}
if (holding_thread == this_thread) {
// A thread, while enqueuing a message, has attempted to log something.
// Do not log while holding the Async log lock.
// Try to catch possible occurrences in debug builds.
DEBUG_ONLY(ShouldNotReachHere();)
return true;
}
if (alw == nullptr) {
// There is no AsyncLogWriter instance yet.
return true;
}
if (this_thread == alw) {
// The async log producer is attempting to log, leading to recursive logging.
return true;
}
return false;
-------------
Changes requested by aboldtch (Reviewer).
PR Review: https://git.openjdk.org/jdk/pull/23513#pullrequestreview-2607892358
PR Review Comment: https://git.openjdk.org/jdk/pull/23513#discussion_r1950359423
PR Review Comment: https://git.openjdk.org/jdk/pull/23513#discussion_r1950354412
More information about the hotspot-runtime-dev
mailing list