Missing class unload events over JDI with Java 17
S A
simeon.danailov.andreev at gmail.com
Thu Sep 2 12:05:29 UTC 2021
Hi all,
bisection lead to:
https://github.com/openjdk/jdk16/commit/ba721f5f2fbbf08e22a9993dce0087f46b1f5552
I've opened: https://bugzilla.redhat.com/show_bug.cgi?id=2000557
Best regards,
Simeon
On Wed, 1 Sept 2021 at 16:12, S A <simeon.danailov.andreev at gmail.com> wrote:
> Hi all,
>
> my team is currently evaluating OpenJDK 17 (the latest early access build)
> for a part of our application. I've been able to get all our relevant tests
> to work, except for one that checks class unload events sent over JDI.
>
> Originally we added the test due to:
> https://bugs.openjdk.java.net/browse/JDK-8227269 (we wanted to be sure no
> class unload events are lost despite the fix)
>
> The test is Eclipse based (Eclipse has its own JDI implementation) and
> expects to receive a certain set of class unload events under controlled
> debugging conditions. The test has been running on OpenJDK 8 and OpenJDK 11
> for over an year now, without failures. On OpenJDK 17 however, the test
> seems to fail nearly always (but not at 100% rate).
>
> I've created a plain Java snippet and was able to reproduce the problem
> with jdb, see instructions below.
>
> In essence, I see all class unloading is done (I'm checking with "
> -Xlog:class+load,class+unload") at the expected time. No amount of waiting
> in the test or in the snippet (e.g. a loop with 50 ms sleeps for several
> seconds after class unloading is triggered) helps with receiving all
> expected class unload JDI events though. Sometimes all of them are sent,
> sometimes none are sent and sometimes only a partial set of events is sent.
>
> Could someone knowledgeable take a look?
>
> I'll try to find the changes that cause the problem (so far I've not
> checked whether earlier OpenJDK releases are affected). I'll also open a
> RHEL support case for this, but those take a while to get in contact with
> OpenJDK developers.
>
> Best regards and thanks,
> Simeon
>
>
> *Reproduction:*
>
> First, I've made a change to OpenJDK code to check whether all class
> unload events are being sent (in case the Eclipse JDI implementation broke
> for some reason with OpenJDK 17). Its a printf in eventHandler.c :
>
> diff --git a/src/jdk.jdwp.agent/share/native/libjdwp/eventHandler.c
> b/src/jdk.jdwp.agent/share/native/libjdwp/eventHandler.c
> index 2a5912f0777..19a91126e18 100644
> --- a/src/jdk.jdwp.agent/share/native/libjdwp/eventHandler.c
> +++ b/src/jdk.jdwp.agent/share/native/libjdwp/eventHandler.c
> @@ -500,6 +500,7 @@ synthesizeUnloadEvent(void *signatureVoid, void
> *envVoid)
> char *durableSignature =
> jvmtiAllocate((int)strlen(signature)+1);
> (void)strcpy(durableSignature, signature);
>
> + printf("Sending class unload event for: %s\n",
> durableSignature);
> eventHelper_recordClassUnload(node->handlerID,
> durableSignature,
> eventBag);
>
> The snippet I use to reproduce the problem loads a few classes, then
> unloads them. It is:
>
> import java.io.File;
> import java.net.URL;
> import java.net.URLClassLoader;
>
> public class TestClassUnloadEvents {
>
> public static void main(String[] args) throws Exception {
> new TestClassUnloadEvents().execute();
> }
>
> private URLClassLoader urlClassLoader;
>
> public void execute() throws Exception {
> beforeClassLoading();
> loadClasses();
> afterClassLoading();
> unloadClasses();
> afterClassUnloading();
> }
>
> private void loadClasses() throws Exception {
> int numberOfClassesToLoad = Integer.valueOf("10");
> String libraryPath = "classes.jar";
> URL[] urls = {
> new File(libraryPath).toURI().toURL()
> };
> urlClassLoader = new URLClassLoader(urls, null);
> for (int i = 0; i < numberOfClassesToLoad; ++i) {
> String className = "sample.C" + i;
> Class<?> loadClass = urlClassLoader.loadClass(className);
> loadClass.newInstance();
> }
> }
>
> private void unloadClasses() throws Exception {
> urlClassLoader.close();
> urlClassLoader = null;
> System.gc();
> System.runFinalization();
> }
>
> public static void beforeClassLoading() {
> System.out.println("BEFORE CLASS LOADING");
> }
>
> public static void afterClassLoading() {
> System.out.println("AFTER CLASS LOADING");
> }
>
> public static void afterClassUnloading() {
> System.out.println("AFTER CLASS UNLOADING");
> }
> }
>
> Create a jar file from the attached "classes.zip" (I would attach a .jar
> directly but gmail is blocking jar attachments, even archived ones; sorry
> about this). Place the "classes.jar" jar file in the same folder as the
> snippet and from that folder run the snippet. E.g.:
>
> /data/git/jdk17/build/linux-x86_64-server-release/jdk/bin/java
> -Xlog:class+load,class+unload
> -agentlib:jdwp=transport=dt_socket,server=y,suspend=y,address=8080
> TestClassUnloadEvents.java
>
> Then attach jdb with:
>
> /data/git/jdk17/build/linux-x86_64-server-release/jdk/bin/jdb -attach 8080
>
> Input "resume", to let the application finish.
>
> Expected output that I sometimes see (with Java 11 I always see all
> expected prints from the change, where event order is not relevant):
>
> ...
> AFTER CLASS LOADING
> [6.312s][info][class,load] java.io.RandomAccessFile$1 source:
> /data/git/jdk17/build/linux-x86_64-server-release/jdk/modules/java.base
> [6.315s][info][class,unload] unloading class sample.C9 0x00000008001c5c30
> [6.315s][info][class,unload] unloading class sample.C8 0x00000008001c5a28
> [6.315s][info][class,unload] unloading class sample.C7 0x00000008001c5820
> [6.315s][info][class,unload] unloading class sample.C6 0x00000008001c5618
> [6.315s][info][class,unload] unloading class sample.C5 0x00000008001c5410
> [6.315s][info][class,unload] unloading class sample.C4 0x00000008001c5208
> [6.315s][info][class,unload] unloading class sample.C3 0x00000008001c5000
> [6.315s][info][class,unload] unloading class sample.C2 0x00000008001c4c10
> [6.315s][info][class,unload] unloading class sample.C1 0x00000008001c4a08
> [6.315s][info][class,unload] unloading class sample.C0 0x00000008001c4800
> [6.325s][info][class,load ] java.lang.ref.Finalizer$2 source:
> /data/git/jdk17/build/linux-x86_64-server-release/jdk/modules/java.base
> Sending class unload event for: Lsample/C9;
> Sending class unload event for: Lsample/C7;
> Sending class unload event for: Lsample/C5;
> Sending class unload event for: Lsample/C3;
> Sending class unload event for: Lsample/C1;
> Sending class unload event for: Lsample/C0;
> Sending class unload event for: Lsample/C8;
> Sending class unload event for: Lsample/C6;
> Sending class unload event for: Lsample/C4;
> Sending class unload event for: Lsample/C2;
> [6.325s][info][class,load ] java.lang.ref.Finalizer$1 source:
> /data/git/jdk17/build/linux-x86_64-server-release/jdk/modules/java.base
> AFTER CLASS UNLOADING
> ...
>
> Example output that I (often) see, which is unexpected:
>
> ...
> AFTER CLASS LOADING
> [4.863s][info][class,load] java.io.RandomAccessFile$1 source:
> /data/git/jdk17/build/linux-x86_64-server-release/jdk/modules/java.base
> [4.867s][info][class,unload] unloading class sample.C9 0x00000008001c5c30
> [4.867s][info][class,unload] unloading class sample.C8 0x00000008001c5a28
> [4.867s][info][class,unload] unloading class sample.C7 0x00000008001c5820
> [4.867s][info][class,unload] unloading class sample.C6 0x00000008001c5618
> [4.867s][info][class,unload] unloading class sample.C5 0x00000008001c5410
> [4.867s][info][class,unload] unloading class sample.C4 0x00000008001c5208
> [4.867s][info][class,unload] unloading class sample.C3 0x00000008001c5000
> [4.867s][info][class,unload] unloading class sample.C2 0x00000008001c4c10
> [4.867s][info][class,unload] unloading class sample.C1 0x00000008001c4a08
> [4.867s][info][class,unload] unloading class sample.C0 0x00000008001c4800
> [4.876s][info][class,load ] java.lang.ref.Finalizer$2 source:
> /data/git/jdk17/build/linux-x86_64-server-release/jdk/modules/java.base
> Sending class unload event for: Lsample/C9;
> Sending class unload event for: Lsample/C7;
> Sending class unload event for: Lsample/C5;
> Sending class unload event for: Lsample/C3;
> [4.876s][info][class,load ] java.lang.ref.Finalizer$1 source:
> /data/git/jdk17/build/linux-x86_64-server-release/jdk/modules/java.base
> AFTER CLASS UNLOADING
> ...
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://mail.openjdk.java.net/pipermail/serviceability-dev/attachments/20210902/1aaca97b/attachment.htm>
More information about the serviceability-dev
mailing list