红联Linux门户
Linux帮助

Linux服务器宕机案例第二则

发布时间:2017-03-30 09:48:42来源:cnblogs.com/kerrycode作者:潇湘隐者
邮件告警发现海外工厂一Linux服务器连接不上,DPA(Database Performance Analyzer)系统也发现其出现问题,ping这台服务器发现网络不通,联系不到当地系统管理员,邮件咨询后,这个系统管理员也发现有问题,直接重启了,事后检查发现日志message里面,从10:10分开始出现下面错误信息:
localhost kernel: ata2.00: qc timeout (cmd 0xa0)
localhost kernel: ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
localhost kernel: sr 2:0:0:0: CDB: Test Unit Ready: 00 00 00 00 00 00
localhost kernel: ata2.00: cmd a0/00:00:00:00:00/00:00:00:00:00/a0 tag 0
localhost kernel: res 51/20:03:00:00:00/00:00:00:00:00/a0 Emask 0x5 (timeout)
localhost kernel: ata2.00: status: { DRDY ERR }
localhost kernel: ata2: soft resetting link
localhost kernel: INFO: task hald-addon-stor:3728 blocked for more than 120 seconds.
localhost kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
localhost kernel: hald-addon-st D ffff8801989b6080     0  3728   3690 0x00000080
localhost kernel:  ffff880428dd76a8 0000000000000082 ffff880428dd7668 ffff88042c6300d0
localhost kernel:  ffff8804294ac0c0 ffff88040d730700 ffff8804294ac490 ffffffff812ef88e
localhost kernel:  ffff880428dd76a8 ffffffff81311442 ffff88042c630000 7fffffffffffffff
localhost kernel: Call Trace:
localhost kernel:  [<ffffffff812ef88e>] ? scsi_done+0x0/0x17
localhost kernel:  [<ffffffff81311442>] ? __ata_scsi_queuecmd+0x1a6/0x200
localhost kernel:  [<ffffffff814527e9>] schedule_timeout+0x36/0xe7
localhost kernel:  [<ffffffff812331b6>] ? kobject_put+0x47/0x4c
localhost kernel:  [<ffffffff8104367e>] ? need_resched+0x23/0x2d
localhost kernel:  [<ffffffff8145265b>] wait_for_common+0xb7/0x12c
localhost kernel:  [<ffffffff8104cf2f>] ? default_wake_function+0x0/0x19
localhost kernel:  [<ffffffff8121e449>] ? __generic_unplug_device+0x32/0x37
localhost kernel:  [<ffffffff81452773>] wait_for_completion+0x1d/0x1f
localhost kernel:  [<ffffffff8122540b>] blk_execute_rq+0xcb/0x104
localhost kernel:  [<ffffffff8121d88c>] ? freed_request+0x34/0x55
localhost kernel:  [<ffffffff812f60af>] scsi_execute+0xde/0x12e
localhost kernel:  [<ffffffff812f61cc>] scsi_execute_req+0xcd/0xf2
localhost kernel:  [<ffffffff81302a9a>] sr_test_unit_ready+0x5c/0xb5
localhost kernel:  [<ffffffff81302d0f>] sr_media_change+0x5d/0x28a
localhost kernel:  [<ffffffff810448c9>] ? task_rq_unlock+0x11/0x13
localhost kernel:  [<ffffffff8104cf08>] ? try_to_wake_up+0x3aa/0x3d1
localhost kernel:  [<ffffffff8131f73f>] media_changed+0x53/0x88
localhost kernel:  [<ffffffff8131f7a5>] cdrom_media_changed+0x31/0x37
localhost kernel:  [<ffffffff81303072>] sr_block_media_changed+0x19/0x1b
localhost kernel:  [<ffffffff8114407d>] check_disk_change+0x29/0x5b
localhost kernel:  [<ffffffff81322f9b>] cdrom_open+0x919/0x9b9
localhost kernel:  [<ffffffff810447f2>] ? __wake_up_sync_key+0x53/0x5f
localhost kernel:  [<ffffffff8142ebec>] ? unix_stream_recvmsg+0x40f/0x4d3
localhost kernel:  [<ffffffff813b63b5>] ? skb_release_data+0xaa/0xaf
localhost kernel:  [<ffffffff8142ebec>] ? unix_stream_recvmsg+0x40f/0x4d3
localhost kernel:  [<ffffffff8104367e>] ? need_resched+0x23/0x2d
Linux服务器宕机案例第二则
 
