SpringBoot线上服务假死，CPU内存正常，什么情况？

背景

开发小伙伴都知道线上服务挂掉，基本都是因为cpu或者内存不足，出现GC频繁OOM之类的情况。本篇文章区别以上的情况给小伙伴们带来不一样的服务挂掉。

还记得哔哩哔哩713事故中那场诡计多端的0吗？

对就是这个0，和本次事故没关系，但深受启发。

问题排查

老规矩在集群环境中同一个服务几个节点无响应。如不及时解决会可能形成雪崩效应。

优先查看服务日志是否有报错，礼貌习惯性查看服务cpu及内存情况。先复习下，若服务无报错。cpu或内存出现异常，按如下步骤排查。

常规排查

1、查看服务进程中线程情况

top -H -p pid
或
ps -mp pid -o THREAD,tid,time

2、查看系统异常线程16进制

printf “%x\n” nid

3、查看异常线程堆栈信息

jstack pid | grep number

查看占用最大内存对象前一百

jmap -histo pid|head -100

导出到文件

jstack -l PID >> a.log

或dump信息使用工具Mat或JProfiler查看

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

经过上面一通手法操作，足以解决此类常规报错了，通常大多是原因各种循环递归、或数据库慢查询等。

Mat使用

在MAT中，会有两种大小表示：

Shallow Size：表示对象自身占用的内存大小，不包括它引用的对象。
Retained size：当前对象内存大小+当前对象直接或间接引用的对象大小，全部的总和，简单理解，就是当前对象被GC后，总共能释放的内存大小。

Histogram视图

以Class Name为维度，分别展示各个类的对象数量。它默认是以byte为单位的，

要显示让单位展示出来，点击Window->Preferences选择最后一项，点击Apply and Close

再重新打开Histogram视图，就会生效了。

Leak Suspects

报表很直观地展现了一个饼图，图中颜色深的部分表示可能存在内存泄漏的嫌疑。

通过这个指标可以快速定位内存泄漏地方出现在哪个类方法里的哪行代码。

本次问题排查

1、信息收集分析

因服务健康监测无响应，cpu及内存情况正常，直接查看堆栈信息，看看线程都在干什么

jstack -l PID >> a.log

Jstack的输出中，Java线程状态主要是以下几种：

RUNNABLE 线程运行中或I/O等待
BLOCKED 线程在等待monitor锁(synchronized关键字)
TIMED_WAITING 线程在等待唤醒，但设置了时限
WAITING 线程在无限等待唤醒

发现都是WAITING线程。

"http-nio-8888-exec-6666" #8833 daemon prio=5 os_prio=0 tid=0x00001f2f0016e100 nid=0x667d waiting on condition [0x00002f1de3c5200]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for  <0x00000007156a29c8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
at com.alibaba.druid.pool.DruidDataSource.takeLast(DruidDataSource.java:1897)
at com.alibaba.druid.pool.DruidDataSource.getConnectionInternal(DruidDataSource.java:1458)
at com.alibaba.druid.pool.DruidDataSource.getConnectionDirect(DruidDataSource.java:1253)
at com.alibaba.druid.filter.FilterChainImpl.dataSource_connect(FilterChainImpl.java:4619)
at com.alibaba.druid.filter.stat.StatFilter.dataSource_getConnection(StatFilter.java:680)
at com.alibaba.druid.filter.FilterChainImpl.dataSource_connect(FilterChainImpl.java:4615)
at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:1231)
at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:1223)
at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:90)
at com.baomidou.dynamic.datasource.ds.ItemDataSource.getConnection(ItemDataSource.java:56)
at com.baomidou.dynamic.datasource.ds.AbstractRoutingDataSource.getConnection(AbstractRoutingDataSource.java:48)
at org.springframework.jdbc.datasource.DataSourceUtils.doGetConnection(DataSourceUtils.java:111)
at org.springframework.jdbc.datasource.DataSourceUtils.getConnection(DataSourceUtils.java:77)
at org.mybatis.spring.transaction.SpringManagedTransaction.openConnection(SpringManagedTransaction.java:82)
at org.mybatis.spring.transaction.SpringManagedTransaction.getConnection(SpringManagedTransaction.java:68)
at org.apache.ibatis.executor.BaseExecutor.getConnection(BaseExecutor.java:336)
at org.apache.ibatis.executor.SimpleExecutor.prepareStatement(SimpleExecutor.java:84)
at org.apache.ibatis.executor.SimpleExecutor.doQuery(SimpleExecutor.java:62)
at org.apache.ibatis.executor.BaseExecutor.queryFromDatabase(BaseExecutor.java:324)
at org.apache.ibatis.executor.BaseExecutor.query(BaseExecutor.java:156)
at org.apache.ibatis.executor.CachingExecutor.query(CachingExecutor.java:109)
at com.github.pagehelper.PageInterceptor.intercept(PageInterceptor.java:143)
at org.apache.ibatis.plugin.Plugin.invoke(Plugin.java:61)
at com.sun.proxy.$Proxy571.query(Unknown Source)

2、定位关键信息，追踪源代码

  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
  at com.alibaba.druid.pool.DruidDataSource.takeLast(DruidDataSource.java:1897)

DruidConnectionHolder takeLast() throws InterruptedException, SQLException {
try {
while (poolingCount == 0) {
emptySignal(); // send signal to CreateThread create connection

              if (failFast && isFailContinuous()) {
                  throw new DataSourceNotAvailableException(createError);
              }

              notEmptyWaitThreadCount++;
              if (notEmptyWaitThreadCount > notEmptyWaitThreadPeak) {
                  notEmptyWaitThreadPeak = notEmptyWaitThreadCount;
              }
              try {
                  // 数据库的连接都没有释放且被占用，连接池中无可用连接，导致请求被阻塞
                  notEmpty.await(); // signal by recycle or creator
              } finally {
                  notEmptyWaitThreadCount--;
              }
              notEmptyWaitCount++;

              if (!enable) {
                  connectErrorCountUpdater.incrementAndGet(this);
                  throw new DataSourceDisableException();
              }
          }
      } catch (InterruptedException ie) {
          notEmpty.signal(); // propagate to non-interrupted thread
          notEmptySignalCount++;
          throw ie;
      }

      decrementPoolingCount();
      DruidConnectionHolder last = connections[poolingCount];
      connections[poolingCount] = null;

      return last;
}

结合日志报错定位到问题代码。因报错可用连接没有正常释放，导致一直await卡死。

问题代码如下：

try {
  SqlSession sqlSession = sqlSessionFactory.openSession(ExecutorType.BATCH);
  TestMapper mapper = sqlSession.getMapper(TestMapper.class);
  mapper.insetList(list);
  sqlSession.flushStatements();
} catch (Exception e) {
   e.printStackTrace();
}

问题复现

按照以上信息在多活环境复现。因线程被打满且都在等待导致监控检查无响应。

tomcat线程被打满：

tomcat默认参数：

最大工作线程数，默认200。

server.tomcat.max-threads=200

最大连接数默认是10000

server.tomcat.max-connections=10000

等待队列长度，默认100。

server.tomcat.accept-count=100

最小工作空闲线程数，默认10。

server.tomcat.min-spare-threads=100

Druid连接池的默认参数如下：

Druid连接池的配置参数如下：

解决

1、Druid连接池的配置超时参数

spring: 
  redis:
    host: localhost
    port: 6379
    password: 
  datasource:
    druid:
      stat-view-servlet:
        enabled: true
        loginUsername: admin
        loginPassword: 123456
    dynamic:
      druid:
        initial-size: 5
        min-idle: 5
        maxActive: 20
        maxWait: 60000
        timeBetweenEvictionRunsMillis: 60000
        minEvictableIdleTimeMillis: 300000
        validationQuery: SELECT 1 FROM DUAL
        testWhileIdle: true
        testOnBorrow: false
        testOnReturn: false
        poolPreparedStatements: true
        maxPoolPreparedStatementPerConnectionSize: 20
        filters: stat,slf4j,wall
        connectionProperties: druid.stat.mergeSql\=true;druid.stat.slowSqlMillis\=5000

2、异常及时关闭连接

sqlSession.close();

SpringBoot假死，十万火急，怎么救火？ (qq.com)

- 前言

- 线上SpringBoot假死，十万火急的现象

- 10大造成假死的可能原因

- 尼恩五板斧分析方法

- 第一板斧：查日志

- 第二板斧：查系统资源

- step1：弄清楚CPU资源的家底（到底多少CPU Cores核数）

- step2：查所有CPU core的使用情况

- 查看进程使用cpu的情况

- 然后，查内存资源

- step3：查IO

- iostat命令查IO的

- iostat命令参数

- iotop查询进程磁盘I/O

- step4：查网络

