【内核】【转载】记一次Linux Hung Task分析过程

vmcore-dmesg.txt截图如下，崩溃栈里面有我们产品的驱动，现在要分析出是不是我们导致的。系统崩溃是因为触发了hung task检测条件，系统panic了。所谓hung task，就是进程的状态为D状态，即TASK_UNINTERRUPTIBLE状态，短时间的D状态是正常的，长时间就会有问题了，可能系统IO有问题，也可能其他bug导致。

直接分析vmcore，先看下有哪些进程是D状态：

有5个进程是D状态，不清楚是哪个进程D状态导致的，又看了下vmcore-dmesg.txt，触发hung task检测条件的进程为1号进程，看下1号进程的调用栈：

从这个调用栈大概可以知道，1号进程（systemd）调用rmdir删除某个文件夹(系统调用号0x0000000000000054，RAX值)时，在内核态等待完成(wait_for_completion)时，系统长时间没有完成并唤醒该进程。首先大概分析看看是删除什么文件夹，根据64位系统调用原理，RDI寄存器里面的地址存储了应用层的文件路径，先获取对应的物理页：

物理页(PAGE)是a2c570，但是很遗憾，这个系统开启了swap,这个应用层物理页已经被swap out了，没法读取里面的内容，那只能在内核态栈里面找找了。

查看do_rmdir代码，在代码开始的地方，有几个局部变量name、dentry、nd。这几个变量里面应该都存储了路径相关的信息，但是这些变量不一定会保存在栈里面，有可能是保存在寄存器里面，这个需要结合汇编代码去分析，通过dis do_rmdir，找到call user_path_parent的地方，这个函数返回值是name，保存在rax寄存器中，我们发现汇编里面是直接使用的rax，并没有保存到栈里面，因此，我们无从知道name的内容；user_path_parent这个函数有四个参数，分别使用rdi,rsi,rdx,rcx传递，rdx中即保存了nd的地址，那rdx里面的地址是怎么来的呢，上图红框里面的那条汇编指令就是给rdx赋值：lea 0x10(%rsp)，%rdx，即把rsp+0x10的地址赋给了rdx，换句话说，rsp+0x10的地方就是nd的起始地址。bt -f 1看下do_rmdir的栈帧：

vmcore里面的do_rmdir的rsp是ffff8835b948fd58这个地址，但是这个时候应该是do_rmdir里面call了vfs_rmdir了，因此，在调用user_parent_path的时候，rsp应该是ffff8835b948fd60(后面只有call，没有push了)，所以nd的地址为ffff8835b948fd70(ffff8835b948fd60+0x10)，我们用这个地址看下nd里面的内容：

可以看到，是在删除一个名为sysstat.service的目录，不过这里只是last name，不是完整的路径，完整的路径还需要结合mnt和dentry去向上回溯，mnt和dentry也同样保存在nameidata里面。这里我就不继续分析到底是哪个完整路径了。

现在已经清楚，systemd 1号进程调用rmdir删除sysstat.service目录时，卡住了，至于为什么卡住，我们下面继续分析。还是回到systemd的内核栈帧上，从调用栈可以看出，do_rmdir里面调用了vfs_rmdir，vfs_rmdir里面调用了cgroup_rmdir，这个cgroup应该是和docker相关的技术，在cgroup_rmdir里面，最终调用了flush_work后，调用wait_for_completion等待完成，但是一直未能等待到，从而导致了panic。flush_work这个和Linux内核的工作队列有关，工作队列是Linux内核中异步执行的一种机制，用于延迟执行一些需要在进程上下文中执行的任务，而flush_work是需要等待work执行完成，才继续向下执行，相当于把异步变成了同步。

bool flush_work(struct work_struct *work)
{//// struct wq_barrier {// struct work_struct	work;// struct completion	done;// };//  wq_barrier有work信息，又有completion信息，既能执行work，又能等待完成struct wq_barrier barr;lock_map_acquire(&work->lockdep_map);lock_map_release(&work->lockdep_map);// start_flush_work主要就是设置barr的逻辑if (start_flush_work(work, &barr)) {// 等待，在这里面设置为D状态然后schedule，等待被唤醒，120s未被唤醒wait_for_completion(&barr.done);destroy_work_on_stack(&barr.work);return true;} else {return false;}
}

flush_work主要逻辑是在start_flush_work里面：

start_flush_work里面主要就是get和insert，最终会调用wake_up_process去唤醒对应的kworker线性去执行worker，所有的数据和结构都会保存到flush_work函数里面的barr这个栈变量中，如果知道了barr的地址，就可以知道最终是唤醒哪个kworker去执行的。

结合反汇编和源码，可以看到，rbp-0x68的地址即为barr的地址

那么flush_work的rbp地址是多少呢，上图所示，ffff8835b948fbf0这个地址是call flush_work自动压入的，此时rsp即为ffff8835b948fbf0，flush_work里面，先push了rbp，然后又mov rsp rbp，所以，rbp是ffff8835b948fbe8，即ffff8835b948fbf0-0x8，所以wq_barrier的地址为ffff8835b948fb80（ffff8835b948fbe8-0x68），看下里面的内容：

可以简单验证下找到的是否正确，这个结构里面有个func的函数指针，根据代码，这个函数指针指向了wq_barrier_func这个函数，看下我们获取的结构里面func是否为wq_barrier_func。

是一致的，于是可以确认找到的wq_barrier的地址是正确的，于是我们顺着wq_barrier->data这个藤，最终找到了worker这个瓜：

最终我们从woker里面找到了那个kworker线程，task为0xffff8835b886af70

这个kworker的名为kworker/3:2，也就是绑定在CPU3上的一个内核线程，这个线程从栈来看，还是一个被调度出去的状态，但是线程的state已经是RUNNING了，那就是说，这个线程已经被唤醒加入到runqueue等待执行了，通过runq命令看下执行队列的排队情况：

可以看到，kworker/3:2已经就绪，就等着前面的线程执行完成了，而当前正在执行的这个lo开头的线程是一个其他厂商的一个内核线程，有没有可能是这个线程某个原因死循环了，一直在跑，导致后面排队的线程得不到执行机会呢。

可以看到，这个线程确实有问题，占用了1038秒的CPU时间，但是只主动切换了1次，也就是说，这个内核线程一直在跑，基本就没有退出过，不过这种情况应该会导致soft_lockup才对，为啥vmcore-dmesg.txt里面没有呢，这个需要看下当前环境上softlockup的配置了，通过sysctl -a|grep watchdog以及sysctl -a|grep softlock可以看到，kernel.watchdog已经关闭，难怪没有能产生soft_lockup日志。如果开启的话，系统早就因为这个内核线程softlockup而panic了，根本不会因为这个问题再引出一个hung task的问题。至此，问题分析清楚，需要客户联系该厂商排查。

原文链接：https://zhuanlan.zhihu.com/p/691542282?utm_campaign=shareopn&utm_medium=social&utm_psn=1782729650826387458&utm_source=wechat_session