JVM日常故障排查小结

前置知识

jstack简介

jstackJVM自带的工具,用于追踪Java进程线程id的堆栈信息、锁信息,或者打印core file,远程调试Java堆栈信息等。

而我们常用的指令则是下面这条:

# 打印对应java进程的堆栈信息
jstack [ option ] pid 

option常见选项

-F	当正常输出的请求不被响应时,强制输出线程堆栈
-m	如果调用到本地方法的话,可以显示C/C++的堆栈
-l	除堆栈外,显示关于锁的附加信息,在发生死锁时可以用jstack -l pid来观察锁持有情况

Monitor锁工作机制

这个知识涉及到了Java锁底层的工作原理,感兴趣的读者可以参阅笔者这篇文章的Synchronized 是怎样实现的 这一小节

聊聊Java关键字synchronized

线程状态复习

在使用jstack排查问题之前,我们必须了解堆栈中的信息,所以我们首先必须复习一下线程中的六大状态:

  1. New:线程处于创建但还未启动的状态。
  2. RUNNABLE:RUNNABLE其实是JVM自定义的一种状态,如果和操作系统的线程状态进行等价理解的话,RUNNABLE是处于操作系统Running或者Ready状态,因为CPU在这两个状态间的切换几乎是瞬时的,所以JVM统一用RUNNABLE表示。
  3. Waiting:线程处于等待唤醒状态。
  4. Timed Waiting:在有限时间内线程等待唤醒。
  5. Blocked:程序等待进入同步区域,等待监视器锁中,线程处于阻塞状态。
  6. Terminated:线程工作完成,处于结束状态了。

了解过线程状态后,我们就可以了解一下jstack导出的dump文件中线程会基于这些状态出现的各种情况:


runnable:线程处于执行中
deadlock:死锁(重点关注)
blocked:线程被阻塞 (重点关注)
Parked:停止
locked:对象加锁
waiting:线程正在等待
waiting to lock:等待上锁
Object.wait():对象等待中
waiting for monitor entry:等待获取监视器(重点关注)
Waiting on condition:等待资源(重点关注),最常见的情况是线程在等待网络的读写

MAT(Memory Analyzer)下载安装

下载地址

https://www.eclipse.org/mat/previousReleases.php

为了后续我们可以查看JVM输出的hprof日志,我们需要下载一个MAT的工具,如下图所示,选择更早版本

在这里插入图片描述

以笔者为例,笔者就选择了1.7版本

在这里插入图片描述

完成下载后,双击下面这个exe文件能打开就说明一切正常

在这里插入图片描述

线程死锁问题排查思路

问题代码

如下所示,笔者使用spring boot写了一段死锁的代码,如下所示,然后将其放到服务器中启动

@RestController
public class TestController {private static Logger logger = LoggerFactory.getLogger(TestController.class);private Object lock1 = new Object();private Object lock2 = new Object();/*** 模拟一个线程死锁的请求** @return*/@GetMapping("deadLock")public String deadLock() throws Exception {Thread t1 = new Thread(() -> {logger.info("线程1开始工作,先获取锁1");synchronized (lock1) {try {Thread.sleep(3000);} catch (InterruptedException e) {e.printStackTrace();}logger.info("线程1获得锁1,尝试获得锁2");synchronized (lock2) {logger.info("线程1获得锁2成功");}}});Thread t2 = new Thread(() -> {logger.info("线程2开始工作,先获取锁2");synchronized (lock2) {try {Thread.sleep(3000);} catch (InterruptedException e) {e.printStackTrace();}synchronized (lock1) {logger.info("线程2获得锁1成功");}}});t1.setName("my-thread-1");t2.setName("my-thread-2");t1.join();t2.join();t1.start();t2.start();return "success";}
}

重现问题

由于这只是一个demo,我们日常发现这种问题的时候大概率是多线程中的业务没有结束,所以重现问题也很简单,通过命令调用一下接口即可

curl http://localhost:8888/deadLock

排查思路

首先确定当前发生死锁的java应用,我们通过jps确定进程id,可以看到笔者服务器的进程id23334


[root@xxxxtmp]# jps
23830 Jps
23334 jar

然后通过jstack -l查看锁以及锁的附加信息

jstack -l 23334

最终可以在jstack的最下方看到这样一段信息(Found one Java-level deadlock),由此确认出现my-thread-1持有0x00000000ec509610等待0x00000000ec509620my-thread-2反之。

然后我们通过jstack信息即可定位到问题代码在TestController.java:53以及TestController.java:37

