并发编程系列:线上问题定位

简介: 面试时经常会被问到“CPU飙高怎么排查”,“内存泄露怎么定位解决”这类问题。本篇介绍一些常见的分析方法和工具

系列文章:

并发编程系列:关于线程中断

并发编程系列:阻塞队列的实现原理

一 背景

   大家都知道,在服务/应用发布到预览或者线上环境时,经常会出现一些测试中没有出现的问题。并且由于环境所限,我们也不可能在线上调试代码,所以只能通过日志、系统信息和dump等手段来在线上定位问题。

   通常需要借助一些工具,例如jdk本身提供的一些jmap,jstack等等,或者是阿里提供的比较强大的Arthus,另外就是最基础的一些命令。根据经验,系统上发生的主要问题是在cpu、内存、磁盘几个方面,因此会优先针对这类问题进行定位。由于绝大部分服务都是部署在Linux环境下,所以一下以Linux命令为例进行说明。

二 top命令

top命令可以用于查询每个进程的情况,显示信息如下:

top - 22:32:03 up 180 days,  7:23,  1 user,  load average: 0.07, 0.06, 0.05
Tasks: 106 total,   1 running, 105 sleeping,   0 stopped,   0 zombie
%Cpu(s):  1.5 us,  1.0 sy,  0.0 ni, 97.5 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem : 16266504 total,   324836 free,  6100252 used,  9841416 buff/cache
KiB Swap:        0 total,        0 free,        0 used.  9827120 avail Mem 
  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND                                                       
 1466 root      20   0 3243684 665836  14684 S   0.7  4.1  82:18.89 java                                                          
  660 root      20   0  835120  25288   8036 S   0.3  0.2 718:10.90 exe                                                           
 4835 root      20   0 6715536 129904  13368 S   0.3  0.8 400:01.40 java                                                          
 8287 root      20   0 1003108 118464  18812 S   0.3  0.7 731:56.27 node /opt/my-ya                                               
 8299 root      20   0 1002164 107792  18816 S   0.3  0.7 730:11.28 node /opt/my-ya                                               
 8395 root      20   0  611552  35476  14504 S   0.3  0.2  14:17.25 node /opt/qkd-n                                               
10184 root      20   0 3089652 673520  15880 S   0.3  4.1  83:32.81 java                                                          
12882 root      20   0  917540  64556  16156 S   0.3  0.4 543:55.74 PM2 v4.4.0: God                                               
13556 root      20   0 2998424 556848  14548 S   0.3  3.4 496:48.18 java                                                          
14293 root      10 -10  151296  26920   6880 S   0.3  0.2   1868:03 AliYunDun                                                     
14755 root      20   0 3030352 676388  14720 S   0.3  4.2  49:16.41 java                                                          
22908 root      20   0  623456  38892  14536 S   0.3  0.2  98:50.65 node /opt/qkd-n                                               
22936 root      20   0  622680  39712  14532 S   0.3  0.2  98:27.12 node /opt/qkd-n                                               
24142 root      20   0 3303328 659496  14716 S   0.3  4.1  23:20.38 java                                                          
25566 root      20   0  706964  52660  16308 S   0.3  0.3  19:17.11 node /opt/qkd-n                                               
25597 root      20   0  708020  53112  16308 S   0.3  0.3  19:06.83 node /opt/qkd-

如上面内容所示,需要注意一下各列的含义,这里再重复一遍,如下表所示:

由于限定我们的应用是Java应用,所以只需要关注COMMOND列是java的进程信息。

有时候%CPU这列的数字可能会超过100%,这不一定是出了问题,因为是机器所有核加在一起的CPU利用率,所以我们需要计算一下,平均每个核上的利用比例,再来确定是否是CPU使用过高,进而再去分析是否发生了死循环、内存回收等问题的可能。

在top命令出来的界面下,输入1(top的交互命令数字),可以查看每个CPU的性能信息:

top - 22:39:16 up 180 days,  7:30,  1 user,  load average: 0.08, 0.06, 0.05
Tasks: 106 total,   1 running, 105 sleeping,   0 stopped,   0 zombie
%Cpu0  :  1.7 us,  1.3 sy,  0.0 ni, 97.0 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu1  :  1.3 us,  1.0 sy,  0.0 ni, 97.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem : 16266504 total,   324240 free,  6100720 used,  9841544 buff/cache
KiB Swap:        0 total,        0 free,        0 used.  9826652 avail Mem

以上是我们某台机器上的实时数据,因为当前运行正常,所以没有异常数据。但看一下下面的数据:

命令行显示了5个CPU,说明是一个5核的机器,平均每个CPU利用率在60%以上。有时可能存在CPU利用率达到100%,如果出现这种情况,那么很有可能是代码中写了死循环,继续看代码定位问题原因。

CPU参数的含义如下:

交互命令H,可以查看每个线程的性能信息:

PID USER      PR  NI    VIRT    RES    SHR S %CPU %MEM     TIME+ COMMAND                                                        
 5875 qkadmin   20   0  163144   3324   1612 R  1.0  0.0   0:00.24 top                                                            
 1498 root      20   0 3243684 665836  14684 S  0.3  4.1  39:27.18 java                                                           
27412 root      20   0 3243684 665836  14684 S  0.3  4.1  15:14.25 java                                                           
 4982 root      20   0 6715536 129904  13368 S  0.3  0.8 198:59.46 java                                                           
 8287 root      20   0 1003108 118728  18812 S  0.3  0.7 688:11.51 node /opt/my-ya                                                
10289 root      20   0 3089652 673520  15880 S  0.3  4.1  30:15.15 java                                                           
12261 root      20   0  803192  10800   4592 S  0.3  0.1  10:05.35 aliyun-service                                                 
12263 root      20   0  803192  10800   4592 S  0.3  0.1   5:45.73 aliyun-service                                                 
14351 root      20   0 2998424 556848  14548 S  0.3  3.4   1:14.78 java

可能发生的几个问题和对应的现象有:

1、某个线程,CPU利用率一直在100%左右,那么说明这个线程很有可能出现死循环,记住这个PID,并进一步定位具体应用;另外也可能是出现内存泄漏,触发频繁GC导致。这种情况,可以使用jstat命令查看GC情况,以分析是否持久代或老年代内存区域满导致触发Full GC,进而使CPU利用率飙高,命令和显示信息如下(81443是当前机器上观察的进程id):

jstat -gcutil 81443 1000 5

信息:

S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT     GCT   
  0.00  53.94  78.77   0.05  97.26  93.39      1    0.006     0    0.000    0.006
  0.00  53.94  78.77   0.05  97.26  93.39      1    0.006     0    0.000    0.006
  0.00  53.94  78.77   0.05  97.26  93.39      1    0.006     0    0.000    0.006
  0.00  53.94  78.77   0.05  97.26  93.39      1    0.006     0    0.000    0.006
  0.00  53.94  78.77   0.05  97.26  93.39      1    0.006     0    0.000    0.006

三 dump

下一步,可以把线程dump下来,然后再继续分析是哪个线程、执行到那段代码导致CPU利用率飙高。使用命令可以参考如下:

jstack 81443 > ./dump01

dump文件内容:

192:dubbo-proxy-tools xxx$ cat dump01 
2021-02-13 22:51:08
Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.212-b10 mixed mode):
"Attach Listener" #14 daemon prio=9 os_prio=31 tid=0x00007f8cef903000 nid=0x1527 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE
"DestroyJavaVM" #12 prio=5 os_prio=31 tid=0x00007f8cef91d000 nid=0x2803 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE
"JPS event loop" #10 prio=5 os_prio=31 tid=0x00007f8cf1153800 nid=0xa703 runnable [0x0000700003656000]
   java.lang.Thread.State: RUNNABLE
  at sun.nio.ch.KQueueArrayWrapper.kevent0(Native Method)
  at sun.nio.ch.KQueueArrayWrapper.poll(KQueueArrayWrapper.java:198)
  at sun.nio.ch.KQueueSelectorImpl.doSelect(KQueueSelectorImpl.java:117)
  at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
  - locked <0x00000007b5700798> (a io.netty.channel.nio.SelectedSelectionKeySet)
  - locked <0x00000007b57007b0> (a java.util.Collections$UnmodifiableSet)
  - locked <0x00000007b5700748> (a sun.nio.ch.KQueueSelectorImpl)
  at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
  at io.netty.channel.nio.SelectedSelectionKeySetSelector.select(SelectedSelectionKeySetSelector.java:62)
  at io.netty.channel.nio.NioEventLoop.select(NioEventLoop.java:753)
  at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:408)
  at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:897)
  at java.lang.Thread.run(Thread.java:748)