- 使用nload查看网络

- 使用iftop查看网络

- 第三斧：查JVM线程死锁

- 1、查看服务进程中线程情况

- 2、查看系统异常线程16进制

- 3、查看异常线程堆栈信息

- 4、分析线程的死锁

- 第四板斧：查JVM堆栈

- 内存溢出与内存泄漏：

- 内存溢出的可能原因排查

- 四种内存溢出的场景

- 一、堆溢出

- 二、栈溢出

- 三、方法区溢出

- 四、直接内存溢出

- 内存溢出总结：

- 内存溢出与内存泄漏的排查

- step1：jps 获取进程id

- step2：jstat 查看GC 统计信息

- step3: 内存泄漏与大对象的分析

- 类型一：轻量级的内存泄漏与大对象在线分析：

- 第一步：jmap 查看进程中占用资源最大的前N个对象，

- 第二步：使用 Arthas 定位大对象的所在的代码

- 类型二：重量量级的内存泄漏与大对象在线分析：

- 第五板斧：查操作系统配置

- 线上案例1：OOM导致假死

- 现象

- 特别说明：发生OOM了JVM并不一定挂

- 事故现场

- 问题定位

- 线上案例2：操作系统线程数不够导致假死

- 现象

- 排查过程

- a.内存状态查询

- b.内存快照导出

- c.栈信息导出

- d.内存信息查看

- e. ulimit查看

- 3.解决办法

- 1.清除页缓存

- 2.ulimit配置调整

- 线上案例3：请求处理速度慢，导致假死

- 背景描述：

- 排查过程：

- 第一步：查看日志、系统资源、jvm内存

- 第二步，查看服务对应的端口的情况。

- 第三步，TCP连接队列打满导致假死

- 解决方案：

- 线上案例4：log输出到控制台导致假死

- 问题：文件下载卡死

- 分析过程

- 解决方案

- 结论

- 线上案例5：Server端CLOSE_WAIT 线上假死

- 问题定位

- 问题排查

- SpringBoot线上服务假死解决，CPU内存正常

- 问题排查

- 1、信息收集分析

- 2、定位关键信息，追踪源代码

- 问题复现

- 解决

- 1、Druid连接池的配置超时参数

- 2、异常及时关闭连接

- SpringBoot假死检测与自愈

- 当SpringBoot发生oom时自动退出

- 配置进行假死检测与自愈

- 最后的一些成熟的建议

- JVM相关的启动参数

- 参考文献

- 《Java 调优圣经》迭代计划

- 推荐阅读

- 免费领取11个技术圣经 PDF

线上SpringBoot假死，十万火急的现象

SpringBoot应用会出现无法访问的情况。具体的表现有3点：

表现1. 客户端请求没有任何响应；
表现2. 请求时, 没有任何日志输出；
表现3. SpringBoot进程是存活的

表现1. 客户端请求没有任何响应；

如果有前端请求，表现为pengding。

如果是RPC Client 调用，表现为连接超时

表现2. 请求时, 没有任何日志输出；查看业务日志的时，发现日志停止没有任何最新的访问日志。

表现3. SpringBoot进程是存活的

通过jps或者ps查看进程，可以看到服务进程存在；

假死判定：

如果有以上三种表现，基本可以确定为 SpringBoot进程假死.

10大造成假死的可能原因

java线程出现死锁，或所有线程被阻塞；
数据库连接池中的连接耗尽，导致获取数据库连接时永久等待；
出现了内存泄漏导致了OutOfMemory，内存空间不足导致分配内存空间持续失败；服务器的可用内存足够，但是分配给jvm的内存被耗尽的情况，容易出现这种情况；
服务程序运行过程中替换了jar包，但是没有进行重启服务，这属于不按规则操作引起的问题；
磁盘空间满，导致需要写数据的地方全部失败；

客户端端收到 500，连接超时
线程池满，无法分配更多的线程来处理请求，通常是因为线程被大量阻塞在某个请求上；

客户端连接超时

尼恩五板斧分析方法

造成SpringBoot无法继续进行业务处理的情况有很多，所以需要多方面的进行一一排查。

第一板斧：查日志
第二板斧：查系统资源
第三板斧：查JVM线程死锁
第四板斧：查JVM堆栈
第五板斧：查操作系统配置

第一板斧：查日志

首先检查服务运行情况，判定业务无法处理的表面原因，是否为SpringBoot假死还是业务异常。

查看项目日志，排查是否有明显的错误情况，针对错误情况处理。

查本地log日志
或者elk的分布式日志

错误信息，非常重要。一般能分析出问题的 70%的原因。

如果有多个节点的服务，可以保留一个节点的状态，用于故障原因分析和查找，另外的节点通过重启服务，来尽快恢复正常服务；

第二板斧：查系统资源

看服务所在机器的网络、磁盘、CPU等进行逐一排查。

首先查CPU资源

step1：弄清楚CPU资源的家底（到底多少CPU Cores核数）

物理cpu数：主板上实际插入的cpu数量，可以数不重复的 physical id 有几个（physical id）
cpu核数：单块CPU上面能处理数据的芯片组的数量，如双核、四核等（cpu cores）
逻辑cpu数：简单来说，它可使处理器中的1颗内核，如2颗内核那样在操作系统中发挥作用。

这样一来，操作系统可使用的执行资源扩大了一倍，大幅提高了系统的整体性能，此时逻辑cpu=物理CPU个数×每颗核数x2。

总核数 = 物理CPU个数 × 每颗物理CPU的核数。

总逻辑CPU数 = 物理CPU个数 ×每颗物理CPU的核数 × 超线程数。

所以这算双核的。

# 查看CPU信息（型号）
cat /proc/cpuinfo | grep name | cut -f2 -d: | uniq -c
# 查看物理CPU个数
 cat /proc/cpuinfo| grep "physical id"| sort| uniq| wc -l
# 查看每个物理CPU中core的个数(即核数)
 cat /proc/cpuinfo| grep "cpu cores"| uniq
# 查看逻辑CPU的个数
cat /proc/cpuinfo| grep "processor"| wc -l

前面有个公式：总逻辑CPU数 = 物理CPU个数 ×每颗物理CPU的核数 × 超线程数。

这个还有一个指标：超线程数。那么 centos7查看是否超线程？

cat /proc/cpuinfo | grep -e "cpu cores"  -e "siblings" | sort | uniq

计算是否开启超线程

逻辑CPU > 物理CPU x CPU核数（开启超线程）
逻辑CPU = 物理CPU x CPU核数（没有开启超线程或不支持超线程）
如果cpu cores数量和siblings数量一致，则没有启用超线程，否则超线程被启用。

从上面执行的结果来看，尼恩的虚拟机没有开启超线程。

尼恩的虚拟机使用的cpu有1 * 4= 4核，每个核有1个超线程，所以有4个逻辑cpu 内核。

step2：查所有CPU core的使用情况

查看所有CPU的使用情况。

mpstat -P ALL 1

%dile 即为空闲CPU比例
%iowait 即为%wa
%iowait% 则表示等待 I/O 的 CPU的时间百分比

CPU没有满就算了。

如果 CPU很满，再查看进程使用cpu的情况

查看进程使用cpu的情况

top命令，查看进程使用cpu的情况

top

ps aux|sort -nr -k3|head -10 命令，查看进程使用cpu的情况

ps aux|sort -nr -k3|head -10

很容易很找到占用CPU很高的进程。然后再进一步分析。

然后，查内存资源

free -m 看整体内存使用情况。判断内存有没有打满。

显示内存信息，以兆为单位，输出信息如下：

$free -m

top命令，也查看进程级别使用 memory 的情况

top

step3：查IO

判断IO有没有打满。

iostat命令查IO的

iostat可以给我们提供丰富的IO状态数据

iostat命令参数

iostat [选项] [<时间间隔>] [<次数>]

-c： 显示CPU使用情况
-d： 显示磁盘使用情况
-N： 显示磁盘阵列(LVM) 信息
-n： 显示NFS 使用情况
-k： 以 KB 为单位显示
-m： 以 M 为单位显示
-t： 报告每秒向终端读取和写入的字符数和CPU的信息
-V： 显示版本信息
-x： 显示详细信息
-p：[磁盘] 显示磁盘和分区的情况

CPU使用统计信息： 用户进程使用率、系统使用率、空闲率等；且以下指标加起来和为1

%user：CPU处在用户模式下的时间百分比。
%nice：CPU处在带NICE值的用户模式下的时间百分比。
%system：CPU处在系统模式下的时间百分比。
%iowait：CPU等待输入输出完成时间的百分比。如果%iowait的值过高，表示硬盘存在I/O瓶颈
%steal：管理程序维护另一个虚拟处理器时，虚拟CPU的无意识等待时间百分比。
%idle：CPU空闲时间百分比。%idle值高，表示CPU较空闲，如果%idle值高但系统响应慢时，有可能是CPU等待分配内存，此时应加大内存容量。%idle值如果持续低于10，那么系统的CPU处理能力相对较低，表明系统中最需要解决的资源是CPU。

