JTReg test fail - java/util/logging/LogManager/TestLoggerNames.java

[ben-walsh]

Intermittent failure ...

Stacktrace

Execution failed: `main' threw exception: java.lang.ClassCastException: java.util.logging.Logger incompatible with TestLoggerNames$TestLogger    

Standard Output

Got expected NullPointerException for Logger.getLogger(null)

Standard Error

java.lang.ClassCastException: java.util.logging.Logger incompatible with TestLoggerNames$TestLogger
    at TestLoggerNames.main(TestLoggerNames.java:147)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:566)
    at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127)
    at java.base/java.lang.Thread.run(Thread.java:825)

... of test https://github.com/ibmruntimes/openj9-openjdk-jdk11/blob/openj9/test/jdk/java/util/logging/LogManager/TestLoggerNames.java observed ...

https://ci.adoptopenjdk.net/view/Test_openjdk/job/openjdk11_j9_openjdktest_x86-64_windows/118/testReport/junit/java_util_logging_LogManager_TestLoggerNames/java/TestLoggerNames/ https://ci.adoptopenjdk.net/view/Test_openjdk/job/openjdk11_j9_openjdktest_x86-64_linux/270/testReport/junit/java_util_logging_LogManager_TestLoggerNames/java/TestLoggerNames/ https://ci.adoptopenjdk.net/view/Test_openjdk/job/openjdk11_j9_openjdktest_ppc64le_linux/129/testReport/java_util_logging_LogManager_TestLoggerNames/java/TestLoggerNames/

I have kicked off a 100x (https://ci.adoptopenjdk.net/view/Test_grinder/job/Grinder/952) and a 100x with -Xint (https://ci.adoptopenjdk.net/view/Test_grinder/job/Grinder/951).

I have also kicked off a 100x with -Xint on Windows (https://ci.adoptopenjdk.net/view/Test_grinder/job/Grinder/950).

[JasonFengJ9]

Will have a look this.

[ben-walsh]

Both https://ci.adoptopenjdk.net/view/Test_grinder/job/Grinder/952 and https://ci.adoptopenjdk.net/view/Test_grinder/job/Grinder/951 showed a 0% failure rate.

https://ci.adoptopenjdk.net/view/Test_grinder/job/Grinder/950 showed a 2% failure rate.

Rebuilding https://ci.adoptopenjdk.net/view/Test_grinder/job/Grinder/951 as 400x - https://ci.adoptopenjdk.net/view/Test_grinder/job/Grinder/971.

[JasonFengJ9]

Update: Here is the test code snippet from TestLoggerNames.java:

        LogManager.getLogManager().addLogger(new TestLogger("com.foo.bar.zzz", null));
        ...
        TestLogger test = (TestLogger)Logger.getLogger("com.foo.bar.zzz");  --> j.l.ClassCastException here

As per Java doc java.util.logging.LogManager.addLogger():

The application should retain its own reference to the Logger object to avoid it being garbage collected. The LogManager may only retain a weak reference.

Java doc for java.util.logging.Logger.getLogger():

Find or create a logger for a named subsystem. If a logger has already been created with the given name it is returned. Otherwise a new logger is created.

Here is how a java.lang.ClassCastException happened:

• LogManager added a new TestLogger("com.foo.bar.zzz") which is a subclass of java.util.logging.Logger;
• GC was triggered and collected the newly added TestLogger instance;
• Logger.getLogger("com.foo.bar.zzz") can't find a logger for the name com.foo.bar.zzz hence creates a new logger which is an instance of java.util.logging.Logger, then ClassCastException is thrown when the test attempts to cast the return instance to TestLogger. If the TestLogger("com.foo.bar.zzz") instance wasn't collected by GC, Logger.getLogger("com.foo.bar.zzz") can retrieve it successfully and the test passes.

Made a simple testcase adding explicit System.gc() calls between the TestLogger adding and retrieving, the ClassCastException is thrown consistently with both OpenJ9 JDK11 and RI.

So this is a JTReg test issue. It need create a strong reference to TestLogger("com.foo.bar.zzz") first before adding it to the LogManager.