之前在WSFC日志分析进阶篇中曾经提到过一些关于WSFC底层原理,例如Resource.dll,RHS,RCM,了解这些组件对于我们后期做群集排错有莫大的帮助,本文我们就通过一个实际的资源死锁的案例,来帮助大家加深下印象
首先,Resource.dll是干嘛的呢,Resouce.dll是每个群集资源所赖以生存的组件,只有有Resouce.dll,群集资源才可以正常运作,resource.dll里面包括了对于群集资源的检测Look alive 和is alive的检测函数定义,以及资源的操作调用定义
RHS是群集资源主机子系统,以进程的方式运作,负责监视群集资源的运行情况是否正常,RHS会根据资源resource.dll里面定义的Look alive 和is alive方法对群集资源进行监视
当经过is alive方法测试后,确认该资源失败,则RHS报告失败给RCM资源控制管理器组件,RCM会把资源按照资源故障故障策略定义对资源进行重启重试,故障转移。
基本上Resource.dll负责定义应该怎么看病,看病的操作步骤,RHS遵循Resource.dll的看病方法和操作步骤看病,RHS判断出病情后,交由RCM护士,RCM护士决定应该按照策略去打针,还是住院。
今天我们主要关注的是RHS看的这个阶段,正常情况下来说,RHS要不就是看好,要不就是不好,好就报告正常,接着循环检测,不好RCM就开始按照策略做处理。
但是除了这两种情况,还有另外一种常见的情况,即资源死锁
什么是资源死锁呢,就是说RHS给群集资源发送is alive检测信号,但是群集资源迟迟不给响应,那你不响应的话,群集怎么知道你到底存不存活呢,群集不会一直等待你资源的响应的,群集一定要准确确认每个资源可不可用,经过一段时间后,群集就会判定资源进入Deadlock死锁,RHS会把你这个不响应的群集资源放在一个单独隔离的RHS进程中,然后RHS尝试重新启动该资源,创建死锁WER报告。
对于资源死锁的时间,WSFC 2008R2开始默认情况下群集会等待5分钟,如果5分钟内,资源还是没有响应,则资源死锁,群集会把该资源单独RHS进程中进行重启尝试。
在2008R2时代开始Deadlock资源死锁的时间可以通过以下命令更改
针对单个资源级别
(Get-ClusterResource“资源名称”).DeadlockTimeout=300000
针对资源类型级别
(Get-ClusterResourceType“Virtual Machine”).DeadlockTimeout=300000
下一层保护是当集群发出终止RHS进程的请求时,它将等待四次DeadlockTimeout值(默认等于20分钟),以使RHS进程终止,如果RHS在20分钟内没有终止,则集群将认为服务器有一些严重的健康问题,并会检查服务器以强制故障转移和恢复,这段时间群集资源可能会停止访问,错误检查代码将为Stop 0x0000009E(Parameter1,Parameter2,0x0000000000000005,Parameter4)。注意:如果RHS进程未能终止,则Parameter3将始终为0x5的值
WSFC 2008R2时代之后
群集IP,群集网络名称,仲裁资源 单独在一个RHS监视进程工作
群集可用磁盘,CSV 单独在一个RHS监视进程工作
其它群集资源在专用RHS监视进程工作
通过这也可以避免以前所有资源都在一个RHS进程托管的弊病,2008R2之前,群集资源都在同一个RHS进程托管,只要其中一个群集资源崩溃,那么整个RHS进程可能会失败,并且托管的所有资源都将失败。
隔离开了之后,如果单个群集资源无响应导致RHS崩溃,群集服务将认为特定的资源可疑,并且需要被隔离。群集服务将自动设置资源公共属性SeparateMonitor 以将该资源标记为在其自己的专用RHS进程中运行,以便在资源再次无响应的情况下; 它不会影响其它群集资源进程
在2008R2时代开始,一旦发生了我们上面讲的资源死锁,即应用不响应is alive请求,将会生成WER报告,在控制面板中可以看到,并收集到该死锁RHS进程的dump,WSFC 2016时代,这项功能更进一步,可以显示更多资源死锁的细部信息,帮助排错人员做live debug
OK,上面基本的信息交代完成后,下面我们来看这次的资源死锁案例
有时候在一些场景下会遇到很多莫名奇妙的问题,尤其是你在做变更的时候,一起变更好多内容,忽然出问题了,你也不知道是哪个变更操作导致的问题,这是最头痛的,这时就需要好好坐下来深入的看看问题
本次的问题大概是一次更新变更,某地针对一个批次的群集节点进行补丁更新,其中两台节点的群集更新完成后重启机器,机器运行缓慢,群集服务无法启动,尝试在两个群集节点上面分别执行强制仲裁,无果,强制仲裁之后,群集又立刻失败,见证磁盘和群集磁盘始终无法联机。
最初怀疑是由于系统更新补丁导致,卸载补丁后发现问题依旧,开始进行群集层面排错,首先检查群集到存储之间是否正常,对于链路确认无问题,接下来从群集事件日志开始看起
查看群集事件日志
Log Name: System
Source: Microsoft-Windows-FailoverClustering
Date:
Event ID: 1573
Task Category: Quorum Manager
Level: Error
Keywords:
User: SYSTEM
Computer:
Description:
Node ‘ZQ1‘ failed to form a cluster. This was because the witness was not accessible. Please ensure that the witness resource is online and available.
Log Name: System
Source: Microsoft-Windows-FailoverClustering
Date:
Event ID: 1069
Task Category: Resource Control Manager
Level: Error
Keywords:
User: SYSTEM
Computer:
Description:
Cluster resource ‘群集磁盘 1‘ in clustered role ‘wlc‘ failed.
Log Name: System
Source: Microsoft-Windows-FailoverClustering
Date:
Event ID: 1230
Task Category: Resource Control Manager
Level: Error
Keywords:
User: SYSTEM
Computer:
Description:
A component on the server did not respond in a timely fashion. This caused the cluster resource ‘群集磁盘 1‘ (resource type ‘‘, DLL ‘clusres.dll‘) to exceed its time-out threshold. As part of cluster health detection, recovery actions will be taken. The cluster will try to automatically recover by terminating and restarting the Resource Hosting Subsystem (RHS) process that is running this resource. Verify that the underlying infrastructure (such as storage, networking, or services) that are associated with the resource are functioning correctly.
大部分群集事件日志表明群集磁盘无法上线,并且出现deadlock以及RHS进程超时
查看clusterlog看到,群集磁盘2出现deadlock
00001148.00001158::2017/09/15-20:24:36.365 ERR [RHS] RhsCall::DeadlockMonitor: Call ONLINERESOURCE timed out for resource ‘èoˉ′ì 2‘.
00001148.00001158::2017/09/15-20:24:36.365 ERR [RHS] Resource èoˉ′ì 2 handling deadlock. Cleaning current operation.
00001148.00001158::2017/09/15-20:24:36.365 ERR [RHS] About to send WER report.
0000084c.0000159c::2017/09/15-20:24:36.365 WARN [RCM] HandleMonitorReply: FAILURENOTIFICATION for ‘èoˉ′ì 2‘, gen(0) result 5018.
0000084c.0000159c::2017/09/15-20:24:36.365 INFO [RCM] TransitionToState(èoˉ′ì 2) OnlinePending-->ProcessingFailure.
0000084c.0000159c::2017/09/15-20:24:36.365 ERR [RCM] rcm::RcmResource::HandleFailure: (èoˉ′ì 2)
目前日志表明群集问题和群集磁盘在两个节点都无法上线相关,群集磁盘无法访问,并出现RHS deadlock.表明群集磁盘IO没有得到及时回应
The computer has rebooted from a bugcheck. The bugcheck was: 0x0000009e (0xfffffab030cce600, 0x00000000000004b0, 0x0000000000000000, 0x0000000000000000). A dump was saved in: C:\Windows\MEMORY.DMP
但是目前我们还是没办法判断问题到底是因为什么导致的,根据bugcheck指示,进一步我们还需要查看dump文件,来查看导致资源死锁的原因,dump可以是WER里面的进程dump,最好可以是一个完整的memory dump,本案例我们以完整memory.dmp为例
从dump中得到发生deadlock的RHS进程是fffffab030cce600,进程中有三个线程,其中两个线程等待在系统线程fffffab0`30f0a6d0,callstack如下,此系统线程在等待TmXPFlt.sys驱动
00 fffff880`08d92420 fffff800`01ad3142 nt!KiSwapContext+0x7a
01 fffff880`08d92560 fffff800`01ad596f nt!KiCommitThreadWait+0x1d2
02 fffff880`08d925f0 fffff880`056880e4 nt!KeWaitForSingleObject+0x19f
03 fffff880`08d92690 fffff880`05680838 TmXPFlt+0xb0e4
04 fffff880`08d926f0 fffff880`05670be2 TmXPFlt+0x3838
05 fffff880`08d927e0 fffff880`0148c0f7 TmPreFlt!TmpQueryFullName+0xb66
06 fffff880`08d928a0 fffff880`0148ea0a fltmgr!FltpPerformPreCallbacks+0x50b
07 fffff880`08d929b0 fffff880`014aa2a3 fltmgr!FltpPassThroughInternal+0x4a
08 fffff880`08d929e0 fffff800`01dd22bb fltmgr!FltpCreate+0x293
09 fffff880`08d92a90 fffff800`01dcddde nt!IopParseDevice+0x14e2
0a fffff880`08d92bf0 fffff800`01dce8c6 nt!ObpLookupObjectName+0x784
0b fffff880`08d92cf0 fffff800`01dd06bc nt!ObOpenObjectByName+0x306
0c fffff880`08d92dc0 fffff800`01d7316b nt!IopCreateFile+0x2bc
0d fffff880`08d92e60 fffff880`014b1f60 nt!IoCreateFileEx+0xfb
0e fffff880`08d92f00 fffff880`014bdc61 fltmgr!FltpCreateFile+0x194
0f fffff880`08d92ff0 fffff880`014e3506 fltmgr!FltCreateFileEx+0x91
10 fffff880`08d93080 fffff880`014de40e dfsrro!DfsrRopLoadPrefixEntriesFromFile+0x416
11 fffff880`08d93250 fffff880`014b00c6 dfsrro!DfsrRoNewInstanceCallback+0x2e2
12 fffff880`08d932b0 fffff880`014af0cb fltmgr!FltpDoInstanceSetupNotification+0x86
13 fffff880`08d93310 fffff880`014afe81 fltmgr!FltpInitInstance+0x27b
14 fffff880`08d93380 fffff880`014b0d5b fltmgr!FltpCreateInstanceFromName+0x1d1
15 fffff880`08d93450 fffff880`014aed6c fltmgr!FltpEnumerateRegistryInstances+0x15b
16 fffff880`08d934f0 fffff880`014aa3f0 fltmgr!FltpDoFilterNotificationForNewVolume+0xec
17 fffff880`08d93560 fffff800`01dd22bb fltmgr!FltpCreate+0x3e0
18 fffff880`08d93610 fffff800`01dcddde nt!IopParseDevice+0x14e2
19 fffff880`08d93770 fffff800`01dce8c6 nt!ObpLookupObjectName+0x784
1a fffff880`08d93870 fffff800`01dd06bc nt!ObOpenObjectByName+0x306
1b fffff880`08d93940 fffff800`01ddbd34 nt!IopCreateFile+0x2bc
1c fffff880`08d939e0 fffff800`01acd0d3 nt!NtCreateFile+0x78
1d fffff880`08d93a70 00000000`76fac28a nt!KiSystemServiceCopyEnd+0x13
1e 00000000`0219f748 00000000`00000000 0x76fac28a
RHS进程中的另外一个线程fffffab0`30ef2b50同样是等待在TmXPFlt.sys驱动上
00 fffff880`08d92420 fffff800`01ad3142 nt!KiSwapContext+0x7a
01 fffff880`08d92560 fffff800`01ad596f nt!KiCommitThreadWait+0x1d2
02 fffff880`08d925f0 fffff880`056880e4 nt!KeWaitForSingleObject+0x19f
03 fffff880`08d92690 fffff880`05680838 TmXPFlt+0xb0e4
04 fffff880`08d926f0 fffff880`05670be2 TmXPFlt+0x3838
05 fffff880`08d927e0 fffff880`0148c0f7 TmPreFlt!TmpQueryFullName+0xb66
06 fffff880`08d928a0 fffff880`0148ea0a fltmgr!FltpPerformPreCallbacks+0x50b
07 fffff880`08d929b0 fffff880`014aa2a3 fltmgr!FltpPassThroughInternal+0x4a
08 fffff880`08d929e0 fffff800`01dd22bb fltmgr!FltpCreate+0x293
09 fffff880`08d92a90 fffff800`01dcddde nt!IopParseDevice+0x14e2
0a fffff880`08d92bf0 fffff800`01dce8c6 nt!ObpLookupObjectName+0x784
0b fffff880`08d92cf0 fffff800`01dd06bc nt!ObOpenObjectByName+0x306
0c fffff880`08d92dc0 fffff800`01d7316b nt!IopCreateFile+0x2bc
0d fffff880`08d92e60 fffff880`014b1f60 nt!IoCreateFileEx+0xfb
0e fffff880`08d92f00 fffff880`014bdc61 fltmgr!FltpCreateFile+0x194
0f fffff880`08d92ff0 fffff880`014e3506 fltmgr!FltCreateFileEx+0x91
10 fffff880`08d93080 fffff880`014de40e dfsrro!DfsrRopLoadPrefixEntriesFromFile+0x416
11 fffff880`08d93250 fffff880`014b00c6 dfsrro!DfsrRoNewInstanceCallback+0x2e2
12 fffff880`08d932b0 fffff880`014af0cb fltmgr!FltpDoInstanceSetupNotification+0x86
13 fffff880`08d93310 fffff880`014afe81 fltmgr!FltpInitInstance+0x27b
14 fffff880`08d93380 fffff880`014b0d5b fltmgr!FltpCreateInstanceFromName+0x1d1
15 fffff880`08d93450 fffff880`014aed6c fltmgr!FltpEnumerateRegistryInstances+0x15b
16 fffff880`08d934f0 fffff880`014aa3f0 fltmgr!FltpDoFilterNotificationForNewVolume+0xec
17 fffff880`08d93560 fffff800`01dd22bb fltmgr!FltpCreate+0x3e0
18 fffff880`08d93610 fffff800`01dcddde nt!IopParseDevice+0x14e2
19 fffff880`08d93770 fffff800`01dce8c6 nt!ObpLookupObjectName+0x784
1a fffff880`08d93870 fffff800`01dd06bc nt!ObOpenObjectByName+0x306
1b fffff880`08d93940 fffff800`01ddbd34 nt!IopCreateFile+0x2bc
1c fffff880`08d939e0 fffff800`01acd0d3 nt!NtCreateFile+0x78
1d fffff880`08d93a70 00000000`76fac28a nt!KiSystemServiceCopyEnd+0x13
1e 00000000`0219f748 00000000`00000000 0x76fac28a
start end module name
fffff880`0567d000 fffff880`056d3000 TmXPFlt (no symbols)
Loaded symbol image file: TmXPFlt.sys
Image path: \??\C:\Program Files (x86)\Trend Micro\OfficeScan Client\TmXPFlt.sys
Image name: TmXPFlt.sys
Browse all global symbols functions data
Timestamp: Wed Jun 10 18:54:43 2009 (4A2F90F4)
CheckSum: 00040739
ImageSize: 00056000
Translations: 0000.04b0 0000.04e4 0409.04b0 0409.04e4
根据此dump分析,RHS进程deadlock和Trend Micro的driver 相关,综合上述的分析,此问题很大可能和磁盘无法上线相关。
尝试在群集节点卸载Trend Micro趋势,再次更新补丁,问题解决。
事实上后期在趋势的官网发现已经给出了此问题的发生原因及解决方法
可以选择按照趋势官网给出的修改注册表方案进行解决
或升级趋势VSAPI扫描引擎为9.5之后的版本,9.5之前的VSAPI扫描引擎皆会与群集有这个资源死锁问题
以上为本次资源死锁案例的分析过程,希望能够为感兴趣的朋友带来帮助!
本文出自 “老王的微软技术研究乐园” 博客,请务必保留此出处http://wzde2012.blog.51cto.com/6474289/1974738
原文地址:http://wzde2012.blog.51cto.com/6474289/1974738