服务器运行情况及线上排查问题常用命令_服务端线上排查日志常见命令

部分内容来自转载，转载地址：https://blog.51cto.com/u_16213694/7153728

一、top命令

top
1

1.1 输出说明

输出可以分为以下两部分

1.1.1 系统概览

以下是几个需要注意的参数

• load average
  系统负载，即任务队列的平均长度。三个数值分别为 1分钟、5分钟、15分钟前到现在的平均值。
  这里具体需要关注的还是load average三个数值。先来说说定义吧：在一段时间内，CPU正在处理以及等待CPU处理的进程数之和。三个数字分别代表了1分钟，5分钟，15分钟的统计值，这个数值的确能反应服务器的负载情况。但是，这个数值高了也并不能直接代表这台机器的性能有问题，可能是因为正在进行CPU密集型的计算，也有可能是因为I/O问题导致运行队列堵了。所以，当我们看到这个数值飙升的时候，还得具体问题具体分析。
  大家都知道，一个CPU在一个时间片里面只能运行一个进程，CPU核数的多少直接影响到这台机器在同时间能运行的进程数。所以一般来说Load Average的数值别超过这台机器的总核数，就基本没啥问题。
  CPU 100% 不是坏事，说明程序写的好把资源都利用上了，但是负载排上 10 肯定浑身难受，说明你的任务积压处理不动了。
• swap.used
  内存信息和swap信息，所有程序的运行都是在内存中进行的，所以内存的性能对与服务器来说非常重要。不过当内存的free变少的时候，其实我们并不需要太紧张。真正需要看的是Swap中的used信息。
  Swap分区是由硬盘提供的交换区，当物理内存不够用的时候，操作系统才会把暂时不用的数据放到Swap中。所以当这个数值变高的时候，说明内存是真的不够用了。
• cpu
  cpu利用率的计算公式

CPU％= 1 - idleTime / sysTime * 100
idleTime：CPU空闲的时间
sysTime：CPU处于用户态和内核态的时间总和
1
2
3

1.1.2 进程详情

以下是几个奇怪名称的含义：
NI nice值，负值表示高优先级，正值表示低优先级
VIRT 进程使用的虚拟内存总量，单位kb。VIRT=SWAP+RES
RES 进程使用的、未被换出的物理内存大小，单位kb。RES=CODE+DATA
SHR 共享内存大小，单位kb
S 进程状态。D=不可中断的睡眠状态 R=运行 S=睡眠 T=跟踪/停止 Z=僵尸进程
TIME+ 进程使用的CPU时间总计，单位1/100秒
COMMAND 命令名/命令行

1.2 常用参数

1.2.1 进程资源占用情况

top -p 28820 -p 38830   #每隔3秒显示pid是28820和pid是38830的两个进程的资源占用情况
1

1.2.2 查看进程下所有线程

top -Hp 31951 以线程模式查看下进程31951的所有线程情况
1

• 输出
  
  pid是线程id。假设想看下第二个线程31998的情况，31998是操作系统的线程ID，先转成16进制，值为7cfe。
  获取该线程的信息(匹配7cf3后取20行差不多)

jstack 31951 | grep 7cfe -A 20
1

二、arthas工具

官网 https://arthas.aliyun.com/doc/

2.1 常用命令

• 启动arthas

java -jar arthas-boot.jar
1

• 查看某一方法实时调用 参数及返回

watch cn.chendd.blog.admin.blog.tag.controller.TagManageController queryTagsPage
1

• 线程总览

dashboard
1

• 打印栈，会打印线程 ID 1 的栈

thread 1
1

• 查看线上代码，通过 jad 来反编译 Class

jad demo.MathGame
1

• 替换运行的类

retransform /tmp/Test.class
1

三、jstack命令

jstack用于生成java虚拟机当前时刻的线程快照。线程快照是当前java虚拟机内每一条线程正在执行的方法堆栈的集合，生成线程快照的主要目的是定位线程出现长时间停顿的原因，如线程间死锁、死循环、请求外部资源导致的长时间等待等。 线程出现停顿的时候通过jstack来查看各个线程的调用堆栈。

jstack [ option ] pid
1

3.1 输出解读

参考https://blog.csdn.net/iteye_5603/article/details/82652200

3.1.1 关键字

locked <地址> 目标：使用synchronized申请对象锁成功,监视器的拥有者。

Blocked：线程阻塞
Waiting for monitor entry：该线程获取锁时发现锁已被持有，进入 "Entry Set"中等待
Waiting on monitor entry：该线程获取锁时发现锁已被持有，进入 "Entry Set"中等待
waiting to lock <地址> 目标：使用synchronized申请对象锁未成功,在冲入区等待。 即是 Entry Set
parking to wait for <地址> 目标

in Object.wait()：获取锁后又执行obj.wait()放弃锁，在 "Wait Set"中等待的线程
Waiting on condition：等待某个资源或条件发生来唤醒自己。具体需要结合jstacktrace来分析，比如线程正在sleep，网络读写繁忙而等待
waiting on <地址> 目标：使用synchronized申请对象锁成功后,释放锁（object.wait）并在等待区等待。即是 Wait Set

Deadlock：表示有死锁
1
2
3
4
5
6
7
8
9
10
11
12
13

3.1.2 几种线程资源堵塞的情况

• 进入队列阻塞
  线程状态BLOCKED,线程动作wait on monitor entry（第一行）,调用修饰waiting to lock总是一起出现。表示在代码级别已经存在冲突的调用。

"d&a-3588" daemon waiting for monitor entry [0x000000006e5d5000]  
java.lang.Thread.State: BLOCKED (on object monitor)
at com.jiuqi.dna.bap.authority.service.UserService$LoginHandler.handle()
- waiting to lock <0x0000000602f38e90> (a java.lang.Object)
at com.jiuqi.dna.bap.authority.service.UserService$LoginHandler.handle()
1
2
3
4
5

• 同步块阻塞

"blocker" runnable
java.lang.Thread.State: RUNNABLE
at com.jiuqi.hcl.javadump.Blocker$1.run(Blocker.java:23)
- locked <0x00000000eb8eff68> (a java.lang.Object)
"blockee-11" waiting for monitor entry
java.lang.Thread.State: BLOCKED (on object monitor)
at com.jiuqi.hcl.javadump.Blocker$2.run(Blocker.java:41)
- waiting to lock <0x00000000eb8eff68> (a java.lang.Object)
"blockee-86" waiting for monitor entry
java.lang.Thread.State: BLOCKED (on object monitor)
at com.jiuqi.hcl.javadump.Blocker$2.run(Blocker.java:41)
- waiting to lock <0x00000000eb8eff68> (a java.lang.Object)
1
2
3
4
5
6
7
8
9
10
11
12

• 持续运行的IO
  IO操作是可以以RUNNABLE状态达成阻塞。例如:数据库死锁、网络读写。 格外注意对IO线程的真实状态的分析。 一般来说,被捕捉到RUNNABLE的IO调用,都是有问题的。
  以下堆栈显示： 线程状态为RUNNABLE。 调用栈在SocketInputStream或SocketImpl上,socketRead0等方法。 调用栈包含了jdbc相关的包。很可能发生了数据库死锁。

"d&a-614" daemon prio=6 tid=0x0000000022f1f000 nid=0x37c8 runnable
[0x0000000027cbd000]
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(Unknown Source)
at oracle.net.ns.Packet.receive(Packet.java:240)
at oracle.net.ns.DataPacket.receive(DataPacket.java:92)
at oracle.net.ns.NetInputStream.getNextPacket(NetInputStream.java:172)
at oracle.net.ns.NetInputStream.read(NetInputStream.java:117)
at oracle.jdbc.driver.T4CMAREngine.unmarshalUB1(T4CMAREngine.java:1034)
at oracle.jdbc.driver.T4C8Oall.receive(T4C8Oall.java:588)
1
2
3
4
5
6
7
8
9
10
11

3.1.3 其它常见情况

• 线程sleep

"redisson-timer-6-1" #68 prio=5 os_prio=0 tid=0x0000fffe90109800 nid=0x16c waiting on condition [0x0000fffeb60bd000]
   java.lang.Thread.State: TIMED_WAITING (sleeping)
	at java.lang.Thread.sleep(Native Method)
	at io.netty.util.HashedWheelTimer$Worker.waitForNextTick(HashedWheelTimer.java:569)
	at io.netty.util.HashedWheelTimer$Worker.run(HashedWheelTimer.java:465)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.lang.Thread.run(Thread.java:750)
1
2
3
4
5
6
7

• 线程不在cpu时间片内，从running回到runnable状态

