RFR: 8266936: Add a finalization JFR event [v9]

[Markus Grönlund]

On Tue, 24 Aug 2021 12:58:29 GMT, Markus Grönlund <mgronlun at openjdk.org> wrote:

>> Greetings,
>> 
>> Object.finalize() was deprecated in JDK9. There is an ongoing effort to replace and mitigate Object.finalize() uses in the JDK libraries; please see https://bugs.openjdk.java.net/browse/JDK-8253568 for more information. 
>> 
>> We also like to assist users in replacing and mitigating uses in non-JDK code.
>> 
>> Hence, this changeset adds a periodic JFR event to help identify which classes are overriding Object.finalize().
>> 
>> Thanks
>> Markus
>
> Markus Grönlund has updated the pull request incrementally with one additional commit since the last revision:
> 
>   Model as finalizerService

Sorry for the wide distribution, but this became necessary as the PR touches many component areas, if only some with minor parts. Below is a high-level description of this suggested PR.

// Design
Per class statistics about finalizers is implemented by services/finalizerServices. The concept of a "service" is modelled after other management components, such as ClassLoadingService and RuntimeService.

Allocation of an object with a class overriding finalize() with a non-empty finalize() method, is hooked by the runtime using bytecode "_return_register_finalizer", which lets it enter InstanceKlass::register_finalizer().
A hook is added to InstanceKlass::register_finalizer() to notify FinalizerService which increments the number of "objects_on_heap" for the corresponding InstanceKlass.

The dedicated finalizer thread is responsible for running the finalizer methods for referent objects whose java.lang.ref.Finalizers have been enqueued for finalization by the GC.
It will get a native method to report the completion state of a finalizer back to the VM. FinalizerService will then increase the total number of finalizers run and decrease the number of outstanding objects on the heap for the corresponding InstanceKlass.

Class Unloading support is in place by adding a hook into SystemDictionary::do_unloading(). The existing JFR class unloading support is extended to also report a FinalizerStatistic event for the class unloading before its corresponding FinalizerEntry is purged.

-Xlog:finalize is added for Unified Logging support.

// JFR event output jdk.FinalizerStatistics:
Event:jdk.FinalizerStatistics {
  startTime = 14:22:06.683
  finalizableClass = jdk.jfr.event.runtime.TestFinalizerStatisticsEvent$TestClassOverridingFinalize (classLoader = app)
  codeSource = "file:///D:/utilities/jtreg/runtime_artifacts/work/classes/jdk/jfr/event/runtime/TestFinalizerStatisticsEvent.d/"
  objects = 0
  totalFinalizersRun = 2
}


Event:jdk.FinalizerStatistics {
  startTime = 14:22:07.244
  finalizableClass = jdk.jfr.internal.RepositoryChunk (classLoader = bootstrap)
  codeSource = N/A
  objects = 3
  totalFinalizersRun = 0
}


// Xlog:finalizer output:
[4.517s][info][finalizer] Registered object (0x0000000073fbf594) of class jdk.jfr.internal.RepositoryChunk as finalizable
[4.737s][info][finalizer] Registered object (0x000000007ee4f130) of class jdk.jfr.event.runtime.TestFinalizerStatisticsEvent$TestClassOverridingFinalize as finalizable
[5.002s][info][finalizer] Finalizer was run for object (0x000000007ee4f130) of class jdk.jfr.event.runtime.TestFinalizerStatisticsEvent$TestClassOverridingFinalize
[5.004s][info][finalizer] Registered object (0x0000000056bf003b) of class jdk.jfr.internal.RepositoryChunk as finalizable
[5.127s][info][finalizer] Registered object (0x0000000014d51169) of class jdk.jfr.event.runtime.TestFinalizerStatisticsEvent$TestClassOverridingFinalize as finalizable
[5.325s][info][finalizer] Finalizer was run for object (0x0000000014d51169) of class jdk.jfr.event.runtime.TestFinalizerStatisticsEvent$TestClassOverridingFinalize
[5.691s][info][finalizer] Registered object (0x000000002baaa366) of class jdk.jfr.internal.RepositoryChunk as finalizable
[5.696s][info][finalizer] Registered object (0x0000000075b10e10) of class jdk.jfr.event.runtime.TestFinalizerStatisticsEvent$TestClassOverridingFinalize as finalizable
[5.891s][info][finalizer] Finalizer was run for object (0x0000000075b10e10) of class jdk.jfr.event.runtime.TestFinalizerStatisticsEvent$TestClassOverridingFinalize
[6.121s][info][finalizer] Registered object (0x000000003c036ecb) of class jdk.jfr.internal.ChunksChannel as finalizable
[6.342s][info][finalizer] Finalizer was run for object (0x000000003c036ecb) of class jdk.jfr.internal.ChunksChannel

// Misc
JfrSymbolTable - an existing JFR internal component repackaged and published to let other JFR native components re-use the symbol ids (more specifically for the CodeSource in this case).

ClassLoadingService - some parts needed to have better conditional compilation and runtime support for running the JVM when excluding JVM feature 'management'.

jmm.h - is a private interface between the JVM and the JDK, so a CSR should not be necessary for the update and version change.

// Performance
The construction of objects with non-empty finalizers is already relatively slow, in that the VM intercepts the allocation using bytecode _return_register_finalizer, where it has to enter the VM. There, another call is made back into Java to construct a java.lang.ref.Finalizer instance. Therefore, the overhead of placing the hook in InstanceKlass::register_finalizer() is considered minimal from a performance perspective (it performs a lookup in a concurrenthashtable and a CAS).

The reporting back to the VM on finalization complete is performed only by the dedicated FinalizerThread. It introduces some additional work, but FinalizerThread is not considered performance-sensitive because of the indeterministic nature of when finalizers are run (if at all).

// Extensibility
The data saved in FinalizerService can also easily be exposed via JMX (java.lang.Management), but it is not part of this change.

The FinalizerEntry struct can also be extended, for example, with performance data.

An attempt was made to see if it was possible to attribute CPU time as well. However, the relatively short-lived character of a typical finalize() method combined with existing thread CPU timing APIs, which proved too coarse-grained (at least on some platforms?), did not give valuable data.
Another possibility could be to attribute some wall-clock time info, but it is currently unclear how useful that is. Also, the selection of what time source to use is another complexity to consider.

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

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