24

我遇到了一个非常特殊的问题。我的 tomcat 以大约 25% 的 CPU 24/7 完美运行,但有时我的 CPU 会飙升至 60%,系统会停止运行并且无法恢复。

当我在减速期间进行线程转储时,几乎所有线程都忙于某种字符串或相关操作。

没有 OutOfMemory 错误或任何异常被抛出,所有请求仍然得到处理,但响应时间恶化到第 n 度,即使是亚秒请求也会减慢到 60 秒甚至更多。

我的服务器配置如下:

    Ubuntu 12.04.2 LTS
    Linux 3.2.0-38-virtual #60-Ubuntu SMP x86_64 x86_64 x86_64 GNU/Linux
    java版本“1.7.0_13”
    Java(TM) SE 运行时环境 (build 1.7.0_13-b20)
    Java HotSpot(TM) 64 位服务器 VM(内部版本 23.7-b01,混合模式)
    导出 JAVA_OPTS='-服务器
    -Xms18g -Xmx18g
    -XX:MaxPermSize=512m
    -XX:ThreadStackSize=512
    -XX:新比率=1
    -XX:幸存者比率=4
    -XX:+UseConcMarkSweepGC
    -XX:+UseParNewGC
    -XX:+CMSClassUnloadingEnabled
    -Xloggc:/usr/tomcat/logs/gc.log
    -XX:+PrintGC详情
    -XX:+打印GCDateStamps
    -XX:+PrintTenuringDistribution
    -Dcom.sun.management.jmxremote
    -Dcom.sun.management.jmxremote.port=9999
    -Dcom.sun.management.jmxremote.authenticate=false
    -Dcom.sun.management.jmxremote.ssl=false
    -Djava.awt.headless=true'

单击此处下载线程转储。我已经删除了大部分线程及其 stackTraces

单击此处下载 vmstat 日志

点击这里下载 gc 日志

关于这个原因的任何想法?谢谢

4

9 回答 9

3

这不是内存问题,因为在您的转储中,GC 甚至都不忙,并且有足够的可用内存。此外,CPU 卡在 60%,但如果应用程序忙于计算(GC 或其他),它会卡在 100%,如果这是网络攻击也是如此。所以这个问题的根源一定包括一些disk-IO操作。

众所周知,Tomcat 是有缺陷的,并且有几个严重的问题。我遇到的一件事是,没有什么特别的原因,Tomcat 突然用无意义的条目淹没了它自己的日志文件。这不仅导致磁盘填充到 100%,而且还大大减慢了传入请求。您可以通过查看 tomcat 日志及其大小来检查这一点。

如果这不是源,您应该使用可用的工具来检查Tomcat 的任何奇怪的磁盘 IO 并从那里继续。

于 2013-11-23T14:47:40.973 回答
3

要尝试查明有问题的请求,您可以在 Tomcat 中配置Stuck Thread Detection Valve 。

这个阀门允许检测需要很长时间才能处理的请求,这可能表明正在处理它的线程被卡住了。

当检测到这样的请求时,其线程的当前堆栈跟踪将写入具有 WARN 级别的 Tomcat 日志。

卡住线程的 ID 和名称可通过 JMX 在stdThreadIds 和stuckThreadNames 属性中获得。这些 ID 可以与标准 Threading JVM MBean (java.lang:type=Threading) 一起使用,以检索有关每个卡住线程的其他信息。

于 2013-02-26T14:43:47.817 回答
3

我认为你的问题是这个配置决定-XX:PermSize=320m -XX:MaxPermSize=320m不允许你的 PemSpace 动态更改,当你用尽它时会导致死锁 - 请记住实习生缓存使用 PermSpace。我会尝试更改-XX:MaxPermSize=320m-XX:MaxPermSize=512m.

于 2013-11-29T05:31:36.970 回答
3

如果 CPU 使用率低于 100%,但应用程序已停止,这意味着某些东西正在阻止 CPU 被充分利用。

I/O 或过多的上下文切换(例如由锁引起的)通常是造成这种情况的罪魁祸首。

您可以在其中一个事件期间发布 vmsstat 1 的输出吗?- 诊断的下一步是消除上下文切换是否是这里的问题。

于 2013-11-23T14:20:50.947 回答
3

尝试使用以下 JVM 选项增加代码缓存的最大大小:

-XX:ReservedCodeCacheSize=256m

有关此建议的背景,请参阅我对另一个问题的回答。

于 2014-11-05T17:54:07.077 回答
2

GC 日志中是否有任何异常?看起来你正在运行一个非常大的堆,其中包含一些不寻常的选项,并且做了很多字符串分配工作。也许您会随着时间的推移遭受堆碎片的困扰(CMS 不会压缩)。还要确保没有进行交换(如果堆太大,可能会发生,因此 VM 很少访问)

我怀疑这与 GC 有关,因为显然没有线程被阻塞。您是否尝试过使用更新的 JDK?您也可以重试但删除一些不常见的选项 -XX:+CMSScavengeBeforeRemark,因为每个次要 JDK 版本可能没有太多的测试覆盖率。

另一个怀疑可能是使用奇怪字符集(kyrillic 或阿拉伯语)的传入请求导致大量字符集映射开销。还要检查您的页面上是否有一些机器人,是否有任何可疑的请求进来?您肯定需要更长的堆栈跟踪来找出字符串操作的根操作。

于 2013-11-23T23:44:20.653 回答
1

您需要使用BTrace诊断方法调用。

编写一个这样的 breace 脚本:

跟踪com.xx.xx调用 String 的 any 方法的前缀类,并打印调用时间。

@TLS
private static Map<String, Integer> countMap = BTraceUtils.newHashMap();

private static String prefix = "com.xx.xx";// package like com.xx.xx which you want to trace ()

@OnMethod(clazz = "java.lang.String", method = "/.*/") //all method in String
public static void traceMethodInvoke() {
    String str = BTraceUtils.jstackStr();
    for (String currentClass : str.split("\\n")) {
        if (BTraceUtils.Strings.startsWith(currentClass, prefix)) {
            if (!countMap.containsKey(currentClass)) {
                countMap.put(currentClass, 1);
            } else {
                countMap.put(currentClass, countMap.get(currentClass) + 1);
            }
            break;
        }
    }
}

@OnTimer(5000)
public static void print() {
    BTraceUtils.println("========================================");
    for (Map.Entry<String, Integer> entry : countMap.entrySet()) {
        if (entry.getValue() > 100) {// print if cont > 10
            BTraceUtils.println(entry.getValue() + "\t\t" + entry.getKey());
        }
    }
    BTraceUtils.println("===========================================");

}  

结果输出如下:

====================================================
1022                           com.xx.xx.classA#m1
322                            com.xx.xx.classA#m2
2022                           com.xx.xx.classA#m21
422                            com.xx.xx.ccc.classX#m11
522                            com.xx.xx.zz.classS#m44
.........

您可以更改prefix用于跟踪另一个包前缀。

根据结果​​,您可以分析源代码并找出问题所在。

于 2013-11-26T16:23:17.840 回答
1

通过查看 RUNNABLE 线程的线程转储扫描后,有一件事很突出。您的系统似乎正在处理/尝试同时处理大量请求。除非你有很多核心,否则很可能会有很多时间切片。另一方面,我看不到明确的>>证据<<这是与 GC 相关的。(但你没有包括 GC 日志......)

我建议你看两件事。

  • 查看操作系统的虚拟内存统计信息。灾难性系统减速的一个可能原因是虚拟内存抖动。这是虚拟内存页面的总应用程序需求超过可用物理内存的地方......并且操作系统花费大量时间在物理内存和交换磁盘/页面文件之间交换页面。
  • 查看您收到的请求模式。在某些时候,您收到的请求的数量/类型可能会超出系统的容量。

如果问题是 VM 抖动,那么解决方案是减少应用程序内存需求。执行此操作的简单方法是减小Java 堆大小。

如果问题是负载,则更难解决:

  • 您可以尝试增强您的硬件(或向您的虚拟机添加更多 VCPU)。
  • 您可以尝试将负载分散到服务器的多个实例上。
  • 您可以尝试减少工作线程的数量,这样您的服务器就不会尝试一次处理这么多的请求。
  • 您可以尝试分析应用程序和/或分析请求统计信息,以查看是否有可以调整的热点,或者可以关闭昂贵的功能......

最后,您可以看看从 CMS 切换到 Parallel Collector 是否有帮助;请参阅 Oracle GC 调优页面:可用收集器。但我怀疑这是一个 GC 问题。

于 2014-03-24T16:18:36.877 回答
0

您应该进行的第一件事是找出哪些线程实际上正在消耗 CPU。它可能是正在执行字符串操作的线程,也可能是可能正在执行 GC 和 Sweep 操作的其他 VM 线程。该链接说明了如何将 CPU 峰值与线程转储关联起来

一旦你能确定线索,就会更清楚下一步应该做什么。

希望这可以帮助

于 2013-02-01T17:15:12.750 回答