诊断工具
1. jps
JVM Process Status Tool,显示指定系统内所有的HotSpot虚拟机进程。option参数如下:
- -l : 输出主类全名或jar路径
- -q : 只输出LVMID
- -m : 输出JVM启动时传递给main()的参数
- -v : 输出JVM启动时显示指定的JVM参数 eg: jps -l -m
2. jstat
jstat(JVM statistics Monitoring)是用于监视虚拟机运行时状态信息的命令,它可以显示出虚拟机进程中的类装载、内存、垃圾收集、JIT编译等运行数据。 -class 监视类装载、卸载数量、总空间以及耗费的时间
# jstat -class 7064
Loaded Bytes Unloaded Bytes Time
9743 19960.8 0 0.0 6.11
* Loaded : 加载class的数量
* Bytes : class字节大小
* Unloaded : 未加载class的数量
* Bytes : 未加载class的字节大小
* Time : 加载时间
-compiler 输出JIT编译过的方法数量耗时等
# jstat -compiler 7064
Compiled Failed Invalid Time FailedType FailedMethod
16451 0 0 100.33 0
* Compiled : 编译数量
* Failed : 编译失败数量
* Invalid : 无效数量
* Time : 编译耗时
* FailedType : 失败类型
* FailedMethod : 失败方法的全限定名
-gc 垃圾回收堆的行为统计,常用命令
# jstat -gc 7064
S0C S1C S0U S1U EC EU OC OU MC MU CCSC CCSU YGC YGCT FGC FGCT GCT
13056.0 13056.0 1007.6 0.0 104960.0 95505.2 917504.0 205679.5 66484.0 64848.5 7132.0 6717.6 3026 50.039 4 0.133 50.172
C即Capacity 总容量,U即Used 已使用的容量
* S0C : survivor0区的总容量
* S1C : survivor1区的总容量
* S0U : survivor0区已使用的容量
* S1C : survivor1区已使用的容量
* EC : Eden区的总容量
* EU : Eden区已使用的容量
* OC : Old区的总容量
* OU : Old区已使用的容量
* PC 当前perm的容量 (KB)
* PU perm的使用 (KB)
* YGC : 新生代垃圾回收次数
* YGCT : 新生代垃圾回收时间
* FGC : 老年代垃圾回收次数
* FGCT : 老年代垃圾回收时间
* GCT : 垃圾回收总消耗时间
# jstat -gc 7064 2000 20
这个命令意思就是每隔2000ms输出1262的gc情况,一共输出20次
-gccapacity 同-gc,不过还会输出Java堆各区域使用到的最大、最小空间
# jstat -gccapacity 7064 2000 20
NGCMN NGCMX NGC S0C S1C EC OGCMN OGCMX OGC OC MCMN MCMX MC CCSMN CCSMX CCSC YGC FGC
131072.0 131072.0 131072.0 13056.0 13056.0 104960.0 917504.0 917504.0 917504.0 917504.0 0.0 1107968.0 66484.0 0.0 1048576.0 7132.0 3027 4
131072.0 131072.0 131072.0 13056.0 13056.0 104960.0 917504.0 917504.0 917504.0 917504.0 0.0 1107968.0 66484.0 0.0 1048576.0 7132.0 3027 4
* NGCMN : 新生代占用的最小空间
* NGCMX : 新生代占用的最大空间
* OGCMN : 老年代占用的最小空间
* OGCMX : 老年代占用的最大空间
* OGC:当前年老代的容量 (KB)
* OC:当前年老代的空间 (KB)
* PGCMN : perm占用的最小空间
* PGCMX : perm占用的最大空间
-gcutil 同-gc,不过输出的是已使用空间占总空间的百分比
# jstat -gcutil 7064 2000 20
S0 S1 E O M CCS YGC YGCT FGC FGCT GCT
0.00 7.76 27.58 22.42 97.54 94.19 3027 50.050 4 0.133 50.183
-gccause 垃圾收集统计概述(同-gcutil),附加最近两次垃圾回收事件的原因
# jstat -gccause 7064 2000 20
S0 S1 E O M CCS YGC YGCT FGC FGCT GCT LGCC GCC
0.00 7.76 33.58 22.42 97.54 94.19 3027 50.050 4 0.133 50.183 Allocation Failure No GC
* LGCC:最近垃圾回收的原因
* GCC:当前垃圾回收的原因
-gcnew 统计新生代的行为
-gcnewcapacity 新生代与其相应的内存空间的统计
-gcold 统计旧生代的行为
-gcoldcapacity 统计旧生代的大小和空间
-gcpermcapacity 永生代行为统计
-printcompilation hotspot编译方法统计
#jstat -gcnew 7064 2000 20
S0C S1C S0U S1U TT MTT DSS EC EU YGC YGCT
13056.0 13056.0 0.0 1012.9 6 6 6528.0 104960.0 57023.3 3027 50.050
* TT:Tenuring threshold(提升阈值)
* MTT:最大的tenuring threshold
* DSS:survivor区域大小 (KB)
# jstat -gcnewcapacity 7064 2000 20
NGCMN NGCMX NGC S0CMX S0C S1CMX S1C ECMX EC YGC FGC
131072.0 131072.0 131072.0 13056.0 13056.0 13056.0 13056.0 104960.0 104960.0 3027 4
* NGC:当前年轻代的容量 (KB)
* S0CMX:最大的S0空间 (KB)
* S0C:当前S0空间 (KB)
* ECMX:最大eden空间 (KB)
* EC:当前eden空间 (KB)
# jstat -printcompilation 7064 2000 20
Compiled Size Type Method
16451 39 1 sun/nio/cs/US_ASCII$Decoder implReplaceWith
* Compiled:被执行的编译任务的数量
* Size:方法字节码的字节数
* Type:编译类型
* Method:编译方法的类名和方法名。类名使用"/" 代替 "." 作为空间分隔符. 方法名是给出类的方法名. 格式是一致于HotSpot - XX:+PrintComplation 选项
3. jmap
jmap(JVM Memory Map)命令用于生成heap dump文件,如果不使用这个命令,还阔以使用-XX:+HeapDumpOnOutOfMemoryError参数来让虚拟机出现OOM的时候·自动生成dump文件。 jmap不仅能生成dump文件,还阔以查询finalize执行队列、Java堆和永久代的详细信息,如当前使用率、当前使用的是哪种收集器等。 dump : 生成堆转储快照
# jmap -dump:live,format=b,file=dump.hprof 28920
finalizerinfo : 显示在F-Queue队列等待Finalizer线程执行finalizer方法的对象
heap : 显示Java堆详细信息。打印heap的概要信息,GC使用的算法,heap的配置及wise heap的使用情况,可以用此来判断内存目前的使用情况以及垃圾回收情况
# jmap -heap 2524
Attaching to process ID 2524, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.131-b11
using thread-local object allocation.
Parallel GC with 4 thread(s) //GC 方式
Heap Configuration://堆内存初始化配置
MinHeapFreeRatio = 0//对应jvm启动参数-XX:MinHeapFreeRatio设置JVM堆最小空闲比率(default 40)
MaxHeapFreeRatio = 100//对应jvm启动参数 -XX:MaxHeapFreeRatio设置JVM堆最大空闲比率(default 70)
MaxHeapSize = 734003200 (700.0MB)//对应jvm启动参数-XX:MaxHeapSize=设置JVM堆的最大大小
NewSize = 44564480 (42.5MB)//对应jvm启动参数-XX:NewSize=设置JVM堆的‘新生代’的默认大小
MaxNewSize = 244318208 (233.0MB)//对应jvm启动参数-XX:MaxNewSize=设置JVM堆的‘新生代’的最大大小
OldSize = 89653248 (85.5MB)//对应jvm启动参数-XX:OldSize=<value>:设置JVM堆的‘老生代’的大小
NewRatio = 2//对应jvm启动参数-XX:NewRatio=:‘新生代’和‘老生代’的大小比率
SurvivorRatio = 8//对应jvm启动参数-XX:SurvivorRatio=设置年轻代中Eden区与Survivor区的大小比值
MetaspaceSize = 21807104 (20.796875MB)//对应jvm启动参数-XX:PermSize=<value>:设置JVM堆的‘永生代’的初始大小??
CompressedClassSpaceSize = 1073741824 (1024.0MB)
MaxMetaspaceSize = 17592186044415 MB
G1HeapRegionSize = 0 (0.0MB)
Heap Usage://堆内存使用情况
PS Young Generation
Eden Space://Eden区内存分布
capacity = 68157440 (65.0MB)//Eden区总容量
used = 2070304 (1.974395751953125MB)//Eden区已使用
free = 66087136 (63.025604248046875MB)//Eden区剩余容量
3.037531926081731% used//Eden区使用比率
From Space://其中一个Survivor区的内存分布
capacity = 5242880 (5.0MB)
used = 0 (0.0MB)
free = 5242880 (5.0MB)
0.0% used
To Space://另一个Survivor区的内存分布
capacity = 17825792 (17.0MB)
used = 0 (0.0MB)
free = 17825792 (17.0MB)
0.0% used
PS Old Generation//当前的Old区内存分布
capacity = 73400320 (70.0MB)
used = 22593392 (21.546737670898438MB)
free = 50806928 (48.45326232910156MB)
30.781053815569198% used
6486 interned Strings occupying 550640 bytes.
histo : 显示堆中对象的统计信息
clstats: to print permanent generation statistics
F : 当-dump没有响应时,强制生成dump快照
4. jstack
用于生成java虚拟机当前时刻的线程快照。
线程快照是当前java虚拟机内每一条线程正在执行的方法堆栈的集合,生成线程快照的主要目的是定位线程出现长时间停顿的原因,如线程间死锁、死循环、请求外部资源导致的长时间等待等。
线程出现停顿的时候通过jstack来查看各个线程的调用堆栈,就可以知道没有响应的线程到底在后台做什么事情,或者等待什么资源。
如果java程序崩溃生成core文件,jstack工具可以用来获得core文件的java stack和native stack的信息,从而可以轻松地知道java程序是如何崩溃和在程序何处发生问题。另外,jstack工具还可以附属到正在运行的java程序中,看到当时运行的java程序的java stack和native stack的信息, 如果现在运行的java程序呈现hung的状态,jstack是非常有用的。
#jstack -l 2524|more
2019-04-29 16:51:29
Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.131-b11 mixed mode):
"DestroyJavaVM" #16 prio=5 os_prio=0 tid=0x0000000005285800 nid=0x177c waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
* -F : 当正常输出请求不被响应时,强制输出线程堆栈
* -l : 除堆栈外,显示关于锁的附加信息
* -m : 如果调用到本地方法的话,可以显示C/C++的堆栈
5. jinfo
jinfo(JVM Configuration info)这个命令作用是实时查看和调整虚拟机运行参数。 之前的jps -v口令只能查看到显示指定的参数,如果想要查看未被显示指定的参数的值就要使用jinfo口令
VM Flags:
Non-default VM flags: -XX:CICompilerCount=3 -XX:InitialHeapSize=134217728 -XX:MaxHeapSize=734003200 -XX:MaxNewSize=244318208 -XX:MinHeapDeltaBytes=524288 -XX:NewSize=44564480 -XX:OldSize=89653248 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseFastUnorderedTimeStamps -XX:-UseLargePagesIndividualAllocation -XX:+UseParallelGC
* -flag : 输出指定args参数的值
* -flags : 不需要args参数,输出所有JVM参数的值
* -sysprops : 输出系统属性,等同于System.getProperties()
6. top
Top命令取得cpu占有率最高的进程,然后取得该进程内的cpu占有率高的线程:
ps -mp pid-o THREAD,tid,time
实战
记一次线上full gc问题处理
问题现象
[root@-server-757799875b-2wkvx /]# jstat -gc 1 2000
S0C S1C S0U S1U EC EU OC OU MC MU CCSC CCSU YGC YGCT FGC FGCT GCT
465408.0 465920.0 0.0 0.0 446464.0 446464.0 2796544.0 2796531.9 109388.0 104798.1 12364.0 11638.8 181 4.508 4129 914.951 919.459
465408.0 465920.0 0.0 0.0 446464.0 446464.0 2796544.0 2796536.4 109388.0 104798.1 12364.0 11638.8 181 4.508 4139 916.811 921.318
465408.0 465920.0 0.0 0.0 446464.0 446464.0 2796544.0 2796542.0 109388.0 104798.1 12364.0 11638.8 181 4.508 4150 918.822 923.330
465408.0 465920.0 0.0 0.0 446464.0 446464.0 2796544.0 2796541.4 109388.0 104798.1 12364.0 11638.8 181 4.508 4160 920.780 925.287
465408.0 465920.0 0.0 0.0 446464.0 446464.0 2796544.0 2796543.5 109388.0 104798.1 12364.0 11638.8 181 4.508 4171 922.759 927.267
465408.0 465920.0 0.0 0.0 446464.0 446464.0 2796544.0 2796544.0 109388.0 104798.1 12364.0 11638.8 181 4.508 4182 924.802 929.310
465408.0 465920.0 0.0 0.0 446464.0 446464.0 2796544.0 2796544.0 109388.0 104798.1 12364.0 11638.8 181 4.508 4193 926.755 931.263
465408.0 465920.0 0.0 0.0 446464.0 446464.0 2796544.0 2796544.0 109388.0 104798.1 12364.0 11638.8 181 4.508 4204 928.730 933.238
465408.0 465920.0 0.0 0.0 446464.0 446455.5 2796544.0 2796542.0 109388.0 104798.1 12364.0 11638.8 181 4.508 4215 930.797 935.304
465408.0 465920.0 0.0 0.0 446464.0 446464.0 2796544.0 2796544.0 109388.0 104798.1 12364.0 11638.8 181 4.508 4222 932.032 936.540
465408.0 465920.0 0.0 0.0 446464.0 446464.0 2796544.0 2796521.6 109388.0 104798.5 12364.0 11638.8 181 4.508 4230 934.761 939.269
* S0C:第一个幸存区的大小
* S1C:第二个幸存区的大小
* S0U:第一个幸存区的使用大小
* S1U:第二个幸存区的使用大小
* EC:伊甸园区的大小
* EU:伊甸园区的使用大小
* OC:老年代大小
* OU:老年代使用大小
* MC:方法区大小
* MU:方法区使用大小
* CCSC:压缩类空间大小
* CCSU:压缩类空间使用大小
* YGC:年轻代垃圾回收次数
* YGCT:年轻代垃圾回收消耗时间
* FGC:老年代垃圾回收次数
* FGCT:老年代垃圾回收消耗时间
* GCT:垃圾回收消耗总时间
[root@kuai-websocket-77b9dc5dbf-8z5mp /]# jinfo 1
VM Flags:
Non-default VM flags: -XX:CICompilerCount=15 -XX:InitialHeapSize=1073741824 -XX:MaxHeapSize=4294967296 -XX:MaxNewSize=1431306240 -XX:MinHeapDeltaBytes=524288 -XX:NewSize=357564416 -XX:OldSize=716177408 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseFastUnorderedTimeStamps -XX:+UseParallelGC
Command line: -Xms1024m -Xmx4096m
[root@kuai-server-757799875b-2wkvx /]# jmap -heap 1
Attaching to process ID 1, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.181-b13
using thread-local object allocation.
Parallel GC with 33 thread(s)
Heap Configuration:
MinHeapFreeRatio = 0
MaxHeapFreeRatio = 100
MaxHeapSize = 4294967296 (4096.0MB)
NewSize = 357564416 (341.0MB)
MaxNewSize = 1431306240 (1365.0MB)
OldSize = 716177408 (683.0MB)
NewRatio = 2
SurvivorRatio = 8
MetaspaceSize = 21807104 (20.796875MB)
CompressedClassSpaceSize = 1073741824 (1024.0MB)
MaxMetaspaceSize = 17592186044415 MB
G1HeapRegionSize = 0 (0.0MB)
Heap Usage:
PS Young Generation
Eden Space:
capacity = 457179136 (436.0MB)
used = 457179136 (436.0MB)
free = 0 (0.0MB)
100.0% used
From Space:
capacity = 476577792 (454.5MB)
used = 0 (0.0MB)
free = 476577792 (454.5MB)
0.0% used
To Space:
capacity = 477102080 (455.0MB)
used = 0 (0.0MB)
free = 477102080 (455.0MB)
0.0% used
PS Old Generation
capacity = 2863661056 (2731.0MB)
used = 2861965360 (2729.382858276367MB)
free = 1695696 (1.6171417236328125MB)
99.94078572963629% used
[root@-server-757799875b-slmzd /]# jmap -histo:live 1|grep WsFrameServer
175: 202 22624 org.apache.tomcat.websocket.server.WsFrameServer
[root@-server-757799875b-slmzd /]# jmap -dump:live,format=b,file=dump.hprof 1
问题分析
分析dump文件:
- Histogram里查看到WsFrameServer的引用对象总共有3.1G大小
Shallow Heap表示对象本身占用内存的大小,不包含对其他对象的引用,也就是对象头加成员变量(不是成员变量的值)的总和。
Retained Heap是该对象自己的Shallow Heap,并加上从该对象能直接或间接访问到对象的Shallow Heap之和。换句话说,Retained Heap是该对象GC之后所能回收到内存的总和。
2. 查找WsFrameServer的GCRoot未释放的外部引用
Paths to GC Roots -> exclude all phantom/weak/soft etc.reference (排除所有虚弱软引用) -查找GC Root线程 -> 查找未释放的内存占用最高的代码逻辑段(很可能是产生内存溢出代码)
- 过滤查看InstanceMonitorHandler的大小
- 查看WsFrameServer的内存占用情况,里面会有两个对象,一个messageBufferText和一个messageBufferBinary,一个10M和一个5M
- 代码诊断: a. spring-websocket.xml中配置bufferSize:
<bean class="org.springframework.web.socket.server.standard.ServletServerContainerFactoryBean">
<property name="maxTextMessageBufferSize" value="5242800"/>
<property name="maxBinaryMessageBufferSize" value="5242800"/>
</bean>
b. 页面关闭时,websocket连接未关闭,导致连接数一直增大
CPU过高
问题解决
首先我们通过top命令查看当前CPU消耗过高的进程是哪个,从而得到进程id;
# top
top - 08:31:10 up 30 min, 0 users, load average: 0.73, 0.58, 0.34
KiB Mem: 2046460 total, 1923864 used, 122596 free, 14388 buffers
KiB Swap: 1048572 total, 0 used, 1048572 free. 1192352 cached Mem
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
9 root 20 0 2557160 288976 15812 S 98.0 14.1 0:42.60 java
然后通过top -Hp 来查看该进程中有哪些线程CPU过高,一般超过80%就是比较高的,80%左右是合理情况。这样我们就能得到CPU消耗比较高的线程id。
# top -Hp 9
top - 08:31:16 up 30 min, 0 users, load average: 0.75, 0.59, 0.35
Threads: 11 total, 1 running, 10 sleeping, 0 stopped, 0 zombie
%Cpu(s): 3.5 us, 0.6 sy, 0.0 ni, 95.9 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st
KiB Mem: 2046460 total, 1924856 used, 121604 free, 14396 buffers
KiB Swap: 1048572 total, 0 used, 1048572 free. 1192532 cached Mem
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
10 root 20 0 2557160 289824 15872 R 79.3 14.2 0:41.49 java
11 root 20 0 2557160 289824 15872 S 13.2 14.2 0:06.78 java
接着通过该线程id的十六进制表示在jstack日志中查看当前线程具体的堆栈信息。
[bdpops@BJxxx ~]$ printf "%x\n" 44075
ac2b
[bdpops@BJxxx ~]$ jstack 43964| grep ac2b -A 30
a # 这里打印结果说明该线程在jstack中的展现形式为0xa
...
"main" #1 prio=5 os_prio=0 tid=0x00007f8718009800 nid=0xb runnable [0x00007f871fe41000]
java.lang.Thread.State: RUNNABLE
at com.aibaobei.chapter2.eg2.UserDemo.main(UserDemo.java:9)
"VM Thread" os_prio=0 tid=0x00007f871806e000 nid=0xa runnable
这里的VM Thread一行的最后显示nid=0xa,这里nid的意思就是操作系统线程id的意思。而VM Thread指的就是垃圾回收的线程。这里我们基本上可以确定,当前系统缓慢的原因主要是垃圾回收过于频繁,导致GC停顿时间较长。
debug gethostbyname: unknown host问题
问题描述
export HADOOP_CLIENT_OPTS=" -agentlib:jdwp=transport=dt_socket,server=y,address=*:8000,suspend=y"
报错
ERROR: transport error 202: gethostbyname: unknown host
ERROR: JDWP Transport dt_socket failed to initialize, TRANSPORT_INIT(510)
JDWP exit error AGENT_ERROR_TRANSPORT_INIT(197): No transports initialized [debugInit.c:750]
问题解决
# jdk1.8及以下
export HADOOP_CLIENT_OPTS=" -agentlib:jdwp=transport=dt_socket,server=y,address=8000,suspend=y"
# jdk1.8以上
export HADOOP_CLIENT_OPTS=" -agentlib:jdwp=transport=dt_socket,server=y,address=*:8000,suspend=y"