Found one Java-level deadlock:
=============================
"my-thread-2":waiting to lock monitor 0x00007f2800ac9318 (object 0x00000000ec509610, a java.lang.Object),which is held by "my-thread-1"
"my-thread-1":waiting to lock monitor 0x00007f27e40062c8 (object 0x00000000ec509620, a java.lang.Object),which is held by "my-thread-2"Java stack information for the threads listed above:
===================================================
"my-thread-2":at com.example.jstackTest.TestController.lambda$deadLock$1(TestController.java:53)- waiting to lock <0x00000000ec509610> (a java.lang.Object)- locked <0x00000000ec509620> (a java.lang.Object)at com.example.jstackTest.TestController$$Lambda$582/2089009876.run(Unknown Source)at java.lang.Thread.run(Thread.java:748)
"my-thread-1":at com.example.jstackTest.TestController.lambda$deadLock$0(TestController.java:37)- waiting to lock <0x00000000ec509620> (a java.lang.Object)- locked <0x00000000ec509610> (a java.lang.Object)at com.example.jstackTest.TestController$$Lambda$581/1994255298.run(Unknown Source)at java.lang.Thread.run(Thread.java:748)Found 1 deadlock.

CPU 飙升问题排查思路

简介

导致CPU 100%的原因有很多,一般来说都是编码不当导致的,所以常规的排查思路为:

  1. 定位进程号,如果是Java进程则查看是哪个线程导致的。
  2. 定位导致CPU 飙升的线程号,转为16进制。
  3. 导致JVM锁信息日志,使用线程号定位代码。
  4. 排查并修复代码问题。

问题复现

首先笔者准备了一个导致CPU飙升的问题代码,可以看到线程池中的线程不会停止不断工作

private ExecutorService threadPool = Executors.newFixedThreadPool(100);private static Object lock = new Object();private static Logger logger = LoggerFactory.getLogger(TestController.class);public TestController() {}@GetMapping({"/test"})public void test() {for(int i = 0; i < 100; ++i) {this.threadPool.execute(() -> {logger.info("加法线程开始工作");long sum = 0L;Object var2 = lock;synchronized(lock){}try {while(true) {sum += 0L;}} finally {;}});}}

然后我们发起请求

 curl http://localhost:9550/test

排查过程

此时使用top命令查看,可以看到24411号进程CPU占用百分比飙升。此时我们就需要进一步定位这个进程的哪一个线程出问题了。

在这里插入图片描述

所以我们需要进一步定位这个问题是哪一个线程导致的,命令如下所示,使用线程模式查看对应pid的线程情况

top -Hp 24411

可以看到25321这个线程CPU占用过高,此时我们就可以通过thread dump定位导致问题的代码段

在这里插入图片描述

键入jstack -l 24411 >/tmp/log.txt到处日志,然后将线程号25321转为16进制,这里笔者使用了一个在线的网站地址

https://www.sojson.com/hexconvert.html

可以看到25321转换为16进制值为62e9,所以我们就使用62e9到导出的日志文件中查看这个线程堆栈情况。

在这里插入图片描述

使用转换的值从刚刚导出的日志中定位,可以看到该线程处于运行状态,很明显这个线程一直处于运行中,有一段逻辑肯定在不停的消耗CPU资源,所以我们查看代码位置在TestController.java:32,由此得到问题代码并修复问题。

在这里插入图片描述

OOM问题排查思路

问题简述

出现OOM问题大抵是有两个原因:

  1. 大流量导致服务器创建大量的对象把内存打爆了,面对这种情况我们除了熔断以外别无他法。
  2. 程序编写不规范导致,大流量情况下出现垃圾内存进而出现OOM,笔者本地探讨的就是这种情况。

复现问题

如下所示,笔者初始化了一个Spring Boot程序,创建一个线程池,模拟无数个线程池将不断将内存写入4M的数据,并且不清理。

RestController
public class TestController {final static ThreadPoolExecutor poolExecutor = new ThreadPoolExecutor(100, 100, 1, TimeUnit.MINUTES,new LinkedBlockingQueue<>());// 创建线程池,通过线程池,保证创建的线程存活final static ThreadLocal<Byte[]> localVariable = new ThreadLocal<Byte[]>();// 声明本地变量(value = "/test0")public String test0(HttpServletRequest request) {poolExecutor.execute(() -> {Byte[] c = new Byte[4* 1024* 1024];localVariable.set(c);// 为线程添加变量});return "success";}}

完成后部署到服务器上,并使用以下命令启动,可以看到笔者调整的jvm堆内存大小(笔者服务器内存为1g故这里设置为100m),以及设置OOM输出参数

java -jar -Xms100m -Xmx100m # 调整堆内存大小
-XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/tmp/heapdump.hprof  # 表示发生OOM时输出日志文件,指定path为/tmp/heapdump.hprof
-XX:+PrintGCTimeStamps -XX:+PrintGCDetails -Xloggc:/tmp/heapTest.log # 打印日志、gc时间以及指定gc日志的路径
demo-0.0.1-SNAPSHOT.jar

完成后我们启动项目使用API post进行并发请求(笔者本次堆区设置很小,所以在服务器中curl一样可以重现问题)

在这里插入图片描述

可以看到服务器不久之后就出现了OOM问题

