JDK-7194633 : G1: Assertion and guarantee failures in block offset table
  • Type: Bug
  • Component: hotspot
  • Sub-Component: gc
  • Affected Version: 7u6
  • Priority: P3
  • Status: Resolved
  • Resolution: Fixed
  • OS: generic
  • CPU: generic
  • Submitted: 2012-08-28
  • Updated: 2013-09-18
  • Resolved: 2012-12-06
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 7 JDK 8 Other
7u40Fixed 8Fixed hs24Fixed
Description
While testing the fix for 7190666, I obtained several different assertion and guarantee failures. All seem to be related to G1's block offset table.

The test case is GCBasher:


$JHOME/bin/java -Xmx128M -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UnlockExperimentalVMOptions -XX:+UseG1GC -d64 -server -jar GCBasher.jar -time:300000

Failure #1:
===========
#  Internal Error (/tmp/jprt/P1/230610.jcuthber/s/src/share/vm/gc_implementation/g1/g1BlockOffsetTable.cpp:305), pid=11948, tid=23
#  guarantee(entry > N_words) failed: Should be in logarithmic region
#
# JRE version: Java(TM) SE Runtime Environment (7.0_06-b24)
# Java VM: Java HotSpot(TM) 64-Bit Server VM (24.0-b20-internal-201208242306.jcuthber.7190666-fastdebug mixed mode solaris-sparc compressed oops)
# Core dump written. Default location: /home/jcuthber/gcbasher/core or core.11948

Stack Trace:
Stack: [0xffffffff71c00000,0xffffffff71d00000],  sp=0xffffffff71cf9da0,  free space=999k
Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)
V  [libjvm.so+0x13a4ca4]  void VMError::report_and_die()+0x79c
V  [libjvm.so+0x77ed68]  void report_vm_error(const char*,int,const char*,const char*)+0x78
V  [libjvm.so+0x8645ec]  void G1BlockOffsetArray::check_all_cards(unsigned long,unsigned long)const+0x10c
V  [libjvm.so+0x865de4]  void G1BlockOffsetArray::alloc_block_work2(HeapWord**,unsigned long*,HeapWord*,HeapWord*)+0x354
V  [libjvm.so+0x8651f8]  HeapWord*G1BlockOffsetArray::forward_to_block_containing_addr_slow(HeapWord*,HeapWord*,const void*)+0x7e8
V  [libjvm.so+0x868034]  HeapWord*G1BlockOffsetArray::forward_to_block_containing_addr(HeapWord*,const void*)+0x1cc
V  [libjvm.so+0x11dc284]  void DirtyCardToOopClosure::do_MemRegion(MemRegion)+0xfc
V  [libjvm.so+0x8b403c]  bool ScanRSClosure::doHeapRegion(HeapRegion*)+0x51c
V  [libjvm.so+0x8721ac]  void G1CollectedHeap::collection_set_iterate_from(HeapRegion*,HeapRegionClosure*)+0x16c
V  [libjvm.so+0x8b1328]  void G1RemSet::scanRS(OopsInHeapRegionClosure*,int)+0xb8
V  [libjvm.so+0x8b1948]  void G1RemSet::oops_into_collection_set_do(OopsInHeapRegionClosure*,int)+0x348
V  [libjvm.so+0x879908]  void G1CollectedHeap::g1_process_strong_roots(bool,SharedHeap::ScanningOption,OopClosure*,OopsInHeapRegionClosure*,OopsInGenClosure*,int)+0x7c8
V  [libjvm.so+0x87ff40]  void G1ParTask::work(unsigned)+0x6c0
V  [libjvm.so+0x13f52b8]  void GangWorker::loop()+0x2a0
V  [libjvm.so+0x102dd80]  java_start+0x258

According to the stack trace, this failure occurred during a GC pause. It looks like we have just allocated a new block and some internal integrity check failed.

Failure #2:
===========
# A fatal error has been detected by the Java Runtime Environment:
#
#  Internal Error (/tmp/jprt/P1/230610.jcuthber/s/src/share/vm/gc_implementation/g1/g1BlockOffsetTable.cpp:541), pid=17648, tid=87
#  assert(_array->offset_array(j) > 0 && _array->offset_array(j) <= (u_char) (N_words+BlockOffsetArray::N_powers-1)) failed: offset array should have been set
#
# JRE version: Java(TM) SE Runtime Environment (7.0_06-b24)
# Java VM: Java HotSpot(TM) 64-Bit Server VM (24.0-b20-internal-201208242306.jcuthber.7190666-fastdebug mixed mode solaris-sparc compressed oops)
# Core dump written. Default location: /home/jcuthber/gcbasher/core or core.17648
#

