【发布时间】:2014-03-31 15:34:43
【问题描述】:
我的 Java 应用程序遇到了一个非常奇怪的问题。
本质上它是一个使用 magnolia(一个 cms 系统)的网页,生产环境中有 4 个实例可用。有时 CPU 在 Java 进程中达到 100%。
所以,第一种方法是进行线程转储,并检查有问题的线程,我发现很奇怪:
"GC task thread#0 (ParallelGC)" prio=10 tid=0x000000000ce37800 nid=0x7dcb runnable
"GC task thread#1 (ParallelGC)" prio=10 tid=0x000000000ce39000 nid=0x7dcc runnable
好吧,这很奇怪,我从来没有遇到过这样的垃圾收集器问题,所以我们接下来要做的是激活 JMX 并使用 jvisualvm 检查机器:堆内存使用率非常高(95% )。
天真的方法:增加内存,因此问题需要更多时间才能出现,结果,在重新启动的服务器上增加了内存(6 GB!),问题出现在重新启动后 20 小时,而在其他内存较少的服务器上(4GB!)已经运行了10天,问题仍然需要几天才能再次出现。此外,我尝试使用服务器失败的 apache 访问日志,并使用 JMeter 将请求重播到本地服务器中,以尝试重现错误......它也没有工作。
然后我稍微调查了一下日志以发现这个错误
info.magnolia.module.data.importer.ImportException: Error while importing with handler [brightcoveplaylist]:GC overhead limit exceeded
at info.magnolia.module.data.importer.ImportHandler.execute(ImportHandler.java:464)
at info.magnolia.module.data.commands.ImportCommand.execute(ImportCommand.java:83)
at info.magnolia.commands.MgnlCommand.executePooledOrSynchronized(MgnlCommand.java:174)
at info.magnolia.commands.MgnlCommand.execute(MgnlCommand.java:161)
at info.magnolia.module.scheduler.CommandJob.execute(CommandJob.java:91)
at org.quartz.core.JobRunShell.run(JobRunShell.java:216)
at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:549)
Caused by: java.lang.OutOfMemoryError: GC overhead limit exceeded
另一个例子
Caused by: java.lang.OutOfMemoryError: GC overhead limit exceeded
at java.util.Arrays.copyOf(Arrays.java:2894)
at java.lang.AbstractStringBuilder.expandCapacity(AbstractStringBuilder.java:117)
at java.lang.AbstractStringBuilder.append(AbstractStringBuilder.java:407)
at java.lang.StringBuilder.append(StringBuilder.java:136)
at java.lang.StackTraceElement.toString(StackTraceElement.java:175)
at java.lang.String.valueOf(String.java:2838)
at java.lang.StringBuilder.append(StringBuilder.java:132)
at java.lang.Throwable.printStackTrace(Throwable.java:529)
at org.apache.log4j.DefaultThrowableRenderer.render(DefaultThrowableRenderer.java:60)
at org.apache.log4j.spi.ThrowableInformation.getThrowableStrRep(ThrowableInformation.java:87)
at org.apache.log4j.spi.LoggingEvent.getThrowableStrRep(LoggingEvent.java:413)
at org.apache.log4j.AsyncAppender.append(AsyncAppender.java:162)
at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:251)
at org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:66)
at org.apache.log4j.Category.callAppenders(Category.java:206)
at org.apache.log4j.Category.forcedLog(Category.java:391)
at org.apache.log4j.Category.log(Category.java:856)
at org.slf4j.impl.Log4jLoggerAdapter.error(Log4jLoggerAdapter.java:576)
at info.magnolia.module.templatingkit.functions.STKTemplatingFunctions.getReferencedContent(STKTemplatingFunctions.java:417)
at info.magnolia.module.templatingkit.templates.components.InternalLinkModel.getLinkNode(InternalLinkModel.java:90)
at info.magnolia.module.templatingkit.templates.components.InternalLinkModel.getLink(InternalLinkModel.java:66)
at sun.reflect.GeneratedMethodAccessor174.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:622)
at freemarker.ext.beans.BeansWrapper.invokeMethod(BeansWrapper.java:866)
at freemarker.ext.beans.BeanModel.invokeThroughDescriptor(BeanModel.java:277)
at freemarker.ext.beans.BeanModel.get(BeanModel.java:184)
at freemarker.core.Dot._getAsTemplateModel(Dot.java:76)
at freemarker.core.Expression.getAsTemplateModel(Expression.java:89)
at freemarker.core.BuiltIn$existsBI._getAsTemplateModel(BuiltIn.java:709)
at freemarker.core.BuiltIn$existsBI.isTrue(BuiltIn.java:720)
at freemarker.core.OrExpression.isTrue(OrExpression.java:68)
然后我发现such problem is due to the garbage collector using a ton of CPU but not able to free much memory
好的,原来是内存有问题,表现在CPU上,所以如果内存使用问题解决了,那么CPU应该没问题,所以我拿了一个heapdump,可惜它太大了无法打开它(文件是10GB),无论如何我在本地运行服务器m加载了一点并进行了堆转储,打开它后,我发现了一些有趣的东西:
有很多
的实例AbstractReferenceMap$WeakRef ==> Takes 21.6% of the memory, 9 million instances
AbstractReferenceMap$ReferenceEntry ==> Takes 9.6% of the memory, 3 million instances
此外,我发现了一个似乎被用作“缓存”的 Map(可怕但真实),问题是这样的映射不同步并且它在线程之间共享(是静态的),问题可能不仅是并发写入,而且由于缺乏同步,无法保证线程 A 会看到线程 B 对映射所做的更改,但是,我无法弄清楚如何使用内存蚀分析器,因为它不使用AbstracReferenceMap,它只是一个普通的HashMap。
不幸的是,我们不直接使用这些类(显然代码使用它们,但不是直接使用),所以我似乎走到了死胡同。
我的问题是
- 我无法重现错误
- 我无法弄清楚内存到底在哪里泄漏(如果是这样的话)
有什么想法吗?
【问题讨论】:
-
我对 Magnolia CMS 不熟悉,但这感觉像是对 apache common 的 ReferenceMap 的不当使用。可能,许多对象正在使用 ReferenceMap 进行“缓存”以允许更快的查找,但如果内存不足,仍然允许 GC 删除条目。但是,如果在 ReferenceMap 中使用了错误类型的引用(硬引用),则无法保证 GC 可以删除这些条目。这将导致其他瞬态数据的保留时间过长。可能值得与 Magnolia 社区联系,那里的其他人很可能以前见过这个确切的问题。
-
您在生产中使用的 JRE 版本是什么?如果它仍然是 java-1.6.0-openjdk-1.6.0.0-1.62 的 1.6 及以上版本,那么我有坏消息要告诉你:bugzilla.redhat.com/show_bug.cgi?id=1051245
-
当前 java 版本是 $ java -version java version "1.6.0_30" OpenJDK Runtime Environment (IcedTea6 1.13.1) (rhel-4.1.13.1.el5_10-x86_64) OpenJDK 64-Bit Server VM (构建 23.25-b01,混合模式)
-
恭喜,您的问题基本上让没有看过原始版本的人无法理解。不要将大的 UPDATE 通知放在顶部,而是尝试以连贯的方式更新您的问题。
-
您是否尝试过创建堆转储并使用 eclipse.org/mat 之类的内容对其进行分析,看看是什么让您的记忆保持活力?
标签: java memory garbage-collection magnolia