hung task日志linux,一次内核hung task分析

最新推荐文章于 2024-09-26 16:35:35 发布

谭康熹

最新推荐文章于 2024-09-26 16:35:35 发布

阅读量304

点赞数

文章标签： hung task日志linux

1、内核hung task检测机制由来

我们知道进程等待IO时，经常处于D状态，即TASK_UNINTERRUPTIBLE状态，处于这种状态的进程不处理信号，所以kill不掉，如果进程长期处于D状态，那么肯定不正常，原因可能有二：

1)IO路径上的硬件出问题了，比如硬盘坏了(只有少数情况会导致长期D，通常会返回错误)；

2)内核自己出问题了。

这种问题不好定位，而且一旦出现就通常不可恢复，kill不掉，通常只能重启恢复了。

内核针对这种开发了一种hung task的检测机制，基本原理是：定时检测系统中处于D状态的进程，如果其处于D状态的时间超过了指定时间(默认120s，可以配置)，则打印相关堆栈信息，也可以通过proc参数配置使其直接panic。

2、hung task相关配置

1)设置timeout时间：

echo xx > /proc/sys/kernel/hung_task_timeout_secs

xx单位为s。

2)设置hung task后是否触发panic

echo 1 > /proc/sys/kernel/hung_task_panic

3、分析示例

今天遇到个hung task的问题，简单记录下分析过程

1)问题现象

控制台上有如下异常打印：

Aug 6 21:17:22 localhost kernel: Appxxx[13608] general protection ip:32be275204 sp:7ff6ad465750 error:0 in libc-2.12.so[32be200000+197000]

...

Aug 6 21:20:47 localhost kernel: INFO: task Appxxx:13189 blocked for more than 120 seconds.

Aug 6 21:20:47 localhost kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

Aug 6 21:20:47 localhost kernel: ZMSSStreaming D 000000000000000d 0 13189 1 0x00000080

Aug 6 21:20:47 localhost kernel: ffff88089c77fc98 0000000000000086 0000000000000001 0000000000000282

Aug 6 21:20:47 localhost kernel: ffff88089c77fc68 ffffffff810a4210 0000000000000000 ffff8807cc4cecd8

Aug 6 21:20:47 localhost kernel: ffff880bfe0d30b8 ffff88089c77ffd8 000000000000f4e8 ffff880bfe0d30b8

Aug 6 21:20:47 localhost kernel: Call Trace:

Aug 6 21:20:47 localhost kernel: [] ? exit_robust_list+0x90/0x160

Aug 6 21:20:47 localhost kernel: [] exit_mm+0x95/0x180

Aug 6 21:20:47 localhost kernel: [] do_exit+0x15f/0x870

Aug 6 21:20:47 localhost kernel: [] ? dequeue_entity+0x105/0x2e0

Aug 6 21:20:47 localhost kernel: [] ? __dequeue_entity+0x30/0x50

Aug 6 21:20:47 localhost kernel: [] do_group_exit+0x58/0xe0

Aug 6 21:20:47 localhost kernel: [] get_signal_to_deliver+0x1f6/0x460

Aug 6 21:20:47 localhost kernel: [] do_signal+0x75/0x800

Aug 6 21:20:47 localhost kernel: [] ? hrtimer_cancel+0x22/0x30

Aug 6 21:20:47 localhost kernel: [] ? do_nanosleep+0x93/0xc0

Aug 6 21:20:47 localhost kernel: [] ? hrtimer_nanosleep+0xc4/0x180

Aug 6 21:20:47 localhost kernel: [] ? hrtimer_wakeup+0x0/0x30

Aug 6 21:20:47 localhost kernel: [] do_notify_resume+0x90/0xc0

Aug 6 21:20:47 localhost kernel: [] int_signal+0x12/0x17

Aug 6 21:20:47 localhost kernel: INFO: task ZMSSStreamingSe:13239 blocked for more than 120 seconds.

Aug 6 21:20:47 localhost kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

Aug 6 21:20:47 localhost kernel: ZMSSStreaming D 0000000000000000 0 13239 1 0x00000080

Aug 6 21:20:47 localhost kernel: ffff8808ca951c98 0000000000000086 ffff8801193b80c0 0000000000000005

Aug 6 21:20:47 localhost kernel: ffff8808ca951c68 ffffffff810a4210 000000101d1b9400 ffff8801193b80f8

Aug 6 21:20:47 localhost kernel: ffff880c0422c678 ffff8808ca951fd8 000000000000f4e8 ffff880c0422c678

Aug 6 21:20:47 localhost kernel: Call Trace:

Aug 6 21:20:47 localhost kernel: [] ? exit_robust_list+0x90/0x160

Aug 6 21:20:47 localhost kernel: [] exit_mm+0x95/0x180

Aug 6 21:20:47 localhost kernel: [] do_exit+0x15f/0x870

Aug 6 21:20:47 localhost kernel: [] ? dequeue_entity+0x105/0x2e0

Aug 6 21:20:47 localhost kernel: [] do_group_exit+0x58/0xe0

Aug 6 21:20:47 localhost kernel: [] get_signal_to_deliver+0x1f6/0x460

Aug 6 21:20:47 localhost kernel: [] do_signal+0x75/0x800

Aug 6 21:20:47 localhost kernel: [] ? hrtimer_nanosleep+0xe7/0x180

Aug 6 21:20:47 localhost kernel: [] ? hrtimer_wakeup+0x0/0x30

Aug 6 21:20:47 localhost kernel: [] do_notify_resume+0x90/0xc0

Aug 6 21:20:47 localhost kernel: [] int_signal+0x12/0x17

2)分析

从阻塞进程的堆栈看，应该是在信号处理过程中，进程退出时阻塞了，最终阻塞的地方在：

Aug 6 21:20:47 localhost kernel: [] exit_mm+0x95/0x180

反汇编再结合源代码确认在

wait_for_completion(&mm->core_done)

而wait_for_completion，默认就是进入D状态等待：

void __sched wait_for_completion(struct completion *x)

{

wait_for_common(x, MAX_SCHEDULE_TIMEOUT, TASK_UNINTERRUPTIBLE);

}

mm->core_done其实就是在等待进程的coredump收集完成，说明此时该进程可能正在收集coredump

结合hung task之前的日志，发现该业务进程发生了段错误：Aug 6 21:17:22 localhost kernel: Appxxx[13608] general protection ip:32be275204 sp:7ff6ad465750 error:0 in libc-2.12.so[32be200000+197000]

那就对上了，用户态进程发生段错误后，内核默认会向该进程发送信号，使其退出，正符合上述的堆栈逻辑。

那么总结起来，这个问题即因为：业务进程Appxxx出现了段错误，从而需要进行coredump的搜集，同时需要向业务进程发送信号使其终止运行，业务进程在处理信号，退出过程中，需要等coredump搜集完成，从而一直处于D状态，而因为业务进程占用的内存比较大导致收集时间比较长，超过了2分钟，所以出现了阻塞，触发hung task检测，但后来coredump收集完成后就自动恢复了。

注：本篇内容非原创，只不过在非析某问题时从网上查看到，刚好现网部分主机经常也没有kdump生成，而在message里有超过120秒的情况下产生堆栈信息和发生call trace的情况。这里提供了分析的一个思路。这里摘录下来。