概述
java语言是当前互联网应用最为广泛的语言,作为一名Java程序员,当业务相对比较稳定以后平时工作不仅coding之外,大部分时间(70%-80%)是会拿来排查突发或则周期性的线上问题。
排查线上问题是具有一定方法或则说是经验规律的,排查者假如对业务系统了解的越深入,那么相对来说定位也会容易一些。
不管怎么说,掌握Java服务线上问题排查思路并才能熟练排查问题常用工具/命令/平台是每一个Java程序员进阶必须把握的实战技能。
整体思路
如果能直接推测出问题,进行确认更改。
如果推测不下来,按照业务流层层定位,锁定问题位置,猜测,验证。
需要快速解决的问题
如果不能很快找到问题缘由,操作步骤如下。
1、打印堆栈,保留日志。
2、重启。
Java 进程资源使用率较高问题定位
JVM相关命令查看GC情况
非快速解决的问题
可以参考下边的形式定位。
根据现象直接猜想问题
这种通常都是比较简单的问题定位,直接按照现象推测问题出在那里,直接看日志、或者根据猜想的诱因直接更改,如果更改后成功问题解决。
无法直接看出缘由的问题
这类问题通常都比较麻烦,需要按部就班的定位。
从数据流的入口处,一层一层的定位,先找到问题出现在那个环节。
找到问题出现的位置后linux压缩命令,猜测缘由,进行验证。
报文捕获
Linux服务器下抓包剖析
捕获数据包(Wireshark)
Java服务常见线上问题
从现象来看,主要是两类问题,系统异常,业务异常。
系统异常一般包括:CPU、内存、磁盘、网络等。
业务异常,比如某个业务执行结果与期望不一致,或者边界bug等。
系统异常
常见的系统异常现象包括:CPU占用率过高、CPU上下文切换频率次数较高、磁盘满了、磁盘I/O过于频繁、网络流量异常(连接数过多)、系统可用内存长期处于较低值(导致OOM Killer)等。
这些问题可用通过top(cpu)、free(内存)、df(磁盘)、dstat(网络流量)、pstack、vmstat、strace(底层系统调用)等工具获取系统异常现象数据。
此外,如果对系统以及应用进行排查后,均未发觉异常现象,那么也有可能是外部基础设施如IAAS平台本身引起的问题。
业务服务异常
常见的业务服务异常现象包括:PV量过低、服务调用历时异常、线程死锁、多线程并发问题、频繁进行Full GC、异常安全功击扫描等。
问题定位
如果能直接猜想出问题,进行确认更改。
如果猜想不下来,按照业务流层层定位,锁定问题位置,猜测,验证,其实这个就是排除法,从外部排查到内部排查的方法来定位线上服务问题。按照数据流程从外到内层层排除,最终锁定问题位置。
定位流程系统异常排查流程系统异常排查流程
业务应用排查流程
linux常用的性能剖析工具
Linux常用的性能剖析工具使用包括:top、free、df、dstat(网络流量)、pstack、vmstat、strace(底层系统调用)等。
CPU
cpu是系统重要的监控指标,能够剖析系统的整体运行状况。监控指标通常包括运行队列、CPU使用率和上下文切换等。
top命令式Linux下常用的CPU性能剖析工具,能够实时显示系统中各个进程的资源占用状况,常用于服务端性能剖析。
top命令显示了各个进程CPU使用情况,一般CPU使用率从高到低排序展示输出。其中Load Average显示最近1分钟、5分钟、15分钟的系统平均负载,上图各值为2.46,1.96,1.99。
我们通常会关注CPU使用率最高的进程,正常情况下就是我们的应用主进程。第七行以下:个进程的状态监控。
内存
内存是排查线上问题的重要参考根据,内存问题好多时侯是导致CPU使用率较高的间接诱因。
系统显存:free是显示的当前显存的使用,-m的意思是M字节来显示显存。
部分参数说明:
total:内存总数:3790M
used:依据使用的内存数:1880M
free:空闲的内存数:188M
shared:当前基本废弃不用,总数0
buff/cache:缓存内存数:1792M
磁盘
df -h
网络
dstat命令可以集成vmstat、iostat、netstat等等工具才能完成的任务。
dstat -c cpu情况
dstat -d 磁盘读写情况
dstat -n 网络情况
dstat -l 显示系统负载
dstat -m 显示形同内存状况
dstat -p 显示系统进程信息
dstat -r 显示系统IO情况
[root@localhost ~]# dstat -c
----total-usage----
usr sys idl wai stl
0 0 100 0 0
0 0 99 0 0
0 0 100 0 0
0 0 100 0 0^C
[root@localhost ~]# dstat -d
-dsk/total-
read writ
0 0
0 0
0 0 ^C
[root@localhost ~]# dstat -l
---load-avg---
1m 5m 15m
0 0 0
0 0 0
0 0 0^C
[root@localhost ~]# dstat -m
------memory-usage-----
used free buf cach
691M 167M 2296k 653M
691M 167M 2296k 653M
691M 167M 2296k 653M
691M 167M 2296k 653M
691M 167M 2296k 653M
691M 167M 2296k 653M
691M 167M 2296k 653M^C
[root@localhost ~]# dstat -p
---procs---
run blk new
0 0
0 0 0
0 0 0
0 0 0
0 0 0^C
[root@localhost ~]# dstat -r
--io/total-
read writ
0 0
0 0
0 0 ^C
[root@localhost ~]# dstat
You did not select any stats, using -cdngy by default.
----total-usage---- -dsk/total- -net/total- ---paging-- ---system--
usr sys idl wai stl| read writ| recv send| in out | int csw
0 0 100 0 0| 0 0 | 66B 194B| 0 0 | 34 51
0 0 100 0 0| 0 0 | 66B 162B| 0 0 | 36 57
0 0 100 0 0| 0 0 | 66B 130B| 0 0 | 38 63
0 0 100 0 0| 0 0 | 66B 130B| 0 0 | 37 56
0 0 100 0 0| 0 0 | 66B 130B| 0 0 | 36 67
0 0 100 0 0| 0 0 | 67B 132B| 0 0 | 38 65
0 0 100 0 0| 0 0 | 66B 130B| 0 0 | 39 65
0 0 100 0 0| 0 0 | 66B 130B| 0 0 | 49 87 ^X
0 0 100 0 0| 0 0 | 245B 243B| 0 0 | 38 63
0 0 100 0 0| 0 0 | 66B 130B| 0 0 | 35 61
0 0 100 0 0| 0 0 | 66B 130B| 0 0 | 38 65
0 0 100 0 0| 0 0 | 67B 132B| 0 0 | 34 53 ^C
[root@localhost ~]#
JVM定位问题工具
在JDK安装目录的bin目录下默认提供了好多有价值的命令行工具。每个小工具容积基本都比较小,因为这种工具只是jdklibtools.jar的简单封装。
其中,定位排查问题时最为常用的命令包括:jstack(线程)、jstat(gc信息)、jps(进程)、jmap(内存)、jinfo(参数)等。
jps命令
jps 用于输出当前用户启动的所有进程 ID,当线上发觉故障或则问题时,能够借助 jps 快速定位对应的 Java 进程 ID。
jps -l -m
# -m,-l 参数用于输出主启动类的完整路径。
当然,我们也可以使用 Linux 提供的查询进程状态命令,例如:
ps -ef | grep tomcat
我们也能快速获取 tomcat 服务的进程 id。
jmap命令
jmap -heap pid 输出当前进程 JVM 堆新生代、老年代、持久代等请情况,GC 使用的算法等信息
jmap -histo:live {pid} | head -n 10 输出当前进程内存中所有对象包含的大小
jmap -dump:format=b,file=/usr/local/logs/gc/dump.hprof {pid} 以二进制输出档当前内存的堆情况,然后可以导入 MAT 等工具进行
jmap(java memory map)可以输出所有显存中对象的工具,甚至可以将VM中的heap以二进制输出成文本。
jmap -heap pid
输出当前进程JVM堆的新生代、老年代、持久代等情况,GC使用的算法等信息。
jmap可以查看JVM进程的显存分配与使用情况linux查看cpu使用率高,使用的GC算法等信息。
jmap -histo:live {pid} | head -n 10 输出当前进程内存中所有对象包含的大小
输出当前进程显存中所有对象实例数 (instances) 和大小 (bytes), 如果某个业务对象实例数和大小存在异常情况,可能存在内存泄露或则业务设计方面存在不合理之处。
jmap -dump:
jmap -dump:format=b,file=/usr/local/logs/gc/dump.hprof {pid}
-dump:formate=b,file= 以二进制输出当前显存的堆情况至相应的文件,然后可以结合 MAT 等显存剖析工具深入剖析当前显存情况。
一般我们要求给 JVM 添加参数 -XX:+Heap Dump On Out Of Memory Error OOM 确保应用发生 OOM 时 JVM 能够保存并 dump 出当前的显存镜像。
当然,如果你决定自动 dump 内存时,dump 操作抢占一定 CPU 时间片、内存资源、磁盘资源等,因此会带来一定的负面影响。
此外,dump 的文件可能比较大 , 一般我们可以考虑使用 zip 命令对文件进行压缩处理,这样在下载文件时能减小带宽的开支。
下载 dump 文件完成以后,由于 dump 文件较大可将 dump 文件备份至制订位置或则直接删掉,以释放c盘在这块的空间占用。
jstack命令
某Java进程CPU占用率高,我们想要定位到其中CPU占用率最高的线程。
利用top命令可以查出占CPU最高的线程pid。
top -Hp {pid}
占用率最高的线程ID为6900,将其转换为16进制方式(因为java native 线程以16进制方式输出)
[root@localhost ~]# printf '%xn' 6900
1af4
[root@localhost ~]#
利用jstack复印出java线程调用栈信息
jstack 6418|grep '0x1af4' -A 50 --color
jinfo命令
查看某个Jvm参数值
jinfo -flag ReservedCodeCacheSize 28461
jinfo -flag MaxPermSize 28461
jstat命令
jstat -gc pid
jstat -gcutil pid
内存剖析工具MAT
MAT(Memory Analyzer Tool),一个基于 Eclipse 的显存剖析工具linux查看cpu使用率高,是一个快速、功能丰富的 JAVA heap 分析工具,它可以帮助我们查找内存泄漏和降低显存消耗。
使用显存剖析工具从众多的对象中进行剖析,快速的估算出在显存中对象的占用大小,看看是谁制止了垃圾收集器的回收工作,并可以通过报表直观的查看到可能导致这些结果的对象。
右侧的饼图显示当前快照中最大的对象。单击工具栏上的柱状图,可以查看当前堆的类信息,包括类的对象数目、浅堆 (Shallow heap)、深堆 (Retained Heap).
浅堆表示一个对象结构所占用显存的大小。深堆表示一个对象被回收后,可以真实释放的显存大小。
1)支配树 (The Dominator Tree)
列出了堆中最大的对象,第二层级的节点表示当被第一层级的节点所引用到的对象,当第一层级对象被回收时,这些对象也将被回收。
这个工具可以帮助我们定位对象间的引用情况,垃圾回收时侯的引用依赖关系
2)Path to GC Roots
被 JVM 持有的对象,如当前运行的线程对象,被 systemclass loader 加载的对象被称为 GC Roots, 从一个对象到 GC Roots 的引用链被称为 Path to GC Roots。
通过剖析 Path to GC Roots 可以找出 JAVA 的显存泄漏问题,当程序不在访问该对象时仍存在到该对象的引用路径。
GC日志剖析
Java 虚拟机 GC 日志是用于定位问题重要的日志信息,频繁的 GC 将造成应用吞吐量增长、响应时间降低,甚至造成服务不可用。
-XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:/usr/local/gc/gc.log -XX:+UseConcMarkSweepGC
我们可以在 java 应用的启动参数中降低 -XX:+PrintGCDetails 可以输出 GC 的详尽日志,例外还可以降低其他的辅助参数,如-Xloggc 制定 GC 日志文件地址。如果你的应用还没有开启该参数 , 下次重启时请加入该参数。
业务日志
业务日志不仅关注系统异常与业务异常之外,还要关注服务执行历时情况,耗时过长的服务调用假如没有熔断等机制,很容易造成应用性能增长或服务不可用,服务不可用很容易引起雪崩。
上面是某一插口的调用情况,虽然大部分调用没有发生异常,但是执行历时相对比较长。
grep ‘[0-9]{3,}ms’ *.log
找出调用耗时大于 3 位数的 dao 方法,把 3 改成 4 就是大于 4 位数
互联网应用目前几乎采用分布式构架,但不限于服务框架、消息中间件、分布式缓存、分布式存储等等。
那么那些应用日志怎么聚合上去进行剖析呢 ?
首先,你须要一套分布式链路调用跟踪系统linux系统,通过在系统线程上线文间透传 traceId 和 rpcId,将所有日志进行聚合,例如网店的鹰眼,spring cloud zipkin 等等。
案例剖析
CPU使用率高问题定位
printf '%xn' 2304 #输出线程 ID 的 16 进制
jstack pid | grep '0x900' -C 30 --color
输出的日志表明该线程仍然处于与 mysql I/O 状态:
参考
Java 线上问题排查思路与工具使用
文章评论