JVM--性能分析

最新推荐文章于 2022-04-14 20:00:02 发布

Tate-Ling

最新推荐文章于 2022-04-14 20:00:02 发布

阅读量3.2k

点赞数 2

分类专栏： Java 文章标签： JVM 性能分析 OOM CPU暴涨

本文链接：https://blog.csdn.net/szzt_lingpeng/article/details/50467803

版权

Java 专栏收录该内容

43 篇文章 0 订阅

订阅专栏

转载自：http://blog.csdn.net/fenglibing/article/details/6411953

一，JDK内置工具使用

1、javah命令(C Header and Stub File Generator)

2、jps命令(Java Virtual Machine Process Status Tool)

3、jstack命令(Java Stack Trace)

4、jstat命令(Java Virtual Machine Statistics Monitoring Tool)

5、jmap命令(Java Memory Map)

6、jinfo命令(Java Configuration Info)

7、jconsole命令(Java Monitoring and Management Console)

8、jvisualvm命令(Java Virtual Machine Monitoring, Troubleshooting, and Profiling Tool)

9、jhat命令(Java Heap Analyse Tool)

10、Jdb命令(The Java Debugger)

11、Jstatd命令(Java Statistics Monitoring Daemon)

二、以上的命令总结的不错，更具体的可以参照JVM的官方网站。接下来总结下我们web应用中遇到的内存溢出和CUP暴涨。

1，内存溢出的分析中，说两个最常见的：

A，java.lang.OutOfMemoryError: Java heap space
B，java.lang.OutOfMemoryError: PermGen space

通常这两个问题的关键就是加大相应块的内存。

2，如果是java heap space异常，这很有可能是项目中某些代码错误导致一些对象没有被释放掉，仅靠报异常的业务日志是无法找出真正有问题的代码，因为有可能报错那块代码仅仅是最后一根稻草，要想根治这问题，我建议是必须把这个堆信息倒出来，然后用MAT进行解析查看。

MAT工具可以分析到这个导出堆信息那一时刻这个对内存的对象占有情况。导出堆信息可使用jmap -dump命令，也可以在JVM启动参数中加上下面数据，那么在JVM报内存溢出之后会自动把堆信息给导出到硬盘上。

-XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=D:\tomcatSSO\JVM\HeapDump

3，内存溢出中通过catalina.out打印的堆栈日志可以查看到OOM报错前会有以下的错误信息或者其他征兆信息：

java.lang.OutOfMemoryError : GC overhead limit exceeded

官方对此的定义是：并行/并发回收器在GC回收时间过长时会抛出OutOfMemroyError。过长的定义是，超过98%的时间用来做GC并且回收了不到2%的堆内存。用来避免内存过小造成应用不能正常工作。

4，解决步骤，因时间问题，暂只贴出一些必要的命令及结果，稍后再做解释

1），查看到当前运行的所有JAVA应用的进程ID

root@ubuntu:/# jps -m -l
99372 org.apache.catalina.startup.Bootstrap start
30972 sun.tools.jps.Jps -m -l

2），查看当前进程的状态

root@ubuntu:/# top -Hp 99372
top - 10:20:06 up 14 days,  6:38,  1 user,  load average: 0.12, 0.21, 0.09    
Tasks:     97    total,      0    running,     97    sleeping,      0    stopped,      0    zombie    
Cpu(s):     0.9%    us,     0.4%    sy,     0.0%    ni,    96.8%    id,     1.9%    wa,     0.0%    hi,     0.0%    si,     0.0%    st    
Mem:      8062616k    total,     5452504k    used,     2610112k    free,      564704k    buffers    
Swap:    10485756k    total,          0k    used,    10485756k    free,     2455556k    cached    
      PID USER     PR  NI  VIRT  RES  SHR S %CPU %ME      TIME+  COMMAND                                                                 
    99809 appdeplo  20   0 4090    2.0g  18    S  4.0 25.4   0:04.26 java       
    99372 appdeplo  20   0 4090    2.0g  18    S  0.0 25.4   0:00.00 java       
    99374 appdeplo  20   0 4090    2.0g  18    S  0.0 25.4   0:33.55 java       
    99375 appdeplo  20   0 4090    2.0g  18    S  0.0 25.4   0:11.24 java       
    99376 appdeplo  20   0 4090    2.0g  18    S  0.0 25.4   0:11.44 java       
    99377 appdeplo  20   0 4090    2.0g  18    S  0.0 25.4  12:03.80 java       
    ......

