我的应用程序在某个时刻运行 util,JVM 一遍又一遍地递归地执行次要垃圾收集,并且永不停止。我的 java 命令行:
java -Xmx4G -Xms4G -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -Xloggc:/home/root/gc.log -jar myApp.jar
GC 输出:
4.238: [Full GC [PSYoungGen: 21968K->9997K(420864K)] [ParOldGen: 74537K->83814K(150144K)] 96505K->93811K(571008K) [PSPermGen: 10761K->10757K(21824K)], 0.3216090 secs] [Times: user=0.99 sys=0.01, real=0.32 secs]
8.660: [GC [PSYoungGen: 400333K->23552K(517568K)] 484147K->117422K(667712K), 0.0554510 secs] [Times: user=0.22 sys=0.00, real=0.06 secs]
8.979: [GC [PSYoungGen: 517504K->23488K(632384K)] 611374K->117358K(782528K), 0.0263860 secs] [Times: user=0.09 sys=0.01, real=0.03 secs]
9.333: [GC [PSYoungGen: 622208K->32K(637888K)] 716078K->117418K(788032K), 0.0249140 secs] [Times: user=0.09 sys=0.01, real=0.02 secs]
9.656: [GC [PSYoungGen: 603040K->32K(603072K)] 720426K->117418K(753216K), 0.0059430 secs] [Times: user=0.02 sys=0.00, real=0.00 secs]
9.960: [GC [PSYoungGen: 603040K->32K(638464K)] 720426K->117418K(788608K), 0.0051460 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
10.263: [GC [PSYoungGen: 602464K->32K(602496K)] 719850K->117418K(752640K), 0.0037990 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
10.575: [GC [PSYoungGen: 602464K->32K(638656K)] 719850K->117418K(788800K), 0.0037570 secs] [Times: user=0.02 sys=0.00, real=0.00 secs]
10.876: [GC [PSYoungGen: 603168K->32K(637952K)] 720554K->117418K(788096K), 0.0039310 secs] [Times: user=0.02 sys=0.00, real=0.00 secs]
11.180: [GC [PSYoungGen: 603168K->32K(638528K)] 720554K->117418K(788672K), 0.0039980 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
11.480: [GC [PSYoungGen: 605216K->64K(637952K)] 722602K->117450K(788096K), 0.0036720 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
11.786: [GC [PSYoungGen: 605248K->64K(640384K)] 722634K->117450K(790528K), 0.0049470 secs] [Times: user=0.02 sys=0.00, real=0.00 secs]
12.091: [GC [PSYoungGen: 609664K->32K(639872K)] 727050K->117418K(790016K), 0.0051130 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
12.395: [GC [PSYoungGen: 609632K->32K(642752K)] 727018K->117418K(792896K), 0.0042050 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
12.704: [GC [PSYoungGen: 614816K->32K(642304K)] 732202K->117418K(792448K), 0.0036980 secs] [Times: user=0.01 sys=0.01, real=0.00 secs]
13.012: [GC [PSYoungGen: 614816K->32K(645504K)] 732202K->117418K(795648K), 0.0040370 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
Heap
PSYoungGen total 1397696K, used 1209524K [0x00000007aaab0000, 0x0000000800000000, 0x0000000800000000)
eden space 1397312K, 86% used [0x00000007aaab0000,0x00000007f47cd078,0x00000007fff40000)
from space 384K, 16% used [0x00000007fffa0000,0x00000007fffb0000,0x0000000800000000)
to space 384K, 0% used [0x00000007fff40000,0x00000007fff40000,0x00000007fffa0000)
ParOldGen total 2796224K, used 98577K [0x0000000700000000, 0x00000007aaab0000, 0x00000007aaab0000)
object space 2796224K, 3% used [0x0000000700000000,0x0000000706044600,0x00000007aaab0000)
PSPermGen total 21248K, used 11122K [0x00000006fae00000, 0x00000006fc2c0000, 0x0000000700000000)
object space 21248K, 52% used [0x00000006fae00000,0x00000006fb8dca60,0x00000006fc2c0000)
jvm 永远执行次要 gcs 时的 Jstack 输出:
"Service Thread" daemon prio=6 tid=0x0000000010e51000 nid=0x3c8c runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"C2 CompilerThread1" daemon prio=10 tid=0x0000000010e50000 nid=0x449c waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"C2 CompilerThread0" daemon prio=10 tid=0x0000000010e3d800 nid=0x46b8 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Attach Listener" daemon prio=10 tid=0x0000000010e3c800 nid=0x37c8 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Signal Dispatcher" daemon prio=10 tid=0x0000000010e35000 nid=0x4088 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Finalizer" daemon prio=8 tid=0x0000000002186000 nid=0x3df8 in Object.wait() [0x000000001216f000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x0000000001fcd4d0> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
- locked <0x0000000001fcd4d0> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)
at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:177)
"Reference Handler" daemon prio=10 tid=0x000000000217f800 nid=0x1cfc in Object.wait() [0x0000000011f5f000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x0000000001fcf510> (a java.lang.ref.Reference$Lock)
at java.lang.Object.wait(Object.java:503)
at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133)
- locked <0x0000000001fcf510> (a java.lang.ref.Reference$Lock)
"main" prio=6 tid=0x000000000208d000 nid=0x4704 runnable [0x000000000244e000]
java.lang.Thread.State: RUNNABLE
at java.util.regex.Pattern.atom(Pattern.java:2199)
at java.util.regex.Pattern.sequence(Pattern.java:2097)
at java.util.regex.Pattern.expr(Pattern.java:1964)
at java.util.regex.Pattern.compile(Pattern.java:1665)
at java.util.regex.Pattern.<init>(Pattern.java:1337)
at java.util.regex.Pattern.compile(Pattern.java:1022)
at java.util.regex.Pattern.matches(Pattern.java:1128)
at com.app.Search.search(Search.java:100)
"VM Thread" prio=10 tid=0x0000000010d92800 nid=0x4208 runnable
"GC task thread#0 (ParallelGC)" prio=6 tid=0x00000000020d4800 nid=0x4538 runnable
"GC task thread#1 (ParallelGC)" prio=6 tid=0x00000000020d6000 nid=0x4390 runnable
"GC task thread#2 (ParallelGC)" prio=6 tid=0x00000000020d7800 nid=0x4874 runnable
"GC task thread#3 (ParallelGC)" prio=6 tid=0x00000000020d9800 nid=0x4558 runnable
"VM Periodic Task Thread" prio=10 tid=0x0000000010e62000 nid=0x455c waiting on condition
JNI global references: 189
Search.search() 搜索匹配给定正则表达式的字符串,代码
Pattern pattern = Pattern.compile(regex);
final Set<String> result = new HashSet<>();
for (final String word : words) {
if (pattern.matcher(word).matches()) {
result.add(word);
}
}
谢谢。
最佳答案
根据您的一个示例(更多示例会有所帮助),您似乎在这里制造了大量垃圾。
at java.util.regex.Pattern.<init>(Pattern.java:1337)
at java.util.regex.Pattern.compile(Pattern.java:1022)
at java.util.regex.Pattern.matches(Pattern.java:1128)
at com.app.Search.search(Search.java:100)
编译模式会创建很多对象,我建议尽可能少这样做(如果有的话)
要获得更多信息,您确实需要使用内存分析器。尝试 VisualVM,它内置于 JDK 或 Java Mission Control,如果你有 Java 7 更新 40+
JVM recursively does minor garbage collections over and over again and never stops.
我怀疑你的意思是重复,而不是递归。
这就是 GC 的设计目的。您正在创建大量的短期对象,而 GC 正在快速清理。
可疑的是 GC 运行的干净程度。这是一个只会产生垃圾的简单程序吗?如果说真正的应用程序有更丑陋的日志的话。
您每秒产生大约 2 GB 的垃圾。这是一些旧系统的上限,而较新的系统每秒可以产生大约 8 GB。
我怀疑如果您使用内存分析器,您可以消除您正在创建的大部分垃圾,并且您的程序会运行得更快。
jvm is doing forever minor gcs:
不是,你可以把3秒内GC的时间加起来就可以了。
10.263: [GC [PSYoungGen: 602464K->32K(602496K)] 719850K->117418K(752640K), 0.0037990 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
10.575: [GC [PSYoungGen: 602464K->32K(638656K)] 719850K->117418K(788800K), 0.0037570 secs] [Times: user=0.02 sys=0.00, real=0.00 secs]
10.876: [GC [PSYoungGen: 603168K->32K(637952K)] 720554K->117418K(788096K), 0.0039310 secs] [Times: user=0.02 sys=0.00, real=0.00 secs]
11.180: [GC [PSYoungGen: 603168K->32K(638528K)] 720554K->117418K(788672K), 0.0039980 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
11.480: [GC [PSYoungGen: 605216K->64K(637952K)] 722602K->117450K(788096K), 0.0036720 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
11.786: [GC [PSYoungGen: 605248K->64K(640384K)] 722634K->117450K(790528K), 0.0049470 secs] [Times: user=0.02 sys=0.00, real=0.00 secs]
12.091: [GC [PSYoungGen: 609664K->32K(639872K)] 727050K->117418K(790016K), 0.0051130 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
12.395: [GC [PSYoungGen: 609632K->32K(642752K)] 727018K->117418K(792896K), 0.0042050 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
12.704: [GC [PSYoungGen: 614816K->32K(642304K)] 732202K->117418K(792448K), 0.0036980 secs] [Times: user=0.01 sys=0.01, real=0.00 secs]
13.012: [GC [PSYoungGen: 614816K->32K(645504K)] 732202K->117418K(795648K), 0.0040370 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
在 2.749 秒内花在 GC 上的总时间是 0.037 秒,这意味着只有 1.4% 的时间在 GC 中,所以 98.6% 的时间不是 GCing。
关于java - JVM 一遍又一遍地进行次要垃圾收集,从不抛出 OutOfMemoryError,我们在Stack Overflow上找到一个类似的问题: https://stackoverflow.com/questions/18916801/