FULL GC有可能导致JVM暂停1分钟以上吗?

jjshanwei 2012-03-07
Xmx128m 的fullgc 要一分钟? 应改不是gc本身的问题
moonese 2012-03-08
jjshanwei 写道
Xmx128m 的fullgc 要一分钟? 应改不是gc本身的问题


不知道是不是这台机器太老,内存太小,上面跑的程序太多的缘故。

建议加上打印gc日志的参数 -verbose:gc -XX:+PrintGCDetails -Xloggc:timer_gc.log,分析gc的日志,就知道是不是 GC 导致的问题了。

或是用 jconsole / jvisualvm 监控下程序的 heap 使用情况。

怀疑是程序里面有死锁或是代码写的不好,有性能问题,这个也可以通过工具查出的。
qianhd 2012-08-21
RednaxelaFX 写道
GC暂停超过1分钟的情况不是没有,但以-Xmx128m的配置来看这个很诡异。
请问能使用 -XX:+PrintSafepointStatistics 来看看VM暂停的统计信息么?
一共是这几个参数:

  product(bool, PrintSafepointStatistics, false,                            \
          "print statistics about safepoint synchronization")               \
                                                                            \
  product(intx, PrintSafepointStatisticsCount, 300,                         \
          "total number of safepoint statistics collected "                 \
          "before printing them out")                                       \
                                                                            \
  product(intx, PrintSafepointStatisticsTimeout,  -1,                       \
          "print safepoint statistics only when safepoint takes"            \
          " more than PrintSafepointSatisticsTimeout in millis")            \




有没有资料详细讲一下这个参数? 
噩梦的问题又来了~
RednaxelaFX 2012-08-21
例如这帖:http://mail.openjdk.java.net/pipermail/hotspot-gc-dev/2011-August/002968.html ?
你可以搜一下OpenJDK的hotspot-gc-dev和hotspot-gc-use这两个邮件列表的过往内容。这个参数不是“标准参数”所以也没啥公开文档描述它的意义的。
qianhd 2012-08-21
RednaxelaFX 写道
例如这帖:http://mail.openjdk.java.net/pipermail/hotspot-gc-dev/2011-August/002968.html ?
你可以搜一下OpenJDK的hotspot-gc-dev和hotspot-gc-use这两个邮件列表的过往内容。这个参数不是“标准参数”所以也没啥公开文档描述它的意义的。



Orz
你真是24小时在线~

如果我设置个 MaxGCPauseMillis这个参数
有意义吗?
RednaxelaFX 2012-08-21
qianhd 写道

如果我设置个 MaxGCPauseMillis这个参数
有意义吗?

不是完全没意义不过这参数我印象中只有在ParallelScavenge和G1中的作用才比较明显,CMS虽然也有用这个参数但我印象中它没啥用。你最好到hotspot-gc-use那边问问,靠谱些。
qianhd 2012-08-23
我加了3个参数
-XX:+PrintGCApplicationStoppedTime -XX:+PrintGCDateStamps -Xloggc:gclog.log

今天早上一看, 果然断了, 晚上8点17的样子
common GC竟然花了41秒 诧异~

另外,不是full GC才会stop all threads吗?

再另外,我设定过最大和最小内存 -Xms64m -Xmx256m
但是实际上最大时内存占用达到了400多m
这是为啥?

再再另外,有没有办法记录当时的JVM的一些状态信息?

求解惑

引用

2012-08-22T20:17:27.921+0800: 16489.272: [GC 191334K->84242K(299840K), 41.4177511 secs]
Total time for which application threads were stopped: 41.4731411 seconds
Total time for which application threads were stopped: 0.0489481 seconds
Total time for which application threads were stopped: 0.1110761 seconds
Total time for which application threads were stopped: 0.0007286 seconds
Total time for which application threads were stopped: 0.0001268 seconds
Total time for which application threads were stopped: 2.8581772 seconds
Total time for which application threads were stopped: 0.0112389 seconds
Total time for which application threads were stopped: 0.0001335 seconds
Total time for which application threads were stopped: 0.0003246 seconds
Total time for which application threads were stopped: 0.0003774 seconds
Total time for which application threads were stopped: 0.0001439 seconds
Total time for which application threads were stopped: 0.0000897 seconds
Total time for which application threads were stopped: 0.0001408 seconds
Total time for which application threads were stopped: 0.0001687 seconds
Total time for which application threads were stopped: 0.0001380 seconds
Total time for which application threads were stopped: 0.0001374 seconds
Total time for which application threads were stopped: 0.0002028 seconds
Total time for which application threads were stopped: 0.0001171 seconds
Total time for which application threads were stopped: 0.0001277 seconds
Total time for which application threads were stopped: 0.0002257 seconds
Total time for which application threads were stopped: 0.0353492 seconds
Total time for which application threads were stopped: 0.0004783 seconds
Total time for which application threads were stopped: 0.0001612 seconds
Total time for which application threads were stopped: 0.0075786 seconds
Total time for which application threads were stopped: 0.0001754 seconds
Total time for which application threads were stopped: 0.0002405 seconds
Total time for which application threads were stopped: 0.0005079 seconds
Total time for which application threads were stopped: 0.0001257 seconds
Total time for which application threads were stopped: 0.0004294 seconds
Total time for which application threads were stopped: 0.0001970 seconds
Total time for which application threads were stopped: 0.0001310 seconds
Total time for which application threads were stopped: 0.0001763 seconds
Total time for which application threads were stopped: 0.0001685 seconds
Total time for which application threads were stopped: 0.0004185 seconds
Total time for which application threads were stopped: 0.0001067 seconds
Total time for which application threads were stopped: 0.0005286 seconds
Total time for which application threads were stopped: 0.0001140 seconds
Total time for which application threads were stopped: 0.0002386 seconds
Total time for which application threads were stopped: 0.0003646 seconds
Total time for which application threads were stopped: 0.0001048 seconds
Total time for which application threads were stopped: 0.0003132 seconds
Total time for which application threads were stopped: 0.0001953 seconds
Total time for which application threads were stopped: 0.0003942 seconds
Total time for which application threads were stopped: 0.0004210 seconds
Total time for which application threads were stopped: 0.0001009 seconds
Total time for which application threads were stopped: 0.0001430 seconds
Total time for which application threads were stopped: 0.0000816 seconds
Total time for which application threads were stopped: 0.0297057 seconds
Total time for which application threads were stopped: 0.0462548 seconds
Total time for which application threads were stopped: 0.0003872 seconds
Total time for which application threads were stopped: 0.0004657 seconds
Total time for which application threads were stopped: 0.0004777 seconds
Total time for which application threads were stopped: 0.0004568 seconds
Total time for which application threads were stopped: 0.0003623 seconds
Total time for which application threads were stopped: 0.0004906 seconds
Total time for which application threads were stopped: 0.0003693 seconds
Total time for which application threads were stopped: 0.0004129 seconds
Total time for which application threads were stopped: 0.0003953 seconds
Total time for which application threads were stopped: 0.0052699 seconds
Total time for which application threads were stopped: 0.0002953 seconds
Total time for which application threads were stopped: 0.0000514 seconds
Total time for which application threads were stopped: 0.0000310 seconds
Total time for which application threads were stopped: 0.0000603 seconds
Total time for which application threads were stopped: 0.0000293 seconds
Total time for which application threads were stopped: 0.0000777 seconds
Total time for which application threads were stopped: 0.0001048 seconds
Total time for which application threads were stopped: 0.0003676 seconds
Total time for which application threads were stopped: 0.0003964 seconds
Total time for which application threads were stopped: 0.0001201 seconds
Total time for which application threads were stopped: 0.0003676 seconds
Total time for which application threads were stopped: 0.0003995 seconds
Total time for which application threads were stopped: 0.0004118 seconds
Total time for which application threads were stopped: 0.0004026 seconds
Total time for which application threads were stopped: 0.0003911 seconds
Total time for which application threads were stopped: 0.0367284 seconds
Total time for which application threads were stopped: 0.0003959 seconds
Total time for which application threads were stopped: 0.0004009 seconds
Total time for which application threads were stopped: 0.0003964 seconds
Total time for which application threads were stopped: 0.0003727 seconds
Total time for which application threads were stopped: 0.0002084 seconds
Total time for which application threads were stopped: 0.0003738 seconds
Total time for which application threads were stopped: 0.0003671 seconds
Total time for which application threads were stopped: 0.0004165 seconds
Total time for which application threads were stopped: 0.0004026 seconds
Total time for which application threads were stopped: 0.0003674 seconds
Total time for which application threads were stopped: 0.0003964 seconds
Total time for which application threads were stopped: 0.0004165 seconds
Total time for which application threads were stopped: 0.0003908 seconds
Total time for which application threads were stopped: 0.0004109 seconds
Total time for which application threads were stopped: 0.0004540 seconds
Total time for which application threads were stopped: 0.0003730 seconds
Total time for which application threads were stopped: 0.0003889 seconds
Total time for which application threads were stopped: 0.0003495 seconds
Total time for which application threads were stopped: 0.0003665 seconds
Total time for which application threads were stopped: 0.0003805 seconds
Total time for which application threads were stopped: 0.0004277 seconds
Total time for which application threads were stopped: 0.0003864 seconds
Total time for which application threads were stopped: 0.0003939 seconds
Total time for which application threads were stopped: 0.0002249 seconds
Total time for which application threads were stopped: 0.0003922 seconds
Total time for which application threads were stopped: 0.0006319 seconds
Total time for which application threads were stopped: 0.0003757 seconds
Total time for which application threads were stopped: 0.0004816 seconds
Total time for which application threads were stopped: 0.0004068 seconds
Total time for which application threads were stopped: 0.0003878 seconds
Total time for which application threads were stopped: 0.0004177 seconds
Total time for which application threads were stopped: 0.0003771 seconds
Total time for which application threads were stopped: 0.0003903 seconds
Total time for which application threads were stopped: 0.0003964 seconds
Total time for which application threads were stopped: 0.0004051 seconds
Total time for which application threads were stopped: 0.0003984 seconds
Total time for which application threads were stopped: 0.0003757 seconds
Total time for which application threads were stopped: 0.0004886 seconds
Total time for which application threads were stopped: 0.0004056 seconds
Total time for which application threads were stopped: 0.0003822 seconds
Total time for which application threads were stopped: 0.0003660 seconds
Total time for which application threads were stopped: 0.0004520 seconds
Total time for which application threads were stopped: 0.0003788 seconds
Total time for which application threads were stopped: 0.0003671 seconds
Total time for which application threads were stopped: 0.0003752 seconds
Total time for which application threads were stopped: 0.0003964 seconds
Total time for which application threads were stopped: 0.0002159 seconds
Total time for which application threads were stopped: 0.0005065 seconds
Total time for which application threads were stopped: 0.0003685 seconds
Total time for which application threads were stopped: 0.0004872 seconds
Total time for which application threads were stopped: 0.0006339 seconds
Total time for which application threads were stopped: 0.0003903 seconds
Total time for which application threads were stopped: 0.0004392 seconds
qianhd 2012-08-24
引用

