Hi David, you are correct. This is why I added class loading and unloading logging arguments, and see that the class unloading is done (I've listed this as part of expected/actual output in my first e-mail). The classes *are* being unloaded on time. Maybe that won't be the case in the future, but this is not the topic here.
Anyway it seems the problem is already known: https://bugs.openjdk.java.net/browse/JDK-8256811 (as recently commented on the RHEL bugzilla ticket) Adding a second GC trigger results in missing events being sent. Best regards, Simeon On Thu, 2 Sept 2021 at 16:13, David Holmes <[email protected]> wrote: > On 2/09/2021 10:05 pm, S A wrote: > > Hi all, > > > > bisection lead to: > > > https://github.com/openjdk/jdk16/commit/ba721f5f2fbbf08e22a9993dce0087f46b1f5552 > > < > https://github.com/openjdk/jdk16/commit/ba721f5f2fbbf08e22a9993dce0087f46b1f5552 > > > > > > I've opened: https://bugzilla.redhat.com/show_bug.cgi?id=2000557 > > <https://bugzilla.redhat.com/show_bug.cgi?id=2000557> > > private void unloadClasses() throws Exception { > urlClassLoader.close(); > urlClassLoader = null; > System.gc(); > System.runFinalization(); > } > > The above is not sufficient to guarantee class unloading has occurred. > There are no specified ways to guarantee class unloading. It will depend > on the GC in use as to what will be sufficient to trigger class unloading. > > Cheers, > David > > > Best regards, > > Simeon > > > > On Wed, 1 Sept 2021 at 16:12, S A <[email protected] > > <mailto:[email protected]>> 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 > > <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 > > ... > > >
