对eclipse启动进行JVM优化纪实（3）

看看开启了4个项目的ECLIPSE启动并运行了一段时间的GC日志：

3.704: [GC 3.705: [DefNew: 209792K->25577K(235968K), 0.0981906 secs] 209792K->25577K(498112K), 0.0983430 secs] [Times: user=0.09 sys=0.00, real=0.10 secs]

8.066: [GC 8.066: [DefNew: 235369K->14539K(235968K), 0.1605831 secs] 235369K->39851K(498112K), 0.1607047 secs] [Times: user=0.16 sys=0.02, real=0.16 secs]

11.182: [Full GC 11.182: [Tenured: 25311K->60749K(262144K), 0.4505412 secs] 215839K->60749K(498112K), [Perm : 69631K->69631K(69632K)], 0.4506786 secs] [Times: user=0.45 sys=0.00, real=0.45 secs]

701.980: [Full GC 701.980: [Tenured: 60749K->66358K(262144K), 0.4241972 secs] 184716K->66358K(498112K), [Perm : 73727K->73727K(73728K)], 0.4243232 secs] [Times: user=0.42 sys=0.00, real=0.42 secs]

716.482: [Full GC (System) 716.482: [Tenured: 66358K->70403K(262144K), 0.4363351 secs] 195199K->70403K(498112K), [Perm : 76273K->76273K(76288K)], 0.4364178 secs] [Times: user=0.44 sys=0.00, real=0.44 secs]

743.651: [GC 743.651: [DefNew: 209792K->5696K(235968K), 0.0521794 secs] 280195K->76099K(498112K), 0.0522957 secs] [Times: user=0.05 sys=0.00, real=0.05 secs]

744.336: [Full GC 744.336: [Tenured: 70403K->55777K(262144K), 0.4912850 secs] 98865K->55777K(498112K), [Perm : 80384K->78678K(80384K)], 0.4915532 secs] [Times: user=0.48 sys=0.00, real=0.49 secs]

747.238: [Full GC (System) 747.238: [Tenured: 55777K->58143K(262144K), 0.4059223 secs] 162296K->58143K(498112K), [Perm : 80020K->80020K(80128K)], 0.4060066 secs] [Times: user=0.41 sys=0.00, real=0.41 secs]

749.552: [GC 749.552: [DefNew: 209792K->4464K(235968K), 0.0181934 secs] 267935K->62608K(498112K), 0.0182757 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]

750.940: [GC 750.940: [DefNew: 214256K->10380K(235968K), 0.0291428 secs] 272400K->68523K(498112K), 0.0292271 secs] [Times: user=0.03 sys=0.00, real=0.03 secs]

1015.645: [GC 1015.645: [DefNew: 220172K->11631K(235968K), 0.0445933 secs] 278315K->69775K(498112K), 0.0446756 secs] [Times: user=0.05 sys=0.00, real=0.04 secs]

1015.721: [Full GC 1015.721: [Tenured: 58143K->67082K(262144K), 0.4201463 secs] 70587K->67082K(498112K), [Perm : 84218K->84218K(84224K)], 0.4202220 secs] [Times: user=0.42 sys=0.00, real=0.42 secs]

Heap

 def new generation   total 235968K, used 88732K [0x10010000, 0x20010000, 0x20010000)

  eden space 209792K,  42% used [0x10010000, 0x156b7250, 0x1ccf0000)

  from space 26176K,   0% used [0x1ccf0000, 0x1ccf0000, 0x1e680000)

  to   space 26176K,   0% used [0x1e680000, 0x1e680000, 0x20010000)

 tenured generation   total 262144K, used 67082K [0x20010000, 0x30010000, 0x30010000)

   the space 262144K,  25% used [0x20010000, 0x24192988, 0x24192a00, 0x30010000)

 compacting perm gen  total 87552K, used 87313K [0x30010000, 0x35590000, 0x36010000)

   the space 87552K,  99% used [0x30010000, 0x35554540, 0x35554600, 0x35590000)

No shared spaces configured.

前面做了三次GC之后间隔了700多秒才进行下一次GC，看来前面的优化是有效果的，但是第三次和第四次的GC都是FULL的，实际变化在perm的内存分配，再看看最后的堆信息，perm的使用率打到了99%可用空间为80多M，看来我们的初始化持久代的大小还是偏小，直接将-XX:PermSize=64M  -XX:MaxPermSize=96M两个属性加到96M再看看。

3.950: [GC 3.950: [DefNew: 209792K->26058K(235968K), 0.1035067 secs] 209792K->26058K(498112K), 0.1036298 secs] [Times: user=0.09 sys=0.00, real=0.09 secs]

8.199: [GC 8.199: [DefNew: 235850K->17267K(235968K), 0.1653340 secs] 235850K->43009K(498112K), 0.1654507 secs] [Times: user=0.17 sys=0.00, real=0.17 secs]

11.523: [GC 11.524: [DefNew: 227059K->20036K(235968K), 0.1272503 secs] 252801K->62838K(498112K), 0.1273666 secs] [Times: user=0.13 sys=0.00, real=0.13 secs]

50.230: [GC 50.230: [DefNew: 229828K->10496K(235968K), 0.0923547 secs] 272630K->72603K(498112K), 0.0924892 secs] [Times: user=0.09 sys=0.00, real=0.09 secs]

92.200: [GC 92.200: [DefNew: 220288K->14340K(235968K), 0.0514004 secs] 282395K->76448K(498112K), 0.0515280 secs] [Times: user=0.05 sys=0.00, real=0.05 secs]

95.266: [GC 95.266: [DefNew: 224132K->8605K(235968K), 0.0516780 secs] 286240K->79752K(498112K), 0.0517501 secs] [Times: user=0.06 sys=0.00, real=0.06 secs]

Heap

 def new generation   total 235968K, used 128262K [0x10010000, 0x20010000, 0x20010000)

  eden space 209792K,  57% used [0x10010000, 0x174ea4b8, 0x1ccf0000)

  from space 26176K,  32% used [0x1ccf0000, 0x1d557468, 0x1e680000)

  to   space 26176K,   0% used [0x1e680000, 0x1e680000, 0x20010000)

 tenured generation   total 262144K, used 71147K [0x20010000, 0x30010000, 0x30010000)

   the space 262144K,  27% used [0x20010000, 0x2458aef8, 0x2458b000, 0x30010000)

 compacting perm gen  total 98304K, used 89738K [0x30010000, 0x36010000, 0x36010000)

   the space 98304K,  91% used [0x30010000, 0x357b2b60, 0x357b2c00, 0x36010000)

No shared spaces configured.

 

我启动eclipse之后，打开了几个JAVA文件，并且开启了一次WTP插件的tomcat服务器，然后关闭了eclipse,这次并没有出现full gc,perm的使用率是91%还有空余空间，以后再加别的项目估计也不会有太大问题，持久代的问题已经解决了，再回过头来看看旧生代，使用率只有27%，这个可以承受，暂时忽略，接下来优化的是新生代，from space的使用率有32%，基本够用，那么说明这几次的GC实际上是内存对象从edem转向from space，edem和from的大小比例是8:1,这样都小的话我们可以适当放大新生代的大小，先前我们设定的-Xmn256M，可以将这个值适当调大，我们看看最后一次GC的信息：

95.266: [GC 95.266: [DefNew: 224132K->8605K(235968K), 0.0516780 secs]

GC的时候新生代的使用大小为224132K约为218M大约占用了新生代90%的空间，由于旧生代只有27%的使用率，这样可以大胆的将-Xmn调成384M，再看看效果：

5.846: [GC 5.846: [DefNew: 314624K->34351K(353920K), 0.1457532 secs] 314624K->34351K(484992K), 0.1458845 secs] [Times: user=0.14 sys=0.00, real=0.14 secs]

9.666: [GC 9.666: [DefNew: 348975K->17807K(353920K), 0.1567220 secs] 348975K->51637K(484992K), 0.1568476 secs] [Times: user=0.11 sys=0.03, real=0.16 secs]

10.824: [GC 10.824: [DefNew: 332431K->30075K(353920K), 0.0794988 secs] 366261K->63905K(484992K), 0.0796350 secs] [Times: user=0.08 sys=0.00, real=0.08 secs]

Heap

 def new generation   total 353920K, used 319084K [0x10010000, 0x28010000, 0x28010000)

  eden space 314624K,  91% used [0x10010000, 0x21a4c420, 0x23350000)

  from space 39296K,  76% used [0x259b0000, 0x2770ef08, 0x28010000)

  to   space 39296K,   0% used [0x23350000, 0x23350000, 0x259b0000)

 tenured generation   total 131072K, used 33829K [0x28010000, 0x30010000, 0x30010000)

   the space 131072K,  25% used [0x28010000, 0x2a1197c8, 0x2a119800, 0x30010000)

 compacting perm gen  total 98304K, used 70830K [0x30010000, 0x36010000, 0x36010000)

   the space 98304K,  72% used [0x30010000, 0x3453ba10, 0x3453bc00, 0x36010000)

No shared spaces configured.

 

果然有效果，从日志来看，新生代的的使用率很高，应该用不了多久会再进行一次GC，可惜我已经关闭eclipse，旧生代的使用率还有所下降，也许是操作次数少的原因。从总的结果来看这次对新生代的调优感觉是很好的，这次对eclipse的调优只是对内存分配的调优，并没有对GC的方式进行调优，因为我觉得在新生代的GC的时候任何一种GC方式对性能不会很大的影响，至少在eclipse里面还好，说白了还是要依据项目而定，也是应该根据需求而定，其实今天对新生代的调优我就觉得是鸡肋，只是不想做太监，还是硬着头皮把这个调优的blog结束掉。

 

总结一下：

         GC调优不是高高在上的圣坛，只要有一定的分析能力和对java内存结构和分配策略有一定了解，相信人人都能做调优，这些调优参数不用记在脑子里面的，除非你是专职做GC调优的人，知道原理就行。