1 source

• Source: Java Virtual Machine JVM Fault Diagnosis and Performance Optimization — Ge Yiming
• Chapter: Chapter 5

This article is some notes of chapter 5.

2 an overview

This article focuses on common garbage collectors in the JVM, including:

• Serial collector
• Parallel collector
• CMS
• G1

I also covered some details about memory allocation and a simple exercise in JVM tuning.

Serial collector

A serial collector is a collector that uses a single thread for garbage collection, with only one worker thread per collection. As the oldest kind of collector, serial collector has the following characteristics:

• Only single threads are used for garbage collection
• Exclusive garbage collection

When The serial collector does a garbage collection, The application thread needs to pause until The collection is complete, a phenomenon known as stop-the-world, or STW.

Parameters of the serial collector are as follows:

• -XX:+UseSerialGC: Both the new generation and the old generation use serial recyclers
• -XX:+UseParNewGC: New generation useParNewCollector, the old days used serial collector (JDK9+Version has removed this parameter becauseCMSbeG1Instead of)
• -XX:+UseParallelGC: New generation useParallelGCCollector, the old days used serial collector

4 Parallel collector

The parallel collection period is improved on the basis of serial collector, which uses multiple threads to collect garbage at the same time. Common parallel collectors are:

• The new generationParNewcollector
• The new generationParallelGCcollector
• The old sParallelOldGCcollector

4.1 ParNew

ParNew is a garbage collector that works in the new generation. It simply multithreads the serial collector. The collection strategy, algorithm and parameters are the same as those of the new generation serial collector. At the same time, ParNew is also an exclusive collector, the collection process will STW. Although ParNew uses multithreading for garbage collection, the parallel collector may be worse than the serial collector on a single-CPU or low-concurrency system.

You can use the following parameters to enable ParNew:

• -XX:+UseParNewGC: New generation useParNew, the old days used serial collector (JDK9+Deleted)
• -XX:+UseConcMarkSweepGC: New generation useParNewUsed in the old daysCMS(JDK9+You are advised to use the default valueG1)

The number of threads at work for ParNew can be specified using -xx :ParallelGCThreads.

4.2 ParallelGC

ParallelGC is a collector that uses a replication algorithm and is similar to ParNew in that it is a multi-threaded, exclusive collector. However, ParallelGC is concerned with the throughput of the system and can be enabled with the following parameters:

• -XX:+UseParallelGC: New generation useParallelGCThe old days used serial collectors
• -XX:+UseParallelOldGC: New generation useParallelGCUsed in the old daysParallelOldGC

ParallelGC provides two parameters to control system throughput:

• -XX:+MaxGCPauseMills: Sets the maximum garbage collection pause time, an integer greater than 0.ParallelGCAdjust as you workJavaHeap size or other parameters, as much as possible to limit the pause timeMaxGCPauseMillsIf you want to keep the pause time small, you might use a smaller heap, because smaller heaps collect faster than larger heaps, but with the consequence that you might have more garbage collections and potentially lower throughput
• -XX:+GCTimeRatio: Sets the throughput size. Yes0-100.Is an integer, let’s sayn, then the system will cost no more than1/(1+n)Time for garbage collection, default value is99That is, the time spent on garbage collection should not exceed1 / (1 + 99) = 1%

In addition, there is a -xx :+UseAdaptiveSizePolicy parameter, which can enable the adaptive policy. After this parameter is enabled, the size of the new generation, the ratio of Eden area to survivor area, and the age of the object promoted to the old age will be automatically adjusted.

4.3 ParallelOldGC

As the name suggests, this is a ParallelGC that worked in the old days, with the same focus on system throughput, using token compression, and JDK 1.6+ available. Related parameters are as follows:

• -XX:+UseParallelOldGC: Specifies to be used in older yearsParallelOldGC(Also used by the new generationParallelGC)
• -XX:ParallelGCThreads: Sets the number of threads for garbage collection

5 CMS

CMS stands for Concurrent Mark Sweep, a multi-threaded collector that uses Mark Sweep and does not reclaim the new generation. Unlike ParallelGC/ParallelOldGC, CMS is primarily concerned with system pause times.

5.1 Workflow

The details are as follows:

• Initial tag:STW, the function is to mark alive objects, including all the content in the old ageGC Roots(JavaIn theGC RootsThis includes objects referenced by the virtual machine stack, objects referenced by class static properties in the method area, objects referenced by constants in the method area, and objects in the local method stackJNIObjects referenced), and objects in the new generation that refer to older objects
• Concurrent marking: Find all surviving objects starting with the objects marked in the initial marking phase
• Pre-cleanup: This phase is used to deal with unlabeled live objects during the concurrent tagging phase, because concurrent tagging does not mark all live objects in the old age (the application will change the references of some objects while tagging)-XX:-CMSPrecleaningEnabledClosed)
• Relabeling:STW, the goal is to complete the marking of all living objects throughout the old age. If this phase takes too long, use it-XX:+CMSScavengeBeforeRemark, before relabellingYong GC, but this parameter may cause frequentCMS GCThe reason can beStamp here
• Concurrent cleanup: Clearing unmarked objects and reclaiming space. Of course, since this process is concurrent, the user thread also runs, and the garbage generated cannot be cleaned up and can only be saved for the next timeGCAfter cleaning, this part of the garbage is called “floating garbage.”
• Concurrent reset: ResetsCMSInternal data results, ready next timeCMSuse

5.2 Main Parameters

• -XX:+UseConcMarkSweepGCOpen:CMS
• -XX:ConcGCThreads/-XX:ParallelCMSThreads: Sets the number of concurrent threads
• -XX:CMSInitiatingOccupancyFraction: Reclamation threshold. When the usage of the old age exceeds this threshold, reclamation is performed. The default value is68, if memory usage growth rate is too fast, resultingCMSRunning out of memory during execution,CMSIt will fail to collect,JVMLaunches the old serial collector for collection, and firesSTWUntil the collection is complete
• -XX:+UseCMSCompactAtFullCollectionBecause:CMSIs a concurrent collector, after which there is a high probability that a large amount of memory fragmentation will occur, causing discrete free space not to be allocated to large objects, and triggering againCMS GC. With this parameter, memory compression is performed once the collection is complete (represented as defragmentation, not concurrent)
• -XX:CMSFullGCsBeforeCompaction: Used to set the number of timesCMSAfter that, perform a memory compression

6 G1