Strack Trace:
Current thread (0x0000000102ed2000):  ConcurrentGCThread [stack: 0xffffffff69b00000,0xffffffff69c00000] [id=87]

Stack: [0xffffffff69b00000,0xffffffff69c00000],  sp=0xffffffff69bfd7f0,  free space=1013k
Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)
V  [libjvm.so+0x13a4ca4]  void VMError::report_and_die()+0x79c
V  [libjvm.so+0x77ed68]  void report_vm_error(const char*,int,const char*,const char*)+0x78
V  [libjvm.so+0x8660b8]  void G1BlockOffsetArray::alloc_block_work2(HeapWord**,unsigned long*,HeapWord*,HeapWord*)+0x628
V  [libjvm.so+0x8651f8]  HeapWord*G1BlockOffsetArray::forward_to_block_containing_addr_slow(HeapWord*,HeapWord*,const void*)+0x7e8
V  [libjvm.so+0x868034]  HeapWord*G1BlockOffsetArray::forward_to_block_containing_addr(HeapWord*,const void*)+0x1cc
V  [libjvm.so+0x9337c0]  HeapWord*HeapRegion::oops_on_card_seq_iterate_careful(MemRegion,FilterOutOfRegionClosure*,bool,signed char*)+0x1a8
V  [libjvm.so+0x8b22f4]  bool G1RemSet::concurrentRefineOneCard_impl(signed char*,int,bool)+0x33c
V  [libjvm.so+0x8b27f8]  bool G1RemSet::concurrentRefineOneCard(signed char*,int,bool)+0x458
V  [libjvm.so+0x8878d8]  bool RefineCardTableEntryClosure::do_card_ptr(signed char*,int)+0x38
V  [libjvm.so+0x7eff3c]  bool DirtyCardQueue::apply_closure_to_buffer(CardTableEntryClosure*,void**,unsigned long,unsigned long,bool,int)+0xac
V  [libjvm.so+0x7f086c]  bool DirtyCardQueueSet::apply_closure_to_completed_buffer(int,int,bool)+0x94
V  [libjvm.so+0x6ea30c]  void ConcurrentG1RefineThread::run()+0x29c
V  [libjvm.so+0x102dd80]  java_start+0x258

This failure failed during concurrent refinement.

Failure #3:
===========
# A fatal error has been detected by the Java Runtime Environment:
#
#  Internal Error (/tmp/jprt/P1/230610.jcuthber/s/src/share/vm/gc_implementation/g1/g1BlockOffsetTable.cpp:541), pid=18837, tid=32
#  assert(_array->offset_array(j) > 0 && _array->offset_array(j) <= (u_char) (N_words+BlockOffsetArray::N_powers-1)) failed: offset array should have been set
#
# JRE version: Java(TM) SE Runtime Environment (7.0_06-b24)
# Java VM: Java HotSpot(TM) 64-Bit Server VM (24.0-b20-internal-201208242306.jcuthber.7190666-fastdebug mixed mode solaris-sparc compressed oops)
# Core dump written. Default location: /home/jcuthber/gcbasher/core or core.18837

Stack Trace:
Current thread (0x0000000100161800):  GCTaskThread [stack: 0xffffffff70a00000,0xffffffff70b00000] [id=32]

