JDK-6914402 : G1: assert(!is_young_card(cached_ptr),"shouldn't get a card in young region")
  • Type: Bug
  • Component: hotspot
  • Sub-Component: gc
  • Affected Version: hs17
  • Priority: P4
  • Status: Resolved
  • Resolution: Fixed
  • OS: generic
  • CPU: generic
  • Submitted: 2010-01-06
  • Updated: 2010-04-06
  • Resolved: 2010-03-02
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 6 JDK 7 Other
6u21Fixed 7Fixed hs17Fixed
Related Reports
Relates :  
JDK-6817995 - G1: Error: guarantee(!r->is_young(),"It was evicted in the current minor cycle.")
Description
I got the assert (very very infrequently) on a Solaris/x64 as well as a Solaris/sparc Niagara box when running GCBasher as follows:-

-d64 -server -XX:+UnlockDiagnosticVMOptions -XX:+UnlockExperimentalVMOptions -XX:+UseG1GC -XX:+VerifyBeforeGC -XX:+VerifyAfterGC -XX:+VerifyDuringGC -Xmx64m -XX:+PrintGCTimeStamps -XX:+PrintGCDetails -XX:+ShowMessageBoxOnError -XX:+PrintCompilation -XX:CICompilerCount=1 -XX:+UseCompressedOops -Xbatch -jar GCBasher.jar -time:300000


170.266: [GC pause (young)170.450:  (initial-mark), 0.18410294 secs]
   [GC concurrent-mark-start]
[Parallel Time: 172.8 ms]
      [Update RS (Start) (ms):  170278.1  170273.1  170272.6  170272.8  170273.4  170272.6  170279.1  170272.7  170272.6  170272.5  170272.8  170273.1  170272.6  170272.6  170272.7  170272.5  170272.9  170272.7  170272.7  170272.6  170272.8  170272.5  170272.6]
      [Update RS (ms):  27.8  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0
       Avg:   1.2, Min:   0.0, Max:  27.8]
         [Processed Buffers : 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
          Sum: 1, Avg: 0, Min: 0, Max: 1]
      [Ext Root Scanning (ms):  6.0  1.3  1.0  0.9  1.1  0.9  7.4  0.8  0.7  0.6  0.8  1.0  0.6  0.5  0.5  0.4  0.6  0.4  0.3  0.3  0.3  0.1  0.1
       Avg:   1.2, Min:   0.1, Max:   7.4]
      [Mark Stack Scanning (ms):  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0
       Avg:   0.0, Min:   0.0, Max:   0.0]
      [Scan-Only Scanning (ms):  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0
       Avg:   0.0, Min:   0.0, Max:   0.0]
         [Scan-Only Regions : 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
          Sum: 0, Avg: 0, Min: 0, Max: 0]
      [Scan RS (ms):  19.4  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0
       Avg:   0.8, Min:   0.0, Max:  19.4]
      [Object Copy (ms):  118.2  137.2  137.2  137.2  133.0  137.1  132.5  136.9  137.0  137.3  137.0  136.5  137.0  137.5  136.8  137.1  136.7  137.1  136.9  137.4  136.7  137.1  137.1
       Avg: 135.9, Min: 118.2, Max: 137.5]
      [Termination (ms):  0.0  33.0  33.2  33.3  37.3  33.3  31.3  33.6  33.4  33.2  33.2  33.6  33.5  32.9  33.6  33.4  33.4  33.3  33.5  32.9  33.6  33.4  33.3
       Avg:  32.0, Min:   0.0, Max:  37.3]
      [Other:   1.7 ms]
   [Clear CT:   1.3 ms]
   [Cur Clear CC:   0.0 ms]
   [Cum Clear CC:   0.1 ms]
   [Min Clear CC:   0.0 ms]
   [Max Clear CC:   0.0 ms]
   [Avg Clear CC:   0.0 ms]
   [Other:  10.0 ms]
   [ 64M->45M(256M)]
 [Times: user=3.91 sys=0.03, real=0.20 secs]
170.760: [GC concurrent-mark-end, 0.1081481 sec]
170.760: [GC remark, 0.0090474 secs]
 [Times: user=0.07 sys=0.01, real=0.01 secs]
170.770: [GC concurrent-count-start]
170.822: [GC concurrent-count-end, 0.0512969]
171.080: [GC cleanup 63M->29M(256M), 0.0069773 secs]
 [Times: user=0.02 sys=0.00, real=0.01 secs]
