JVM log output description

Post address: http://www.iteye.com/topic/603347

In large-scale Java applications, it is essential to optimize the program and specify a suitable garbage collection mechanism. How can we determine whether a GC optimizes the program? We can view the GC logs printed by JVM for analysis and further optimization. At present, no article explicitly specifies the format of the logs printed by various GC algorithms in Java, and how to read. So next, this article will try to introduce various garbage collection mechanisms and explain the log formats under this mechanism.

1. Garbage collection Algorithm
1.1 reference counting collector)
The system records the number of times an object is applied. When the number of applications is 0, the memory occupied by this object can be recycled. This algorithm does not need to be suspended, but the disadvantage is that it cannot solve the problem of repeated use. Therefore, Java does not provide such garbage collectors.
1.2Tracing Algorithm (tracing collector)
The garbage collector of the tracing algorithm scans from the root set to identify which objects are reachable and which objects are inaccessible, and marks the reachable objects in some way.
1.2.1Copy Algorithm
The replication algorithm divides the heap into two regions. One region contains the current data object (tospace), and the Other region contains the discarded data (fromspace ). The replication algorithm copies the surviving objects from fromspace to tospace, and then switches the fromspace and tospace pointers. The previous fromspace changes to the current tospace region.
1.2.2Mark-compact Algorithm

1.2.3 mark-clear (mark-sweep)
Using the-xx flags for our collectors for jdk6,

• Useserialgc is "serial" + "Serial old"
• Useparnewgc is "parnew" + "Serial old"
  
• Useconcmarksweepgc is "parnew" + "CMS" + "Serial old ". "CMS" is used most of the time to collect the tenured generation. "Serial old" is used when a concurrent mode failure occurs.
  
• Useparallelgc is "parallel scavenge" + "Serial old"
  
• Useparalleloldgc is "parallel scavenge" + "parallel old"

 

Serailgc

1, serial young GC
0.246: [GC 0.246: [defnew: 1403 K-> 105 K (1984 K), 0.0109275 secs] 1403 K-> 1277 K (6080 K), 0.0110143 secs]
2, serial OLG GC

1.133: [GC 1.133: [defnew: 960 K-> 64 K (960 K), 0.0012208 secs] 1.135: [tenured: 7334 K-> 7142 K (7424 K ), 0.0213756 secs] 7884 K-> 7142 K (8384 K), [perm: 364 K-> 364 K (12288 K)], 0.0226997 secs] [times:
User = 0.01 sys = 0.00, real = 0.02 secs]

 

Parrallel GCThe enhanced version of serailgc to adapt to Muti core is to use parallel collection during minorgc, while fullgc has not changed.

Parralllel compacting GC
Based on parrallelgc, fullgc also becomes concurrent with the parallel compacting collector, the old and permanent generations are collected in a stop-theworld, mostly parallel fashion with sliding compaction. the collector utilizes three phases. first,
Each generation is logically divided into fixed-sized regions. in the marking phase, the initial set of live objects directly reachable from the application code is divided among garbage collection threads, and then all live objects are marked in parallel.
As an object is identified as live, the data for the region it is in is updated with information about the size and location of the object. remarks to be translated

 

Concurrent mark-sweep (CMS) CollectorOne requirement is that the corresponding time of the application is more important than the application throughput. To meet this requirement, JVM provides the Garbage Collector CMS in this scenario, minorgc and parralelgc use the same garbage collector, but different algorithms are replaced in the old generation.

CMS divides the recovery of the old generation into four stages, of which only two stages are to stop-the-world, And the rest stages are not required, thus reducing the system suspension time, the disadvantage is that in the remaining two phases, more applications will compete for JVM resources.

 

As you can see, the CMS running process.

A collection cycle for the CMS collector starts with a short pause, called the initial mark, thatidentifies the initial set of live objects directly reachable from the application code. then, during the concurrent marking phase, the collector marks all live objects that are transitivelyreachable from this set. because the application is running and updating reference fields while the marking phase is taking place, not all live objects are guaranteed to be marked at the end of
Concurrent marking phase. to handle this, the application stops again for a second pause, called remark, which finalizes marking by revisiting any objects that were modified during the concurrent marking phase. because the remark pause is more substantial
Than the initial mark, multiple threads are run in parallel to increase its efficiency. remarks to be translated

