GC日志

jvm 的GC日志初体验 关于GC的一些参数 -verbose.gc开关可显示GC的操作内容。打开它,可以显示最忙和最空闲收集行为发生的时间、收集前后的内存大小、收集需要的时间等。打开-xx:+ printgcdetails开关,可以详细了解GC中的变化。打开-XX: + PrintGCTimeStamps开关,可以了解这些垃圾收集发生的时间,自JVM启动以后以秒计量。最后,通过-xx: + PrintHeapAtGC开关了解堆的更详细的信息。为了了解新域的情况,可以通过-XX:=PrintTenuringDistribution开关了解获得使用期的对象权。

 

启动weblogic服务器之后,初始产生日志 0.000: [Full GC 0.000: [Tenured: 0K->4260K(1023104K), 0.1055162 secs] 30082K->4260K(1138240K), 0.1057452 secs] 4.628: [Full GC 4.628: [Tenured: 4260K->6546K(1023104K), 0.1354001 secs] 39901K->6546K(1138240K), 0.1356303 secs] 6.176: [Full GC 6.176: [Tenured: 6546K->7961K(1023104K), 0.1651181 secs] 21755K->7961K(1138240K), 0.1653515 secs] 12.859: [Full GC 12.859: [Tenured: 7961K->12270K(1023104K), 0.2777087 secs] 47887K->12270K(1138240K), 0.2779328 secs] 17.641: [GC 17.641: [DefNew: 102397K->3032K(115136K), 0.0495016 secs] 114668K->15303K(1138240K), 0.0497269 secs] 28.348: [Full GC 28.348: [Tenured: 12270K->15435K(1023104K), 0.2675010 secs] 75659K->15435K(1138240K), 0.2677256 secs] 40.499: [GC 40.499: [DefNew: 102399K->12736K(115136K), 0.3827322 secs] 117835K->45861K(1138240K), 0.3831325 secs] 48.871: [GC 48.871: [DefNew: 115136K->12736K(115136K), 0.5656438 secs] 148261K->85635K(1138240K), 0.5657204 secs] 56.585: [GC 56.585: [DefNew: 115135K->12736K(115136K), 0.4458067 secs] 188035K->118444K(1138240K), 0.4458949 secs] 66.213: [GC 66.213: [DefNew: 115135K->12736K(115136K), 0.3692542 secs] 220844K->144890K(1138240K), 0.3693315 secs] 76.251: [GC 76.251: [DefNew: 115135K->12735K(115136K), 0.2650355 secs] 247289K->174145K(1138240K), 0.2651241 secs] 82.396: [GC 82.397: [DefNew: 115135K->12735K(115136K), 0.1989967 secs] 276545K->217355K(1138240K), 0.1990755 secs] 89.504: [GC 89.504: [DefNew: 115135K->12735K(115136K), 0.2733299 secs] 319755K->291353K(1138240K), 0.2734123 secs] 95.257: [GC 95.258: [DefNew: 115135K->12736K(115136K), 0.3487282 secs] 399385K->340864K(1138240K), 0.3488096 secs] 98.271: [GC 98.271: [DefNew: 115135K->12735K(115136K), 0.4132144 secs] 443264K->388184K(1138240K), 0.4132912 secs] 101.577: [GC 101.577: [DefNew: 115135K->12736K(115136K), 0.5328404 secs] 513112K->470981K(1138240K), 0.5329206 secs] 105.371: [GC 105.371: [DefNew: 115135K->12736K(115136K), 0.6153580 secs] 573381K->532211K(1138240K), 0.6154395 secs] 182.208: [GC 182.208: [DefNew: 115136K->12736K(115136K), 0.4843296 secs] 634611K->564985K(1138240K), 0.4844138 secs] 191.752: [GC 191.752: [DefNew: 115135K->12735K(115136K), 0.5217968 secs] 667385K->603813K(1138240K), 0.5218681 secs] 201.570: [GC 201.570: [DefNew: 115135K->12735K(115136K), 0.4042610 secs] 706213K->638724K(1138240K), 0.4043473 secs] 211.013: [GC 211.013: [DefNew: 115135K->12736K(115136K), 0.3656211 secs] 741123K->668281K(1138240K), 0.3656906 secs] 223.204: [GC 223.204: [DefNew: 115136K->12736K(115136K), 0.2736965 secs] 770681K->690113K(1138240K), 0.2737970 secs] 228.496: [GC 228.496: [DefNew: 115135K->12735K(115136K), 0.2129989 secs] 792513K->733502K(1138240K), 0.2130814 secs] 236.952: [GC 236.952: [DefNew: 115134K->12736K(115136K), 0.2766950 secs] 858428K->814409K(1138240K), 0.2767798 secs] 做了一个大数据量查询后日志增加 588.865: [GC 588.865: [DefNew: 115135K->12736K(115136K), 0.0928617 secs] 916809K->824497K(1138240K), 0.0929371 secs] 725.903: [GC 725.903: [DefNew: 115135K->12736K(115136K), 0.1385650 secs] 926897K->837837K(1138240K), 0.1386372 secs] 736.062: [GC 736.062: [DefNew: 115136K->12736K(115136K), 0.3076112 secs] 940237K->860163K(1138240K), 0.3076883 secs] 750.298: [GC 750.298: [DefNew: 115135K->12736K(115136K), 0.2565046 secs] 962563K->882354K(1138240K), 0.2565766 secs] 758.875: [GC 758.875: [DefNew: 115135K->12736K(115136K), 0.2601905 secs] 984754K->904344K(1138240K), 0.2602707 secs] 764.257: [GC 764.258: [DefNew: 115135K->12736K(115136K), 0.2654858 secs] 1006744K->926708K(1138240K), 0.2655555 secs] 769.393: [GC 769.393: [DefNew: 115135K->115135K(115136K), 0.0000126 secs]769.393: [Tenured: 913972K->413259K(1023104K), 2.8389837 secs] 1029108K->413259K(1138240K), 2.8391320 secs] 对于DefNew和Tenured目前还不是很明白,根据字面意思理解,Tenured为系统占用,DefNew为动态增加。 时间点   [GC开始时间:[动态分配:初始值->分配值(可用值) ,  消耗时间     ] 初始值->回收后占用值(可用值),消耗时间] 764.257: [GC 764.258: [DefNew: 115135K->12736K(115136K), 0.2654858 secs] 1006744K->926708K(1138240K), 0.265555

posted on 2013-10-23 18:16  heartstage  阅读(608)  评论(0编辑  收藏  举报

导航