块设备I/O统计信息： 每秒读写的数据量、总读写数据量等。

读指标：

r/s: 每秒完成的读 I/O 设备次数。即 rio/s，这个大可能说明很多随机IO
rkB/s: 每秒读K字节数。是 rsect/s 的一半，因为每扇区大小为512字节。
rrqm/s: 每秒进行 merge 的读操作数目。即 rmerge/s
%rrqm：在发送到设备之前合并到一起的读请求的百分比。
r_await：每个读操作平均所需的时间，重点关注，对于HDD，高于20ms可能就请求太多，导致排队了，因为正常一次寻道也就10ms。
rareq-sz：向设备发出的读请求的平均大小(单位为 k)

写指标：

w/s: 每秒完成的写 I/O 设备次数。即 wio/s
wkB/s: 每秒写K字节数。是 wsect/s 的一半。
wrqm/s: 每秒进行 merge 的写操作数目。即 wmerge/s
%wrqm：在发送到设备之前合并到一起的写请求的百分比。
w_await：平均每次写请求的时间(以毫秒为单位)。这包括请求在队列中花费的时间和执行它们所花费的时间。重点关注，对于HDD，高于20ms可能就请求太多，导致排队了，因为正常一次寻道也就10ms。
wareq-sz：向设备发出的写请求的平均大小(单位为 k)。

抛弃指标：

d/s：每秒设备完成的抛弃请求数（合并后）。
dkB/s：从设备中每秒抛弃的kB数量
drqm/s: 每秒排队到设备中的合并抛弃请求的数量
%drqm:抛弃请求在发送到设备之前已合并在一起的百分比。
d_await: 发出要服务的设备的抛弃请求的平均时间（以毫秒为单位）。这包括队列中的请求所花费的时间以及为请求服务所花费的时间。
dareq-sz: 发出给设备的抛弃请求的平均大小（以千字节为单位）。

其它指标：

aqu-sz: 发出到设备的请求的平均队列长度。注意：在以前的版本中，此字段称为avgqu-sz。这个指标高需要重点关注，可能IO太多，需要等待
%util: 一秒中有百分之多少的时间用于 I/O 操作，即被io消耗的cpu百分比，向设备发出I/O请求的经过时间百分比（设备的带宽利用率）。当串行服务请求的设备的该值接近100％时，将发生设备饱和。但是对于并行处理请求的设备（例如RAID阵列和现代SSD），此数字并不反映其性能限制。这个指标高说明IO基本上就到瓶颈了，但是低也不一定IO就不是瓶颈。一般%util大于70%,I/O压力就比较大.

同时可以结合vmstat查看查看b参数(等待资源的进程数)和wa参数(I/O等待所占用的CPU时间的百分比,高过30%时I/O压力高)

iotop查询进程磁盘I/O

iotop 是一个类似 top 的工具，用来显示实时的磁盘活动。

iotop 监控 Linux 内核输出的 I/O 使用信息，并且显示一个系统中进程或线程的当前 I/O 使用情况。

iotop 是一个类似 top 的工具，用来显示实时的磁盘活动。

iotop 监控 Linux 内核输出的 I/O 使用信息，并且显示一个系统中进程或线程的当前 I/O 使用情况。

它显示每个进程/线程读写 I/O 带宽。它同样显示当等待换入和等待 I/O 的线程/进程花费的时间的百分比。

Total DISK READ 和 Total DISK WRITE 的值一方面表示了进程和内核线程之间的总的读写带宽，另一方面也表示内核块设备子系统的。

Actual DISK READ 和 Actual DISK WRITE 的值表示在内核块设备子系统和下面硬件（HDD、SSD 等等）对应的实际磁盘 I/O 带宽。

iotop命令参数使用

-o, --only只显示正在产生I/O的进程或线程。除了传参，可以在运行过程中按o生效。
-b, --batch非交互模式，一般用来记录日志。
-n NUM, --iter=NUM设置监测的次数，默认无限。在非交互模式下很有用。
-d SEC, --delay=SEC设置每次监测的间隔，默认1秒，接受非整形数据例如1.1。
-p PID, --pid=PID指定监测的进程/线程。
-u USER, --user=USER指定监测某个用户产生的I/O。
-P, --processes仅显示进程，默认iotop显示所有线程。
-a, --accumulated显示累积的I/O，而不是带宽。
-k, --kilobytes使用kB单位，而不是对人友好的单位。在非交互模式下，脚本编程有用。
-t, --time 加上时间戳，非交互非模式。
-q, --quiet 禁止头几行，非交互模式。有三种指定方式。
-q 只在第一次监测时显示列名
-qq 永远不显示列名。
-qqq 永远不显示I/O汇总。

交互按键，和top命令类似，iotop也支持以下几个交互按键。

left和right方向键：改变排序。  
r：反向排序。
o：切换至选项--only。
p：切换至--processes选项。
a：切换至--accumulated选项。
q：退出。
i：改变线程的优先级。

命令例子：

 #时间刷新间隔2秒，输出5次
 iotop  -d 2 -n 5

#非交互式，输出pid为 1404  的进程信息，这里示例1404 为nginx进程
 iotop -botq -p 1404

可以看到读磁盘的速率，写入的速率

查看各个磁盘的IO情况。

kB_read/s：每秒从设备（drive expressed）读取的数据量；
kB_wrtn/s：每秒向设备（drive expressed）写入的数据量；
kB_read：读取的总数据量；
kB_wrtn：写入的总数量数据量；这些单位都为Kilobytes。

查看各个磁盘的 await 和 util。

iostat -dx 1|awk '{print $1"\t"$10"\t"$11"\t"$12}'

step4：查网络

网络使用情况也是监控的重要指标。

当带宽不足时会大大增加请求的响应时间。

为了防止突发性并发压力，应该保证服务器的带宽使用率在80%以上。

这里需要注意的是，物理网卡限制了服务器所能使用的最大宽带。

使用nload查看网络

首先需要安装nload，以centos为例

yum install nload -y

安装完成后我们直接运行nload

nload

输入nload命令后，网络使用情况如上图所示。

其中，网络使用情况分为流入网卡的数据与流出网卡的数据。

Incoming 流入网卡的对应下行带宽的网速，
Outgoing流出网卡的数据对应上行带宽的网速。

如果 “当前网速” 持续接近 “最大网速” 时，代表带宽使用率已经接近100%。

指标说明：

Curr：当前网速
Avg：平均网速
Min：最小网速
Max：最大网速
Ttl：总流量

使用iftop查看网络

如还不满意可用iftop

使用iftop命令，CentOS系统下使用yum install iftop -y进行安装

iftop命令的界面如下：

iftop -P （可动态展示所有有流量的连接，包含端口解析）

-i：指定需要监测的网卡
-n：将输出的主机信息都通过IP显示，不进行DNS反向解析
-B：将输出以bytes为单位显示网卡流量，默认是bits
-p：以混杂模式运行iftop，此时iftop可以作为网络嗅探器使用
-N：只显示连接端口号，不显示端口对应的服务名称
-P：显示主机以及端口信息，这个参数非常有用
-F：显示特定网段的网卡进出流量
-m：设置iftop输出界面中最上面的流量刻度最大值，流量刻度分五个大段显示

界面上面显示的是类似刻度尺的刻度范围，为显示流量图形的长条作标尺用的。

#"TX"：从网卡发出的流量
#"RX"：网卡接收流量
#"TOTAL"：网卡发送接收总流量
#"cum"：iftop开始运行到当前时间点的总流量
#"peak"：网卡流量峰值
#"rates"：分别表示最近2s、10s、40s 的平均流量

iftop交互式参数：

参数      含义
P        暂停/继续 (Display unpaused/paused )
h        帮助/显示（help / Display）
b        平均流量刻度条开关 （Bars on/off）
B        2s、10s、40s内的平均流量 （Bars show 2s/10s/40s average）
T        显示/隐藏每个连接的总流量（ show / hide cumulative totals）
j/k      上移/下滚（通vi hjkl 左上下右）
l        过滤 （screen filter > IP、主机名或端口支持模糊查询  ctrl+删除键回退）
L        对数尺度、计算尺;  直线标度、线性标尺  (logarithmic scale && linear scale)==加个进度条比例不同
q        退出（quit）
n        DNS解析开关（DNS resolution off/on）主要看hosts 文件有无
s/d      显示源/目的主机信息  show/hide  source/dest host
S/D      显示源/目的端口信息  port display  dest/source或on
t        仅显示接收流量。received traffic only ， 仅显示发送流量 sent traffic only，接收发送同时显示  two line per host 接收发送合并显示 one line per host
N        端口号及对应服务名称切换，只识别通用端口修改后不显示服务。port resolution on/off
p        全量显示/关闭端口信息   (port display off/on)
1/2/3    根据近2 秒、10 秒、40 秒的平均网络流量排序  sort by col 1/2/3
<        根据源ip/主机名排序 （sort by  source）
>        根据目的地址ip或主机名排序 (sort by dest)
o        冻结当前连接显示  order frozen/unfrozen

第三斧：查JVM线程死锁

重点分析是否线程被阻塞在某个位置了

通过jstack -F pid查找线程死锁，导出线程堆栈，然后查看线程状态；

1、查看服务进程中线程情况

top -H -p pid

top -H -p 1293

或

ps -mp pid -o THREAD,tid,time

ps -mp  1293 -o THREAD,tid,time

2、查看系统异常线程16进制

printf “%x\n” nid

3、查看异常线程堆栈信息

jstack pid | grep number

例如：
jstack 1293 | grep 100
jmap -histo 1293|head -100

导出到文件

jstack -l PID >> a.log

4、分析线程的死锁

尼恩提示：如何分析线程的死锁, 操作的步骤比较繁琐。具体请看《调优圣经》视频。

《调优圣经》pdf 写完之后，配套视频，即将发布

第四板斧：查JVM堆栈

如果内存空闲空间充足，可以确定不是内存不足引起；
如果垃圾回收日志正常，包括年轻代和老年代，也基本可以确定不是内存不足引起；
通过查看内存中的对象实例和占用空间，如果没有特别大的情况，也基本可以确定不是内存不足引起；
排除了内存不足的原因，可能发生了内存泄漏，需要进行内存泄漏排查；

所以，核心还是排查内存溢出与内存泄漏。

内存溢出与内存泄漏：

内存溢出：申请内存空间，超出最大堆内存空间。
内存泄露：其实包含了内存溢出，堆内存空间被无用对象占用没有及时释放，导致占用内存，最终导致内存泄露。

内存溢出的可能原因排查

内存溢出是由于没被引用的对象（垃圾）过多造成JVM没有及时回收，造成的内存溢出。如果出现这种现象可进行代码排查：

（1）是否应用中的类中和引用变量过多使用了Static修饰，如 public staitc Students；

在类中的属性中使用 static 修饰的最好只用基本类型或字符串。如：public static int i = 0; public static String str;

（2）是否应用中使用了大量的递归或无限递归（递归中用到了大量的建新的对象）

（3）是否App中使用了大量循环或死循环（循环中用到了大量的新建的对象）

（4）检查应用中是否使用了向数据库查询所有记录的方法。即一次性全部查询的方法，如果数据量超过10万多条了，就可能会造成内存溢出。所以在查询时应采用“分页查询”。

（5）检查是否有数组，List，Map中存放的是对象的引用而不是对象，因为这些引用会让对应的对象不能被释放，会大量存储在内存中。

（6）检查是否使用了“非字面量字符串进行+”的操作。

因为String类的内容是不可变的，每次运行"+"就会产生新的对象，如果过多会造成新String对象过多，从而导致JVM没有及时回收而出现内存溢出。

四种内存溢出的场景

栈溢出(StackOverflowError)
堆溢出(OutOfMemoryError:Java heap space)
永久代溢出(OutOfMemoryError: PermGen space)
直接内存溢出

一、堆溢出

创建对象时如果没有可以分配的堆内存，JVM就会抛出OutOfMemoryError:java heap space异常。

堆溢出实例：

/**
 * VM Args: -Xms20m -Xmx20m -XX:+HeapDumpOnOutOfMemoryError
 */
public static void main(String[] args) {
    List<byte[]> list = new ArrayList<>();
    int i=0;
    while(true){
        list.add(new byte[5*1024*1024]);
        System.out.println("分配次数："+(++i));
    }
}

运行结果：

分配次数：1
分配次数：2
分配次数：3

java.lang.OutOfMemoryError: Java heap space
Dumping heap to java_pid2464.hprof ...
Heap dump file created [16991068 bytes in 0.047 secs]

Exception in thread "main" java.lang.OutOfMemoryError: Java heap space
    at com.ghs.test.OOMTest.main(OOMTest.java:16)

附：dump文件会在项目的根目录下生成

从上面的例子我们可以看出，在进行第4次内存分配时，发生了内存溢出。

二、栈溢出

栈空间不足时，需要分下面两种情况处理：

线程请求的栈深度大于虚拟机所允许的最大深度，将抛出StackOverflowError
虚拟机在扩展栈深度时无法申请到足够的内存空间，将抛出OutOfMemberError

附：当前大部分的虚拟机栈都是可动态扩展的。

下面是一个案例

public class StackSOFTest {

    int depth = 0;

    public void sofMethod(){
        depth ++ ;
        sofMethod();
    }

    public static void main(String[] args) {
        StackSOFTest test = null;
        try {
            test = new StackSOFTest();
            test.sofMethod();
        } finally {
            System.out.println("递归次数："+test.depth);
        }
    }
}

执行结果:

递归次数：982
Exception in thread "main" java.lang.StackOverflowError
    at com.ghs.test.StackSOFTest.sofMethod(StackSOFTest.java:8)
    at com.ghs.test.StackSOFTest.sofMethod(StackSOFTest.java:9)
    at com.ghs.test.StackSOFTest.sofMethod(StackSOFTest.java:9)
……后续堆栈信息省略

三、方法区溢出

方法区存放Class的相关信息，下面借助CGLib直接操作字节码，生成大量的动态类。

public class MethodAreaOOMTest {

    public static void main(String[] args) {
        int i=0;
        try {
            while(true){
                Enhancer enhancer = new Enhancer();
                enhancer.setSuperclass(OOMObject.class);
                enhancer.setUseCache(false);
                enhancer.setCallback(new MethodInterceptor() {
                    @Override
                    public Object intercept(Object obj, Method method, Object[] args, MethodProxy proxy) throws Throwable {
                        return proxy.invokeSuper(obj, args);
                    }
                });
                enhancer.create();
                i++;
            }
        } finally{
            System.out.println("运行次数："+i);
        }
    }

    static class OOMObject{

    }
}

运行结果:

运行次数：56
Exception in thread "main" 
Exception: java.lang.OutOfMemoryError thrown from the UncaughtExceptionHandler in thread "main"

四、直接内存溢出

DirectMemory可以通过-XX:MaxDirectMemorySize指定，

如果不指定，默认与Java堆的最大值(-Xmx指定)一样。

如何模拟直接内存溢出？ NIO会使用到直接内存，你可以通过NIO来模拟，

在下面的例子中，跳过NIO，直接使用UnSafe来分配直接内存。

public class DirectMemoryOOMTest {

    /**
     * VM Args:-Xms20m -Xmx20m -XX：MaxDirectMemorySize=10m
     * @param args
     */
    public static void main(String[] args) {
        int i=0;
        try {
            Field field = Unsafe.class.getDeclaredFields()[0];
            field.setAccessible(true);
            Unsafe unsafe = (Unsafe) field.get(null);
            while(true){
                unsafe.allocateMemory(1024*1024);
                i++;
            }
        } catch (Exception e) {
            e.printStackTrace();
        }finally {
            System.out.println("分配次数："+i);
        }
    }
}

运行结果：

Exception in thread "main" java.lang.OutOfMemoryError
    at sun.misc.Unsafe.allocateMemory(Native Method)
    at com.ghs.test.DirectMemoryOOMTest.main(DirectMemoryOOMTest.java:20)
分配次数：27953

内存溢出总结：

栈内存溢出：程序所要求的栈深度过大。
堆内存溢出：分清内存泄露还是内存容量不足。泄露则看对象如何被 GC Root 引用，不足则通过调大-Xms，-Xmx参数。
永久代溢出：Class对象未被释放，Class对象占用信息过多，有过多的Class对象。
直接内存溢出：系统哪些地方会使用直接内存。

内存溢出与内存泄漏的排查

大概会用到下面的工具

通过jstat查看内存使用和垃圾回收情况，查看内存占用情况以及垃圾回收情况是否异常；

jstat 是JDK中提供的一个命令行工具，主要用来打印JVM 性能数据相关的统计数据。

主要包含以下几个方面：垃圾回收(GC)方面数据、编译(Compilation)相关数据、类加载信息(Class Loader)

jstat 最大的优势就是可以在JVM运行时，实时的抓取这些数据。

使用jstack我们能够生成虚拟机当前时刻的线程快照，包含虚拟机中每一个线程正在执行的方法堆栈的集合，用于定位线程出现长时间停顿的原因，如死锁、死循环、外部资源长时间等待等
通过jmap -heap查看内存分配情况，查看是否内存空间被占满，导致无法分配足够的内存空间；

有时候，光看线程快照是不够的。

需要更加进一步的观察到对象实例，此时我们可以使用jmap命令。

Jmap 可以用来查看内存信息，实例个数以及占用内存大小.

jmap -histo[:live] 打印每个class的实例数目,内存占用,类全名信息.

注意：VM的内部类名字开头会加上前缀”*”. 如果子参数加上live后,只统计活的对象数量.
通过gclog查看垃圾回收原因，需要在服务启动时指定记录垃圾回收日志；
Arthas 线上排查

大概的步骤：

step1： jps 获取进程id

使用jps找出这个进程在本地虚拟机的唯一ID，因为在后面的排查过程中都是需要这个LVMID来确定要监控的是哪一个虚拟机进程。
命令格式为：

jps [ options ] [ hostid ]

常用jps -l。

step2：jstat 查看GC 统计信息

查看已使用空间站总空间的百分比.
命令格式：jstat [ option vmid [interval[s|ms] [count]] ]

例子

jstat -gcutil 20954 1000

gcutil指：已使用空间站总空间的百分比。
20954指：pid
1000指：每1000毫秒查询一次，一直查。

新生代Eden区（E，表示Eden）使用了97.14%的空间，

两个Survivor区（S0、S1，表示Survivor0、Survivor1）分别是64.38%和0%，

老年代（O，表示Old）使用了29.07%。

程序运行以来共发生Minor GC（YGC，表示Young GC）32次，总耗时1.016秒，

发生Full GC（FGC，表示Full GC）3次，Full GC总耗时0.4秒，

总的耗时（GCT，表示GC Time）为1.416秒。

step3: 内存泄漏与大对象的分析

分析方法通常有两种：

类型一：轻量级的在线分析：

第一步：jmap 查看进程中占用资源最大的前N个对象，

第二步：知道哪个对象消耗内存了，再去定位代码就不难了。

类型二：重量级的离线分析：

使用“Java内存影像工具：jmap”生成堆转储快照（一般称为headdump或dump文件）。

把堆dump下来再用MAT等工具进行分析，但dump堆要花较长的时间，并且文件巨大，再从服务器上拖回本地导入工具，这个过程有些折腾，不到万不得已最好别这么干。

类型一：轻量级的内存泄漏与大对象在线分析：

第一步：jmap 查看进程中占用资源最大的前N个对象，

jmap命令格式：jmap [ option ] vmid

使用命令如下： jmap -histo:live 1293

jmap 查看进程中占用资源最大的前20个对象，

jmap -histo pid|head -N

例如：
jmap -histo 1293|head -20

这里会有自己工程内的类的大对象，第四列为类名。

第二步：使用 Arthas 定位大对象的所在的代码

Arthas 是 Alibaba 在 2018 年 9 月开源的 Java 诊断工具。支持 JDK6+，采用命令行交互模式，提供 Tab 自动不全，可以方便的定位和诊断线上程序运行问题。截至本篇文章编写时，已经收获 Star 17000+。

Arthas 官方文档十分详细，本文也参考了官方文档内容，同时在开源在的 Github 的项目里的 Issues 里不仅有问题反馈，更有大量的使用案例，也可以进行学习参考。

开源地址：https://github.com/alibaba/arthas

官方文档：https://alibaba.github.io/arthas

得益于 Arthas 强大且丰富的功能，让 Arthas 能做的事情超乎想象。

下面仅仅列举几项常见的使用情况，更多的使用场景可以在熟悉了 Arthas 之后自行探索。

是否有一个全局视角来查看系统的运行状况？
为什么 CPU 又升高了，到底是哪里占用了 CPU ？
运行的多线程有死锁吗？有阻塞吗？
程序运行耗时很长，是哪里耗时比较长呢？如何监测呢？
这个类从哪个 jar 包加载的？为什么会报各种类相关的 Exception？
我改的代码为什么没有执行到？难道是我没 commit？分支搞错了？
遇到问题无法在线上 debug，难道只能通过加日志再重新发布吗？
有什么办法可以监控到 JVM 的实时运行状态？

下面列举一些 Arthas 的常用命令，

命令	介绍
dashboard	当前系统的实时数据面板
thread	查看当前 JVM 的线程堆栈信息
watch	方法执行数据观测
trace	方法内部调用路径，并输出方法路径上的每个节点上耗时
stack	输出当前方法被调用的调用路径
tt	方法执行数据的时空隧道，记录下指定方法每次调用的入参和返回信息，并能对这些不同的时间下调用进行观测
monitor	方法执行监控
jvm	查看当前 JVM 信息
vmoption	查看，更新 JVM 诊断相关的参数
sc	查看 JVM 已加载的类信息
sm	查看已加载类的方法信息
jad	反编译指定已加载类的源码
classloader	查看 classloader 的继承树，urls，类加载信息
heapdump	类似 jmap 命令的 heap dump 功能

尼恩提示：如何使用使用 Arthas 定位大对象的所在的代码, 操作的步骤比较繁琐。

如何使用使用 Arthas 定位大对象的所在的代码 ,具体请看《调优圣经》视频。

《调优圣经》pdf 写完之后，配套视频，即将发布

类型二：重量量级的内存泄漏与大对象在线分析：

使用 jmap或dump信息使用工具Mat或JProfiler或者 JVisualVM 分析

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

例如：
jmap -dump:live,format=b,file=/dump.bin 1293

尼恩提示：如何使用使用 jmap导出后，使用JVisualVM 分析定位大对象的所在的代码, 操作的步骤也比较繁琐。

如何使用使用 jmap 使用JVisualVM 分析定位大对象的所在的代码 ,具体请看《调优圣经》视频。

《调优圣经》pdf 写完之后，配套视频，即将发布

第五板斧：查操作系统配置

文件句柄数的限制
内存映射数的限制
线程数限制

等等

线上案例1：OOM导致假死

这个是来自互联网的案例，原文如下：

https://blog.csdn.net/weixin_42130396/article/details/126020231

现象

某一次生产事故，由于一次性从数据库查询过多数据，从而导致线程OOM：Java heap space 异常

注意数据规模：数据表的15W数据，JVM堆内存2G

线上的情况是：在线程OOM发生时，java进程却没有立即挂掉。

问题是，咱们常常说：发生OOM，程序就会挂。这里的情况是：发生OOM了，JVM没有挂。

特别说明：发生OOM了JVM并不一定挂

尼恩写了一个详细的文章进行了介绍：

美团一面：OOM后，JVM一定会退出吗？为什么？

事故现场

监控发现线上服务挂了一台，进程还在，springboot假死，

登录服务器查询日志发现了java.lang.OutOfMemoryError: GC overhead limit exceeded，

该错误表示：jvm使用大量的时间去做gc，但没有什么回收的效果(创建了大量大对象且不回收垃圾)。

异常日志中可以看到引发OOM的原因是hibernate 调用repository.findAll()导致的

问题定位

导出hprof文件到本地使用jdk自带的jvisualvm进行分析，

首先来看看有什么大对象吧

依然是导出hprof文件到本地使用jdk自带的jvisualvm进行分析，这次没有那么幸运可以直接通过点击跳转“查看导致 OutOfMemoryError 异常错误的线程”查到有用的线索，那就来看看有什么大对象吧

可以看到这个list.size竟然有159482，展开看看这个list都存着什么对象。

展开查看metadata——>fields——>fullName(或者tableName和columnName)，看看有没有熟悉的表和字段可以定位到是查询了哪个表的全部数据

到这里，已经排查出到了，是jpa查询了部门表的全部数据。

再结合该时间执行的定时任务，最终找到代码位置：

List<SysDepartmentMainData> departments = departmentMainDataRepository.findAll();

但是问题来了，部门数据怎么可能有15万多？

该项目中的部门表是定时任务，每天先清空表再同步公司主数据部门信息全量覆盖的。

该方法是加事务的，所以不会有清空表后但调用主数据接口失败导致表里没数据的情况。

查看公司主数据的部门表只有4千多，那这15万是怎么进来的？

那就要去看一下存表的代码逻辑了，果然发现了问题，以下是问题原因和最终修复

线上案例2：操作系统线程数不够导致假死

现象

监控发现线上服务挂了一台，进程还在，springboot假死，

但是，操作系统无异常

cpu、内存、io等全部正常

排查过程

a.内存状态查询

jstat -gcutil pid

没问题。

b.内存快照导出

sudo -u wwwroot `jmap -dump:live,format=b,file=heap001 pid`

上述命令导不出的时候，执行下面这条语句

sudo -u wwwroot `jmap -F -dump:live,format=b,file=heap001 pid`

没问题。

c.栈信息导出

sudo -u wwwroot `jstack pid > aaa.txt `

sudo -u wwwroot `jstack pid > aaa.txt `

d.内存信息查看

free

没问题。

e. ulimit查看

注意不同的用户情况

有问题。

线程数不够

解决办法

1.清除页缓存

echo 3 > /proc/sys/vm/drop_caches

2.ulimit配置调整

配置不合理存在的现象是：

1、程序无法进入

2、无任何异常日志

3、线程数和数据库连接数均不多

4、程序进程正常

1、查看命令：ulimit -a
2、修改vim /etc/security/limits.conf，添加或修改配置（可能之前已经存在），添加完成后关闭putty并重新连接通过ulimit -a查看是否生效

* soft nproc 35535
* hard nproc 65535
* soft nofile 35535
* hard nofile 65535

3、如果上述修改无法生效，尝试查看或修改vim /etc/security/limits.d/20-nproc.conf，内容同上
4、如果2、3均无法生效，联系运维排查无法生效问题

线上案例3：请求处理速度慢，导致假死

背景描述：

项目在运行过程中，突然无法处理新的请求。

来的tps都是几千几万，突然间所有机器都变为0了，对线上业务影响极大！

于是立即查看服务运行状况，但是还是在running中，于是可以认为是SpringBoot假死。

排查过程：

第一步：查看日志、系统资源、jvm内存

没有问题

第二步，查看服务对应的端口的情况。

使用命令netstat -anp ｜grep 端口号，可以查看该端口详细的情况，

如下，有协议类型、源ip+port、tcp协议状态等信息，这里主要关注tcp协议的连接数量和每条连接对应的状态。

 netstat -an |grep 80  
tcp4       0      0  192.168.31.24.51380    120.253.255.102.443    ESTABLISHED
tcp4       0      0  192.168.31.24.50935    192.30.71.80.443       ESTABLISHED
tcp4      31      0  192.168.31.24.50863    3.80.20.154.443        CLOSE_WAIT 
tcp6       0      0  fe80::b7ca:330b:.1028  fe80::5059:ee74:.1025  ESTABLISHED
tcp6       0      0  fe80::b7ca:330b:.1024  fe80::5059:ee74:.1024  ESTABLISHED

还可以通过grep具体的tcp状态码来确定当前tcp端口的连接数量及情况。

netstat -an |grep 80 |grep CLOSE_WAIT

netstat -an |grep 80 |grep CLOSE_WAIT
tcp4      31      0  192.168.31.24.50863    3.80.20.154.443        CLOSE_WAIT 
tcp4      31      0  192.168.31.24.50855    3.80.20.154.443        CLOSE_WAIT 
tcp4      31      0  192.168.31.24.50854    3.80.20.154.443        CLOSE_WAIT 
tcp4      31      0  192.168.31.24.50853    3.80.20.154.443        CLOSE_WAIT 
tcp4      31      0  192.168.31.24.50852    3.80.20.154.443        CLOSE_WAIT

除此之外，还可以使用 ss -lnr |grep 80，确定对应端口的 Send-Q 和 Recv-Q 数量。

一样可以反应对应端口的tcp是否阻塞。

第三步，TCP连接队列打满导致假死

根据上一步查看服务端口的tcp情况，确定最终问题是由于tcp连接没有正确释放，导致端口的TCP连接队列打满，后续请求无法进入连接队列而造成Tomcat假死！

最后，确定问题后，去服务中寻找原因。

可能由于对应的http请求没有进行Response，或者由于服务处理速度远不及请求的数量，导致连接队列在运行中慢慢被打满。

解决方案：

1.碰到该类情况，首先可以尝试进行服务的重启，可能可以继续支持服务，一定时间后服务会进入假死；同时在业务前侧进行关闭，减少甚至关闭请求量。使业务的损失降低到最小。 2.回退版本，一般问题的出现都是由新业务上线造成的，先回退无问题版本。 3.针对排查的问题，锁定问题原因，进行针对性解决。

线上案例4：log输出到控制台导致假死

下面的是一个文件下载卡死，本质还是线上假死案例：

问题：文件下载卡死

在一个大型的文件下载集群（100多个实例）上，某天用户通知我们说：

你们下载一个文件咋下载了一整天都没下载下来

根据日志和下载的文件发现，不是因为下载文件慢，而是程序就卡住了，也就是说假死。

分析过程

1、分析日志，跟踪程序，发现代码没啥毛病，日志也看不出来个所以然

2、jstack -l pid 堆栈跟踪，堆栈信息给出部分

Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.131-b11 mixed mode):

"Attach Listener" #186 daemon prio=9 os_prio=0 tid=0x00007fbf98001000 nid=0x28e8 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
        - None

"pool-47-thread-4" #185 prio=5 os_prio=0 tid=0x00007fbf4c44c800 nid=0x2b76 runnable [0x00007fbf348e3000]
   java.lang.Thread.State: RUNNABLE
        at java.io.FileOutputStream.writeBytes(Native Method)
        at java.io.FileOutputStream.write(FileOutputStream.java:326)
        at java.io.BufferedOutputStream.write(BufferedOutputStream.java:122)
        - locked <0x0000000080223058> (a java.io.BufferedOutputStream)
        at java.io.PrintStream.write(PrintStream.java:480)
        - locked <0x0000000080223038> (a java.io.PrintStream)
        at java.io.FilterOutputStream.write(FilterOutputStream.java:97)
        at ch.qos.logback.core.joran.spi.ConsoleTarget$1.write(ConsoleTarget.java:37)
        at ch.qos.logback.core.encoder.LayoutWrappingEncoder.doEncode(LayoutWrappingEncoder.java:131)
        at ch.qos.logback.core.OutputStreamAppender.writeOut(OutputStreamAppender.java:187)
        at ch.qos.logback.core.OutputStreamAppender.subAppend(OutputStreamAppender.java:212)
        at ch.qos.logback.core.OutputStreamAppender.append(OutputStreamAppender.java:100)
        at ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(UnsynchronizedAppenderBase.java:84)
        at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:48)
        at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:270)
        at ch.qos.logback.classic.Logger.callAppenders(Logger.java:257)
        at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:421)
        at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:383)
        at ch.qos.logback.classic.Logger.info(Logger.java:591)
        at com.baidu.adb.client.download.AbstractPartitionDownloader$Worker.run(AbstractPartitionDownloader.java:99)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:748)

   Locked ownable synchronizers:
        - <0x0000000587fa71f0> (a java.util.concurrent.ThreadPoolExecutor$Worker)
        - <0x000000008021cbe8> (a java.util.concurrent.locks.ReentrantLock$FairSync)
 
  "pool-47-thread-3" #184 prio=5 os_prio=0 tid=0x00007fbf4c44b800 nid=0x2b74 waiting on condition [0x00007fbf35af5000]
   java.lang.Thread.State: WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x000000008021cbe8> (a java.util.concurrent.locks.ReentrantLock$FairSync)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:870)
  ....

从堆栈信息中可以看到，pool-47-thread-4 处于RUNNABLE，并且获得了2个锁

Locked ownable synchronizers:
        - <0x0000000587fa71f0> (a java.util.concurrent.ThreadPoolExecutor$Worker)
        - <0x000000008021cbe8> (a java.util.concurrent.locks.ReentrantLock$FairSync)

而pool-47-thread-3和pool-47-thread-2的状态是WAITING，并且都是处于waiting on condition状态，并且都在等待0x000000008021cbe8，也就是死锁了。

再看一下pool-47-thread-4的堆栈信息， at ch.qos.logback.core.joran.spi.ConsoleTarget$1.write(ConsoleTarget.java:37)，也就是说是logback没有释放锁，并且是console appender上

查看logback文件，logger中有个appender是console

解决方案

如果logback工作线程无法完成，则一定是因为它的阻塞队列已满。

工作线程正在等待存放其日志条目，由于线程正在等待，因此我们知道它释放了队列上的锁，但它仍然持有打印流上的锁。

控制台写入线程在尝试获取打印流上的锁时被阻塞，因此它们是死锁的。

避免代码更改的最小修复方法是将控制台附加器换成不需要获取打印流上的锁的附加器。

结论：

程序在终端有打印信息输出，在后台运行后，信息无法输出到终端，

打印信息过多后，缓冲区写满，程序停止运行，造成假死现象

解决方法：

后台运行的程序不打印输出信息到终端

由于程序采用log4j，所以屏蔽 log4j.xml 配置中的 Console 配置输出

使用 nohup 将打印信息追加到 nohup.out 文件中，这种会随着时间的累计生成很大的文件

