某客户S2600T交换机故障后业务异常问题分析报告v1.0

发布时间:  2015-11-26 浏览次数:  765 下载次数:  8
问题描述

(1) 故障发生时间:  2014-10-16 19:59:14
(2) 故障恢复时间:  2014-10-18 02:40:00
(3) 故障的业务影响范围: S2600T存储对应的两台SUSE11主机(主机名为:pnxfh0eapnew01和pnxfh0eapnew02)业务异常,业务人员尝试修复时,执行umount操作,后重新mount时报错。
(4) 故障现象的详细描述: 10月16日晚上20点左右,S2600T存储(序列号:210235862510E7000030)所连的交换机A故障,交换机故障在1分钟左右后恢复,S2600T所连的2台SUSE11主机业务异常,业务人员经过各种尝试进行修复,并且umount了相应存储空间,后mount时失败,S2600T上未看到异常,所连接的其它主机(VMware)业务正常。
(5) 故障后现场恢复过程:
2014-10-16 19:59:14 交换机A故障,修复1分钟后故障恢复,业务侧发现异常,业务人员尝试修复。
2014-10-17 19:30:00 客户上升到华为,分析存储日志未发现异常,ISM界面看到SUSE主机只有2条路径;主机侧mount失败。
2014-10-17 22:30:00 业务人员继续讨论和决策各种恢复方案,计划使用文件系统修复命令进行修复,需要提供11TB至20TB存储空间,先将数据备份,华为
计划从备件库攒一套存储。
2014-10-18 02:50:00 客户复位主机,业务恢复,确认业务正常。
2014-10-18 04:00:00 收集主机日志,现场人员撤离。

处理过程

存储日志分析:

S2600T存储在本次问题的时间段内,未出现I/O超时、I/O错误等异常,和交换机的断开和重连处理过程正常,在ISM上看到2台SUSE主机都只有2条路径(对应同一个启动器)是正常的,以下是详细分析过程。
存储在2014-10-16 20:00:06感知到交换机A故障,上报2个端口断开,分别是A、B控的P0端口,告警在约1分钟后恢复(第一个时间是故障时间,第二个时间为恢复时间):
2014-10-16 20:00:06    0xe020b0001    Major    2014-10-16 20:00:59    The link to the FC host port (controller enclosure 0, FC interface module B0, port P0) is down.    Step 1 Check whether the cable to the host port is removed or damaged.
2014-10-16 20:00:07    0xe020b0001    Major    2014-10-16 20:01:01    The link to the FC host port (controller enclosure 0, FC interface module A0, port P0) is down.    Step 1 Check whether the cable to the host port is removed or damaged.
存储message中检查到主机名为pnxfh0eapnew01的启动器10000000c9c6fa78链接断开:
[2014-10-16 20:00:00][1367569800][5400040e0e77][INF][ Found lgnInfo.NPortID 0x440100 WWN: 10000000c9c6fa78 sess ffff88013eb20de0][FC_TGT][PF_TGTBr.GTDown,2123][swapper]
[2014-10-16 20:00:00][1367569800][5400040e0e7b][INF][TGT_LinkDown port(0x110000), session ffff88013eb20de0, pLgn ffffc90006a36840, nLogins 63][FC_TGT][PF_TGTBr.GTDown,2142][swapper]
1分钟左右之后,重新建立链接,端口断开告警恢复:
[2014-10-16 20:01:01][1367585125][15000000d0020][INFO][Continue previous log:print details info:Wwn(10000000c9c6fa78), Host(ffff88006cb11e00),Portid(110000), Sessiontype(1){0:Mirror 1:Host 2:Switch}][TGT][TGT_LinkUp,2256]
[2014-10-16 20:01:01][1367585125][5400040e3425][INF][DRV_TGT_LINKUP port 110000, session ffff88013eb91360, fc4 tgt pLgn ffffc90006f11d78, nLogins 48][FC_TGT][PF_Repor.rtConn,614][swapper]
以上过程处理正常,存储中未看到I/O超时、I/O错误等异常打印。
现场反馈主机102.0.33.102(pnxfh0eapnew01)配置2个启动器,但路径信息中启动器10000090fa4ffb0c对应的路径的物理主机名为无效值:

主机侧多路径只能看2条路径,而且对应同一个启动器10000000c9c6fa78:

由此可见,另外1个启动器10000090fa4ffb0c对应的路径并未建立。主机102.00.33.103(pnxfh0eapnew02)对应的情况是一样的,只有1个启动器的2条路径是正常。

主机日志分析:

主机与S2600T存储之间只有2条路径,这2条路径对应同一个启动器,该启动器所连接的交换机A故障后,主机到存储之间无业务路径,导致I/O error,文件系统受损。以下是详细分析过程。
主机102.0.33.102(pnxfh0eapnew01)使用14个1000G的LUN创建1个VG:datavg
  VG     #PV #LV #SN Attr   VSize   VFree 
  datavg  14   1   0 wz--n-  13.67t   3.67t
在该vg上创建1个10T的lv:data,对应的盘符为/dev/mapper/datavg-data
  LV     VG     Attr   LSize  Origin Snap%  Move Log Copy%  Convert
  data   datavg -wi-ao 10.00t    
/dev/mapper/datavg-data上创建的是reiserf,挂载点为/data
/dev/mapper/datavg-data on /data type reiserfs (rw)
/dev/mapper/datavg-data 在底层对应的设备名为:dm-6
dm-name-datavg-data -> ../../dm-6
在10月16日19:59:13驱动报两条链路断开。
Oct 16 19:59:13 pnxfh0eapnew01 kernel: [2925286.350690]  rport-0:0-2: blocked FC remote port time out: removing target and saving binding
Oct 16 19:59:13 pnxfh0eapnew01 kernel: [2925286.350940]  rport-0:0-3: blocked FC remote port time out: removing target and saving binding
在10月16日19:59:23开始,dm-6上有大量I/O error打印:
Oct 16 19:59:23 pnxfh0eapnew01 kernel: [2925286.366113] Buffer I/O error on device dm-6, logical block 2469144558
...
Oct 16 19:59:23 pnxfh0eapnew01 kernel: [2925286.366188] Buffer I/O error on device dm-6, logical block 2469144559
...
Oct 16 19:59:23 pnxfh0eapnew01 kernel: [2925286.367029] Buffer I/O error on device dm-6, logical block 2469144560
多路径将Path ID为0和1的两条路径状态置为failed,说明故障交换机连接启动器10000000c9c6fa78(对应的路径ID为0和1):
Oct 16 19:59:25 pnxfh0eapnew01 kernel: [2925286.375045] [2256][2014-10-16 19:59:13:592499][00005342053702d5][INFO][LPM][LPM_PingActivePathDone][725]Path becomes {XMP_PATH_FAILED} from {XMP_PATH_ACTIVE}. disk {13},tpg {1}, path {0}
Oct 16 19:59:25 pnxfh0eapnew01 kernel: [2925286.410884] [2281][2014-10-16 19:59:13:628377][00005342053702d5][INFO][LPM][LPM_PingActivePathDone][725]Path becomes {XMP_PATH_FAILED} from {XMP_PATH_ACTIVE}. disk {13},tpg {0}, path {1}
多路径找不到可用路径,所有路径都是断开的:
Oct 16 19:59:25 pnxfh0eapnew01 kernel: [2925286.387595] [2265][2014-10-16 19:59:13:605053][0000534205310bb6][ERROR][LPM][LPM_AsynchronousCmd][2998]select path fail. pass to upper layer
10月17日16:30:11 REISERFS文件系统开始报错,存在大量I/O error
Oct 17 16:30:11 pnxfh0eapnew01 kernel: [2999064.067574] REISERFS error (device dm-6): vs-13070 reiserfs_read_locked_inode: i/o failure occurred trying to find stat data of [994 17196 0x0 SD]
在10月18日02:49:45,OS重启,发现了受损的REISERFS,系统在自动挂载时,自行用log进行了修复:
Oct 18 02:49:45 pnxfh0eapnew01 kernel: [   89.150911] REISERFS (device dm-6): found reiserfs format "3.6" with standard journal
Oct 18 02:49:45 pnxfh0eapnew01 kernel: [   89.151053] REISERFS (device dm-6): using ordered data mode
Oct 18 02:49:45 pnxfh0eapnew01 kernel: [   89.163416] REISERFS (device dm-6): journal params: device dm-6, size 8192, journal first block 18, max trans len 1024, max batch 900, max commit age 30, max trans age 30
Oct 18 02:49:45 pnxfh0eapnew01 kernel: [   89.163940] REISERFS (device dm-6): checking transaction log (dm-6)
Oct 18 02:49:47 pnxfh0eapnew01 kernel: [   91.080718] REISERFS (device dm-6): replayed 205 transactions in 2 seconds
Oct 18 02:49:47 pnxfh0eapnew01 kernel: [   91.090988] REISERFS (device dm-6): Using r5 hash to sort names
主机102.0.33.103(pnxfh0eapnew02)的处理过程类似:
在10月16日19:59:08驱动报两条链路断开。
Oct 16 19:58:08 pnxfh0eapnew02 kernel: [2925089.174846]  rport-0:0-2: blocked FC remote port time out: removing target and saving binding
Oct 16 19:58:08 pnxfh0eapnew02 kernel: [2925089.175087]  rport-0:0-4: blocked FC remote port time out: removing target and saving binding
多路径将Path ID为0和1的两条路径状态置为failed
Oct 16 19:58:08 pnxfh0eapnew02 kernel: [2925089.176039] [568][2014-10-16 19:58:08:193215][00005342053702d5][INFO][LPM][LPM_PingActivePathDone][725]Path becomes {XMP_PATH_FAILED} from {XMP_PATH_ACTIVE}. disk {9},tpg {1}, path {0}
Oct 16 19:58:08 pnxfh0eapnew02 kernel: [2925089.176067] [571][2014-10-16 19:58:08:193244][00005342053702d5][INFO][LPM][LPM_PingActivePathDone][725]Path becomes {XMP_PATH_FAILED} from {XMP_PATH_ACTIVE}. disk {1},tpg {0}, path {1}
在10月16日19:59:54开始,dm-6上有大量I/O error打印
Oct 16 19:59:54 pnxfh0eapnew02 kernel: [2925195.684460] Buffer I/O error on device dm-6, logical block 4054
在10月18日02:36:19,OS重启,发现了受损的REISERFS,系统在自动挂载时,自行用log进行了修复:
Oct 18 02:36:19 pnxfh0eapnew02 kernel: [ 1740.069108] REISERFS (device dm-6): journal params: device dm-6, size 8192, journal first block 18, max trans len 1024, max batch 900, max commit age 30, max trans age 30
Oct 18 02:36:19 pnxfh0eapnew02 kernel: [ 1740.069788] REISERFS (device dm-6): checking transaction log (dm-6)
Oct 18 02:36:19 pnxfh0eapnew02 kernel: [ 1740.097034] REISERFS (device dm-6): Using r5 hash to sort names
在2014-10-20,现场再次检查了2台SUSE11主机的路径状态,2台主机都只能看到1个启动器对应的2条路径,另外1个启动器的路径未建立。所以确认本次故障的交换机A是接路径正常的启动器,在交换机A故障后,无路径可用,主机I/O无法下发,导致业务异常。

根因
现场2台SUSE11 SP2主机,各有2个启动器,但是其中1个启动器的路径未建立,故障的交换机A连接路径状态正常的启动器;交换机A故障后,无业务路径可用,报I/O error,文件系统受损,业务中断。
解决方案
1、现场最终通过复位主机后,系统在自动挂载时,通过log修复受损的文件系统恢复正常。
2、2台SUSE主机目前都只有1个启动器对应的2条路径正常,另外1个启动器对应路径未建立,影响可靠性,请重新配置,保证主机通过2个交换机与存储建立逻辑链路。
(该问题可能由于交换机配置、或者主机侧HBA卡驱动导致的,请客户联系相应交换机和HBA卡厂商协助分析。请反馈交换机日志和配置,并再次收集存储日志,以分析主机与存储建立链接的过程。)

END