我预先承认,这个问题非常类似于:大量cms标记/备注暂停,即使旧版还没有满一半,并且无明显原因开始使用终身收藏。我发帖是因为1。这些线已经有1年多的历史了,还有2年。我希望学习如何找到这种行为的根本原因。
我们有一个OAS/OC4J(这不是我们的错!)运行在RHEL5/Redhat 5.11、Java 6上的全天候Java应用服务器。这在内存方面已经稳定了很多年,直到最近,由于频繁的CMS终身空间周期,我们开始看到高CPU利用率。即使年轻和终身空间都有足够的空间,这种情况也会发生。我对这一主题的阅读表明,CMS的长期周期通常始于长期(旧代)空间约为容量的92%时。但我们看到这种情况反复发生,30%的容量甚至更少。另外,我应该提到的是,当总堆似乎小于总堆使用率的默认值45%时,也就是InitiatingHeapOccupencyPercent
。
我们仍在审查最近的代码更改,并尝试了一些事情,但这些问题仍然存在。到目前为止,我们无法在生产服务器之外进行复制,尽管在开发/质量保证环境中的工作仍在进行中。
我想我有三个主要问题:
-XX: UseCMSLaunatingCraancyOnly
和-XX: CMSLaunatingCraancyFraction=NN
(例如在上面引用的文章中)。什么可能是NN的合理(==安全)值,以及以这种方式覆盖默认CMS人体工程学的风险是什么?-XX:PrintGCDetails
-XX:PrintGCDateStamps-XX:PrintTenuringDistribution-XX:TraceClassUnloading-XX:UseCommarkSweepGC-XX:CMSClassUnloadingEnabled-XX:HeapDumpOnAutofmemoryError-XX:ExplicitgVokesConcurrent-XX:UseCompactFullCollection-Xms10g-Xmx10g
-Xmn3g-XX:SurvivorRatio=6-XX:PermSize=256m-XX:MaxPermSize=256m-XX:TargetSurvivorRatio=80-XX:parallegcthreads=8
注意:我们最近尝试将年轻一代提高到3.5克,这是一个有点绝望的实验。(在生产中!)没有观察到真正的明显差异
jmap-heap
。注意:From Space
似乎总是100%被占用。这是正常的,还是表示什么?:
using parallel threads in the new generation.
using thread-local object allocation.
Concurrent Mark-Sweep GCHeap Configuration:
MinHeapFreeRatio = 40
MaxHeapFreeRatio = 70
MaxHeapSize = 10737418240 (10240.0MB)
NewSize = 3758096384 (3584.0MB)
MaxNewSize = 3758096384 (3584.0MB)
OldSize = 5439488 (5.1875MB)
NewRatio = 2
SurvivorRatio = 6
PermSize = 268435456 (256.0MB)
MaxPermSize = 268435456 (256.0MB)
Heap Usage:
New Generation (Eden + 1 Survivor Space):
capacity = 3288334336 (3136.0MB)
used = 1048575408 (999.9994354248047MB)
free = 2239758928 (2136.0005645751953MB)
31.88773709900525% used
Eden Space:
capacity = 2818572288 (2688.0MB)
used = 578813360 (551.9994354248047MB)
free = 2239758928 (2136.0005645751953MB)
20.535693282172794% used
From Space:
capacity = 469762048 (448.0MB)
used = 469762048 (448.0MB)
free = 0 (0.0MB)
100.0% used
To Space:
capacity = 469762048 (448.0MB)
used = 0 (0.0MB)
free = 469762048 (448.0MB)
0.0% used
concurrent mark-sweep generation:
capacity = 6979321856 (6656.0MB)
used = 1592989856 (1519.1935119628906MB)
free = 5386332000 (5136.806488037109MB)
22.82442175425016% used
Perm Generation:
capacity = 268435456 (256.0MB)
used = 249858712 (238.2838363647461MB)
free = 18576744 (17.716163635253906MB)
93.07962357997894% used
- 来自内部GC Log解析器的输出,显示频繁的初始标记(IM)/备注(RM)周期,以及较低的年轻/终身占用率。您可以看到Young gen占用率慢慢增长到98.30%,之后不久我们就会执行预期的
ParNew
(PN)Young GC:
| | PN: |YHeapB4|YHeapAf|YHeapDt|
| |------|-------|-------|-------|
| |PF,CF,| | | |
| | SY: |OHeapB4|OHeapAf|OHeapDt|
| |------|-------|-------|-------|
Date |Time |IM,RM:|Y Occ% |OHeap |O Occ% |Duration|THeapB4|THeapAf|THeapDt|Promoted|% Garbage|Interval| Alloc |AllocRate(MB/s)|PromoRate(MB/s)
------------------------------------------------------------------------------------------------------------------------------------------------------------
2016-12-05|14:16:59.455| RM | 15.11|1620287| 23.77| 0.18
2016-12-05|14:17:03.057| IM | 16.16|1615358| 23.70| 0.66
2016-12-05|14:17:13.444| RM | 17.70|1615358| 23.70| 0.23
2016-12-05|14:17:17.227| IM | 18.82|1513691| 22.21| 0.70
2016-12-05|14:17:27.887| RM | 28.54|1513691| 22.21| 0.33
2016-12-05|14:17:30.390| IM | 29.45|1513667| 22.21| 1.02
2016-12-05|14:17:41.326| RM | 32.90|1513667| 22.21| 0.66
2016-12-05|14:17:44.290| IM | 34.86|1513666| 22.21| 1.23
...[deleted for brevity]...
2016-12-05|14:37:28.024| IM | 95.88|1377444| 20.21| 2.93
2016-12-05|14:37:40.601| RM | 95.89|1377444| 20.21| 2.15
2016-12-05|14:37:46.032| IM | 95.89|1377443| 20.21| 2.83
2016-12-05|14:37:58.557| RM | 98.30|1377443| 20.21| 2.21
2016-12-05|14:38:03.988| IM | 98.30|1377307| 20.21| 2.90
2016-12-05|14:38:15.638| PN |3211264| 458752|2752512| 0.77|4588571|1942900|2645671| 106841| 96.12
2016-12-05|14:38:18.193| RM | 18.04|1484148| 21.78| 0.24
2016-12-05|14:38:21.813| IM | 18.04|1480802| 21.73| 0.75
2016-12-05|14:38:31.822| RM | 19.05|1480802| 21.73| 0.34
...[and so on]...
- 实际GC日志输出从上面输出的
14:17:03.057
处的第一个初始标记(IM)开始。与上面类似地截断,但我确实显示了ParNew Young GC以保持完整性:
2016-12-05T14:17:03.057-0800: [GC [1 CMS-initial-mark: 1615358K(6815744K)] 2134211K(10027008K), 0.6538170 secs] [Times: user=0.65 sys=0.00, real=0.66 secs]
2016-12-05T14:17:06.178-0800: [CMS-concurrent-mark: 2.463/2.467 secs] [Times: user=5.04 sys=0.01, real=2.46 secs]
2016-12-05T14:17:06.251-0800: [CMS-concurrent-preclean: 0.072/0.073 secs] [Times: user=0.07 sys=0.00, real=0.08 secs]
CMS: abort preclean due to time 2016-12-05T14:17:13.442-0800: [CMS-concurrent-abortable-preclean: 7.189/7.192 secs] [Times: user=7.46 sys=0.02, real=7.19 secs]
2016-12-05T14:17:13.444-0800: [GC[YG occupancy: 568459 K (3211264 K)][Rescan (parallel) , 0.1020240 secs][weak refs processing, 0.0312140 secs][class unloading, 0.0396040 secs][scrub symbol & string tables, 0.0368990 secs] [1 CMS-remark: 1615358K(6815744K)] 2183818K(10027008K), 0.2344980 secs] [Times: user=0.89 sys=0.00, real=0.23 secs]
2016-12-05T14:17:15.212-0800: [CMS-concurrent-sweep: 1.533/1.533 secs] [Times: user=1.54 sys=0.00, real=1.54 secs]
2016-12-05T14:17:15.225-0800: [CMS-concurrent-reset: 0.013/0.013 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
2016-12-05T14:17:17.227-0800: [GC [1 CMS-initial-mark: 1513691K(6815744K)] 2118034K(10027008K), 0.7036950 secs] [Times: user=0.71 sys=0.00, real=0.70 secs]
2016-12-05T14:17:20.548-0800: [CMS-concurrent-mark: 2.613/2.617 secs] [Times: user=5.62 sys=0.03, real=2.62 secs]
2016-12-05T14:17:20.667-0800: [CMS-concurrent-preclean: 0.113/0.119 secs] [Times: user=0.23 sys=0.00, real=0.12 secs]
CMS: abort preclean due to time 2016-12-05T14:17:27.886-0800: [CMS-concurrent-abortable-preclean: 7.217/7.219 secs] [Times: user=8.54 sys=0.07, real=7.22 secs]
2016-12-05T14:17:27.887-0800: [GC[YG occupancy: 916526 K (3211264 K)][Rescan (parallel) , 0.2159770 secs][weak refs processing, 0.0000180 secs][class unloading, 0.0460640 secs][scrub symbol & string tables, 0.0404060 secs] [1 CMS-remark: 1513691K(6815744K)] 2430218K(10027008K), 0.3276590 secs] [Times: user=1.59 sys=0.02, real=0.33 secs]
2016-12-05T14:17:29.611-0800: [CMS-concurrent-sweep: 1.396/1.396 secs] [Times: user=1.40 sys=0.00, real=1.39 secs]
...[And So On]...
2016-12-05T14:38:03.988-0800: [GC [1 CMS-initial-mark: 1377307K(6815744K)] 4534072K(10027008K), 2.9013180 secs] [Times: user=2.90 sys=0.00, real=2.90 secs]
2016-12-05T14:38:09.403-0800: [CMS-concurrent-mark: 2.507/2.514 secs] [Times: user=5.03 sys=0.03, real=2.51 secs]
2016-12-05T14:38:09.462-0800: [CMS-concurrent-preclean: 0.058/0.058 secs] [Times: user=0.06 sys=0.00, real=0.06 secs]
2016-12-05T14:38:15.638-0800: [GC [ParNew
Desired survivor size 375809632 bytes, new threshold 4 (max 15)
- age 1: 115976192 bytes, 115976192 total
- age 2: 104282224 bytes, 220258416 total
- age 3: 85871464 bytes, 306129880 total
- age 4: 98122648 bytes, 404252528 total
: 3211264K->458752K(3211264K), 0.7731320 secs] 4588571K->1942900K(10027008K), 0.7732860 secs] [Times: user=3.15 sys=0.00, real=0.77 secs]
CMS: abort preclean due to time 2016-12-05T14:38:18.192-0800: [CMS-concurrent-abortable-preclean: 7.842/8.730 secs] [Times: user=12.50 sys=0.07, real=8.73 secs]
2016-12-05T14:38:18.193-0800: [GC[YG occupancy: 579220 K (3211264 K)][Rescan (parallel) , 0.1208810 secs][weak refs processing, 0.0008320 secs][class unloading, 0.0483220 secs][scrub symbol & string tables, 0.0414970 secs] [1 CMS-remark: 1484148K(6815744K)] 2063368K(10027008K), 0.2376050 secs] [Times: user=1.07 sys=0.00, real=0.24 secs]
2016-12-05T14:38:19.798-0800: [CMS-concurrent-sweep: 1.366/1.366 secs] [Times: user=1.40 sys=0.00, real=1.37 secs]
2016-12-05T14:38:19.811-0800: [CMS-concurrent-reset: 0.012/0.012 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
2016-12-05T14:38:21.813-0800: [GC [1 CMS-initial-mark: 1480802K(6815744K)] 2060239K(10027008K), 0.7487000 secs] [Times: user=0.75 sys=0.00, real=0.75 secs]
根据Alexey出色的观察和建议,我们将尝试在生产中增加Perm Gener(我会报告)。但作为对他猜测的初步验证,我对我们一台主机上所有容器JVM的perm gen使用情况进行了调查,这似乎非常合理。在下面的片段中,PID=2979(perm gen容量为92%)是表现出恒定CMS收集行为的一个。
[oracle@ikm-oasb-3 bin]$ for p in `opmnctl status | grep OC4JG | awk '{print $5}'`; do echo -n "PID=$p "; jmap -heap $p | grep -A4 'Perm Gen' | egrep '%'; done 2> /dev/null
PID=8456 89.31778371334076% used
PID=8455 89.03931379318237% used
PID=8454 91.1630779504776% used
PID=8453 89.17466700077057% used
PID=8452 87.69496977329254% used
PID=2979 92.2750473022461% used
PID=1884 90.25585949420929% used
PID=785 76.16643011569977% used
PID=607 89.06879723072052% used
CMS旧空间清理周期当旧空间达到占用阈值或永久空间达到阈值时触发。
在Java8之前,永久空间是垃圾收集堆的一部分,属于CMS算法的范围。
你的烫发率是93%
Perm Generation:
capacity = 268435456 (256.0MB)
used = 249858712 (238.2838363647461MB)
free = 18576744 (17.716163635253906MB)
93.07962357997894% used
本文描述了类似的情况。
如果建议您增加烫发空间,或者您可以使用-XX: CMSLaunatingPerm占领分数=95
选项为烫发空间配置单独的占用阈值。
更多GC调优选项。
我们使用G1收集器<当一个年轻的GC发生时(不是混合GC),堆的变化:[Eden:3666.0M(3666.0M)- 堆的变化为4819.1M(5346.0-526.9) 伊甸园改变了3666.0(3666.0-0.0)和幸存者-34M(20-54);为什么堆的变化不等于伊甸园和幸存者的总和(4819.1不等于(3666.0-34))?年轻的GC清除对象在老一代? gc日志:
问题内容: 我对Heap,Young,Tenured和Perm一代感到困惑。 谁能解释一下? 问题答案: Java垃圾收集器被称为分 代垃圾收集器 。应用程序中的对象生存的时间长短不一,具体取决于它们的创建位置和使用方式。此处的主要见解在于,针对短期和长期对象使用不同的垃圾回收策略,可以针对每种情况专门优化GC。 松散地说,当对象在新 世代中 “生存”重复的垃圾回收时,它们将迁移到 终身代 。该
我正在为max分配8GB内存给Java编写的应用程序。它会内存溢出。我相信年轻一代总是比默认情况下的老一代小(堆的1/4)。而Eden/幸存者1,2在年轻一代内部。我相信在Eden空间中创建了新对象。 即使老一代还没有满,但年轻一代已经完全满了,java应用程序还是会耗尽内存吗? 如果短寿命的对象比长寿命的对象多,那么可以为年轻一代分配更多内存,或者至少将堆的50%分配给年轻一代吗?或者,由于jv
我目前正在尝试创建带有python文件和大量额外软件包的docker映像。txt。 当我运行命令“sudo docker build-t XXX”时软件包被一个接一个地下载和安装,直到我收到一个错误:“由于环境错误,无法安装软件包:[Errno 28]设备上没有剩余空间” 我已经做了“sudo docker system prune”的原子选项,所有过去的docker镜像都被删除了。 此外,“su
据我所知,对于旧一代JVM中的空间,它可以用于两个目的, 用于从年轻一代升级到老一代的物品 用于特殊用例中的新对象分配(https://stackoverflow.com/questions/9053144/will-i-encounter-java-lang-outofmemoryerror-even-with-no-lack-of-memory) 我的问题是, 在老一代中,是否还有其他利用空间
在某个时刻,我的应用程序开始创建许多临时阵列,这是预期的行为,我想给年轻一代提供大量空间,所以临时阵列不会被提升到终身一代。 JVM选项: 在某些时候,我的GC日志开始看起来像这样: 我非常困惑的事实,年轻一代的大小是629120K(=629M),而我预计它是约1/2(因为NewRatio=2)的终身一代大小这是158690816K(=158G)。终身大小生成对应于NewRatio和Xms的预期,