线上案例5：Server端CLOSE_WAIT 线上假死

下面的是一个真实的线上假死案例：

一个spring boot工程，对外提供rest接口服务，但是隔三差五的就会出现500连接超时的现象。

问题定位

在排除了内存、CPU、磁盘占满场景后，无意中发现这台机器出现了大量的网络连接CLOSE_WAIT。

观察CLOSE_WAIT情况、统计close_wait的连接数量

lsof -i:8091 |grep "CLOSE_WAIT"  |wc -l

CLOSE_WAIT连接数是67，而且还在增长。

为什么会出现大量的CLOSE_WAIT状态呢？我们得先介绍一下socket断开过程中的四次挥手。

由于TCP连接是全双工的，因此每个方向都必须单独进行关闭。假设终止命令由client端发起。

当clien端传输完成数据，或者需要断开连接时：

Client端发送一个FIN报文给Server端。(序号为M)

1.1. 表示通过调用close(socket) API，客户端Client要终止Client到Server这个方向的连接。
1.2 表示Client不再会发送数据到Server端。(但Server还能继续发给Client端)
1.3 Client状态变为FIN_WAIT_1

Server端收到FIN后，发送一个ACK报文给Client端。(序号为M+1)

2.1 Server状态变为CLOSE_WAIT
2.2 Client收到序号为(M+1)的ACK后状态变为FIN_WAIT_2

Server端也发送一个FIN报文给Client端。(序号为N)

3.1 表示Server也要终止到Client端这个方向的连接。
3.2. 通过调用close(socket) API。
3.3 Server端状态变为LAST_ACK

Client端收到报文FIN后，也发送一个ACK报文给服务器。(序号N+1)

4.1 Client状态变为TIME_WAIT

Server端收到序号为(N+1)的ACK

5.1 Server的状态变为CLOSED.

等带2MSL之后

6.1 Client的状态也变为CLOSE.

至此，一个完整的TCP连接就关闭了。

两个基本问题：

Q: Sever的CLOSE_WAIT出现在什么时候呢？

A: 在Sever端收到Client的FIN消息之后。

Q: 状态CLOSE_WAIT在什么时候转换成下一个状态呢？

A: 在Server端向Client发送FIN消息之后。

回到前面的问题：为什么会出现大量的CLOSE_WAIT状态呢？

如果Server端一直没有向client端发送FIN消息(调用close() API)，那么这个CLOSE_WAIT会一直存在下去。

原因分析

从上面我们看到出现CLOSE_WAIT，说明Server端没有发起close()操作，这基本上是用户server端程序的问题了；通常情况下，Server都是等待Client访问，如果Client退出请求关闭连接，server端自觉close()对应的连接。但是服务方还没有来得及自觉close()，在Server返回ack这个时间差，Server连接状态就是close_wait。

按说这个时间差是很短的，不足以让整个应用不能对外响应，除非一种情况，那就是某个时刻并发量达到了tomcat的处理请求的极限，同一时间，整个处理请求的线程池全部被占用，并且等待close。

刚好上面的线上SpringBoot应用，基本符合这个场景。

问题排查

问题排查思路是，通过jstack查询线程信息，看http究竟阻塞在哪里了

jps

jstack $PID > stack.txt

先找到该进程的pid，然后通过jstack命令导出线程信息。

在stack.txt中，搜索BLOCKED，发现了大量线程阻塞。

文件内容查找： 
grep BLOCKED  stack.txt

搜索BLOCKED的 nio线程

# -C 3 展示匹配内容及后面3行
grep "BLOCKED" -C 3 | grep "http-nio-exec"   stack.txt

http-nio-xx-exec-是tomcat处理请求的线程名称，可以看出，大多数线程都被blocked。这就是发生假死的根源。

线程信息里面也可以看到栈信息，明确告诉我们阻塞发生在了代码哪一行。

跟进代码果然，代码中请求了两个已经不能正常访问的http地址。

修改代码后，发布到开发环境，继续观察CLOSE_WAIT情况、统计close_wait的连接数量

lsof -i:8091 |grep "CLOSE_WAIT"  |wc -l

修改前是67，而且还在增长。

修改后变成了0。

ok，线上的close_wait的问题已经解决了。SpringBoot假死也已经解决。

SpringBoot线上服务假死解决，CPU内存正常

问题排查

老规矩在集群环境中同一个服务几个节点无响应。如不及时解决会可能形成雪崩效应。

优先查看服务日志是否有报错，礼貌习惯性查看服务cpu及内存情况。

先复习下，若服务无报错。cpu或内存出现异常,按如下步骤排查。

问题排查

1、信息收集分析

因服务健康监测无响应，cpu及内存情况正常，直接查看堆栈信息，看看线程都在干什么

jstack -l PID >> a.log

Jstack的输出中，Java线程状态主要是以下几种：

RUNNABLE 线程运行中或I/O等待

BLOCKED 线程在等待monitor锁(synchronized关键字)

TIMED_WAITING 线程在等待唤醒，但设置了时限

WAITING 线程在无限等待唤醒

发现都是WAITING线程。

"http-nio-8888-exec-6666" #8833 daemon prio=5 os_prio=0 tid=0x00001f2f0016e100 nid=0x667d waiting on condition [0x00002f1de3c5200]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for  <0x00000007156a29c8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
at com.alibaba.druid.pool.DruidDataSource.takeLast(DruidDataSource.java:1897)
at com.alibaba.druid.pool.DruidDataSource.getConnectionInternal(DruidDataSource.java:1458)
....
at org.apache.ibatis.executor.CachingExecutor.query(CachingExecutor.java:109)
at com.github.pagehelper.PageInterceptor.intercept(PageInterceptor.java:143)
at org.apache.ibatis.plugin.Plugin.invoke(Plugin.java:61)
at com.sun.proxy.$Proxy571.query(Unknown Source)

2、定位关键信息，追踪源代码

关键信息如下：

  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
  at com.alibaba.druid.pool.DruidDataSource.takeLast(DruidDataSource.java:1897)

DruidDataSource.takeLast 方法

DruidConnectionHolder takeLast() throws InterruptedException, SQLException {
    try {
        while (poolingCount == 0) {
            emptySignal(); // send signal to CreateThread create connection

            if (failFast && isFailContinuous()) {
                throw new DataSourceNotAvailableException(createError);
            }

            notEmptyWaitThreadCount++;
            if (notEmptyWaitThreadCount > notEmptyWaitThreadPeak) {
                notEmptyWaitThreadPeak = notEmptyWaitThreadCount;
            }
            try {
                // 数据库的连接都没有释放且被占用，连接池中无可用连接，导致请求被阻塞
                notEmpty.await(); // signal by recycle or creator
            } finally {
                notEmptyWaitThreadCount--;
            }
            notEmptyWaitCount++;

            if (!enable) {
                connectErrorCountUpdater.incrementAndGet(this);
                throw new DataSourceDisableException();
            }
        }
    } catch (InterruptedException ie) {
        ...
    }
    ...
        return last;
}

源码中的核心代码如下：

// 数据库的连接都没有释放且被占用，连接池中无可用连接，导致请求被阻塞
notEmpty.await(); // signal by recycle or creator

从 Druid 连接池获取连接的时候，如果池子里边的连接，一直都没有释放且被占用，连接池中无可用连接，导致请求被阻塞。

结合日志报错定位到问题代码。因报错可用连接没有正常释放，导致一直await卡死。问题代码如下：

try {
    SqlSession sqlSession = sqlSessionFactory.openSession(ExecutorType.BATCH);
    TestMapper mapper = sqlSession.getMapper(TestMapper.class);
    mapper.insetList(list);
    sqlSession.flushStatements();
} catch (Exception e) {
    e.printStackTrace();
}

问题复现

按照以上信息在多活环境复现。因线程被打满且都在等待导致监控检查无响应。

tomcat线程被打满：

tomcat默认参数：

最大工作线程数，默认200。 server.tomcat.max-threads=200 最大连接数默认是10000 server.tomcat.max-connections=10000 等待队列长度，默认100。 server.tomcat.accept-count=100

最小工作空闲线程数，默认10。 server.tomcat.min-spare-threads=100

Druid连接池的默认参数如下：

Druid连接池的配置参数如下：

