Java服务生产环境下的问题排查

已于 2024-05-06 11:45:09 修改
阅读量734 收藏 9
点赞数 1
文章标签： java jvm 开发语言
于 2023-06-22 14:38:51 首次发布
版权声明：本文为博主原创文章，遵循 CC 4.0 BY-SA 版权协议，转载请附上原文出处链接和本声明。
本文链接：https://blog.youkuaiyun.com/qq_45867699/article/details/131338474
版权

Java服务生产环境下的问题排查

前言

在生产环境中，我们无法通过断点调试、新增log、可视化工具去立马查看当前的运行状态和拿到错误信息，此时，借助Java自带的命令行工具以及相关dump分析工具以及一些小技巧，可以大大提升我们排查问题的效率

一、运行参数

下面会列出一些常用且非常有效的命令以及参数来查看运行时Java程序的信息，从而辅助你了解程序运行状态。还有大量可用的功能由其他参数提供，自行参阅Oracle官方文档

1.1 查看JVM参数

jps -l 查看所有正在运行的Java程序，同时显示启动类类名，获取到PID：

4706 org.apache.catalina.startup.Bootstrap
5023 sun.tools.jps.Jps

jinfo -flags [PID] 查看运行时进程参数与JVM参数：

Attaching to process ID 28987, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.171-b11
Non-default VM flags: -XX:CICompilerCount=3 -XX:InitialHeapSize=132120576 -XX:MaxHeapSize=2092957696 -XX:MaxNewSize=697303040 -XX:MinHeapDeltaBytes=524288 -XX:NewSize=44040192 -XX:OldSize=88080384 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseParallelGC
Command line:  -Dspring.config.location=application.properties -Dspring.profiles.active=staging

java -XX:+PrintFlagsFinal -version 查看当前虚拟机默认JVM参数

1.2 查看即时GC状态

jstat -gc PID 1000 10 每秒查看一次gc信息，共10次

S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT     GCT   
512.0  512.0   15.3   0.0    4416.0   1055.2   11372.0     7572.5   14720.0 14322.5 1664.0 1522.8     40    0.137   8      0.039    0.176

输出比较多的参数，每个字段的解释参看这里

期间可能碰到提示sun.jvm.hotspot.runtime.VMVersionMismatchException: Supported versions are 24.181-b01. Target VM is 25.171-b11的问题，原因在于安装了多个版本，使用which、ls -l可简介定位到与当前执行Java程序相同的Java版本

二、错误排查

2.1 内存问题

查看JVM内存

  • 查看JVM内存状态：jmap -heap [pid]

    要注意的是在使用CMS GC 情况下，jmap -heap的执行有可能会导致Java进程挂起

  • 查看JVM堆中对象内存占用情况：jmap -histo [pid]

  • 导出JVM 中内存信息：jmap -dump:format=b,file=[filename] [pid]

    jhat是SUN 1.6及以上版本中自带的一个用于分析JVM堆DUMP文件的工具，基于此工具可分析JVM HEAP中对象的内存占用情况

    jhat -J-Xmx1024M [file] （此处的file指的是jmap -dump导出的内存数据文件）

    执行后等待console中输出 start HTTP server on port 7000 即可使用浏览器访问 IP：7000

  • eclipse Memory Analyzer：Eclipse 提供的一个用于分析JVM 堆Dump文件的插件。借助这个插件可查看对象的内存占用状况，引用关系，分析内存泄露等。

分析OOM问题

内存泄露导致OOM？内存占用异常的高？这是生产环境常常出现的问题，Java提供dump文件供我们对内存里发生过的事情进行了记录，我们需要借助一些工具从中获取有价值的信息。

导出Dump文件

  • 提前对Java程序加上这些参数印dump文件 -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=./
  • 对正在运行的程序使用jmap：jmap -dump:format=b,file=[filename] [pid]

分析Dump文件

  • 如果Dump文件不太大的话，可以传到 http://heaphero.io/index.jsp 来分析
    在这里插入图片描述

  • 文件比较大，且想进行更加系统的分析，推荐使用MAT分析，有如下几种常用查看方式：

    1. 首页中的【Leak Suspects】能推测出问题所在
    2. 点击【Create a histogram from an arbitrary set of objects】查到所有对象的数量
    3. 右键点击某个对象【Merge Shortest Paths to GC Roots】-> 【exclude all phantom/weak/soft etc. references】能查询到大量数量的某个对象是哪个GC ROOT引用的

2.2 线程问题

任务长时间不退出？CPU 负载过高？很可能因为死循环或者死锁，导致某些线程一直执行不被中断，但是不报错是最烦人的，所以日志里看不到错误信息，并且又不能用dump文件分析，因为跟内存无关。这个时候就需要用线程分析工具来帮我们了。

导出jstack文件
使用jstack PID > 文件，如果失败请加-F参数，如果还失败请使用Java程序启动时使用的用户执行jstack，下面是jstack的部分输出格式：

      [线程名]                                                              [PID的16进制]
"http-nio-8080-Acceptor-0" #17 daemon prio=5 os_prio=0 tid=0x00007fac2c4bd000 nid=0x29f4 runnable [0x00007fac192f6000]
   java.lang.Thread.State: RUNNABLE（tomcat的工作线程正在运行，有NEW/RUNNABLE/BLOCKED/WAITING/TIMED_WATING/TERMINATED状态）
    at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method)
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:422)
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:250)
    - locked <0x00000000faf845a8> (a java.lang.Object)
    at org.apache.tomcat.util.net.NioEndpoint$Acceptor.run(NioEndpoint.java:682)
    at java.lang.Thread.run(Thread.java:748)

jstack的输出可以看到所有的线程以及他们的状态，我们就可以看有哪些我们自己创建的正在运行的线程，那很可能就是那个一直在执行的线程了，此时线程名就格外重要了，所以建议创建新线程时指定有意义的线程名。当然，通过PID查找也非常方便。

排查步骤

  1. top 查看到哪个java程序负载高
  2. top -Hp PID 查看该进程所有进程的运行状态
  3. 记录下高负载的线程ID，printf "&x" PID转换成16进制
  4. jstack PID > 文件
  5. 在jstack文件中用转换成16进制之后的线程ID查询线程运行堆栈
  6. 从堆栈中了解到线程在执行什么任务，并结合业务与代码判断问题所在

CPU 飙升

方案一：使用操作系统以及JDK原生命令排查问题

  1. top -c 查看cpu和内存使用率最高的进程pid。此处拿到进程ID：370044
    在这里插入图片描述

  2. top -Hp 进程ID 查看该进程下的所有线程CPU的占用情况。此处拿到线程ID：370046
    在这里插入图片描述

  3. printf "%x\n" 线程ID 将进程ID370046转化为16进制：5a57e
    在这里插入图片描述

  4. jstack 进程ID | grep -10 线程ID 查找该进程下线程ID（jstack堆栈信息中的nid）=5a57e的上下20行线程堆栈信息。双引号中的内容就是线程名（如果线程名为“VM Thread”，说明是虚拟机GC回收线程，例"VM Thread" os_prio=0 tid=0x00007f871806e000 nid=0xa runnable）
    在这里插入图片描述

  5. 拿到该线程所执行的堆栈信息，分析相对应的代码

如果发现是GC回收线程占用CPU过高，可对该服务进行GC分析

方案二：使用Arthas（阿尔萨斯）分析CPU高占用问题

  1. curl -O https://alibaba.github.io/arthas/arthas-boot.jar或wget https://alibaba.github.io/arthas/arthas-boot.jar，下载阿尔萨斯arthas-boot.jar：https://alibaba.github.io/arthas/arthas-boot.jar

  2. java -jar arthas-boot.jar 显示当前服务器所运行的java服务
    在这里插入图片描述

  3. 输入对应服务ID，回车。此处输入1，回车
    在这里插入图片描述

  4. thread -n 3 查看下CPU占用最高的3个线程
    在这里插入图片描述
    dashboard 命令用于整体展示该服务进程所有线程、内存、GC等情况，其输出如下
    在这里插入图片描述
    exit 退出

Arthars还可以远程监控：java -jar arthas-boot.jar --target-ip 172.19.1.134，默认会连接该服务器3658端口
关于Arthas详细使用，可参考 https://www.jianshu.com/p/95449939cca3

2.3 Java VisualVM 概述

对于使用命令行远程监控jvm 太麻烦 。 在JDK1.6 中 Oracle 提供了一个新的可视化的。 JVM 监控工具 Java VisualVM 。jvisualvm.exe 在JDK 的 bin 目录下。