G1 is the garbage collector introduced in JDK7 and is the default garbage collector in JDK9+.

• Parallelism: There can be more than one collection periodGCThreads working simultaneously
• Concurrency: Part of the work can be performed concurrently with the application and generally does not block the application for the entire payback period
• generationalGC: Give consideration to the new generation and the old age
• Space collation: Appropriate object movement occurs during the collection process
• Predictability: Select only some areas for memory reclamation, which reduces the reclamation range and can be controlled at the same timeSTWtime

6.1 G1The working process

The G1 recycling process may have four stages:

• The new generationGC
• Concurrent marking cycle
• Hybrid recycling
• (optional)Full GC

Let’s take a look at each of them.

6.1.1 CenozoicGC

The working area of the new-generation GC is Eden area and survivor area. Once Eden area is occupied, the new-generation GC will start. After the generation GC, all Eden districts will be cleared, and old districts will be increased (because some survivor districts or Eden districts will be promoted to old districts).

For example, here is part of the G1 GC log of the new generation:

[1.076s][INFO][GC,start] GC(0) Pause Young (Normal) (G1 Evacuation Pause) [1.076s][INFO][GC, Task] GC(0) Using 2 workers of 10forEvacuation [1.079s][info][GC, Phases] GC(0) Pre Evacuate Collection Set: 37 ms [1.367 s][info][GC, Phases] GC(0) Evacuate Collection Set: Post Evacuate Collection Set: 0.1ms [1.079s][info][GC, Phases] GC(0) Other: 0.2ms [1.079s][info][GC,heap] GC(0) Eden Regions: 9->0(7) [1.079s][info][GC,heap] GC(0) Survivor regions: 0->2(2) [1.079s][info][GC,heap] GC(0) Old Regions: 0->1 [1.079s][info][GC,heap] GC(0) Humongous Regions: 0->0 [1.079s][info][GC,metaspace] GC(0) metaspace: 3473K->3473K(1056768K) [1.079s][info][GC] GC(0) Pause Young (Normal) (G1 Evacuation Pause) 9M->2M(20M) 2.689ms [info][GC, CPU] GC(0) User=0.00s Sys=0.00s Real=0.01sCopy the code

You can see that the Eden area is cleared, and the survivor area and the elderly area increase.

6.1.2 Concurrent marking cycle

G1’s concurrent marking phase is similar to CMS’s and can be divided into the following steps:

• Initial flag (STW) : Marks objects directly reachable from the root node. This phase is accompanied by a new generationGC
• Root region scan (concurrent) : Scanning bysurvivorArea directly accessible elderly areas, and mark these directly accessible objects
• Concurrency flags (concurrency) : andCMSSimilarly, the whole heap is scanned and found alive and marked, a concurrent process, but one that will be created by the new generationGCinterrupt
• Relabel (STW) : to correct the marked result, useSATB(Snapshot-At-The-Beginning) algorithm to create a snapshot of the living object at the beginning of the tag, which helps speed up the re-tag
• Exclusive cleaning (STW) : Calculates the live objects and for each regionGCThe scale is recycled and sorted, and the memory set is updated at this stage (Remebered Set)
• Concurrent cleanup (concurrent) : Concurrent garbage cleanup

Is one of the more important stages concurrent mark phase, after the concurrent mark, will increase the area of some marked as G, because these areas are marked as G internal high proportion of garbage, in the hope that in subsequent GC are collected, and the area will be marked as G G1 records in what is referred to as a Collection in the Collection of Sets.

6.1.3 Mixed recycling

During the concurrent marking cycle, although some objects are collected, the overall percentage is quite low, but after the concurrent marking cycle, G1 already knows which areas have the most garbage objects and can recycle them in the next phase.

This phase is called mixed collection because both the normal young generation GC is performed and some marked old age areas are picked up for collection, processing both Cenozoic and old age. The hybrid GC executes several times until enough memory has been reclaimed, then it triggers a new generation GC, and the cycle continues as follows:

6.1.4 Full GC

If a memory shortage occurs during a concurrent collection, G1 performs Full GC as CMS does. In addition, a Full GC can result if there is not enough space in the hybrid GC, or if the survivor zone of the new generation GC and the old generation GC cannot accommodate the surviving objects.

6.2 G1Related parameters

• -XX:+UseG1GCOpening:G1
• -XX:MaxGCPauseMills:STWMaximum time, if any pause time exceeds the set value,G1Will try to automatically adjust the ratio of new generation and old age, adjust heap size, etc
• -XX:ParallelGCThreads: is used to set concurrent reclamationGCNumber of worker threads
• -XX:InitiatingHeapOccupancyPercent: You can specify when the total heap usage reaches the point at which concurrent marking cycles are triggered. The default is45. Once this value is set,G1Always not to modify, if the setting is too large, it means that the concurrent cycle will not start, causeFull GCIf set too small, concurrency cycles will execute very frequently, a lotGCThread preemptionCPUPerformance degradation

7 GCTune simple experiments

7.1 an overview of the

A simple experiment to test the impact of different JVM startup parameters on Tomcat, through the pressure test, to obtain the main performance indicators of JVM, experience the impact of different parameters on system performance. Environment:

• Tomcat 10.0.5
• Its 11.0.10
• JMeter 5.4.1

Step 7.2

7.2.1 Adding a Thread Group

Select Thread(Users) from Test Plan, select Thread Group, set the number of threads and loop times:

7.2.2 Adding a Sampler

Select the thread group you just added and select Edit->Add->Sampler->HTTP Request to Add the HTTP Sampler:

The default Tomcat page, port 1080, is selected for testing.

7.2.3 Adding a Summary Report

After selecting HTTP Request, right-click Add->Listener->Summary Request to Add a Summary report. Then you can test the HTTP Request.

7.3 test

Environment variables are introduced first:

export CATALINA_OPTS="-Xlog:gc:gc.log -Xmx32m -Xms32m -XX:ParallelGCThreads=4" 
Copy the code

The following operations are based on this environment variable. First, set the initial heap and maximum heap to 32M, then run Tomcat and test in JMeter. Here are the first 100 lines of the GC log:

[0.040s][info][gc] Using G1
[0.377s][info][gc] GC(0) Pause Young (Normal) (G1 Evacuation Pause) 14M->3M(32M) 2.699ms
[0.573s][info][gc] GC(1) Pause Young (Normal) (G1 Evacuation Pause) 14M->5M(32M) 2.605ms
[0.678s][info][gc] GC(2) Pause Young (Normal) (G1 Evacuation Pause) 16M->6M(32M) 2.355ms
[0.793s][info][gc] GC(3) Pause Young (Normal) (G1 Evacuation Pause) 17M->7M(32M) 1.579ms
[0.796s][info][gc] GC(4) Pause Young (Concurrent Start) (Metadata GC Threshold) 7M->7M(32M) 0.925ms
[0.796s][info][gc] GC(5) Concurrent Cycle
[0.808s][info][gc] GC(5) Pause Remark 8M->8M(32M) 2.363ms
[0.815s][info][gc] GC(5) Pause Cleanup 9M->9M(32M) 0.021ms
[0.816s][info][gc] GC(5) Concurrent Cycle 19.666ms
[0.899s][info][gc] GC(6) Pause Young (Normal) (G1 Evacuation Pause) 19M->8M(32M) 1.150ms
[1.018s][info][gc] GC(7) Pause Young (Normal) (G1 Evacuation Pause) 20M->9M(32M) 1.243ms
[17.760s][info][gc] GC(8) Pause Young (Normal) (G1 Evacuation Pause) 22M->15M(32M) 2.984ms
[17.810s][info][gc] GC(9) Pause Young (Normal) (G1 Evacuation Pause) 22M->19M(32M) 2.921ms
[17.818s][info][gc] GC(10) Pause Young (Concurrent Start) (G1 Evacuation Pause) 22M->21M(32M) 1.168ms
[17.818s][info][gc] GC(11) Concurrent Cycle
[17.822s][info][gc] GC(12) Pause Young (Normal) (G1 Evacuation Pause) 23M->23M(32M) 1.129ms
[17.830s][info][gc] GC(13) Pause Young (Normal) (G1 Evacuation Pause) 24M->24M(32M) 1.426ms
[17.836s][info][gc] GC(14) Pause Young (Normal) (G1 Evacuation Pause) 25M->25M(32M) 1.050ms
[17.843s][info][gc] GC(15) Pause Young (Normal) (G1 Evacuation Pause) 26M->26M(32M) 1.195ms
[17.853s][info][gc] GC(11) Pause Remark 27M->27M(32M) 3.820ms
[17.855s][info][gc] GC(16) Pause Young (Normal) (G1 Evacuation Pause) 27M->26M(32M) 1.672ms
[17.858s][info][gc] GC(17) Pause Young (Normal) (G1 Evacuation Pause) 27M->26M(32M) 1.069ms
[17.869s][info][gc] GC(18) Pause Young (Normal) (G1 Evacuation Pause) 27M->27M(32M) 1.121ms
[17.872s][info][gc] GC(19) Pause Young (Normal) (G1 Evacuation Pause) 28M->27M(32M) 0.811ms
[17.876s][info][gc] GC(20) Pause Young (Normal) (G1 Evacuation Pause) 28M->28M(32M) 0.867ms
[17.878s][info][gc] GC(11) Pause Cleanup 29M->29M(32M) 0.029ms
[17.879s][info][gc] GC(21) Pause Young (Prepare Mixed) (G1 Evacuation Pause) 29M->28M(32M) 0.905ms
[17.879s][info][gc] GC(11) Concurrent Cycle 60.929ms
[17.885s][info][gc] GC(22) To-space exhausted
[17.885s][info][gc] GC(22) Pause Young (Mixed) (G1 Evacuation Pause) 29M->30M(32M) 2.788ms
[17.891s][info][gc] GC(23) To-space exhausted
[17.891s][info][gc] GC(23) Pause Young (Concurrent Start) (G1 Evacuation Pause) 31M->31M(32M) 2.017ms
[17.891s][info][gc] GC(25) Concurrent Cycle
[17.915s][info][gc] GC(24) Pause Full (G1 Evacuation Pause) 31M->24M(32M) 24.037ms
[17.915s][info][gc] GC(25) Concurrent Cycle 24.201ms
[17.918s][info][gc] GC(26) Pause Young (Normal) (G1 Evacuation Pause) 25M->25M(32M) 0.881ms
[17.921s][info][gc] GC(27) Pause Young (Concurrent Start) (G1 Evacuation Pause) 26M->25M(32M) 1.092ms
[17.921s][info][gc] GC(28) Concurrent Cycle
[17.924s][info][gc] GC(29) Pause Young (Normal) (G1 Evacuation Pause) 26M->25M(32M) 0.842ms
[17.931s][info][gc] GC(30) Pause Young (Normal) (G1 Evacuation Pause) 26M->26M(32M) 2.357ms
[17.933s][info][gc] GC(31) Pause Young (Normal) (G1 Evacuation Pause) 27M->26M(32M) 1.058ms
[17.936s][info][gc] GC(32) Pause Young (Normal) (G1 Evacuation Pause) 27M->26M(32M) 0.966ms
[17.941s][info][gc] GC(33) Pause Young (Normal) (G1 Evacuation Pause) 27M->27M(32M) 0.911ms
[17.954s][info][gc] GC(34) Pause Young (Normal) (G1 Evacuation Pause) 28M->27M(32M) 1.532ms
[17.961s][info][gc] GC(35) To-space exhausted
[17.961s][info][gc] GC(35) Pause Young (Normal) (G1 Evacuation Pause) 28M->29M(32M) 1.326ms
[17.967s][info][gc] GC(36) To-space exhausted
[17.967s][info][gc] GC(36) Pause Young (Normal) (G1 Evacuation Pause) 30M->30M(32M) 1.425ms
[17.989s][info][gc] GC(37) Pause Full (G1 Evacuation Pause) 30M->28M(32M) 22.554ms
[17.989s][info][gc] GC(28) Concurrent Cycle 68.160ms
[17.993s][info][gc] GC(38) Pause Young (Normal) (G1 Evacuation Pause) 29M->29M(32M) 0.951ms
[17.997s][info][gc] GC(39) To-space exhausted
[17.997s][info][gc] GC(39) Pause Young (Concurrent Start) (G1 Evacuation Pause) 30M->30M(32M) 1.763ms
[17.997s][info][gc] GC(41) Concurrent Cycle
[18.020s][info][gc] GC(40) Pause Full (G1 Evacuation Pause) 30M->29M(32M) 22.459ms
[18.020s][info][gc] GC(41) Concurrent Cycle 22.538ms
[18.028s][info][gc] GC(42) To-space exhausted
[18.028s][info][gc] GC(42) Pause Young (Normal) (G1 Evacuation Pause) 30M->30M(32M) 1.399ms
[18.049s][info][gc] GC(43) Pause Full (G1 Evacuation Pause) 30M->30M(32M) 21.067ms
[18.058s][info][gc] GC(44) To-space exhausted
[18.058s][info][gc] GC(44) Pause Young (Concurrent Start) (G1 Evacuation Pause) 31M->31M(32M) 1.830ms
[18.058s][info][gc] GC(46) Concurrent Cycle
[18.080s][info][gc] GC(45) Pause Full (G1 Evacuation Pause) 31M->30M(32M) 22.113ms
[18.080s][info][gc] GC(46) Concurrent Cycle 22.213ms
[18.169s][info][gc] GC(47) To-space exhausted
[18.169s][info][gc] GC(47) Pause Young (Normal) (G1 Evacuation Pause) 31M->31M(32M) 87.776ms
[18.192s][info][gc] GC(48) Pause Full (G1 Evacuation Pause) 31M->30M(32M) 22.622ms
[18.214s][info][gc] GC(49) Pause Full (G1 Evacuation Pause) 30M->30M(32M) 22.480ms
[18.216s][info][gc] GC(50) Pause Young (Concurrent Start) (G1 Evacuation Pause) 30M->30M(32M) 1.112ms
[18.216s][info][gc] GC(52) Concurrent Cycle
[18.241s][info][gc] GC(51) Pause Full (G1 Evacuation Pause) 30M->30M(32M) 25.469ms
[18.266s][info][gc] GC(53) Pause Full (G1 Evacuation Pause) 30M->30M(32M) 24.480ms
[18.266s][info][gc] GC(52) Concurrent Cycle 50.062ms
[18.267s][info][gc] GC(54) Pause Young (Normal) (G1 Evacuation Pause) 30M->30M(32M) 0.681ms
[18.293s][info][gc] GC(55) Pause Full (G1 Evacuation Pause) 30M->30M(32M) 25.581ms
[18.316s][info][gc] GC(56) Pause Full (G1 Evacuation Pause) 30M->30M(32M) 22.917ms
[18.317s][info][gc] GC(57) Pause Young (Concurrent Start) (G1 Evacuation Pause) 30M->30M(32M) 1.170ms
[18.317s][info][gc] GC(59) Concurrent Cycle
[18.342s][info][gc] GC(58) Pause Full (G1 Evacuation Pause) 30M->30M(32M) 24.189ms
[18.365s][info][gc] GC(60) Pause Full (G1 Evacuation Pause) 30M->30M(32M) 23.685ms
[18.365s][info][gc] GC(59) Concurrent Cycle 48.004ms
[18.366s][info][gc] GC(61) Pause Young (Normal) (G1 Evacuation Pause) 30M->30M(32M) 0.810ms
[18.393s][info][gc] GC(62) Pause Full (G1 Evacuation Pause) 30M->30M(32M) 26.309ms
[18.419s][info][gc] GC(63) Pause Full (G1 Evacuation Pause) 30M->30M(32M) 26.395ms
[18.421s][info][gc] GC(64) Pause Young (Concurrent Start) (G1 Evacuation Pause) 30M->30M(32M) 0.978ms
[18.421s][info][gc] GC(66) Concurrent Cycle
[18.447s][info][gc] GC(65) Pause Full (G1 Evacuation Pause) 30M->30M(32M) 26.732ms
[18.473s][info][gc] GC(67) Pause Full (G1 Evacuation Pause) 30M->30M(32M) 25.213ms
[18.473s][info][gc] GC(66) Concurrent Cycle 52.098ms
[18.474s][info][gc] GC(68) Pause Young (Normal) (G1 Evacuation Pause) 30M->30M(32M) 1.288ms
[18.503s][info][gc] GC(69) Pause Full (G1 Evacuation Pause) 30M->30M(32M) 28.438ms
[18.526s][info][gc] GC(70) Pause Full (G1 Evacuation Pause) 30M->30M(32M) 22.862ms
[18.527s][info][gc] GC(71) Pause Young (Concurrent Start) (G1 Evacuation Pause) 30M->30M(32M) 1.047ms
[18.527s][info][gc] GC(73) Concurrent Cycle
[18.551s][info][gc] GC(72) Pause Full (G1 Evacuation Pause) 30M->30M(32M) 24.183ms
[18.572s][info][gc] GC(74) Pause Full (G1 Evacuation Pause) 30M->30M(32M) 21.006ms
[18.573s][info][gc] GC(73) Concurrent Cycle 45.322ms
[18.574s][info][gc] GC(75) Pause Young (Normal) (G1 Evacuation Pause) 30M->30M(32M) 0.711ms
[18.598s][info][gc] GC(76) Pause Full (G1 Evacuation Pause) 30M->30M(32M) 24.588ms
Copy the code

You can see that Full GC occurs frequently.

7.4 tuning

The easiest way to resolve frequent Full GC occurrences is to increase the heap memory and start Tomcat again with the following parameters:

export CATALINA_OPTS="-Xlog:gc:gc.log -Xmx256m -Xms32m -XX:ParallelGCThreads=4"
Copy the code

The log is as follows:

[0.024s][info][GC] Using G1 [0.278s][info][GC] GC(0) Pause Young (Normal) (G1 Evacuation Pause) 14M->3M(32M) 2.545ms [0.355s][info][GC] GC(1) Pause Young (Normal) (G1 Evacuation Pause) 7M->4M(32M) 2.359ms [0.485s][info][GC] GC(2) Pause Young (Normal) (G1 Evacuation Pause) 13M->5M(32M) 1.345ms [0.595s][info][GC] GC(3) Pause Young (Normal) (G1 Evacuation Pause) Pause) 15M->6M(32M) 2.102ms [0.686s][info][GC] GC(4) Pause Young (Concurrent Start) (Metadata GC Threshold) 16M->7M(32M) 3.140ms [0.686s][info][GC] GC(5) Concurrent Cycle [0.696s][info][GC] GC(5) Pause Remark 8M->8M(32M) 2.647ms [0.700s][info][GC] GC(5) Pause Cleanup 8M->8M(32M) 0.019ms [0.700s][info][GC] GC(5) Concurrent Cycle 13.683ms [0.761s][INFO][GC] GC(6) Pause Young (Normal) (G1 Evacuation Pause) 17M->8M(32M) 1.689ms [0.835s][INFO][GC] GC(7) Pause Young (Normal) (G1 Evacuation Pause) 19M->8M(32M) 1.680ms [11.813s][info][GC] GC(8) Pause Young (Normal) (G1 Evacuation Pause) Pause) 19M->11M(32M) 2.670ms [11.890s][info][GC] GC(9) Pause Young (Normal) (G1 Evacuation Pause) 21M->17M(32M) 4.077ms [11.907s][INFO][GC] GC(10) Pause Young (Concurrent Start) (G1 Evacuation Pause) 22M->21M(32M) 1.528ms [11.907s][INFO][GC] GC(11) Concurrent Cycle [11.917s][INFO][GC] GC(12) Pause Young (Normal) (G1 Evacuation Pause) 23M->23M(32M) 1.918ms [11.921s][info][GC] GC(13) Pause Young (Normal) (G1 Evacuation Pause) 24M->24M(32M) 0.955ms [11.926s][info][GC] GC(14) Pause Young (Normal) (G1 Evacuation Pause) 25M->24M(32M) 0.733ms [11.930s][info][GC] GC(15) Pause Young (Normal) (G1 Evacuation Pause) 25M->25M(32M) 0.769ms [11.934s][info][GC] GC(11) Pause Remark 25M->25M(32M) 3.490ms [11.937s][info][GC] GC(16) Pause Young (Normal) (G1 Evacuation Pause) 26M->25M(32M) 0.787ms [11.945s][info][GC] GC(17) Pause Young (Normal) (G1 Evacuation Pause) 26M->25M(32M) 0.893ms [11.949s][info][GC] GC(18) Pause Young (Normal) (G1 Evacuation Pause) 26M->26M(32M) 0.911ms [11.949s][info][GC] GC(11) Pause Cleanup 26M->26M(32M) 0.029ms [11.950s][INFO][GC] GC(11) Concurrent Cycle 42.921ms [11.962s][INFO][GC] GC(19) Pause Young (Normal) (G1 Evacuation) Pause) 27M->26M(32M) 0.855ms [11.971s][info][GC] GC(20) Pause Young (Concurrent Start) (G1 Evacuation Pause) 27M->27M(32M) 1.335ms [11.971s][info][GC] GC(21) Concurrent Cycle [11.978s][info][GC] GC(22) Pause Young (Normal) (G1 Evacuation Pause) 28M->28M(32M) 0.853ms [11.981s][info][GC] GC(23) Pause Young (Normal) (G1 Evacuation Pause) 29M->28M(32M) 0.777ms [11.984s][info][GC] GC(24) Pause Young (Normal) (G1 Evacuation Pause) 29M->29M(64M) 0.944ms [info][GC] GC(21) Pause Remark Cleanup 39M->39M(64M) 3.139ms [12.032s][info][GC] GC(21) Pause Cleanup 39M->39M(64M) 0.041ms [12.036s][info][GC] GC(25) Pause Young (Normal) (G1 Evacuation Pause) 39M->32M(64M) 3.190ms [12.037s][info][GC] GC(21) Concurrent Cycle 65.196ms [12.096s][info][GC] GC(26) Pause Young (Normal) (G1 Evacuation Pause) 41M->34M(64M) 2.597ms [12.150s][info][GC] GC(27) Pause Young (Concurrent Start) (G1 Evacuation Pause) 43M->37M(64M) 2.926ms [12.150s][info][GC] GC(28) Concurrent Cycle [12.246s][info][GC] GC(28) Pause Remark 42M->42M(64M) 73.769ms [12.263s][INFO][GC] GC(29) Pause Young (Normal) (G1 Evacuation Pause) 45M->38M(109M) 2.864ms [12.263s][info][GC] GC(28) [info][GC] GC(28) Concurrent Cycle 117.019ms [12.341s][info][GC] GC(30) Concurrent Cycle 117.019ms [12.341s] Pause Young (Normal) (G1 Evacuation Pause) 59M->40M(109M) 3.691ms [12.468s][info][GC] GC(31) Pause Young (Normal) (G1 Evacuation Pause) 72M->44M(109M) 3.743ms [12.594s][info][GC] GC(32) Pause Young (Normal) (G1 Evacuation Pause) 76M->47M(109M) 3.134ms [12.764s][info][GC] GC(33) Pause Young (Normal) (G1 Evacuation Pause) 79M->48M(109M) 2.044ms [12.855s][info][GC] GC(34) Pause Young (Normal) (G1 Evacuation Pause) 80M->48M(109M) 2.071ms [12.949s][info][GC] GC(35) Pause Young (Normal) (G1 Evacuation Pause) 82M->48M(109M) 1.615ms [13.035s][info][GC] GC(36) Pause Young (Normal) (G1) Evacuation Pause) 3m ->48M(109M) 1.681ms [13.133s][info][GC] GC(37) Pause Young (Normal) (G1 Evacuation Pause) 83M->50M(109M) 3.947ms [13.214s][info][GC] GC(38) Pause Young (Normal) (G1 Evacuation Pause) 855m ->50M(109M) 3.206ms [13.285s][info][GC] GC(39) Pause Young (Normal) (G1 Evacuation Pause) 855m ->50M(109M) 2.009ms [13.362s][info][GC] GC(40) Pause Young (Normal) (G1 Evacuation Pause) 87M->50M(109M) 2.705ms [13.454s][info][GC] GC(41) Pause Young (Normal) (G1) Evacuation Pause) 90 m - > 50 m (109 m) 3.772 msCopy the code

