Skip to content

Instantly share code, notes, and snippets.

@thhart
Created May 14, 2021 07:49
Show Gist options
  • Save thhart/8214316c1c7aab45382cc77fcdbce213 to your computer and use it in GitHub Desktop.
Save thhart/8214316c1c7aab45382cc77fcdbce213 to your computer and use it in GitHub Desktop.
[2021-05-14T09:41:26.450+0200] Initializing The Z Garbage Collector
[2021-05-14T09:41:26.450+0200] Version: 16+36 (release)
[2021-05-14T09:41:26.450+0200] NUMA Support: Disabled
[2021-05-14T09:41:26.450+0200] CPUs: 32 total, 32 available
[2021-05-14T09:41:26.450+0200] Memory: 64276M
[2021-05-14T09:41:26.450+0200] Large Page Support: Disabled
[2021-05-14T09:41:26.450+0200] Workers: 20 parallel, 4 concurrent
[2021-05-14T09:41:26.452+0200] Address Space Type: Contiguous/Unrestricted/Complete
[2021-05-14T09:41:26.452+0200] Address Space Size: 393216M x 3 = 1179648M
[2021-05-14T09:41:26.452+0200] Heap Backing File: /memfd:java_heap
[2021-05-14T09:41:26.452+0200] Heap Backing Filesystem: tmpfs (0x1021994)
[2021-05-14T09:41:26.452+0200] Min Capacity: 8M
[2021-05-14T09:41:26.452+0200] Initial Capacity: 1006M
[2021-05-14T09:41:26.452+0200] Max Capacity: 24576M
[2021-05-14T09:41:26.452+0200] Medium Page Size: 32M
[2021-05-14T09:41:26.452+0200] Pre-touch: Disabled
[2021-05-14T09:41:26.452+0200] Available space on backing filesystem: N/A
[2021-05-14T09:41:26.452+0200] Uncommit: Enabled
[2021-05-14T09:41:26.452+0200] Uncommit Delay: 60s
[2021-05-14T09:41:26.599+0200] Runtime Workers: 20 parallel
[2021-05-14T09:41:26.600+0200] Using The Z Garbage Collector
[2021-05-14T09:41:26.600+0200] CDS archive(s) mapped at: [0x0000000800000000-0x0000000800bc0000-0x0000000800bc0000), size 12320768, SharedBaseAddress: 0x0000000800000000, ArchiveRelocationMode: 0.
[2021-05-14T09:41:26.600+0200] Compressed class space mapped at: 0x0000000800c00000-0x0000000840c00000, reserved size: 1073741824
[2021-05-14T09:41:26.600+0200] Narrow klass base: 0x0000000800000000, Narrow klass shift: 3, Narrow klass range: 0x100000000
[2021-05-14T09:41:28.243+0200] GC(0) Garbage Collection (Metadata GC Threshold)
[2021-05-14T09:41:28.244+0200] GC(0) Pause Mark Start 0.084ms
[2021-05-14T09:41:28.257+0200] GC(0) Concurrent Mark 13.379ms
[2021-05-14T09:41:28.257+0200] GC(0) Pause Mark End 0.069ms
[2021-05-14T09:41:28.260+0200] GC(0) Concurrent Process Non-Strong References 2.819ms
[2021-05-14T09:41:28.260+0200] GC(0) Concurrent Reset Relocation Set 0.001ms
[2021-05-14T09:41:28.262+0200] GC(0) Concurrent Select Relocation Set 2.059ms
[2021-05-14T09:41:28.263+0200] GC(0) Pause Relocate Start 0.009ms
[2021-05-14T09:41:28.270+0200] GC(0) Concurrent Relocate 7.175ms
[2021-05-14T09:41:28.270+0200] GC(0) Load: 1.52/4.21/5.09
[2021-05-14T09:41:28.270+0200] GC(0) MMU: 2ms/95.8%, 5ms/98.3%, 10ms/99.2%, 20ms/99.2%, 50ms/99.7%, 100ms/99.8%
[2021-05-14T09:41:28.270+0200] GC(0) Mark: 4 stripe(s), 2 proactive flush(es), 1 terminate flush(es), 1 completion(s), 0 continuation(s)
[2021-05-14T09:41:28.270+0200] GC(0) NMethods: 2533 registered, 0 unregistered
[2021-05-14T09:41:28.270+0200] GC(0) Metaspace: 20M used, 21M committed, 1048M reserved
[2021-05-14T09:41:28.270+0200] GC(0) Soft: 4695 encountered, 0 discovered, 0 enqueued
[2021-05-14T09:41:28.270+0200] GC(0) Weak: 1698 encountered, 573 discovered, 248 enqueued
[2021-05-14T09:41:28.270+0200] GC(0) Final: 2 encountered, 2 discovered, 2 enqueued
[2021-05-14T09:41:28.270+0200] GC(0) Phantom: 927 encountered, 883 discovered, 400 enqueued
[2021-05-14T09:41:28.270+0200] GC(0) Small Pages: 43 / 86M, Empty: 0M, Relocated: 10M, In-Place: 0
[2021-05-14T09:41:28.270+0200] GC(0) Medium Pages: 1 / 32M, Empty: 0M, Relocated: 0M, In-Place: 0
[2021-05-14T09:41:28.270+0200] GC(0) Large Pages: 0 / 0M, Empty: 0M, Relocated: 0M, In-Place: 0
[2021-05-14T09:41:28.270+0200] GC(0) Forwarding Usage: 3M
[2021-05-14T09:41:28.270+0200] GC(0) Min Capacity: 8M(0%)
[2021-05-14T09:41:28.270+0200] GC(0) Max Capacity: 24576M(100%)
[2021-05-14T09:41:28.270+0200] GC(0) Soft Max Capacity: 4096M(17%)
[2021-05-14T09:41:28.270+0200] GC(0) Mark Start Mark End Relocate Start Relocate End High Low
[2021-05-14T09:41:28.270+0200] GC(0) Capacity: 1006M (4%) 1006M (4%) 1006M (4%) 1006M (4%) 1006M (4%) 1006M (4%)
[2021-05-14T09:41:28.270+0200] GC(0) Free: 24458M (100%) 24456M (100%) 24454M (100%) 24518M (100%) 24518M (100%) 24448M (99%)
[2021-05-14T09:41:28.270+0200] GC(0) Used: 118M (0%) 120M (0%) 122M (0%) 58M (0%) 128M (1%) 58M (0%)
[2021-05-14T09:41:28.270+0200] GC(0) Live: - 24M (0%) 24M (0%) 24M (0%) - -
[2021-05-14T09:41:28.270+0200] GC(0) Allocated: - 2M (0%) 4M (0%) 6M (0%) - -
[2021-05-14T09:41:28.270+0200] GC(0) Garbage: - 93M (0%) 93M (0%) 27M (0%) - -
[2021-05-14T09:41:28.270+0200] GC(0) Reclaimed: - - 0M (0%) 66M (0%) - -
[2021-05-14T09:41:28.270+0200] GC(0) Garbage Collection (Metadata GC Threshold) 118M(0%)->58M(0%)
[2021-05-14T09:41:32.773+0200] GC(1) Garbage Collection (Metadata GC Threshold)
[2021-05-14T09:41:32.773+0200] GC(1) Pause Mark Start 0.015ms
[2021-05-14T09:41:32.800+0200] GC(1) Concurrent Mark 26.509ms
[2021-05-14T09:41:32.800+0200] GC(1) Pause Mark End 0.046ms
[2021-05-14T09:41:32.804+0200] GC(1) Concurrent Process Non-Strong References 4.598ms
[2021-05-14T09:41:32.804+0200] GC(1) Concurrent Reset Relocation Set 0.009ms
[2021-05-14T09:41:32.806+0200] GC(1) Concurrent Select Relocation Set 1.882ms
[2021-05-14T09:41:32.806+0200] GC(1) Pause Relocate Start 0.012ms
[2021-05-14T09:41:32.815+0200] GC(1) Concurrent Relocate 8.140ms
[2021-05-14T09:41:32.815+0200] GC(1) Load: 1.48/4.15/5.07
[2021-05-14T09:41:32.815+0200] GC(1) MMU: 2ms/95.8%, 5ms/98.3%, 10ms/99.2%, 20ms/99.2%, 50ms/99.7%, 100ms/99.8%
[2021-05-14T09:41:32.815+0200] GC(1) Mark: 4 stripe(s), 2 proactive flush(es), 1 terminate flush(es), 1 completion(s), 0 continuation(s)
[2021-05-14T09:41:32.815+0200] GC(1) NMethods: 5002 registered, 0 unregistered
[2021-05-14T09:41:32.815+0200] GC(1) Metaspace: 35M used, 36M committed, 1056M reserved
[2021-05-14T09:41:32.815+0200] GC(1) Soft: 5076 encountered, 0 discovered, 0 enqueued
[2021-05-14T09:41:32.815+0200] GC(1) Weak: 2801 encountered, 855 discovered, 240 enqueued
[2021-05-14T09:41:32.815+0200] GC(1) Final: 165 encountered, 18 discovered, 18 enqueued
[2021-05-14T09:41:32.815+0200] GC(1) Phantom: 905 encountered, 804 discovered, 316 enqueued
[2021-05-14T09:41:32.815+0200] GC(1) Small Pages: 54 / 108M, Empty: 0M, Relocated: 9M, In-Place: 0
[2021-05-14T09:41:32.815+0200] GC(1) Medium Pages: 1 / 32M, Empty: 0M, Relocated: 0M, In-Place: 0
[2021-05-14T09:41:32.815+0200] GC(1) Large Pages: 0 / 0M, Empty: 0M, Relocated: 0M, In-Place: 0
[2021-05-14T09:41:32.815+0200] GC(1) Forwarding Usage: 2M
[2021-05-14T09:41:32.815+0200] GC(1) Min Capacity: 8M(0%)
[2021-05-14T09:41:32.815+0200] GC(1) Max Capacity: 24576M(100%)
[2021-05-14T09:41:32.815+0200] GC(1) Soft Max Capacity: 4096M(17%)
[2021-05-14T09:41:32.815+0200] GC(1) Mark Start Mark End Relocate Start Relocate End High Low
[2021-05-14T09:41:32.815+0200] GC(1) Capacity: 1006M (4%) 1006M (4%) 1006M (4%) 1006M (4%) 1006M (4%) 1006M (4%)
[2021-05-14T09:41:32.815+0200] GC(1) Free: 24436M (99%) 24408M (99%) 24404M (99%) 24470M (100%) 24470M (100%) 24396M (99%)
[2021-05-14T09:41:32.815+0200] GC(1) Used: 140M (1%) 168M (1%) 172M (1%) 106M (0%) 180M (1%) 106M (0%)
[2021-05-14T09:41:32.815+0200] GC(1) Live: - 34M (0%) 34M (0%) 34M (0%) - -
[2021-05-14T09:41:32.815+0200] GC(1) Allocated: - 28M (0%) 32M (0%) 40M (0%) - -
[2021-05-14T09:41:32.815+0200] GC(1) Garbage: - 105M (0%) 105M (0%) 31M (0%) - -
[2021-05-14T09:41:32.815+0200] GC(1) Reclaimed: - - 0M (0%) 74M (0%) - -
[2021-05-14T09:41:32.815+0200] GC(1) Garbage Collection (Metadata GC Threshold) 140M(1%)->106M(0%)
[2021-05-14T09:41:36.611+0200] === Garbage Collection Statistics =======================================================================================================================
[2021-05-14T09:41:36.611+0200] Last 10s Last 10m Last 10h Total
[2021-05-14T09:41:36.611+0200] Avg / Max Avg / Max Avg / Max Avg / Max
[2021-05-14T09:41:36.611+0200] Collector: Garbage Collection Cycle 34.145 / 41.950 34.145 / 41.950 34.145 / 41.950 34.145 / 41.950 ms
[2021-05-14T09:41:36.611+0200] Contention: Mark Segment Reset Contention 0 / 0 0 / 0 0 / 0 0 / 0 ops/s
[2021-05-14T09:41:36.611+0200] Contention: Mark SeqNum Reset Contention 0 / 0 0 / 0 0 / 0 0 / 0 ops/s
[2021-05-14T09:41:36.611+0200] Critical: Allocation Stall 0 / 0 0 / 0 0 / 0 0 / 0 ops/s
[2021-05-14T09:41:36.611+0200] Critical: Allocation Stall 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 ms
[2021-05-14T09:41:36.611+0200] Critical: GC Locker Stall 0 / 0 0 / 0 0 / 0 0 / 0 ops/s
[2021-05-14T09:41:36.611+0200] Critical: GC Locker Stall 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 ms
[2021-05-14T09:41:36.611+0200] Critical: Relocation Stall 0 / 0 0 / 0 0 / 0 0 / 0 ops/s
[2021-05-14T09:41:36.611+0200] Critical: Relocation Stall 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 ms
[2021-05-14T09:41:36.611+0200] Memory: Allocation Rate 135 / 1098 135 / 1098 135 / 1098 135 / 1098 MB/s
[2021-05-14T09:41:36.611+0200] Memory: Out Of Memory 0 / 0 0 / 0 0 / 0 0 / 0 ops/s
[2021-05-14T09:41:36.611+0200] Memory: Page Cache Flush 0 / 0 0 / 0 0 / 0 0 / 0 MB/s
[2021-05-14T09:41:36.611+0200] Memory: Page Cache Hit L1 8 / 36 8 / 36 8 / 36 8 / 36 ops/s
[2021-05-14T09:41:36.611+0200] Memory: Page Cache Hit L2 0 / 0 0 / 0 0 / 0 0 / 0 ops/s
[2021-05-14T09:41:36.611+0200] Memory: Page Cache Hit L3 8 / 31 8 / 31 8 / 31 8 / 31 ops/s
[2021-05-14T09:41:36.611+0200] Memory: Page Cache Miss 0 / 1 0 / 1 0 / 1 0 / 1 ops/s
[2021-05-14T09:41:36.611+0200] Memory: Uncommit 0 / 0 0 / 0 0 / 0 0 / 0 MB/s
[2021-05-14T09:41:36.611+0200] Memory: Undo Object Allocation Failed 0 / 0 0 / 0 0 / 0 0 / 0 ops/s
[2021-05-14T09:41:36.611+0200] Memory: Undo Object Allocation Succeeded 0 / 0 0 / 0 0 / 0 0 / 0 ops/s
[2021-05-14T09:41:36.611+0200] Memory: Undo Page Allocation 0 / 0 0 / 0 0 / 0 0 / 0 ops/s
[2021-05-14T09:41:36.611+0200] Phase: Concurrent Mark 19.944 / 26.509 19.944 / 26.509 19.944 / 26.509 19.944 / 26.509 ms
[2021-05-14T09:41:36.611+0200] Phase: Concurrent Mark Continue 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 ms
[2021-05-14T09:41:36.611+0200] Phase: Concurrent Process Non-Strong References 3.708 / 4.598 3.708 / 4.598 3.708 / 4.598 3.708 / 4.598 ms
[2021-05-14T09:41:36.611+0200] Phase: Concurrent Relocate 7.657 / 8.140 7.657 / 8.140 7.657 / 8.140 7.657 / 8.140 ms
[2021-05-14T09:41:36.611+0200] Phase: Concurrent Reset Relocation Set 0.005 / 0.009 0.005 / 0.009 0.005 / 0.009 0.005 / 0.009 ms
[2021-05-14T09:41:36.611+0200] Phase: Concurrent Select Relocation Set 1.970 / 2.059 1.970 / 2.059 1.970 / 2.059 1.970 / 2.059 ms
[2021-05-14T09:41:36.611+0200] Phase: Pause Mark End 0.057 / 0.069 0.057 / 0.069 0.057 / 0.069 0.057 / 0.069 ms
[2021-05-14T09:41:36.611+0200] Phase: Pause Mark Start 0.049 / 0.084 0.049 / 0.084 0.049 / 0.084 0.049 / 0.084 ms
[2021-05-14T09:41:36.611+0200] Phase: Pause Relocate Start 0.010 / 0.012 0.010 / 0.012 0.010 / 0.012 0.010 / 0.012 ms
[2021-05-14T09:41:36.611+0200] Subphase: Concurrent Classes Purge 0.129 / 0.174 0.129 / 0.174 0.129 / 0.174 0.129 / 0.174 ms
[2021-05-14T09:41:36.611+0200] Subphase: Concurrent Classes Unlink 2.827 / 3.508 2.827 / 3.508 2.827 / 3.508 2.827 / 3.508 ms
[2021-05-14T09:41:36.611+0200] Subphase: Concurrent Mark 17.871 / 23.296 17.871 / 23.296 17.871 / 23.296 17.871 / 23.296 ms
[2021-05-14T09:41:36.611+0200] Subphase: Concurrent Mark Idle 1.061 / 1.074 1.061 / 1.074 1.061 / 1.074 1.061 / 1.074 ms
[2021-05-14T09:41:36.611+0200] Subphase: Concurrent Mark Try Flush 0.076 / 0.136 0.076 / 0.136 0.076 / 0.136 0.076 / 0.136 ms
[2021-05-14T09:41:36.611+0200] Subphase: Concurrent Mark Try Terminate 0.645 / 1.077 0.645 / 1.077 0.645 / 1.077 0.645 / 1.077 ms
[2021-05-14T09:41:36.611+0200] Subphase: Concurrent References Enqueue 0.002 / 0.002 0.002 / 0.002 0.002 / 0.002 0.002 / 0.002 ms
[2021-05-14T09:41:36.611+0200] Subphase: Concurrent References Process 0.156 / 0.168 0.156 / 0.168 0.156 / 0.168 0.156 / 0.168 ms
[2021-05-14T09:41:36.611+0200] Subphase: Concurrent Roots ClassLoaderDataGraph 0.143 / 0.728 0.143 / 0.728 0.143 / 0.728 0.143 / 0.728 ms
[2021-05-14T09:41:36.611+0200] Subphase: Concurrent Roots CodeCache 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 ms
[2021-05-14T09:41:36.611+0200] Subphase: Concurrent Roots JavaThreads 1.489 / 3.024 1.489 / 3.024 1.489 / 3.024 1.489 / 3.024 ms
[2021-05-14T09:41:36.611+0200] Subphase: Concurrent Roots OopStorageSet 0.015 / 0.030 0.015 / 0.030 0.015 / 0.030 0.015 / 0.030 ms
[2021-05-14T09:41:36.611+0200] Subphase: Concurrent Weak Roots OopStorageSet 0.398 / 0.624 0.398 / 0.624 0.398 / 0.624 0.398 / 0.624 ms
[2021-05-14T09:41:36.611+0200] Subphase: Pause Mark Try Complete 0.002 / 0.003 0.002 / 0.003 0.002 / 0.003 0.002 / 0.003 ms
[2021-05-14T09:41:36.611+0200] System: Java Threads 66 / 113 66 / 113 66 / 113 66 / 113 threads
[2021-05-14T09:41:36.611+0200] =========================================================================================================================================================
@YSMull
Copy link

YSMull commented Jul 1, 2021

the sum of per gc pause time is less than 0.1 ms,micrometer can not  calculate accurately

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment