Windows云服务器CPU使用率高的问题一例

作者：声东

大家好，今天跟大家分享一例Windows云服务器CPU使用率高的问题。

问题症状

客户购买了一台Windows 2016云服务器，登录之后发现这台服务器的CPU使用率一直保持在90%以上。

问题分析

首先登录到服务器，打开任务管理器，切换到性能页面，确认问题确实存在。从下图可以看出，这台服务器有非常明显的CPU使用率高的症状。

然后，我们切换到任务管理器，详细信息页面，点击CPU使得进程以CPU使用率高低排序。我们看到CPU使用率最高的进程是svchost.exe。这个进程是Windows操作系统里的服务宿主进程，即service host进程。

接下来，我们打开资源管理器，切换到CPU页面，根据上边找到的进程PID，勾选对应的svchost.exe进程。我们发现使用CPU最高的服务是Schedule，也就是微软的计划任务服务。

总结上边发现的所有信息，我们可以确认，这台服务器中，计划任务这个服务，占用了系统大量的CPU资源，一般情况下，这是不合理的。进一步调试这个问题，我们需要抓取这个进程的转储文件。Windows里，转储文件可以简单分为两大类，一类是系统的转储文件，一类是某个进程的。系统的转储文件（有可能）包括整个系统的信息，而进程的转储文件，一般只包含这个特定进程的用户控件的信息。在Windows上，我们可以用任务管理器简单的抓取进程转储文件。

然后，我们用windbg打开转储文件。另外我这边推荐大家使用一个windbg的扩展，这个扩展在微软技术支持团队普遍使用，非常好用。这个扩展叫做mex。安装这个扩展很简单，只需要根据操作系统是x86或者amd64，把对应的dll拷贝到windbg安装目录下边winext子目录中即可。

https://www.microsoft.com/en-us/download/details.aspx?id=53304

我们使用!mex.us (unique stack)命令在命令行输出进程中所有的call stacks，发现正在运行的线程，基本都在处理 LRPC调用。LRPC调用在接到消息之后，唤起计划任务去查询某个任务相关的信息。

00007ffdffa271c4 ntdll!ZwAlpcSendWaitReceivePort+0x14
 00007ffdfd6db211 rpcrt4!LRPC_BASE_CCALL::DoSendReceive+0x111
 00007ffdfd77808e rpcrt4!NdrpClientCall3+0xa0e
 00007ffdfd775102 rpcrt4!NdrClientCall3+0xf2
 00007ffdff90692b sechost!LsaInternalClientLookupSids+0xa7
 00007ffdff90676e sechost!LsaLookupTranslateSids+0x4e
 00007ffdff90659a sechost!LookupAccountSidInternal+0xda
 00007ffdff9064b5 sechost!LookupAccountSidLocalW+0x25
 00007ffdf605d1c0 schedsvc!User::LookupUserSid+0xd0
 00007ffdf605cfa1 schedsvc!User::FromSidToDomainAccount+0x31
 00007ffdf6033531 schedsvc!User::StreamIn+0x1a1
 00007ffdf6042a69 schedsvc!JobBucket::StreamIn+0x189
 00007ffdf6038410 schedsvc!Triggers::Trigulator::ReadData+0xe0
 00007ffdf603960e schedsvc!Triggers::Trigulator::StreamIn+0x30e
 00007ffdf603eebb schedsvc!JobStore::LoadTaskXml+0x11b
 00007ffdf60500ce schedsvc!RpcServer::RetrieveTask+0x1ae
 00007ffdf604ddc8 schedsvc!SchRpcRetrieveTask+0x28
 00007ffdfd717de3 rpcrt4!Invoke+0x73
 00007ffdfd77bc6d rpcrt4!Ndr64StubWorker+0xbfd
 00007ffdfd6aa8dc rpcrt4!NdrServerCallAll+0x3c
 00007ffdfd6fa194 rpcrt4!DispatchToStubInCNoAvrf+0x24
 00007ffdfd6f90ad rpcrt4!RPC_INTERFACE::DispatchToStubWorker+0x1bd
 00007ffdfd6f995b rpcrt4!RPC_INTERFACE::DispatchToStub+0xcb
 00007ffdfd6d9afc rpcrt4!LRPC_SCALL::DispatchRequest+0x34c
 00007ffdfd6d9f7c rpcrt4!LRPC_SCALL::HandleRequest+0x2bc
 00007ffdfd6f426c rpcrt4!LRPC_ADDRESS::HandleRequest+0x36c
 00007ffdfd6f5acb rpcrt4!LRPC_ADDRESS::ProcessIO+0x91b
 00007ffdfd6e85ca rpcrt4!LrpcIoComplete+0xaa
 00007ffdff9b2bbe ntdll!RtlReleaseSRWLockExclusive+0x116e
 00007ffdff9b3699 ntdll!RtlReleaseSRWLockExclusive+0x1c49
 00007ffdff118364 kernel32!BaseThreadInitThunk+0x14
 00007ffdff9e70d1 ntdll!RtlUserThreadStart+0x21

