Linux运行卡死【INFO: task multipathd:5832 blocked for more than 120 seconds】

发布时间 2023-05-08 10:22:22作者: 树苗叶子

问题背景

系统在正常运行过程中,突然收到监控平台告警,服务器无法ping通。

分析过程

机房人员重启服务器后,查看/var/log/messages日志发现如下报错:

May  6 19:43:45 xxx kernel: INFO: task multipathd:5832 blocked for more than 120 seconds.
May  6 19:43:45 xxx kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
May  6 19:43:45 xxx kernel: multipathd    D 0000000000000008     0  5832      1 0x00000000
May  6 19:43:45 xxx kernel: ffff88110341d968 0000000000000082 0000000000000000 ffff881007b2b800
May  6 19:43:45 xxx kernel: ffffffff8136a2b0 ffff8810b5ce12c0 ffff88110341d938 ffffffffa03d1e1e
May  6 19:43:45 xxx kernel: ffff881649c71098 ffff88110341dfd8 000000000000fb88 ffff881649c71098
May  6 19:43:45 yqhl-db2 kernel: Call Trace:
May  6 19:43:45 yqhl-db2 kernel: [<ffffffff8136a2b0>] ? scsi_done+0x0/0x60
May  6 19:43:45 yqhl-db2 kernel: [<ffffffffa03d1e1e>] ? qla2xxx_queuecommand+0x35e/0x370 [qla2xxx]
May  6 19:43:45 yqhl-db2 kernel: [<ffffffff81505b05>] schedule_timeout+0x215/0x2e0
May  6 19:43:45 yqhl-db2 kernel: [<ffffffff8107e44d>] ? del_timer+0x7d/0xe0
May  6 19:43:45 yqhl-db2 kernel: [<ffffffff81505783>] wait_for_common+0x123/0x180
May  6 19:43:45 yqhl-db2 kernel: [<ffffffff81060500>] ? default_wake_function+0x0/0x20
May  6 19:43:45 yqhl-db2 kernel: [<ffffffff8150589d>] wait_for_completion+0x1d/0x20
May  6 19:43:45 yqhl-db2 kernel: [<ffffffff812633cc>] blk_execute_rq+0x8c/0xf0
May  6 19:43:45 yqhl-db2 kernel: [<ffffffff81049198>] ? gup_pud_range+0x148/0x1d0
May  6 19:43:45 yqhl-db2 kernel: [<ffffffff81219809>] ? security_capable+0x29/0x30
May  6 19:43:45 yqhl-db2 kernel: [<ffffffff81078b7a>] ? capable+0x2a/0x60
May  6 19:43:45 yqhl-db2 kernel: [<ffffffff81267cf2>] sg_io+0x212/0x3d0
May  6 19:43:45 yqhl-db2 kernel: [<ffffffff812682b0>] scsi_cmd_ioctl+0x400/0x470
May  6 19:43:45 yqhl-db2 kernel: [<ffffffff810a499e>] ? futex_wake+0x10e/0x120
May  6 19:43:45 yqhl-db2 kernel: [<ffffffff81268371>] scsi_cmd_blk_ioctl+0x51/0x70
May  6 19:43:45 yqhl-db2 kernel: [<ffffffffa044316f>] sd_ioctl+0xaf/0x110 [sd_mod]
May  6 19:43:45 yqhl-db2 kernel: [<ffffffff81264e77>] __blkdev_driver_ioctl+0x67/0x80
May  6 19:43:45 yqhl-db2 kernel: [<ffffffff812652fd>] blkdev_ioctl+0x1ed/0x6e0
May  6 19:43:45 yqhl-db2 kernel: [<ffffffff811ba29c>] block_ioctl+0x3c/0x40
May  6 19:43:45 yqhl-db2 kernel: [<ffffffff81194842>] vfs_ioctl+0x22/0xa0
May  6 19:43:45 yqhl-db2 kernel: [<ffffffff811949e4>] do_vfs_ioctl+0x84/0x580
May  6 19:43:45 yqhl-db2 kernel: [<ffffffff810097cc>] ? __switch_to+0x1ac/0x320
May  6 19:43:45 yqhl-db2 kernel: [<ffffffff81194f61>] sys_ioctl+0x81/0xa0
May  6 19:43:45 yqhl-db2 kernel: [<ffffffff8100b0f2>] system_call_fastpath+0x16/0x1b

使用如下关键字搜索:

INFO: task multipathd:5832 blocked for more than 120 seconds.

/proc/sys/kernel/hung_task_timeout_secs

结果是Linux系统BUG。

以下信息来自网络:

仔细阅读打印信息发现关键信息是“hung_task_timeout_secs”,通过搜索,发现这是linux kernel的一个bug。

大家对这个问题的解释也都比较一致,摘抄一段:

By default Linux uses up to 40% of the available memory for file system caching.

After this mark has been reached the file system flushes all outstanding data to disk causing all following IOs going synchronous.

For flushing out this data to disk this there is a time limit of 120 seconds by default.

In the case here the IO subsystem is not fast enough to flush the data withing 120 seconds.

This especially happens on systems with a lot of memory.

The problem is solved in later kernels。

一般情况下,Linux会把可用内存的40%的空间作为文件系统的缓存。

当缓存快满时,文件系统将缓存中的数据整体同步到磁盘中。但是系统对同步时间有最大120秒的限制。

如果文件系统不能在时间限制之内完成数据同步,则会发生上述的错误。

这通常发生在内存很大的系统上。系统内存大,则缓冲区大,同步数据所需要的时间就越长,超时的概率就越大。

Linux会设置40%的可用内存用来做系统cache,当flush数据时这40%内存中的数据由于和IO同步问题导致超时(120s),所将40%减小到10%,避免超时。

解决方法

缩小文件系统缓存大小

降低缓存占内存的比例,比如由40%降到10%,这样的话需要同步到磁盘上的数据量会变小,IO写时间缩短,会相对比较平稳。

文件系统缓存的大小是由内核参数vm.dirty_ratiovm.dirty_backgroud_ratio控制决定的。

vm.dirty_background_ratio指定当文件系统缓存脏页数量达到系统内存百分之多少时(如5%)就会触发pdflush/flush/kdmflush等后台回写进程运行,将一定缓存的脏页异步地刷入外存。

vm.dirty_ratio则指定了当文件系统缓存脏页数量达到系统内存百分之多少时(如10%),系统不得不开始处理缓存脏页(因为此时脏页数量已经比较多,为了避免数据丢失需要将一定脏页刷入外存),在此过程中很多应用进程可能会因为系统转而处理文件IO而阻塞。

通常情况下,vm.dirty_ratio的值要大于vm.dirty_background_ratio的值。

# 编辑参数文件
vi /etc/sysctl.conf
# 添加下面两个参数
vm.dirty_background_ratio=5
vm.dirty_ratio=10
# 使参数生效
# sysctl -p