Throughput of 1.4W per second:

After the heap size is increased, it is obvious that the number of GC is reduced without Full GC. At this time, the concurrency can be increased to observe the performance bottleneck. For example, the number of threads can be increased to 2000 and the number of cycles remains the same:

Again, the log looks like this (the last 50 lines) :

[7.554s][info][GC] GC(73) Pause Young (Concurrent Start) (G1 Evacuation Pause) 114M->82M(132M) 1.920ms [info][GC] GC(74) Concurrent Cycle [7.590s][info][GC] GC(74) Pause Remark 99M->99M(132M) 4.054ms [info][GC] GC(74) Pause Cleanup 113M->113M(132M) 0.089ms [7.620s][info][GC] GC(74) Concurrent Cycle 66.09ms [7.624s][info][GC] GC(75) Pause Young (Normal) (G1 Evacuation Pause) 114M->82M(132M) 2.885ms [7.677s][info][GC] GC(76) Pause Young (Concurrent Start) (G1 Evacuation Pause) 114M->82M(132M) 2.369ms [7.677s][info][GC] GC(77) Concurrent Cycle [7.730s][info][GC] GC(78) Pause Young (Normal) (G1 Evacuation Pause) 114M->82M(132M) 2.615ms [7.756s][info][GC] GC(77) Pause Remark 95M->95M(132M) 2.964ms [7.793s][info][GC] GC(79) Pause Young (Normal) (G1 Evacuation Pause) 114M->82M(132M) 5.707ms [7.811s][info][GC] GC(77) Pause Cleanup 92M->92M(132M) 0.255ms [7.812s][info][GC] GC(77) Concurrent Cycle 134.823ms [7.854s][info][GC] GC(80) Pause Young (Normal) (G1 Evacuation Pause) 114M->82M(132M) 2.604ms [7.912s][info][GC] GC(81) Pause Young (Concurrent Start) (G1 Evacuation Pause) 114M->82M(132M) 1.952ms [7.912s][info][GC] GC(82) Concurrent Cycle [7.940s][info][GC] GC(82) Pause Remark 94M->94M(132M) 3.422ms [info][GC] GC(82) Pause Cleanup 105M->105M(132M) 0.06ms [7.960s][info][GC] GC(82) Concurrent Cycle 47.595ms [7.976s][info][GC] GC(83) Pause Young (Prepare Mixed) (G1 Evacuation Pause) 114M->81M(132M) 2.423ms [7.985s][info][GC] GC(84) Pause Young (Mixed) (G1 Evacuation Pause) 86M->81M(132M) 1.495ms [8.038s][info][GC] GC(85) Pause Young (Concurrent Start) (G1 Evacuation Pause) 113M->81M(132M) 2.309ms [8.038s][info][GC] GC(86) Concurrent Cycle [info][GC] GC(86) Pause Remark 104M->104M(132M) 3.507ms [8.098s][info][GC] GC(87) Pause Young (Normal) (G1 Evacuation Pause) 114M->81M(132M) 3.336ms [8.106s][info][GC] GC(86) Pause Cleanup 86M->86M(132M) 0.112ms [info][GC] GC(86) Concurrent Cycle 67.767ms [8.148s][info][GC] GC(88) Pause Young (Normal) (G1 Evacuation Pause) 114M->81M(132M) 2.621ms [8.205s][info][GC] GC(89) Pause Young (Concurrent Start) (G1 Evacuation Pause) 114M->81M(132M) 2.943ms [8.205s][INFO][GC] GC(90) Concurrent Cycle [8.263s][INFO][GC] GC(91) Pause Young (Normal) (G1 Evacuation Pause) 114M->81M(132M) 2.117ms [8.274s][info][GC] GC(90) Pause Remark 84M->84M(132M) 4.372ms [8.309s][info][GC] GC(90) Pause Remark Cleanup 102M->102M(132M) 0.082ms [8.309s][info][GC] GC(90) Concurrent Cycle 103.562ms [8.331s][info][GC] GC(92) Pause Young (Prepare Mixed) (G1 Evacuation Pause) 114M->81M(132M) 2.712ms [8.342s][info][GC] GC(93) Pause Young (Mixed) (G1 Evacuation Pause) 86M->80M(132M) 1.982ms [8.392s][info][GC] GC(94) Pause Young (Normal) (G1 Evacuation Pause) 114M->80M(132M) 1.921ms [8.437s][info][GC] GC(95) Pause Young (Normal) (G1 Evacuation Pause) 114M->80M(132M) 1.980ms [8.487s][info][GC] GC(96) Pause Young (Normal) (G1 Evacuation Pause) 114M->80M(132M) 1.965ms [8.528s][info][GC] GC(97) Pause Young (Normal) (G1 Evacuation Pause) 114M->80M(132M) 1.959ms [8.600s][info][GC] GC(98) Pause Young (Normal) (G1 Evacuation Pause) 114M->80M(132M) 5.305ms [8.655s][info][GC] GC(99) Pause Young (Normal) (G1 Evacuation Pause) 115M->80M(132M) 2.709ms [8.709s][info][GC] GC(100) Pause Young (Normal) (G1 Evacuation Pause) 115M->80M(132M) 1.762ms [info][GC] GC(101) Pause Young (Normal) (G1 Evacuation Pause) 115M->80M(132M) 1.767ms [8.801s][info][GC] GC(102) Pause Young (Normal) (G1 Evacuation Pause) 115M->80M(132M) 1.739ms [8.850s][info][GC] GC(103) Pause Young (Normal) (G1 Evacuation Pause) 115M->80M(132M) 1.696ms [8.899s][info][GC] GC(104) Pause Young (Normal) (G1 Evacuation Pause) 115M->80M(132M) 1.499ms [8.952s][info][GC] GC(105) Pause Young (Normal) (G1 Evacuation Pause) 115M->80M(132M) 1.289ms [8.999s][info][GC] GC(106) Pause Young (Normal) (G1 Evacuation Pause) 115M->80M(132M) 1.219ms [9.043s][info][GC] GC(107) Pause Young (Normal) (G1 Evacuation Pause) 115M->80M(132M) 1.110msCopy the code

