Uploaded image for project: 'JDK'
  1. JDK
  2. JDK-8315465

GenShen: Old-gen needs special attention during GLOBAL GC

    XMLWordPrintable

Details

    • gc

    Description

      A GLOBAL concurrent GC is typically executed in response to user invocation of System.gc(). During a GLOBAL GC, we concurrently mark all of OLD and YOUNG, and perform a single mixed evacuation cycle that collects some YOUNG and some OLD. Priority is given to collecting regions that have the most amount of garbage, whether OLD or YOUNG. It is important to replenish the free pool quickly, especially since a GLOBAL mark cycle typically takes much longer to run than a YOUNG mark cycle, so we run the risk of running out of memory before GC has completed.

      This ticket is motivated by an assert failure which drew attention to the problem that we do not expand OLD as part of a GLOBAL GC. Normally, OLD gets expanded at the end of the prior GC iff there are pending mixed-evacuation OLD region candidates to be collected. For GLOBAL GC, we need something like one of the following:

      1. Expand OLD at end of final mark but before we choose collection set, or
      2. Choose the collection set without worrying about OLD or YOUNG generation sizes, and then adjust the OLD and YOUNG generation sizes after collection set has been chosen (as done for FULL GC)

      Here is an excerpt of the log and reported assertion failure:
      ```
      [552.640s][info][gc,free ] FreeSet map legend: M:mutator_free C:collector_free O:old_collector_free H:humongous ~:retired \
      old _:retired young
      [552.640s][info][gc,free ] mutator free range [1..3180], collector free range [3181..3916], old collector free range [35\
      27..3527] allocates from left to right
      [552.640s][info][gc,free ] 0: _mMM_MMMM___M______________________M____MMM____M_M_M_MMMMM_MMMM_
      [552.640s][info][gc,free ] 64: MMM_M__M__MM_MMMM_MMM__M______________________________HHHHH__~__
      [552.640s][info][gc,free ] 128: __~~~~~~~~~~~~~~__~_________M____~~~_M__________M_M_____________
      [552.640s][info][gc,free ] 192: M____M_M_M_______M________________M________M___M_______M________
      [552.640s][info][gc,free ] 256: _____MM______________M___M______~_____M_________________M_______
      [552.640s][info][gc,free ] 320: ______________M_________________________________________________
      [552.640s][info][gc,free ] 384: ________________________________________________________________
      [552.640s][info][gc,free ] 448: __M____________________M___M______________m___M_______M_______M_
      [552.640s][info][gc,free ] 512: MM_____________mMM_________________________M_____________M_____~
      [552.640s][info][gc,free ] 576: ______________M____________________M_________________M__________
      [552.640s][info][gc,free ] 640: ___________________________________M___________HHHHHHHHHHHm____M
      [552.640s][info][gc,free ] 704: ____________________________________HHHHHHHHHHH_________________
      [552.640s][info][gc,free ] 768: _M___M_______m_MM_____M_________________________________________
      [552.640s][info][gc,free ] 832: ________M_MM___M_____M_____M_____________________M______________
      [552.640s][info][gc,free ] 896: M_______________________________________________________________
      [552.640s][info][gc,free ] 960: ________M_MMM_MM_MM_MM___M__MM____M____M_M_MM___M_MMM__M_M__M_M_
      [552.640s][info][gc,free ] 1024: ____M_M____MM_MM_M___M__M_____M__MM_M_MMM_M__MM____MM___MMM_____
      [552.640s][info][gc,free ] 1088: _M__m__MM__MM_MM_M_M_M_______M_M_M____MMM_______MMM_______M_____
      [552.640s][info][gc,free ] 1152: ________________________________________________________________
      [552.640s][info][gc,free ] 1216: ______MMm___M___________MM______M____M_M___M___M_______M___M____
      [552.640s][info][gc,free ] 1280: _MM________M_M_M_________MM__MM___M_HHHHHHHHHHHHHHHHHHHHHHHHHHHH
      [552.640s][info][gc,free ] 1344: H_____MM___M____________M_____MMM__________M______M______M_M____
      [552.640s][info][gc,free ] 1408: ______________________________M__M___M__________M__M____________
      [552.640s][info][gc,free ] 1472: ______M_MM___M______M_____M___________M__________M___MM_M____M__
      [552.640s][info][gc,free ] 1536: _____M_MMM_____M_______________________________________MMM______
      [552.640s][info][gc,free ] 1600: __M_M_M______M____________M____MM____M_______M_M________M__MM___
      [552.640s][info][gc,free ] 1664: MM_MM_M__M___M________________M__M_M__M__________________M__MMMM
      [552.640s][info][gc,free ] 1728: _________MM__M_______M__M______MM___MM_____M____________________
      [552.640s][info][gc,free ] 1792: _____M__M_____M________M______M___MM_____M__MM_M___M_MM_________
      [552.640s][info][gc,free ] 1856: ____M_________M________M____M____________M___________M__M__M____
      [552.640s][info][gc,free ] 1920: ____M___M_______________M___M____________________________M_M___M
      [552.640s][info][gc,free ] 1984: ______M___M_M___MM__M_MM______________________M_________________
      [552.640s][info][gc,free ] 2048: ______________M__________________M___M__________________________
      [552.640s][info][gc,free ] 2112: M__M___M___M____________________________________________________
      [552.640s][info][gc,free ] 2176: M__________________________________M_M__________________________
      [552.640s][info][gc,free ] 2240: ________M_______________________________________________________
      [552.640s][info][gc,free ] 2304: ________M_M___MM____MM___M_______M_____M________________________
      [552.640s][info][gc,free ] 2368: _______M________M__M_M___M_________M_____________M______________
      [552.640s][info][gc,free ] 2432: _________________M__________________M___________________________
      [552.640s][info][gc,free ] 2496: ______________________________________M_________________________
      [552.640s][info][gc,free ] 2560: _________M_MMMMMM_M_MMMM_M____MMM__M__M_MM____M_M_M___M_MM____M_
      [552.640s][info][gc,free ] 2624: ____MMM___M_M____M_M___MMMMMM_M__MM__M____M_M_M__MM_M_M_M_M__MM_
      [552.640s][info][gc,free ] 2688: ___M_____MM_____________________________________________________
      [552.640s][info][gc,free ] 2752: _________________________________________M______________________
      [552.640s][info][gc,free ] 2816: _____________________________________________M__________________
      [552.640s][info][gc,free ] 2880: _______________________________M________________________________
      [552.640s][info][gc,free ] 2944: _____________________________M___M_____________M____________M___
      [552.640s][info][gc,free ] 3008: ________________________MM_________________________________M____
      [552.640s][info][gc,free ] 3072: _______________________M__________M____M__MMM___M_______________
      [552.640s][info][gc,free ] 3136: __________________________MMMMMMMMMMMMMMMMMMMCCCCCCCCC_C________
      [552.640s][info][gc,free ] 3200: _CC_C__CC______C__________C___C_C____CCCC__C___CCC__C___________
      [552.640s][info][gc,free ] 3264: _______________________________________C__C_CC_C_CCC__CCCC______
      [552.640s][info][gc,free ] 3328: ________________________________________________________________
      [552.640s][info][gc,free ] 3392: _______________________________c________________________________
      [552.640s][info][gc,free ] 3456: __CC____c__c____________________________c_______________________
      [552.640s][info][gc,free ] 3520: _______o____________c_____c_______________________________CCCCCC
      [552.640s][info][gc,free ] 3584: CC~CCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCC
      [552.640s][info][gc,free ] 3648: CCCCCCC_________________________________________________________
      [552.640s][info][gc,free ] 3712: ______CCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCC~~C~~~~~~~~~
      [552.640s][info][gc,free ] 3776: ~~~~~~~~~~~~~~~~~~~__C___~~~~~_~~~~~~~CCCCCCCCCCC_CCC______~~~~~
      [552.640s][info][gc,free ] 3840: ~~~~_~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~_______C___C________________
      [552.640s][info][gc,free ] 3904: ___CCCCCC_C~C____________~_______________________~_~__~______~__
      [552.640s][info][gc,free ] 3968: __
      [552.641s][info][gc,free ] Free: 1675M, Max: 4096K regular, 77824K humongous, Frag: 96% external, 1% internal; Used: 20866\
      K, Mutator Free: 424 Collector Reserve: 761M, Max: 4096K; Used: 23335K Old Collector Reserve: 102K, Max: 102K; Used: 3994K
      [552.641s][info][gc,ergo ] GC(99) Start GC cycle (GLOBAL)
      [552.641s][info][gc,start ] GC(99) Concurrent reset
      [552.641s][info][gc,task ] GC(99) Using 4 of 8 workers for concurrent reset
      [552.669s][info][gc ] GC(99) Concurrent reset 28.332ms
      [552.669s][info][safepoint,cleanup] updating inline caches, 0.0000001 secs
      [552.669s][info][safepoint,cleanup] safepoint cleanup tasks, 0.0000190 secs
      [552.669s][info][gc,start ] GC(99) Pause Init Mark (GLOBAL) (unload classes)
      [552.669s][info][gc,task ] GC(99) Using 8 of 8 workers for init marking
      [552.719s][info][gc ] GC(99) Terminating old gc cycle.
      [552.719s][info][gc ] GC(99) Abandon SATB buffers
      [552.719s][info][gc ] GC(99) Cancel marking: OLD
      [552.719s][info][gc ] GC(99) Old generation transition from Marking to Idle
      [552.719s][info][gc ] GC(99) Terminating old gc cycle.
      [552.719s][info][gc ] GC(99) Cancel marking: OLD
      [552.719s][info][gc,ref ] GC(99) Clearing All SoftReferences
      [552.719s][info][gc ] GC(99) Pause Init Mark (GLOBAL) (unload classes) 50.480ms
      [552.719s][info][safepoint,stats ] ShenandoahInitMark [ 128 0 ][ 24576 23060 \
      50510636 50558272 ] 0
      [552.719s][info][safepoint ] Safepoint "ShenandoahInitMark", Time since last: 125924117 ns, Reaching safepoint: 24576 ns, Cl\
      eanup: 23060 ns, At safepoint: 50510636 ns, Total: 50558272 ns
      [552.720s][info][gc,start ] GC(99) Concurrent marking roots
      [552.720s][info][gc,task ] GC(99) Using 4 of 8 workers for concurrent marking roots
      [552.726s][info][gc ] GC(99) Concurrent marking roots 6.552ms
      [552.726s][info][gc,start ] GC(99) Concurrent marking (GLOBAL) (unload classes)
      [552.726s][info][gc,task ] GC(99) Using 4 of 8 workers for concurrent marking
      [552.958s][info][handshake ] Handshake "Shenandoah Flush SATB Handshake", Targeted threads: 128, Executed by requesting thre\
      ad: 128, Total completion time: 185983 ns
      [552.958s][info][handshake ] Handshake "Shenandoah Flush SATB Handshake", Targeted threads: 128, Executed by requesting thre\
      ad: 128, Total completion time: 40785 ns
      [552.958s][info][gc ] GC(99) Concurrent marking (GLOBAL) (unload classes) 231.642ms
      [552.958s][info][safepoint,cleanup] updating inline caches, 0.0000001 secs
      [552.958s][info][safepoint,cleanup] safepoint cleanup tasks, 0.0000100 secs
      [552.958s][info][gc,start ] GC(99) Pause Final Mark (GLOBAL) (unload classes)
      [552.958s][info][gc,task ] GC(99) Using 8 of 8 workers for final marking
      [552.958s][info][gc,age ] GC(99) - age 1: prev 1027032320 bytes, curr 0 bytes, mortality 1.00
      [552.958s][info][gc,age ] GC(99) - age 2: prev 4520 bytes, curr 0 bytes, mortality 1.00
      [552.958s][info][gc,age ] GC(99) ----------------------------------------------------------------------------
      [552.958s][info][gc,age ] GC(99) - age 3: prev 5784 bytes, curr 0 bytes, mortality 1.00
      [553.004s][info][gc,ergo ] GC(99) Planning to promote in place 0 humongous regions and 0 regular regions, spanning a total\
       of 0 used bytes
      [553.004s][info][gc,ergo ] GC(99) Adaptive CSet Selection for GLOBAL. Max Young Evacuation: 633M, Max Old Evacuation: 2280\
      B, Actual Free: 14754M.
      [553.005s][info][gc,ergo ] GC(99) Chosen CSet evacuates young: 253K (of which at least: 87056B are to be promoted), old: 2\
      272B
      [553.005s][info][gc,ergo ] GC(99) Collectable Garbage: 12941M (98%), Immediate: 12326M (93%), 3082 regions, CSet: 615M (4%\
      ), 154 regions
      [553.005s][info][gc,ergo ] GC(99) Evacuation Targets: YOUNG: 253K, PROMOTE: 87056B, OLD: 2272B, TOTAL: 340K

      # A fatal error has been detected by the Java Runtime Environment:
      #
      # Internal Error (/home/kdnilsen/github/shenandoah.ref-processor-updates-remembered-set/src/hotspot/share/gc/shenandoah/shenandoah\
      Generation.cpp:397), pid=11582, tid=12127
      # assert(old_available >= old_consumed) failed: Cannot consume more than is available
      #
      # JRE version: OpenJDK Runtime Environment (22.0) (fastdebug build 22-internal-adhoc.kdnilsen.shenandoah.ref-processor-updates-reme\
      mbered-set)
      # Java VM: OpenJDK 64-Bit Server VM (fastdebug 22-internal-adhoc.kdnilsen.shenandoah.ref-processor-updates-remembered-set, mixed mo\
      de, compressed oops, compressed class ptrs, shenandoah gc, linux-amd64)
      # Problematic frame:
      # V [libjvm.so+0x154e04a] ShenandoahGeneration::adjust_evacuation_budgets(ShenandoahHeap*, ShenandoahCollectionSet*, unsigned lon\
      g)+0x4da
      #
      # No core dump will be written. Core dumps have been disabled. To enable core dumping, try "ulimit -c unlimited" before starting Ja\
      va again
      #
      # An error report file with more information is saved as:
      # /local/home/kdnilsen/tmp/specjbb-reference-rem-set/hs_err_pid11582.log
      #
      # If you would like to submit a bug report, please visit:
      # https://bugreport.java.com/bugreport/crash.jsp
      #
      ```

      Attachments

        Activity

          People

            kdnilsen Kelvin Nilsen
            kdnilsen Kelvin Nilsen
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: