记一次内存爆涨分析 , JVM命令使用-白红宇

记一次内存爆涨分析 , JVM命令使用

阅读量：5925 次

发布时间：2019-06-19

本文共 4477 字，大约阅读时间需要 14 分钟。

问题描述:

tomcat服务突然不可用 , 所有请求均不通 .

第一想法就是服务挂了. 登录服务器

查询tomcat进程, 服务还在运行中
- 服务运行中 , 但接口不可用 .
- 可以想到硬件到了极限 , CPU , 内存 , 日志(大日志文件占满服务器)

查询进程状态 . java占用内存超95%
- 死循环
- 大对象 map 或 list

查日志,确定问题所在
- 一个select查询, 查了几十万条数据,而且多次刷. 把内存占满了.
- 有日志就是好办事 .

下面是没有日志的问题定位方式 .使用jvm命令. 以下为我本地的模拟操作

还是前面的逻辑:

确定服务是否还在运行中

$ jps -l3408 org.apache.catalina.startup.Bootstrap9920 org.jetbrains.jps.cmdline.Launcher48928716 org.jetbrains.idea.maven.server.RemoteMavenServer9852 sun.tools.jps.Jps

可以看到 3408为tomcat进程, 可以列出来,说明服务没问题 . 在运行中.

进程的硬件状态

$ top PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND3408 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(
    
     )        .........

截取了线程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查询.查询了大量数据.没有做数据量限制.