JDK-8197901 : Crash during GC when logging level is debug
  • Type: Bug
  • Component: hotspot
  • Sub-Component: runtime
  • Affected Version: 9,10,11
  • Priority: P3
  • Status: Resolved
  • Resolution: Fixed
  • Submitted: 2018-02-14
  • Updated: 2024-03-05
  • Resolved: 2018-02-23
The Version table provides details related to the release that this issue/RFE will be addressed.

Unresolved : Release in which this issue/RFE will be addressed.
Resolved: Release in which this issue/RFE has been resolved.
Fixed : Release in which this issue/RFE has been fixed. The release containing this fix may be available for download as an Early Access Release or a General Availability Release.

To download the current JDK release, click here.
JDK 11 JDK 8
11 b03Fixed 8u421Fixed
Related Reports
Duplicate :  
JDK-8197442 - [Graal] runtime/Metaspace/DefineClass.java crashes with "biases should not be seen by VM thread here"
Relates :  
JDK-8209150 - [TESTBUG] Add logging to verify JDK-8197901 to a different test
Relates :  
JDK-8059924 - com/sun/management/DiagnosticCommandMBean/DcmdMBeanPermissionsTest.java: assert(Universe::verify_in_progress() || !SafepointSynchronize::is_at_safepoint()) failed: invariant
Description
Log system tries to print classname during GC. The class is calling Klass:external_name which tries to print hashcode for java_mirror object. It fails to resolve this object by link.
Comments
URL: http://hg.openjdk.java.net/jdk/jdk/rev/4aa67aba6c85 User: jwilhelm Date: 2018-02-28 18:06:35 +0000
28-02-2018
URL: http://hg.openjdk.java.net/jdk/hs/rev/4aa67aba6c85 User: mseledtsov Date: 2018-02-23 22:14:03 +0000
23-02-2018
The suggested fix: http://cr.openjdk.java.net/~lmesnik/8197901/webrev.00/
20-02-2018
Yeah, that would be nice to remove that unless there's some other reason to always hash mirrors. I can't think of any.
16-02-2018
Do you propose to use address instead of hash always for anonymous classes? I think it also allow us to remove eager hashcode computation introduced by https://bugs.openjdk.java.net/browse/JDK-8059924.
16-02-2018
[14.973s][info][class,unload] unloading class java.lang.invoke.LambdaForm$DMH/4296774704 0x00000001001b9430 [14.973s][info][class,unload] unloading class java.lang.invoke.LambdaForm$DMH/4295457840 0x0000000100077c30 [14.973s][info][class,unload] unloading class java.lang.invoke.LambdaForm$DMH/4295415856 0x000000010006d830 [14.973s][info][class,unload] unloading class java.lang.invoke.LambdaForm$MH/4295410736 0x000000010006c430 [14.973s][info][class,unload] unloading class java.lang.invoke.LambdaForm$MH/4295409712 0x000000010006c030 [14.973s][info][class,unload] unloading class java.lang.invoke.LambdaForm$MH/4295408688 0x000000010006bc30 Using ik (address of InstanceKlass works). Could make the name a bit longer, maybe truncate to lower 32 bits?
16-02-2018
Leonid, you're right, just using the address of ik would be better and probably more useful. There's no reason to hash the mirror in this case.
16-02-2018
Following fix might works but it make external_name to print different results depending on GC state. So might be the best idea would be to don't try to print this hash code? patch: diff -r 6b510cb0f14f src/hotspot/share/oops/klass.cpp --- a/src/hotspot/share/oops/klass.cpp Wed Feb 07 21:53:38 2018 +0000 +++ b/src/hotspot/share/oops/klass.cpp Tue Feb 13 19:32:45 2018 -0800 @@ -578,8 +578,9 @@ const InstanceKlass* ik = static_cast<const InstanceKlass*>(this); if (ik->is_anonymous()) { intptr_t hash = 0; - if (ik->java_mirror() != NULL) { - // java_mirror might not be created yet, return 0 as hash. + // java_mirror might not be created yet, return 0 as hash. + // There java_mirror might be incorrect during GC. See JDK-8197901. + if (!Universe::heap()->is_gc_active() && ik->java_mirror() != NULL) { hash = ik->java_mirror()->identity_hash(); } char hash_buf[40];
14-02-2018
VM crashes while trying to print name of anonymous class during GC. It happened with any GC with Xint. The stack trace is here: # # A fatal error has been detected by the Java Runtime Environment: # # Internal Error (/scratch/opt/mach5/mesos/work_dir/slaves/9190d864-6621-4810-ba08-d8d8c75ba674-S513/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/7f222a8d-b031-4bc7-87ea-41f231f28b09/runs/fd41efa9-5ef4-4cb2-88ce-256923678b32/workspace/open/src/hotspot/share/runtime/handles.cpp:37), pid=23358, tid=23374 # assert(oopDesc::is_oop(obj)) failed: not an oop: 0x00000000e0007940 # # JRE version: Java(TM) SE Runtime Environment (10.0+43) (fastdebug build 10+43) # Java VM: Java HotSpot(TM) 64-Bit Server VM (fastdebug 10+43, mixed mode, tiered, compressed oops, g1 gc, linux-amd64) # Core dump will be written. Default location: Core dumps may be processed with "/usr/libexec/abrt-hook-ccpp %s %c %p %u %g %t e" (or dumping to /scratch/opt/mach5/mesos/work_dir/slaves/9190d864-6621-4810-ba08-d8d8c75ba674-S797/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/bfaaa568-9e13-423f-97d5-7340adb861f1/runs/db403b6f-e42b-4da5-b277-53084baa9d43/testoutput/jtreg/JTwork/scratch/1/core.23358) # # If you would like to submit a bug report, please visit: # http://bugreport.java.com/bugreport/crash.jsp # --------------- S U M M A R Y ------------ Command Line: -Dtest.class.path.prefix=/scratch/opt/mach5/mesos/work_dir/slaves/9190d864-6621-4810-ba08-d8d8c75ba674-S797/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/bfaaa568-9e13-423f-97d5-7340adb861f1/runs/db403b6f-e42b-4da5-b277-53084baa9d43/testoutput/jtreg/JTwork/classes/0/java/lang/invoke/RicochetTest.d:/scratch/opt/mach5/mesos/work_dir/jib-master/install/jdk/10/43/src.full/open/test/jdk/java/lang/invoke -Dtest.src=/scratch/opt/mach5/mesos/work_dir/jib-master/install/jdk/10/43/src.full/open/test/jdk/java/lang/invoke -Dtest.src.path=/scratch/opt/mach5/mesos/work_dir/jib-master/install/jdk/10/43/src.full/open/test/jdk/java/lang/invoke -Dtest.classes=/scratch/opt/mach5/mesos/work_dir/slaves/9190d864-6621-4810-ba08-d8d8c75ba674-S797/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/bfaaa568-9e13-423f-97d5-7340adb861f1/runs/db403b6f-e42b-4da5-b277-53084baa9d43/testoutput/jtreg/JTwork/classes/0/java/lang/invoke/RicochetTest.d -Dtest.class.path=/scratch/opt/mach5/mesos/work_dir/slaves/9190d864-6621-4810-ba08-d8d8c75ba674-S797/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/bfaaa568-9e13-423f-97d5-7340adb861f1/runs/db403b6f-e42b-4da5-b277-53084baa9d43/testoutput/jtreg/JTwork/classes/0/java/lang/invoke/RicochetTest.d -Dtest.vm.opts=-ea -esa -Xmx512m -Dtest.tool.vm.opts=-J-ea -J-esa -J-Xmx512m -Dtest.compiler.opts= -Dtest.java.opts=-Xlog:all=trace:file=all.log -Dtest.jdk=/scratch/opt/mach5/mesos/work_dir/jib-master/install/jdk/10/43/linux-x64-debug.jdk/jdk-10/fastdebug -Dcompile.jdk=/scratch/opt/mach5/mesos/work_dir/jib-master/install/jdk/10/43/linux-x64-debug.jdk/jdk-10/fastdebug -Dtest.timeout.factor=10.0 -Dtest.nativepath=/scratch/opt/mach5/mesos/work_dir/jib-master/install/jdk/10/43/linux-x64-debug.test/jdk/jtreg/native -ea -esa -Xmx512m -Xlog:all=trace:file=all.log -Djava.library.path=/scratch/opt/mach5/mesos/work_dir/jib-master/install/jdk/10/43/linux-x64-debug.test/jdk/jtreg/native -XX:+IgnoreUnrecognizedVMOptions -XX:-VerifyDependencies -DRicochetTest.MAX_ARITY=10 com.sun.javatest.regtest.agent.MainWrapper /scratch/opt/mach5/mesos/work_dir/slaves/9190d864-6621-4810-ba08-d8d8c75ba674-S797/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/bfaaa568-9e13-423f-97d5-7340adb861f1/runs/db403b6f-e42b-4da5-b277-53084baa9d43/testoutput/jtreg/JTwork/java/lang/invoke/RicochetTest.d/junit.0.jta java/lang/invoke/RicochetTest.java test.java.lang.invoke.RicochetTest Host: sca00idl.us.oracle.com, Intel(R) Xeon(R) CPU E5-2690 0 @ 2.90GHz, 8 cores, 59G, Oracle Linux Server release 7.1 Time: Tue Feb 13 15:53:29 2018 PST elapsed time: 6 seconds (0d 0h 0m 6s) --------------- T H R E A D --------------- Current thread (0x00007f54dc049000): GCTaskThread "GC Thread#5" [stack: 0x00007f54e0e50000,0x00007f54e0f50000] [id=23374] Stack: [0x00007f54e0e50000,0x00007f54e0f50000], sp=0x00007f54e0f4d310, free space=1012k Native frames: (J=compiled Java code, A=aot compiled Java code, j=interpreted, Vv=VM code, C=native code) V [libjvm.so+0x1836f72] VMError::report_and_die(int, char const*, char const*, __va_list_tag*, Thread*, unsigned char*, void*, void*, char const*, int, unsigned long)+0x162 V [libjvm.so+0x1837d3f] VMError::report_and_die(Thread*, char const*, int, char const*, char const*, __va_list_tag*)+0x2f V [libjvm.so+0xb3de4d] report_vm_error(char const*, int, char const*, char const*, ...)+0xdd V [libjvm.so+0xe39d82] HandleArea::allocate_handle(oop)+0x132 V [libjvm.so+0x148d767] oopDesc::slow_identity_hash()+0xf7 V [libjvm.so+0x11ec890] Klass::external_name() const+0x140 V [libjvm.so+0x13c27fc] Method::name_and_sig_as_C_string(Klass*, Symbol*, Symbol*)+0x1c V [libjvm.so+0x14a3068] OopMapCache::lookup(methodHandle const&, int, InterpreterOopMap*)+0x138 V [libjvm.so+0x13c2e6a] Method::mask_for(int, InterpreterOopMap*)+0x9a V [libjvm.so+0xc9115b] frame::oops_interpreted_do(OopClosure*, RegisterMap const*, bool)+0x48b V [libjvm.so+0x1777e6a] JavaThread::oops_do(OopClosure*, CodeBlobClosure*)+0x21a V [libjvm.so+0x1780dd9] Threads::possibly_parallel_threads_do(bool, ThreadClosure*)+0x109 V [libjvm.so+0x1782138] Threads::possibly_parallel_oops_do(bool, OopClosure*, CodeBlobClosure*)+0x28 V [libjvm.so+0xda2dff] G1RootProcessor::process_all_roots(OopClosure*, CLDClosure*, CodeBlobClosure*)+0x8f V [libjvm.so+0xd0a4ba] G1FullGCAdjustTask::work(unsigned int)+0x13a V [libjvm.so+0x18b1ff0] GangWorker::loop()+0xe0 V [libjvm.so+0x14c056a] thread_native_entry(Thread*)+0xfa
14-02-2018