171.087: [GC concurrent-cleanup-start]
171.093: [GC concurrent-cleanup-end, 0.0053815]
# To suppress the following error report, specify this argument
# after -XX: or in .hotspotrc:  SuppressErrorAt=/concurrentG1Refine.cpp:273
==============================================================================
Unexpected Error
------------------------------------------------------------------------------
Internal Error at concurrentG1Refine.cpp:273, pid=12698, tid=48
Error: assert(!is_young_card(cached_ptr),"shouldn't get a card in young region")

Do you want to debug the problem?

To debug, run 'dbx - 12698'; then switch to thread 48
Enter 'yes' to launch dbx automatically (PATH must include dbx)
Otherwise, press RETURN to abort...
==============================================================================


  [7] ConcurrentG1Refine::cache_insert(this = ???, card_ptr = ???, defer = ???) (optimized), at 0xffffffff7c51a290 (line ~273) in "concurrentG1Refine.cpp"
  [8] HRInto_G1RemSet::concurrentRefineOneCard(this = ???, card_ptr = ???, worker_i = ???) (optimized), at 0xffffffff7c6deb2c (line ~809) in "g1RemSet.cpp"
  [9] RefineCardTableEntryClosure::do_card_ptr(this = ???, card_ptr = ???, worker_i = ???) (optimized), at 0xffffffff7c6b9360 (line ~59) in "g1CollectedHeap.cpp"
  [10] DirtyCardQueue::apply_closure_to_buffer(cl = ???, buf = ???, index = ???, sz = ???, consume = ???, worker_i = ???) (optimized), at 0xffffffff7c624964 (line ~54) in "dirtyCardQueue.cpp"
  [11] DirtyCardQueueSet::apply_closure_to_completed_buffer_helper(this = ???, worker_i = ???, nd = ???) (optimized), at 0xffffffff7c625254 (line ~182) in "dirtyCardQueue.cpp"
  [12] DirtyCardQueueSet::apply_closure_to_completed_buffer(this = ???, worker_i = ???, stop_at = ???, during_pause = ???) (optimized), at 0xffffffff7c625324 (line ~207) in "dirtyCardQueue.cpp"
  [13] ConcurrentG1RefineThread::run(this = ???) (optimized), at 0xffffffff7c51b634 (line ~115) in "concurrentG1RefineThread.cpp"
  [14] java_start(thread_addr = ???) (optimized), at 0xffffffff7cee19c0 (line ~1019) in "os_solaris.cpp"
Comments
EVALUATION ChangeSet=http://hg.openjdk.java.net/jdk7/hotspot-gc/hotspot/rev/deada8912c54,ChangeRequest=6914402
04-02-2010
EVALUATION A region containing cards in the hot card cache or card count cache may be freed after a clean up pause (i.e. none of the objects it contains has been marked as live during concurrent marking). If the region is then tagged as young (i.e. it is used as the current allocation region) then when a card in the region is evicted from the current active card caches then this assert will trip. Filters were added to eliminate cards in young regions that were evicted from the hot card cache. A similar situation can arise with the cards recorded in the card count cache. Thus this assert is invalid and an additional filter on cards evicted from the card count cache is needed.
03-02-2010
SUGGESTED FIX A possible fix could be to change the code in cache_insert from: jbyte* ConcurrentG1Refine::cache_insert(jbyte* card_ptr, bool* defer) { int count; jbyte* cached_ptr = add_card_count(card_ptr, &count, defer); assert(cached_ptr != NULL, "bad cached card ptr"); assert(!is_young_card(cached_ptr), "shouldn't get a card in young region"); to: jbyte* ConcurrentG1Refine::cache_insert(jbyte* card_ptr, bool* defer) { int count; jbyte* cached_ptr = add_card_count(card_ptr, &count, defer); assert(cached_ptr != NULL, "bad cached card ptr"); if (is_young_card(cached_ptr)) { // The region containing cached_ptr has been freed during a clean up // pause. assert(cached_ptr != card_ptr, "shouldn't be"); // We've just inserted a new card pointer into the card count cache // - its count would be zero so we don't want to defer the cleaning // of card_ptr. assert(defer == false, "deferring non-hot card"); return NULL; } Then the code in HRInto_G1RemSet::concurrentRefineOneCard will skip the processing of the return value of cache_insert and immediately process the card passed in.
12-01-2010