Web 服务器“任务被阻止超过 120 秒”

Web 服务器“任务被阻止超过 120 秒”

我的网络服务器每两天就会宕机一次。它变得没有响应,我只能在控制台上看到下面的消息。

任务****阻塞时间超过120秒。

解决这个问题的唯一方法是重置服务器,但这不太好,我想修复它。

我的服务器在 VMWare 环境中运行。

问题:

  • 14.89 的平均负载是我的问题吗?
  • 如果没有,我下一步该怎么做才能排除故障?

这是我的崩溃日志:

 KERNEL: /usr/lib/debug/lib/modules/2.6.32-431.3.1.el6.x86_64/vmlinux
    DUMPFILE: /var/crash/127.0.0.1-2014-08-26-01:25:16/vmcore  [PARTIAL DUMP]
        CPUS: 4
        DATE: Tue Aug 26 01:25:11 2014
      UPTIME: 00:14:00
LOAD AVERAGE: 14.89, 5.57, 2.09
       TASKS: 207
    NODENAME: test01
     RELEASE: 2.6.32-431.3.1.el6.x86_64
     VERSION: #1 SMP Fri Jan 3 21:39:27 UTC 2014
     MACHINE: x86_64  (2933 Mhz)
      MEMORY: 2 GB
       PANIC: "Kernel panic - not syncing: hung_task: blocked tasks"
         PID: 58
     COMMAND: "khungtaskd"
        TASK: ffff88007a4e9500  [THREAD_INFO: ffff88007a4ea000]
         CPU: 2
       STATE: TASK_RUNNING (PANIC)

...

INFO: task vmtoolsd:1186 blocked for more than 120 seconds.
      Not tainted 2.6.32-431.3.1.el6.x86_64 #1
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
vmtoolsd      D 0000000000000003     0  1186      1 0x00000000
 ffff88007bc39b98 0000000000000086 0000000000000000 ffff880037de6f28
 ffff88003793c800 ffff88007bc39c38 ffff88007bc39b38 ffffffffa00026d0
 ffff88007b847af8 ffff88007bc39fd8 000000000000fbc8 ffff88007b847af8
Call Trace:
 [<ffffffffa00026d0>] ? dm_unplug_all+0x50/0x70 [dm_mod]
 [<ffffffff8111f940>] ? sync_page+0x0/0x50
 [<ffffffff815280b3>] io_schedule+0x73/0xc0
 [<ffffffff8111f97d>] sync_page+0x3d/0x50
 [<ffffffff81528b7f>] __wait_on_bit+0x5f/0x90
 [<ffffffff8111fbb3>] wait_on_page_bit+0x73/0x80
 [<ffffffff8109b330>] ? wake_bit_function+0x0/0x50
 [<ffffffff81135c05>] ? pagevec_lookup_tag+0x25/0x40
 [<ffffffff8111ffdb>] wait_on_page_writeback_range+0xfb/0x190
 [<ffffffff8112009f>] filemap_fdatawait+0x2f/0x40
 [<ffffffff811206c4>] filemap_write_and_wait+0x44/0x60
 [<ffffffff811c5864>] __sync_blockdev+0x24/0x50
 [<ffffffff811c58a3>] sync_blockdev+0x13/0x20
 [<ffffffff811f0034>] sync_quota_sb+0x74/0x130
 [<ffffffff811bad1a>] __sync_filesystem+0x7a/0x90
 [<ffffffff811baf2b>] sync_filesystem+0x4b/0x70
 [<ffffffff811c61ee>] freeze_bdev+0xfe/0x280
 [<ffffffff8119de6b>] do_vfs_ioctl+0x1fb/0x580
 [<ffffffff8119e271>] sys_ioctl+0x81/0xa0
 [<ffffffff8100b072>] system_call_fastpath+0x16/0x1b
