云主机夯死故障分析

一、问题描述

在这里插入图片描述

某次巡检发现，某台云主机无法远程ssh，连接上之后界面卡住不动，且无法手动中断；登录移动云控制台，发现界面夯住，报如下错误：“INFO: task xxx:xxx blocked for more than 240 seconds.”，“echo 0 > /proc/sys/kernel/hung_task_timeout_secs ……”

在这里插入图片描述

二、原因分析

1）首先我们来回顾下Linux系统内核hung_task机制

正如本文开始图中所示，内核打印“INFO: task xxx:xxx blocked for more than 240 seconds.”这样的警示信息，正是内核的hung task机制作用所致。Linux的hung task机制通过内核线程khungtaskd来实现的，khungtaskd监控TASK_UNINTERRUPTIBLE状态的进程，如果在120s周期内没有切换，就会打印详细信息。

linux启动后，会创建一个内核线程(khungtaskd)，定期(120)唤醒后，遍历系统中的所有进程，检查是否存在处于D状态超过120s(该值用户可以自定义设置)的进程，如果存在，则打印相关警告和进程堆栈。如果配置了hung_task_panic（proc或内核启动参数），则直接发起panic。

我们可以执行：sysctl -a --pattern hung 查看当前hung机制配置，现场实际为hung超时未240s，且不会触发kernel panic，如下所示：

在这里插入图片描述

实现原理：kernel/hung_task.c代码如下：
在这里插入图片描述

总之，核心思想就是创建一个内核监测进程(khungtaskd)循环(每隔CONFIG_DEFAULT_HUNG_TASK_TIMEOUT时间—>kernel.hung_task_timeout_secs)监测处于D状态的每一个进程（任务），统计它们在两次检测之间的调度次数（上下文切换），如果发现有任务在两次监测之间没有发生任何的调度，则可判断该进程一直处于D状态，很有可能已经死锁，这时触发报警日志并打印到前台，输出进程的基本信息，栈回溯以及寄存器保存信息以供内核开发人员定位。其中，D状态：是一种不可中断的深度睡眠 ，一般由IO引起，同步IO在做读或写操作时，cpu不能做其它事情，只能等待，依赖于它的进程也会因为等待它而阻塞，此状态的进程不会消耗CPU。其次睡眠的原因是因为等待某些资源（比如锁或者磁盘IO），这也是我们看到非常多D状态的进程都处在处理IO操作的原因。关键它还不能被手动中断，区别于“硬件中断”的中断，它不希望在其获取到资源或者超时前被终止。它不会被信号唤醒，也就不会响应kill -9这类信号。这也是它跟S（可中断睡眠）状态的区别。注意：一般，当硬件故障或者驱动bug出现时就会导致进程长时间处于D状态无法退出，依赖或等待它的其他进程都被阻塞卡死。

另外，如果一个进程一直占用CPU，其他进程始终无法被调度执行，极端情况下甚至无法响应中断，此时系统可能就会完全hung住不响应任何用户操作。这种情况还是发生在内核代码或者驱动代码bug中，应用程序不会出现这个问题。

soft_lockup：CPU被某个进程长时间占用，其他进程得不到调用。eg：长时间禁用内核抢占；
hard_lockup：CPU被某个进程长时间占用，其他进程得不到调用，同时也不响应中断。eg：长时间屏蔽中断响应

Linux内核通过watchdog机制来检查系统中是否出现soft_lockup和hard_lockup。watchdog,中文名称叫做“看门狗”，全称watchdogtimer，watchdog的主要思想是：通过优先级更高的任务来观察优先级较低的任务(进程/中断)是否被成功执行调度，因此可以通过中断来观察进程是否被正常调度，而通过NMI(不可屏蔽中断)来观察中断是否被响应。watchdog对应的代码在watchdog.c中，主要实现逻辑：

为每个CPU core创建一个(watchdog/%u)内核进程，它会周期性的更新watchdog_touch_ts变量

设置一个时钟中断，它会周期性的更新hrtimer_interrupts变量
同时负责检测soft_lockup，通过查看watchdog_touch_ts的值是否被更新，来判断(watchdog/%u)进程是否被执行，从而判断CPU是否被其他进程一直占用

设置一个NMI（不可屏蔽中断），它会每watchdog_thresh秒触发一次，同时负责检测hard_lockup，通过查看hrtimer_interrupts的值是否被更新，来判断是否出现hard_lockup

在这里插入图片描述

2）进程状态

进程自创建以后，状态可能发生一系列的变化，直到进程退出。即进程在TASK_RUNNING状态变和非TASK_RUNNING状态之间转化；常见进程状态有以下几种：

O：进程正在处理器运行,这个状态很少见.

S (TASK_INTERRUPTIBLE)：可中断状态，或休眠状态（sleeping，）

R (TASK_RUNNING)：等待运行（runable）R Running or runnable (on run queue) 进程处于运行或就绪状态

I：空闲状态（idle）

Z(TASK_DEAD - EXIT_ZOMBIE)：退出状态，称为僵死，也称为僵尸状态（zombie）；进程在退出的过程中，处于TASK_DEAD状态。在这个退出过程中，进程占有的所有资源将被回收，除了task_struct结构（以及少数资源）以外。于是进程就只剩下task_struct这么个空壳，故称为僵尸，。保留task_struct是因为task_struct里面保存了进程的退出码、以及一些统计信息。而其父进程很可能会用到这些信息，实际内核中已经建立了从pid到task_struct查找关系，还有进程间的父子关系，父进程可以通过wait系列的系统调用（如wait4、waitid）来等待某个或某些子进程的退出，并获取它的退出信息。然后wait系列的系统调用会顺便将子进程的尸体（task_struct）也释放掉。子进程在退出的过程中，内核会给其父进程发送一个信号，通知父进程来“收尸”，这个信号默认是SIGCHLD。

T(TASK_STOPPED or TASK_TRACED)：暂停或跟踪状态（Traced），向进程发送一个SIGSTOP信号，它就会因响应该信号而进入TASK_STOPPED状态；向进程发送一个SIGCONT信号，可以让其从TASK_STOPPED状态恢复到TASK_RUNNING状态。当进程正在被跟踪时，它处于TASK_TRACED这个特殊的状态。“正在被跟踪”指的是进程暂停下来，等待跟踪它的进程对它进行操作。比如在gdb中对被跟踪的进程下一个断点，进程在断点处停下来的时候就处于TASK_TRACED状态。对于进程本身来说，TASK_STOPPED和TASK_TRACED状态很类似，都是表示进程暂停下来。
而TASK_TRACED状态相当于在TASK_STOPPED之上多了一层保护，处于TASK_TRACED状态的进程不能响应SIGCONT信号而被唤醒。只能等到调试进程通过ptrace系统调用执行PTRACE_CONT、PTRACE_DETACH等操作（通过ptrace系统调用的参数指定操作），或调试进程退出，被调试的进程才能恢复TASK_RUNNING状态。

B：进程正在等待更多的内存页

X(TASK_DEAD - EXIT_DEAD)：退出状态，进程即将被销毁；进程将被置于EXIT_DEAD退出状态，这意味着接下来的代码立即就会将该进程彻底释放。所以EXIT_DEAD状态是非常短暂的，几乎不可能通过ps命令捕捉到。

D（TASK_UNINTERRUPTIBLE）:不可中断的深度睡眠，一般由IO引起；不可中断指的并不是CPU不响应外部硬件的中断，而是指进程不响应异步信号。TASK_UNINTERRUPTIBLE状态存在的意义就在于，内核的某些处理流程是不能被打断的。如果响应异步信号，程序的执行流程中就会被插入一段用于处理异步信号的流程（这个插入的流程可能只存在于内核态，也可能延伸到用户态），这样原有的流程就被中断了。（可搜索《linux内核异步中断浅析》参见）

3）关于jbd2进程

The Journaling Block Device (JBD) provides a filesystem-independent interface for filesystem journaling. ext3, ext4 and OCFS2 are known to use JBD. OCFS2 starting from Linux 2.6.28[1] and ext4 use a fork of JBD called JBD2.[2]日志块设备 (JBD) 为日志型文件系统提供了一个独立于文件系统的接口。如众所周知的ext3、ext4 和 OCFS2 都使用 JBD。在Linux 2.6.28 中ext4 开始使用 OCFS2 的 JBD 的一个分支，即 JBD2，即新的ext4采用jbd2来。

ext4 支持根据用户需求采用多种模式的日志记录。包括：Writeback 模式（它仅记录元数据）； Ordered 模式（默认方式，它记录元数据，但写为元数据的数据是从日志中写入的）； Journal 模式（最可靠的模式，它同时记录元数据和数据。，但它也是最慢的，因为所有数据都要经过日志。）

在这里插入图片描述

//关闭ext4的journal功能
tune2fs -O has_journal /dev/sdb1
//检查磁盘完整性
e2fsck -f /dev/sdb1
//检查当前文件系统的功能
dumpe2fs /dev/sdb | grep has_journal  //或rep 'Filesystem features'，输出如下
dumpe2fs 1.42.9 (28-Dec-2013)
Filesystem features:      has_journal ext_attr resize_inode dir_index filetype needs_recovery extent 64bit flex_bg sparse_super large_file huge_file uninit_bg dir_nlink extra_isize
//查看当前jbd2的io
iotop

在这里插入图片描述

注：Journal模式调用的顺序如下：

ext4_load_journal -> ext4_get_dev_journal -> jbd2_journal_init_dev -> jbd2_stats_proc_init -> jbd2_seq_info_fops -> jbd2_seq_info_open -> jbd2_seq_info_ops -> jbd2_seq_info_show

JBD日志系统为跨多个扇区的操作提供原子性保护。对于操作系统而言，所有的元数据和数据都存储在文件系统所在的块设备上。日志可以是同一个块设备的一部分，或者是一个单独的设备。一个日志文件系统首先记录所有在日志中的操作。一旦这些作为一个原子操作的操作们都被记录到日志之中了，它们才会被一起写到实际的块设备中。日志（journal）是管理一个块设备的更新的内部记录（log）。更新首先会放到日志之中，然后反射到它们在磁盘上的真实位置。其中，handle 代表一个原子更新，原子地完成的全部一组改写会被提取出来引用为一个 handle，JBD 将一组 handle 打包为一个事务（transaction），并将事务一次写入日志。JBD 保障事务本身是原子性的。这样，作为事务的组成部分的 handle 们自然也是原子性的。写入日志叫transaction commiting，提交到磁盘叫commit，提交完成日志声明空间擦除（释放日志的过程）可重新使用叫checkpointing（用于重复使用，清除无效日志）。

JBD的操作函数：

1>journal_start
journal_start 的主要作用是取得一个原子操作描述符handle_t,如果当前进程已经有一个，则直接返回，否则，需要新创建一个。

2> journal_stop
该函数的主要作用是将该handle与transaction断开链接，调整所属transaction的额度。如果该原子操作时同步的，则设置事务的t_synchronous_commit标志。在事务提交时，会根据该标志决定缓冲区的写方式。

3> journal_get_create_access
取得通过journal_start()获得原子操作描述符后，在修改缓冲区前，我们应该在jbd中先获得该缓冲区的写权限。journal_get_create_access()、journal_get_write_access()和journal_get_undo_access()这三个函数的作用就是在jbd中取得该缓冲区的写权限。

4> journal_get_write_access
journal_get_write_access()函数的作用是使jbd取得对bh的写权限

5> journal_dirty_data
jbd 在取得缓冲区的写权限后，文件系统就可以修改改缓冲区的内容了。

6> journal_forget
以索引块缓冲区为例。如果一个原子操作在运行过程中，要分配一个新的索引块，则它就先调用journal_get_write_access()函数取得写权限，然后修改这个索引块缓冲区，然后调用journal_dirty_metadata()将该缓冲区设为脏。但是，如果不幸，该原子操作后边运行出错了，需要将之前的修改全部取消，则需要调用journal_forget()函数使jbd“忘记”该缓冲区。

//开启几个内核 trace查看sync调用，也可使用sysdig查看；开启执行 flush 时输出日志
echo 1 > /sys/kernel/debug/tracing/events/jbd2/jbd2_commit_flushing/enable  