属性	说明	建议值
username	登录数据库的用户名
password	登录数据库的用户密码
initialSize	默认0，启动程序时，在连接池中初始化多少个连接	10-50足够
maxActive	默认8，连接池中最多支持多少个活动会话
maxWait	默认-1，程序向连接池中请求连接时,超过maxWait的值后，认为本次请求失败，即连接池，没有可用连接，单位毫秒，设置-1时表示无限等待	100
minEvictableIdleTimeMillis	池中某个连接的空闲时长达到 N 毫秒后, 连接池在下次检查空闲连接时，将回收该连接,要小于防火墙超时设置 net.netfilter.nf_conntrack_tcp_timeout_established	见说明部分
timeBetweenEvictionRunsMillis	检查空闲连接的频率，单位毫秒, 非正整数时表示不进行检查
keepAlive	程序没有close连接且空闲时长超过 minEvictableIdleTimeMillis,则会执行validationQuery指定的SQL,以保证该程序连接不会池kill掉,其范围不超过minIdle指定的连接个数	true
minIdle	默认8，回收空闲连接时，将保证至少有minIdle个连接.	与initialSize相同
removeAbandoned	要求程序从池中get到连接后, N 秒后必须close,否则druid 会强制回收该连接,不管该连接中是活动还是空闲, 以防止进程不会进行close而霸占连接。	false,当发现程序有未正常close连接时设置为true
removeAbandonedTimeout	设置druid 强制回收连接的时限，当程序从池中get到连接开始算起，超过此值后，druid将强制回收该连接，单位秒。	应大于业务运行最长时间
logAbandoned	当druid强制回收连接后，是否将stack trace 记录到日志中	true
testWhileIdle	当程序请求连接，池在分配连接时，是否先检查该连接是否有效。(高效)	true
validationQuery	检查池中的连接是否仍可用的 SQL 语句,drui会连接到数据库执行该SQL, 如果正常返回，则表示连接可用，否则表示连接不可用
testOnBorrow	程序申请连接时,进行连接有效性检查（低效，影响性能）	false
testOnReturn	程序返还连接时,进行连接有效性检查（低效，影响性能）	false
poolPreparedStatements	缓存通过以下两个方法发起的SQL: public PreparedStatement prepareStatement(String sql) public PreparedStatement prepareStatement(String sql,int resultSetType, int resultSetConcurrency)	true
maxPoolPrepareStatementPerConnectionSize	每个连接最多缓存多少个SQL	20
filters	这里配置的是插件,常用的插件有:监控统计: filter:stat 日志监控: filter:log4j 或者 slf4j 防御SQL注入: filter:wall	stat,wall,slf4j
connectProperties	连接属性。比如设置一些连接池统计方面的配置。 druid.stat.mergeSql=true;druid.stat.slowSqlMillis=5000 比如设置一些数据库连接属性

解决

1、Druid连接池的配置超时参数

spring: 
  redis:
    host: localhost
    port: 6379
    password: 
  datasource:
    druid:
      stat-view-servlet:
        enabled: true
        loginUsername: admin
        loginPassword: 123456
    dynamic:
      druid:
        initial-size: 10
        min-idle: 5
        maxActive: 100
        maxWait: 60000
        timeBetweenEvictionRunsMillis: 60000
        minEvictableIdleTimeMillis: 300000
        validationQuery: SELECT 1 FROM DUAL
        testWhileIdle: true
        testOnBorrow: false
        testOnReturn: false
        poolPreparedStatements: true
        maxPoolPreparedStatementPerConnectionSize: 20
        filters: stat,slf4j,wall
        connectionProperties: druid.stat.mergeSql\=true;druid.stat.slowSqlMillis\=5000

2、异常及时关闭连接

发生异常，及时关闭连接

try {
    SqlSession sqlSession = sqlSessionFactory.openSession(ExecutorType.BATCH);
    TestMapper mapper = sqlSession.getMapper(TestMapper.class);
    mapper.insetList(list);
    sqlSession.flushStatements();
} catch (Exception e) {
    e.printStackTrace();
    sqlSession.close(); //异常及时关闭连接
}

SpringBoot假死检测与自愈

首先，配置当SpringBoot发生oom时自动退出
其次，配置进行假死检测与自愈

当SpringBoot发生oom时自动退出

在使用springboot开发应用时遇到一个问题，当springboot发生内存溢出时，springboot并没有自动退出，因为当发生oom时springboot对oom异常进行了管理（oom异常也可以被try catch捕获）解决方法：在启动jar包时加入命令行参数

XX:+CrashOnOutOfMemoryError

当发生内存溢出时jvm会自动退出，并且在当前程序目录下生成error文件日志，里面包括是哪个线程引起的oom，当前内存使用情况等。

配置进行假死检测与自愈

为了防止这个问题，临时采取定期检查该站点url的方式判断tomcat的运行情况。

写一个shell脚本：当取得到健康检查url状态码不是200时，强制重启SpringBoot。

#!/bin/bash

n=`curl -I -s  |grep "200 OK" |wc -l`

 
if [ $n -ne 1 ]

  then

   source /etc/profile

   /usr/local/app/bin/deploy.sh stop 

  /usr/local/app/bin/deploy.sh start

fi

用crond每隔一段时间执行一次上面的假死检测与自愈脚本。

最后的一些成熟的建议

给出一些实战经验，让工作中更加从容：

调优参数务必加上-XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=，发生OOM让JVM自动dump出内存，方便后续分析问题解决问题
堆内存不要设置的特别大，因为你设置的特别大，发生OOM时生成的dump文件就特别大，不好分析。建议不超过8G。
想主动dump出JVM的内存，有挺多方式，但不管哪种方式，主动dump内存会引发STW，请择时操作。即通过arthas提供的命令heapdump主动dump出JVM的内存，这个操作会引发FGC，背后是STW，操作时请选择好时机，不然老板可能提刀来见。
我提供的代码务必拉下来跑跑，找下感觉。最好是自己也去写一份与我提供的不同的，加深理解，加深印象。

JVM相关的启动参数

-XX:+HeapDumpOnOutOfMemoryError

从字面就可以很容易的理解，在发生OutOfMemoryError异常时，进行堆的Dump，这样就可以获取异常时的内存快照了。
-XX:HeapDumpPath=/usr/local/heap-dump/

这个也很好理解，就是配置HeapDump的路径，

方便我们管理，这里我们配置为/usr/local/heap-dump/，当然你也可以根据自己的需要，定义为其他的目录。

posted @ 2023-07-07 14:55 CharyGao 阅读(1411) 评论(0) 编辑收藏举报

刷新页面返回顶部

硅基文明

代码改变不了世界，但是改变世界需要代码。

SpringBoot线上服务假死，CPU内存正常，什么情况？

背景

问题排查

常规排查

本次问题排查

问题复现

解决

线上SpringBoot假死，十万火急的现象

10大造成假死的可能原因

尼恩五板斧分析方法

第一板斧：查日志

第二板斧：查系统资源

step1： 弄清楚CPU资源的家底（到底多少CPU Cores核数）

step2：查所有CPU core的使用情况

查看进程使用cpu的情况

然后，查内存资源

step3：查IO

iostat命令 查IO的

iostat命令参数

iotop查询进程磁盘I/O

step4：查网络

使用nload查看网络

使用iftop查看网络

第三斧：查JVM线程死锁

1、查看服务进程中线程情况

2、查看系统异常线程16进制

3、查看异常线程堆栈信息

4、分析线程的死锁

第四板斧：查JVM堆栈

内存溢出与内存泄漏：

内存溢出的可能原因排查

四种内存溢出的场景

一、堆溢出

二、栈溢出

三、方法区溢出

四、直接内存溢出

内存溢出总结：

内存溢出与内存泄漏的排查

step1： jps 获取进程id

step2：jstat 查看GC 统计信息

step3: 内存泄漏与大对象的分析

类型一：轻量级的内存泄漏与大对象在线分析：

第一步：jmap 查看进程中占用资源最大的前N个对象，

第二步：使用 Arthas 定位大对象的所在的代码

类型二：重量量级的内存泄漏与大对象在线分析：

第五板斧：查操作系统配置

线上案例1：OOM导致假死

现象

特别说明 ：发生OOM了JVM并不一定挂

事故现场

问题定位

线上案例2：操作系统线程数不够导致假死

现象

排查过程

a.内存状态查询

b.内存快照导出

c.栈信息导出

d.内存信息查看

e. ulimit查看

解决办法

1.清除页缓存

2.ulimit配置调整

线上案例3：请求处理速度慢，导致假死

背景描述：

排查过程：

第一步：查看日志、系统资源、jvm内存

第二步，查看服务对应的端口的情况。

第三步，TCP连接队列打满导致假死

解决方案：

线上案例4：log输出到控制台导致假死

问题：文件下载卡死

分析过程

解决方案

结论：

线上案例5：Server端CLOSE_WAIT 线上假死

问题定位

问题排查

SpringBoot线上服务假死解决，CPU内存正常

step1：弄清楚CPU资源的家底（到底多少CPU Cores核数）

iostat命令查IO的

特别说明：发生OOM了JVM并不一定挂

1、信息收集分析

最后的一些成熟的建议