2012-08-24T10:47:26.359+0800: 62319.697: [Full GC62334.410: [SoftReference, 1591 refs, 0.0004489 secs]62334.411: [WeakReference, 7980 refs, 0.0011812 secs]62334.412: [FinalReference, 1683 refs, 0.0012770 secs]62334.413: [PhantomReference, 125 refs, 0.0000475 secs]62334.413: [JNI Weak Reference, 0.0003093 secs] [PSYoungGen: 7912K->0K(183360K)] [PSOldGen: 146039K->70830K(145024K)] 153952K->70830K(328384K) [PSPermGen: 42129K->42129K(65536K)], 17.9215166 secs] [Times: user=0.75 sys=0.25, real=17.92 secs]



引用

2012-08-24T14:21:54.218+0800: 75187.848: [GC75197.407: [SoftReference, 0 refs, 0.0000056 secs]75197.407: [WeakReference, 102 refs, 0.0000212 secs]75197.407: [FinalReference, 1318 refs, 0.6698083 secs]75198.077: [PhantomReference, 1549 refs, 0.0088953 secs]75198.086: [JNI Weak Reference, 0.0315859 secs] [PSYoungGen: 170048K->1232K(171328K)] 240878K->72062K(316352K), 10.2911859 secs] [Times: user=2.01 sys=0.01, real=10.30 secs]



从这个GC日志 能看出来17秒和10秒时间分别花在什么地方了吗
qianhd 2012-08-24
我发现一个现象, 长时间的GC的前面一般3,4个小时都没有发生过GC, 因为是个GUI程序,我都最下化, 这样内存占用会减少很多, 但是虚拟内存占用还是原来那么多.
会不会在GC的时候,需要重新把虚拟内存的数据读回到内存, 这样就触发 先腾出内存,(某些进程的内容先暂存虚拟内存),然后把虚拟内存的数据读进来.

会不会是这种原因导致的??
qianhd 2012-08-30
引用

2012-08-29T19:14:30.968+0800: 10069.800: [GC10099.225: [SoftReference, 0 refs, 0.0000109 secs]10099.226: [WeakReference, 4072 refs, 0.0012099 secs]10099.227: [FinalReference, 984 refs, 1.5822450 secs]10100.809: [PhantomReference, 251 refs, 0.0001394 secs]10100.809: [JNI Weak Reference, 0.0994015 secs] [PSYoungGen: 175672K->8528K(167360K)] 251523K->100182K(353152K), 31.1580402 secs] [Times: user=0.61 sys=0.52, real=31.16 secs]



其实GC执行, 并没有花很多时间, 从上面这段信息看, 开始准备GC在10069.800, 真正GC开始在10099.225, 中间花费了约30秒, 貌似时间大部分是花费在GC的准备上.
这需要看看openJDK里面,执行GC前哪些操作比较耗时,
我前面的猜测是可能和windows内存和虚拟内存有关, 这东西越来越底层了, 有点力不从心
Global site tag (gtag.js) - Google Analytics