情境导入

产线一个问题:业务系统调用后台超时,问是不是 FULL GC 的问题。

查看方式

  • 知道 GC 文件的位置

··· locate xxx.log ···

  • 知道如何查看 FULL GC 日志
cat /XXX/gc.log | grep -a 'Full'| more

简单分析

直接根据 full gc 的关键词查看。

一般在并发较高的系统中会出现这种日志,且几天出现一次。

但是一旦出现,一次 FULL GC 可能时间多达 10S,就会导致外部调用超时。

教训

你应该知道如何让系统打印 GC 日志,并且当系统调用超时的时候,可以联系到 FULL GC,并会排查。

  • 问题2

线上每台机器去看的效率实在不高,建议有一个监控系统。

可以在第一时间获取到 FULL GC 的日志,并且发送邮件/短信通知给相关负责人。

IDEA 中打印 GC 日志

编写测试类

public class Main {

    public static void main(String[] args) throws InterruptedException {
        List<String> stringList = new ArrayList<>();
        while (true) {
            for(int i = 0; i < 10000; i++) {
                stringList.add(UUID.randomUUID().toString());
            }
            TimeUnit.SECONDS.sleep(1);
            System.out.println(stringList.size());
        }
    }
}

配置运行 jvm 参数

【run】=>【Edit Configration】=>【vm option】

  • 打印 GC 日志信息
-XX:+PrintGCDetails

测试日志如下:

10000
20000
30000
[GC (Allocation Failure) [PSYoungGen: 33280K->4689K(38400K)] 33280K->4697K(125952K), 0.0032247 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
40000
50000
60000
70000
[GC (Allocation Failure) [PSYoungGen: 37969K->5112K(38400K)] 37977K->9224K(125952K), 0.0046176 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
80000

简单分析

[GC (Allocation Failure) [PSYoungGen: 33280K->4689K(38400K)] 33280K->4697K(125952K), 0.0032247 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 

GC 日志

GC 原因:Allocation Failure

GC 类型:PSYoungGen

GC 效果: 33280K->4689K(38400K)

GC 消耗时间:Times: user=0.00 sys=0.00, real=0.00 secs

没有打印 gc.log

场景

有时候一台机器会出现,没有设置 jvm 打印日志怎么办呢。

命令 jstat

jstat -gcutil <pid>

如何查看 pid

$ jps
29296 Jps
28710 jboss-modules.jar

首先获取 pid

$ps -ef | grep "projectName"
projectName   15599 15514 52 Jul02 ?        08:45:15 /bea/jdk1.7.0_99/bin/java -D[Standalone] 

可知对应 pid=15599

执行命令

jstat -gcutil 15599

日志信息如下:

S0     S1     E      O      P     YGC     YGCT    FGC    FGCT     GCT   
0.00  98.97   2.71  79.48  53.54   3759  118.032     2    0.951  118.984
  • 字段解释

S0 :年轻代中第一个survivor(幸存区)已使用的占当前容量百分比 S1 :年轻代中第二个survivor(幸存区)已使用的占当前容量百分比 E :年轻代中Eden(伊甸园)已使用的占当前容量百分比 O :old代已使用的占当前容量百分比 P :perm代已使用的占当前容量百分比 YGC :从应用程序启动到采样时年轻代中gc次数 YGCT :从应用程序启动到采样时年轻代中gc所用时间(s) FGC :从应用程序启动到采样时old代(全gc)gc次数 FGCT :从应用程序启动到采样时old代(全gc)gc所用时间(s) GCT:从应用程序启动到采样时gc用的总时间(s)

统计监控

jstat -gcutil pid 300 >/tmp/gc.log

300 是一个时间间隔,单位为 ms,但是不要低于 50,会失去意义。

这个对性能损耗比较小,生产可以使用,但是不要使用 jmap/jstatck

如何查看的 GC 器类型

命令

java -XX:+PrintCommandLineFlags -version

效果

-XX:InitialHeapSize=128975232 -XX:MaxHeapSize=2063603712 -XX:+PrintCommandLineFlags -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseParallelGC 
java version "1.8.0_121"
Java(TM) SE Runtime Environment (build 1.8.0_121-b13)
Java HotSpot(TM) 64-Bit Server VM (build 25.121-b13, mixed mode)

各个版本默认类型

jdk1.7 默认垃圾收集器Parallel Scavenge(新生代)+Parallel Old(老年代)

jdk1.8 默认垃圾收集器Parallel Scavenge(新生代)+Parallel Old(老年代)

jdk1.9 默认垃圾收集器G1

jboss 默认配置文件地址

/app/xxx/jboss/bin/standalone.conf

chat

Q1-java 链路压测性能降低 50%,涉及到多个应用。应该如何分析呢?

链路压测性能降低50%可能是由多种原因引起的,需要进行系统性的分析来找到根本原因。以下是一些可能的步骤和方法,帮助你进行分析:

  1. 性能监控和日志分析: 检查应用程序的性能监控和日志记录系统。查看是否有任何异常或错误信息。重点关注慢查询、错误率、资源利用率等指标。

  2. 系统资源分析: 使用系统工具(例如top、htop、iostat等)来监控服务器的 CPU、内存、磁盘和网络使用情况。检查是否有资源瓶颈。

  3. 网络延迟和带宽: 检查网络延迟和带宽。如果涉及多个应用程序,可能存在网络通信方面的问题。使用网络分析工具(例如Wireshark)进行深入分析。

  4. 数据库性能分析: 如果应用程序涉及数据库,检查数据库的性能。查看慢查询日志,检查索引是否正确使用,以及是否有不必要的数据库连接。

  5. 代码分析: 进行应用程序代码的审查。查看最近的代码更改是否可能导致性能问题。重点关注与性能相关的代码段,例如循环、嵌套查询等。

  6. 压测环境配置: 检查链路压测的环境配置是否与生产环境一致。确保测试环境的硬件、网络等条件与实际环境相似。

  7. 版本管理: 检查应用程序和依赖库的版本。有时升级到新版本可能导致性能问题,特别是在一些库或框架存在Bug的情况下。

  8. 并发连接数: 考虑检查并发连接数是否达到系统的极限。可能是由于并发连接数过多导致性能下降。

  9. 缓存机制: 如果应用程序使用了缓存,检查缓存的命中率和性能。不正确的缓存配置可能导致性能问题。

  10. 分布式系统调试: 如果涉及多个应用程序,确保分布式系统的各个组件协同工作。检查服务之间的通信是否有异常。

  11. 第三方服务: 如果应用程序依赖于第三方服务,检查这些服务的性能。可能是由于第三方服务的问题导致性能下降。

  12. 内存泄漏: 检查是否存在内存泄漏问题。使用工具如Java VisualVM或MAT(Memory Analyzer Tool)来分析内存使用情况。

  13. 线程分析: 使用工具如VisualVM或Thread Dump Analyzer分析应用程序的线程情况,查找是否有死锁或线程争用。

以上步骤并非详尽无遗,但它们可以为你提供一些方向来定位性能问题。在进行分析时,建议逐步排查,逐步缩小范围,以找到问题的确切位置。

Q2-怀疑是 gc 造成的,应该如何分析?

如果怀疑是GC(垃圾回收)引起的性能问题,你可以采取以下步骤来进行分析:

  1. GC日志分析: 开启Java应用程序的GC日志,并对日志进行分析。GC日志中包含了GC事件的详细信息,包括每次GC的类型、持续时间、频率等。你可以使用工具如jstatjvisualvm或其他GC日志分析工具来帮助分析GC情况。

    通过以下JVM参数开启GC日志:

     -XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:/path/to/gc.log
    
  2. GC暂停时间分析: 查看GC暂停时间,特别关注Full GC的暂停时间。长时间的GC暂停可能导致性能下降。你可以通过GC日志中的时间戳信息来确定GC暂停的时间点。

  3. GC日志分析工具: 使用工具如GCViewerGCEasy等来分析GC日志。这些工具可以以图形化的方式展示GC事件,帮助你更直观地理解GC行为。

  4. 内存使用情况: 观察应用程序的内存使用情况,包括堆内存和非堆内存的使用情况。GC问题可能与内存泄漏或内存过度分配有关。

  5. Heap Dump分析: 在GC发生时生成Heap Dump,并使用Heap Dump分析工具(如Eclipse Memory Analyzer)来检查内存中的对象。这可以帮助你确定是否存在内存泄漏或不必要的对象。

    通过以下JVM参数生成Heap Dump:

     -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/path/to/heapdump.hprof
    
  6. 调整GC策略: 根据GC日志的分析结果,考虑调整GC策略。你可以选择不同的垃圾回收器,调整堆大小,或者使用GC相关的JVM参数进行优化。

  7. 分析业务代码: 在GC问题的背后可能是业务代码中的一些问题,例如内存泄漏、不合理的对象创建等。仔细审查业务代码,特别关注与内存管理相关的部分。

  8. 使用JVM Profiler: 使用JVM性能分析工具,如VisualVM、YourKit等,来检查应用程序的性能瓶颈。这些工具可以提供更详细的性能分析信息,包括方法级别的性能分析。

在进行分析时,记得采用科学的方法,逐步排除可能性。

同时,对于生产环境,谨慎地进行任何调整,确保在非生产环境中进行充分的测试和验证。

Q3-gc log 要怎么看?

GC(垃圾回收)日志包含了有关Java应用程序中垃圾回收事件的详细信息。GC日志的分析可以帮助你了解垃圾回收的性能表现,找到潜在的性能问题。以下是一些常见的GC日志参数和如何读取它们:

GC日志参数

为了生成GC日志,你可以使用以下JVM参数:

-XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:/path/to/gc.log
  • -XX:+PrintGC: 开启GC日志输出。
  • -XX:+PrintGCDetails: 输出更详细的GC信息。
  • -XX:+PrintGCDateStamps: 在每条GC日志行前加上时间戳。
  • -Xloggc:/path/to/gc.log: 将GC日志输出到指定文件。

GC日志样例

一条典型的GC日志条目如下:

2023-11-13T10:30:45.678-0700: 156.456: [GC (Allocation Failure) [PSYoungGen: 4194304K->524288K(4718592K)] 6291456K->2097152K(9437184K), 0.1234567 secs] [Times: user=0.12 sys=0.01, real=0.12 secs]

这个例子中包含以下信息:

  • 时间戳(2023-11-13T10:30:45.678-0700): 记录了GC事件的发生时间。
  • GC类型(GC (Allocation Failure)): 表示发生的GC类型,例如垃圾收集的原因。
  • 堆内存变化(PSYoungGen: 4194304K->524288K(4718592K)): 描述了年轻代(Young Generation)的变化,包括垃圾回收前后的大小以及总大小。
  • 堆内存总变化(6291456K->2097152K(9437184K)): 描述了整个堆内存的变化,包括垃圾回收前后的大小以及总大小。
  • GC持续时间(0.1234567 secs): 表示垃圾回收的持续时间。
  • 用户、系统、实际时间([Times: user=0.12 sys=0.01, real=0.12 secs]): 提供了垃圾回收阶段的用户态、内核态、以及实际时间。

GC日志分析

在分析GC日志时,你可以关注以下几点:

  1. GC类型: 查看GC日志中的GC类型,了解垃圾回收的原因。例如,Allocation Failure 表示由于分配失败触发的GC。

  2. 堆内存变化: 观察堆内存的变化,特别关注垃圾回收前后的大小和总大小。这可以帮助你确定GC的频率以及堆内存的使用情况。

  3. GC持续时间: 注意垃圾回收的持续时间,尤其是Full GC。长时间的GC暂停可能影响应用程序的性能。

  4. 分析GC频率和时长: 查看GC事件的频率和时长。如果GC事件频繁或者持续时间较长,可能需要调整堆大小或GC策略。

  5. GC时间与业务操作关联: 将GC日志的时间戳与业务操作日志对比,看是否有GC事件与业务操作的相关性。这有助于找到可能导致GC的业务代码。

  6. 使用GC日志分析工具: 使用工具如GCViewerGCEasy等来图形化地分析GC日志,以更清晰地了解GC事件的模式和影响。

通过这些分析,你可以更好地理解应用程序的GC行为,找到潜在的性能问题,并进行相应的优化。

Q4-前面不是时间戳 而是 81415.284 这种时间,如何转换为一般的时间?

这种时间格式通常是相对于应用程序启动的时间的毫秒数。要将这种相对时间转换为一般的日期和时间格式,你需要知道应用程序启动的确切时间。

以下是一个简单的步骤,假设 81415.284 表示从应用程序启动开始的毫秒数:

  1. 获取应用程序启动时间: 记录应用程序启动的确切时间,可以使用系统时间或者应用程序日志中的时间戳。

  2. 转换相对时间: 将相对时间 81415.284 加上应用程序启动的时间戳。这将得到一个以毫秒为单位的绝对时间。

  3. 转换为一般时间格式: 使用你喜欢的编程语言或工具,将绝对时间转换为一般的日期和时间格式。以下是一个示例使用Java的代码:

    long relativeTimeMillis = 81415; // 这里假设是 81415.284 的整数部分
    long applicationStartTimeMillis = System.currentTimeMillis(); // 应用程序启动的时间戳
    
    long absoluteTimeMillis = applicationStartTimeMillis + relativeTimeMillis;
    java.util.Date date = new java.util.Date(absoluteTimeMillis);
    
    System.out.println(date);
    

    这段代码中,absoluteTimeMillis 是相对时间和应用程序启动时间的和,然后使用 java.util.Date 类来创建一个日期对象,最后打印出来。

请注意,这是一个简化的例子,实际上可能需要对时区、日期格式等进行更多的处理,具体取决于你的需求和使用的编程语言。

Q5-如何根据 ps -ef | grep java 的信息,获取应用的启动时间?

在Linux系统上,你可以使用ps命令结合grepawk等工具来获取Java应用的启动时间。启动时间通常在ps输出的一些列参数中。以下是一个可能的方法:

ps -eo pid,lstart,cmd | grep java

上述命令中:

  • -eo pid,lstart,cmd:指定ps命令输出的列为进程ID(pid)、启动时间(lstart)、和命令行(cmd)。

  • grep java:过滤出包含”java”的进程。

输出可能类似于:

1234 Mon Nov 13 10:30:45 2023 java -jar your-application.jar

其中,1234是Java应用程序的进程ID,Mon Nov 13 10:30:45 2023是启动时间,后面是Java应用程序的命令行。

你可以使用awk来提取启动时间:

ps -eo pid,lstart,cmd | grep java | awk '{print $2, $3, $4, $5, $6}'

这将输出类似于:

Mon Nov 13 10:30:45 2023

你可以根据需要调整awk命令的参数来选择输出的时间信息。

然后,你可以使用这个时间信息与相对时间(例如 81415.284)进行计算,从而得到相对于应用程序启动的绝对时间。

拓展阅读

jmap

jstat

jconsole

参考资料

在IDE的后台打印GC日志

JVM的GC日志的主要参数

【GC分析】Java GC日志查看

jvm 性能调优工具之 jstat

JVM系列:查看JVM使用的什么垃圾收集器