3），查看栈信息

root@ubuntu:/# jstack -l 99372
2016-01-05 10:20:48
Full thread dump Java HotSpot(TM) 64-Bit Server VM (20.45-b01 mixed mode):

"Attach Listener" daemon prio=10 tid=0x00007fa2a0177800 nid=0xab52 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
	- None

"pool-2-thread-6" prio=10 tid=0x00007fa2a01cb000 nid=0x1e41b waiting on condition [0x00007fa27d1ce000]
   java.lang.Thread.State: WAITING (parking)
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for  <0x000000078e5ae7e8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156)
	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987)
	at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:399)
	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:957)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:917)
	at java.lang.Thread.run(Thread.java:662)

   Locked ownable synchronizers:
	- None

"pool-2-thread-5" prio=10 tid=0x00007fa2a01ca000 nid=0x1e41a waiting on condition [0x00007fa2a434f000]
   java.lang.Thread.State: WAITING (parking)
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for  <0x000000078e5ae7e8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156)
	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987)
	at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:399)
	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:957)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:917)
	at java.lang.Thread.run(Thread.java:662)

   Locked ownable synchronizers:
	- None

"VM Thread" prio=10 tid=0x00007fa2c4061000 nid=0x18431 runnable 

"GC task thread#0 (ParallelGC)" prio=10 tid=0x00007fa2c401a000 nid=0x1842f runnable 

"GC task thread#1 (ParallelGC)" prio=10 tid=0x00007fa2c401b800 nid=0x18430 runnable 

"VM Periodic Task Thread" prio=10 tid=0x00007fa2c4097800 nid=0x18438 waiting on condition 

JNI global references: 1640    <pre name="code" class="java">数据量太多，省略了很多......

4），查看class实例数量

root@ubuntu:/# jmap -histo 99372
 num     #instances         #bytes  class name
