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

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

    XMLWordPrintable

    Details

    • Subcomponent:
      gc
    • Resolved In Build:
      b18

      Backports

        Description

        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

          Attachments

            Issue Links

              Activity

                People

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

                  Dates

                  Created:
                  Updated:
                  Resolved: