JDK-8205426 : Humongous continues remembered set does not match humongous start region one after Remark
  • Type: Bug
  • Component: hotspot
  • Sub-Component: gc
  • Affected Version: 11
  • Priority: P2
  • Status: Closed
  • Resolution: Fixed
  • Submitted: 2018-06-20
  • Updated: 2021-04-14
  • Resolved: 2018-07-09
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 12
11 b22Fixed 12Fixed
Related Reports
Duplicate :  
JDK-8205429 - applications/kitchensink/Kitchensink.java crashes in G1HeapVerifier::verify
Relates :  
JDK-8204169 - Humongous continues region remembered set states do not match the one from the corresponding humongous start region
Relates :  
JDK-8265119 - G1: update_remset_before_rebuild mixes liveness in words with liveness in bytes
Description
JDK-8204169 introduced some checking and changes to make sure that the humongous continues region's remembered set matches the one from their corresponding humongous starts region.

The patch does not seem to be complete (or this is a new issue) as Kitchensink rarely crashes because of that.

GC log log snippet:

[...]
[2216.224s][1529512263954ms][debug][gc,heap        ] GC(524) Heap after GC invocations=525 (full 9): garbage-first heap   total 7412736K, used 719586K [0x000000062dc00000, 0x0000000800000000)
[2216.224s][1529512263954ms][debug][gc,heap        ] GC(524)   region size 1024K, 8 young (8192K), 8 survivors (8192K)
[2216.224s][1529512263954ms][debug][gc,heap        ] GC(524)  Metaspace       used 44822K, capacity 46934K, committed 47280K, reserved 1091584K
[2216.224s][1529512263954ms][debug][gc,heap        ] GC(524)   class space    used 4151K, capacity 4799K, committed 4864K, reserved 1048576K
[2216.224s][1529512263954ms][info ][gc             ] GC(524) Pause Young (G1 Evacuation Pause) 5038M->702M(7239M) 885.290ms
[2216.224s][1529512263954ms][info ][gc,cpu         ] GC(524) User=1.00s Sys=0.01s Real=0.89s
[2217.132s][1529512264861ms][info ][gc,heap,exit   ] Heap
[2217.132s][1529512264861ms][info ][gc,heap,exit   ]  garbage-first heap   total 7412736K, used 911074K [0x000000062dc00000, 0x0000000800000000)
[2217.132s][1529512264861ms][info ][gc,heap,exit   ]   region size 1024K, 196 young (200704K), 8 survivors (8192K)
[2217.132s][1529512264861ms][info ][gc,heap,exit   ]  Metaspace       used 44885K, capacity 47035K, committed 47280K, reserved 1091584K
[2217.132s][1529512264861ms][info ][gc,heap,exit   ]   class space    used 4162K, capacity 4833K, committed 4864K, reserved 1048576K
[2217.140s][1529512264870ms][info ][gc,verify,start] Verifying 
[2218.621s][1529512266350ms][error][gc,verify      ] Remset states differ: Region 359 (HC) remset Untracked with starts region 358 (HS) remset Complete
[2218.621s][1529512266351ms][error][gc,verify      ] Remset states differ: Region 360 (HC) remset Untracked with starts region 358 (HS) remset Complete
[2218.621s][1529512266351ms][error][gc,verify      ] Remset states differ: Region 361 (HC) remset Untracked with starts region 358 (HS) remset Complete
[2218.621s][1529512266351ms][error][gc,verify      ] Remset states differ: Region 362 (HC) remset Untracked with starts region 358 (HS) remset
[...]

and the corresponding heap map:

| 358|0x0000000644200000, 0x0000000644300000, 0x0000000644300000|100%|HS|  |TAMS 0x0000000644300000, 0x0000000644200000| Complete 
| 359|0x0000000644300000, 0x0000000644400000, 0x0000000644400000|100%|HC|  |TAMS 0x0000000644400000, 0x0000000644300000| Untracked 
| 360|0x0000000644400000, 0x0000000644500000, 0x0000000644500000|100%|HC|  |TAMS 0x0000000644500000, 0x0000000644400000| Untracked 
| 361|0x0000000644500000, 0x0000000644600000, 0x0000000644600000|100%|HC|  |TAMS 0x0000000644600000, 0x0000000644500000| Untracked 
| 362|0x0000000644600000, 0x0000000644700000, 0x0000000644700000|100%|HC|  |TAMS 0x0000000644700000, 0x0000000644600000| Untracked 
| 363|0x0000000644700000, 0x0000000644800000, 0x0000000644800000|100%|HC|  |TAMS 0x0000000644800000, 0x0000000644700000| Untracked 
| 364|0x0000000644800000, 0x0000000644900000, 0x0000000644900000|100%|HC|  |TAMS 0x0000000644900000, 0x0000000644800000| Untracked 
| 365|0x0000000644900000, 0x0000000644a00000, 0x0000000644a00000|100%|HC|  |TAMS 0x0000000644a00000, 0x0000000644900000| Untracked 

I.e. HC are untracked while HS is complete.

This is heap verification after GC:
[stress.process.out] [2219.067s][error][gc,verify] Heap after failed verification (kind 0):
Comments
The problem is that liveness calculation (and setting the remset state) in the HC region depends on liveness; marking attributes live bytes on the whole HS region, and only later distributes it across the entire humongous objects (i.e. to the HC region). So a thread might get to work on a HC region which liveness has not been "distributed" properly from the HS region, so giving a different result than for the HS region.
25-06-2018
Inconsistency may occur when updating the remembered set state in parallel during the Remark phase when parts of the humongous object are handled out of order. Also occurs in gc/g1/TestEagerReclaimHumongousRegionsClearMarkBits and gc/TestHumongousReferenceObject tests when run with additional verification code and sufficiently often.
25-06-2018
The young GC does not look different to others: [gc,heap ] GC(524) Heap before GC invocations=524 (full 9): garbage-first heap total 7412736K, used 5158254K [0x000000062dc00000, 0x0000000800000000) [gc,heap ] GC(524) region size 1024K, 4343 young (4447232K), 7 survivors (7168K) [gc,heap ] GC(524) Metaspace used 44822K, capacity 46934K, committed 47280K, reserved 1091584K [gc,heap ] GC(524) class space used 4151K, capacity 4799K, committed 4864K, reserved 1048576K [gc,start ] GC(524) Pause Young (G1 Evacuation Pause) [gc,task ] GC(524) Using 4 workers of 4 for evacuation [gc,mmu ] GC(524) MMU target violated: 201.0ms (200.0ms/201.0ms) [gc,phases ] GC(524) Pre Evacuate Collection Set: 0.5ms [gc,phases ] GC(524) Evacuate Collection Set: 35.5ms [gc,phases ] GC(524) Post Evacuate Collection Set: 845.6ms [gc,phases ] GC(524) Other: 14.4ms [gc,heap ] GC(524) Eden regions: 4336->0(4335) [gc,heap ] GC(524) Survivor regions: 7->8(543) [gc,heap ] GC(524) Old regions: 632->632 [gc,heap ] GC(524) Humongous regions: 67->67 [gc,metaspace ] GC(524) Metaspace: 44822K->44822K(1091584K) [gc,heap ] GC(524) Heap after GC invocations=525 (full 9): garbage-first heap total 7412736K, used 719586K [0x000000062dc00000, 0x0000000800000000) [gc,heap ] GC(524) region size 1024K, 8 young (8192K), 8 survivors (8192K) [gc,heap ] GC(524) Metaspace used 44822K, capacity 46934K, committed 47280K, reserved 1091584K [gc,heap ] GC(524) class space used 4151K, capacity 4799K, committed 4864K, reserved 1048576K [gc ] GC(524) Pause Young (G1 Evacuation Pause) 5038M->702M(7239M) 885.290ms [gc,cpu ] GC(524) User=1.00s Sys=0.01s Real=0.89s No eager reclaim going on
20-06-2018
Of the two (large) humongous objects that are affected, the humongous regions are only partially "Untracked". After the first "Complete" HS region, there is a set of "Untracked" HC regions, one "Complete", then another "Untracked" HC and the remaining are "Complete" again. | 358|HS|Complete | 359|HC|Untracked | 360|HC|Untracked | 361|HC|Untracked | 362|HC|Untracked | 363|HC|Untracked | 364|HC|Untracked | 365|HC|Untracked | 366|HC|Untracked | 367|HC|Untracked | 368|HC|Untracked | 369|HC|Untracked | 370|HC|Untracked | 371|HC|Untracked | 372|HC|Untracked | 373|HC|Untracked | 374|HC|Untracked | 375|HC|Untracked | 376|HC|Untracked | 377|HC|Untracked | 378|HC|Untracked | 379|HC|Untracked | 380|HC|Untracked | 381|HC|Complete | 382|HC|Untracked | 383|HC|Complete | 384|HC|Complete | 385|HC|Complete | 386|HC|Complete | 387|HC|Complete | 388|HC|Complete and 405|HS|Complete 406|HC|Untracked 407|HC|Untracked 408|HC|Untracked 409|HC|Untracked 410|HC|Untracked 411|HC|Untracked 412|HC|Untracked 413|HC|Untracked 414|HC|Untracked 415|HC|Untracked 416|HC|Untracked 417|HC|Untracked 418|HC|Untracked 419|HC|Complete 420|HC|Untracked 421|HC|Complete 422|HC|Complete 423|HC|Complete 424|HC|Complete 425|HC|Complete 426|HC|Complete 427|HC|Complete 428|HC|Complete 429|HC|Complete 430|HC|Complete 431|HC|Complete 432|HC|Complete 433|HC|Complete 434|HC|Complete 435|HC|Complete From an impact POV there does not seem to be an issue since HC region remembered sets are always empty. It is still strange.
20-06-2018