Kernel panic - not syncing: hung_task: blocked tasks
Pid: 58, comm: khungtaskd Not tainted 2.6.32-431.3.1.el6.x86_64 #1
Call Trace:
 [<ffffffff81527213>] ? panic+0xa7/0x16f
 [<ffffffff810e6346>] ? watchdog+0x246/0x250
 [<ffffffff810e6100>] ? watchdog+0x0/0x250
 [<ffffffff8109af06>] ? kthread+0x96/0xa0
 [<ffffffff8100c20a>] ? child_rip+0xa/0x20
 [<ffffffff8109ae70>] ? kthread+0x0/0xa0
 [<ffffffff8100c200>] ? child_rip+0x0/0x20

sar 详细信息

# sar -r
Linux 2.6.32-431.3.1.el6.x86_64 (test01)        08/26/2014      _x86_64_        (4 CPU)

12:00:01 AM kbmemfree kbmemused  %memused kbbuffers  kbcached  kbcommit   %commit
12:10:01 AM    287032   1634920     85.07    111308    937968    597956      9.88
12:20:01 AM    252300   1669652     86.87    113592    946640    633132     10.46
12:30:01 AM    229752   1692200     88.05    115680    958476    703876     11.63
12:40:01 AM    147420   1774532     92.33    121260   1045248    601400      9.94
12:50:02 AM    155808   1766144     91.89    125484   1037572    595232      9.84
01:00:01 AM    120928   1801024     93.71    128380   1043552    664652     10.98
Average:       198873   1723079     89.65    119284    994909    632708     10.46

01:11:22 AM       LINUX RESTART

01:26:05 AM       LINUX RESTART

01:40:45 AM       LINUX RESTART

01:55:30 AM       LINUX RESTART

02:00:01 AM kbmemfree kbmemused  %memused kbbuffers  kbcached  kbcommit   %commit
02:10:01 AM    993480    928472     48.31     56524    463256    599784      9.91
02:20:01 AM    965424    956528     49.77     68212    478076    591716      9.78
02:30:01 AM    874868   1047084     54.48     78216    508992    657420     10.87

# sar -q
Linux 2.6.32-431.3.1.el6.x86_64 (test01)        08/26/2014      _x86_64_        (4 CPU)

12:00:01 AM   runq-sz  plist-sz   ldavg-1   ldavg-5  ldavg-15
12:10:01 AM         2       183      0.08      0.71      0.86
12:20:01 AM         2       185      0.03      0.11      0.44
12:30:01 AM         5       207      1.98      1.28      0.77
12:40:01 AM         2       183      0.01      0.69      0.84
12:50:02 AM         1       181      0.00      0.10      0.43
01:00:01 AM         5       202      1.99      1.33      0.80
Average:            3       190      0.68      0.70      0.69

01:11:22 AM       LINUX RESTART

01:26:05 AM       LINUX RESTART

01:40:45 AM       LINUX RESTART

01:55:30 AM       LINUX RESTART

02:00:01 AM   runq-sz  plist-sz   ldavg-1   ldavg-5  ldavg-15
02:10:01 AM         2       184      0.05      0.13      0.11
02:20:01 AM         1       184      0.06      0.05      0.07
02:30:01 AM         8       204      2.07      1.33      0.61
02:40:01 AM         4       187      0.01      0.65      0.71

# sar -d
Linux 2.6.32-431.3.1.el6.x86_64 (test01)        08/26/2014      _x86_64_        (4 CPU)

