java 单点定位 java如何定位线上问题

概述

Java语言是当前互联网应用最为广泛的语言，作为一名Java程序员，当业务相对比较稳定之后平常工作除了coding之外，大部分时间（70%-80%）是会用来排查突发或者周期性的线上问题。
排查线上问题是具有一定技巧或者说是经验规律的，排查者如果对业务系统了解的越深入，那么相对来说定位也会容易一些。
不管怎么说，掌握Java服务线上问题排查思路并能够熟练排查问题常用工具/命令/平台是每一个Java程序员进阶必须掌握的实战技能。

整体思路

如果能直接猜测出问题，进行确认修改。
如果猜测不出来，按照业务流层层定位，锁定问题位置，猜测，验证。

需要快速解决的问题

非快速解决的问题

可以参考下面的方式定位。

根据现象直接猜测问题

这种一般都是比较简单的问题定位，直接根据现象猜测问题出在哪里，直接看日志、或者按照猜测的原因直接修改，如果修改后成功问题解决。

无法直接看出原因的问题

这类问题一般都比较麻烦，需要按部就班的定位。
从数据流的入口处，一层一层的定位，先找到问题出现在哪个环节。
找到问题出现的位置后，猜测原因，进行验证。

报文捕获

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使用率最高的进程，正常情况下就是我们的应用主进程。第七行以下：个进程的状态监控。

• PID：进程id。
• USER：进程所有者。
• PR：进程优先级。
• NI：nice值。负值表示高优先级，正值表示低优先级。
• VIRT：进程使用的虚拟内存总量，单位kb。VIRT=SWAP+RES
• RES：进程使用的、未被换出的物理内存大小，单位kb。RES=CODE+DATA
• SHR：共享内存大小，单位kb。
• S：进程状态。D=不可中断的睡眠状态，R=运行，S=睡眠，T=跟踪/停止，Z=僵尸进程。
• %CPU：上次更新到现在的CPU时间占用百分比。
• %MEM：进程使用的物理内存百分比
• TIME+：进程使用的CPU时间总计，单位1/100秒。
• COMMAND：进程名称。

内存

内存是排查线上问题的重要参考依据，内存问题很多时候是引起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目录下默认提供了很多有价值的命令行工具。每个小工具体积基本都比较小，因为这些工具只是jdk\lib\tools.jar的简单封装。

其中，定位排查问题时最为常用的命令包括：jstack（线程）、jstat（gc信息）、jps（进程）、jmap（内存）、jinfo（参数）等。

• jps：查询当前机器的所有java进程信息。
• jmap：输出某个java进程内存情况（如：产生哪些对象及数量等）。
• jstack：打印某个java线程的线程栈信息。
• jinfo：用于查看jvm的配置参数。

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进程的内存分配与使用情况，使用的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 文件备份至制定位置或者直接删除，以释放磁盘在这块的空间占用。

jstack命令

某Java进程CPU占用率高，我们想要定位到其中CPU占用率最高的线程。

1. 利用top命令可以查出占CPU最高的线程pid。

top -Hp {pid}

2. 占用率最高的线程ID为6900，将其转换为16进制形式（因为java native 线程以16进制形式输出）

[root@localhost ~]# printf '%x\n' 6900
1af4
[root@localhost ~]#

3. 利用jstack打印出java线程调用栈信息

jstack 6418|grep '0x1af4' -A 50 --color

4. jinfo命令

查看某个Jvm参数值
jinfo -flag ReservedCodeCacheSize 28461
jinfo -flag MaxPermSize 28461

5. jstat命令

jstat -gc pid
jstat -gcutil pid

内存分析工具

MAT

MAT(Memory Analyzer Tool)，一个基于 Eclipse 的内存分析工具，是一个快速、功能丰富的 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 位数

互联网应用目前几乎采用分布式架构，但不限于服务框架、消息中间件、分布式缓存、分布式存储等等。

那么这些应用日志如何聚合起来进行分析呢 ?

首先，你需要一套分布式链路调用跟踪系统，通过在系统线程上线文间透传 traceId 和 rpcId，将所有日志进行聚合，例如淘宝的鹰眼，spring cloud zipkin 等等。

案例分析

CPU使用率高问题定位

• 按照定位流程首先排除了系统层面的问题。
• 利用 top -Hp 6814 输出进程 ID 为 6814 的所有线程 CPU 使用率情况，发现某个线程使用率比较高，有些异常。

printf '%x\n' 2304     #输出线程 ID 的 16 进制
jstack pid | grep '0x900' -C 30 --color

输出的日志表明该线程一直处于与 mysql I/O 状态：

• 利用 jmap -dump:format=b,file=/usr/local/logs/gc/dump.hprof {pid} 以二进制输出档当前内存的堆情况，然后可以导入 MAT 等工具进行分析。
  如下图所示，点击 MAT 的支配树可以发现存在某个超大对象数组，实例对象数目多大 30 多万个。
  
  经过分析发现数组中每一个对象都是核心业务对象，我们的业务系统有一个定时任务线程会访问数据库某张业务表的所有记录。
  然后加载至内存然后进行处理因此内存吃紧，导致 CPU 突然飙升。发现该问题后，已对该方案进行重新设计。