"Apollo-RemoteConfigLongPollService-1" #17 daemon prio=5 os_prio=0 tid=0x0000ffff8d1f0000 nid=0x137 runnable [0x0000ffff6d53a000]
   java.lang.Thread.State: RUNNABLE
	at java.net.SocketInputStream.socketRead0(Native Method)
	at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
	at java.net.SocketInputStream.read(SocketInputStream.java:171)
	at java.net.SocketInputStream.read(SocketInputStream.java:141)
	at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
	at java.io.BufferedInputStream.read1(BufferedInputStream.java:286)
	at java.io.BufferedInputStream.read(BufferedInputStream.java:345)
	- locked <0x00000000e21030c0> (a java.io.BufferedInputStream)
	at sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:743)
	at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:678)
	at sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1595)
	- locked <0x00000000e2103118> (a sun.net.www.protocol.http.HttpURLConnection)
	at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1500)
	- locked <0x00000000e2103118> (a sun.net.www.protocol.http.HttpURLConnection)
	at java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:480)
	at com.ctrip.framework.apollo.util.http.HttpUtil.doGetWithSerializeFunction(HttpUtil.java:104)
	at com.ctrip.framework.apollo.util.http.HttpUtil.doGet(HttpUtil.java:69)
	at com.ctrip.framework.apollo.internals.RemoteConfigLongPollService.doLongPollingRefresh(RemoteConfigLongPollService.java:179)
	at com.ctrip.framework.apollo.internals.RemoteConfigLongPollService.access$100(RemoteConfigLongPollService.java:49)
	at com.ctrip.framework.apollo.internals.RemoteConfigLongPollService$2.run(RemoteConfigLongPollService.java:128)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	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:750)
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27

3.2 参数

-F 当’jstack [-l] pid’没有响应的时候强制打印栈信息
-l 长列表. 打印关于锁的附加信息,例如属于java.util.concurrent的ownable synchronizers列表.
-m 打印java和native c/c++框架的所有栈信息. 
-h | -help打印帮助信息
pid 需要被打印配置信息的java进程id,可以用jps工具查询
1
2
3
4
5

3.3 说明

1. 不同的 JAVA虚机的线程 DUMP的创建方法和文件格式是不一样的，不同的 JVM版本， dump信息也有差别。
2. 在实际运行中，往往一次 dump的信息，还不足以确认问题。建议产生三次 dump信息，如果每次 dump都指向同一个问题，我们才确定问题的典型性。

四、jmap

功能：jmap是JDK自带的工具软件，主要用于打印指定Java进程(或核心文件、远程调试服务器)的共享对象内存映射或堆内存细节。可以使用jmap生成Heap Dump，堆Dump是反应Java堆使用情况的内存镜像，其中主要包括系统信息、虚拟机属性、完整的线程Dump、所有类和对象的状态等。 一般，在内存不足、GC异常等情况下，我们就会怀疑有内存泄露。这个时候我们就可以制作堆Dump来查看具体情况。

jmap [option] [server_id@]
1

<no option> 如果使用不带选项参数的jmap打印共享对象映射，将会打印目标虚拟机中加载的每个共享对象的起始地址、映射大小以及共享对象文件的路径全称。这与Solaris的pmap工具比较相似。
-dump:[live,]format=b,file=<filename> 以hprof二进制格式转储Java堆到指定filename的文件中。live子选项是可选的。如果指定了live子选项，堆中只有活动的对象会被转储。想要浏览heap dump，你可以使用jhat(Java堆分析工具)读取生成的文件。
-finalizerinfo 打印等待终结的对象信息。
-heap 打印一个堆的摘要信息，包括使用的GC算法、堆配置信息和generation wise heap usage。
-histo[:live] 打印堆的柱状图。其中包括每个Java类、对象数量、内存大小(单位：字节)、完全限定的类名。打印的虚拟机内部的类名称将会带有一个’*’前缀。如果指定了live子选项，则只计算活动的对象。
-permstat 打印Java堆内存的永久保存区域的类加载器的智能统计信息。对于每个类加载器而言，它的名称、活跃度、地址、父类加载器、它所加载的类的数量和大小都会被打印。此外，包含的字符串数量和大小也会被打印.
-F 强制模式。如果指定的pid没有响应，请使用jmap -dump或jmap -histo选项。此模式下，不支持live子选项。
-h 打印帮助信息。
-help 打印帮助信息。
-J<flag> 指定传递给运行jmap的JVM的参数。
-heap 打印一个堆的摘要信息 包括使用的GC算法、堆配置信息和generation wise heap usage。
1
2
3
4
5
6
7
8
9
10
11

C:\Users\Think>jmap -heap 10444
Attaching to process ID 10444, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.91-b14

