OperationType in SafepointBegin event

[Jean-Philippe Bempel]

Hi Stefan,

I agree and we are doing the same at Datadog, putting thresholds to 0
for both SafepointBegin & ExecuteVMOperation. it's just that the day
you are putting a threshold because too many safepoints, you may miss
information to troubleshoot.
Information is already there and latency for both events come from
different issues (threads to reach the safepoint, and VM operation
like a GC may have completely different characteristics)

Jean-Philippe

On Wed, Nov 25, 2020 at 9:07 AM Stefan Karlsson
<stefan.karlsson at oracle.com> wrote:
>
> Hi,
>
> I'll let others answer your proposal, but I want to give another
> perspective on this:
>
> Whenever I use JFR to debug latencies, I almost always change the
> threshold of ExecuteVMOperation to 0ms. (I do the same for other events
> as well, but I don't know them by heart) Maybe it would make sense to
> make it the default for this event? I don't think the system would be
> overwhelmed by getting a few more events, especially now that we are
> replacing more and more VM operations with thread-local handshakes.
>
> StefanK
>
> On 2020-11-24 16:57, Jean-Philippe Bempel wrote:
> > Hello All,
> >
> > With default JFR settings (default.jfc) you may end up with no 1:1
> > mapping between SafepointBegin event and ExecuteVMOperation event.
> > While having ExecuteVMOperation without SafepointBegin could be normal
> > (Some VMOperation does not require Safepoint like Handshake for
> > example), Having a SafepointBegin should normally be associated with a
> > VM operation.
> >
> > By default JFR settings record SafepointBegin & ExecutionVMOperation
> > events greater than 10ms (threshold). So your VM Operation could be
> > quick (less than 10ms, so not recorded along with VMOperation type)
> > but the SafepointBegin event can have a long duration because bringing
> > all Java threads at safepoint (so called Time-To-SafePoint) can take
> > several ms in itself (ex System.arraycopy call on large buffers).
> >
> > So you’re ending up with a long SafepointBegin event, but without
> > ExecuteVMOperation event associated, and could not figure out what
> > triggers this safepoint.
> > Currently, SafepointBegin event does not record the VMOperation
> > type[1] unlike ExecuteVMOperation event[2] which does not facilitate
> > the troubleshooting.
> >
> > Note: Xlog tracing (-Xlog:safepoint) give us the VMOperation type[3]
> >
> > My proposal is the following:
> >
> > Add the same operation field in SafepointBegin than in
> > ExecuteVMOperation event in metadata.xml and modify
> > post_safepoint_begin_event to add VMThread::vm_op_type() and set it
> > into the event.
> > If you are ok with that I can open a ticket and push a PR.
> >
> > Regards,
> > Jean-Philippe
> >
> > [1] https://github.com/openjdk/jdk/blob/master/src/hotspot/share/jfr/metadata/metadata.xml#L560
> > [2] https://github.com/openjdk/jdk/blob/master/src/hotspot/share/jfr/metadata/metadata.xml#L589
> > [3] https://github.com/openjdk/jdk/blob/master/src/hotspot/share/runtime/safepoint.cpp#L1114-L1125
> >