JDK-8181807 : Internal error "StringStream is re-allocated with a different ResourceMark"
  • Type: Bug
  • Component: hotspot
  • Sub-Component: runtime
  • Affected Version: 10
  • Priority: P4
  • Status: Closed
  • Resolution: Duplicate
  • Submitted: 2017-06-08
  • Updated: 2019-05-22
  • Resolved: 2017-09-05
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 10
10Resolved
Related Reports
Duplicate :  
JDK-8181917 - Refactor UL LogStreams to avoid using resource area
Relates :  
JDK-8181917 - Refactor UL LogStreams to avoid using resource area
Description
# 
# A fatal error has been detected by the Java Runtime Environment: 
# 
# Internal Error (/home/katya/work/JavaSE/Hotspot/ws/hs10/hotspot/src/share/vm/utilities/ostream.cpp:340), pid=28556, tid=28603 
# assert(rm == __null || Thread::current()->current_resource_mark() == rm) failed: StringStream is re-allocated with a different ResourceMark. Current: 0x00007f49babad200 original: 0x00007f49babad470 
# 
# JRE version: Java(TM) SE Runtime Environment (10.0) (fastdebug build 10-internal+0-2017-06-07-102447.katya.hs10) 
# Java VM: Java HotSpot(TM) 64-Bit Server VM (fastdebug 10-internal+0-2017-06-07-102447.katya.hs10, mixed mode, tiered, jvmci, jvmci compiler, compressed oops, g1 gc, linux-amd64) 
# Core dump will be written. Default location: Core dumps may be processed with "/usr/share/apport/apport %p %s %c" (or dumping to /home/katya/work/JavaSE/Hotspot/ws/hs10/JTwork/scratch/core.28556) 


Current thread (0x00007f4a8c2ac800):  VMThread "VM Thread" [stack: 0x00007f49baaaf000,0x00007f49babaf000] [id=28603]

Stack: [0x00007f49baaaf000,0x00007f49babaf000],  sp=0x00007f49babac590,  free space=1013k
Native frames: (J=compiled Java code, A=aot compiled Java code, j=interpreted, Vv=VM code, C=native code)
V  [libjvm.so+0x1771c62]  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+0x1772a2f]  VMError::report_and_die(Thread*, char const*, int, char const*, char const*, __va_list_tag*)+0x2f
V  [libjvm.so+0xb17f8d]  report_vm_error(char const*, int, char const*, char const*, ...)+0xdd
V  [libjvm.so+0x142b9c6]  stringStream::write(char const*, unsigned long)+0x216
V  [libjvm.so+0x11d482c]  LogStreamBase<stringStream>::write(char const*, unsigned long)+0x5c
V  [libjvm.so+0x142bfd6]  outputStream::do_vsnprintf_and_write_with_automatic_buffer(char const*, __va_list_tag*, bool)+0x106
V  [libjvm.so+0x142cc24]  outputStream::print_cr(char const*, ...)+0x1d4
V  [libjvm.so+0xe01795]  KlassInfoEntry::print_on(outputStream*) const+0x115
V  [libjvm.so+0xe050aa]  KlassInfoHisto::print_elements(outputStream*) const+0x16a
V  [libjvm.so+0xe071f4]  HeapInspection::heap_inspection(outputStream*)+0x2e4
V  [libjvm.so+0x1773aad]  VM_GC_HeapInspection::doit()+0x8d
V  [libjvm.so+0xa3a853]  CollectedHeap::full_gc_dump(GCTimer*, bool)+0x3d3
V  [libjvm.so+0xca1e02]  G1CollectedHeap::do_full_collection(bool, bool)+0x5a2
V  [libjvm.so+0xca2bd9]  G1CollectedHeap::satisfy_failed_allocation_helper(unsigned long, unsigned char, bool, bool, bool, bool*)+0x129
V  [libjvm.so+0xca2d1d]  G1CollectedHeap::satisfy_failed_allocation(unsigned long, unsigned char, bool*)+0x11d
V  [libjvm.so+0x17b4687]  VM_G1CollectForAllocation::doit()+0xb7
V  [libjvm.so+0x17b2519]  VM_Operation::evaluate()+0xa9
V  [libjvm.so+0x17aea8a]  VMThread::evaluate_operation(VM_Operation*)+0x15a
V  [libjvm.so+0x17af572]  VMThread::loop()+0x2a2
V  [libjvm.so+0x17afce0]  VMThread::run()+0xc0
V  [libjvm.so+0x141ba22]  thread_native_entry(Thread*)+0x112

