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

Shenandoah: only print heap changes for operations that directly affect it

XMLWordPrintable

    • gc
    • b18

        Our current log prints the heap changes for every operation, including those that do not change the heap directly. It clutters the GC log unnecessarily. We might consider only printing heap changes for the ops that do affect either used() or capacity().

        Before:
        [124.743s][info][gc] Trigger: Average GC time (1748.33 ms) is above the time for allocation rate (2215 MB/s) to deplete free headroom (3856M)
        [124.749s][info][gc] GC(21) Concurrent reset 14567M->14585M(20480M) 6.079ms
        [124.751s][info][gc] GC(21) Pause Init Mark (unload classes) 0.504ms
        [125.482s][info][gc] GC(21) Concurrent marking (unload classes) 14671M->16071M(20480M) 731.045ms
        [125.484s][info][gc] GC(21) Pause Final Mark (unload classes) 0.932ms
        [125.492s][info][gc] GC(21) Concurrent roots processing 16175M->16216M(20480M) 7.794ms
        [125.492s][info][gc] GC(21) Concurrent cleanup 16216M->16128M(20480M) 0.169ms
        [125.725s][info][gc] GC(21) Concurrent evacuation 16128M->17201M(20480M) 232.863ms
        [125.726s][info][gc] GC(21) Pause Init Update Refs 0.101ms
        [126.531s][info][gc] GC(21) Concurrent update references 17255M->19111M(20480M) 805.111ms
        [126.533s][info][gc] GC(21) Pause Final Update Refs 0.244ms
        [126.533s][info][gc] GC(21) Concurrent cleanup 19111M->5423M(20480M) 0.238ms

        After:
        [125.755s][info][gc] Trigger: Average GC time (1764.16 ms) is above the time for allocation rate (2241 MB/s) to deplete free headroom (3950M)
        [125.760s][info][gc] GC(21) Concurrent reset 5.215ms
        [125.763s][info][gc] GC(21) Pause Init Mark (unload classes) 0.470ms
        [126.507s][info][gc] GC(21) Concurrent marking (unload classes) 744.055ms
        [126.510s][info][gc] GC(21) Pause Final Mark (unload classes) 0.826ms
        [126.525s][info][gc] GC(21) Concurrent roots processing 12.399ms
        [126.525s][info][gc] GC(21) Concurrent cleanup 16260M->16098M(20480M) 0.168ms
        [126.726s][info][gc] GC(21) Concurrent evacuation 200.802ms
        [126.727s][info][gc] GC(21) Pause Init Update Refs 0.111ms
        [127.445s][info][gc] GC(21) Concurrent update references 717.766ms
        [127.446s][info][gc] GC(21) Pause Final Update Refs 0.265ms
        [127.447s][info][gc] GC(21) Concurrent cleanup 18736M->5208M(20480M) 0.229ms

              shade Aleksey Shipilev
              shade Aleksey Shipilev
              Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

                Created:
                Updated:
                Resolved: