eclipse-openj9 / openj9

Eclipse OpenJ9: A Java Virtual Machine for OpenJDK that's optimized for small footprint, fast start-up, and high throughput. Builds on Eclipse OMR (https://github.com/eclipse/omr) and combines with the Extensions for OpenJDK for OpenJ9 repo.
Other
3.28k stars 722 forks source link

OpenJDK logging/LogManager/Configuration/rootLoggerHandlers/BadRootLoggerHandlers Expected root level FINER, got: INFO #15294

Open pshipton opened 2 years ago

pshipton commented 2 years ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.openjdk_aarch64_mac_Nightly/75 jdk_util_1 java/util/logging/LogManager/Configuration/rootLoggerHandlers/BadRootLoggerHandlers.java

20:02:46  ACTION: main -- Failed. Execution failed: `main' threw exception: java.lang.RuntimeException: Expected root level FINER, got: INFO
20:02:46  REASON: User specified action: run main/othervm/java.security.policy==test.policy -Dlogging.properties=badlogging.properties -Dclz=1custom.DotHandler BadRootLoggerHandlers CUSTOM 
20:02:46  TIME:   0.418 seconds
20:02:46  messages:
20:02:46  command: main -Dlogging.properties=badlogging.properties -Dclz=1custom.DotHandler BadRootLoggerHandlers CUSTOM
20:02:46  reason: User specified action: run main/othervm/java.security.policy==test.policy -Dlogging.properties=badlogging.properties -Dclz=1custom.DotHandler BadRootLoggerHandlers CUSTOM 
20:02:46  Mode: othervm [/othervm specified]
20:02:46  Additional options from @modules: --add-modules java.logging
20:02:46  elapsed time (seconds): 0.418
20:02:46  configuration:
20:02:46  Boot Layer
20:02:46    add modules: java.logging
20:02:46  
20:02:46  STDOUT:
20:02:46  Root level is: INFO
20:02:46  Handler(1) created
20:02:46  Handler(1) closed
20:02:46  Root level is: FINE
20:02:46  Handler(2) created
20:02:46  Handler(2) closed
20:02:46  Root level is: INFO
20:02:46  STDERR:
20:02:46  WARNING: A command line option has enabled the Security Manager
20:02:46  WARNING: The Security Manager is deprecated and will be removed in a future release
20:02:46  WARNING: A terminally deprecated method in java.lang.System has been called
20:02:46  WARNING: System::setSecurityManager has been called by java.lang.System
20:02:46  WARNING: Please consider reporting this to the maintainers of java.lang.System
20:02:46  WARNING: System::setSecurityManager will be removed in a future release
20:02:46  INFO [Fri Jun 10 10:02:31 AEST 2022]: BadRootLoggerHandlers main: hi (CUSTOM)
20:02:46  INFO [Fri Jun 10 10:02:31 AEST 2022]: BadRootLoggerHandlers main: there!
20:02:46  java.lang.RuntimeException: Expected root level FINER, got: INFO
20:02:46    at BadRootLoggerHandlers.main(BadRootLoggerHandlers.java:225)
20:02:46    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
20:02:46    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
20:02:46    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
20:02:46    at java.base/java.lang.reflect.Method.invoke(Method.java:568)
20:02:46    at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127)
20:02:46    at java.base/java.lang.Thread.run(Thread.java:862)
20:02:46  
20:02:46  JavaTest Message: Test threw exception: java.lang.RuntimeException: Expected root level FINER, got: INFO
20:02:46  JavaTest Message: shutting down test
20:02:46  
20:02:46  STATUS:Failed.`main' threw exception: java.lang.RuntimeException: Expected root level FINER, got: INFO
20:02:46  rerun:
20:02:46  cd /Users/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_aarch64_mac_Nightly/aqa-tests/TKG/output_16548188468038/jdk_util_1/work/scratch/3 && \
20:02:46  HOME=/Users/jenkins \
20:02:46  PATH=/bin:/usr/bin:/usr/sbin \
20:02:46  CLASSPATH=/Users/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_aarch64_mac_Nightly/aqa-tests/TKG/output_16548188468038/jdk_util_1/work/classes/1/java/util/logging/LogManager/Configuration/rootLoggerHandlers/BadRootLoggerHandlers.d:/Users/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_aarch64_mac_Nightly/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/util/logging/LogManager/Configuration/rootLoggerHandlers:/Users/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_aarch64_mac_Nightly/jvmtest/openjdk/jtreg/lib/javatest.jar:/Users/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_aarch64_mac_Nightly/jvmtest/openjdk/jtreg/lib/jtreg.jar \
20:02:46      /Users/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_aarch64_mac_Nightly/openjdkbinary/j2sdk-image/bin/java \
20:02:46          -Dtest.vm.opts='-ea -esa -Xmx1540m -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache -XX:-UseCompressedOops' \
20:02:46          -Dtest.tool.vm.opts='-J-ea -J-esa -J-Xmx1540m -J-Xdump:system:none -J-Xdump:heap:none -J-Xdump:system:events=gpf+abort+traceassert+corruptcache -J-XX:-UseCompressedOops' \
20:02:46          -Dtest.compiler.opts= \
20:02:46          -Dtest.java.opts= \
20:02:46          -Dtest.jdk=/Users/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_aarch64_mac_Nightly/openjdkbinary/j2sdk-image \
20:02:46          -Dcompile.jdk=/Users/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_aarch64_mac_Nightly/openjdkbinary/j2sdk-image \
20:02:46          -Dtest.timeout.factor=8.0 \
20:02:46          -Dtest.nativepath=/Users/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_aarch64_mac_Nightly/openjdkbinary/openjdk-test-image/jdk/jtreg/native \
20:02:46          -Dtest.root=/Users/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_aarch64_mac_Nightly/aqa-tests/openjdk/openjdk-jdk/test/jdk \
20:02:46          -Dtest.name=java/util/logging/LogManager/Configuration/rootLoggerHandlers/BadRootLoggerHandlers.java \
20:02:46          -Dtest.file=/Users/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_aarch64_mac_Nightly/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/util/logging/LogManager/Configuration/rootLoggerHandlers/BadRootLoggerHandlers.java \
20:02:46          -Dtest.src=/Users/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_aarch64_mac_Nightly/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/util/logging/LogManager/Configuration/rootLoggerHandlers \
20:02:46          -Dtest.src.path=/Users/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_aarch64_mac_Nightly/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/util/logging/LogManager/Configuration/rootLoggerHandlers \
20:02:46          -Dtest.classes=/Users/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_aarch64_mac_Nightly/aqa-tests/TKG/output_16548188468038/jdk_util_1/work/classes/1/java/util/logging/LogManager/Configuration/rootLoggerHandlers/BadRootLoggerHandlers.d \
20:02:46          -Dtest.class.path=/Users/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_aarch64_mac_Nightly/aqa-tests/TKG/output_16548188468038/jdk_util_1/work/classes/1/java/util/logging/LogManager/Configuration/rootLoggerHandlers/BadRootLoggerHandlers.d \
20:02:46          -Dtest.class.path.prefix=/Users/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_aarch64_mac_Nightly/aqa-tests/TKG/output_16548188468038/jdk_util_1/work/classes/1/java/util/logging/LogManager/Configuration/rootLoggerHandlers/BadRootLoggerHandlers.d:/Users/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_aarch64_mac_Nightly/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/util/logging/LogManager/Configuration/rootLoggerHandlers \
20:02:46          -Dtest.modules=java.logging \
20:02:46          -Djava.security.policy==/Users/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_aarch64_mac_Nightly/aqa-tests/TKG/output_16548188468038/jdk_util_1/work/scratch/3/test.policy_new \
20:02:46          -Djava.security.manager=default \
20:02:46          --add-modules java.logging \
20:02:46          -ea \
20:02:46          -esa \
20:02:46          -Xmx1540m \
20:02:46          -Xdump:system:none \
20:02:46          -Xdump:heap:none \
20:02:46          -Xdump:system:events=gpf+abort+traceassert+corruptcache \
20:02:46          -XX:-UseCompressedOops \
20:02:46          -Djava.library.path=/Users/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_aarch64_mac_Nightly/openjdkbinary/openjdk-test-image/jdk/jtreg/native \
20:02:46          -Dlogging.properties=badlogging.properties \
20:02:46          -Dclz=1custom.DotHandler \
20:02:46          com.sun.javatest.regtest.agent.MainWrapper /Users/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_aarch64_mac_Nightly/aqa-tests/TKG/output_16548188468038/jdk_util_1/work/java/util/logging/LogManager/Configuration/rootLoggerHandlers/BadRootLoggerHandlers.d/main.4.jta CUSTOM
pshipton commented 1 year ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_sanity.openjdk_aarch64_mac_Nightly/145 jdk_util_1 java/util/logging/LogManager/Configuration/rootLoggerHandlers/BadRootLoggerHandlers.java

