【问题标题】:Problems with Java garbage collector and memoryJava垃圾收集器和内存问题
【发布时间】: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。

不幸的是,我们不直接使用这些类(显然代码使用它们,但不是直接使用),所以我似乎走到了死胡同。

我的问题是

  1. 我无法重现错误
  2. 我无法弄清楚内存到底在哪里泄漏(如果是这样的话)

有什么想法吗?

【问题讨论】:

  • 我对 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


【解决方案1】:

有很多可能性,也许您已经探索过其中的一些。

这绝对是某种内存泄漏。

如果您的服务器有用户会话,并且当用户处于非活动状态超过 X 分钟/小时时您的用户会话没有过期或被正确处理,您将获得已用内存的累积。

如果您的程序生成了一个或多个映射,并且您没有清除旧/不需要条目的映射,您可能会再次获得已用内存的累积。例如,我曾经考虑添加一个映射来跟踪进程线程,以便用户可以从每个线程获取信息,直到我的老板指出,在任何时候都没有从映射中删除完成的线程,所以如果用户保持登录状态在和活跃的情况下,他们会永远抓住这些线索。

您应该尝试在非生产服务器上进行负载测试,在该服务器上模拟大量用户对您的应用的正常使用情况。甚至可能将服务器的内存限制得比平时更低。

祝你好运,记忆问题很难追查。

【讨论】:

  • 感谢您的提示,目前我们不跟踪用户会话,实际上您甚至无法登录页面,但是我发现了一个像缓存一样工作的地图(grrrr),我也发现了finalize() 被覆盖了,你能检查一下我对这个问题的更新吗?
  • 如果finalize 被覆盖为只调用super.finalize(),与没有被覆盖的情况没有什么不同。
【解决方案2】:

我的猜测是您正在运行自动导入,它调用了 ImportHandler 的某些实例。该处理程序配置为备份它将要更新的所有节点(我认为这是默认选项),并且由于您的数据类型中可能有很多数据,并且所有这些都是在会话中完成的,因此您运行记不清。尝试找出它是哪个导入作业并禁用它的备份。

HTH, 一月

【讨论】:

    【解决方案3】:

    对于一个难以调试的问题,您需要找到一种方法来重现它。只有这样,您才能测试实验性更改并确定它们是否会使问题变得更好或更糟。在这种情况下,我会尝试编写循环来快速创建和删除服务器连接,创建服务器连接并快速向其发送占用大量内存的请求等。

    在您可以重现它之后,尝试减小堆大小,看看您是否可以更快地重现它。但是第二次这样做,因为小堆可能不会达到“GC 开销限制”,这意味着 GC 花费了过多的时间(从某种意义上说是 98%)试图恢复内存。

    对于内存泄漏,您需要弄清楚它在代码中的何处累积对对象的引用。例如。它会构建所有传入网络请求的地图吗? 网络搜索 https://www.google.com/search?q=how+to+debug+java+memory+leaks 显示了许多有关如何调试 Java 内存泄漏的有用文章,包括有关使用您正在使用的 Eclipse Memory Analyzer 等工具的提示。搜索特定的错误消息https://www.google.com/search?q=GC+overhead+limit+exceeded 也很有帮助。

    no-op finalize() 方法不应该导致这个问题,但它们很可能会加剧它。 finalize() 上的文档显示,拥有 finalize() 方法会强制 GC 两次确定实例未被引用(在调用 finalize() 之前和之后)。

    因此,一旦您可以重现问题,请尝试删除那些无操作的finalize() 方法,看看问题是否需要更长的时间才能重现。

    内存中有很多AbstractReferenceMap$WeakRef 实例,这一点很重要。 弱引用的意义在于引用一个对象而不强制它留在内存中。 AbstractReferenceMap 是一个 Map,它可以让键和/或值成为弱引用或软引用。 (软引用的目的是尝试将对象保留在内存中,但在内存不足时让 GC 释放它。)无论如何,内存中的所有 WeakRef 实例可能会加剧问题,但应该'不要将引用的 Map 键/值保留在内存中。他们指的是什么?还有什么是指这些对象?

    【讨论】:

    • +1 引用:“对于一个困难的调试问题,您需要找到一种方法来重现它。只有这样您才能测试实验性更改并确定它们是否会使问题变得更好或更糟。”
    【解决方案4】:

    'no-op'finalize() 方法绝对应该被删除,因为它们可能会使任何 GC 性能问题变得更糟。但我怀疑您还有其他内存泄漏问题。

    建议:

    • 首先摆脱无用的finalize()方法。

    • 如果您有其他 finalize() 方法,请考虑摆脱它们。 (根据最终确定做事通常是个坏主意...)

    • 使用内存分析器尝试识别正在泄漏的对象,以及导致泄漏的原因。有很多 SO Questions ... 和其他有关查找 Java 代码泄漏的资源。例如:


    现在说说你的特殊症状。

    首先,OutOfMemoryErrors 被抛出的地方可能无关紧要。

    但是,您拥有大量 AbstractReferenceMap$WeakRefAbstractReferenceMap$ReferenceEntry 对象的事实是一个字符串指示,表明您的应用程序或它正在使用的库中的某些内容正在执行大量缓存......并且该缓存与问题有关。 (AbstractReferenceMap 类是 Apache Commons Collections 库的一部分。它是 ReferenceMapReferenceIdentityMap 的超类。)

    您需要追踪那些WeakRefReferenceEntry 对象所属的地图对象(或多个对象),以及它们所引用的(目标)对象。然后你需要弄清楚是什么创建了它/它们,并弄清楚为什么没有清除条目以响应高内存需求。

    • 您是否对其他地方的目标对象有强引用(这会阻止 WeakRefs 被破坏)?

    • 是/是地图使用不正确导致泄漏。 (仔细阅读 javadocs ...)

    • 映射是否被多个线程使用而没有外部同步?这可能会导致损坏,这可能表现为大量存储泄漏。


    不幸的是,这些只是理论,可能还有其他原因导致这种情况。事实上,可以想象这根本不是内存泄漏。


    最后,您观察到堆越大问题越严重。对我来说,这仍然与Reference / 缓存相关问题一致。

    • Reference 对象比常规引用更适合 GC。

    • 当 GC 需要“破坏”Reference 时,会产生更多工作;例如处理参考队列。

    • 即使发生这种情况,产生的无法访问的对象最早也要等到下一个 GC 周期才能被收集。

    所以我可以看到,与 4Gb 堆相比,充满引用的 6Gb 堆将如何显着增加在 GC 中花费的时间百分比,这可能会导致“GC 开销限制”机制更早启动。

    但我认为这是偶然的症状,而不是根本原因。

    【讨论】:

    • 我一直在使用 Ecplipse Memory Analyzer 来获得一些启发。我还阅读了一些关于它的教程,但是我仍然无法将我的可疑(请参阅更新的答案)链接到我认为导致问题的地图,但是我认为这是由于我对 eclipse 内存缺乏了解分析工具。有教程吗?我查了eclipsesource.com/blogs/2013/01/21/…
    • @JuanAntonioGomezMoriano - 那篇博文看起来很棒。有什么不明白的?
    • 我会在一天结束时重新阅读它,并且会更具体。谢谢!
    • @JuanAntonioGomezMoriano 地图可能不会导致问题。如果它确实对对象有弱引用,那么关键问题是这些对象是什么以及对它们的强引用在哪里?
    • @Jerry101 - 同意。因此,他需要做的第一件事就是查看参考文献所指的内容。
    【解决方案5】:

    你说你已经试过jvisualvm,来检查机器。也许,再试一次,像这样:

    • 这次看看“Sampler -> Memory”选项卡。

    • 它应该告诉您哪些(类型)对象占用的内存最多。

    • 然后找出这些对象通常在哪里创建和删除。

    【讨论】:

      【解决方案6】:

      您的内存泄漏似乎来自您的数组。垃圾收集器无法识别从数组中删除的对象实例,因此不会被收集以释放内存。我的建议是,当您从数组中删除一个对象时,将前一个对象的位置分配给null,因此垃圾收集器可以意识到它是一个null 对象,然后将其删除。怀疑这将是您的确切问题,但了解这些事情总是好的,并检查这是否是您的问题。

      当您需要删除它/清理它时,将对象实例分配给null 也很好。这是因为finalize() 方法粗略而邪恶,有时不会被垃圾收集器调用。最好的解决方法是自己调用它(或其他类似方法)。这样,您就可以确保垃圾清理已成功执行。正如 Joshua Bloch 在他的书中所说:Effective Java, 2nd edition, Item 7, page 27: Avoid finalizers。 “终结者是不可预测的,通常是危险的并且通常是不必要的”。可以看here部分。

      因为没有显示代码,我看不出这些方法是否有用,但仍然值得了解这些东西。希望这些提示对您有所帮助!

      【讨论】:

        【解决方案7】:

        尝试使用一种工具来定位源代码中的漏洞,例如plumbr

        【讨论】:

          【解决方案8】:
          • 很多时候,“奇怪”错误可能是由插入 JVM 的 Java 代理引起的。如果您有任何代理正在运行(例如 jrebel/liverebel、newrelic、jprofiler),请先尝试在没有它们的情况下运行。
          • 使用非标准参数 (-XX) 运行 JVM 时也会发生奇怪的事情;已知某些组合会导致问题;您目前使用哪些参数?
          • Magnolia 本身也可能存在内存泄漏,您是否尝试过谷歌搜索“magnolia leak”?您是否使用任何 3rd-party magnolia 模块?如果可能,请尝试禁用/删除它们。

          问题可能仅与您的一部分有关。您可以尝试通过在暂存/开发服务器上“重放”您的访问日志来重现该问题。

          如果没有其他方法,如果是我,我会做以下事情: - 试图在“空” Magnolia 实例上复制问题(没有我的任何代码) - 尝试在“空”Magnolia 实例上复制问题(没有第 3 方模块) - 尝试升级所有软件(magnolia、3rd-party 模块、JVM) - 最后尝试使用YourKit运行生产站点并尝试找到泄漏

          【讨论】:

            【解决方案9】:

            按照上面的建议,我会与 Magnolia 的开发人员取得联系,但与此同时:

            您收到此错误是因为 GC 在运行时没有收集太多数据

            如果太多,并发收集器将抛出 OutOfMemoryError 时间花在垃圾收集上:如果超过 98% 总时间花在垃圾收集上,不到堆的 2% 恢复后,会抛出 OutOfMemoryError。

            由于您无法更改实现,我建议您更改 GC 的配置,以一种运行频率较低的方式,这样就不太可能以这种方式失败。

            这是一个示例配置,只是为了让您开始使用参数,您必须弄清楚您的最佳位置。 GC 的日志可能会对此有所帮助

            我的虚拟机参数如下: -Xms=6G -Xmx=6G -XX:MaxPermSize=1G -XX:NewSize=2G -XX:MaxTenuringThreshold=8 -XX:幸存者比率=7 -XX:+UseConcMarkSweepGC -XX:+CMSClassUnloadingEnabled -XX:+CMSPermGenSweepingEnabled -XX:CMSInitiatingOccupancyFraction=60 -XX:+HeapDumpOnOutOfMemoryError -XX:+PrintGC详情 -XX:+PrintGCTimeStamps -XX:+PrintTenuringDistribution -Xloggc:logs/gc.log

            【讨论】:

            • 或者,如果您必须运行不可更改的代码,则完全相反:检测(内存不足)错误,然后自动重新启动服务器(如果可能)。
            猜你喜欢
            • 1970-01-01
            • 1970-01-01
            • 2012-06-28
            • 1970-01-01
            • 2017-03-15
            • 2012-06-12
            • 1970-01-01
            • 1970-01-01
            • 2018-01-25
            相关资源
            最近更新 更多