Stack: [0xffffffff70a00000,0xffffffff70b00000],  sp=0xffffffff70af9e50,  free space=999k
Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)
V  [libjvm.so+0x13a4ca4]  void VMError::report_and_die()+0x79c
V  [libjvm.so+0x77ed68]  void report_vm_error(const char*,int,const char*,const char*)+0x78
V  [libjvm.so+0x8660b8]  void G1BlockOffsetArray::alloc_block_work2(HeapWord**,unsigned long*,HeapWord*,HeapWord*)+0x628
V  [libjvm.so+0x8651f8]  HeapWord*G1BlockOffsetArray::forward_to_block_containing_addr_slow(HeapWord*,HeapWord*,const void*)+0x7e8
V  [libjvm.so+0x868034]  HeapWord*G1BlockOffsetArray::forward_to_block_containing_addr(HeapWord*,const void*)+0x1cc
V  [libjvm.so+0x11dc284]  void DirtyCardToOopClosure::do_MemRegion(MemRegion)+0xfc
V  [libjvm.so+0x8b403c]  bool ScanRSClosure::doHeapRegion(HeapRegion*)+0x51c
V  [libjvm.so+0x872114]  void G1CollectedHeap::collection_set_iterate_from(HeapRegion*,HeapRegionClosure*)+0xd4
V  [libjvm.so+0x8b1328]  void G1RemSet::scanRS(OopsInHeapRegionClosure*,int)+0xb8
V  [libjvm.so+0x8b1948]  void G1RemSet::oops_into_collection_set_do(OopsInHeapRegionClosure*,int)+0x348
V  [libjvm.so+0x879908]  void G1CollectedHeap::g1_process_strong_roots(bool,SharedHeap::ScanningOption,OopClosure*,OopsInHeapRegionClosure*,OopsInGenClosure*,int)+0x7c8
V  [libjvm.so+0x87ff40]  void G1ParTask::work(unsigned)+0x6c0
V  [libjvm.so+0x13f52b8]  void GangWorker::loop()+0x2a0
V  [libjvm.so+0x102dd80]  java_start+0x258

Failure #3 looks like failure #2 except it happened during a GC pause rather than during concurrent refinement.

Failure #4:
===========
# A fatal error has been detected by the Java Runtime Environment:
#
#  Internal Error (/tmp/jprt/P1/230610.jcuthber/s/src/share/vm/memory/space.cpp:812), pid=14087, tid=15
#  assert(p == current_top || oop(p)->is_oop()) failed: p is not a block start
#
# JRE version: Java(TM) SE Runtime Environment (7.0_06-b24)
# Java VM: Java HotSpot(TM) 64-Bit Server VM (24.0-b20-internal-201208242306.jcuthber.7190666-fastdebug mixed mode solaris-sparc compressed oops)
# Core dump written. Default location: /home/jcuthber/gcbasher/core or core.14087

Stack trace:
Current thread (0x000000010013f800):  GCTaskThread [stack: 0xffffffff72c00000,0xffffffff72d00000] [id=15]

Stack: [0xffffffff72c00000,0xffffffff72d00000],  sp=0xffffffff72cfa0e0,  free space=1000k
Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)
V  [libjvm.so+0x13a4ca4]  void VMError::report_and_die()+0x79c
V  [libjvm.so+0x77ed68]  void report_vm_error(const char*,int,const char*,const char*)+0x78
V  [libjvm.so+0x11e9f88]  unsigned long ContiguousSpace::block_size(const HeapWord*)const+0x170
V  [libjvm.so+0x868014]  HeapWord*G1BlockOffsetArray::forward_to_block_containing_addr(HeapWord*,const void*)+0x1ac
V  [libjvm.so+0x11dc284]  void DirtyCardToOopClosure::do_MemRegion(MemRegion)+0xfc
V  [libjvm.so+0x8b403c]  bool ScanRSClosure::doHeapRegion(HeapRegion*)+0x51c
V  [libjvm.so+0x872114]  void G1CollectedHeap::collection_set_iterate_from(HeapRegion*,HeapRegionClosure*)+0xd4
V  [libjvm.so+0x8b1328]  void G1RemSet::scanRS(OopsInHeapRegionClosure*,int)+0xb8
V  [libjvm.so+0x8b1948]  void G1RemSet::oops_into_collection_set_do(OopsInHeapRegionClosure*,int)+0x348
V  [libjvm.so+0x879908]  void G1CollectedHeap::g1_process_strong_roots(bool,SharedHeap::ScanningOption,OopClosure*,OopsInHeapRegionClosure*,OopsInGenClosure*,int)+0x7c8
V  [libjvm.so+0x87ff40]  void G1ParTask::work(unsigned)+0x6c0
V  [libjvm.so+0x13f52b8]  void GangWorker::loop()+0x2a0
V  [libjvm.so+0x102dd80]  java_start+0x258

This failure occurred on a different machine.

Typically the test case runs no more than 10 or 11 iterations before hitting one of the errors. Failure #4 was seen after 92 iterations.

When ResizePLAB was disabled (and the default OldPLABSize used) the test ran 30 iterations without failure. Increasing the value of OldPLABSize to 8k, 16k, and 32k cause the failures to show up after only a few iterations again.

Comments
PUBLIC COMMENTS See Description.
28-08-2012