RFR: 8267920: Create separate Events buffer for VMOperations [v2]

[Coleen Phillimore]

On Fri, 28 May 2021 17:47:46 GMT, Stefan Karlsson <stefank at openjdk.org> wrote:

>> The Events classes collect events in a circular buffer that gets dumped into the hs_err files. There are different sections to sort out different types of events. See:
>> 
>>   // A log for internal exception related messages, like internal
>>   // throws and implicit exceptions.
>>   static ExceptionsEventLog* _exceptions;
>> 
>>   // Deoptization related messages
>>   static StringEventLog* _deopt_messages;
>> 
>>   // Redefinition related messages
>>   static StringEventLog* _redefinitions;
>> 
>>   // Class unloading events
>>   static UnloadingEventLog* _class_unloading;
>> 
>> There's also a buffer for non-categorized events:
>> 
>>   // A log for generic messages that aren't well categorized.
>>   static StringEventLog* _messages;
>> 
>> I propose that we create a separate buffer for VMOperations. This will make it easier to debug GC related bugs.
>> 
>> With the proposed patch, the hs_err files will now have a section that looks like this.
>> 
>> VM Operations (20 events):
>> Event: 0,186 Executing VM operation: HandshakeAllThreads
>> Event: 0,186 Executing VM operation: HandshakeAllThreads done
>> Event: 0,230 Executing VM operation: ZMarkStart
>> Event: 0,230 Executing VM operation: ZMarkStart done
>> Event: 0,232 Executing VM operation: HandshakeAllThreads
>> Event: 0,232 Executing VM operation: HandshakeAllThreads done
>> Event: 0,232 Executing VM operation: HandshakeAllThreads
>> Event: 0,232 Executing VM operation: HandshakeAllThreads done
>> Event: 0,232 Executing VM operation: HandshakeAllThreads
>> Event: 0,233 Executing VM operation: HandshakeAllThreads done
>> Event: 0,233 Executing VM operation: ZMarkEnd
>> Event: 0,233 Executing VM operation: ZMarkEnd done
>> Event: 0,234 Executing VM operation: HandshakeAllThreads
>> Event: 0,234 Executing VM operation: HandshakeAllThreads done
>> Event: 0,234 Executing VM operation: ZVerify
>> Event: 0,234 Executing VM operation: ZVerify done
>> Event: 0,234 Executing VM operation: CleanClassLoaderDataMetaspaces
>> Event: 0,234 Executing VM operation: CleanClassLoaderDataMetaspaces done
>> Event: 0,235 Executing VM operation: ZRelocateStart
>> Event: 0,235 Executing VM operation: ZRelocateStart done
>
> Stefan Karlsson has updated the pull request incrementally with one additional commit since the last revision:
> 
>   Review coleenp

This looks good. Took a while to figure out why LogFunction was added, but this is helpful.  We might want to separate class loading in the future.

src/hotspot/share/utilities/events.hpp line 471:

> 469: // These end up in the default log.
> 470: typedef EventMarkWithLogFunction<Events::log> EventMark;
> 471: typedef EventMarkWithLogFunction<Events::log_vm_operation> EventMarkVMOperation;

Can you add a comment just above EventMarkVMOperation line 470 like,
// These go to the vm_operation log
For some reason, I read the comment as applying to both instantiations.

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

Marked as reviewed by coleenp (Reviewer).

PR: https://git.openjdk.java.net/jdk/pull/4243