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

2019独角兽企业重金招聘Python工程师标准>>>

问题描述:

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%

接下去思路:

1. 突然的情况 , 那么一定有操作. 先大胆的断定为接口异常. 先定位http请求的线程.
   • 大部分情况下,都是http线程的异常
2. 如果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查询.查询了大量数据.没有做数据量限制.

• 过千数据不应当在接口中查询
• 参数校验一定要到位
• 日志很重要, 日志输出也要合理. 不能大量输出

问题定位结束 .

转载于:https://my.oschina.net/ElEGenT/blog/2243642