 .   ____          _            __ _ _/\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \\\/  ___)| |_)| | | | | || (_| |  ) ) ) )'  |____| .__|_| |_|_| |_\__, | / / / /=========|_|==============|___/=/_/_/_/:: Spring Boot ::                (v2.7.8)2023-01-28 23:42:39.579  INFO 3721 --- [           main] c.e.jstackTest.JstackTestApplication     : Starting JstackTestApplication v0.0.1-SNAPSHOT using Java 1.8.0_202 on iZ8vb7bhe4b8nhhhpavhwpZ with PID 3721 (/tmp/jstackTest-0.0.1-SNAPSHOT.jar started by root in /tmp)
2023-01-28 23:42:39.588  INFO 3721 --- [           main] c.e.jstackTest.JstackTestApplication     : No active profile set, falling back to 1 default profile: "default"
2023-01-28 23:42:42.300  INFO 3721 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8888 (http)
2023-01-28 23:42:42.340  INFO 3721 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2023-01-28 23:42:42.340  INFO 3721 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.71]
2023-01-28 23:42:42.613  INFO 3721 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2023-01-28 23:42:42.615  INFO 3721 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 2875 ms
2023-01-28 23:42:44.324  INFO 3721 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8888 (http) with context path ''
2023-01-28 23:42:44.351  INFO 3721 --- [           main] c.e.jstackTest.JstackTestApplication     : Started JstackTestApplication in 5.923 seconds (JVM running for 7.085)
2023-01-28 23:43:29.742  INFO 3721 --- [nio-8888-exec-1] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring DispatcherServlet 'dispatcherServlet'
2023-01-28 23:43:29.742  INFO 3721 --- [nio-8888-exec-1] o.s.web.servlet.DispatcherServlet        : Initializing Servlet 'dispatcherServlet'
2023-01-28 23:43:29.748  INFO 3721 --- [nio-8888-exec-1] o.s.web.servlet.DispatcherServlet        : Completed initialization in 5 ms
java.lang.OutOfMemoryError: Java heap space
Dumping heap to /tmp/heapdump.hprof ...
Heap dump file created [151939570 bytes in 1.112 secs]
Exception in thread "pool-1-thread-5" java.lang.OutOfMemoryError: Java heap spaceat com.example.jstackTest.TestController.lambda$test0$0(TestController.java:25)at com.example.jstackTest.TestController$$Lambda$582/394910033.run(Unknown Source)at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)at java.lang.Thread.run(Thread.java:748)
Exception in thread "pool-1-thread-7" java.lang.OutOfMemoryError: Java heap spaceat com.example.jstackTest.TestController.lambda$test0$0(TestController.java:25)at com.example.jstackTest.TestController$$Lambda$582/394910033.run(Unknown Source)at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)at java.lang.Thread.run(Thread.java:748)
Exception in thread "pool-1-thread-9" java.lang.OutOfMemoryError: Java heap space

排查思路

然后笔者使用top定位,可以看到哪个堆区大小设置为100m的进程内存占用达到10%,很明显这个进程是有问题的。

在这里插入图片描述

然后使用top -Hp 3721查看进程的线程信息,可以看到这里面的每一个线程基本都把堆区内存打满了,我们不妨查看任意一个线程

在这里插入图片描述

我们首先使用jstack -l 3721将日志导出,这里就以3873转为16进制查看线程状态,可以发现线程处于等待状态,而且日志中并没有存在死锁的信息,所以我们必须进一步查看堆区情况确认是否是因为内存泄漏导致的。

在这里插入图片描述

然后使用jmap查看堆区使用情况

jmap -heap 3721

从下面的日志可以看出老年代使用率高达82%,很明显有一些长期没有释放的对象在内存中导致OOM问题。

在这里插入图片描述

我们从上文设置的oom日志路径中找到日志/tmp/heapdump.hprof,导出到本地,使用MAT打开

在这里插入图片描述

找到使用率最高的Byte数组,点击下图Histogram ,点击内存占用最高的选项展开。

在这里插入图片描述