双击启动 Java VisualVM 后可以看到窗口左侧 “应用程序 ”栏中有“ 本地 ”、“远程 ” 、“快照 ”三个项目。

“本地 ”下显示的是在 localhost 运行的 Java 程序的资源占用情况，如果本地有 Java 程序在运行的话启动 Java VisualVM 即可看到相应的程序名，点击程序名打开相应的资源监控菜单，以图形的形式列出程序所占用的 CPU 、 Heap 、 PermGen 、类、线程的 统计信息。

“远程” 项下列出的远程主机上的 Java 程序的资源占用情况，但需要在远程主机上运行 jstatd 守护程序

VisualVM分为 3 类， 本地 它会自动侦测到，并显示出来

双击Local 下的任一节点，看到右边的变化 ，你可以监控 CPU ，内存，类，线程等运行状况，实时监控服务器性能。

右键 VisualVM我们可以看到 Thread Dump, Heap Dump

做 Thread Dump 很快，马上就可以看到结果

Heap Dump要稍花费一些时间（可以看到当前 heap 里对象的数量及占用的比例，做 OOM 很好用）

2.6 Full GC频发

root@ds-mars-int-0:/data/app/online-ds# ps aux | grep Application
root          37  2.9 22.5 43698816 21608820 ?   Sl   7月28 124:10 java -Xmx16G -XX:+UseTLAB -XX:+DisableExplicitGC -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:gc.log -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=10 -XX:GCLogFileSize=10M -XX:+UseG1GC -XX:MaxGCPauseMillis=100 -XX:G1RSetUpdatingPauseTimePercent=5 -XX:ErrorFile=/data/app/online-ds/logs/hs_error%p_2023-07-28-192321.log -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/data/app/online-ds/mem.dump -XX:-OmitStackTraceInFastThrow -Dcom.sun.management.jmxremote.port=7601 -Dcom.sun.management.jmxremote.ssl=false -Dcom.sun.management.jmxremote.authenticate=false -cp /data/app/online-ds:conf/:lib/* -Djava.library.path=/data/app/online-ds:conf/:asr_lib/:/usr/local/lib/tensorflow/ -Dspring.profiles.active=ds-mars-int co.mega.ds.Application

java
-Xmx16G 
-XX:+UseTLAB 
-XX:+DisableExplicitGC 
-XX:+PrintGCDetails 
-XX:+PrintGCDateStamps 
-Xloggc:gc.log 
-XX:+UseGCLogFileRotation 
-XX:NumberOfGCLogFiles=10 
-XX:GCLogFileSize=10M 
-XX:+UseG1GC 
-XX:MaxGCPauseMillis=100 
-XX:G1RSetUpdatingPauseTimePercent=5 
-XX:ErrorFile=/data/app/online-ds/logs/hs_error%p_2023-07-28-192321.log 
-XX:+HeapDumpOnOutOfMemoryError 
-XX:HeapDumpPath=/data/app/online-ds/mem.dump 
-XX:-OmitStackTraceInFastThrow 
-Dcom.sun.management.jmxremote.port=7601 
-Dcom.sun.management.jmxremote.ssl=false 
-Dcom.sun.management.jmxremote.authenticate=false 
-cp /data/app/online-ds:conf/:lib/* 
-Djava.library.path=/data/app/online-ds:conf/:asr_lib/:/usr/local/lib/tensorflow/
-Dspring.profiles.active=ds-mars-int 
co.mega.ds.Application

参考：
https://heapdump.cn/article/1870333
https://coding.imooc.com/class/241.html
https://crossoverjie.top/2018/07/08/java-senior/JVM-Troubleshoot/
https://www.jianshu.com/p/1b1c998c4448

评论
添加红包

请填写红包祝福语或标题

个

红包个数最小为10个

元

红包金额最低5元

当前余额3.43元 前往充值 >
需支付：10.00元
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包

打赏作者

自传丶

你的鼓励将是我创作的最大动力

¥1 ¥2 ¥4 ¥6 ¥10 ¥20
扫码支付：¥1
获取中
扫码支付

您的余额不足，请更换扫码支付或充值

打赏作者

实付元
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明：

1.余额是钱包充值的虚拟货币，按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载，可以购买VIP、付费专栏及课程。

余额充值