Concurrent mark-sweep GC log format:

Full GC is called 

Promotion failed (
Mark-sweep-compact stop-the-world)Parnew (promotion failed): when there are fragments in the free space of the old generation, there is not enough continuous space to store the upgrade of the new generation of objects, the opportunity to trigger promotion
Failed. In this case, it is necessary to call a mark-compact garbage collector. (Serial old GC is used by default)

106.641: [GC 106.641: [parnew (promotion failed): 14784 K-> 14784 K (14784 K), 0.0370328 secs] 106.678:
[Cms106.715: [CMS-Concurrent-MARK: 0.065/0.103 secs] [times: User = 0.17 sys = 0.00, real = 0.11 secs]

(Concurrent mode failure): 41568 K-> 27787 K (49152 K), 0.2128504 secs] 52402 K-> 27787 K (63936 K), [CMS perm: 2086 K-> 2086 K (12288 K)], 0.2499776 secs] [times: User = 0.28
Sys = 0.00, real = 0.25 secs]

Full Promotion Guarantee Failure(Concurrent mode failure ):
When the garbage collection algorithm predicts that the free space of the old generation will be used up by the system before the next conc-mark-sweep algorithm call. To solve this problem, the garbage collection algorithm enters the conccurent mode failure state and calls a stop-the-world (Serail old GC) command to clean up the System Heap.

Eg: In order to trigger this situation, we first allocate 64 MB of memory to the JVM, and then the proportion of the new generation and old generation is 7, that is, if the concurrent mode failure is triggered for the elderly at 7x8 = 58:

 

 

Public class fullpromotionguaranteefailure
{
Public static void main (string [] ARGs)
{
List <byte []> byteslist = new arraylist <byte []> ();
For (INT I = 0; I <7*8*1024; I ++)
{
Byteslist. Add (New byte [1, 1024]);
}

// Byteslist = NULL; no necessary GC will know whether the variables in the function will be referenced
Byte [] bytes = new byte [16*1024*1024];
String. valueof (Bytes [0]);
}
}

Runtime JVM parameters:
-Xmx64m-xms64m-XX: newratio = 7-XX: Mirror = 0-verbose: GC-XX: + printgcdetails-XX: + printgctimestamps-XX: + mirror-XX: + useconcmarksweepgc
-Xloggc: full-promotion-guarantee-failure.log
Full-promotion-guarantee-failure.log content

0.195: [GC 0.195: [parnew: 2986 K-> 2986 K (8128 K), 0.0000083 secs] 0.195: [cms0.212: [CMS-Concurrent-preclean: 0.011/0.031 secs] [times: User = 0.03 sys = 0.02, real = 0.03 secs]

(Concurrent mode failure): 56046 K-> 138 K (57344 K), 0.0271519 secs] 59032 K-> 138 K (65472 K), [CMS perm: 2079 K-> 2078 K (12288 K)], 0.0273119 secs] [times: User = 0.03 sys = 0.00, real = 0.03 secs]

 

 

Calling serial old GC is time-consuming and the entire application is suspended. This is obviously not what we want to see. To avoid concurrent mode failure, refer to the bloggc in bluedavy.
Policy Optimization

Stop-the-world GC happens when a JNI critical section is released. Here again the young generation collection failed due to "full promotion guarantee failure" and then the full GC was invoked.

283.736: [full GC 283.736: [parnew: 261599 K-> 261599 K (261952 K), 0.0000615 secs]

826554 K-> 826554 K (1048384 K), 0.0003259 secs]
GC locker: trying a full collection because scavenge failed

Reference link:

1. Java SE 6 hotspot [Tm] Virtual Machine garbage collection Tuning
2. Turbo-charging Java hotspot
   Virtual Machine, v1.4.x to improve the performance and scalability of Application Servers
3. Understanding concurrent mark sweep Garbage Collector logs
4. What the heck's a concurrent mode?
5. Https://java.sun.com/j2se/reference/...whitepaper.pdf
6. Http://blogs.sun.com/jonthecollector...the_sum_of_the
7. Http://blogs.sun.com/jonthecollector...t_the_heck_s_a