我们在产品中的一个应用程序遇到问题。
虚拟机配置如下
-XX:MaxPermSize=300M -Xms2560M -Xmx2560M -Xloggc:/app/log/gc-admin-20120619-123754.log -verbose:gc -XX:+PrintGCTimeStamps -XX:+PrintGCDetails -XX:+UseConcMarkSweepGC -XX:CMSInitiatingOccupancyFraction =80 -XX:+DisableExplicitGC -XX:CMSMaxAbortablePrecleanTime=8000
我错过并将应用的两个选项是 XX:PermSize - 应该与 MaxPermSize 相同(推荐) UseCMSInitiatingOccupancyOnly 当使用 CMSInitiatingOccupancyFraction 时,否则您指定的值不会坚持!
然而,随着管道的这些变化,我不太相信它会解决我的问题。
我看到并发模式失败,但是当失败发生时,世界集合的停止需要永恒。目前我有点困惑为什么!
这是一些示例
168427.476: [GC [1 CMS-initial-mark: 2135988K(2578880K)] 2141041K(2617216K), 3.1029210 secs] [Times: user=0.02 sys=0.01, real=3.10 secs] 168430.596: [CMS-concurrent-mark--mark-secs] ] 168441.309: [GC 168441.309: [ParNew: 36520K->36520K(38336K), 0.0000210 secs]168441.309: [CMS168747.453: [CMS-concurrent-mark: 309.313/316.8575 secs=2.8s: 用户,sys.8575 secs=2.8s real=316.81 secs](并发模式失败):2561882K->1310927K(2578880K), 767.0309740 secs] 2598402K->1310927K(2617216K), [CMS Perm : 96774K->96171K(158792K), 7674K->96171K(158792K) 76 s [158792K]. =3.87 系统=5.06,真实=766.92 秒]
让我担心整个 STW 集合的是时间 766.92 秒,但 CPU 时间只有“user=3.87 sys=5.06”,那么剩下的时间里发生了什么?这就是我感到困惑的地方,我无法想象停止应用程序中的所有线程需要那么长时间!可能会折腾??
169545.325: [GC [1 CMS-initial-mark: 2141069K(2578880K)] 2166025K(2617216K), 0.0530140 secs] [Times: user=0.05 sys=0.00, real=0.06 secs] 169545.379: [CMS-concurrent-mark--mark-secs] ] 169558.635:[CMS 并发标记:10.407/13.256 秒] [时间:用户 = 7.58 系统 = 0.53,真实 = 13.25 秒] 169558.635:[CMS 并发预清理启动] 169558.684:[CMS 并发预清理: 0.048/0.048 秒] [时间:用户 = 0.01 系统 = 0.00,实际 = 0.05 秒] 169558.684:[CMS 并发中止预清理启动] 169560.544:[GC 169560.544:[ParNew169560.605:[CMS 并发中止-preclean: 0.210/1.921 secs] [Times: user=0.93 sys=0.05, real=1.92 secs] 169560.846: [GC [YG occupancy: 1906 K (38336 K)]169560.846: [Rescan (parallel) , 0.0046910 secs]169560. :[弱 refs 处理,0.0000990 秒] [1 CMS 备注:2350428K(2578880K)] 2352335K(2617216K),0.0048570 秒] [时间:user=0.01 sys=0.00, real=0.01 secs] 169560.853: [CMS-concurrent-sweep-start] 169568.204: [CMS-concurrent-sweep: 7.351/7.351 secs] [Times: user=0.91 sys=0.09, real=7.34 secs] 169568.204:[CMS-concurrent-reset-start] 169568.211:[CMS-concurrent-reset:0.007/0.007 secs] [Times:user=0.01 sys=0.00,real=0.01 secs]
这个显示没有问题
252247.318: [GC [1 CMS-initial-mark: 2069401K(2578880K)] 2075094K(2617216K), 1.5311840 secs] [Times: user=0.01 sys=0.00, real=1.53 secs] 252248.849: [CMS-concurrent-mark--mark-secs] ] 252350.336: [GC 252350.336: [ParNew: 20984K->4222K(38336K), 12.2251190 secs]252362.561: [CMS252520.780: [CMS-concurrent-mark: 161.376/271.922 secs] = 1s.7 用户,2.56 秒real=271.89 secs](并发模式失败):2232372K->1061586K(2578880K), 407.2310250 secs] 2240205K->1061586K(2617216K), [CMS Perm : 97525K->97381K41s [1604880K450].Time].Time =4.23 系统=2.99,真实=419.39 秒]
然后是另一个巨大的“Times: user=4.23 sys=2.99, real=419.39 secs”。CPU 时间是次要的“user=4.23 sys=2.99”,但总时间是“419.39”。什么可能导致VM挂起这么长时间?理想情况下,2.5g 应该在 10 秒内收集到 STW 集合中!!
我要降低阈值 CMSInitiatingOccupancyFraction 但我认为这样的收集时间不会有帮助!有些系列运行顺利,有些则不顺利,但就像我说的那样,当世界完全停止时,我担心的是时机。
我已阅读 https://blogs.oracle.com/jonthecollector/entry/what_the_heck_s_a
我们正在使用jdk6。
有人曾经经历过类似的事情吗?