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

GenShen: Resume Old GC even with back-to-back Young GC triggers

XMLWordPrintable

    • gc
    • master

      If old-gen GC is active, it should be resumed following each completed young GC cycle. When resumed, it is expected to receive a minimum time slice of ShenandoahMinimumOldTimeMs before it is preempted for a subsequent young GC cycle.

      We have observed that if the heuristic trigger for young is active at the moment a previous young GC cycle ends, OLD GC is not resumed. Rather, it is "triggered" a second time. This represents an error in the GC log. This is not a new trigger. Rather, it should be reported as resumption of previously interrupted concurrent old marking efforts.

      When old GC triggers in this manner, it does resume the previously interrupted concurrent marking effort, but it does not get the intended minimal time slice.

      We need to correct the GC log, and we need to enforce the intended time slice.

      Below is an excerpt from a relevant GC log. The new trigger occurs within 1 ms following the end of previous GC. Even though concurrent old marking is active from prior trigger, this is announced in the log as a new Trigger (Old). Note that we perform some concurrent marking of old. However, it is only 1.838ms of concurrent marking rather than the prescribed 100 ms.

      ```
      [9630.688s][info][gc,stats ]
      [9630.688s][info][gc,metaspace] Metaspace: 1512K(1600K)->1512K(1600K) NonClass: 1426K(1472K)->1426K(1472K) Class: 85K(128K)->85K(128K)
      [9630.689s][info][gc ] Trigger (Young): Average GC time (51219.99 ms) is above the time for average allocation rate (1946 MB/s) to deplete free headroom (13433M) (margin of error = 1.88)
      [9630.689s][info][gc,ergo ] Free headroom: 39648M (free) - 26214M (spike) - 0B (penalties) = 13433M
      [9630.689s][info][gc ] Trigger (Old): Old has overgrown, live at end of previous OLD marking: 71481M, current usage: 185G, percent growth: 165.6%
      [9630.689s][info][gc,free ] Free: 39648M, Max: 32768K regular, 29664M humongous, Frag: 26% external, 0% internal; Used: 0B, Mutator Free: 1239 Collector Reserve: 16736M, Max: 32768K; Used: 0B Old Collector Reserve: 1965K, Max: 1\
      965K; Used: 30802K
      [9630.689s][info][gc,start ] GC(34) Concurrent marking (Old)
      [9630.689s][info][gc,task ] GC(34) Using 48 of 96 workers for concurrent marking
      [9630.690s][info][gc ] Trigger (Young): Average GC time (51219.99 ms) is above the time for average allocation rate (1946 MB/s) to deplete free headroom (13433M) (margin of error = 1.88)
      [9630.690s][info][gc,ergo ] Free headroom: 39648M (free) - 26214M (spike) - 0B (penalties) = 13433M
      [9630.690s][info][gc ] Preempting old generation mark to allow Young GC
      [9630.690s][info][gc,thread ] Cancelling GC: Concurrent GC
      [9630.691s][info][gc ] GC(34) Concurrent marking (Old) 1.838ms
      [9630.691s][info][gc,ergo ] GC(34) At end of OLD marking increment: GCU: 1636.2%, MU: -28.5% for duration 0.004s (totals to be subsumed in next gc report)
      [9630.691s][info][gc,ergo ] GC(34) At end of Concurrent Old Marking increment: Young generation used: 271G, used regions: 271G, humongous waste: 0B, soft capacity: 512G, max capacity: 326G, available: 39648M
      [9630.691s][info][gc,ergo ] GC(34) At end of Concurrent Old Marking increment: Old generation used: 185G, used regions: 185G, humongous waste: 60719K, soft capacity: 0B, max capacity: 185G, available: 1972K

      ``

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

              Created:
              Updated:
              Resolved: