RFR: 8369283: Improve trace logs in safepoint machinery [v6]
David Holmes
dholmes at openjdk.org
Thu Oct 9 04:43:19 UTC 2025
On Wed, 8 Oct 2025 08:13:40 GMT, Aleksey Shipilev <shade at openjdk.org> wrote:
>> src/hotspot/share/runtime/safepoint.cpp line 169:
>>
>>> 167: LogStream ls(lt);
>>> 168: cur_state->print_on(&ls);
>>> 169: }
>>
>> Why is this not useful for debugging? I can understand you might not need it for your profiling but UL is primarily about debugging assistance.
>
> I reasoned it is way too noisy to be useful even for debugging.
>
> Note this is `thread_not_running()` checker, which is called from two places in `SafepointSynchronize::synchronize_threads`: initial filtering and on-going checks for state changes. In well-behaved applications most of the threads are actually not running, blocked somewhere in idle thread pool. So prnting this from the initial filtering dumps info on potentially thousands of threads we do not care about 99.9% of the time.
>
> I argued to myself that what we really care about are the threads that are _transiting_ from runnable to blocked. So the new `log_trace(safepoint)` statements are in caller code that uses this `thread_not_running()` checker, and is able to print exactly what they see. "thread is now blocked", for example.
>
> I don't think there are useful bits in `TSS`, really. We can amend trace logs to pull some of that, if you want. Look what it prints in current mainline:
>
>
> [792737314ns] Thread: 0x0000785db85bf4c0 [0x214944] State: _running _at_poll_safepoint 0
> [792737594ns] JavaThread state: _thread_in_Java
> [792738025ns] Thread: 0x0000785db85c08e0 [0x214945] State: _running _at_poll_safepoint 1
> [792738246ns] JavaThread state: _thread_in_vm
I thought it was intended to report which threads still running - i.e. are not reaching the safepoint.
-------------
PR Review Comment: https://git.openjdk.org/jdk/pull/27673#discussion_r2415550637
More information about the hotspot-dev
mailing list