LRPC机制是一种客户端服务器机制，也就是说，为了理解为什么作为LRPC的服务器端，计划任务会接到LRPC消息。我们可以尝试找出发送消息的客户端进程。下边这个微软官方博客中，提到了怎么在LRPC堆栈上找出客户端进程PID的方法。

https://blogs.msdn.microsoft.com/ntdebugging/2012/02/28/debugging-backwards-proving-root-cause/

具体的原理和方法请参考这篇文章。我们用同样的方式，在不同的调用栈上去找出客户端进程的PID。发现这个进程的PID是一致的。

0:037> .frame /r 0x1a; !mex.x
1a 000000be`ba77f870 00007ffd`fd6e85ca rpcrt4!LRPC_ADDRESS::ProcessIO+0x91b
rax=0006000000000000 rbx=000002739dfc7ed0 rcx=0000027380010000
rdx=00000000c48b6030 rsi=0000000000000001 rdi=0000027380018a80
rip=00007ffdfd6f5acb rsp=000000beba77f870 rbp=000000beba77f970
 r8=0000027380010000 r9=0000000000000000 r10=0000000000ffffff
r11=00000273bfbd9b20 r12=0000000000000000 r13=0000000000000002
r14=0000000000000001 r15=0000000000000001
iopl=0 nv up ei pl zr na po nc
cs=0033 ss=002b ds=002b es=002b fs=0053 gs=002b efl=00000246
rpcrt4!LRPC_ADDRESS::ProcessIO+0x91b:
00007ffd`fd6f5acb 4533ff xor r15d,r15d
0:037> dd 0000027380018a80+8
00000273`80018a88 00001148 00000000 000012e8 00000000
00000273`80018a98 0000176c 00000000 7c9abb2f 00000000
00000273`80018aa8 00000000 00000000 00000000 c48b6036
00000273`80018ab8 00000001 00000002 00000000 00000001
00000273`80018ac8 00000000 00000000 00000000 00000000
00000273`80018ad8 11f97a48 00000000 0000000d 00000000
00000273`80018ae8 00000036 00000000 00000000 00000000
00000273`80018af8 00000036 00000000 004d005c 00630069
0:037> ? 00001148 
Evaluate expression: 4424 = 00000000`00001148

也就是说，LRPC客户端对应的进程PID是4424，可以看到它是客户在另外一个登录会话里的explorer进程。

为了了解explorer的行为，我们继续抓explorer的转储文件，我们发现所有与计划任务有关的线程，都来自msctf模块的调用，这个模块跟Text Framework Serivce相关。观察线程行为，可以大概看出，这个模块在通过task schedule去查询信息。

0:057> !us -a taskschd
-a is only for Kernel analysis. Ignoring option.
1 thread [stats]: 52
 00007ffdffa27024 ntdll!NtAlpcCreateSecurityContext+0x14
 00007ffdfd6d5e0a rpcrt4!LRPC_CASSOCIATION::OpenSecurityContextWorker+0xd2
 00007ffdfd6ef9ca rpcrt4!LRPC_BASE_BINDING_HANDLE::DriveStateForward+0x51a
 00007ffdfd6de5e9 rpcrt4!LRPC_BINDING_HANDLE::NegotiateTransferSyntax+0xa79
 00007ffdfd777f11 rpcrt4!NdrpClientCall3+0x891
 00007ffdfd775102 rpcrt4!NdrClientCall3+0xf2
 00007ffdfd6bd9e3 rpcrt4!EP_LOOKUP_DATA::LookupNextChunk+0x10f
 00007ffdfd6bdcd2 rpcrt4!EP_LOOKUP_DATA::ResolveEndpoint+0x186
 00007ffdfd6bb2cd rpcrt4!ResolveEndpointWithEpMapper+0x95
 00007ffdfd6bad1c rpcrt4!ResolveEndpointIfNecessary+0xa8
 00007ffdfd6edb97 rpcrt4!LRPC_BASE_BINDING_HANDLE::SubmitResolveEndpointRequest+0xe3
 00007ffdfd6edd08 rpcrt4!LRPC_BASE_BINDING_HANDLE::ResolveEndpoint+0x100
 00007ffdfd6efa26 rpcrt4!LRPC_BASE_BINDING_HANDLE::DriveStateForward+0x576
 00007ffdfd6de5e9 rpcrt4!LRPC_BINDING_HANDLE::NegotiateTransferSyntax+0xa79
 00007ffdfd777f11 rpcrt4!NdrpClientCall3+0x891
 00007ffdfd775102 rpcrt4!NdrClientCall3+0xf2
 00007ffdf72c7940 taskschd!RpcSession::HighestVersion+0x24
 00007ffdf72c5d2d taskschd!?Connect@?QITaskService@@TaskServiceImpl@@UEAAJUtagVARIANT@@000@Z+0x27d
 00007ffdfd4e793c msctf!DllUnregisterServer+0x118c
 00007ffdfd4871bf msctf+0x71bf
 00007ffdff118364 kernel32!BaseThreadInitThunk+0x14
 00007ffdff9e70d1 ntdll!RtlUserThreadStart+0x21

