jvm 日志输出说明

来源：互联网发布：js单选按钮默认选中编辑：程序博客网时间：2024/05/30 05:26

在大型的java运用中，要进行程序调优，指定一个合适的垃圾回收机制是必不可少的，那如何可确定某gc是否使得程序最优化呢？我们可以查看jvm打印出的gc日志来分析，并做出进一步优化，而目前并没有一篇文章明确的指明java中各种gc算法打印出日志的格式，以及如何阅读。所以接下来本文将试着边介绍各种垃圾回收机制边解释该回收机制下log的格式。
1，垃圾收集算法
1.1 引用计数法（Reference Counting Collector）
    系统记录对象被应用的次数，当应用次数为0时，就可以将该对象所占内存回收。该算法可以不用暂停运用，但缺点是无法解决重复运用的问题。所以java并没有提供此类垃圾回收器。
1.2  tracing算法(Tracing Collector)
       tracing算法的垃圾收集器从根集开始扫描，识别出哪些对象可达，哪些对象不可达，并用某种方式标记可达对象。
1.2.1 复制（ Copying ）算法
     复制算法将堆等分成2个区域，一个区域含有现在的数据对象(ToSpace)，而另一个区域包含废弃的数据(FromSpace)。复制算法将存活的对象从FromSpace复制到ToSpace，然后切换Fromspace和ToSpace的指针，以前的FromSpace变为现在的ToSpace区域。
1.2.2 标记－整理（ Mark-Compact ）算法

  1.2.3 标记-清除（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: 1403K->105K(1984K), 0.0109275 secs] 1403K->1277K(6080K), 0.0110143 secs]
2, Serial Olg Gc

1.133: [GC 1.133: [DefNew: 960K->64K(960K), 0.0012208 secs]1.135: [Tenured: 7334K->7142K(7424K), 0.0213756 secs] 7884K->7142K(8384K), [Perm : 364K->364K(12288K)], 0.0226997 secs] [Times: user=0.01 sys=0.00, real=0.02 secs]

Parrallel GC serailGC的适应muti Core的加强版，就是在minorGC时候采用并行的进行收集，而fullGC并没有改变

Parralllel Compacting GC 在parrallelGC的基础上将fullgc也变为并发的了

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.备注待翻译

Concurrent Mark-Sweep (CMS) Collector 有一种需求是应用的相应时间比应用的吞吐重要，为了满足这种需求，jvm提供了该场景下的垃圾收集器CMS，使用该垃圾收集器的时候minorGC和 ParralelGC当中采用的一样，只是在老生代更换了不同的算法。

CMS将老生代的回收分为4个阶段其中只有2个阶段是要stop-the-world的,而其余阶段是不需要的，因此降低了系统暂停时间，缺点是在其余的2个阶段会更应用抢jvm资源。

从上图可以看出，CMS的运行过程。

A collection cycle for the CMS collector starts with a short pause, called the initial mark, that

identifies 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 transitively

reachable 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 the 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. 备注待翻译

Concurrent Mark-Sweep GC log format：

Full GC 被调用的出现情况

promotion failed( mark-sweep-compact stop-the-world ) ParNew (promotion failed): 当老生代空闲空间存在碎片，导致没有足够大的连续空间开存放新生代对象的升级时，机会触发promotion failed。此时调用一个Mark-Compact 垃圾收集器是很有必要的。（默认采用 Serial Old GC）

106.641: [GC 106.641: [ParNew (promotion failed): 14784K->14784K(14784K), 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): 41568K->27787K(49152K), 0.2128504 secs] 52402K->27787K(63936K), [CMS Perm : 2086K->2086K(12288K)], 0.2499776 secs] [Times: user=0.28 sys=0.00, real=0.25 secs]

full promotion guarantee failure ( concurrent mode failure ): 当垃圾回收算法预测在下一次Conc-Mark-Sweep算法调用之前，老生代的空余空间将会被系统占用光。为了解决这一问题，垃圾回收算法进入conccurent mode failure状态，调用一个 stop-the-world（serail Old GC）来清理系统Heap。

eg:为了触发这种情况我们先分配64m内存给jvm，然后新生代和老年代的占用比例为7，即老年代用了7*8=58 触发concurrent mode failure的情况:

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[1024]);
   }

    //bytesList = null; 没有必要的 gc会知道函数里面变量是否还会被引用
    byte[] bytes = new byte[16 * 1024 * 1024];
   String.valueOf(bytes[0]);
    }
}

运行时JVM参数：
-Xmx64m -Xms64m -XX:NewRatio=7 -XX:MaxTenuringThreshold=0 -verbose:gc -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCApplicationStoppedTime -XX:+UseConcMarkSweepGC
-Xloggc:full-promotion-guarantee-failure.log
full-promotion-guarantee-failure.log 内容

0.195: [GC 0.195: [ParNew: 2986K->2986K(8128K), 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): 56046K->138K(57344K), 0.0271519 secs] 59032K->138K(65472K), [CMS Perm : 2079K->2078K(12288K)], 0.0273119 secs] [Times: user=0.03 sys=0.00, real=0.03 secs]

调用Serial Old GC 是费时并且暂停了整个应用，这显然不是我们想看到的。为了避免办法出现（ concurrent mode failure ）这种情况,可以参考bluedavy的该篇blog GC 策略的调优

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: 261599K->261599K(261952K), 0.0000615 secs]
826554K->826554K(1048384K), 0.0003259 secs]
GC locker: Trying a full collection because scavenge failed

参考链接：

Java SE 6 HotSpot[tm] Virtual Machine Garbage Collection Tuning
Turbo-charging Java HotSpot Virtual Machine, v1.4.x to Improve the Performance and Scalability of Application Servers
Understanding Concurrent Mark Sweep Garbage Collector Logs
What the Heck's a Concurrent Mode?
https://java.sun.com/j2se/reference/...whitepaper.pdf
http://blogs.sun.com/jonthecollector...the_sum_of_the
http://blogs.sun.com/jonthecollector...t_the_heck_s_a

0 0