记一次内存爆涨分析 , JVM命令使用
问题描述:
tomcat服务突然不可用 , 所有请求均不通 .
第一想法就是服务挂了.
登录服务器
- 查询tomcat进程, 服务还在运行中
- 服务运行中 , 但接口不可用 .
- 可以想到硬件到了极限 , CPU , 内存 , 日志(大日志文件占满服务器)
- 查询进程状态 . java占用内存超95%
- 死循环
- 大对象 map 或 list
- 查日志,确定问题所在
- 一个select查询, 查了几十万条数据,而且多次刷. 把内存占满了.
- 有日志就是好办事 .
下面是没有日志的问题定位方式 .使用jvm命令.
以下为我本地的模拟操作
还是前面的逻辑:
确定服务是否还在运行中
$ jps -l
3408 org.apache.catalina.startup.Bootstrap
9920 org.jetbrains.jps.cmdline.Launcher
4892
8716 org.jetbrains.idea.maven.server.RemoteMavenServer
9852 sun.tools.jps.Jps
可以看到 3408为tomcat进程, 可以列出来,说明服务没问题 . 在运行中.
进程的硬件状态
$ top
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
3408 root 20 0 5494m 1.7g 11m S 6.7 95.9 1:19.12 java
可以看到 , %MEM为内存显示为百分比 . 内存占用95.9%
接下去思路:
- 突然的情况 , 那么一定有操作. 先大胆的断定为接口异常. 先定位http请求的线程.
- 大部分情况下,都是http线程的异常
- 如果http线程无异常 , 再找其他问题
定位http线程问题
$ jstack 3408 | grep http
"http-apr-80-exec-2" daemon prio=6 tid=0x000000000d60c000 nid=0x2088 runnable [0x000000000fc7a000]
"http-apr-80-exec-1" daemon prio=6 tid=0x000000000d60d800 nid=0x2364 waiting for monitor entry [0x000000000e1de000]
"http-apr-80-AsyncTimeout" daemon prio=6 tid=0x000000000c21e800 nid=0x1f68 waiting on condition [0x00000000102cf000]
"http-apr-80-Acceptor-0" daemon prio=6 tid=0x000000000c21e000 nid=0x15e0 runnable [0x00000000100df000]
"http-apr-80-Sendfile" daemon prio=6 tid=0x000000000c21d000 nid=0x9d4 in Object.wait() [0x000000000febe000]
"http-apr-80-Poller" daemon prio=6 tid=0x000000000c21c800 nid=0x7b0 in Object.wait() [0x000000000fdaf000]
tomcat的http请求默认线程名格式为:http-apr-80-exec-xx , xx代表线程号 .
我这里只是模拟 , 只有两个线程,线程1是waiting状态 , 线程2 是runnable状态
那么一般情况下, 资源被线程过度使用才会爆. 一般只有一个线程为runnbale,其他都在等待资源 . 为waiting状态.
那么把线程2的栈信息打印出来
打印异常栈信息
$ jstack 7048 | grep "http-apr-80-exec-2" -A 200
"http-apr-80-exec-2" daemon prio=6 tid=0x000000000d86b000 nid=0x2478 runnable [0x0000000010aea000]
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:152)
at java.net.SocketInputStream.read(SocketInputStream.java:122)
at com.mysql.jdbc.util.ReadAheadInputStream.fill(ReadAheadInputStream.java:101)
at com.mysql.jdbc.util.ReadAheadInputStream.read(ReadAheadInputStream.java:174)
- locked <0x00000007f52a1398> (a com.mysql.jdbc.util.ReadAheadInputStream)
at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:3001)
at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3462)
at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3452)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3893)
at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2526)
at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2673)
at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2549)
- locked <0x00000007f5245990> (a com.mysql.jdbc.JDBC4Connection)
at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1861)
- locked <0x00000007f5245990> (a com.mysql.jdbc.JDBC4Connection)
at com.mysql.jdbc.PreparedStatement.execute(PreparedStatement.java:1192)
- locked <0x00000007f5245990> (a com.mysql.jdbc.JDBC4Connection)
.......
at org.mybatis.spring.SqlSessionTemplate.selectList(SqlSessionTemplate.java:231)
at org.apache.ibatis.binding.MapperMethod.executeForMany(MapperMethod.java:137)
at org.apache.ibatis.binding.MapperMethod.execute(MapperMethod.java:75)
at org.apache.ibatis.binding.MapperProxy.invoke(MapperProxy.java:53)
at com.sun.proxy.$Proxy76.selectByCondition(Unknown Source)
........
at com.sun.proxy.$Proxy77.selectByCondition(Unknown Source)
at com.test.services.SelectService.selectListByCondition(SelectService.java:63)
at com.test.controllers.SelectController.selectListByCondition(SelectController.java:142)
at com.test.controllers.SelectController$$FastClassBySpringCGLIB$$299008ba.invoke(<generated>)
.........
截取了线程2的一部分信息.
栈的执行顺序是从下往上的 . 最上面是最后执行的.
最上面可以看到 , 线程2 执行了一个select查询,最后在读取数据 , 那么就是在读取数据库数据.
现在可以定位问题原因, 查询了大量数据写到内存里 ,把内存占满了.
顺着栈信息向下找 ,可以找到业务方法的信息
at com.sun.proxy.$Proxy77.selectByCondition(Unknown Source)
at com.test.services.SelectService.selectListByCondition(SelectService.java:63)
at com.test.controllers.SelectController.selectListByCondition(SelectController.java:142)
那么出问题的代码位置也定位到了.SelectService的63行调用了一个select查询.查询了大量数据.没有做数据量限制.
- 过千数据不应当在接口中查询
- 参数校验一定要到位
- 日志很重要, 日志输出也要合理. 不能大量输出
问题定位结束 .
如果文章有帮助到您，请点个赞，您的反馈会让我感到文章是有价值的