系统版本为Oracle Linux Server release 5.7, VMware虚拟机,刚开始检查的时候,注意力集中在“ kernel: INFO: task hald-addon-stor:3728 blocked for more than 120 seconds”等相关信息上,关于hald-addon-store,这个是挂载媒体设备读写操作的进程,它是一个硬件守护进程,不停的检测有没有设备接入接出。
[root@localhost log]# grep 'Jul  7' messages | grep -E 'more than 120 seconds|hung_task_timeout_secs'
localhost kernel: INFO: task hald-addon-stor:3728 blocked for more than 120 seconds.
localhost kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
localhost kernel: INFO: task hald-addon-stor:3728 blocked for more than 120 seconds.
localhost kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
localhost kernel: INFO: task hald-addon-stor:3728 blocked for more than 120 seconds.
localhost kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[root@localhost log]# 
 
而关于“task blocked for more than 120 seconds”,网上很多资料都千篇一律的说,修改参数 vm.dirty_ratio 和 vm.dirty_backgroud_ratio 可以避免这个问题。但是我对这个还是有点疑虑,理由如下一些:
 
1、这台服务器的vm.dirty_background_ratio 参数为10,vm.dirty_ratio为20。这个我查了一下,Redhat的官方文档介绍这是默认值。
[root@localhost log]# sysctl -a | grep 'vm.dirty'
vm.dirty_background_ratio = 10
vm.dirty_background_bytes = 0
vm.dirty_ratio = 20
vm.dirty_bytes = 0
vm.dirty_writeback_centisecs = 500
vm.dirty_expire_centisecs = 3000
 
2、这台服务器已经运行好多年了,如果这个参数有问题,理应经常出现这个问题,但是到目前为止只出现了一次这个问题。
 
3、我们还有多台服务器都是这个操作系统版本,内核参数同样是官方的默认值,也没有见到其出现过这样的问题。
 
当然也不排除某些操作触发了某些临界值导致了这个错误。那么我们还是继续分析一下错误信息吧,看能否挖掘出一些信息。
sar -r 查看发现这一段时间的内存使用情况,已使用内存的百分数(%memused)非常高,已使用交换空间的百分数(%swapused)比例也在个位数到40%直接,服务器在10:31重启,10:00 到10:30之间的数据没有,不清楚什么原因导致。从这些数据也可以看出内存资源非常紧张。
Linux服务器宕机案例第二则
 
另外也用sar -u查看了CPU,CPU使用率不高。基本正常,当时忘记查看I/O和传送速率的统计信息(现在去查看,已经看不到昨天的数据了),另外在message日志里面看到有"ata2.00: status: { DRDY ERR }", "ata2.00: qc timeout(cmd 0xa0)"; 之类的错误信息
Linux服务器宕机案例第二则
 
关于这个错误,很多资料都说是硬盘故障或硬盘读写错误等等。也有说是内核bug的
Linux服务器宕机案例第二则
 
当然我们系统的内核版本为2.6.32-200.13.1.el5uek ,这个https://lists.linuxfoundation.org/pipermail/bugme-new/2009-July/022389.html 链接也说了不止出现在2.6.31这个内核版本:
I have seen this messages not only on 2.6.31... also on many other 2.6 kernels.
 
但是自己的知识和经验也无法判断、定位问题,只能有个模糊的判断,要么是硬盘故障或读写错误,要么是内核错误。让那边系统管理员去检查存储设备是否有什么告警,暂时没有回馈,检查磁盘分区是否存在坏块,发现没有坏块情况
[root@localhost ~]# /sbin/badblocks -v /dev/sda
Checking blocks 0 to 104857600
Checking for bad blocks (read-only test): done
Pass completed, 0 bad blocks found.
[root@localhost ~]# /sbin/badblocks -v /dev/sdb
Checking blocks 0 to 157286400
Checking for bad blocks (read-only test): done
Pass completed, 0 bad blocks found.
[root@localhost ~]# /sbin/badblocks -v /dev/sdc
Checking blocks 0 to 41943040
Checking for bad blocks (read-only test): done
Pass completed, 0 bad blocks found.
[root@localhost ~]# /sbin/badblocks -v /dev/sdd
Checking blocks 0 to 104857600
Checking for bad blocks (read-only test): done
Pass completed, 0 bad blocks found.
[root@localhost ~]# /sbin/badblocks -v /dev/sde
Checking blocks 0 to 188743680
Checking for bad blocks (read-only test): done
Pass completed, 0 bad blocks found.
 