这里补充一下截图中看到的两个选项:

  1. with incoming references: 表示的是 当前查看的对象,被外部的应用。
  2. with outGoing references: 表示的是 当前对象,引用了外部对象。

所以我们的选择with incoming reference

在这里插入图片描述

可以定位到就是我们一个线程池中的threadLocal使用不当导致OOM问题了

在这里插入图片描述

参考文献

Java内存分析工具MAT(Memory Analyzer Tool)安装使用实例

JVM参数-XX:+HeapDumpOnOutOfMemoryError使用方法

Java 内存限制

Java 性能调优实战

面渣逆袭(Java 虚拟机-JVM面试题八股文)必看👍

Java程序员必备:jstack命令解析

内存分析工具MAT的使用入门

本文来自互联网用户投稿,该文观点仅代表作者本人,不代表本站立场。本站仅提供信息存储空间服务,不拥有所有权,不承担相关法律责任。如若转载,请注明出处:http://www.mzph.cn/news/230454.shtml

如若内容造成侵权/违法违规/事实不符,请联系多彩编程网进行投诉反馈email:809451989@qq.com,一经查实,立即删除!

相关文章

计算智能 | 粒子群算法

一、寻找非线性函数的最大值 这里我们使用python来求解《MATLAB智能算法30个案例分析》种第13章的内容。 我们使用基本粒子群算法寻找非线性函数 的最大值。 在Python程序中&#xff0c;我们规定粒子数为20&#xff0c;每个粒子的维数为2&#xff0c;算法迭代进化次数为300&…

I/O模型及相似概念

I/O I/O&#xff08;输入/输出&#xff09;模型是计算机系统中用于处理输入和输出操作的方法。在计算机程序中&#xff0c;I/O操作通常涉及与外部设备&#xff08;如硬盘、网络、键盘、显示器等&#xff09;的数据交互。不同的I/O模型采用不同的方式来处理这些数据交互&#x…

一文带你了解Pytest..

在之前的文章里我们已经学习了Python自带测试框架UnitTest&#xff0c;但是UnitTest具有一定的局限性 这篇文章里我们来学习第三方框架pytest&#xff0c;它在保留了UnitTest框架语法的基础上有着更多的优化处理 下面我们将从以下角度来介绍Pytest&#xff1a; Pytest基本介绍…

GDB Tutorial

背景&#xff1a; 最近在重新学习操作系统&#xff0c;顺带重学一下C语言&#xff0c;GDB是C语言进行调试的工具&#xff0c;也就重新学一下GDB&#xff0c;本文没有什么创新只是记录所学内容&#xff0c;供以后翻阅和查询。 一、首先需要安装一系列软件 apt-get install bui…

按摩师(空间优化的动态规划算法)

一个有名的按摩师会收到源源不断的预约请求&#xff0c;每个预约都可以选择接或不接。在每次预约服务之间要有休息时间&#xff0c;因此她不能接受相邻的预约。给定一个预约请求序列&#xff0c;替按摩师找到最优的预约集合&#xff08;总预约时间最长&#xff09;&#xff0c;…

Typora+Picgo(正常) 却上传图片失败问题解决思路和办法

报错信息 在typora中粘贴图片时报错&#xff0c;显示上传图片失败&#xff0c;有点奇怪&#xff0c;而我确定我的picgo正常且通过了测试&#xff0c;那我们就去看日志&#xff0c;跟踪排查问题在哪里 我的picgo日志文件路径在 D:\user\username\Application Data\picgo\picg…

Linux下Netty实现高性能UDP服务

前言 近期笔者基于Netty接收UDP报文进行业务数据统计的功能&#xff0c;因为Netty默认情况下处理UDP收包只能由一个线程负责&#xff0c;无法像TCP协议那种基于主从reactor模型实现多线程监听端口&#xff0c;所以笔者查阅网上资料查看是否有什么方式可以接收UDP收包的性能瓶颈…

如何实现公网访问本地内网搭建的WBO白板远程协作办公【内网穿透】

最近&#xff0c;我发现了一个超级强大的人工智能学习网站。它以通俗易懂的方式呈现复杂的概念&#xff0c;而且内容风趣幽默。我觉得它对大家可能会有所帮助&#xff0c;所以我在此分享。点击这里跳转到网站。 文章目录 前言1. 部署WBO白板2. 本地访问WBO白板3. Linux 安装cp…

Python的代码c语言可以用吗,python代码大全和用法

本篇文章给大家谈谈Python的代码c语言可以用吗&#xff0c;以及python代码大全和用法&#xff0c;希望对各位有所帮助&#xff0c;不要忘了收藏本站喔。 深度学习的图片等比resize后&#xff0c;再把图片反向resize回来&#xff0c;验证通过 import cv2 import numpy as npdef …

