作为一名合格的架构师,如何能快速定位生产故障的根源,快速修复并恢复,已经成为其必备技能。以下是我整理的出想法:
目录
1. 故障收集
2. 必备技能
2.1 网络与cup
2.2 HotSpot VM
2.3 Mbean
2.4 JVM工具
2.4.1 jps
2.4.2 jinfo
2.4.3 jconsole
2.4.4 jvisualvm
2.4.5 jmap
2.4.6 jstat
2.4.7 jstack
2.4.8 jstatd
2.4.9 jdb
2.4.10 jhat
2.5 OOM killer
3. gc log
3.1 生成日志
3.2 日志解析
3.3 gcviewer
4. heap dump
4.1 dump生成
4.2 OQL
4.3 jhat
4.4 jvisaulvm
4.5 eclipse mat
4.6 jprofiler
4.7 HeapAnalyzer
5. High CPU
6. 远程监控
6.1 Jstatd连接
6.2 Jmx连接
7. 在线诊断
8. Coredump
9. 性能调优
9.1 JVM常用参数
9.2 垃圾收集器方面
9.3 代码实现方面
参阅资料
1. 故障收集
2. 必备技能
2.1 网络与cup
-
查看网络状况
netstat -n | awk '/^tcp/ {++S[$NF]} END {for(a in S) print a, S[a]}'
-
使用top去获取进程cpu使用率;使用/proc文件查看进程所占内存。
#!/bin/bashfor i in `ps -ef | egrep -v "awk|$0" | awk '/'$1'/{print $2}'`domymem=`cat /proc/$i/status 2> /dev/null | grep VmRSS | awk '{print $2" " $3}'`cpu=`top -n 1 -b |awk '/'$i'/{print $9}'`done
2.2 HotSpot VM
otSpot是目前最常见的开源JVM(GPL协议),用来提供一个运行环境,运行Java应用,本次讨论基于此。
JIT compiler,代码生成器负责把Java字节码编译成优化过的native机器码,然后再全速执行,这种运行方式效率高。
解释执行方式,解释器每次把一小段代码转换成本机代码并执行,如此往复完成Java字节码的所以操作。
2.3 Mbean
Java SE 5 已引入的 java.lang.management 包定义了 9 个 Mbean。
类装载器 | ClassLoadingMXBean |
编译器 | CompilationMXBean |
内存 | MemoryMXBean |
线程 | ThreadMXBean |
运行时 | RuntimeMXBean |
操作系统 | OperatingSystemMXBean |
垃圾收集器 | GarbageCollectorMXBean |
内存管理器 | MemoryManagerMXBean |
内存池 | MemoryPoolMXBean |
2.4 JVM工具
2.4.1 jps
Java Virtual Machine Process Status Tool,进程状态工具,命令格式:
jps [ options ] [ hostid ]
options
- -q :忽略输出的类名、Jar名以及传递给main方法的参数,只输出pid。
- -m :输出传递给main方法的参数,如果是内嵌的JVM则输出为null。
- -l :输出应用程序主类的完整包名,或者是应用程序JAR文件的完整路径。
- -v :输出传给JVM的参数。
- -V :输出通过标记的文件传递给JVM的参数(.hotspotrc文件,或者是通过参数-XX:Flags=<filename>指定的文件)。
- -J :用于传递jvm选项到由javac调用的java加载器中,例如,“-J-Xms48m”将把启动内存设置为48M,使用-J选项可以非常方便的向基于Java的开发的底层虚拟机应用程序传递参数。
jps
jps -l 172.16.200.118
2.4.2 jinfo
Java Configuration Info,jinfo可以输出并修改运行时的java 进程的系统属性及JVM参数,命令格式:
jinfo [option] <pid>
(to connect to running process)
jinfo [option] <executable <core>
(to connect to a core file)
jinfo [option] [server_id@]<remote server IP or hostname>
(to connect to remote debug server)
jinfo 3424
jinfo -flag InitialHeapSize 3424
2.4.3 jconsole
Java Monitoring and Management Console,一个java GUI可视化监视工具,并可通过远程连接监视远程的服务器VM。用java写的GUI程序,用来监控VM,并可监控远程的VM,非常易用,而且功能非常强。命令行里打 jconsole,选则进程就可以了。
2.4.4 jvisualvm
Java Virtual Machine Monitoring, Troubleshooting, and Profiling Tool,jvisualvm同jconsole都是一个基于图形化界面的、可以查看本地及远程的JAVA GUI监控工具,Jvisualvm同jconsole的使用方式一样,直接在命令行打入Jvisualvm即可启动,不过Jvisualvm相比,界面更美观一些,数据更实时。
2.4.5 jmap
Java Memory Map,打印出某个java进程(使用pid)内存内的,所有‘对象’的情况(如:产生那些对象,及其数量),可以输出所有内存中对象的工具,甚至可以将VM 中的heap,以二进制输出成文本。命令格式:
jmap [option] pid
jmap [option] executable core
jmap [option] [server-id@]remote-hostname-or-IP
options
- -dump:[live,]format=b,file=<filename>:使用hprof二进制形式输出到文件(live子选项是可选的,活的对象到文件)
- -finalizerinfo:打印正等候回收的对象的信息.
- -heap: 打印heap的概要信息,GC使用的算法,heap的配置及wise heap的使用情况.
- -histo[:live]: 打印每个class的实例数目,内存占用,类全名信息. VM的内部类名字开头会加上前缀”*”.
- -permstat: 打印classload和jvm heap长久层的信息.
jmap -heap 2048
jmap -histo 5308>c:\5308.log
jmap -dump:format=b,file=c:\HeapDump.hprof 1484
2.4.6 jstat
Java Virtual Machine Statistics Monitoring Tool,用于监控基于HotSpot的JVM,对其堆的使用情况进行实时的命令行的统计,可以对指定的JVM做如下监控:
- 类的加载及卸载情况
- 查看新生代、老生代及持久代的容量及使用情况
- 查看新生代、老生代及持久代的垃圾收集情况,包括垃圾回收的次数及垃圾回收所占用的时间
- 查看新生代中Eden区及Survior区中容量及分配情况等
命令格式:jstat [ generalOption | outputOptions vmid [interval[s|ms] [count]] ]
jstat -gc 5308 2000 3
jstat -gcutil 5308 2000 3
generalOption – 单个的常用的命令行选项,如-help, -options, 或 -version。
outputOptions –一个或多个输出选项,由单个的statOption选项组成,可以和-t, -h, and -J等选项配合使用。
statOption |
Displays… |
class |
查看类加载情况的统计 |
compiler |
查看HotSpot中即时编译器编译情况的统计 |
gc |
查看JVM中堆的垃圾收集情况的统计 |
gccapacity |
查看新生代、老生代及持久代的存储容量情况 |
gccause |
用于查看垃圾收集的统计情况(这个和-gcutil选项一样),如果有发生垃圾收集,它还会显示最后一次及当前正在发生垃圾收集的原因。 |
gcutil |
查看新生代、老生代及持代垃圾收集的情况 |
gcnew |
查看新生代垃圾收集的情况 |
gcnewcapacity |
查看新生代的存储容量情况 |
gcold |
查看老生代及持久代发生GC的情况 |
gcoldcapacity |
查看老生代的容量 |
printcompilation |
HotSpot编译方法的统计 |
- -t,用于在输出内容的第一列显示时间戳,这个时间戳代表JVM开始启动到现在的时间
- -h n,用于指定每隔几行就输出列头,如果不指定,默认是只在第一行出现列头
- interval,间隔时间,单位可以是秒或者毫秒,通过指定s或ms确定,默认单位为毫秒。
- count, 打印次数,如果缺省则打印无数次。
-gc |
|
列名 |
说明 |
S0C |
新生代中Survivor space中S0当前容量的大小(KB) |
S1C |
新生代中Survivor space中S1当前容量的大小(KB) |
S0U |
新生代中Survivor space中S0容量使用的大小(KB) |
S1U |
新生代中Survivor space中S1容量使用的大小(KB) |
EC |
Eden space当前容量的大小(KB) |
EU |
Eden space容量使用的大小(KB) |
OC |
Old space当前容量的大小(KB) |
OU |
Old space使用容量的大小(KB) |
|
|
|
|
MC |
Metaspace当前容量的大小(KB)(java8) |
MU |
Metaspace使用容量的大小(KB)(java8) |
YGC |
从应用程序启动到采样时发生 Young GC 的次数 |
YGCT |
从应用程序启动到采样时 Young GC 所用的时间(秒) |
FGC |
从应用程序启动到采样时发生 Full GC 的次数 |
FGCT |
从应用程序启动到采样时 Full GC 所用的时间(秒) |
GCT |
从应用程序启动到采样时用于垃圾回收的总时间(单位秒),它的值等于 YGC+FGC |
-gcutil |
|
列名 |
说明 |
S0 |
Heap上的 Survivor space 0 区已使用空间的百分比 |
S1 |
Heap上的 Survivor space 1 区已使用空间的百分比 |
E |
Heap上的 Eden space 区已使用空间的百分比 |
O |
Heap上的 Old space 区已使用空间的百分比 |
|
|
M |
非堆内存MetaSpace已使用空间的百分比(java8) |
YGC |
从应用程序启动到采样时发生 Young GC 的次数 |
YGCT |
从应用程序启动到采样时Young GC 所用的时间(单位秒) |
FGC |
从应用程序启动到采样时发生 Full GC 的次数 |
FGCT |
从应用程序启动到采样时Full GC 所用的时间(单位秒) |
GCT |
从应用程序启动到采样时用于垃圾回收的总时间(单位秒),它的值等于YGC+FGC |
2.4.7 jstack
Java Stack Trace,用于打印出给定的java进程ID或core file或远程调试服务的Java堆栈信息。如果java程序崩溃生成core文件,jstack工具可以用来获得core文件的java stack和native stack的信息,从而可以轻松地知道java程序是如何崩溃和在程序何处发生问题。命令格式:
jstack [option] pid
jstack [option] executable core
jstack [option] [server-id@]remote-hostname-or-IP
jstack 5308>c:\5308thread.log
Full thread dump OpenJDK Client VM (19.0-b09 mixed mode, sharing): "Attach Listener" daemon prio=10 tid=0xb3da5400 nid=0x13ea waiting on condition [0x00000000] java.lang.Thread.State: RUNNABLE "Worker-15" prio=10 tid=0x09b7b400 nid=0x12f2 in Object.wait() [0xb30f9000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) at org.eclipse.core.internal.jobs.WorkerPool.sleep(WorkerPool.java:188) - locked <0x6e5f87c0> (a org.eclipse.core.internal.jobs.WorkerPool) at org.eclipse.core.internal.jobs.WorkerPool.startJob(WorkerPool.java:220) at org.eclipse.core.internal.jobs.Worker.run(Worker.java:50) "Worker-12" prio=10 tid=0x09910c00 nid=0x12a0 in Object.wait() [0xb4026000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) at org.eclipse.core.internal.jobs.WorkerPool.sleep(WorkerPool.java:188) - locked <0x6e5f87c0> (a org.eclipse.core.internal.jobs.WorkerPool) at org.eclipse.core.internal.jobs.WorkerPool.startJob(WorkerPool.java:220) at org.eclipse.core.internal.jobs.Worker.run(Worker.java:50) .......省略 "Low Memory Detector" daemon prio=10 tid=0x097eb000 nid=0xa9f runnable [0x00000000] java.lang.Thread.State: RUNNABLE "CompilerThread0" daemon prio=10 tid=0x097e9000 nid=0xa9e waiting on condition [0x00000000] java.lang.Thread.State: RUNNABLE "Signal Dispatcher" daemon prio=10 tid=0x097e7400 nid=0xa9d runnable [0x00000000] java.lang.Thread.State: RUNNABLE "Finalizer" daemon prio=10 tid=0x097e4000 nid=0xa9c in Object.wait() [0xb4dd1000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:133) - locked <0x6e2e02f8> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:149) at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:177) "Reference Handler" daemon prio=10 tid=0x097df400 nid=0xa9b in Object.wait() [0xb4e22000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) at java.lang.Object.wait(Object.java:502) at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133) - locked <0x6e2e0098> (a java.lang.ref.Reference$Lock) "main" prio=10 tid=0x097b0400 nid=0xa99 runnable [0xbf8b9000] java.lang.Thread.State: RUNNABLE at org.eclipse.swt.internal.gtk.OS.Call(Native Method) at org.eclipse.swt.widgets.Display.sleep(Display.java:4069) at org.eclipse.ui.application.WorkbenchAdvisor.eventLoopIdle(WorkbenchAdvisor.java:364) at org.eclipse.ui.internal.ide.application.IDEWorkbenchAdvisor.eventLoopIdle(IDEWorkbenchAdvisor.java:917) at org.eclipse.ui.internal.Workbench.runEventLoop(Workbench.java:2697) at org.eclipse.ui.internal.Workbench.runUI(Workbench.java:2660) at org.eclipse.ui.internal.Workbench.access$4(Workbench.java:2494) at org.eclipse.ui.internal.Workbench$7.run(Workbench.java:674) at org.eclipse.core.databinding.observable.Realm.runWithDefault(Realm.java:332) at org.eclipse.ui.internal.Workbench.createAndRunWorkbench(Workbench.java:667) at org.eclipse.ui.PlatformUI.createAndRunWorkbench(PlatformUI.java:149) at org.eclipse.ui.internal.ide.application.IDEApplication.start(IDEApplication.java:123) at org.eclipse.equinox.internal.app.EclipseAppHandle.run(EclipseAppHandle.java:196) at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.runApplication(EclipseAppLauncher.java:110) at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.start(EclipseAppLauncher.java:79) at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:344) at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:179) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:616) at org.eclipse.equinox.launcher.Main.invokeFramework(Main.java:622) at org.eclipse.equinox.launcher.Main.basicRun(Main.java:577) at org.eclipse.equinox.launcher.Main.run(Main.java:1410) "VM Thread" prio=10 tid=0x097dd800 nid=0xa9a runnable
"GC task thread#0 (ParallelGC)" prio=10 tid=0x08726800 nid=0x1e30 runnable "GC task thread#1 (ParallelGC)" prio=10 tid=0x08727c00 nid=0x1e31 runnable "VM Periodic Task Thread" prio=10 tid=0x097ed400 nid=0xaa0 waiting on condition JNI global references: 2131
如何读懂上面jvm stack 线程信息呢?
它主要包含5部分信息:Full thread dump identifier、custom application Threads、HotSpot VM Thread、HotSpot GC Thread、JNI global references count
这里解析下上面“Worker-15”的信息:
- Worker-15,Thread name
- prio=10,线程优先级
- tid=0x09b7b400,java线程的id
- nid=0x12f2,native线程的id
- in Object.wait() [0xb30f9000] ,线程执行方法,[0xb30f9000]是线程栈起始地址
- java.lang.Thread.State: TIMED_WAITING (on object monitor),TIMED_WAITING 是线程的状态
- locked <0x6e5f87c0> (a org.eclipse.core.internal.jobs.WorkerPool) ,0x947571b0表示锁对象的地址信息
当然如果你还有些不懂的话,可以参阅另一篇非常好的文章虚拟机stack全分析
线程状态含义及注意事项(红色重点关注):
- Deadlock:死锁线程,一般指多个线程调用间,进入相互资源占用,导致一直等待无法释放的情况。
- Runnable:一般指该线程正在执行状态中,该线程占用了资源,正在处理某个请求,有可能正在传递SQL到数据库执行,有可能在对某个文件操作,有可能进行数据类型等转换。
- Waiting on condition:等待资源,或等待某个条件的发生。具体原因需结合 stacktrace来分析。
- 如果堆栈信息明确是应用代码,则证明该线程正在等待资源。一般是大量读取某资源,且该资源采用了资源锁的情况下,线程进入等待状态,等待资源的读取。
- 又或者,正在等待其他线程的执行等。
- 如果发现有大量的线程都在处在 Wait on condition,从线程 stack看,正等待网络读写,这可能是一个网络瓶颈的征兆。因为网络阻塞导致线程无法执行。
- 一种情况是网络非常忙,几乎消耗了所有的带宽,仍然有大量数据等待网络读写;
- 另一种情况也可能是网络空闲,但由于路由等问题,导致包无法正常的到达。
- 另外一种出现 Wait on condition的常见情况是该线程在 sleep,等待 sleep的时间到了时候,将被唤醒。
- Blocked:线程阻塞,是指当前线程执行过程中,所需要的资源长时间等待却一直未能获取到,被容器的线程管理器标识为阻塞状态,可以理解为等待资源超时的线程。
- Waiting for monitor entry 和 in Object.wait():Monitor是 Java中用以实现线程之间的互斥与协作的主要手段,它可以看成是对象或者 Class的锁。每一个对象都有,也仅有一个 monitor。从下图1中可以看出,每个 Monitor在某个时刻,只能被一个线程拥有,该线程就是 “Active Thread”,而其它线程都是 “Waiting Thread”,分别在两个队列 “ Entry Set”和 “Wait Set”里面等候。在 “Entry Set”中等待的线程状态是 “Waiting for monitor entry”,而在 “Wait Set”中等待的线程状态是 “in Object.wait()”。
这里演示3个示例
示例1:Waiting to lock 和 Blocked
"RMI TCP Connection(267865)-172.16.5.25" daemon prio=10 tid=0x00007fd508371000 nid=0x55ae waiting for monitor entry [0x00007fd4f8684000]java.lang.Thread.State: BLOCKED (on object monitor)
at org.apache.log4j.Category.callAppenders(Category.java:201)
- waiting to lock <0x00000000acf4d0c0> (a org.apache.log4j.Logger)
at org.apache.log4j.Category.forcedLog(Category.java:388)
at org.apache.log4j.Category.log(Category.java:853)
at org.apache.commons.logging.impl.Log4JLogger.warn(Log4JLogger.java:234)
at com.tuan.core.common.lang.cache.remote.SpyMemcachedClient.get(SpyMemcachedClient.java:110)
1)线程状态是 Blocked,阻塞状态。说明线程等待资源超时!
2)“ waiting to lock <0x00000000acf4d0c0>”指线程在等待给这个 0x00000000acf4d0c0 地址上锁(英文可描述为:trying to obtain 0x00000000acf4d0c0 lock)。
3)在 dump 日志里查找字符串 0x00000000acf4d0c0,发现有大量线程都在等待给这个地址上锁。如果能在日志里找到谁获得了这个锁(如locked < 0x00000000acf4d0c0 >),就可以顺藤摸瓜了。
4)“waiting for monitor entry”说明此线程通过 synchronized(obj) {……} 申请进入了临界区,从而进入了下图1中的“Entry Set”队列,但该 obj 对应的 monitor 被其他线程拥有,所以本线程在 Entry Set 队列中等待。
示例2:Waiting on condition 和 TIMED_WAITING
"RMI TCP Connection(idle)" daemon prio=10 tid=0x00007fd50834e800 nid=0x56b2 waiting on condition [0x00007fd4f1a59000]java.lang.Thread.State: TIMED_WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000000acd84de8> (a java.util.concurrent.SynchronousQueue$TransferStack)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:198)
at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:424)
at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:323)
at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:874)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:945)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
at java.lang.Thread.run(Thread.java:662)
1)“TIMED_WAITING (parking)”中的 timed_waiting 指等待状态,但这里指定了时间,到达指定的时间后自动退出等待状态;parking指线程处于挂起中。
2)“waiting on condition”需要与堆栈中的“parking to wait for <0x00000000acd84de8> (a java.util.concurrent.SynchronousQueue$TransferStack)”结合来看。首先,本线程肯定是在等待某个条件的发生,来把自己唤醒。其次,SynchronousQueue 并不是一个队列,只是线程之间移交信息的机制,当我们把一个元素放入到 SynchronousQueue 中时必须有另一个线程正在等待接受移交的任务,因此这就是本线程在等待的条件。
示例3:in Obejct.wait() 和 TIMED_WAITING
"RMI RenewClean-[172.16.5.19:28475]" daemon prio=10 tid=0x0000000041428800 nid=0xb09 in Object.wait() [0x00007f34f4bd0000]java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x00000000aa672478> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:118)
- locked <0x00000000aa672478> (a java.lang.ref.ReferenceQueue$Lock)
at sun.rmi.transport.DGCClient$EndpointEntry$RenewCleanThread.run(DGCClient.java:516)
at java.lang.Thread.run(Thread.java:662)
1)“TIMED_WAITING (on object monitor)”,对于本例而言,是因为本线程调用了 java.lang.Object.wait(long timeout) 而进入等待状态。
2)“Wait Set”中等待的线程状态就是“ in Object.wait() ”。当线程获得了 Monitor,进入了临界区之后,如果发现线程继续运行的条件没有满足,它则调用对象(一般就是被 synchronized 的对象)的 wait() 方法,放弃了 Monitor,进入 “Wait Set”队列。只有当别的线程在该对象上调用了 notify() 或者 notifyAll() ,“ Wait Set”队列中线程才得到机会去竞争,但是只有一个线程获得对象的 Monitor,恢复到运行态。
3)请注意(日志和执行是反的),是先 locked <0x00000000aa672478>,后 waiting on <0x00000000aa672478>,之所以先锁再等同一个对象,请看下面它的代码实现:线程的执行中,先用 synchronized 获得了这个对象的 Monitor(对应于 locked <0x00000000aa672478> );当执行到 lock.wait(timeout);,线程就放弃了 Monitor 的所有权,进入“Wait Set”队列(对应于 waiting on <0x00000000aa672478> )。
static private class Lock { };
private Lock lock = new Lock();
public Reference<? extends T> remove(long timeout)
{synchronized (lock) {Reference<? extends T> r = reallyPoll();if (r != null) return r;for (;;) {lock.wait(timeout);r = reallyPoll();……}
}
2.4.8 jstatd
jstatd是一个基于RMI(Remove Method Invocation)的服务程序,它用于监控基于HotSpot的JVM中资源的创建及销毁,向远程机器提供本机jvm应用程序的信息
2.4.9 jdb
The Java Debugger,用来对core文件和正在运行的Java进程进行实时地调试,里面包含了丰富的命令帮助您进行调试,它的功能和Sun studio里面所带的dbx非常相似,但 jdb是专门用来针对Java应用程序的。现在应该说日常的开发中很少用到JDB了,因为现在的IDE已经帮我们封装好了,如使用ECLIPSE调用程序就是非常方便的,只要在非常特定的情况下可能会用到这个命令,如远程服务器的维护,没有IDE进行调试,那这个时候JDB应该可以帮上忙。
2.4.10 jhat
Java Heap Analyse Tool,用于对JAVA heap进行离线分析的工具,下面有专门介绍
2.5 OOM killer
理解和配置 Linux 下的 Out of memory
3. gc log
3.1 生成日志
打印供研发人员分析
-XX:+PrintGC:输出形式:[GC 118250K->113543K(130112K), 0.0094143 secs] [Full GC 121376K->10414K(130112K), 0.0650971 secs]
-XX:+PrintGCDetails:输出形式:[GC [DefNew: 8614K->781K(9088K), 0.0123035 secs] 118250K->113543K(130112K), 0.0124633 secs] [GC [DefNew: 8614K->8614K(9088K), 0.0000665 secs][Tenured: 112761K->10414K(121024K), 0.0433488 secs] 121376K->10414K(130112K), 0.0436268 secs]
-XX:+PrintGCTimeStamps:输出形式:11.851: [GC 98328K->93620K(130112K), 0.0082960 secs]
-Xloggc:filename:输出GC信息到日志文件。
日志产生:
Catalina.sh添加JAVA_OPTS=‘-server -XX:+PrintGCDateStamps -XX:+PrintGCDetails -Xloggc:/root/apache-tomcat-8.0.36/logs/gc.log’
注:window不稳定,不论述
3.2 日志解析
3.3 gcviewer
java -jar gcviewer-1.35-SNAPSHOT.jar(见下图),
当然,你也可以使用在线工具: easygc.io gc日志分析
4. heap dump
4.1 dump生成
下面种方式均可以:
Jmap
jmap -dump:format=b,file=c:\HeapDump.hprof 1484
Jconsole
Mbean->com.sun.management->HotSpotDiagnos->Operations->dumpHeap p0=F:\Downloads\my.hprof ,点击生产dump
Jvisualvm
可视化略
应用程序启动参数
应用程序:vm args:-XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=E:\\gclog.hprof,tomcat的话,window修改catalina.bat,linux修改catalina.sh。
4.2 OQL
在快照转储文件查询,更多API
by class name:
select s from java.lang.String s
show content of Strings that match a regular expression:
select {instance: s, content: s.toString()} from java.lang.String s where /java/.test(s.toString())
returns an enumeration of all Java classes:
select heap.classes();
query all threads:
select {name:t.name?t.name.toString():"null",thread:t} from instanceof java.lang.Thread t
query exception:
SELECT exceptions.@objectId, exceptions.@displayName, exceptions.detailMessage.toString() FROM INSTANCEOF java.lang.Exception exceptions
4.3 jhat
jhat(默认http://localhost:7000/),注:分析比较简洁,dump文件不大可以,文件大时比较容易卡死
4.4 jvisaulvm
Dump的分类:
应用快照(.apps)
分析内存profile(.nps)
CPU性能分析profile(.nps)
线程dump(.tdump)
堆dump(.hprof)
4.5 eclipse mat
如果内存占用高的话,有很多分析内存快照的第三方工具,eclipse mat,它比jvisualvm功能更专业,出了查看每个类及对应实例占用的空间、数量,还可以查询对象之间的调用链,可以查看某个实例到GC Root之间的链,等等。可以在eclipse中安装mat插件,也可以下载独立的版本。
- Shallow Heap:浅堆
对象自身占用的内存大小,不包括它引用的对象。针对非数组类型的对象,它的大小就是对象与它所有的成员变量大小的总和。当然这里面还会包括一些java语言特性的数据存储单元。针对数组类型的对象,它的大小是数组元素对象的大小总和。
- Retained Heap:深堆
Retained Size=当前对象大小+当前对象可直接或间接引用到的对象的大小总和。(间接引用的含义:A->B->C, C就是间接引用)
换句话说,Retained Size就是当前对象被GC后,从Heap上总共能释放掉的内存。
- Histogram: Lists number of instances per class
- Dominator Tree: List the biggest objects and what they keep alive.
- Top Consumers: Print the most expensive objects grouped by class and by package.
- Tread_overview
- [Reports]Leak Suspects: includes leak suspects and a system overview
- [Reports]Top Components: list reports for components bigger than 1 percent of the total heap.
- Running Leak Suspect Report
4.6 jprofiler
操作视图:
Classes view:类视图
Allocation view:堆的分配视图,包含方法、子方法、对象映射、热点等分配情况
Biggest objects view:大对象列表
Reference view:对象引用视图
Inspections view:堆搜索视图
Graph:对象视图(调用关系)
Time view
4.7 HeapAnalyzer
5. High CPU
1.查询占有CPU高的进程及PID,
top 或 ps aux
2.查询对于进程内耗时及CPU占有高的线程及TID
ps -mp 3869 -o THREAD,tid,time
printf "%x\n" 3878 //转换
3.打印线程堆栈信息
jstack 3869|grep f26 -A60 //后60行
jstack 3869|grep f26 -B20 -A60 //找到前20行后60行
6. 远程监控
6.1 Jstatd连接
添加文件E:\Program Files\Java\jdk1.8.0_40\bin\jstatd.all.policy
grant codebase "file:${java.home}/../lib/tools.jar" {
permission java.security.AllPermission;
};
进入到JAVA_HOME/bin中
jstatd -J-Djava.security.policy=jstatd.all.policy -J-Djava.rmi.server.logCalls=true
jstatd -J-Djava.security.policy=jstatd.all.policy -J-Djava.rmi.server.hostname=172.16.200.118 -J-Djava.rmi.server.logCalls=true
注:要使Java VisualVM 不能连接到远程服务器上,使用 hostname -i 命令查看,如果显示的是 127.0.0.1 或者与本机实际 IP 不一致的话,需要把 /etc/hosts 文件中相应的地址改为本机实际 IP 或者修改hostname。
6.2 Jmx连接
window:E:\Program Files\apache-tomcat-8.0.21\bin\catalina.bat
set "JAVA_OPTS=-Dcom.sun.management.jmxremote.port=2099 -Dcom.sun.management.jmxremote.ssl=false -Dcom.sun.management.jmxremote.authenticate=false“
linux:/usr/local/apache-tomcat-8.0.21/bin/catalina.sh
CATALINA_OPTS='-Djava.rmi.server.hostname=172.16.201.204 -Dcom.sun.management.jmxremote.port=2099 -Dcom.sun.management.jmxremote -Dcom.sun.management.jmxremote.ssl=false -Dcom.sun.management.jmxremote.authenticate=false‘
注:authenticate=true设置文件jmxremote.access和jmxremote.password
7. 在线诊断
- greys-anatomy
- awesome-scripts
========awesome-scripts========
安装:
curl -s "https://raw.githubusercontent.com/superhj1987/awesome-scripts/master/self-installer.sh" | bash -s
使用:
-
显示最繁忙的java线程: -c <要显示的线程栈数> -p <指定的Java Process>
opscipts show-busy-java-threads [-c] [-p]
-
使用greys跟踪方法耗时
opscripts greys [@IP:PORT]
ga?: trace [class] [method]
-
显示当前cpu和内存使用状况,包括全局和各个进程的。
opscripts show-cpu-and-memory
-
进入jvm调试交互命令行,包含对java栈、堆、线程、gc等状态的查看
opscripts jvm [pid]
8. Coredump
如果需要到这个层面的话,那你一定摊上大事了!应程序由于各种异常或者bug导致在运行过程中异常退出或者中止,并且在满足一定条件下会产生一个叫做core的文件,Core文件会包含了程序运行时的内存,寄存器状态,堆栈指针,内存管理信息还有各种函数调用堆栈信息等。
1. ulimit –a 查看是否启用
ulimit -c 0 //不产生core文件
ulimit -c 100 //设置core文件最大为100k
ulimit -c unlimited //不限制core文件大小
2. echo “ulimit -c 1024” >> /etc/profile //注:重新登陆 LINUX
3.编写C程序,验证,略(默认生成在当前执行目录)
4.安装gdb程序
Question1:如何判断一个文件是coredump文件?
readelf -h core.1399 //文件头的Type字段的类型是CORE (Core file)
Question2:如何调整coredump文件位置?
echo /var/log/core.%e.%p>/proc/sys/kernel/core_pattern
%% 单个%字符
%p 所dump进程的进程ID
%u 所dump进程的实际用户ID
%g 所dump进程的实际组ID
%s 导致本次core dump的信号
%t core dump的时间 (由1970年1月1日计起的秒数)
%h 主机名
%e 程序文件名
Question3:java程序崩溃时如何生成?
正常退出, kill -s SIGSEGV 6879
9. 性能调优
JVM调优目标:使用较小的内存占用来获得较高的吞吐量或者较低的延迟。这里有几个比较重要的指标:
- 内存占用:程序正常运行需要的内存大小
- 延迟:由于垃圾收集而引起的程序停顿时间
- 吞吐量:用户程序运行时间占用户程序和垃圾收集占用总时间的比值
9.1 JVM常用参数
-server #64位机器下默认
-Xms6000M #最小堆大小
-Xmx6000M #最大堆大小
-Xmn500M #新生代大小
-Xss256K #栈大小
-XX:PermSize=500M (JDK7)
-XX:MaxPermSize=500M (JDK7)
-XX:MetaspaceSize=128m (JDK8)
-XX:MaxMetaspaceSize=512m(JDK8)
-XX:SurvivorRatio=65536
-XX:MaxTenuringThreshold=0 #晋升到老年代需要的存活次数,设置为0时,survivor区失去作用,一次minor gc,eden中存活的对象就会进入老年代,默认是15,使用CMS时默认是4
-Xnoclassgc #不做类的gc
#-XX:+PrintCompilation #输出jit编译情况,慎用
-XX:+TieredCompilation #启用多层编译,jd8默认开启
-XX:CICompilerCount=4 #编译器数目增加
-XX:-UseBiasedLocking #取消偏向锁
-XX:AutoBoxCacheMax=20000 #自动装箱的缓存数量,如int默认缓存为-128~127
-Djava.security.egd=file:/dev/./urandom #替代默认的/dev/random阻塞生成因子
-XX:+AlwaysPreTouch #启动时访问并置零内存页面,大堆时效果比较好
-XX:-UseCounterDecay #禁止JIT调用计数器衰减。默认情况下,每次GC时会对调用计数器进行砍半的操作,导致有些方法一直是个温热,可能永远都达不到C2编译的1万次的阀值。
-XX:ParallelRefProcEnabled=true # 默认为false,并行的处理Reference对象,如WeakReference
-XX:+DisableExplicitGC #此参数会影响使用堆外内存,会造成oom,如果使用NIO,请慎重开启
#-XX:+UseParNewGC #此参数其实在设置了cms后默认会启用,可以不用设置
-XX:+UseConcMarkSweepGC #使用cms垃圾回收器
#-XX:+UseCMSCompactAtFullCollection #是否在fullgc是做一次压缩以整理碎片,默认启用
-XX:CMSFullGCsBeforeCompaction=0 #full gc触发压缩的次数
#-XX:+CMSClassUnloadingEnabled #如果类加载不频繁,也没有大量使用String.intern方法,不建议打开此参数,况且jdk7后string pool已经移动到了堆中。开启此项的话,即使设置了Xnoclassgc也会进行class的gc, 但是某种情况下会造成bug:https://www.google.com/url?sa=t&rct=j&q=&esrc=s&source=web&cd=5&cad=rja&uact=8&ved=0ahUKEwjR16Wf6MHQAhWLrVQKHfLdCe4QFgg8MAQ&url=https%3A%2F%2Fblogs.oracle.com%2Fpoonam%2Fentry%2Fjvm_hang_with_cms_collector&usg=AFQjCNFNtkw6jHM-uyz-Wjri3LtAVXWJ8g&sig2=BFxSfHc-AIek18fEhY07mg。
#-XX:+CMSParallelRemarkEnabled #并行标记, 默认开启, 可以不用设置
#-XX:+CMSScavengeBeforeRemark #强制remark之前开始一次minor gc,减少remark的暂停时间,但是在remark之后也将立即开始又一次minor gc
-XX:CMSInitiatingOccupancyFraction=90 #触发full gc的内存使用百分比
-XX:+PrintClassHistogram #打印类统计信息
-XX:+PrintHeapAtGC #打印gc前后的heap信息
-XX:+PrintGCDetails #以下都是为了记录gc日志
-XX:+PrintGCDateStamps
-XX:+PrintGCApplicationStoppedTime #打印清晰的GC停顿时间外,还可以打印其他的停顿时间,比如取消偏向锁,class 被agent redefine,code deoptimization等等
-XX:+PrintTenuringDistribution #打印晋升到老年代的年龄自动调整的情况(并行垃圾回收器启用UseAdaptiveSizePolicy参数的情况下以及其他垃圾回收期也会动态调整,从最开始的MaxTenuringThreshold变成占用当前堆50%的age)
#-XX:+UseAdaptiveSizePolicy # 此参数在并行回收器时是默认开启的会根据应用运行状况做自我调整,如MaxTenuringThreshold、survivor区大小等,其他情况下最好不要开启
#-XX:StringTableSize #字符串常量池表大小(hashtable的buckets的数目),java 6u30之前无法修改固定为1009,后面的版本默认为60013,可以通过此参数设置
-XX:GCTimeLimit=98 #gc占用时间超过多少抛出OutOfMemoryError
-XX:GCHeapFreeLimit=2 #gc回收后小于百分之多少抛出OutOfMemoryError
-Xloggc:/home/logs/gc.log
9.2 垃圾收集器方面
垃圾收集器方面,Serial可以直接排除掉,现在最普通的服务器也有双核64位\8G内存,默认的收集器是PS Scavenge和PS MarkSweep。所以在并行(Parallel)和并发(Concurrent)两者之间选择。如果系统对峰值处理要求不高,而对一两秒的停顿可以接受,则使用(-XX:+UseParallelGC);如果应用对响应有更高的要求,停顿最好小于一秒,则使用(-XX:+UseConcMarkSweepGC)。
JVM配置方面,一般情况可以先用默认配置(基本的一些初始参数可以保证一般的应用跑的比较稳定了),在测试中根据系统运行状况(会话并发情况、会话时间等),结合gc日志、内存监控、使用的垃圾收集器等进行合理的调整,当老年代内存过小时可能引起频繁Full GC,当内存过大时Full GC时间会特别长。
那么JVM的配置比如新生代、老年代应该配置多大最合适呢?答案是不一定,调优就是找答案的过程,物理内存一定的情况下,新生代设置越大,老年代就越小,Full GC频率就越高,但Full GC时间越短;相反新生代设置越小,老年代就越大,Full GC频率就越低,但每次Full GC消耗的时间越大。建议如下:
-Xms和-Xmx的值设置成相等,堆大小默认为-Xms指定的大小,默认空闲堆内存小于40%时,JVM会扩大堆到-Xmx指定的大小;空闲堆内存大于70%时,JVM会减小堆到-Xms指定的大小。如果在Full GC后满足不了内存需求会动态调整,这个阶段比较耗费资源。
新生代尽量设置大一些,让对象在新生代多存活一段时间,每次Minor GC 都要尽可能多的收集垃圾对象,防止或延迟对象进入老年代的机会,以减少应用程序发生Full GC的频率。
老年代如果使用CMS收集器,新生代可以不用太大,因为CMS的并行收集速度也很快,收集过程比较耗时的并发标记和并发清除阶段都可以与用户线程并发执行。
方法区大小的设置,1.6之前的需要考虑系统运行时动态增加的常量、静态变量等,1.7只要差不多能装下启动时和后期动态加载的类信息就行。
9.3 代码实现方面
性能出现问题比如程序等待、内存泄漏除了JVM配置可能存在问题,代码实现上也有很大关系:
- 避免创建过大的对象及数组:过大的对象或数组在新生代没有足够空间容纳时会直接进入老年代,如果是短命的大对象,会提前出发Full GC。
- 避免同时加载大量数据,如一次从数据库中取出大量数据,或者一次从Excel中读取大量记录,可以分批读取,用完尽快清空引用。
- 当集合中有对象的引用,这些对象使用完之后要尽快把集合中的引用清空,这些无用对象尽快回收避免进入老年代。
- 可以在合适的场景(如实现缓存)采用软引用、弱引用,比如用软引用来为ObjectA分配实例:SoftReference objectA=new SoftReference(); 在发生内存溢出前,会将objectA列入回收范围进行二次回收,如果这次回收还没有足够内存,才会抛出内存溢出的异常。
- 避免产生死循环,产生死循环后,循环体内可能重复产生大量实例,导致内存空间被迅速占满。
- 尽量避免长时间等待外部资源(数据库、网络、设备资源等)的情况,缩小对象的生命周期,避免进入老年代,如果不能及时返回结果可以适当采用异步处理的方式等。
最后,想了解怎样快速收集故障现场,请参阅《收集故障现场脚本》
参阅资料
- BTrace
- easygc.io gc日志分析
- fastthread.io thread dump分析
- 听阿里巴巴JVM工程师为你分析常见Java故障案例
- MySQL Statement cancellation timer故障排查分享
- JDBC驱动自身问题引发的FullGC