logo标签列表

我的应用程序一直在进行Full GC！

javajbossgarbage-collection
9

我在性能调优应用程序和了解GC的工作方面是新手，所以可能会问同样的问题一百万次！

问题是，大约2-3周前，我的Web应用程序不知何故开始时不时地崩溃。查看日志，得出结论是由于OOM错误导致崩溃：

Caused by: java.sql.SQLException: java.lang.OutOfMemoryError: Java heap space
    at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1055)
    at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:956)
    at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:926)
    at com.mysql.jdbc.Util.handleNewInstance(Util.java:430)
    ...

并且

14:29:58,469 ERROR [[dispatcher]] Servlet.service() for servlet dispatcher threw exception
java.lang.OutOfMemoryError: GC overhead limit exceeded
    at org.hibernate.event.def.AbstractFlushingEventListener.flushEntities(AbstractFlushingEventListener.java:193)
    at org.hibernate.event.def.AbstractFlushingEventListener.flushEverythingToExecutions(AbstractFlushingEventListener.java:76)
    at org.hibernate.event.def.DefaultAutoFlushEventListener.onAutoFlush(DefaultAutoFlushEventListener.java:35)
    at org.hibernate.impl.SessionImpl.autoFlushIfRequired(SessionImpl.java:969)
    at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1114)
    at org.hibernate.impl.QueryImpl.list(QueryImpl.java:79)
    at com.tennisearth.dao.hibernate.HibernateCommentaryDao.getCommentary(HibernateCommentaryDao.java:52)
    at com.tennisearth.service.impl.CommentaryServiceImpl.getCommentary(CommentaryServiceImpl.java:454)
    at com.tennisearth.service.impl.CommentaryServiceImpl.getCommentaryMap(CommentaryServiceImpl.java:165)
    at com.tennisearth.web.controllers.WidgetsController.commentaryList(WidgetsController.java:704)
    at com.tennisearth.web.controllers.WidgetsController.widgets(WidgetsController.java:290)
    at sun.reflect.GeneratedMethodAccessor259.invoke(Unknown Source)
            ...

随后，我开始记录GC日志，并发现当服务器启动时，GC运行正常：

3.808: [GC 56505K->5808K(251264K), 0.0120840 secs]
3.820: [Full GC 5808K->5614K(251264K), 0.0540460 secs]
7.169: [GC 71214K->9589K(251264K), 0.0068780 secs]
8.173: [GC 75189K->13543K(251264K), 0.0174120 secs]
8.624: [GC 79143K->13693K(251264K), 0.0088080 secs]
9.907: [GC 79293K->16013K(251264K), 0.0132330 secs]
11.832: [GC 81613K->22100K(311360K), 0.0227030 secs]
13.338: [GC 136508K->38851K(316864K), 0.0346600 secs]
13.373: [Full GC 38851K->38559K(316864K), 0.2093700 secs]
15.113: [GC 164255K->45826K(331520K), 0.0151220 secs]
18.946: [GC 177794K->58815K(322688K), 0.0254140 secs]
22.699: [GC 186431K->70079K(322880K), 0.0500300 secs]
40.246: [GC 191871K->78818K(311296K), 0.0429900 secs]
41.280: [GC 196706K->81375K(324608K), 0.0340230 secs]
42.798: [GC 199135K->82432K(324736K), 0.0074390 secs]
43.487: [GC 200192K->85729K(394112K), 0.0098220 secs]
45.564: [GC 274145K->97421K(394688K), 0.0212620 secs]
46.829: [GC 285837K->100769K(491968K), 0.0287150 secs]
48.011: [GC 388705K->106326K(491648K), 0.0275700 secs]
51.035: [GC 394262K->114643K(493376K), 0.0199210 secs]
58.073: [GC 407187K->118997K(493760K), 0.0190090 secs]
61.094: [GC 411541K->122449K(496320K), 0.0181850 secs]
83.288: [GC 419985K->128776K(467968K), 0.0206970 secs]
91.216: [GC 414152K->136966K(459136K), 0.0237830 secs]
108.336: [GC 410758K->137782K(445632K), 0.0158180 secs]
116.492: [GC 400566K->139454K(434304K), 0.0126040 secs]
139.645: [GC 391742K->140705K(420608K), 0.0113540 secs]
150.825: [GC 383009K->158942K(428096K), 0.0375920 secs]
151.909: [GC 391774K->178964K(437824K), 0.0677160 secs]
153.518: [GC 417702K->280503K(496000K), 0.1514220 secs]
153.669: [Full GC 280503K->274184K(618880K), 0.7686300 secs]
155.431: [GC 468706K->366398K(658880K), 0.1449730 secs]
155.579: [GC 366772K->364514K(603072K), 0.0524370 secs]
155.631: [Full GC 364514K->348726K(753728K), 0.9406650 secs]
157.072: [GC 508278K->395401K(733376K), 0.0369850 secs]
157.839: [GC 554533K->473779K(762816K), 0.1072000 secs]
159.105: [GC 614259K->509767K(771840K), 0.0883110 secs]
163.696: [GC 650247K->516783K(748416K), 0.0878210 secs]
163.784: [Full GC 516783K->512313K(920384K), 0.6153950 secs]

但是在第二天检查日志时，GC日志一直显示全量GC。
65515.860: [Full GC 815615K->763589K(932096K), 1.3774000 secs]
65517.398: [Full GC 815615K->761150K(932096K), 1.3959730 secs]
65518.920: [Full GC 815615K->770183K(932096K), 1.3627860 secs]
65520.388: [Full GC 815615K->772928K(932096K), 1.3690040 secs]
65521.849: [Full GC 815615K->777388K(932096K), 1.3932870 secs]
65523.321: [Full GC 815615K->773739K(932096K), 1.6262920 secs]
65525.032: [Full GC 815615K->782518K(932096K), 1.3857020 secs]
65526.493: [Full GC 815615K->784568K(932096K), 1.3901050 secs]
65528.031: [Full GC 815615K->743695K(932096K), 1.2809140 secs]
65530.065: [Full GC 815615K->721823K(932096K), 1.3245560 secs]
65538.982: [Full GC 815615K->729961K(932096K), 1.2241330 secs]
65540.508: [Full GC 815615K->729519K(932096K), 1.2257770 secs]
65542.135: [Full GC 815615K->731559K(932096K), 1.2206840 secs]
65547.769: [Full GC 815615K->722653K(932096K), 1.5854120 secs]
65558.803: [Full GC 815616K->727582K(932096K), 1.2067870 secs]
65566.769: [Full GC 815615K->728443K(932096K), 1.2114200 secs]
65570.652: [Full GC 815616K->730066K(932096K), 1.2135840 secs]
65572.352: [Full GC 815616K->723875K(932096K), 1.4702710 secs]
65577.304: [Full GC 815615K->727897K(932096K), 1.2087790 secs]
65583.316: [Full GC 815615K->727540K(932096K), 1.2091610 secs]
65590.292: [Full GC 815615K->728114K(932096K), 1.2074670 secs]
65599.993: [Full GC 815615K->722369K(932096K), 1.2465300 secs]
65616.109: [Full GC 815615K->728427K(932096K), 1.2092820 secs]
65620.070: [Full GC 815615K->728823K(932096K), 1.2068140 secs]
65626.774: [Full GC 815615K->728454K(932096K), 1.2046050 secs]
65637.302: [Full GC 815615K->722224K(932096K), 1.4699560 secs]
65639.319: [Full GC 815615K->728140K(932096K), 1.2258630 secs]
65656.674: [Full GC 815615K->726831K(932096K), 1.2203520 secs]
65667.239: [Full GC 815615K->727786K(932096K), 1.2212360 secs]
65678.905: [Full GC 815615K->721629K(932096K), 1.4281870 secs]
65686.655: [Full GC 815615K->728126K(932096K), 1.2147860 secs]
65689.521: [Full GC 815615K->723848K(932096K), 1.2070410 secs]
65697.409: [Full GC 815615K->727932K(932096K), 1.2111580 secs]
65712.853: [Full GC 815615K->721999K(932096K), 1.4991350 secs]
65719.399: [Full GC 815615K->727715K(932096K), 1.2149930 secs]
65727.209: [Full GC 815615K->727355K(932096K), 1.2048690 secs]
65728.726: [Full GC 815615K->730012K(932096K), 1.2185660 secs]
65730.225: [Full GC 815615K->725299K(932096K), 1.4965130 secs]
65732.111: [Full GC 815615K->728544K(932096K), 1.2107770 secs]
65738.952: [Full GC 815615K->726932K(932096K), 1.2066580 secs]

我的应用程序是否存在内存泄漏问题，还是需要调整配置？我正在使用以下设置：

CentOS release 5.2 (Final) x86_64  
Java JDK 1.6.06 64-bit  
JBoss 4.2.2.GA
RAM: 4GB
Swap Space: 2GB
Processor: Intel(R) Xeon(R) CPU X3323 @ 2.50GHz

以下命令用于运行jboss：
java -Dprogram.name=run.sh -server -Xms256m -Xmx1024m -XX:PermSize=64m -XX:MaxPermSize=256m -verbose:gc -Xloggc:/data1/logs/jboss/GC.log -XX:+HeapDumpOnOutOfMemoryError -Dsun.rmi.dgc.client.gcInterval=3600000 -Dsun.rmi.dgc.server.gcInterval=3600000 -Dorg.apache.catalina.STRICT_SERVLET_COMPLIANCE=false -Djava.net.preferIPv4Stack=true -Djava.library.path=/usr/local/java/jboss-4.2.2.GA/bin/native -Djava.endorsed.dirs=/usr/local/java/jboss-4.2.2.GA/lib/endorsed -classpath /usr/local/java/jboss-4.2.2.GA/bin/run.jar:/usr/local/java/jdk1.6.0_06/lib/tools.jar org.jboss.Main -c default -b <IP_ADDRESS> -Djboss.messaging.ServerPeerID=1

非常感谢您的帮助。同时，对于如何分析GC/堆转储，如果您能提供一些指导，将对我以后的工作有很大帮助。
此致敬礼， Sumit Taneja
4
赞成一个写得好的问题。 - Nishant
@Sumit，不要发GC日志，发Hibernate代码。 - Dead Programmer
它可能无法解决您的问题，但您的JDK急需升级！ - Joachim Sauer
@Sumit：请看一下错误报告http://bugs.mysql.com/bug.php?id=36565。 - Dead Programmer
@Suresh @Joachim：在这个特定的 JBoss 实例中提供了 2 个 Web 应用程序（内部 Web 应用程序和 JForum），所有部署都通过适当的关闭 / 重启 JBoss 服务器来处理。因此，除非是由 JBoss 自动完成（如果有的话！！），否则不应该有任何脏卸载 / 重新加载 Web 模块。 - Sumit
显示剩余3条评论
3个回答
3

Eclipse有一个很好的工具叫做Memory Analyzer。它可以分析OOM产生的堆转储。它绘制出非常好的图表，帮助您缩小内存消耗的主要部分 - 您的应用程序，JBoss，设置的其他部分 - 到非常细节的水平。

如果您在此处粘贴其输出，则我们可以继续研究您的问题。

感谢您的迅速回复。我将安装MAT并发布输出。同时，也会在Full GC发生时发布来自jboss的堆转储。 - Sumit
同意，如果你有一个堆转储，MAT非常有用。 - Jubal
3

使用4GB RAM并使用-Xmx1024m（最大的java堆内存为1024M）可能不是有意为之。

另一方面，我认为你的查询返回的结果过多，可能是由于连接操作或使用了null限制，导致列表过大。

你可以从中间进行GC快照开始。

# jmap -dump:format=b,file=dump.hprof <pid>

然后使用上述的内存分析工具。

谢谢提供的信息，我会检查并更新。同时，我不确定你所说的“使用4GB RAM运行并使用-Xmx1024m（最大Java堆量为1024M）可能不是故意的”具体意思是什么。我已经有意地添加了-Xms和-Xmx标志来运行jboss。 - Sumit
@Sumit：我的意思是，如果你在该服务器上没有运行其他任何东西，那么你可以为JVM分配更多的内存，因为其他3GB几乎什么也不做。如果服务器运行其他东西，那么这完全没问题。 - David Lantos
感谢您的澄清。是的，服务器上还运行着其他应用程序！！ - Sumit
服务器刚刚自动重启，因此GC现在恢复正常（Full GC很少发生）。我使用您的命令拍摄了堆快照，并发现了一些可能有问题的对象。当定期进行Full GC时，将再次拍摄快照以确认这些对象，并发布代码以获取解决方案建议。 - Sumit
1
问题已经确定。将会开一个单独的问题来寻求解决方案。将此答案标记为正确答案，因为MAT在确定问题方面帮了很大的忙。谢谢大家！ - Sumit
0
Somewhere your code is creating temporary objects in an memory- less environment.
Please look at your code (HibernateCommentaryDao.java) 

it is something with n+1 fetch

过度的GC时间和OutOfMemoryError

如果垃圾回收所花费的时间超过了98％，且恢复的堆内存不到2％，并行收集器将抛出OutOfMemoryError。此功能旨在防止应用程序因堆太小而无法取得任何进展而长时间运行。如果需要，可以通过在命令行中添加选项-XX：-UseGCOverheadLimit来禁用此功能。

谢谢您查看这个问题。按照您的要求，我添加了相关代码（抱歉，代码太长了，无法在此处发布！）。 - Sumit
网页内容由stack overflow 提供, 点击上面的
可以查看英文原文，
原文链接