using thread-local object allocation.
Parallel GC with 8 thread(s)

Heap Configuration:
   MinHeapFreeRatio         = 0 /对应jvm启动参数-XX:MinHeapFreeRatio设置JVM堆最小空闲比率(default 40)
   MaxHeapFreeRatio         = 100 对应jvm启动参数 -XX:MaxHeapFreeRatio设置JVM堆最大空闲比率(default 70)
   MaxHeapSize              = 1258291200 (1200.0MB) //对应jvm启动参数-XX:MaxHeapSize=设置JVM堆的最大大小
   NewSize                  = 13631488 (13.0MB)/对应jvm启动参数-XX:NewSize=设置JVM堆的‘新生代’的默认大小
   MaxNewSize               = 419430400 (400.0MB)  /对应jvm启动参数-XX:MaxNewSize=设置JVM堆的‘新生代’的最大大小
   OldSize                  = 28311552 (27.0MB) //对应jvm启动参数-XX:OldSize=<value>:设置JVM堆的‘老生代’的大小
   NewRatio                 = 2
   SurvivorRatio            = 8
   MetaspaceSize            = 21807104 (20.796875MB)
    //对应jvm启动参数-XX:PermSize=<value>:设置JVM堆的‘永生代’的初始大小，jdk1.8变成了元空间
   CompressedClassSpaceSize = 1073741824 (1024.0MB)
   MaxMetaspaceSize         = 17592186044415 MB
   G1HeapRegionSize         = 0 (0.0MB)

Heap Usage:
PS Young Generation
Eden Space:
   capacity = 177209344 (169.0MB)
   used     = 129068368 (123.08918762207031MB)
   free     = 48140976 (45.91081237792969MB)
   72.83383882962741% used
From Space:
   capacity = 52428800 (50.0MB)
   used     = 35522768 (33.87715148925781MB)
   free     = 16906032 (16.122848510742188MB)
   67.75430297851562% used
To Space:
   capacity = 54001664 (51.5MB)
   used     = 0 (0.0MB)
   free     = 54001664 (51.5MB)
   0.0% used
PS Old Generation
   capacity = 224395264 (214.0MB)
   used     = 141988944 (135.4112091064453MB)
   free     = 82406320 (78.58879089355469MB)
   63.27626593759127% used

90919 interned Strings occupying 16817872 bytes.

C:\Users\Think>
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50

查看堆内存(histogram)中的对象数量及大小，应该配合过滤条件，找出占字节空间比较大的一些元素

num     #instances         #bytes  class name
编号     个数                字节     类名
----------------------------------------------
   1:             7        1322080  [I
   2:          5603         722368  <methodKlass>
   3:          5603         641944  <constMethodKlass>
   4:         34022         544352  java.lang.Integer
   5:           371         437208  <constantPoolKlass>
   6:           336         270624  <constantPoolCacheKlass>
   7:           371         253816  <instanceKlassKlass>
   后面省略
1
2
3
4
5
6
7
8
9
10
11

jmap -histo:live
1

这个命令执行，JVM会先触发gc，然后再统计信息。

输出内存使用情况到文件中，将内存使用的详细情况输出到文件，执行命令：

jmap -dump:format=b,file=heapDump 6900
1

然后用jhat命令可以查看dump详情，

jhat -port 5000 heapDump
1

在浏览器中访问：http://localhost:5000/ 查看详细信息

总结
1.如果程序内存不足或者频繁GC，很有可能存在内存泄露情况，这时候就要借助Java堆Dump查看对象的情况。
2.要制作堆Dump可以直接使用jvm自带的jmap命令
3.可以先使用jmap -heap命令查看堆的使用情况，看一下各个堆空间的占用情况。
4.使用jmap -histo:[live]查看堆内存中的对象的情况。如果有大量对象在持续被引用，并没有被释放掉，那就产生了内存泄露，就要结合代码，把不用的对象释放掉。
5.也可以使用 jmap -dump:format=b,file=命令将堆信息保存到一个文件中，再借助jhat命令查看详细内容
6.在内存出现泄露、溢出或者其它前提条件下，建议多dump几次内存，把内存文件进行编号归档，便于后续内存整理分析。

五、jvisualvm

六、jps

jps
1

jps(Java Virtual Machine Process Status Tool)是JDK 自带的一个显示当前所有java进程pid的命令，简单实用，非常适合在linux/unix平台上简单察看当前java进程的一些简单情况。

七、