----------------------------------------------
   1:        597898       62595560  [C
   2:        243033       33614728  <constMethodKlass>
   3:        243033       33063672  <methodKlass>
   4:        342869       30172472  java.lang.reflect.Method
   5:        120996       25028488  [I
   6:         16442       20905128  <constantPoolKlass>
   7:        603721       19319072  java.lang.String
   8:        435131       17405240  java.util.LinkedHashMap$Entry
   9:         58400       15075344  [B
  10:         16442       13387968  <instanceKlassKlass>
  11:        242672       13356000  <symbolKlass>
  12:        137129       11400208  [Ljava.util.HashMap$Entry;
  13:         13040        9948864  <constantPoolCacheKlass>
  14:        286860        9179520  java.util.HashMap$Entry
  15:        187443        8997264  org.aspectj.weaver.reflect.ShadowMatchImpl
  16:        296775        7590256  [Ljava.lang.String;
  17:        221520        7088640  java.util.concurrent.ConcurrentHashMap$HashEntry
  18:        121426        5999544  [Ljava.lang.Object;
  19:        187443        5998176  org.aspectj.weaver.patterns.ExposedState
  20:        244039        5684168  [Z......

打印较多，后面的省略。
默认是按照实例的数量排序的，我们只需要知道数量最大的那几个就行。

5），查看内存占用情况

root@ubuntu:/# jmap -heap 99372
using thread-local object allocation.
Parallel GC with 2 thread(s)

Heap Configuration:
   MinHeapFreeRatio = 40
   MaxHeapFreeRatio = 70
   MaxHeapSize      = 2147483648 (2048.0MB)
   NewSize          = 1310720 (1.25MB)
   MaxNewSize       = 17592186044415 MB
   OldSize          = 5439488 (5.1875MB)
   NewRatio         = 2
   SurvivorRatio    = 8
   PermSize         = 21757952 (20.75MB)
   MaxPermSize      = 805306368 (768.0MB)

Heap Usage:
PS Young Generation
Eden Space:
   capacity = 250281984 (238.6875MB)
   used     = 28369376 (27.055145263671875MB)
   free     = 221912608 (211.63235473632812MB)
   11.334965284596754% used
From Space:
   capacity = 12124160 (11.5625MB)
   used     = 0 (0.0MB)
   free     = 12124160 (11.5625MB)
   0.0% used
To Space:
   capacity = 44367872 (42.3125MB)
   used     = 0 (0.0MB)
   free     = 44367872 (42.3125MB)
   0.0% used
PS Old Generation
   capacity = 1431699456 (1365.375MB)
   used     = 262699976 (250.53022003173828MB)
   free     = 1168999480 (1114.8447799682617MB)
   18.348821388390608% used
PS Perm Generation
   capacity = 150470656 (143.5MB)
   used     = 148745800 (141.85504913330078MB)
   free     = 1724856 (1.6449508666992188MB)
   98.85369277581935% used

6），导出整个堆信息：

jmap -dump:format=b,file=/user/temp/99372.hprof 99372

三、生产环境解决思路。前几天有几个节点在生产环境中出现了CPU暴涨的情况，有时过段时间又会才降下来。以下是捕捉到的环境数据

1，使用top命令找到找到CPU占用最多的java进程

>>top
top - 11:33:59 up 71 days,  7:52,  1 user,  load average: 1.00, 1.01, 0.95
Tasks: 176 total,   1 running, 175 sleeping,   0 stopped,   0 zombie
Cpu(s):  2.1%us,  0.6%sy,  0.0%ni, 96.4%id,  1.0%wa,  0.0%hi,  0.0%si,  0.0%st
Mem:   8062368k total,  7842652k used,   219716k free,   388592k buffers
Swap: 10485756k total,    28248k used, 10457508k free,  4312248k cached
   PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND                                                                                     
 87006 appdeplo  20   0 5293m 2.5g  19m S 99.2 33.1 166:48.76 java                                                                                        
  1625 root      20   0 18316  604  444 S  2.0  0.0  12:11.35 irqbalance                                                                                  
     1 root      20   0 19356 1276 1060 S  0.0  0.0   0:03.09 init                                                                                        
     2 root      20   0     0    0    0 S  0.0  0.0   0:00.01 kthreadd                                                                                    
     3 root      RT   0     0    0    0 S  0.0  0.0   1:16.13 migration/0                                                                                 
     4 root      20   0     0    0    0 S  0.0  0.0   0:32.06 ksoftirqd/0                                                                                 
     5 root      RT   0     0    0    0 S  0.0  0.0   0:00.00 stopper/0                                                                                   
     6 root      RT   0     0    0    0 S  0.0  0.0   0:05.42 watchdog/0                                                                                  
     7 root      RT   0     0    0    0 S  0.0  0.0   1:16.63 migration/1                                                                                 
     8 root      RT   0     0    0    0 S  0.0  0.0   0:00.00 stopper/1                                                                                   
     9 root      20   0     0    0    0 S  0.0  0.0   0:32.38 ksoftirqd/1                                                                                 
    10 root      RT   0     0    0    0 S  0.0  0.0   0:04.48 watchdog/1                                                                                  
    11 root      RT   0     0    0    0 S  0.0  0.0   1:18.27 migration/2                                                                                 
    省略了部分......

2，通过top -Hp pid命令找到87006进程的具体线程信息

>>top -Hp 87006
top - 11:34:21 up 71 days,  7:52,  1 user,  load average: 1.06, 1.02, 0.96
Tasks: 200 total,   1 running, 199 sleeping,   0 stopped,   0 zombie
Cpu(s):  2.1%us,  0.6%sy,  0.0%ni, 96.4%id,  1.0%wa,  0.0%hi,  0.0%si,  0.0%st
Mem:   8062368k total,  7841156k used,   221212k free,   388624k buffers
Swap: 10485756k total,    28244k used, 10457512k free,  4312268k cached
   PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND                                                                                     
 87013 appdeplo  20   0 5293m 2.5g  19m R 101.2 33.1  83:37.63 java     //此处显示的是十进制的PID，但堆栈信息里面显示的是16进制用
 87384 appdeplo  20   0 5293m 2.5g  19m S  2.0 33.1   0:02.09 java     //可以在linux上使用 printf "%x\n" 87013 进行转换，或者其他进制转换工具
 87006 appdeplo  20   0 5293m 2.5g  19m S  0.0 33.1   0:00.00 java     //87013 转换为十进制结果为：153e5
 87008 appdeplo  20   0 5293m 2.5g  19m S  0.0 33.1   0:51.36 java                                                                                        
 87009 appdeplo  20   0 5293m 2.5g  19m S  0.0 33.1   1:33.77 java                                                                                        
 87010 appdeplo  20   0 5293m 2.5g  19m S  0.0 33.1   1:33.47 java                                                                                        
 87011 appdeplo  20   0 5293m 2.5g  19m S  0.0 33.1   1:33.43 java                                                                                        
 87012 appdeplo  20   0 5293m 2.5g  19m S  0.0 33.1   1:33.41 java                                                                                        
 87014 appdeplo  20   0 5293m 2.5g  19m S  0.0 33.1   0:00.35 java                                                                                        
 87015 appdeplo  20   0 5293m 2.5g  19m S  0.0 33.1   0:01.16 java                                                                                        
 省略了部分......

3，通过栈信息找到该线程的信息，由于内容太多，只显示需要的数据。

此处重点说明下：

1），一般通过线程id就能找到具体的线程问题，即可定位到问题

2），下面这种情况居然定位到是“VM Thread”的问题着实让我纳闷，此时我为了捕捉现场（CPU可能会隔断时间就降下来），于是敲了一堆的JVM命令，把内存信息到记录下来了

>>jstack -l 87006

2016-03-02 11:35:14
Full thread dump Java HotSpot(TM) 64-Bit Server VM (20.45-b01 mixed mode):
"http-8080-46" daemon prio=10 tid=0x00007f2e1805b000 nid=0x1a601 runnable [0x00007f2daa0ea000]
   java.lang.Thread.State: RUNNABLE
	at java.net.SocketInputStream.socketRead0(Native Method)
	at java.net.SocketInputStream.read(SocketInputStream.java:129)
	at oracle.net.ns.Packet.receive(Packet.java:239)
	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.net.ns.NetInputStream.read(NetInputStream.java:92)
	at oracle.net.ns.NetInputStream.read(NetInputStream.java:77)
	at oracle.jdbc.driver.T4CMAREngine.unmarshalUB1(T4CMAREngine.java:1023)
	at oracle.jdbc.driver.T4CMAREngine.unmarshalSB1(T4CMAREngine.java:999)
	at oracle.jdbc.driver.T4C8Oall.receive(T4C8Oall.java:584)
	at oracle.jdbc.driver.T4CPreparedStatement.doOall8(T4CPreparedStatement.java:194)
	at oracle.jdbc.driver.T4CPreparedStatement.fetch(T4CPreparedStatement.java:1011)
	at oracle.jdbc.driver.OracleResultSetImpl.close_or_fetch_from_next(OracleResultSetImpl.java:314)
	- locked <0x000000079b3900f8> (a oracle.jdbc.driver.T4CConnection)
	at oracle.jdbc.driver.OracleResultSetImpl.next(OracleResultSetImpl.java:228)
	- locked <0x000000079b3900f8> (a oracle.jdbc.driver.T4CConnection)
	at net.sf.log4jdbc.ResultSetSpy.next(ResultSetSpy.java:1233)
	at com.alibaba.druid.filter.FilterChainImpl.resultSet_next(FilterChainImpl.java:654)
	at com.alibaba.druid.filter.FilterAdapter.resultSet_next(FilterAdapter.java:1885)
	at com.alibaba.druid.filter.FilterChainImpl.resultSet_next(FilterChainImpl.java:651)
	at com.alibaba.druid.proxy.jdbc.ResultSetProxyImpl.next(ResultSetProxyImpl.java:882)
	at com.alibaba.druid.pool.DruidPooledResultSet.next(DruidPooledResultSet.java:69)
	at com.sinoservices.common.dao.impl.ExtendSqlDaoImpl.find(ExtendSqlDaoImpl.java:229)
	at com.sinoservices.common.util.DaoUtils.find(DaoUtils.java:642)
	at com.sinoservices.chem.report.service.impl.EsDiyReportManagerImpl.oracleBySql(EsDiyReportManagerImpl.java:1292)
	at com.sinoservices.chem.report.service.impl.EsDiyReportManagerImpl.queryBySqlOracle(EsDiyReportManagerImpl.java:910)
	at com.sinoservices.chem.report.service.impl.EsDiyReportManagerImpl.queryBySql(EsDiyReportManagerImpl.java:380)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
	at org.springframework.aop.framework.adapter.AfterReturningAdviceInterceptor.invoke(AfterReturningAdviceInterceptor.java:51)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:96)
	at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:260)
	at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:94)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:80)
	at com.sinoservices.common.aop.AccessLogServiceAspect.around(AccessLogServiceAspect.java:56)
	at sun.reflect.GeneratedMethodAccessor120.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:621)
	at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:610)
	at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:65)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
	at com.sun.proxy.$Proxy494.queryBySql(Unknown Source)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at com.sinoservices.framework.flex.service.impl.GridExportManagerImpl.exportExcel(GridExportManagerImpl.java:102)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
	at org.springframework.aop.framework.adapter.AfterReturningAdviceInterceptor.invoke(AfterReturningAdviceInterceptor.java:51)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:96)
	at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:260)
	at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:94)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:80)
	at com.sinoservices.common.aop.AccessLogServiceAspect.around(AccessLogServiceAspect.java:56)
	at sun.reflect.GeneratedMethodAccessor120.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:621)
	at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:610)
	at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:65)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
	at com.sun.proxy.$Proxy477.exportExcel(Unknown Source)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at com.sinoservices.framework.flex.web.JsonFacadeServletExcel.doGet(JsonFacadeServletExcel.java:137)
	at com.sinoservices.framework.flex.web.JsonFacadeServletExcel.doPost(JsonFacadeServletExcel.java:187)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:637)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
	at com.sinoservices.xframework.core.web.interceptors.ServletWebInterceptor.doService(SourceFile:37)
	at com.sinoservices.xframework.core.web.interceptors.ServletWebInterceptor.intercept(SourceFile:42)
	at com.sinoservices.xframework.core.web.c.intercept(SourceFile:315)
	at com.sinoservices.xframework.core.web.WebFilter.doFilter(SourceFile:205)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293)
	at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:859)
	at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:602)
	at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489)
	at java.lang.Thread.run(Thread.java:662)

   Locked ownable synchronizers:
	- None