Throughput of 2.3W per second:

With the same parameter, increase the number of threads and the throughput increases, indicating that the performance bottleneck has not been reached, increase the number of concurrent threads again:

The log is as follows:

[58.313s][info][GC] GC(354) Pause Young (Normal) (G1 Evacuation Pause) 217M->209M(241M) 3.415ms [58.328s][info][GC] GC(355) Pause Young (Normal) (G1 Evacuation Pause) 220M->210M(241M) 1.408ms [58.354s][info][GC] GC(356) Pause Young (Normal) (G1 Evacuation Pause) 220M->210M(241M) 4.860ms [58.378s][info][GC] GC(353) Pause Remark 221M->221M(241M) 5.735ms [58.392s][INFO][GC] GC(357) Pause Young (Normal) (G1 Evacuation Pause) 221M->210M(241M) 1.799ms [58.401s][info][gc] gc (353) Pause Cleanup 218M->218M(241M) 0.430ms [58.401s][info][GC] GC(353) Concurrent Cycle 109.426ms [58.416s][info][GC] GC(358) Pause Young (Prepare Mixed) (G1 Evacuation Pause) 221M->210M(241M) 1.584ms [58.431s][info][GC] GC(359) Pause Young (Mixed) (G1 Evacuation Pause) 221M->187M(241M) 1.880ms [58.463s][info][GC] GC(360) Pause Young (Mixed) (G1 Evacuation Pause) 197M->165M(244M) 2.684ms [58.485s][info][GC] GC(361) Pause Young (Mixed) (G1 Evacuation Pause) 175M->144M(244M) 4.659ms [58.505s][info][GC] GC(362) Pause Young (Mixed) (G1 Evacuation Pause) Pause) 154M->124M(244M) 5.943ms [58.522s][info][GC] GC(363) Pause Young (Mixed) (G1 Evacuation Pause) 134M->118M(244M) 3.665ms [58.640s][info][GC] GC(364) Pause Young (Normal) (G1 Evacuation Pause) 163M->119M(247M) 3.835ms [58.722s][info][GC] GC(365) Pause Young (Normal) (G1 Evacuation Pause) 170M->119M(247M) 1.531ms [58.823s][info][GC] GC(366) Pause Young (Normal) (G1 Evacuation Pause) 178M->119M(247M) 1.982ms [58.926s][info][GC] GC(367) Pause Young (Normal) (G1 Evacuation Pause) 185M->120M(247M) 2.277ms [59.023s][info][GC] GC(368) Pause Young (Normal) (G1 Evacuation Pause) Pause) 191M->120M(247M) 3.918ms [59.192s][info][GC] GC(369) Pause Young (Normal) (G1 Evacuation Pause) 194M->120M(247M) 2.634ms [59.346s][info][GC] GC(370) Pause Young (Normal) (G1 Evacuation Pause) 205M->120M(247M) 2.053ms [59.479s][info][GC] GC(371) Pause Young (Normal) (G1 Evacuation Pause) 206M->120M(247M) 2.384ms [59.615s][info][GC] GC(372) Pause Young (Normal) (G1 Evacuation Pause) 207M->120M(247M) 3.700ms [59.733s][info][GC] GC(373) Pause Young (Normal) (G1 Evacuation Pause) 207M->120M(247M) 6.038ms [59.917s][info][GC] GC(374) Pause Young (Normal) (G1 Evacuation Pause) Pause) 208M->120M(247M) 2.311ms [60.062s][info][GC] GC(375) Pause Young (Normal) (G1 Evacuation Pause) 209M->120M(247M) 2.319ms [60.197s][info][GC] GC(376) Pause Young (Normal) (G1 Evacuation Pause) 210M->120M(247M) 2.315ms [info][GC] GC(377) Pause Young (Normal) (G1 Evacuation Pause) 210M->120M(247M) 3.419ms [60.456s][info][GC] GC(378) Pause Young (Normal) (G1 Evacuation Pause) 212M->120M(247M) 2.019ms [60.638s][info][GC] GC(379) Pause Young (Normal) (G1 Evacuation Pause) 212M->120M(247M) 2.782ms [60.799s][info][GC] GC(380) Pause Young (Normal) (G1 Evacuation Pause) Pause) 212M->120M(247M) 2.341ms [60.947s][info][GC] GC(381) Pause Young (Normal) (G1 Evacuation Pause) 213M->120M(247M) 2.954ms [61.102s][info][GC] GC(382) Pause Young (Normal) (G1 Evacuation Pause) 217M->120M(247M) 2.598ms [61.234s][info][GC] GC(383) Pause Young (Concurrent Start) (G1 Evacuation Pause) 216M->120M(247M) 2.340ms [info][GC] GC(384) Concurrent Cycle [61.271s][info][GC] GC(384) Pause Remark 133M->133M(247M) 4.457ms [info][GC] GC(384) Pause Cleanup 135M->135M(247M) 0.171ms [61.288s][info][GC] GC(384) Concurrent Cycle 53.972ms [61.444s][info][GC] GC(385) Pause Young (Prepare Mixed) (G1 Evacuation Pause) 216M->120M(247M) 2.913ms [info][GC] GC(386) Pause Young (Mixed) (G1 Evacuation Pause) 131M->103M(247M) 3.910ms [61.486s][info][GC] GC(387) Pause Young (Mixed) (G1 Evacuation Pause) 114M->95M(247M) 3.828ms [61.684s][info][GC] GC(388) Pause Young (Normal) (G1 Evacuation Pause) 200M->95M(247M) 2.013ms [61.881s][info][GC] GC(389) Pause Young (Normal) (G1 Evacuation Pause) Pause) 215M->95M(247M) 2.089ms [62.073s][info][GC] GC(390) Pause Young (Concurrent Start) (G1 Evacuation Pause) 217M->95M(247M) 2.686ms [62.073s][info][GC] GC(391) Concurrent Cycle [62.103s][info][GC] GC(391) Pause Remark 106M->106M(247M) 106M->106M(247M) 106M->106M(247M) 106M->106M(247M) 106M->106M(247M) 106M->106M(247M) 106M->106M(247M) [info][gc] Concurrent Cycle 49.728ms [62.334s][info][GC] GC(392) Pause Young (Prepare Mixed) (G1 Evacuation Pause) 217M->95M(247M) 2.472ms [62.348s][info][GC] GC(393) Pause Young (Mixed) (G1 Evacuation Pause) 106M->75M(247M) 1.981ms [62.363s][info][GC] GC(394) Pause Young (Mixed) (G1 Evacuation Pause) 86M->59M(247M) 3.422msCopy the code

