- 浏览: 282142 次
- 性别:
- 来自: 天津
文章分类
最新评论
-
狼子六:
已经开始用了
Java 枚举7常见种用法 -
相约的旋律:
方法一下面的"public static fianl ...
Java 枚举7常见种用法 -
kiddy2012:
...
[转载]程序员装B指南 -
fancy105:
写得很好,简单明了双全面!
Java 枚举7常见种用法 -
he_wen:
请问一下 G1算法是否在线上使用了?
Garbage First(G1) 日志分析工具
CMS GC with -XX:+PrintGCDetails and -XX:+PrintGCTimeStamps prints a lot of information. Understanding this information can help in fine tuning various parameters of the application and CMS to achieve best performance.
Let's have a look at some of the CMS logs generated with 1.4.2_10:
39.910: [GC 39.910: [ParNew: 261760K->0K(261952K), 0.2314667 secs] 262017K->26386K(1048384K), 0.2318679 secs]
Young generation (ParNew) collection. Young generation capacity is 261952K and after the collection its occupancy drops down from 261760K to 0. This collection took 0.2318679 secs.
40.146: [GC [1 CMS-initial-mark: 26386K(786432K)] 26404K(1048384K), 0.0074495 secs]
Beginning of tenured generation collection with CMS collector. This is initial Marking phase of CMS where all the objects directly reachable from roots are marked and this is done with all the mutator threads stopped.
Capacity of tenured generation space is 786432K and CMS was triggered at the occupancy of 26386K.
40.154: [CMS-concurrent-mark-start]
Start of concurrent marking phase.
In Concurrent Marking phase, threads stopped in the first phase are
started again and all the objects transitively reachable from the
objects marked in first phase are marked here.
40.683: [CMS-concurrent-mark: 0.521/0.529 secs]
Concurrent marking took total 0.521 seconds cpu time and 0.529 seconds wall time that includes the yield to other threads also.
40.683: [CMS-concurrent-preclean-start]
Start of precleaning.
Precleaning is also a concurrent phase. Here in this phase we look at
the objects in CMS heap which got updated by promotions from young
generation or new allocations or got updated by mutators while we were
doing the concurrent marking in the previous concurrent marking phase.
By rescanning those objects concurrently, the precleaning phase helps
reduce the work in the next stop-the-world “remark” phase.
40.701: [CMS-concurrent-preclean: 0.017/0.018 secs]
Concurrent precleaning took 0.017 secs total cpu time and 0.018 wall time.
40.704: [GC40.704: [Rescan (parallel) , 0.1790103 secs]40.883: [weak refs processing, 0.0100966 secs] [1 CMS-remark: 26386K(786432K)] 52644K(1048384K), 0.1897792 secs]
Stop-the-world phase. This phase rescans any residual updated objects in CMS heap, retraces from the roots and also processes Reference objects. Here the rescanning work took 0.1790103 secs and weak reference objects processing took 0.0100966 secs. This phase took total 0.1897792 secs to complete.
40.894: [CMS-concurrent-sweep-start]
Start of sweeping of dead/non-marked objects. Sweeping is concurrent phase performed with all other threads running.
41.020: [CMS-concurrent-sweep: 0.126/0.126 secs]
Sweeping took 0.126 secs.
41.020: [CMS-concurrent-reset-start]
Start of reset.
41.147: [CMS-concurrent-reset: 0.127/0.127 secs]
In this phase, the CMS data structures are reinitialized so that a new cycle may begin at a later time. In this case, it took 0.127 secs.
This was how a normal CMS cycle runs. Now let us look at some other CMS log entries:
197.976: [GC 197.976: [ParNew: 260872K->260872K(261952K),
0.0000688 secs]197.976: [CMS197.981: [CMS-concurrent-sweep: 0.516/0.531
secs]
(concurrent mode failure): 402978K->248977K(786432K), 2.3728734 secs] 663850K->248977K(1048384K), 2.3733725 secs]
This shows that a ParNew collection was requested, but it was not attempted because it was estimated that there was not enough space in the CMS generation to promote the worst case surviving young generation objects. We name this failure as “full promotion guarantee failure”.
Due to this, Concurrent Mode of CMS is interrupted and a Full GC is invoked at 197.981. This mark-sweep-compact stop-the-world Full GC took 2.3733725 secs and the CMS generation space occupancy dropped from 402978K to 248977K.
The concurrent mode failure can either be avoided by increasing the tenured generation size or initiating the CMS collection at a lesser heap occupancy by setting CMSInitiatingOccupancyFraction to a lower value and setting UseCMSInitiatingOccupancyOnly to true. The value for CMSInitiatingOccupancyFraction should be chosen appropriately because setting it to a very low value will result in too frequent CMS collections.
Sometimes we see these promotion failures even when the logs show
that there is enough free space in tenured generation. The reason is
'fragmentation' - the free space available in tenured generation is not
contiguous, and promotions from young generation require a contiguous
free block to be available in tenured generation. CMS collector is a
non-compacting collector, so can cause fragmentation of space for some
type of applications. In his blog, Jon talks in detail on how to deal
with this fragmentation problem:
http://blogs.sun.com/roller/page/jonthecollector?entry=when_the_sum_of_the
Starting with 1.5, for the CMS collector, the promotion guarantee check is done differently. Instead of assuming that the promotions would be worst case i.e. all of the surviving young generation objects would get promoted into old gen, the expected promotion is estimated based on recent history of promotions. This estimation is usually much smaller than the worst case promotion and hence requires less free space to be available in old generation. And if the promotion in a scavenge attempt fails, then the young generation is left in a consistent state and a stop-the-world mark-compact collection is invoked. To get the same functionality with UseSerialGC you need to explicitly specify the switch -XX:+HandlePromotionFailure.
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
283.736: [Full GC 283.736: [ParNew: 261599K->261599K(261952K), 0.0000288 secs]
Stop-the-world GC happening 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 is being invoked.
CMS can also be run in incremental mode (i-cms), enabled with -XX:+CMSIncrementalMode. In this mode, CMS collector does not hold the processor for the entire long concurrent phases but periodically stops them and yields the processor back to other threads in application. It divides the work to be done in concurrent phases in small chunks(called duty cycle) and schedules them between minor collections. This is very useful for applications that need low pause times and are run on machines with small number of processors.
Some logs showing the incremental CMS.
2803.125: [GC 2803.125: [ParNew: 408832K->0K(409216K),
0.5371950 secs] 611130K->206985K(1048192K) icms_dc=4 , 0.5373720
secs]
2824.209: [GC 2824.209: [ParNew: 408832K->0K(409216K), 0.6755540
secs] 615806K->211897K(1048192K) icms_dc=4 , 0.6757740 secs]
Here, the scavenges took respectively 537 ms and 675 ms. In between these two scavenges, iCMS ran for a brief period as indicated by the icms_dc value, which indicates a duty-cycle. In this case the duty cycle was 4%. A simple calculation shows that the iCMS incremental step lasted for 4/100 \* (2824.209 - 2803.125 - 0.537) = 821 ms, i.e. 4% of the time between the two scavenges.
Starting with 1.5, CMS has one more phase – concurrent abortable preclean. Abortable preclean is run between a 'concurrent preclean' and 'remark' until we have the desired occupancy in eden. This phase is added to help schedule the 'remark' phase so as to avoid back-to-back pauses for a scavenge closely followed by a CMS remark pause. In order to maximally separate a scavenge from a CMS remark pause, we attempt to schedule the CMS remark pause roughly mid-way between scavenges.
There is a second reason why we do this. Immediately following a scavenge there are likely a large number of grey objects that need rescanning. The abortable preclean phase tries to deal with such newly grey objects thus reducing a subsequent CMS remark pause.
The scheduling of 'remark' phase can be controlled by two jvm options CMSScheduleRemarkEdenSizeThreshold and CMSScheduleRemarkEdenPenetration. The defaults for these are 2m and 50% respectively. The first parameter determines the Eden size below which no attempt is made to schedule the CMS remark pause because the pay off is expected to be minuscule. The second parameter indicates the Eden occupancy at which a CMS remark is attempted.
After 'concurrent preclean' if the Eden occupancy is above CMSScheduleRemarkEdenSizeThreshold, we start 'concurrent abortable preclean' and continue precleanig until we have CMSScheduleRemarkEdenPenetration percentage occupancy in eden, otherwise we schedule 'remark' phase immediately.
7688.150: [CMS-concurrent-preclean-start]
7688.186: [CMS-concurrent-preclean: 0.034/0.035 secs]
7688.186: [CMS-concurrent-abortable-preclean-start]
7688.465: [GC 7688.465: [ParNew: 1040940K->1464K(1044544K), 0.0165840 secs] 1343593K->304365K(2093120K), 0.0167509 secs]
7690.093: [CMS-concurrent-abortable-preclean: 1.012/1.907 secs]
7690.095: [GC[YG occupancy: 522484 K (1044544 K)]7690.095: [Rescan
(parallel) , 0.3665541 secs]7690.462: [weak refs processing, 0.0003850
secs] [1 CMS-remark: 302901K(1048576K)] 825385K(2093120K), 0.3670690
secs]
In the above log, after a preclean, 'abortable preclean' starts. After the young generation collection, the young gen occupancy drops down from 1040940K to 1464K. When young gen occupancy reaches 522484K which is 50% of the total capacity, precleaning is aborted and 'remark' phase is started.
Note that in 1.5, young generation occupancy also gets printed in the final remark phase.
For more detailed information and tips on GC tuning, please refer to the following documents:
http://java.sun.com/docs/hotspot/gc5.0/gc_tuning_5.html
http://java.sun.com/docs/hotspot/gc1.4.2/
官方地址:
http://blogs.oracle.com/poonam/entry/understanding_cms_gc_logs
发表评论
-
Garbage First(G1) 日志分析工具
2012-12-22 22:35 2138G1介绍:http://softbeta.iteye.com/ ... -
Garbage First(G1)介绍
2012-07-08 13:34 2193介绍: Garbage First(G1)致 ... -
ubuntu12.04上编译openjdk7
2012-06-13 15:31 4823获取源码 从openjdk代码仓库获取(比较慢) ... -
jinfo 查看、设置JVM参数
2012-04-25 15:36 5097用法: # jinfo -h Usage: ... -
一些参数,弥补CMS(Concurrent Mark-Sweep)收集器的缺点
2012-03-28 21:11 1636CMS缺点:http://softbeta.iteye ... -
[转载]PrintCompilation 参数解释
2012-03-27 13:59 1503英文不好,所以就不翻译了: b Blocking co ... -
Java内存管理——垃圾收集概念及特点
2012-02-03 12:37 1014碎碎念,介绍Java内存管 ... -
[转载]hotspot源码(JDK7)
2012-01-19 19:25 1495源码结构图,方便理解: ├─agent ... -
跨平台获取java进程id(Process ID in Java)
2012-01-18 19:20 9086原创地址:http://blog.lichengwu.cn/ ... -
[转载]为程序员量身定制的12个目标
2012-01-15 22:38 873对程序员 们来说挑战自我非常重要,要么不断创新,要 ... -
了解CMS(Concurrent Mark-Sweep)垃圾回收器
2011-12-27 20:13 120161.总体介绍: CMS(Concurrent Mark- ... -
利用VisualVM监视远程JVM
2011-11-17 20:06 4606VisualVM介绍 VisualVM是集成了多个JDK命令 ... -
[转载]Java 虚拟机指令
2011-10-28 20:18 7610x00 nop 什么都不做 0x01 acon ... -
[转载]堆和栈的区别
2010-09-07 00:19 769一、预备知识—程序的内存分配 一个由C/C++编译的程序 ... -
浅谈Java垃圾回收
2011-02-25 21:29 691垃圾回收,是java同c++的 ... -
hibernate属性配置
2011-06-16 23:25 3032这些属性有的时候很需要,但是记不住,所以做个备忘。 ... -
JVM问答
2011-07-18 15:12 784大部分内容来源网络, ... -
[转载]毕业奋斗八年成功后有感,给年轻人的10个忠告
2009-07-29 16:06 6021、努力 工作要努 ... -
[转载]年轻人应该知道的71个做饭技巧
2009-09-28 00:04 7391、煮水饺时,在水里放 ... -
[转载]Java开源软件六大帮派
2009-09-28 12:40 692Java 开源软件千千万,就好像一个江湖,有势力的有 ...
相关推荐
GChisto及CMS GC相应补丁文件,补丁文件未亲测。 This patch adds the following features and improvements when using CMS GC in incremental mode: detecting Full GCs corrected parsing errors when using -XX:...
用于分析 java gc日志文件。根据日志中的CMS GC统计信息可得到Full GC(也可以理解为Major GC)以及Minor GC相关数据
【现象】悲催的是运行了几天后,突然有几台机器开始报警,上机器看到的现象是CMS GC的remark竟然花了20s+,而实际上这个时候old也就用了2g+,这个时
这个系统没有去做日志;审核;复杂权限等企业级的功能;主要想的是为中小型互联网站服务;那些复杂臃肿的功能;留给别人去2次开发。不然的话;会严重影响51javacms的推广和应用; 我个人认为java在互联网的应用...
动易cms动易cms动易cms动易cms动易cms动易cms动易cms动易cms动易cms动易cms动易cms动易cms
cms源码 cms源码 cms源码 cms源码 cms源码 cms源码 cms源码 cms源码
仅适用于以下 JVM 参数-verbosegc -XX:+PrintGCDateStamps -XX:+PrintGCTimeStamps -XX:+PrintGCDetails -Xloggc:logs/gc.log和 CMS 收集器。 使用 JDK 6 测试。 #总结报告示例 Total time: 20.51 min Young size ...
Lin 已经内置了 CMS 中最为常见的需求:用户管理、权限管理、日志系统等。开发者只需要集中精力开发自己的 CMS 业务即可。 3、Lin CMS 本身也是一套开发规范 Lin CMS 除了内置常见的功能外,还提供了一套开发规范与...
这个系统没有去做日志;审核;复杂权限等企业级的功能;主要想的是为中小型互联网站服务;那些复杂臃肿的功能;留给别人去2次开发。不然的话;会严重影响51javacms的推广和应用; 我个人认为java在互联网的应用...
cms 相关的理解以及概述
苹果cms在线采集70多个接口,用谷歌浏览器用谷歌浏览器
jvm性能调优-垃圾收集器parnew&CMS底层三色标记算-performance-gc-parnew-cms
微窗 CMS是一款免费开源的微信公众号和支付宝服务窗管理平台系统,... 微窗cms 更新日志:v3.0 bulid 20160527 修复一个高危漏洞(getshell)请尽快升级此版本! 修复借用微信Oauth接口电脑扫码登录失败的bug。
你不需要会安卓开发,不需要对响应式网站布局有极强的理解。保持和你以前的网站建设开发习惯。简单快捷的建立手机网站。极大的降低了手机网站建设的技术投入和开发成本。 大米CMS ASP发布后,受到需多中小企建站的...
企业CMS源码,企业CMS源码,企业CMS源码.
Util6 CMS系统特色后台采用 Layui 2.+ 作为UI支撑,简约界面最大亮点:同时支持N套子系统,并可轻松集成单点登录系统内置菜单、用户、角色、字典、日志等模块,权限控制到按钮数据库SQL记录日志方便调试扩展方便,...
小苹果cms是一个基于苹果cms进行开发的带有采集功能的php视频网站源码。软件特点:1、本程序全部开源2、基于苹果cms二次开发,支持原本苹果cms...性能更稳定小苹果cms V1.1 更新日志:修复一些无用的代码,让运行更稳定
基于thinkphp的cms学生学籍管理系统 功能模块:1.管理员模块 管理学生和用户(班主任和年级主任) 2.教师模块 对学生进行增删改 对自己密码修改 操作步骤: 1.首先将数据库相关操作完成 建立数据库连接 数据表的...
Fork CMS 4.5.4 更新日志 Github:在自述文件找到安全问题时,添加一些提示; Github:在自述文件中修正了错字; 核心:修复了分析区域中的一些打字错误; 核心:修复html5文件输入重新验证不工作; 页面:修复博客...