VM_Operation (0x00007f4963efd150): G1CollectForAllocation, mode: safepoint, requested by thread 0x00007f496818d800
Comments
Reclosing as a duplicate of JDK-8181917. Bugs should only be closed as "Fixed" when there is an associated changeset.
05-09-2017
Fixed with JDK-8181917
05-09-2017
See also https://bugs.openjdk.java.net/browse/JDK-8181917 and discussion in hotspot-dev: http://mail.openjdk.java.net/pipermail/hotspot-dev/2017-June/027090.html. Basically, the error can be worked around by removing ResourceMark but in the end it should be fixed in UL.
12-06-2017
[~iveresov] you are right. I was discussing about this and wanted to correct my previous comment. But you were faster. So that code is incorrect but probably we didn't have a chance to provoke the problem. And Graal provoked it.
09-06-2017
[~sangheki], but you can clearly see how the problem may occur just by looking at the code. You can print into a StringStream only under the ResourceMark it was created under.
09-06-2017
I think you should be able to reproduce the issue using fastdebug bundle built from latest hs10 workspace. This is what I did.
09-06-2017
I tried it only with ""-XX:+UnlockExperimentalVMOptions -XX:+EnableJVMCI -XX:+TieredCompilation -XX:+UseJVMCICompiler -Djvmci.compiler=graal" options and the test always failed with them. Most likely graal requires more memory and as result the issue is not seen without Graal options.
09-06-2017
I have a couple of questions. 1) Is it 100% reproducible from you? 2) I couldn't find same binary(2017-06-07-102447.katya.hs10), instead I tried with 2017-06-07-200033.katya.hs10. I could reproduce the problem 2 times out of 2 tries. But without JVMCICompiler option(-XX:-UseJVMCICompiler), I couldn't reproduce it (tried only 2 times).
09-06-2017
It's a GC issue: void HeapInspection::heap_inspection(outputStream* st) { ResourceMark rm; Eventually calls: void KlassInfoEntry::print_on(outputStream* st) const { ResourceMark rm; Which is disliked by a StringStream because when it needs to reallocate it's backing store it expects it to happen in the same resource arena.
08-06-2017
Note, the test doesn't crash in case LogLevelSwitcher threads are not executed (you can comment them out in gc/logging/TestUnifiedLoggingSwitchStress.java). The test also runs with "-Xmx256M -Xms256M" which might be close to min heap requirements for Graal.
08-06-2017
can it be a gc bug?
08-06-2017
Full hs_err file attached.
08-06-2017
Steps to reproduce: > jtreg -vt -k:\!ignore -javaoptions:"-XX:+UnlockExperimentalVMOptions -XX:+EnableJVMCI -XX:+TieredCompilation -XX:+UseJVMCICompiler -Djvmci.compiler=graal" -jdk:HS10_fastdebug -dir:hotspot/test gc/logging/TestUnifiedLoggingSwitchStress.java
08-06-2017
gc/logging/TestUnifiedLoggingSwitchStress.java ran with "-XX:+UnlockExperimentalVMOptions -XX:+EnableJVMCI -XX:+TieredCompilation -XX:+UseJVMCICompiler -Djvmci.compiler=graal" crashes with # # A fatal error has been detected by the Java Runtime Environment: # # Internal Error (/home/katya/work/JavaSE/Hotspot/ws/hs10/hotspot/src/share/vm/utilities/ostream.cpp:340), pid=28556, tid=28603 # assert(rm == __null || Thread::current()->current_resource_mark() == rm) failed: StringStream is re-allocated with a different ResourceMark. Current: 0x00007f49babad200 original: 0x00007f49babad470 # # JRE version: Java(TM) SE Runtime Environment (10.0) (fastdebug build 10-internal+0-2017-06-07-102447.katya.hs10) # Java VM: Java HotSpot(TM) 64-Bit Server VM (fastdebug 10-internal+0-2017-06-07-102447.katya.hs10, mixed mode, tiered, jvmci, jvmci compiler, compressed oops, g1 gc, linux-amd64) # Core dump will be written. Default location: Core dumps may be processed with "/usr/share/apport/apport %p %s %c" (or dumping to /home/katya/work/JavaSE/Hotspot/ws/hs10/JTwork/scratch/core.28556)
08-06-2017