"VM Thread" prio=10 tid=0x00007f2e34064800 nid=0x153e5 runnable 

"GC task thread#0 (ParallelGC)" prio=10 tid=0x00007f2e3401a000 nid=0x153e1 runnable 

"GC task thread#1 (ParallelGC)" prio=10 tid=0x00007f2e3401b800 nid=0x153e2 runnable 

"GC task thread#2 (ParallelGC)" prio=10 tid=0x00007f2e3401d800 nid=0x153e3 runnable 

"GC task thread#3 (ParallelGC)" prio=10 tid=0x00007f2e3401f800 nid=0x153e4 runnable 

"VM Periodic Task Thread" prio=10 tid=0x00007f2e3409b800 nid=0x153ec waiting on condition 

JNI global references: 2055

4，jinfo命令，可查看JVM启动的相关环境参数

>>jinfo 87006

Java System Properties:

java.runtime.name = Java(TM) SE Runtime Environment
sun.boot.library.path = /app/jdk/jdk1.6.0_45/jre/lib/amd64
java.vm.version = 20.45-b01
shared.loader = 
java.vm.vendor = Sun Microsystems Inc.
java.vendor.url = http://java.sun.com/
path.separator = :
tomcat.util.buf.StringCache.byte.enabled = true
java.util.logging.config.file = /app/tomcat/SCS_TMS_COLD_TOM_APP_CNSZ17_01/conf/logging.properties
java.vm.name = Java HotSpot(TM) 64-Bit Server VM
file.encoding.pkg = sun.io
sun.java.launcher = SUN_STANDARD
user.country = US
sun.os.patch.level = unknown
java.vm.specification.name = Java Virtual Machine Specification
user.dir = /app/tomcat/logs
java.runtime.version = 1.6.0_45-b06
java.awt.graphicsenv = sun.awt.X11GraphicsEnvironment
java.endorsed.dirs = /app/tomcat/SCS_TMS_COLD_TOM_APP_CNSZ17_01/endorsed
os.arch = amd64
java.io.tmpdir = /app/tomcat/SCS_TMS_COLD_TOM_APP_CNSZ17_01/temp
line.separator = 

