RFR: 8369283: Improve trace logs in safepoint machinery [v5]

[Aleksey Shipilev]

On Wed, 8 Oct 2025 05:32:46 GMT, David Holmes <dholmes at openjdk.org> wrote:

>> Aleksey Shipilev has updated the pull request incrementally with one additional commit since the last revision:
>> 
>>   A bit more verbose
>
> 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 now:


[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

-------------

PR Review Comment: https://git.openjdk.org/jdk/pull/27673#discussion_r2412981865