Java Virtual Machine Series (IV)---view GC logs

This section is interspersed with a little bit of knowledge about how to configure and view a GC log for a Java application in eclipse, as I know by research, because the book is not written in detail and is primarily intended for the next section.

I. Configuring the GC in Eclipse

In eclipse, if you want to configure a GC log for an app, first right-click the app (the class where the Main method resides)->run As->run configurations->arguments, and configure the following parameters in VM Arguments:

-xms20m//Minimum heap memory
-xmx20m//Max heap Memory
-xx:+printgctimestamps//Print GC time
-xx:+printgcdetails//Print GC for more information
-VERBOSE:GC//Turn on GC log
-xloggc:d:/gc4.log//GC log location, followed by viewing this log file
Location of-xmn10m//Cenozoic memory Area
-xx:survivorratio=8//Proportion of Eden and survivor areas in the replication algorithm (follow-up chapters will elaborate)

As shown in the following:

After the configuration is finished, click Applay->run, and then you can go to the log path you just configured and find the appropriate file to view.

Second, view GC

The following is a specific example to view and analyze the GC log

1. Create three mutually referenced object instances

2. Configure GC

3. View Log Contents

Java HotSpot (TM) 64-bit Server VM (25.121-b13) for Windows-amd64 JRE (1.8.0_121-B13), built in Dec 18:21:36 by "Ja  Va_re "with MS VC + + 10.0 (VS2010) memory:4k page, physical 4057600k (480696k free), swap 8113324k (3128576k free) CommandLine Flags:-xx:initialheapsize=20971520-xx:maxheapsize=20971520-xx:maxnewsize=10485760-xx:newsize=10485760-xx:+ printgc-xx:+printgcdetails-xx:+printgctimestamps-xx:survivorratio=8-xx:+usecompressedclasspointers-xx:+ USECOMPRESSEDOOPS-XX:-USELARGEPAGESINDIVIDUALALLOCATION-XX:+USEPARALLELGC 0.121: [GC (System.GC ()) [PSYoungGen: 4219k->680k (9216K)] 4219k->3760k (19456K), 0.0024028 secs] [times:user=0.00 sys=0.00, real=0.00 secs] 0.124: [Full GC (System.GC ()) [psyounggen:680k->0k (9216K)] [paroldgen:3080k->3639k (10240K)] 3760k->3639k (19456K), [ metaspace:2587k->2587k (1056768K)], 0.0062622 secs] [times:user=0.06 sys=0.00, real=0.01 secs] Heap Psyounggen to Tal 9216K, used 82K [0x00000000ff600000, 0x0000000100000000, 0x0000000100000000) Eden Space 8192K, 1% used [0x00000000ff600000,0x00000000ff614920,0x00000000ffe00000] from space 1024K, 0% Used [0x00000000ffe00000,0x00000000ffe00000,0x00000000fff00000] to space 1024K, 0% used [0x00000000fff00000,0x0000000 0fff00000,0x0000000100000000) Paroldgen total 10240K, used 3639K [0x00000000fec00000, 0x00000000ff600000, 0x00000000 ff600000) object Space 10240K, 35% used [0x00000000fec00000,0x00000000fef8de58,0x00000000ff600000] Metaspace used 2 593K, capacity 4486K, committed 4864K, reserved 1056768K class space used 286K, capacity 386K, committed 512K, reserve D 1048576K

The above is the generated GC log, where:

The first two lines are some of the virtual machine information, such as using the hotspot virtual machine, JRE version, etc. the third line is the parameter information just configured, the real GC information is the 4th, 5 rows, so here directly to the 4, 52 rows out for analysis:

1) The first number 0.121, 0.124 represents the time the GC occurs, the meaning of this number is the number of seconds since the start of the Java Virtual machine;

2) the "[GC" and "[Full GC" at the beginning of the GC log illustrate the type of pauses for this garbage collection, not the new generation GC or the older GC. If there is "full", this GC is Stop-the-world, that is, when performing GC operations, will stop the current other threads in progress, there is a "this is my territory, you all give me out of the way" of the overbearing have wood? If the collection triggered by a method called System.GC () will display "full GC (SYSTEM.GC)", the example of this article is the collection using System.GC ();

3) The next "[Psyounggen", "[Paroldgen", "[metaspace") indicate the area where the GC occurred, and the region name shown here is closely related to the GC collector used (the garbage collector will be described in more detail later). The following is the name of the zone represented by the common collector:

1> If you are using a serial (serial) collector, the New generation is named Default, Generation, and the display is defnew

2> If you are using a parnew (parallel) collector, the Cenozoic name will change to [parnew, meaning parallel New Generation

3> If the parallel scavenge collector is used, the new generation name is Psyonggen

The same old age and perpetual generation, the name is determined by the garbage collector

As in the above log, the new generation name is [Psyounggen, using the Parallel scavenge collector; The old age name is [Paroldgen, using the paralled OID collector (Parallel Scavenge collector version of the old age), there is also a meta-space area, some articles use "[PermGen", this time before JDK8 version, because I use the JDK8, so has been "[metaspace" replaced, as to why is replaced, can refer to article: 52122880

4) After the colon in each area, "680k->0k (9216K)" Inside the brackets means "the memory area has used capacity after the GC has used capacity->GC (the total capacity of the memory area )" . The "3760k->3639k (19456K)" Outside the square brackets indicates that the Java heap has used capacity (total Java heap capacity) after the GC has used capacity->GC.

5) Back 0.0062622 secs indicates that the memory area GC occupies a time unit of seconds, and some collectors give specific time, as in this example "[times:user=0.06 sys=0.00, real=0.01 secs]", the user, The time implications of SYS, REAL, and Linux commands are always, representing the CPU time consumed by the user state, the CPU time consumed by the kernel state, and the wall clock time elapsed from the start to the end of the operation (Wall clock times)

TIPS: The difference between the wall clock time and CPU time is that the wall clock time includes a variety of non-operational waiting times, such as waiting for the IO of the disk, waiting for the thread to block, and the CPU time does not include these times, but when the system has CPU or multicore, multi-threaded operation will overlay these CPU time, So it is perfectly normal for the reader to see the user or sys time exceeding the real time.

The above descriptions of the parameters in the GC log are excerpted from the in-depth understanding of Java Virtual Machine (second edition)

Looking down, from line 6th to the end of the content is the size of the memory area of the change situation!

Note: The above content from the "deep understanding of Java Virtual Machine", according to their own understanding to summarize, some content and book content is the same because only so the description is relatively understood, after all, the great God or the great God, is not the same color fireworks!!

Java Virtual Machine Series (IV)---view GC logs