python识别增强静脉清晰度 opencv-python图像处理案例

一.任务说明 用python实现静脉清晰度提升。 二.代码实现 import cv2 import numpy as npdef enhance_blood_vessels(image):# 调整图像对比度和亮度enhanced_image cv2.convertScaleAbs(image, alpha0.5, beta40)# 应用CLAHE&#xff08;对比度受限的自适应直方图均衡化&…

Java序列化、反序列化-为什么要使用序列化?Serializable接口的作用?

什么是序列化和反序列化&#xff1f; 把对象转换成字节序列把字节序列恢复成对象 结合OSI七层协议模型&#xff0c;序列化和反序列化是在那一层做的&#xff1f; 在OSI七层模型中&#xff0c;序列化工作的层级是表示层。这一层的主要功能包括把应用层的对象转换成一段连续的二进…

vue中用v-html根据后端返回结果设置样式

一、问题 1》今日遇到一个需求&#xff0c;是一个表格列返回状态status&#xff0c;并拥有多种不同颜色。 2》平日里见到的基本都是返回01234......前端用插槽放进去&#xff0c;根据数字去判断显示字段以及设置不同样式&#xff0c;今天看到的是后端直接返回一个字符串&#…

面试经典150题(27-28)

leetcode 150道题 计划花两个月时候刷完&#xff0c;今天&#xff08;第十三天&#xff09;完成了2道(27-28)150&#xff1a; 今天这两道是真的汗流浃背&#xff01;&#xff01;&#xff01; 27.&#xff08;209. 长度最小的子数组&#xff09;题目描述&#xff1a; 给定一…

SpringBoot3 Web开发新特性(Problemdetails、函数式Web)

目录 1. Problemdetails2. 函数式Web2.1 场景2.2 主要逻辑2.3 核心对象2.4 示例程序 1. Problemdetails 错误信息返回新格式 package org.springframework.boot.autoconfigure.web.servlet; ......省略部分...... public class WebMvcAutoConfiguration {......省略部分.....…

Leetcode 2967. Minimum Cost to Make Array Equalindromic

Leetcode 2967. Minimum Cost to Make Array Equalindromic 1. 解题思路2. 代码实现 题目链接&#xff1a;2967. Minimum Cost to Make Array Equalindromic 1. 解题思路 这一题其实我的思路有点笨&#xff0c;多少有点暴力求解的意思。 显然&#xff0c;如果我们给出全部的…

PCL 点云半径查找

目录 一、 算法概述二、代码实现三、测试示例一、 算法概述 适用:根据已知点坐标,在点云中搜索其指定半径范围内的所有点云。 二、代码实现 #include <iostream> #include <vector> #include <

如何搭建企业管理系统Odoo并远程访问管理界面【内网穿透】

文章目录 前言1. 下载安装Odoo&#xff1a;2. 实现公网访问Odoo本地系统&#xff1a;3. 固定域名访问Odoo本地系统 前言 Odoo是全球流行的开源企业管理套件&#xff0c;是一个一站式全功能ERP及电商平台。 开源性质&#xff1a;Odoo是一个开源的ERP软件&#xff0c;这意味着企…

【贪心算法】【中位贪心】LeetCode:100123.执行操作使频率分数最大

涉及知识点 双指针 C算法&#xff1a;前缀和、前缀乘积、前缀异或的原理、源码及测试用例 包括课程视频 贪心算法 题目 给你一个下标从 0 开始的整数数组 nums 和一个整数 k 。 你可以对数组执行 至多 k 次操作&#xff1a; 从数组中选择一个下标 i &#xff0c;将 nums[i] …

【云原生之Docker实战】Docker环境下部署群晖DSM系统(详细教程)

【云原生之Docker实战】Docker环境下部署群晖DSM系统(详细教程) 一、Virtual DSM介绍2.1 Virtual DSM特点二、本地环境介绍2.1 本地环境规划2.2 本次实践介绍三、本地环境检查3.1 检查Docker服务状态3.2 检查Docker版本3.3 检查docker compose 版本四、环境准备工作4.1 检查c…

STL技术概述与入门

STL技术概述与入门 STL介绍STL六大组件初识容器算法迭代器1. vector存放内置数据类型2. Vector存放自定义数据类型3. Vector容器的嵌套 ✨ 总结 参考博文1&#xff1a;STL技术——STL概述和入门 参考博文2&#xff1a;&#xff1c;C&#xff1e;初识STL —— 标准模板库 STL介…