DevOps tips & tricks: March 2022

HOWTO

GitHub

https://github.com/dveselka/java-tutorial/tree/master/.github/workflows

Workflow file

# This workflow will build a Java project with Maven, and cache/restore any dependencies to improve the workflow execution time
# For more information see: https://help.github.com/actions/language-and-framework-guides/building-and-testing-java-with-maven

name: Java CI with Maven

on: [push]

jobs:
  build:

    runs-on: ubuntu-latest

    steps:
    - uses: actions/checkout@v2
    - name: Set up JDK 11
      uses: actions/setup-java@v2
      with:
        java-version: '11'
        distribution: 'temurin'
        cache: maven
    - name: Build with Maven
      run: mvn -B package --file pom.xml

Run list

Job detail

HOWTO

GitHub

* test class https://github.com/dveselka/java-tutorial/blob/master/src/main/java/gc/LogGC.java

GC logs with timestamp -Xlog:gc*::time

[2022-03-16T22:30:42.734+0100] GC(30) Pause Full (G1 Compaction Pause)
[2022-03-16T22:30:42.734+0100] GC(30) Phase 1: Mark live objects
[2022-03-16T22:30:43.663+0100] GC(30) Phase 1: Mark live objects 929.512ms
[2022-03-16T22:30:43.663+0100] GC(30) Phase 2: Prepare for compaction
[2022-03-16T22:30:43.941+0100] GC(30) Phase 2: Prepare for compaction 277.577ms
[2022-03-16T22:30:43.941+0100] GC(30) Phase 3: Adjust pointers
[2022-03-16T22:30:44.372+0100] GC(30) Phase 3: Adjust pointers 430.642ms
[2022-03-16T22:30:44.372+0100] GC(30) Phase 4: Compact heap
[2022-03-16T22:30:44.748+0100] GC(30) Phase 4: Compact heap 375.878ms
[2022-03-16T22:30:44.751+0100] GC(30) Eden regions: 0->0(99)
[2022-03-16T22:30:44.751+0100] GC(30) Survivor regions: 0->0(13)
[2022-03-16T22:30:44.751+0100] GC(30) Old regions: 1541->1539
[2022-03-16T22:30:44.751+0100] GC(30) Archive regions: 0->0
[2022-03-16T22:30:44.751+0100] GC(30) Humongous regions: 129->129
[2022-03-16T22:30:44.751+0100] GC(30) Metaspace: 3704K(3904K)->3704K(3904K) NonClass: 3407K(3520K)->3407K(3520K) Class: 297K(384K)->297K(384K)
[2022-03-16T22:30:44.751+0100] GC(30) Pause Full (G1 Compaction Pause) 3331M->3330M(3964M) 2017.026ms
[2022-03-16T22:30:44.751+0100] GC(30) User=15.35s Sys=0.02s Real=2.02s
[2022-03-16T22:30:44.751+0100] GC(17) Concurrent Rebuild Remembered Sets 3586.878ms
[2022-03-16T22:30:44.751+0100] GC(17) Concurrent Mark Abort
[2022-03-16T22:30:44.751+0100] GC(17) Concurrent Mark Cycle 5637.293ms
Exception in thread "main" java.lang.OutOfMemoryError: Java heap space
    at java.base/java.util.HashMap.resize(HashMap.java:702)
    at java.base/java.util.HashMap.putVal(HashMap.java:661)
    at java.base/java.util.HashMap.put(HashMap.java:610)
    at gc.LogGC.main(LogGC.java:15)
[2022-03-16T22:30:44.755+0100] Heap
[2022-03-16T22:30:44.755+0100]  garbage-first heap   total 4059136K, used 3412405K [0x0000000708400000, 0x0000000800000000)
[2022-03-16T22:30:44.755+0100]   region size 2048K, 1 young (2048K), 0 survivors (0K)
[2022-03-16T22:30:44.755+0100]  Metaspace       used 3801K, committed 3968K, reserved 1056768K
[2022-03-16T22:30:44.755+0100]   class space    used 307K, committed 384K, reserved 1048576K

GC logs with -Xlog:gc*

[0.002s][warning][logging] Output options for existing outputs are ignored.
[0.016s][info   ][gc     ] Using G1
[0.019s][info   ][gc,init] Version: 17.0.1+12 (release)
[0.019s][info   ][gc,init] CPUs: 8 total, 8 available
[0.019s][info   ][gc,init] Memory: 15849M
[0.019s][info   ][gc,init] Large Page Support: Disabled
[0.019s][info   ][gc,init] NUMA Support: Disabled
[0.019s][info   ][gc,init] Compressed Oops: Enabled (Zero based)
[0.019s][info   ][gc,init] Heap Region Size: 2M
[0.019s][info   ][gc,init] Heap Min Capacity: 8M
[0.019s][info   ][gc,init] Heap Initial Capacity: 248M
[0.019s][info   ][gc,init] Heap Max Capacity: 3964M
[0.019s][info   ][gc,init] Pre-touch: Disabled
[0.019s][info   ][gc,init] Parallel Workers: 8
[0.019s][info   ][gc,init] Concurrent Workers: 2
[0.019s][info   ][gc,init] Concurrent Refinement Workers: 8
[0.019s][info   ][gc,init] Periodic GC: Disabled