//任意进程执行 sync 时输出日志
echo 1 > /sys/kernel/debug/tracing/events/ext4/ext4_sync_file_enter/enable

//查看日志，查看对应的fd号定位文件
cat /sys/kernel/debug/tracing/trace_pipe

4）JBD IO占用高假死

iostat -dtxNm 2 10  //查看当前io，注意最后三列：await  svctm  %util，或iotop查看
dstat -r -l -t --top-io  //看下io前几名的进程

--io/total- ---load-avg--- ----system---- ----most-expensive----
 read  writ| 1m   5m  15m |     time     |     i/o process      
0.78  33.6 |0.27 0.65 0.94|27-08 20:36:58|NVS        2547B   14M
   0   126 |0.27 0.65 0.94|27-08 20:36:59|NVS           0    19M
   0  15.0 |0.32 0.66 0.94|27-08 20:37:00|NVS           0    20M
   0  16.0 |0.32 0.66 0.94|27-08 20:37:01|NVS        8910B   20M
   0  12.0 |0.32 0.66 0.94|27-08 20:37:02|NVS           0    20M
   0  16.0 |0.32 0.66 0.94|27-08 20:37:03|NVS        4455B   20M
   0   116 |0.32 0.66 0.94|27-08 20:37:04|NVS           0    20M
   0  17.0 |0.30 0.64 0.93|27-08 20:37:05|NVS        8910B   20M
   0  13.0 |0.30 0.64 0.93|27-08 20:37:06|NVS          15k   20M
   0  15.0 |0.30 0.64 0.93|27-08 20:37:07|NVS        4455B   19M
   0  16.0 |0.30 0.64 0.93|27-08 20:37:08|NVS        4455B   20M
   0   143 |0.30 0.64 0.93|27-08 20:37:09|NVS        4455B   20M
   0  16.0 |0.27 0.63 0.93|27-08 20:37:10|NVS        4455B   20M
   0  14.0 |0.27 0.63 0.93|27-08 20:37:11|NVS        4455B   20M
   0  65.0 |0.27 0.63 0.93|27-08 20:37:12|NVS           0    20M
   0  17.0 |0.27 0.63 0.93|27-08 20:37:13|NVS           0    19M
   0   128 |0.27 0.63 0.93|27-08 20:37:14|NVS           0    19M
   0  19.0 |0.25 0.62 0.92|27-08 20:37:15|NVS        8910B   20M
   0  12.0 |0.25 0.62 0.92|27-08 20:37:16|NVS           0    20M
   0  17.0 |0.25 0.62 0.92|27-08 20:37:17|NVS        8910B   20M
   0  19.0 |0.25 0.62 0.92|27-08 20:37:18|NVS        8910B   20M

在这里插入图片描述

对jbd占用高IO的磁盘，执行remount：

mount -t ext4 -o remount,rw,barrier=0,commit=60,noatime,nodiratime /dev/mapper/VGroup-lv_home /usr/local/software

如果使用老版本的Linux，会因系统的bug错误导致JBD占用IO过高；相关经验显示受影响的版本：：

CentOS6.5-64bit
CentOS6.9-64bit

内核版本：2.6.32-131.0.15.el6.x86_64

这时就需要升级内核版本；现场使用centos7.9，不受此影响，且根据事后反推也确实非系统原因。

另外磁盘分区使用率慢也会导致JDB IO问题；

5）本次故障其他可能原因

1> 系统出现死锁，mutex lock（互斥锁）等；

2> 资源竞争激烈，导致设定超时时间内无法拿到资源，eg，内存耗尽；

3> 资源异常，导致系统资源获取异常甚至无法获取

4> JBD 触发IO异常，进程进入D状态

cat /proc/5171/stack //分析挂死调用栈
#分析进程D状态进程，查看谁拿到了锁？什么原因不释放？有无死锁问题？
Perf sched record [-p D进程PID] –g
Perf record [-p D进程PID] –g

现场故障为：云硬盘到期被平台冻结，导致docker所在硬盘无法正常读取，触发jbd 报错。