排查java进程cpu100%的大致过程

• 之前遇到过
  之前也遇到过cpu 100%的问题，原因是while循环，死循环了，一直占有cpu。
• cpu为什么会100%
  我们都知道cpu是时分(time division)的，操作系统里有很多线程，每个线程的运行时间由cpu决定，cpu会分给每个线程一个时间片，时间片是一个很短的时间长度，如果在时间片内，线程一直占有，则是100%；我们应该意识到，cpu运行速度很快（主频非常高），除非密集型耗费cpu的运算，其它类型任务都会在小于时间片的时间内结束。
• cpu 100%大致排查过程
  排查java cpu100%的问题，大致步骤是固定的，首先找到占用cpu的进程，如果是java进程，则继续查看是哪个线程占用cpu，然后根据线程id从线程栈中找到对应线程栈，到这里，问题基本也就解决了。

故事背景

今天后台管理系统出现cpu 100%，这个问题间歇性出现，后台管理系统使用ssm（spring+springmvc+mybatis）+shiro实现，用户量很小，所以可以排除高并发导致。接下来，我们按照前述排查步骤，进行排查。

找到cpu 100%的进程

登录linux服务器找到占用cpu的进程，使用top

top 

找出服务器的所有java进程，

ps -ef | grep java 

或者使用

jps 

经对比，占用cpu的进程是java进程，继续挖，找出占用CPU的线程

top -H -p pid 

-H表示以线程的维度展示，默认以进程维度展示。

一共4个占用cpu的线程id 2944-2947,需要将线程id从十进制转为十六进制，因为java线程栈文件中的线程id是十六进制。十进制 转十六进制的命令是

echo "obase=16;number" | bc 

obase（output base）是输出的进制，number是输入值，默认十进制，bc（An arbitrary precision calculator language）是任意进制转换语言。
执行

echo "obase=16;2944" | bc 

结果是

B80 

导出栈

将java进程的线程栈导出，

jstack pid > pid.tdump 

pid.tdump文件后缀名随意，通常以tdump结尾。
在pid.tdump中找到nid=0XB80的线程，这4个线程都是gc线程。一般的cpu 100%问题到这就结束了，但是这次不一样，因为这4个线程是gc 线程。gc线程忙碌表示内存不够用了，要进行内存回收，第一反应是java内存回收不了，导致一直gc。

"GC task thread#0 (ParallelGC)" os_prio=0 tid=0x00007fa49c01f000 nid=0xb80 runnable  
 
"GC task thread#1 (ParallelGC)" os_prio=0 tid=0x00007fa49c020800 nid=0xb81 runnable  
 
"GC task thread#2 (ParallelGC)" os_prio=0 tid=0x00007fa49c022800 nid=0xb82 runnable  
 
"GC task thread#3 (ParallelGC)" os_prio=0 tid=0x00007fa49c024000 nid=0xb83 runnable  

导出堆

首先看一下堆的使用情况

jstat -gcutil pid 

查看Java内存占用情况，发现老年代和伊甸区，使用率都90%多，但是存活区分配的很小大约500KB，并且基本没有使用；伊甸园区本来应该复制到存活区，但存活区过小，所以直接复制到老年代，但老年代已经没有空间了，所以，伊甸区越积累越多。那么到底是什么占着老年代不释放呢？
没办法，导出java 堆来看看吧。如下将堆内存导出，只导出live的对象:

jmap -dump:live,format=b,file=pid.hprof pid 

同样的 文件后缀名可以是任意的，因为它也是二进制的，不过通常以hprof结尾。

jvisualvm分析快照

使用JAVA_HOME/bin/jvisualvm.exe，载入快照（文件—–>载入—>文件类型（堆））

按照大小排序，找出占用内存最大的类别，居然是字节数组，右击在实例图中显示，

我们发现字节数组的值都很规律，前半部分的字节数组基本都相同，我就想能不能把字节数组转为字符串，这样就能 知道字节数组是什么内容了，恰好左下角有个将字节数组另存为二进制文件的选项。

将二进制文件转为字符串，发现这些字节数组是当前用户的信息，如下

        File file = new File("C://Users//DELL//Desktop//heap.bin"); 
        final FileInputStream fileInputStream = new FileInputStream(file); 
        byte[] buffer = new byte[300]; 
        int len = -1; 
        while((len=fileInputStream.read(buffer))!=-1){ 
            System.out.println(new String(buffer,0,len , "utf8")); 
        } 
     

结合项目分析

当前用户信息放在session中，而session又放在ehcache和redis，check shiro的sessionDAO发现，session销毁时，只将redis的session删除，而未将ehcache中的也删除，另外查看ehcache中关于session cache配置，内存中元素个数是0，也就是不限制，这个很危险，并且配置的也不正确。为了重现这个问题，重启了tomcat，然后jmeter压测登录，发现老年区和伊甸区又满了，在等待了3个小时（最大存活时间）后，cpu仍然100%。
RedisSessionDAO .java

public class RedisSessionDAO extends EnterpriseCacheSessionDAO { 
	@Override 
    public void doDelete(Session session) { 
        //将redis中的session清除 
    } 
    } 

---

ehcache.xml，shiro session ehcache配置可以参考shiro session设置了过期时间不起作用、无效；

<cache name="shiro-activeSessionCache"  
maxEntriesLocalHeap="0" 
 eternal="false"  
 timeToIdleSeconds="10800"  //3小时 
 timeToLiveSeconds="10800" //3小时 
 overflowToDisk="false"/> 

---

session过期时间为3小时，时间太长了

    <bean id="sessionManager" class="org.apache.shiro.web.session.mgt.DefaultWebSessionManager"> 
    		<property name="globalSessionTimeout" value="10800000"></property> 
   </bean> 

改正

改正，session销毁时，将ehcache中的session也销毁
RedisSessionDAO .java

public class RedisSessionDAO extends EnterpriseCacheSessionDAO { 
	@Override 
    public void doDelete(Session session) { 
    //将echache中的session也删除 
    getActiveSessionsCache().remove(sessionId); 
     //将redis中的session清除 
    } 
    } 

---

ehcache.xml

<cache name="shiro-activeSessionCache" 
           maxEntriesLocalHeap="100" 
           eternal="true" 
           timeToIdleSeconds="0" 
           timeToLiveSeconds="0" 
           overflowToDisk="true"/> 

---

去掉globalSessionTimeout，默认是30分钟

    <bean id="sessionManager" class="org.apache.shiro.web.session.mgt.DefaultWebSessionManager"> 
   </bean> 

观察

jmeter压测一段时间后，老年代上升了，但过了1个小时（session调度器的默认执行间隔）后，old区，降下去了。到此为止，问题基本解决了。

必知必会java内存分析命令

上文提到的jstack、jmap、jstat、jvisualvm都位于 JAVA_HOME/bin 目录下，这个目录下有很多有用的工具。

疑问

虽然ehcache配置错误，但配了最大存活时间和最大空闲时间为3个小时，即使内存不限制数量，但到了3个小时ehcache应该会删除才是，为什么没删除呢？这个由于时间限制加上本身配置就是错误的应该配置为不限制，所以没继续追踪下去。

9年全栈开发经验，请关注个人公众号