"Service Thread" #9 daemon prio=9 os_prio=31 tid=0x00007f8cf3822800 nid=0x5503 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE
"C1 CompilerThread3" #8 daemon prio=9 os_prio=31 tid=0x00007f8cf1802800 nid=0x3a03 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE
"C2 CompilerThread2" #7 daemon prio=9 os_prio=31 tid=0x00007f8cf480c000 nid=0x3c03 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

线程id (nid=0x2803) 是16进制,可与转成10进制,来跟top命令观察的id对应(可以简单地使用 printf "%x\n" 0x5503即可):

192:dubbo-proxy-tools xxxx$ printf "%x\n" 0x5503
5503

2、某个线程一直在top 10的位置,那么说明该线程可能有性能问题

3、CPU利用率高的线程不断变化,说明不是某一个线程导致的CPU利用率飙高

相关文章
|
存储 缓存 安全
Go语言内存模型深度解析
【2月更文挑战第16天】Go语言以其简洁的语法、强大的并发编程能力和高效的内存管理而备受开发者青睐。本文将对Go语言的内存模型进行深度解析,探讨其内存布局、内存分配与回收机制以及内存安全等方面的内容,帮助读者更好地理解和应用Go语言的内存管理特性。
|
算法
【MATLAB】 SSA奇异谱分析信号分解算法
【MATLAB】 SSA奇异谱分析信号分解算法
733 0
|
Web App开发 Cloud Native Docker
删除容器报错:Error response from daemon: conflict: unable to delete
云原生日益普及的现在,docker容器化成为现有很多服务的改进方向,docker凭借更高效的利用系统资源、更快速的启动时间、一致的运行环境、持续支付和部署、更轻松的迁移、更轻松的维护和拓展等优势,迅速走红。但是,很多容器部署后在回收时,都会遇到各种各样的问题,比如今天讨论的删除镜像的问题,有时候删除操作会莫名其妙的报错。
1018 1
|
算法 NoSQL IDE
C语言性能优化:代码优化技巧与工具。
C语言性能优化:代码优化技巧与工具。
|
9月前
|
存储 C语言 开发者
【C语言】格式化输出占位符及其标志字符详解(基于ISO/IEC 9899:2024)
在C语言中,格式化输出通过 `printf` 函数等格式化输出函数来实现。格式说明符(占位符)定义了数据的输出方式,标准ISO/IEC 9899:2024(C23)对这些格式说明符进行了详细规定。本文将详细讲解格式说明符的组成部分,包括标志字符、宽度、精度、长度修饰符和类型字符,并适当增加表格说明。
430 6
|
11月前
|
缓存 NoSQL 数据处理
原生php实现redis缓存配置和使用方法
通过上述步骤,你可以在PHP项目中配置并使用Redis作为高性能的缓存解决方案。合理利用Redis的各种数据结构和特性,可以有效提升应用的响应速度和数据处理效率。记得在实际应用中根据具体需求选择合适的缓存策略,如设置合理的过期时间,以避免内存过度消耗。
243 0
|
人工智能 运维 数据安全/隐私保护
【阿里天池赛题】2021年赛道一:医学影像报告异常检测
本文介绍了2021年阿里天池全球人工智能技术创新大赛的医学影像报告异常检测赛题,包括赛题背景、数据说明、评估标准和比赛规则。
208 8
|
12月前
|
JavaScript 前端开发
js登录注册简单tab切换页面(含前台表单验证)
文章介绍了如何使用HTML、CSS和JavaScript创建一个简单的登录注册页面,并实现Tab切换效果。包括了表单验证,点击登录或注册按钮时,可以切换显示相应的表单。同时提供了完整的前端代码和实现效果图。
|
存储 人工智能 数据库
RAG流程优化(微调)的4个基本策略
在本文中,我们将介绍使用私有数据优化检索增强生成(RAG)的四种策略,可以提升生成任务的质量和准确性。通过使用一些优化策略,可以有效提升检索增强生成系统的性能和输出质量,使其在实际应用中能够更好地满足需求。
357 0
|
人工智能 弹性计算 监控
【阿里云云原生专栏】阿里云云原生与AI结合:智能应用的快速构建与部署
【5月更文挑战第24天】阿里云融合云原生和AI技术,助力快速构建智能应用。弹性伸缩、CI/CD、微服务和自动化运维带来优势。通过需求分析、环境准备、数据处理、模型开发到服务部署,阿里云提供容器服务、函数计算、服务网格等工具,支持自动化测试和监控,实现一站式智能应用开发。示例代码展示创建ACK集群和部署AI模型服务过程。
954 1