另外在message里面发现系统启动时,有大量BAR 13: can't allocate I/O resource [0x10000-0xffff]信息。
egvlnx03 kernel: ACPI: ACPI bus type pnp unregistered
egvlnx03 kernel: system 00:01: ioport range 0x1000-0x103f has been reserved
egvlnx03 kernel: system 00:01: ioport range 0x1040-0x104f has been reserved
egvlnx03 kernel: system 00:01: ioport range 0xcf0-0xcf1 has been reserved
egvlnx03 kernel: system 00:08: iomem range 0xfed00000-0xfed003ff has been reserved
egvlnx03 kernel: system 00:0d: ioport range 0xfce0-0xfcff has been reserved
egvlnx03 kernel: system 00:0d: iomem range 0xf0000000-0xf7ffffff has been reserved
egvlnx03 kernel: system 00:0d: iomem range 0xfe800000-0xfe9fffff has been reserved
egvlnx03 kernel: pci 0000:00:15.3: BAR 13: can't allocate I/O resource [0x10000-0xffff]
egvlnx03 kernel: pci 0000:00:15.4: BAR 13: can't allocate I/O resource [0x10000-0xffff]
egvlnx03 kernel: pci 0000:00:15.5: BAR 13: can't allocate I/O resource [0x10000-0xffff]
egvlnx03 kernel: pci 0000:00:15.6: BAR 13: can't allocate I/O resource [0x10000-0xffff]
egvlnx03 kernel: pci 0000:00:15.7: BAR 13: can't allocate I/O resource [0x10000-0xffff]
egvlnx03 kernel: pci 0000:00:16.3: BAR 13: can't allocate I/O resource [0x10000-0xffff]
egvlnx03 kernel: pci 0000:00:16.4: BAR 13: can't allocate I/O resource [0x10000-0xffff]
egvlnx03 kernel: pci 0000:00:16.5: BAR 13: can't allocate I/O resource [0x10000-0xffff]
egvlnx03 kernel: pci 0000:00:16.6: BAR 13: can't allocate I/O resource [0x10000-0xffff]
egvlnx03 kernel: pci 0000:00:16.7: BAR 13: can't allocate I/O resource [0x10000-0xffff]
egvlnx03 kernel: pci 0000:00:17.3: BAR 13: can't allocate I/O resource [0x10000-0xffff]
egvlnx03 kernel: pci 0000:00:17.4: BAR 13: can't allocate I/O resource [0x10000-0xffff]
egvlnx03 kernel: pci 0000:00:17.5: BAR 13: can't allocate I/O resource [0x10000-0xffff]
egvlnx03 kernel: pci 0000:00:17.6: BAR 13: can't allocate I/O resource [0x10000-0xffff]
egvlnx03 kernel: pci 0000:00:17.7: BAR 13: can't allocate I/O resource [0x10000-0xffff]
egvlnx03 kernel: pci 0000:00:18.2: BAR 13: can't allocate I/O resource [0x10000-0xffff]
egvlnx03 kernel: pci 0000:00:18.3: BAR 13: can't allocate I/O resource [0x10000-0xffff]
egvlnx03 kernel: pci 0000:00:18.4: BAR 13: can't allocate I/O resource [0x10000-0xffff]
egvlnx03 kernel: pci 0000:00:18.5: BAR 13: can't allocate I/O resource [0x10000-0xffff]
egvlnx03 kernel: pci 0000:00:18.6: BAR 13: can't allocate I/O resource [0x10000-0xffff]
egvlnx03 kernel: pci 0000:00:18.7: BAR 13: can't allocate I/O resource [0x10000-0xffff]
 
经过查证,有篇文章解释了这个消息出现的原因,并表示可以忽略这个问题。
该消息表明内核无法分配预取内存插槽。
预取内存插槽的编号是 13(PCI_BRIDGE_RESOURCES)。
如果系统在 PCI 总线上有 13 个 PCI 桥设备,则会记录以上消息。
虽然记录了该条消息,但是内核使用的是非预取窗口,而不是预取区域。 所以,可以忽略该问题。
内核参数我们暂时不打算修改,暂时只能先建议系统管理员增加内存资源,再观察系统具体运行情况。 
 
本文永久更新地址:http://www.linuxdiyf.com/linux/29591.html