0
在問題All thread are blocked,like STW,and no responding之後，我添加了一些JAVA_OPTS。GC日誌讓我感到困惑
這是我的新選擇。
-server -Xms32g -Xmx32g \ -XX:NewSize=10g -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:CMSInitiatingOccupancyFraction=75 -XX:+UseCMSInitiatingOccupancyOnly \ -XX:+CMSParallelRemarkEnabled -XX:+PrintSafepointStatistics -XX:PrintSafepointStatisticsCount=1 \ -XX:+PrintGCDateStamps -verbose:gc -XX:+PrintGCDetails -XX:+PrintGCApplicationStoppedTime -XX:+PrintGCApplicationConcurrentTime \ -XX:+PrintGCCause -Xloggc:/var/log/flume-ng/gc.log -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=10 -XX:GCLogFileSize=10M
剛剛應用程序停止工作。
這裏是最後一行gc log（gc log的最後一個字是stopped:）。
2016-01-09T18:37:14.193+0800: 18879.031: Application time: 0.0071232 seconds 2016-01-09T18:37:14.193+0800: 18879.032: Total time for which application threads were stopped: 0.0003769 seconds, Stopping threads took: 0.0000800 seconds 2016-01-09T18:37:21.704+0800: 18886.542: Application time: 7.5105681 seconds 2016-01-09T18:37:21.705+0800: 18886.543: [GC (Allocation Failure) 2016-01-09T18:37:21.705+0800: 18886.543: [ParNew: 8412583K->36040K(9437184K), 0.0159936 secs] 21350038K->12973495K(32505856K), 0.0162151 secs] [Times: user=0.34 sys=0.00, real=0.02 secs] 2016-01-09T18:37:21.721+0800: 18886.559: Total time for which application threads were stopped: 0.0172971 seconds, Stopping threads took: 0.0001286 seconds 2016-01-09T18:37:37.830+0800: 18902.668: Application time: 16.1087180 seconds 2016-01-09T18:42:43.301+0800: 19208.140: Total time for which application threads were stopped:
然後，我使用jstack -m命令。然後，應用程序恢復正常。
這是下一個gc日誌（第一行的305.4698351 second是我執行jstack command的時間減去應用程序停止工作的時間）。
2016-01-09T18:42:43.301+0800: 19208.140: Total time for which application threads were stopped: 305.4715152 seconds, Stopping threads took: 305.4698351 seconds skip some Application time log 2016-01-09T18:42:44.340+0800: 19209.179: [GC (Allocation Failure) 2016-01-09T18:42:44.340+0800: 19209.179: [ParNew: 8424650K->127192K(9437184K), 0.0331325 secs] 21362105K->13064648K(32505856K), 0.0333109 secs] [Times: user=0.72 sys=0.00, real=0.03 secs] 2016-01-09T18:42:44.374+0800: 19209.212: Total time for which application threads were stopped: 0.0338915 seconds, Stopping threads took: 0.0000998 seconds 2016-01-09T18:42:44.374+0800: 19209.212: Application time: 0.0001254 seconds 2016-01-09T18:42:44.375+0800: 19209.213: [GC (GCLocker Initiated GC) 2016-01-09T18:42:44.375+0800: 19209.213: [ParNew: 133268K->152503K(9437184K), 0.0335528 secs] 13070724K->13089959K(32505856K), 0.0336755 secs] [Times: user=0.69 sys=0.00, real=0.04 secs] 2016-01-09T18:42:44.408+0800: 19209.247: Total time for which application threads were stopped: 0.0345724 seconds, Stopping threads took: 0.0001147 seconds 2016-01-09T18:42:46.920+0800: 19211.759: Application time: 0.8197406 seconds 2016-01-09T18:42:46.921+0800: 19211.760: [GC (Allocation Failure) 2016-01-09T18:42:46.921+0800: 19211.760: [ParNew: 8541111K->441557K(9437184K), 0.0993869 secs] 21478567K->13379018K(32505856K), 0.0995702 secs] [Times: user=2.25 sys=0.00, real=0.10 secs] 2016-01-09T18:42:49.571+0800: 19214.409: Application time: 0.6178457 seconds 2016-01-09T18:42:49.572+0800: 19214.410: [GC (Allocation Failure) 2016-01-09T18:42:49.572+0800: 19214.410: [ParNew: 8830165K->812963K(9437184K), 0.1568946 secs] 21767626K->13750433K(32505856K), 0.1571136 secs] [Times: user=3.58 sys=0.00, real=0.16 secs] 2016-01-09T18:42:49.729+0800: 19214.568: Total time for which application threads were stopped: 0.1581075 seconds, Stopping threads took: 0.00seconds 2016-01-09T18:42:52.286+0800: 19217.125: [GC (GCLocker Initiated GC) 2016-01-09T18:42:52.286+0800: 19217.125: [ParNew: 9201571K->973385K(9437184K), 0.3264006 secs] 22139041K->14095607K(32505856K), 0.3265784 secs] [Times: user=4.46 sys=0.00, real=0.33 secs] 2016-01-09T18:42:55.279+0800: 19220.117: [GC (Allocation Failure) 2016-01-09T18:42:55.279+0800: 19220.117: [ParNew: 9361993K->1048576K(9437184K), 0.3140569 secs] 22484215K->14506810K(32505856K), 0.3142791 secs] [Times: user=5.36 sys=0.00, real=0.31 secs] 2016-01-09T18:42:58.222+0800: 19223.061: Application time: 0.0000301 seconds 2016-01-09T18:42:58.223+0800: 19223.061: [GC (GCLocker Initiated GC) 2016-01-09T18:42:58.223+0800: 19223.061: [ParNew: 9437184K->1048576K(9437184K), 0.3384320 secs] 22895418K->14892045K(32505856K), 0.3386214 secs] [Times: user=5.71 sys=0.00, real=0.34 secs] 2016-01-09T18:43:01.166+0800: 19226.005: [GC (GCLocker Initiated GC) 2016-01-09T18:43:01.166+0800: 19226.005: [ParNew: 9437184K->1048576K(9437184K), 0.3425942 secs] 23280717K->15266436K(32505856K), 0.3427797 secs] [Times: user=5.89 sys=0.00, real=0.35 secs] 2016-01-09T18:43:04.112+0800: 19228.950: Application time: 0.6938848 seconds
當時2016-01-09 18:43該應用程序再次停止工作。
然後我再次使用jstack -m命令，應用程序又回來了。
這是gc日誌。
2016-01-09T18:46:18.871+0800: 19423.709: [GC (Allocation Failure) 2016-01-09T18:46:18.871+0800: 19423.710: [ParNew: 9437184K->1048576K(9437184K), 0.3188298 secs] 23655044K->15632857K(32505856K), 0.3191140 secs] [Times: user=5.55 sys=0.00, real=0.32 secs] 2016-01-09T18:46:19.190+0800: 19424.029: Total time for which application threads were stopped: 195.0782503 seconds, Stopping threads took: 194.7573545 seconds 2016-01-09T18:46:22.197+0800: 19427.035: [GC (Allocation Failure) 2016-01-09T18:46:22.197+0800: 19427.036: [ParNew: 9437184K->1048576K(9437184K), 0.3175688 secs] 24021465K->16017865K(32505856K), 0.3177865 secs] [Times: user=5.85 sys=0.00, real=0.32 secs] 2016-01-09T18:46:25.111+0800: 19429.950: [GC (Allocation Failure) 2016-01-09T18:46:25.112+0800: 19429.950: [ParNew: 9437184K->1048576K(9437184K), 0.2808750 secs] 24406473K->16384589K(32505856K), 0.2810767 secs] [Times: user=5.04 sys=0.00, real=0.28 secs] 2016-01-09T18:46:27.974+0800: 19432.813: [GC (Allocation Failure) 2016-01-09T18:46:27.975+0800: 19432.813: [ParNew: 9437184K->1048576K(9437184K), 0.32secs] 24773197K->16833663K(32505856K), 0.3203207 secs] [Times: user=5.53 sys=0.00, real=0.32 secs] ......... 2016-01-09T18:55:25.249+0800: 19970.088: [GC (Allocation Failure) 2016-01-09T18:55:25.249+0800: 19970.088: [ParNew: 8419546K->31852K(9437184K), 0.0155374 secs] 13769434K->5382550K(32505856K), 0.0157411 secs] [Times: user=0.33 sys=0.00, real=0.02 secs]
我發現，i之後執行jstack -m命令時，GC log ParNew: from size->to size(9437184K)是異常時，成爲to size越來越大像一些內存不能released.But我執行jstack -m所述第二時間，所述尺寸之後變小一段的時間。
當系統不正常時，jstack命令必須添加選項-F和jmap需要執行幾個小時。
這是jstack -F結果文件中的一個特殊線程。除in_vm外，所有線程的狀態都被阻止。
Attaching to process ID 23694, please wait... Debugger attached successfully. Server compiler detected. JVM version is 25.66-b17 Deadlock Detection: No deadlocks found. Thread 143283: (state = IN_VM) - sun.misc.Unsafe.freeMemory(long) @bci=0 (Compiled frame; information may be imprecise) - java.nio.DirectByteBuffer$Deallocator.run() @bci=17, line=94 (Compiled frame) - sun.misc.Cleaner.clean() @bci=12, line=143 (Compiled frame) - io.netty.util.internal.Cleaner0.freeDirectBuffer(java.nio.ByteBuffer) @bci=34, line=66 (Compiled frame) - io.netty.util.internal.PlatformDependent0.freeDirectBuffer(java.nio.ByteBuffer) @bci=1, line=147 (Compiled frame) - io.netty.util.internal.PlatformDependent.freeDirectBuffer(java.nio.ByteBuffer) @bci=13, line=281 (Compiled frame) - io.netty.buffer.UnpooledUnsafeDirectByteBuf.freeDirect(java.nio.ByteBuffer) @bci=1, line=115 (Compiled frame) - io.netty.buffer.UnpooledUnsafeDirectByteBuf.deallocate() @bci=24, line=508 (Compiled frame) - io.netty.buffer.AbstractReferenceCountedByteBuf.release() @bci=39, line=106 (Compiled frame) - io.netty.util.ReferenceCountUtil.release(java.lang.Object) @bci=11, line=59 (Compiled frame) - io.netty.util.ReferenceCountUtil.safeRelease(java.lang.Object) @bci=1, line=84 (Compiled frame) - io.netty.channel.ChannelOutboundBuffer.remove() @bci=40, line=258 (Compiled frame) - io.netty.channel.ChannelOutboundBuffer.removeBytes(long) @bci=83, line=334 (Compiled frame) - io.netty.channel.socket.nio.NioSocketChannel.doWrite(io.netty.channel.ChannelOutboundBuffer) @bci=238, line=317 (Compiled frame) - io.netty.channel.AbstractChannel$AbstractUnsafe.flush0() @bci=89, line=750 (Compiled frame) - io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.flush0() @bci=9, line=303 (Compiled frame) - io.netty.channel.AbstractChannel$AbstractUnsafe.flush() @bci=15, line=719 (Compiled frame) - io.netty.channel.DefaultChannelPipeline$HeadContext.flush(io.netty.channel.ChannelHandlerContext) @bci=4, line=1119 (Compiled frame) - io.netty.channel.AbstractChannelHandlerContext.invokeFlush() @bci=8, line=735 (Compiled frame) - io.netty.channel.AbstractChannelHandlerContext.access$1500(io.netty.channel.AbstractChannelHandlerContext) @bci=1, line=32 (Compiled frame) - io.netty.channel.AbstractChannelHandlerContext$16.run() @bci=4, line=723 (Compiled frame) - io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(long) @bci=26, line=357 (Compiled frame) - io.netty.channel.nio.NioEventLoop.run() @bci=106, line=357 (Compiled frame) - io.netty.util.concurrent.SingleThreadEventExecutor$2.run() @bci=13, line=111 (Interpreted frame) - java.lang.Thread.run() @bci=11, line=745 (Interpreted frame)
這是我的環境。
java version "1.8.0_66" Linux version 2.6.32-504.el6.x86_64
爲什麼ParNew日誌異常。 – famoss