java更新停止程序_Java-JVM垃圾收集应用程序停止时间差异

我正在使用以下版本的Java运行tomcat的大型实例：

Java版本“ 1.6.0_20”

OpenJDK运行时环境(IcedTea6 1.9.7)(6b20-1.9.7-0ubuntu1?10.04.1

OpenJDK 64位服务器VM(内部版本19.0-b09,混合模式)

并设置以下参数：

-Xms13152m

-Xmx13152m

-Xmn768m

-XX:+UseConcMarkSweepGC

-XX:CMSInitiatingOccupancyFraction=60

-XX:+CMSIncrementalMode

-XX:+CMSIncrementalPacing

-XX:CMSIncrementalDutyCycleMin=0

-XX:CMSIncrementalDutyCycle=10

-XX:+DisableExplicitGC

启用GC调试语句.每隔几个小时,我就会看到发生次要GC并长时间停止应用程序的行为,但是GC本身似乎并没有花费那么长时间：

{Heap before GC invocations=392 (full 74):

par new generation total 707840K, used 698252K [0x00000004bfa00000, 0x00000004efa00000, 0x00000004efa00000)

eden space 629248K, 99% used [0x00000004bfa00000, 0x00000004e607de48, 0x00000004e6080000)

from space 78592K, 87% used [0x00000004ead40000, 0x00000004ef0a5370, 0x00000004efa00000)

to space 78592K, 0% used [0x00000004e6080000, 0x00000004e6080000, 0x00000004ead40000)

concurrent mark-sweep generation total 12681216K, used 10877603K [0x00000004efa00000, 0x00000007f5a00000, 0x00000007f5a00000)

concurrent-mark-sweep perm gen total 50260K, used 30106K [0x00000007f5a00000, 0x00000007f8b15000, 0x0000000800000000)

13120.154: [GC 13120.154: [ParNew Desired survivor size 40239104 bytes, new threshold 1 (max 4) - age 1: 41912720 bytes, 41912720 total: 698252K->41387K(707840K), 0.1239080 secs] 11575856K->10987714K(13389056K) icms_dc=20 , 0.1239930 secs] [Times: user=0.00 sys=0.00, real=0.12 secs]

Heap after GC invocations=393 (full 74):

par new generation total 707840K, used 41387K [0x00000004bfa00000, 0x00000004efa00000, 0x00000004efa00000)

eden space 629248K, 0% used [0x00000004bfa00000, 0x00000004bfa00000, 0x00000004e6080000)

from space 78592K, 52% used [0x00000004e6080000, 0x00000004e88eace0, 0x00000004ead40000)

to space 78592K, 0% used [0x00000004ead40000, 0x00000004ead40000, 0x00000004efa00000)

concurrent mark-sweep generation total 12681216K, used 10946327K [0x00000004efa00000, 0x00000007f5a00000, 0x00000007f5a00000)

concurrent-mark-sweep perm gen total 50260K, used 30106K [0x00000007f5a00000, 0x00000007f8b15000, 0x0000000800000000)

}

Total time for which application threads were stopped: 32.1614890 seconds

在这种情况下,我希望GC最多将应用程序停止0.12秒.有谁知道为什么应用程序停止时间和GC时间之间会有如此巨大的差异？

更新

我在GClog中包含了更长的代码段：

{Heap before GC invocations=201 (full 18):

par new generation total 707840K, used 639557K [0x00000004c4e00000, 0x00000004f4e00000, 0x00000004f4e00000)

eden space 629248K, 100% used [0x00000004c4e00000, 0x00000004eb480000, 0x00000004eb480000)

from space 78592K, 13% used [0x00000004eb480000, 0x00000004ebe917e8, 0x00000004f0140000)

to space 78592K, 0% used [0x00000004f0140000, 0x00000004f0140000, 0x00000004f4e00000)

concurrent mark-sweep generation total 12681216K, used 6634693K [0x00000004f4e00000, 0x00000007fae00000, 0x00000007fae00000)

concurrent-mark-sweep perm gen total 47232K, used 28977K [0x00000007fae00000, 0x00000007fdc20000, 0x0000000800000000)

2011-04-12T18:42:16.450+0000: 12770.352: [GC 12770.352: [ParNew

Desired survivor size 40239104 bytes, new threshold 15 (max 15)

- age 1: 3701392 bytes, 3701392 total

- age 2: 517360 bytes, 4218752 total

- age 3: 2113840 bytes, 6332592 total

- age 4: 3489008 bytes, 9821600 total

: 639557K->12278K(707840K), 0.0948620 secs] 7274251K->6646972K(13389056K) icms_dc=0 , 0.0949550 secs] [Times: user=0.00 sys=0.00, real=0.10 secs]

Heap after GC invocations=202 (full 18):

par new generation total 707840K, used 12278K [0x00000004c4e00000, 0x00000004f4e00000, 0x00000004f4e00000)

eden space 629248K, 0% used [0x00000004c4e00000, 0x00000004c4e00000, 0x00000004eb480000)

from space 78592K, 15% used [0x00000004f0140000, 0x00000004f0d3dbf0, 0x00000004f4e00000)

to space 78592K, 0% used [0x00000004eb480000, 0x00000004eb480000, 0x00000004f0140000)

concurrent mark-sweep generation total 12681216K, used 6634693K [0x00000004f4e00000, 0x00000007fae00000, 0x00000007fae00000)

concurrent-mark-sweep perm gen total 47232K, used 28977K [0x00000007fae00000, 0x00000007fdc20000, 0x0000000800000000)

}

Total time for which application threads were stopped: 0.0952670 seconds

Application time: 5.0191420 seconds

Total time for which application threads were stopped: 0.0001670 seconds

Application time: 2.2198130 seconds

Total time for which application threads were stopped: 0.0004480 seconds

Application time: 5.5295710 seconds

Total time for which application threads were stopped: 0.0001950 seconds

Application time: 0.0097140 seconds

Total time for which application threads were stopped: 0.0000530 seconds

Application time: 7.1299730 seconds

Total time for which application threads were stopped: 0.0001610 seconds

Application time: 12.0198160 seconds

Total time for which application threads were stopped: 0.0001550 seconds

Application time: 1.5298610 seconds

Total time for which application threads were stopped: 0.0001630 seconds

Application time: 0.0097650 seconds

Total time for which application threads were stopped: 0.0000590 seconds

Application time: 0.1199330 seconds

Total time for which application threads were stopped: 0.0000550 seconds

Application time: 10.0998880 seconds

Total time for which application threads were stopped: 0.0003490 seconds

Application time: 1.0093980 seconds

Total time for which application threads were stopped: 0.0003040 seconds

Application time: 0.6099830 seconds

Total time for which application threads were stopped: 0.0001700 seconds

Application time: 0.0298490 seconds

Total time for which application threads were stopped: 0.0000930 seconds

Application time: 0.2025080 seconds

Total time for which application threads were stopped: 0.0023430 seconds

Application time: 0.0190510 seconds

Total time for which application threads were stopped: 0.0003010 seconds

Application time: 0.1793310 seconds

Total time for which application threads were stopped: 0.0002150 seconds

Application time: 0.0560830 seconds

Total time for which application threads were stopped: 0.0010000 seconds

Application time: 1.7072960 seconds

{Heap before GC invocations=202 (full 18):

par new generation total 707840K, used 641302K [0x00000004c4e00000, 0x00000004f4e00000, 0x00000004f4e00000)

eden space 629248K, 99% used [0x00000004c4e00000, 0x00000004eb447fd8, 0x00000004eb480000)

from space 78592K, 15% used [0x00000004f0140000, 0x00000004f0d3dbf0, 0x00000004f4e00000)

to space 78592K, 0% used [0x00000004eb480000, 0x00000004eb480000, 0x00000004f0140000)

concurrent mark-sweep generation total 12681216K, used 6634693K [0x00000004f4e00000, 0x00000007fae00000, 0x00000007fae00000)

concurrent-mark-sweep perm gen total 47232K, used 29039K [0x00000007fae00000, 0x00000007fdc20000, 0x0000000800000000)

2011-04-12T18:43:04.052+0000: 12817.954: [GC 12817.955: [ParNew

Desired survivor size 40239104 bytes, new threshold 4 (max 15)

- age 1: 36162128 bytes, 36162128 total

- age 2: 2531664 bytes, 38693792 total

- age 3: 420840 bytes, 39114632 total

- age 4: 2052544 bytes, 41167176 total

- age 5: 3484040 bytes, 44651216 total

: 641302K->44375K(707840K), 0.2037750 secs] 7275996K->6679069K(13389056K) icms_dc=0 , 0.2039060 secs] [Times: user=0.00 sys=0.00, real=0.21 secs]

Heap after GC invocations=203 (full 18):

par new generation total 707840K, used 44375K [0x00000004c4e00000, 0x00000004f4e00000, 0x00000004f4e00000)

eden space 629248K, 0% used [0x00000004c4e00000, 0x00000004c4e00000, 0x00000004eb480000)

from space 78592K, 56% used [0x00000004eb480000, 0x00000004edfd5f88, 0x00000004f0140000)

to space 78592K, 0% used [0x00000004f0140000, 0x00000004f0140000, 0x00000004f4e00000)

concurrent mark-sweep generation total 12681216K, used 6634693K [0x00000004f4e00000, 0x00000007fae00000, 0x00000007fae00000)

concurrent-mark-sweep perm gen total 47232K, used 29039K [0x00000007fae00000, 0x00000007fdc20000, 0x0000000800000000)

}

Total time for which application threads were stopped: 0.2043140 seconds

Application time: 0.0001040 seconds

Total time for which application threads were stopped: 0.0000890 seconds

Application time: 4.0399400 seconds

{Heap before GC invocations=203 (full 18):

par new generation total 707840K, used 673623K [0x00000004c4e00000, 0x00000004f4e00000, 0x00000004f4e00000)

eden space 629248K, 100% used [0x00000004c4e00000, 0x00000004eb480000, 0x00000004eb480000)

from space 78592K, 56% used [0x00000004eb480000, 0x00000004edfd5f88, 0x00000004f0140000)

to space 78592K, 0% used [0x00000004f0140000, 0x00000004f0140000, 0x00000004f4e00000)

concurrent mark-sweep generation total 12681216K, used 6634693K [0x00000004f4e00000, 0x00000007fae00000, 0x00000007fae00000)

concurrent-mark-sweep perm gen total 47232K, used 29040K [0x00000007fae00000, 0x00000007fdc20000, 0x0000000800000000)

2011-04-12T18:44:23.258+0000: 12897.160: [GC 12897.160: [ParNew

Desired survivor size 40239104 bytes, new threshold 1 (max 15)

- age 1: 46278472 bytes, 46278472 total

- age 2: 23234248 bytes, 69512720 total

- age 3: 2144024 bytes, 71656744 total

- age 4: 391464 bytes, 72048208 total

: 673623K->78592K(707840K), 0.1607580 secs] 7308317K->6752580K(13389056K) icms_dc=0 , 0.1608520 secs] [Times: user=0.00 sys=0.00, real=0.16 secs]

Heap after GC invocations=204 (full 18):

par new generation total 707840K, used 78592K [0x00000004c4e00000, 0x00000004f4e00000, 0x00000004f4e00000)

eden space 629248K, 0% used [0x00000004c4e00000, 0x00000004c4e00000, 0x00000004eb480000)

from space 78592K, 100% used [0x00000004f0140000, 0x00000004f4e00000, 0x00000004f4e00000)

to space 78592K, 0% used [0x00000004eb480000, 0x00000004eb480000, 0x00000004f0140000)

concurrent mark-sweep generation total 12681216K, used 6673988K [0x00000004f4e00000, 0x00000007fae00000, 0x00000007fae00000)

concurrent-mark-sweep perm gen total 47232K, used 29040K [0x00000007fae00000, 0x00000007fdc20000, 0x0000000800000000)

}

Total time for which application threads were stopped: 75.1222720 seconds

Application time: 0.0660880 seconds

Total time for which application threads were stopped: 0.0001500 seconds

Application time: 0.0001110 seconds

Total time for which application threads were stopped: 0.0000620 seconds

Application time: 0.0000320 seconds

Total time for which application threads were stopped: 0.0000620 seconds

Application time: 0.5790490 seconds

Total time for which application threads were stopped: 0.0151370 seconds

Application time: 0.0241790 seconds

Total time for which application threads were stopped: 0.0111420 seconds

Application time: 0.1488160 seconds

Total time for which application threads were stopped: 0.0168360 seconds

Application time: 0.0237110 seconds

Total time for which application threads were stopped: 0.0008580 seconds

Application time: 0.0594260 seconds

Total time for which application threads were stopped: 0.0179450 seconds

Application time: 0.0331740 seconds

Total time for which application threads were stopped: 0.0072850 seconds

Application time: 1.2617710 seconds

{Heap before GC invocations=204 (full 18):

par new generation total 707840K, used 707840K [0x00000004c4e00000, 0x00000004f4e00000, 0x00000004f4e00000)

eden space 629248K, 100% used [0x00000004c4e00000, 0x00000004eb480000, 0x00000004eb480000)

from space 78592K, 100% used [0x00000004f0140000, 0x00000004f4e00000, 0x00000004f4e00000)

to space 78592K, 0% used [0x00000004eb480000, 0x00000004eb480000, 0x00000004f0140000)

concurrent mark-sweep generation total 12681216K, used 6673988K [0x00000004f4e00000, 0x00000007fae00000, 0x00000007fae00000)

concurrent-mark-sweep perm gen total 47232K, used 29089K [0x00000007fae00000, 0x00000007fdc20000, 0x0000000800000000)

2011-04-12T18:44:25.690+0000: 12899.592: [GC 12899.592: [ParNew

Desired survivor size 40239104 bytes, new threshold 1 (max 15)

- age 1: 42048296 bytes, 42048296 total

: 707840K->58684K(707840K), 0.1654070 secs] 7381828K->6802196K(13389056K) icms_dc=0 , 0.1655450 secs] [Times: user=0.00 sys=0.00, real=0.17 secs]

Heap after GC invocations=205 (full 18):

par new generation total 707840K, used 58684K [0x00000004c4e00000, 0x00000004f4e00000, 0x00000004f4e00000)

eden space 629248K, 0% used [0x00000004c4e00000, 0x00000004c4e00000, 0x00000004eb480000)

from space 78592K, 74% used [0x00000004eb480000, 0x00000004eedcf320, 0x00000004f0140000)

to space 78592K, 0% used [0x00000004f0140000, 0x00000004f0140000, 0x00000004f4e00000)

concurrent mark-sweep generation total 12681216K, used 6743511K [0x00000004f4e00000, 0x00000007fae00000, 0x00000007fae00000)

concurrent-mark-sweep perm gen total 47232K, used 29089K [0x00000007fae00000, 0x00000007fdc20000, 0x0000000800000000)

}

Total time for which application threads were stopped: 0.1709510 seconds

Application time: 1.0183040 seconds

Total time for which application threads were stopped: 0.0009220 seconds

Application time: 0.0209220 seconds

Total time for which application threads were stopped: 0.0009260 seconds

Application time: 0.0181760 seconds

Total time for which application threads were stopped: 0.0002780 seconds

Application time: 0.0773630 seconds

Total time for which application threads were stopped: 0.0019720 seconds

Application time: 0.0045340 seconds

Total time for which application threads were stopped: 0.0001400 seconds

Application time: 0.0245930 seconds

Total time for which application threads were stopped: 0.0004070 seconds

Application time: 0.4811530 seconds

Total time for which application threads were stopped: 0.0043100 seconds

Application time: 0.0015090 seconds

Total time for which application threads were stopped: 0.0052290 seconds

Application time: 0.0264570 seconds

Total time for which application threads were stopped: 0.0072530 seconds

Application time: 0.0135600 seconds

Total time for which application threads were stopped: 0.0121400 seconds

Application time: 0.0278510 seconds

Total time for which application threads were stopped: 0.0078060 seconds

Application time: 0.0136080 seconds

Total time for which application threads were stopped: 0.0121390 seconds

Application time: 0.0066360 seconds

Total time for which application threads were stopped: 0.0004330 seconds

Application time: 0.0107480 seconds

Total time for which application threads were stopped: 0.0001900 seconds

Application time: 0.0027230 seconds

Total time for which application threads were stopped: 0.0132610 seconds

Application time: 0.0126600 seconds

Total time for which application threads were stopped: 0.0003420 seconds

Application time: 0.5384840 seconds

{Heap before GC invocations=205 (full 18):

par new generation total 707840K, used 687932K [0x00000004c4e00000, 0x00000004f4e00000, 0x00000004f4e00000)

eden space 629248K, 100% used [0x00000004c4e00000, 0x00000004eb480000, 0x00000004eb480000)

from space 78592K, 74% used [0x00000004eb480000, 0x00000004eedcf320, 0x00000004f0140000)

to space 78592K, 0% used [0x00000004f0140000, 0x00000004f0140000, 0x00000004f4e00000)

concurrent mark-sweep generation total 12681216K, used 6743511K [0x00000004f4e00000, 0x00000007fae00000, 0x00000007fae00000)

concurrent-mark-sweep perm gen total 47232K, used 29092K [0x00000007fae00000, 0x00000007fdc20000, 0x0000000800000000)

2011-04-12T18:44:28.223+0000: 12902.125: [GC 12902.125: [ParNew

Desired survivor size 40239104 bytes, new threshold 15 (max 15)

- age 1: 5906520 bytes, 5906520 total

: 687932K->45478K(707840K), 0.2139570 secs] 7431444K->6860368K(13389056K) icms_dc=0 , 0.2142010 secs] [Times: user=0.00 sys=0.00, real=0.21 secs]

Heap after GC invocations=206 (full 18):

par new generation total 707840K, used 45478K [0x00000004c4e00000, 0x00000004f4e00000, 0x00000004f4e00000)

eden space 629248K, 0% used [0x00000004c4e00000, 0x00000004c4e00000, 0x00000004eb480000)

from space 78592K, 57% used [0x00000004f0140000, 0x00000004f2da9b30, 0x00000004f4e00000)

to space 78592K, 0% used [0x00000004eb480000, 0x00000004eb480000, 0x00000004f0140000)

concurrent mark-sweep generation total 12681216K, used 6814889K [0x00000004f4e00000, 0x00000007fae00000, 0x00000007fae00000)

concurrent-mark-sweep perm gen total 47232K, used 29092K [0x00000007fae00000, 0x00000007fdc20000, 0x0000000800000000)

}

更新

我将应用程序切换到多核计算机上,以减轻CMS收集带来的痛苦,现在,在稳定状态下,我看不到任何暂停.但是,在更新搜索索引的过程中,大量大型内存结构会快速生成,并且应用程序会再次遭受长时间的STW暂停.我不确定如何避免这种情况,因为这些对象可能应该驻留在终身代中,我增加了幸存者空间的大小(-XX：SurvivorRatio = 8),但仍然观察到很长时间的停顿.参见下面的GC日志：

{Heap before GC invocations=103 (full 48):

par new generation total 921600K, used 912322K [0x000000050ce00000, 0x000000054b600000, 0x000000054b600000)

eden space 819200K, 99% used [0x000000050ce00000, 0x000000053e776380, 0x000000053ee00000)

from space 102400K, 97% used [0x000000053ee00000, 0x0000000544f7a630, 0x0000000545200000)

to space 102400K, 0% used [0x0000000545200000, 0x0000000545200000, 0x000000054b600000)

concurrent mark-sweep generation total 11264000K, used 6486203K [0x000000054b600000, 0x00000007fae00000, 0x00000007fae00000)

concurrent-mark-sweep perm gen total 48516K, used 29211K [0x00000007fae00000, 0x00000007

fdd61000, 0x0000000800000000)

2011-04-14T15:15:25.322+0000: 2358.684: [GC 2358.684: [ParNew

Desired survivor size 52428800 bytes, new threshold 1 (max 15)- age 1: 102164088 bytes, 102164088 total

: 912322K->99941K(921600K), 30.0146400 secs] 7398525K->6818473K(12185600K), 30.0147850 se

cs] [Times: user=0.00 sys=0.00, real=30.02 secs]

Heap after GC invocations=104 (full 48): par new generation total 921600K, used 99941K [0x000000050ce00000, 0x000000054b600000,

0x000000054b600000)

eden space 819200K, 0% used [0x000000050ce00000, 0x000000050ce00000, 0x000000053ee00000)

from space 102400K, 97% used [0x0000000545200000, 0x000000054b399710, 0x000000054b6000

00)

to space 102400K, 0% used [0x000000053ee00000, 0x000000053ee00000, 0x00000005452000

00) concurrent mark-sweep generation total 11264000K, used 6718531K [0x000000054b600000, 0x0

0000007fae00000, 0x00000007fae00000) concurrent-mark-sweep perm gen total 48516K, used 29211K [0x00000007fae00000, 0x00000007

fdd61000, 0x0000000800000000)}

Total time for which application threads were stopped: 30.0152850 seconds

Application time: 0.9450500 seconds