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 <[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 (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 > ... >