java.vm.specification.vendor = Sun Microsystems Inc.
java.naming.factory.url.pkgs = org.apache.naming
java.util.logging.manager = org.apache.juli.ClassLoaderLogManager
os.name = Linux
sun.jnu.encoding = UTF-8
java.library.path = /app/jdk/jdk1.6.0_45/jre/lib/amd64/server:/app/jdk/jdk1.6.0_45/jre/lib/amd64:/app/jdk/jdk1.6.0_45/jre/../lib/amd64:/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib
java.specification.name = Java Platform API Specification
java.class.version = 50.0
sun.management.compiler = HotSpot 64-Bit Tiered Compilers
os.version = 2.6.32-504.el6.x86_64
user.home = /home/appdeploy
catalina.useNaming = true
user.timezone = Asia/Chongqing
java.awt.printerjob = sun.print.PSPrinterJob
file.encoding = UTF-8
java.specification.version = 1.6
catalina.home = /app/tomcat/SCS_TMS_COLD_TOM_APP_CNSZ17_01
java.class.path = /app/tomcat/SCS_TMS_COLD_TOM_APP_CNSZ17_01/bin/bootstrap.jar
user.name = appdeploy
java.naming.factory.initial = org.apache.naming.java.javaURLContextFactory
package.definition = sun.,java.,org.apache.catalina.,org.apache.coyote.,org.apache.tomcat.,org.apache.jasper.
java.vm.specification.version = 1.0
sun.java.command = org.apache.catalina.startup.Bootstrap start
java.home = /app/jdk/jdk1.6.0_45/jre
sun.arch.data.model = 64
user.language = en
java.specification.vendor = Sun Microsystems Inc.
java.vm.info = mixed mode
java.version = 1.6.0_45
java.ext.dirs = /app/jdk/jdk1.6.0_45/jre/lib/ext:/usr/java/packages/lib/ext
sun.boot.class.path = /app/jdk/jdk1.6.0_45/jre/lib/resources.jar:/app/jdk/jdk1.6.0_45/jre/lib/rt.jar:/app/jdk/jdk1.6.0_45/jre/lib/sunrsasign.jar:/app/jdk/jdk1.6.0_45/jre/lib/jsse.jar:/app/jdk/jdk1.6.0_45/jre/lib/jce.jar:/app/jdk/jdk1.6.0_45/jre/lib/charsets.jar:/app/jdk/jdk1.6.0_45/jre/lib/modules/jdk.boot.jar:/app/jdk/jdk1.6.0_45/jre/classes
server.loader = 
java.vendor = Sun Microsystems Inc.
catalina.base = /app/tomcat/SCS_TMS_COLD_TOM_APP_CNSZ17_01
file.separator = /
java.vendor.url.bug = http://java.sun.com/cgi-bin/bugreport.cgi
common.loader = ${catalina.base}/lib,${catalina.base}/lib/*.jar,${catalina.home}/lib,${catalina.home}/lib/*.jar
sun.io.unicode.encoding = UnicodeLittle
sun.cpu.endian = little
package.access = sun.,org.apache.catalina.,org.apache.coyote.,org.apache.tomcat.,org.apache.jasper.,sun.beans.
sun.cpu.isalist = 

VM Flags:

-Djava.util.logging.config.file=/app/tomcat/SCS_TMS_COLD_TOM_APP_CNSZ17_01/conf/logging.properties<span style="color:#ff0000;"> -Xms256M -Xmx2048M -XX:MaxPermSize=768M</span> 
-Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager -Djava.endorsed.dirs=/app/tomcat/SCS_TMS_COLD_TOM_APP_CNSZ17_01/endorsed 
-Dcatalina.base=/app/tomcat/SCS_TMS_COLD_TOM_APP_CNSZ17_01 -Dcatalina.home=/app/tomcat/SCS_TMS_COLD_TOM_APP_CNSZ17_01 
-Djava.io.tmpdir=/app/tomcat/SCS_TMS_COLD_TOM_APP_CNSZ17_01/temp

5，jmap -heap 查看内存信息，此处遍发现了一点端倪

1），发现了有几个内存区占用了差不多100%，但是这并不能表示该区域全部占满，因为JVM是在需要的时候才会扩展，比如下面的持久带。

2），再看老年代，已经全部被占用了。此时立马导出整个堆数据

>>jmap -heap 87006
using thread-local object allocation.
Parallel GC with 4 thread(s)
Heap Configuration:	// 配置
   MinHeapFreeRatio = 40
   MaxHeapFreeRatio = 70
   MaxHeapSize      = 2147483648 (2048.0MB)
   NewSize          = 1310720 (1.25MB)
   MaxNewSize       = 17592186044415 MB
   OldSize          = 5439488 (5.1875MB)
   NewRatio         = 2		
   SurvivorRatio    = 8
   PermSize         = 21757952 (20.75MB)
   MaxPermSize      = 805306368 (768.0MB)
//由NewRatio和SurvivorRatio的值可确认，一共2048MB的内存，可以计算出每个内存区域的最大值
Eden Space = 2048 * 1/3 * 4/5 = 546.1M
From Space = 2048 * 1/3 * 1/10 = 68.2M
To Space   = 2048 * 1/3 * 1/10 = 68.2M
PS Old Generation = 2048 * 2/3 = 1365M
PS Perm Generation = 768M

Heap Usage:
PS Young Generation
Eden Space:	// 新生代
   capacity = 225378304 (214.9375MB)
   used     = 225378304 (214.9375MB)
   free     = 0 (0.0MB)
   100.0% used
From Space:	// 存活代1
   capacity = 238551040 (227.5MB)
   used     = 0 (0.0MB)
   free     = 238551040 (227.5MB)
   0.0% used
To Space:	// 存活代2
   capacity = 238551040 (227.5MB)
   used     = 0 (0.0MB)
   free     = 238551040 (227.5MB)
   0.0% used
PS Old Generation	//老年代
   capacity = 1431699456 (1365.375MB)
   used     = 1431699448 (1365.3749923706055MB)
   free     = 8 (7.62939453125E-6MB)
   99.99999944122351% used
PS Perm Generation	//持久带
   capacity = 316342272 (301.6875MB)
   used     = 316060504 (301.41878509521484MB)
   free     = 281768 (0.26871490478515625MB)
   99.91092938726823% used

6， jmap导出整个堆信息

>>jmap -dump:format=b,file=outfile 87006

7，再通过eclipse的AMT工具进行解析该内存文件，查看到是http-8080-46线程占用了1.1G内存

8，返回到第三步再查看http-8080-46的线程栈信息，从后看前看分析如下：

 // 1,通过线程名称判断是http请求
  "http-8080-46" daemon prio=10 tid=0x00007f2e1805b000 nid=0x1a601 runnable [0x00007f2daa0ea000]
       java.lang.Thread.State: RUNNABLE
	at java.net.SocketInputStream.socketRead0(Native Method)
	at net.sf.log4jdbc.ResultSetSpy.next(ResultSetSpy.java:1233)
	at com.sinoservices.chem.report.service.impl.EsDiyReportManagerImpl.oracleBySql(EsDiyReportManagerImpl.java:1292)
	at com.sinoservices.chem.report.service.impl.EsDiyReportManagerImpl.queryBySqlOracle(EsDiyReportManagerImpl.java:910)
	at com.sinoservices.chem.report.service.impl.EsDiyReportManagerImpl.queryBySql(EsDiyReportManagerImpl.java:380)
	at com.sinoservices.framework.flex.service.impl.GridExportManagerImpl.exportExcel(GridExportManagerImpl.java:102) // 3，调用的是报表导出
	at com.sinoservices.xframework.core.web.interceptors.ServletWebInterceptor.doService(SourceFile:37)
	at com.sinoservices.xframework.core.web.WebFilter.doFilter(SourceFile:205)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293) // 2，确认是http请求
	at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:602)
	at java.lang.Thread.run(Thread.java:662)

9，此时基本上可判断是导出报表功能所致，判断应该是导出报表的sql语句查询的对象太多，导致内存满了。因为我有具体的堆信息，我便再次查看MAT工具。

10，具体类方法和sql语句已找到，愉快的分析完成，可根据具体情况提出解决方案!

Tate-Ling

关注

2
点赞
踩
6

收藏

觉得还不错? 一键收藏
0
评论
JVM--性能分析

转载自：http://blog.csdn.net/fenglibing/article/details/6411953JDK内置工具使用一、javah命令(C Header and Stub File Generator)二、jps命令(Java Virtual Machine Process Status Tool)三、jstack命令(Java St
复制链接

扫一扫