Also learn JAVA/JVM/GC (iv)

GC Log Parser Code:

1  Public classJvmtest {2      Public Static voidMain (string[] args) {3         4         intm = 1024 * 1024;5         byte[] B =New byte[2 *m];6System.out.println ("Allocate 2M");7 8         byte[] B1 =New byte[2 *m];9System.out.println ("Allocate 2M");Ten  One         byte[] B2 =New byte[2 *m]; ASystem.out.println ("Allocate 2M"); -  -         byte[] B3 =New byte[2 *m]; theSystem.out.println ("Allocate 2M"); -  -         byte[] B4 =New byte[2 *m]; -System.out.println ("Allocate 2M"); +  -         byte[] B5 =New byte[2 *m]; +System.out.println ("Allocate 2M"); A  at         byte[] B6 =New byte[2 *m]; -System.out.println ("Allocate 2M"); -     } -}

One, serial GC

1. Execute the order as follows

Java-xms20m-xmx20m-xmn10m-xx:+useserialgc-xx:+printgcdetails Jvmtest

2. GC logs are as follows:

　　

allocate 2Mallocate 2Mallocate 2M[gc[defnew:6831k ->231k (9216K), 0.0064660 secs] 6831k->6375k (19456K), 0.0065000 secs] [times:user=0.01 sys=0.00, real=0.01  secs]allocate 2Mallocate 2Mallocate 2M[gc[defnew:6547k ->6547k (9216K), 0.0000150 secs] [Tenured:6144k->8192k (10240K), 0.0086010 secs] 12691k->12516k (19456K), [perm:2585k->2585k (21248K)],0.0086580 secs] [times:user=0.00 sys=0.00, real=0.01 secs]allocate 2MHeap defNewGeneration Total 9216K, used 6509K [0x00000007f9a00000, 0x00000007fa400000, 0x00000007fa400000) Eden Space 8192K,79% used [0x00000007f9a00000, 0x00000007fa05b770, 0x00000007fa200000) from Space 1024K,0% used [0x00000007fa300000, 0x00000007fa300000, 0x00000007fa400000) to space 1024K,0% used [0x00000007fa200000, 0x00000007fa200000, 0x00000007fa300000) tenured generation total 10240K, used 8192K [0x00000007fa400000, 0x00000007fae00000, 0x00000007fae00000) The space 10240K,80% used [0x00000007fa400000, 0x00000007fac000c8, 0x00000007fac00200, 0x00000007fae00000) Compacting Perm gen Total 21248K, used 2592K [0x00000007fae00000, 0x00000007fc2c0000, 0x0000000800000000) The space 21248K,12% used [0x00000007fae00000, 0x00000007fb088230, 0x00000007fb088400, 0x00000007fc2c0000) No GKFX spaces configured.

As shown above 6 m of memory was first allocated, a YGC was made once, and then 6 m of memory was allocated after a GC for the entire heap.

The above blue font shows the first YGC log, where 6831k->231k (9216K) indicates that the size of the younger generation is less than 6831K to 231K, that is, 6831-231 is recycled = 6600K, 9216K represents the size of the younger generation occupied area (because the start parameter is set to-xmn10m, that is, the younger generation is 10M, the default Eden and Survivor are 8:1, so the Eden area is 8M and each survivor area is 1M). The size of the entire heap is reduced from 6831K to 6375K, which means that 6831-6375 = 456K is recycled. The 19456K represents the entire old generation, Eden area, and a survivor area. The total use of this recovery was 0.0065000 seconds. In the last paragraph, user indicates that YGC users are time-consuming, SYS indicates that the system is time consuming, real represents actual time.

The dark red font below shows the entire heap GC, one YGC and one time PERMGC. YGC Log Ibid. Here tenured memory is not reduced, because the young generation GC after allocating 2 m of memory, the Eden area in the young generation is 6547K, and the total Eden size is 8*1024=8192k, if you allocate 2M, that is 6547k+2048k=8595k > 8192K , therefore cannot allocate the memory in the younger generation, can only allocate the memory in the old generation, therefore the eldest brother by 6144k+2048k=8192k. At this point Perm also conducted a GC, but no memory is reduced.

Second, parallel GC

A:useparallelgc

1. Execute the order as follows:

Java-xms20m-xmx20m-xmn10m-xx:+useparallelgc-xx:+printgcdetails Jvmtest

2. GC logs are as follows

allocate 2Mallocate 2Mallocate 2M[GC [psyounggen:6831k ->352k (9216K)] 6831k->6496k (19456K), 0.0072050 secs] [times:user=0.02 sys=0.00, real=0.01 secs] [Full GC [psyounggen:352k ->0k (9216K)] [paroldgen:6144k->6373k (10240K)] 6496k->6373k (19456K) [pspermgen:2585k->2584k (21504K)], 0.0129170 secs] [ times:user=0.01 sys=0.00, real=0.01 secs]allocate 2Mallocate 2Mallocate 2M[Full GC [psyounggen:6315k ->4096k (9216K)] [paroldgen:6373k->8420k (10240K)] 12689k->12516k (19456K) [pspermgen:2584k->2584k (21504K)], 0.0101690 secs] [times:user=0.01 sys=0.01, real=0.01 secs]allocate 2MHeap psyounggen total 9216K, used 6281K [0x00000007ff600000, 0x0000000800000000, 0x0000000800000000) Eden Space 8192K,76% used [0x00000007ff600000,0x00000007ffc22660,0x00000007ffe00000) from Space 1024K,0% used [0x00000007ffe00000,0x00000007ffe00000,0x00000007fff00000) to space 1024K,0% used [0x00000007fff00000,0x00000007fff00000,0x0000000800000000) Paroldgen total 10240K, used 8420K [0x00000007fec00000, 0x00000007ff600000, 0x00000007ff600000) object Space 10240K,82% used [0x00000007fec00000,0x00000007ff4391d8,0x00000007ff600000) Pspermgen total 21504K, used 2591K [0x00000007f9a00000, 0x00000007faf00000, 0x00000007fec00000) object Space 21504K,12% used [0x00000007f9a00000,0x00000007f9c87e60,0x00000007faf00000)

As shown in the GC log, the JVM performed 3 GC, one YGC and two FGC. YGC log analysis with SERIALGC.

For the first time, the size of the young generation was reduced from 352K to 0K, so the FGC recovered 352K. The old generation changed from 6144K to 6373K, adding 229K (Is it the target of promotion from younger generations?). )。 The size of the entire heap was reduced from 6496K to 6373K, with a total of 6494k-6373k=121k recycled. The size of the perm area is reduced from 2585K to 2584K, which amounts to a recovery of 1K.

The second FGC, the size of the younger generation reduced from 6315K to 4096K, recycled 6315k-4096k=2219k. The old generation increased from 6373K to 8420K, increased by 2047K, and the whole heap was reduced from 12689K to 12516K, with a total of 12689k-12516k=173k recycled. The size of the perm area does not change.

B, USEPARALLELOLDGC

Log with PARALLELGC.

The only difference between USEPARALLELGC and USEPARALLELOLDGC is:

-XX:+USEPARALLELGC used in the young generation of multi-threading, old generation of single-threaded,-XX:+USEPARALLELOLDGC used in both young and old generations are multi-threaded.

Third, CMS GC

1. The command is as follows:

　　　　

Java-xms20m-xmx20m-xmn10m-xx:+useconcmarksweepgc-xx:+printgcdetails Jvmtest

2, the log is as follows:

[Gc[parnew:6831k->257k (9216K), 0.0078490 secs] 6831k->6403k (19456K), 0.0079190 secs] [times:user=0.01 sys=0.01, real=0.01secs] [gc[parnew:6573k->6573k (9216K), 0.0000550 secs][cms:6146k->8192k (10240K), 0.0139330 secs] 12719k->12517k (19456K), [CMS Perm: 2588k->2587k (21248K)], 0.0140560 secs] [times:user=0.01 sys=0.00, real=0.01secs] [GC [1 cms-initial-mark:8192k (10240K)] 14565K (19456K), 0.0004510 secs] [times:user=0.00 sys=0.00, real=0.00secs] [CMS-concurrent-mark:0.003/0.003 secs] [times:user=0.00 sys=0.00, real=0.01secs] [CMS-concurrent-preclean:0.004/0.004 secs] [times:user=0.01 sys=0.00, real=0.00secs] [CMS-concurrent-abortable-preclean:0.000/0.000 secs] [times:user=0.00 sys=0.00, real=0.00secs] [Gc[yg occupancy:7510 K (9216 k)][rescan (parallel), 0.0004280 secs][weak refs processing, 0.0000140 secs][scrub string table, 0.0001790 s ECS] [1 cms-remark:9216k (10240K)] 16726K (19456K), 0.0006900 secs] [times:user=0.00 sys=0.00, real=0.00secs] [CMS-concurrent-sweep:0.000/0.000 secs] [times:user=0.00 sys=0.00, real=0.00secs] [CMS-concurrent-reset:0.000/0.000 secs] [times:user=0.00 sys=0.00, real=0.00secs] [gc[parnew:7510k->7510k (9216K), 0.0000300 secs][cms:9216k->9216k (10240K), 0.0088070 secs] 16726k->16615k (19456K), [CMS Perm: 2619k->2619k (21248K)], 0.0089500 secs] [times:user=0.01 sys=0.00, real=0.00secs] [Full gc[cms:9216k->9216k (10240K), 0.0062390 secs] 16615k->16603k (19456K), [CMS perm:2619k->2619k (21248K)], 0.0062830 secs] [ times:user=0.00 sys=0.00, real=0.01 secs]

CMS GC log more than the identity of the various stages of the CMS, the contents of the log and serial and parallel no big difference.

　　

Also learn JAVA/JVM/GC (iv)