RFR: 8352738: Implement JEP 520: JFR Method Timing and Tracing
Aleksey Shipilev
shade at openjdk.org
Thu May 22 12:35:10 UTC 2025
On Mon, 19 May 2025 15:24:42 GMT, Erik Gahlin <egahlin at openjdk.org> wrote:
> Could I have a review of this enhancement that will add tracing capabilities to JFR? There are opportunities for performance improvements in the implementation, but I would rather add them later and separately.
>
> Testing: tier 1-3, test/jdk/jdk/jfr
>
> Thanks
> Erik
Impressive work! I read it a bit superficially, here are comments/questions:
src/hotspot/share/jfr/instrumentation/jfrClassTransformer.cpp line 47:
> 45: #include "utilities/macros.hpp"
> 46:
> 47: static void log_pending_exception(oop throwable) {
Put it under `JfrClassTransformer::`? Global symbols would eventually clash.
src/hotspot/share/jfr/instrumentation/jfrClassTransformer.cpp line 109:
> 107: Handle pd(THREAD, ik->protection_domain());
> 108: Symbol* const class_name = ik->name();
> 109: const char* const klass_name = class_name != nullptr ? class_name->as_C_string() : "";
Unused `klass_name`?
src/hotspot/share/jfr/instrumentation/jfrClassTransformer.cpp line 131:
> 129: assert(new_ik != nullptr, "invariant");
> 130: assert(new_ik->name() != nullptr, "invariant");
> 131: assert(strncmp(ik->name()->as_C_string(), new_ik->name()->as_C_string(), strlen(ik->name()->as_C_string())) == 0, "invariant");
Nit: I suspect `IK->name()` is an interned `Symbol`, so you can just compare those directly, without converting to `C_String`.
src/hotspot/share/jfr/instrumentation/jfrClassTransformer.cpp line 143:
> 141: return nullptr;
> 142: }
> 143: return state != nullptr ? klass_being_redefined(ik, state) : nullptr;
Redundant `state != nullptr` check here.
src/hotspot/share/jfr/instrumentation/jfrEventClassTransformer.cpp line 215:
> 213: assert(JdkJfrEvent::is_a(ik), "invariant");
> 214: if (has_annotation(ik, annotation_type, default_value, value)) {
> 215: return true;
Unnecessary change.
src/hotspot/share/jfr/instrumentation/jfrJvmtiAgent.cpp line 81:
> 79: jint* new_class_data_len,
> 80: unsigned char** new_class_data) {
> 81: if (class_being_redefined == nullptr) {
OK, so this method is now completely empty. Do you even need it then? Or is it a part of some external API? If so, put a comment here, so no one removes it accidentally.
src/hotspot/share/jfr/jni/jfrJavaSupport.cpp line 942:
> 940: typeArrayOop obj = oopFactory::new_typeArray(T_LONG, length, CHECK_NULL);
> 941: ArrayAccess<>::arraycopy_from_native(&array->first(), obj, typeArrayOopDesc::element_offset<jlong>(0), length);
> 942: array->clear();
This will trip someone at some point: the method name suggests we create the array of the incoming argument. But this method _also_clears the incoming array. Do we even need to clear it? Can this clearing be done in callers?
src/hotspot/share/jfr/jni/jfrUpcalls.cpp line 289:
> 287: }
> 288:
> 289: // Call JVMUpcalls::onMethodTrace(byte[], long[] , String[], String[], int[])
Confused me a little: the signature here does not match the arguments we actually push. Maybe easier to just say `JVMUpcalls::onMethodTrace` without signature.
src/hotspot/share/jfr/jni/jfrUpcalls.cpp line 291:
> 289: // Call JVMUpcalls::onMethodTrace(byte[], long[] , String[], String[], int[])
> 290: JavaCallArguments args;
> 291: JavaValue result(T_OBJECT);
Sounds more like `T_ARRAY`, as it returns `byte[]`? Likely does not matter for anything.
src/hotspot/share/jfr/metadata/metadata.xml line 1297:
> 1295: <Field type="Method" name="method" label="Method" />
> 1296: <Field type="long" name="invocations" label="Invocations" description = "The number of times the method was invoked"/>
> 1297: <Field type="Tickspan" name="average" label="Average" description="An approximation of the wall-clock time it took for the method to execute"/>
Suggestion:
<Field type="long" name="invocations" label="Invocations" description="The number of times the method was invoked "/>
<Field type="Tickspan" name="average" label="Average" description="An approximation of the wall-clock time it took for the method to execute" />
src/hotspot/share/jfr/recorder/checkpoint/types/traceid/jfrTraceIdEpoch.cpp line 67:
> 65:
> 66: bool JfrTraceIdEpoch::is_synchronizing() {
> 67: return Atomic::load_acquire(&_synchronizing);
This suggests the writes to `_synchronizing` should be releases. One might think `OrderAccess::fence`-s in `{begin|end}_epoch_shift` and do it, but at least in `begin_epoch_shift`, the fence is misplaced, should be "ops; fence(); releasing-store". Maybe you want to just `Atomic::release_store_fence(&_synchronizing, ...)` them instead.
src/hotspot/share/jfr/recorder/checkpoint/types/traceid/jfrTraceIdEpoch.cpp line 81:
> 79:
> 80: bool JfrTraceIdEpoch::has_method_tracer_changed_tag_state() {
> 81: return Atomic::load(&_method_tracer_state);
Checking: sure that no memory ordering is needed here? Sounds like this code consumes some state from another thread when checking this flag.
+ if (JfrTraceIdEpoch::has_method_tracer_changed_tag_state()) {
+ do_method_tracer_klasses();
+ }
src/hotspot/share/jfr/recorder/checkpoint/types/traceid/jfrTraceIdMacros.hpp line 54:
> 52: #define LEAKP_META_BIT (BIT << 2)
> 53: #define LEAKP_BIT (LEAKP_META_BIT << META_SHIFT)
> 54: #define TIMING_BIT LEAKP_BIT // Alias
I guess there a reason to piggyback on leakp bit? Is this necessary? Sounds like there is still space for this bit? I guess it might be confusing when something like `SET_TIMING_BIT` sets `LEAKP_BIT`?
src/hotspot/share/jfr/support/methodtracer/jfrFilter.cpp line 73:
> 71: if (name->equals("jdk.proxy1", 10)) {
> 72: return false;
> 73: }
Curious: what's `jdk.proxy1` module?
src/hotspot/share/jfr/support/methodtracer/jfrFilter.cpp line 231:
> 229: } else if (mod == 3) {
> 230: modification = "+timing +tracing";
> 231: }
Common style: convert to `switch` and `ShouldNotReachHere()` the `default` case?
src/hotspot/share/jfr/support/methodtracer/jfrFilterManager.cpp line 81:
> 79:
> 80: const JfrFilter* JfrFilterManager::current() {
> 81: return Atomic::load(&_current);
Memory ordering question again: does it need `load_acquire`? For example, are we accessing `JfrFilter` contents from another thread? `xchg` installation covers the release part, we only need need `load_acquire` here.
src/hotspot/share/jfr/support/methodtracer/jfrMethodProcessor.cpp line 90:
> 88:
> 89: static inline bool is_timing(int modification) {
> 90: return modification == -1 ? false : (modification & 1) != 0;
Reliability: convert `1` and `2` magical numbers to symbolic constants somewhere?
src/hotspot/share/jfr/support/methodtracer/jfrMethodTracer.cpp line 141:
> 139:
> 140: // 1. Is the ik the initial load, i.e.the first InstanceKlass, or a scratch klass, denoting a redefine / retransform?
> 141: const Klass* const existing_klass = JfrClassTransformer::find_existing_klass(ik, THREAD);
Sounds like `JfrClassTransformer::find_existing_klass` can return `InstanceKlass*`, and thus we can avoid a whole lot of `InstanceKlass::cast`-s everywhere?
src/hotspot/share/jfr/support/methodtracer/jfrMethodTracer.cpp line 192:
> 190: }
> 191:
> 192: static inline void log_add(const InstanceKlass* ik) {
Move it under `JfrMethodTracer::log_add` to avoid symbol clash later.
src/hotspot/share/jfr/support/methodtracer/jfrMethodTracer.cpp line 284:
> 282: static GrowableArray<jlong>* _current_unloaded_class_ids = nullptr;
> 283: static GrowableArray<jlong>* _stale_class_ids = nullptr;
> 284: static GrowableArray<jlong>* _empty_class_ids = nullptr;
Global symbols, move them under `JfrMethodTracer`?
src/hotspot/share/jfr/support/methodtracer/jfrTraceTagging.hpp line 31:
> 29: #include "memory/allStatic.hpp"
> 30:
> 31: class InstanceKlass;;
Suggestion:
class InstanceKlass;
src/hotspot/share/oops/instanceKlass.hpp line 360:
> 358: Method* method_with_idnum(int idnum) const;
> 359: Method* method_with_orig_idnum(int idnum) const;
> 360: Method* method_with_orig_idnum(int idnum, int version) const;
Checking: do you need these turned `const`, or this is just convenient touchup? If this is unnecessary, I would probably limit the changes to shared code.
src/jdk.jfr/share/classes/jdk/jfr/internal/EventControl.java.rej line 1:
> 1: diff a/src/jdk.jfr/share/classes/jdk/jfr/internal/EventControl.java b/src/jdk.jfr/share/classes/jdk/jfr/internal/EventControl.java (rejected hunks)
This checks in `.rej` file! Odd that bots have not complained about it. Please report this to Skara folks.
src/jdk.jfr/share/classes/jdk/jfr/internal/MetadataRepository.java line 208:
> 206: nativeControls.remove(n);
> 207: TypeLibrary.removeType(nativeType.getId());
> 208: pEventType.setAnnotations(nativeType.getAnnotationElements());
This looks like accidental removal. Is it?
src/jdk.jfr/share/classes/jdk/jfr/internal/tracing/PlatformTracer.java line 249:
> 247: }
> 248:
> 249: private synchronized static void reset() {
Any sense to do `synchronized` here, given that `timed{Methods,Classes}` are `ConcurrentHashMap`-s?
src/jdk.jfr/share/classes/jdk/jfr/internal/tracing/PlatformTracer.java line 273:
> 271: JVM.exclude(current);
> 272: long classId = Type.getKnownType(String.class).getId();
> 273: long methodId = classId << 16 + 983059;
What's `983059`?
src/jdk.jfr/share/classes/jdk/jfr/tracing/MethodTracer.java line 53:
> 51: long endTime = JVM.counterTime();
> 52: long duration = endTime - startTime;
> 53: if (MethodTraceEvent.enabled() && JVM.getEventWriter() != null) {
Comprehension check: This method is "only" called from the instrumented code. Do we then actually know that `MethodTraceEvent` is enabled? Can squeeze a few cycles bypassing this check.
-------------
PR Review: https://git.openjdk.org/jdk/pull/25306#pullrequestreview-2860740206
PR Review Comment: https://git.openjdk.org/jdk/pull/25306#discussion_r2102248620
PR Review Comment: https://git.openjdk.org/jdk/pull/25306#discussion_r2102255800
PR Review Comment: https://git.openjdk.org/jdk/pull/25306#discussion_r2102262165
PR Review Comment: https://git.openjdk.org/jdk/pull/25306#discussion_r2102264172
PR Review Comment: https://git.openjdk.org/jdk/pull/25306#discussion_r2102267383
PR Review Comment: https://git.openjdk.org/jdk/pull/25306#discussion_r2102271892
PR Review Comment: https://git.openjdk.org/jdk/pull/25306#discussion_r2102278626
PR Review Comment: https://git.openjdk.org/jdk/pull/25306#discussion_r2102288863
PR Review Comment: https://git.openjdk.org/jdk/pull/25306#discussion_r2102292285
PR Review Comment: https://git.openjdk.org/jdk/pull/25306#discussion_r2102294829
PR Review Comment: https://git.openjdk.org/jdk/pull/25306#discussion_r2102311652
PR Review Comment: https://git.openjdk.org/jdk/pull/25306#discussion_r2102320379
PR Review Comment: https://git.openjdk.org/jdk/pull/25306#discussion_r2102326390
PR Review Comment: https://git.openjdk.org/jdk/pull/25306#discussion_r2102338488
PR Review Comment: https://git.openjdk.org/jdk/pull/25306#discussion_r2102348149
PR Review Comment: https://git.openjdk.org/jdk/pull/25306#discussion_r2102352820
PR Review Comment: https://git.openjdk.org/jdk/pull/25306#discussion_r2102358055
PR Review Comment: https://git.openjdk.org/jdk/pull/25306#discussion_r2102363240
PR Review Comment: https://git.openjdk.org/jdk/pull/25306#discussion_r2102364937
PR Review Comment: https://git.openjdk.org/jdk/pull/25306#discussion_r2102394386
PR Review Comment: https://git.openjdk.org/jdk/pull/25306#discussion_r2102398712
PR Review Comment: https://git.openjdk.org/jdk/pull/25306#discussion_r2102402444
PR Review Comment: https://git.openjdk.org/jdk/pull/25306#discussion_r2102407122
PR Review Comment: https://git.openjdk.org/jdk/pull/25306#discussion_r2102412679
PR Review Comment: https://git.openjdk.org/jdk/pull/25306#discussion_r2102426431
PR Review Comment: https://git.openjdk.org/jdk/pull/25306#discussion_r2102430181
PR Review Comment: https://git.openjdk.org/jdk/pull/25306#discussion_r2102445353
More information about the hotspot-jfr-dev
mailing list