Throughput 2.7W:

Due to space constraints, other methods will not be described, but if you want to further improve throughput, you can start from the following aspects:

• Tuning heap memory:-Xmx1g
• Use more threads:-XX:ParallelGCThreads=8
• Set larger initial heap memory:-Xms512m
• Set larger New generation:-XX:G1NewSizePercent+-XX:G1MaxNewSizePercent

Appendix I: Some details of recycling are discussed

8.1 Disabling ExplicitGC

Typically, system.gc () triggers the Full GC, collecting both old and new generations, and the JVM provides a DisableExplicitGC to control whether or not the GC can be triggered explicitly. System.gc() is a native method with the source code in jvm.cpp:

If disabled, it is an empty implementation, that is, nothing is executed.

8.2 the explicitGCUsing concurrent collection

By default, if system.gc () is in effect, the traditional Full GC is used and UseG1GC and UseConcMarkSweepGC are ignored. CMS/G1 is not executed concurrently. If you use – XX: + ExplicitGCInvokesConcurrent, will change this default behavior.

For example:

public static void main(String[] args){
    byte [] b = new byte[1024*1024*10];
    System.gc();
}
Copy the code

With parameters:

-Xlog:gc*,gc+marking*=debug,gc+heap=debug
-Xmx30m
Copy the code

