现象
线上某系统运行不到一周,响应速度变慢,并且多次重启,排查时发现CPU占用到100%,但这段时间系统并发量并未改变,数据库、缓存等也没发现异常。
排查过程
1、top指令查看哪个进程占用CPU高
发现确实是该系统的java进程。
2、使用 top -Hp 进程id
看哪个线程,然后利用jstack
命令查看对应线程一直在干什么
很经典的排查线上CPU 100%问题的操作步骤,注意要转十六进制 .
最终发现是GC操作占用CPU。
3、此处怀疑是某处有内存泄露,使用jmap -histo:live 进程id | head -20
查看占用内存最多的对象有哪些
此处注意: ‘jmap’ 命令导出堆转储文件时(‘jmap -dump:live,format=b,file=文件名称 进程id’) 时,会触发Full GC!!!触发Full GC可能导致线上服务不可用。因此要慎重使用,比如如果是多实例部署的话,先隔离一个实例,避免对线上产生影响。‘jmap -histo:live’ 这条命令则没那么恐怖的后果。
由于打印出的结果主要是对象签名,不太容易看,于是最终还是导出了一份堆转储文件,用MAT分析,下面是截图
参见标红的位置,首先可以看到是某处ThreadLocalMap一直有堆积、没有被释放。
然后进一步往下追,可以看到出问题的地方是org.crazycake.shiro.SessionInMemory
,对应的业务对象是UserInfo
这个自定义类的对象。
源码分析
org.crazycake.shiro.SessionInMemory
这个类来自于shiro-redis
包,用于在shiro
中使用redis
缓存session
。出问题的代码,是shiro-redis 3.2.0
版本中的RedisSessionDAO
读取session的代码,如下:
@Override
protected Session doReadSession(Serializable sessionId) {
if (sessionId == null) {
logger.warn("session id is null");
return null;
}
Session s = getSessionFromThreadLocal(sessionId);
if (s != null) {
return s;
}
logger.debug("read session from redis");
try {
s = (Session) valueSerializer.deserialize(redisManager.get(keySerializer.serialize(getRedisSessionKey(sessionId))))