12:00:01 AM       DEV       tps  rd_sec/s  wr_sec/s  avgrq-sz  avgqu-sz     await     svctm     %util
12:10:01 AM    dev8-0      8.96     60.88    141.18     22.54      0.24     27.08      3.74      3.35
12:10:01 AM   dev8-16      0.10      0.03      2.01     20.47      0.00     36.49     24.80      0.25
12:10:01 AM  dev253-0     21.05     60.68    143.19      9.69      0.58     27.56      1.60      3.36
12:10:01 AM  dev253-1      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00
12:20:01 AM    dev8-0      4.60     23.08     73.54     21.00      0.07     14.29      2.45      1.13
12:20:01 AM   dev8-16      0.06      0.01      1.08     17.73      0.00     29.70     13.68      0.08
12:20:01 AM  dev253-0      9.77     23.09     74.63     10.00      0.13     13.02      1.16      1.13
12:20:01 AM  dev253-1      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00
12:30:01 AM    dev8-0      3.13     32.93     41.52     23.80      0.03     10.57      3.58      1.12
12:30:01 AM   dev8-16      0.02      1.57      0.09     90.18      0.00     12.45     13.73      0.03
12:30:01 AM  dev253-0      6.01     34.93     41.61     12.75      0.06      9.46      1.89      1.14
12:30:01 AM  dev253-1      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00
12:40:01 AM    dev8-0     27.83    841.82    198.60     37.39      0.35     12.65      2.40      6.69
12:40:01 AM   dev8-16      2.46    202.41      2.21     83.16      0.01      5.28      4.29      1.06
12:40:01 AM  dev253-0     49.09   1043.80    200.80     25.35      3.62     73.59      1.53      7.52
12:40:01 AM  dev253-1      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00
12:50:02 AM    dev8-0      6.25     17.44    130.97     23.74      0.07     11.60      2.57      1.61
12:50:02 AM   dev8-16      0.63     56.52      3.12     94.54      0.01      8.11      4.74      0.30
12:50:02 AM  dev253-0     18.11     73.85    134.09     11.48      0.21     11.74      0.95      1.72
12:50:02 AM  dev253-1      0.01      0.11      0.00      8.00      0.00     13.88      1.75      0.00
01:00:01 AM    dev8-0      5.30     12.40     86.55     18.67      0.06     11.20      2.48      1.32
01:00:01 AM   dev8-16      0.09      0.23      2.36     27.57      0.00     22.68     11.36      0.11
01:00:01 AM  dev253-0     11.26     12.63     88.91      9.02      0.11      9.89      1.18      1.33
01:00:01 AM  dev253-1      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00

Average:          DEV       tps  rd_sec/s  wr_sec/s  avgrq-sz  avgqu-sz     await     svctm     %util
Average:       dev8-0      9.31    163.72    111.88     29.59      0.14     14.72      2.71      2.53
Average:      dev8-16      0.56     43.25      1.81     80.72      0.00      7.72      5.41      0.30
Average:     dev253-0     19.16    206.91    113.70     16.73      0.78     40.65      1.40      2.69
Average:     dev253-1      0.00      0.02      0.00      8.00      0.00     13.88      1.75      0.00

01:11:22 AM       LINUX RESTART

01:26:05 AM       LINUX RESTART

01:40:45 AM       LINUX RESTART

01:55:30 AM       LINUX RESTART

02:00:01 AM       DEV       tps  rd_sec/s  wr_sec/s  avgrq-sz  avgqu-sz     await     svctm     %util
02:10:01 AM    dev8-0      9.86    160.76     92.83     25.72      0.08      8.07      3.25      3.20
02:10:01 AM   dev8-16      1.03     43.08     21.27     62.61      0.01      8.14      4.74      0.49
02:10:01 AM  dev253-0     20.23    203.27    114.09     15.69      0.18      8.70      1.73      3.49
02:10:01 AM  dev253-1      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00
02:20:01 AM    dev8-0      4.76     74.76     51.09     26.42      0.03      6.83      3.51      1.67

答案1

我要做的第一件事就是停止/禁用 vmtoolsd 守护进程,如果您有 vmware 订阅,请向他们提出案例。这里看起来 vmtoolsd 守护进程正在试图冻结文件系统。

以下是您可以向 vmware 团队提供的进一步步骤

崩溃时提示运行

1:设置1186

2:BT

3:dis -rl 0xfe/0x280 即block_device传递给freeze_bdev()的地方

4:您还可以验证此过程处于不可中断状态的时间

a:任务-R last_ran

b: runq |grep “从 set 命令获得的 CPU 编号或此任务最后运行在哪个 CPU 上)

复制代码

pd(c 获得的值 - a 获得的值)/60 --> 这将告诉您 vmtoolsd 处于 D 状态的时间长度

另外,从操作系统方面来说,您可以进行一些更改,降低 vm.dirty_ratio 和 dirty_background_ratio 的值,因为这将快速刷新脏页。

但根据我的经验,我认为最好的方法是禁用 vmtoolsd,因为它有冻结文件系统的已知历史,并同时向 VMware 提出案例以了解他们的意见。

相关内容