1 thread [stats]: 53
 00007ffdffa271c4 ntdll!ZwAlpcSendWaitReceivePort+0x14
 00007ffdfd6db211 rpcrt4!LRPC_BASE_CCALL::DoSendReceive+0x111
 00007ffdfd77808e rpcrt4!NdrpClientCall3+0xa0e
 00007ffdfd775102 rpcrt4!NdrClientCall3+0xf2
 00007ffdfba677a3 sspicli!SspipGetUserName+0x123
 00007ffdfba675c0 sspicli!GetUserNameExW+0x50
 00007ffdf72c5bff taskschd!?Connect@?QITaskService@@TaskServiceImpl@@UEAAJUtagVARIANT@@000@Z+0x14f
 00007ffdfd4e793c msctf!DllUnregisterServer+0x118c
 00007ffdfd4871bf msctf+0x71bf
 00007ffdff118364 kernel32!BaseThreadInitThunk+0x14
 00007ffdff9e70d1 ntdll!RtlUserThreadStart+0x21

2 threads [stats]: 54 56
 00007ffdffa271c4 ntdll!ZwAlpcSendWaitReceivePort+0x14
 00007ffdfd6db211 rpcrt4!LRPC_BASE_CCALL::DoSendReceive+0x111
 00007ffdfd77808e rpcrt4!NdrpClientCall3+0xa0e
 00007ffdfd775102 rpcrt4!NdrClientCall3+0xf2
 00007ffdf72c752e taskschd!RpcSession::Enumerate+0xbe
 00007ffdf72c53eb taskschd!?GetFolder@?QITaskService@@TaskServiceImpl@@UEAAJPEAGPEAPEAUITaskFolder@@@Z+0x15b
 00007ffdfd4e7960 msctf!DllUnregisterServer+0x11b0
 00007ffdfd4871bf msctf+0x71bf
 00007ffdff118364 kernel32!BaseThreadInitThunk+0x14
 00007ffdff9e70d1 ntdll!RtlUserThreadStart+0x21

4 threads [stats]: 50 51 55 57
 00007ffdffa271c4 ntdll!ZwAlpcSendWaitReceivePort+0x14
 00007ffdfd6db211 rpcrt4!LRPC_BASE_CCALL::DoSendReceive+0x111
 00007ffdfd77808e rpcrt4!NdrpClientCall3+0xa0e
 00007ffdfd775102 rpcrt4!NdrClientCall3+0xf2
 00007ffdf72cf106 taskschd!RpcSession::GetTaskInfo+0x4e
 00007ffdf72cf053 taskschd!UniSession::GetTaskInfo+0x47
 00007ffdf72fd55e taskschd!?get_State@?QIRegisteredTask@@RegisteredTaskImpl@@UEAAJPEAW4_TASK_STATE@@@Z+0x7e
 00007ffdfd4e79a3 msctf!DllUnregisterServer+0x11f3
 00007ffdfd4871bf msctf+0x71bf
 00007ffdff118364 kernel32!BaseThreadInitThunk+0x14
 00007ffdff9e70d1 ntdll!RtlUserThreadStart+0x21

基于以上信息，很难在没有微软msctf模块private symbol和代码的情况下，进一步深入研究这个模块的行为，建议客户把系统升级到最新的Rollup，之后问题不能重现。

结论

基本上来说，微软会很快修复Windows中明显的问题，所以强烈建议经常保持Windows系统安装了最新的补丁，这样可以避免很多问题。

了解更多请微博关注阿里云客户满意中心