Full GC is triggered:

And if add – XX: + ExplicitGCInvokesConcurrent, not happen Full GC, but using the G1 concurrent GC:

8.3 How can the target be promoted to the old age

There are several ways for an object to be promoted to the old age:

• Promotion through age: insurvivorAfter surviving to a certain age (the default is 15), they will enter the old age, but it needs to be noted that the actual promotion age of the object is fromsurvivorThat is to say, by default, people who reach the age of 15 will be promoted to the old age, but those who do not reach that age can also be promoted and can pass-XX:MaxTenuringThresoldSet promotion age,
• Promotion by size: If the object is big, big enoughedenArea andsurvivorDistricts can not accommodate, will be directly promoted to the old age, can pass-XX:PreteureSizeThresholdSet, in bytes

8.4 aboutTLAB

TLAB (Thread Local Allocation Buffer) is a thread-specific memory Allocation area. Used to speed up the distribution of the object is the cause of the region, although object is allocated on the heap, all threads and heap is Shared, there may be multiple threads at the same time the application heap space, easy to cause conflict, and object allocation is a very common operation, so the Java provides TLAB to avoid conflict when allocating objects thread, improve the efficiency of object allocation. With TLAB enabled, the virtual machine allocates a TLAB area for each Java thread.

8.4.1 A simple test

Test code:

public static void main(String[] args){
    long start = System.nanoTime();
    for (int i = 0; i < 1 _0000_0000; i++) {
        byte [] b = new byte[2];
        b[0] = 1;
    }
    long end = System.nanoTime();
    System.out.println(end-start);
}
Copy the code

Parameters:

-server -XX:+UseTLAB -Xcomp -XX:-BackgroundCompilation -XX:+DoEscapeAnalysis
Copy the code

Output:

1013561
Copy the code

Modify parameters to close TLAB:

-server -XX:-UseTLAB -Xcomp -XX:-BackgroundCompilation -XX:+DoEscapeAnalysis
Copy the code

Output:

3154586
Copy the code

As you can see, the time it takes to turn TLAB on is about a third of the time it takes to turn TLAB off.

8.4.2 Object Assignment

As can be seen from the above experiment, TLAB has a great influence on object allocation. However, because TLAB space is usually relatively small, it is easy to fill up. For example, TLAB is 100KB, and 80KB has been used, if you need to allocate a 30KB object, then there are two methods:

• Abandon the currentTLABArea: is to apply for a piece againTLABBut it would be a waste of timeTLABThe rest of the20KB
• Allocate directly to the heap: keep currentTLABIn the future, if there is less than20KBObject can use the rest directly20KB

Therefore, the JVM maintains a value called refill_waste:

• When the requested object is greater thanrefill_waste, will choose heap allocation
• If the value is smaller than this value, the current value is discardedTLAB, the newly builtTLABTo assign a new object

By default, both TLAB and refill_waste sizes are constantly adjusted at run time for optimal system health.

After the introduction of TLAB, the object allocation process is as follows:

9 Appendix II: Common UsageGCParameters of the summary

9.1 Parameters related to serial collector

• -XX:+UseSerialGC: New generation and old generation use serial collector
• -XX:SurvivorRatioSet:edenArea andsurvivorZone size ratio
• -XX:PretenureSizeThreshold: Sets the threshold for the large object to enter the old age. If the threshold exceeds the threshold, the object will be allocated to the old age
• -XX:MaxTenuringThreshold: Sets the maximum number of years the object enters each timeMinor GCThe age of the last object increases by one, and any object older than that age goes into the old age

9.2 Parameters related to parallel Collector

• -XX:+UseParNewGC: The new generation uses parallel collector, the old generation uses serial collector (JDK9+Deleted)
• -XX:+UseParallelOldGC: Used in the old daysParallelOldGCNew generation useParallelGC
• -XX:+ParallelGCThreads: Sets the number of threads used for garbage collection
• -XX:MaxGCPauseMills: Maximum garbage collection pause time, an integer greater than 0
• -XX:GCTimeRatio: Sets the throughput size, one0-100.The integer
• -XX:+UseAdaptiveSizePolicy: Open adaptive strategies, Cenozoic size,edenArea andsurvivorThe ratio of districts and age parameters of objects promoted to the old age will be adjusted dynamically

9.3 CMSRelated parameters

• -XX:+UseConcMarkSweepGC: The new generation uses parallel collector, the old generation uses itCMS+ serial collector
• -XX:ParallelCMSThreadsSetting:CMSNumber of threads
• -XX:CMSInitiatingOccupancyFraction: sets how much garbage collection is triggered after the old space is used. The default is usage68%
• -XX:+UseCMSCompactAtFullCollection: Sets whether memory defragmentation is required after garbage collection
• -XX:CMSFullGCsBeforeCompaction: Set the number of timesCMSAfter that, perform a memory compression
• -XX:+CMSClassUnloadingEnabled: allows collection of class metadata areas
• -XX:CMSInitiatingPermOccupancyFraction: When the permanent area occupation rate reaches the specified percentage, perform the operation onceCMS GC, premise open-XX:+CMSClassUnloadingEnabled
• -XX:+CMSIncrementalMode: Using incremental mode (JDK9Remove)

9.4 G1Related parameters

• -XX:+UseG1GCOpen:G1
• -XX:MaxGCPauseMills: Sets the maximum garbage collection pause time
• -XX:GCPauseIntervalMills: Sets the pause interval

9.5 TLABRelated parameters

• -XX:+UseTLABOpen:TLAB
• -XX:+PrintTLAB: Print relevant information (JDK9Does not support)
• -XX:TLABSizeSet:TLABThe area size
• -XX:+ResizeTLAB: automatic adjustmentTLABThe size of the

9.6 Other Parameters

• -XX:+DisableExplicitGC: Disables explicitGC
• -XX:+ExplicitGCInvokesConcurrent: Uses concurrency to handle explicitGC

10 reference

• Gold -JVM principle of GC garbage collector CMS details
• Understanding Java Garbage Collection Logging: What Are GC Logs and How To Analyze Them