[4.399s][info][gc,heap     ] GC(31) Survivor regions: 12->12(12)
[4.399s][info][gc,heap     ] GC(31) Old regions: 1535->1563
[4.399s][info][gc,heap     ] GC(31) Archive regions: 0->0
[4.399s][info][gc,heap     ] GC(31) Humongous regions: 244->244
[4.399s][info][gc,metaspace] GC(31) Metaspace: 3706K(3904K)->3706K(3904K) NonClass: 3409K(3520K)->3409K(3520K) Class: 297K(384K)->297K(384K)
[4.399s][info][gc          ] GC(31) Pause Young (Normal) (G1 Preventive Collection) 3632M->3637M(3716M) 34.114ms
[4.399s][info][gc,cpu      ] GC(31) User=0.23s Sys=0.01s Real=0.04s
[4.407s][info][gc,start    ] GC(32) Pause Young (Normal) (G1 Preventive Collection)
[4.407s][info][gc,task     ] GC(32) Using 8 workers of 8 for evacuation
[4.429s][info][gc,phases   ] GC(32)   Pre Evacuate Collection Set: 0.2ms
[4.429s][info][gc,phases   ] GC(32)   Merge Heap Roots: 0.1ms
[4.429s][info][gc,phases   ] GC(32)   Evacuate Collection Set: 21.4ms
[4.429s][info][gc,phases   ] GC(32)   Post Evacuate Collection Set: 0.1ms
[4.429s][info][gc,phases   ] GC(32)   Other: 0.1ms
[4.429s][info][gc,heap     ] GC(32) Eden regions: 12->0(80)
[4.429s][info][gc,heap     ] GC(32) Survivor regions: 12->12(12)
[4.429s][info][gc,heap     ] GC(32) Old regions: 1563->1577
[4.429s][info][gc,heap     ] GC(32) Archive regions: 0->0
[4.429s][info][gc,heap     ] GC(32) Humongous regions: 244->244
[4.429s][info][gc,metaspace] GC(32) Metaspace: 3706K(3904K)->3706K(3904K) NonClass: 3409K(3520K)->3409K(3520K) Class: 297K(384K)->297K(384K)
[4.429s][info][gc          ] GC(32) Pause Young (Normal) (G1 Preventive Collection) 3661M->3666M(3716M) 21.847ms
[4.429s][info][gc,cpu      ] GC(32) User=0.14s Sys=0.00s Real=0.02s
[4.430s][info][gc,start    ] GC(33) Pause Young (Normal) (G1 Humongous Allocation)
[4.430s][info][gc,task     ] GC(33) Using 8 workers of 8 for evacuation
[4.443s][info][gc,phases   ] GC(33)   Pre Evacuate Collection Set: 0.1ms
[4.443s][info][gc,phases   ] GC(33)   Merge Heap Roots: 0.0ms
[4.443s][info][gc,phases   ] GC(33)   Evacuate Collection Set: 11.5ms
[4.443s][info][gc,phases   ] GC(33)   Post Evacuate Collection Set: 0.5ms
[4.443s][info][gc,phases   ] GC(33)   Other: 0.1ms
[4.443s][info][gc,heap     ] GC(33) Eden regions: 2->0(93)
[4.443s][info][gc,heap     ] GC(33) Survivor regions: 12->2(12)
[4.443s][info][gc,heap     ] GC(33) Old regions: 1577->1591
[4.443s][info][gc,heap     ] GC(33) Archive regions: 0->0
[4.443s][info][gc,heap     ] GC(33) Humongous regions: 244->244
[4.443s][info][gc,metaspace] GC(33) Metaspace: 3706K(3904K)->3706K(3904K) NonClass: 3409K(3520K)->3409K(3520K) Class: 297K(384K)->297K(384K)
[4.443s][info][gc          ] GC(33) Pause Young (Normal) (G1 Humongous Allocation) 3670M->3672M(3816M) 12.175ms
[4.443s][info][gc,cpu      ] GC(33) User=0.07s Sys=0.00s Real=0.01s
[4.443s][info][gc,ergo     ] Attempting full compaction
[4.443s][info][gc,task     ] GC(34) Using 8 workers of 8 for full compaction
[4.443s][info][gc,start    ] GC(34) Pause Full (G1 Compaction Pause)
[4.449s][info][gc,phases,start] GC(34) Phase 1: Mark live objects
[5.430s][info][gc,phases      ] GC(34) Phase 1: Mark live objects 980.544ms
[5.430s][info][gc,phases,start] GC(34) Phase 2: Prepare for compaction
[5.443s][info][gc,phases      ] GC(34) Phase 2: Prepare for compaction 13.229ms
[5.443s][info][gc,phases,start] GC(34) Phase 3: Adjust pointers
[5.738s][info][gc,phases      ] GC(34) Phase 3: Adjust pointers 295.030ms
[5.738s][info][gc,phases,start] GC(34) Phase 4: Compact heap
[5.756s][info][gc,phases      ] GC(34) Phase 4: Compact heap 17.952ms
[5.785s][info][gc,heap        ] GC(34) Eden regions: 0->0(99)
[5.785s][info][gc,heap        ] GC(34) Survivor regions: 2->0(12)
[5.785s][info][gc,heap        ] GC(34) Old regions: 1591->1541
[5.785s][info][gc,heap        ] GC(34) Archive regions: 0->0
[5.785s][info][gc,heap        ] GC(34) Humongous regions: 244->129
[5.785s][info][gc,metaspace   ] GC(34) Metaspace: 3706K(3904K)->3706K(3904K) NonClass: 3409K(3520K)->3409K(3520K) Class: 297K(384K)->297K(384K)
[5.785s][info][gc             ] GC(34) Pause Full (G1 Compaction Pause) 3672M->3331M(3964M) 1341.941ms
[5.785s][info][gc,cpu         ] GC(34) User=9.83s Sys=0.22s Real=1.35s
[5.785s][info][gc,ergo        ] Attempting maximum full compaction clearing soft references
[5.785s][info][gc,task        ] GC(35) Using 8 workers of 8 for full compaction
[5.786s][info][gc,start       ] GC(35) Pause Full (G1 Compaction Pause)
[5.786s][info][gc,phases,start] GC(35) Phase 1: Mark live objects
[6.797s][info][gc,phases      ] GC(35) Phase 1: Mark live objects 1011.022ms
[6.797s][info][gc,phases,start] GC(35) Phase 2: Prepare for compaction
[7.091s][info][gc,phases      ] GC(35) Phase 2: Prepare for compaction 293.850ms
[7.091s][info][gc,phases,start] GC(35) Phase 3: Adjust pointers
[7.551s][info][gc,phases      ] GC(35) Phase 3: Adjust pointers 460.264ms
[7.551s][info][gc,phases,start] GC(35) Phase 4: Compact heap
[7.967s][info][gc,phases      ] GC(35) Phase 4: Compact heap 416.610ms
[7.971s][info][gc,heap        ] GC(35) Eden regions: 0->0(99)
[7.971s][info][gc,heap        ] GC(35) Survivor regions: 0->0(12)
[7.971s][info][gc,heap        ] GC(35) Old regions: 1541->1540
[7.971s][info][gc,heap        ] GC(35) Archive regions: 0->0
[7.971s][info][gc,heap        ] GC(35) Humongous regions: 129->129
[7.971s][info][gc,metaspace   ] GC(35) Metaspace: 3706K(3904K)->3706K(3904K) NonClass: 3409K(3520K)->3409K(3520K) Class: 297K(384K)->297K(384K)
[7.971s][info][gc             ] GC(35) Pause Full (G1 Compaction Pause) 3331M->3330M(3964M) 2185.032ms
[7.971s][info][gc,cpu         ] GC(35) User=15.44s Sys=0.03s Real=2.18s
[7.971s][info][gc,marking     ] GC(19) Concurrent Mark From Roots 5527.878ms
[7.971s][info][gc,marking     ] GC(19) Concurrent Mark Abort
[7.971s][info][gc             ] GC(19) Concurrent Mark Cycle 5539.567ms
Exception in thread "main" java.lang.OutOfMemoryError: Java heap space
    at java.base/java.util.HashMap.resize(HashMap.java:702)
    at java.base/java.util.HashMap.putVal(HashMap.java:661)
    at java.base/java.util.HashMap.put(HashMap.java:610)
    at gc.LogGC.main(LogGC.java:15)
[7.973s][info][gc,heap,exit   ] Heap
[7.973s][info][gc,heap,exit   ]  garbage-first heap   total 4059136K, used 3412405K [0x0000000708400000, 0x0000000800000000)
[7.973s][info][gc,heap,exit   ]   region size 2048K, 1 young (2048K), 0 survivors (0K)
[7.973s][info][gc,heap,exit   ]  Metaspace       used 3802K, committed 3968K, reserved 1056768K
[7.973s][info][gc,heap,exit   ]   class space    used 307K, committed 384K, reserved 1048576K

DevOps tips & tricks

Monday, March 21, 2022

Create GihHub Action with Maven build

HOWTO

GitHub

Workflow file

Wednesday, March 16, 2022

JDK 11 - garbage collector logging

HOWTO

GitHub

GC logs with timestamp -Xlog:gc*::time

GC logs with -Xlog:gc*