22:18:31  messages:
22:18:31  command: main -Dlogging.properties=badlogging.properties -Dclz=1custom.DotHandler BadRootLoggerHandlers CUSTOM
22:18:31  reason: User specified action: run main/othervm -Dlogging.properties=badlogging.properties -Dclz=1custom.DotHandler BadRootLoggerHandlers CUSTOM 
22:18:31  Mode: othervm [/othervm specified]
22:18:31  Additional options from @modules: --add-modules java.logging
22:18:31  elapsed time (seconds): 0.392
22:18:31  configuration:
22:18:31  Boot Layer
22:18:31    add modules: java.logging
22:18:31  
22:18:31  STDOUT:
22:18:31  Root level is: INFO
22:18:31  Handler(1) created
22:18:31  Handler(1) closed
22:18:31  Root level is: FINE
22:18:31  Handler(2) created
22:18:31  Handler(2) closed
22:18:31  Root level is: INFO
22:18:31  STDERR:
22:18:31  INFO [Wed Mar 29 13:18:19 AEDT 2023]: BadRootLoggerHandlers main: hi (CUSTOM)
22:18:31  INFO [Wed Mar 29 13:18:19 AEDT 2023]: BadRootLoggerHandlers main: there!
22:18:31  java.lang.RuntimeException: Expected root level FINER, got: INFO
22:18:31    at BadRootLoggerHandlers.main(BadRootLoggerHandlers.java:225)