Guest Dominik Rappaport Posted September 30, 2007 Posted September 30, 2007 Hi, I'm currently investigating a processor hug problem on one of our servers. The machine is a Windows Server 2003 R2 box with Service Pack 1. I found out, that the wmiprvse.exe process consumes constantly 50% CPU time (the machine has two processors). I followed the "Tracking Down a Processor Hog" topic in the Debugging Tools help. I attached to the process and used the runaway 3 command two times to find out the thread that consumes most of the CPU time. It was the thread with ID 2740 which corresponds to the internal number 9. ~9kb gives the following stack trace: ChildEBP RetAddr Args to Child 0197ede4 77b8d08c 00030000 00000000 00000880 ntdll!RtlAllocateHeap+0xa17 0197ee04 5dc1eb8c 00000880 72e96f00 0197ef10 msvcrt!malloc+0x6c 0197ee14 5dbd30de 00000880 0078eb08 00792e00 cimwin32!operator new[]+0xe 0197ef10 5dbd37a7 0078eb08 0079b23e 0079b212 cimwin32!CWin32Printer::GetDeviceCapabilities+0x5e 0197ef6c 5dbd3c6a 0079b23e 00000001 00000000 cimwin32!CWin32Printer::GetExpensiveProperties+0x33b 0197efd8 5dbd3d8a 007b27c0 00000000 0197effc cimwin32!CWin32Printer::DynInstancePrinters+0x17d 0197efe8 6958b30f 007b27c0 00000000 007b27c0 cimwin32!CWin32Printer::EnumerateInstances+0xf 0197effc 69590556 007b27c0 00000000 00000000 framedyn!Provider::CreateInstanceEnum+0x21 0197f4e8 01018ba7 00760598 0144719c 00000000 framedyn!CWbemProviderGlue::CreateInstanceEnumAsync+0x1bc 0197f52c 01018f52 00000000 00101e18 00000000 wmiprvse!CInterceptor_IWbemSyncProvider::Helper_CreateInstanceEnumAsync+0x152 0197f56c 77c40f3b 00760598 0140bfec 00000000 wmiprvse!CInterceptor_IWbemSyncProvider::CreateInstanceEnumAsync+0x70 0197f594 77cb23f7 01018ee2 0197f778 00000005 RPCRT4!Invoke+0x30 0197f994 77cb1a95 000cc2c8 000c25f4 000c0204 RPCRT4!NdrStubCall2+0x299 0197f9ec 7545e487 000cc2c8 000c0204 000c25f4 RPCRT4!CStdStubBuffer_Invoke+0xc6 0197fa00 77608ec1 005d4d34 000c0204 000c25f4 FastProx!CBaseStublet::Invoke+0x22 0197fa44 77608e74 000c0204 000b65b8 000af1a8 ole32!SyncStubInvoke+0x33 0197fa8c 7751b2b7 000c0204 000c3540 005d4d34 ole32!StubInvoke+0xa7 0197fb64 7751b0b5 000c25f4 00000000 005d4d34 ole32!CCtxComChnl::ContextInvoke+0xe3 0197fb80 77609926 000c0204 00000001 005d4d34 ole32!MTAInvoke+0x1a 0197fbb0 77608c33 d0908070 000c25f4 005d4d34 ole32!AppInvoke+0xa3 I set a breakpoint at msvcrt!malloc+0x6c and continued execution but the breakpoint was never reached. After five minutes I broke in and printed again a stack trace of this thread: ChildEBP RetAddr Args to Child 0197ede4 77b8d08c 00030000 00000000 00000880 ntdll!RtlAllocateHeap+0xa2f 0197ee04 5dc1eb8c 00000880 72e96f00 0197ef10 msvcrt!malloc+0x6c 0197ee14 5dbd30de 00000880 0078eb08 00792e00 cimwin32!operator new[]+0xe 0197ef10 5dbd37a7 0078eb08 0079b23e 0079b212 cimwin32!CWin32Printer::GetDeviceCapabilities+0x5e 0197ef6c 5dbd3c6a 0079b23e 00000001 00000000 cimwin32!CWin32Printer::GetExpensiveProperties+0x33b 0197efd8 5dbd3d8a 007b27c0 00000000 0197effc cimwin32!CWin32Printer::DynInstancePrinters+0x17d 0197efe8 6958b30f 007b27c0 00000000 007b27c0 cimwin32!CWin32Printer::EnumerateInstances+0xf 0197effc 69590556 007b27c0 00000000 00000000 framedyn!Provider::CreateInstanceEnum+0x21 0197f4e8 01018ba7 00760598 0144719c 00000000 framedyn!CWbemProviderGlue::CreateInstanceEnumAsync+0x1bc 0197f52c 01018f52 00000000 00101e18 00000000 wmiprvse!CInterceptor_IWbemSyncProvider::Helper_CreateInstanceEnumAsync+0x152 0197f56c 77c40f3b 00760598 0140bfec 00000000 wmiprvse!CInterceptor_IWbemSyncProvider::CreateInstanceEnumAsync+0x70 0197f594 77cb23f7 01018ee2 0197f778 00000005 RPCRT4!Invoke+0x30 0197f994 77cb1a95 000cc2c8 000c25f4 000c0204 RPCRT4!NdrStubCall2+0x299 0197f9ec 7545e487 000cc2c8 000c0204 000c25f4 RPCRT4!CStdStubBuffer_Invoke+0xc6 0197fa00 77608ec1 005d4d34 000c0204 000c25f4 FastProx!CBaseStublet::Invoke+0x22 0197fa44 77608e74 000c0204 000b65b8 000af1a8 ole32!SyncStubInvoke+0x33 0197fa8c 7751b2b7 000c0204 000c3540 005d4d34 ole32!StubInvoke+0xa7 0197fb64 7751b0b5 000c25f4 00000000 005d4d34 ole32!CCtxComChnl::ContextInvoke+0xe3 0197fb80 77609926 000c0204 00000001 005d4d34 ole32!MTAInvoke+0x1a 0197fbb0 77608c33 d0908070 000c25f4 005d4d34 ole32!AppInvoke+0xa3 It was now evident that the AllocHeap function never returned. The user mode time of this thread had reached over 11 hours: User Mode Time Thread Time 9:2740 0 days 11:38:13.828 Has any of you knowledge why AllocateHeap could hang? The version of the ntdll.dll file is 5.2.3790.1830. Kind regards, Dominik
Guest Mathieu CHATEAU Posted September 30, 2007 Posted September 30, 2007 Re: Win2K3R2SP1/wmiprivse consumes 50% cpu time/AllocateHeap never returns Hello, Do you have SCOM 2007 installed ? -- Cordialement, Mathieu CHATEAU English blog: http://lordoftheping.blogspot.com French blog: http://www.lotp.fr "Dominik Rappaport" <Dominik.Rappaport@rappaport.at> wrote in message news:cdpuf35e7h071a4if1j3ogq50kv90425u3@4ax.com... > Hi, > > I'm currently investigating a processor hug problem on one of our > servers. The machine is a Windows Server 2003 R2 box with Service Pack > 1. I found out, that the wmiprvse.exe process consumes constantly 50% > CPU time (the machine has two processors). > > I followed the "Tracking Down a Processor Hog" topic in the Debugging > Tools help. I attached to the process and used the runaway 3 command > two times to find out the thread that consumes most of the CPU time. > It was the thread with ID 2740 which corresponds to the internal > number 9. > > ~9kb gives the following stack trace: > > ChildEBP RetAddr Args to Child > 0197ede4 77b8d08c 00030000 00000000 00000880 > ntdll!RtlAllocateHeap+0xa17 > 0197ee04 5dc1eb8c 00000880 72e96f00 0197ef10 msvcrt!malloc+0x6c > 0197ee14 5dbd30de 00000880 0078eb08 00792e00 cimwin32!operator > new[]+0xe > 0197ef10 5dbd37a7 0078eb08 0079b23e 0079b212 > cimwin32!CWin32Printer::GetDeviceCapabilities+0x5e > 0197ef6c 5dbd3c6a 0079b23e 00000001 00000000 > cimwin32!CWin32Printer::GetExpensiveProperties+0x33b > 0197efd8 5dbd3d8a 007b27c0 00000000 0197effc > cimwin32!CWin32Printer::DynInstancePrinters+0x17d > 0197efe8 6958b30f 007b27c0 00000000 007b27c0 > cimwin32!CWin32Printer::EnumerateInstances+0xf > 0197effc 69590556 007b27c0 00000000 00000000 > framedyn!Provider::CreateInstanceEnum+0x21 > 0197f4e8 01018ba7 00760598 0144719c 00000000 > framedyn!CWbemProviderGlue::CreateInstanceEnumAsync+0x1bc > 0197f52c 01018f52 00000000 00101e18 00000000 > wmiprvse!CInterceptor_IWbemSyncProvider::Helper_CreateInstanceEnumAsync+0x152 > 0197f56c 77c40f3b 00760598 0140bfec 00000000 > wmiprvse!CInterceptor_IWbemSyncProvider::CreateInstanceEnumAsync+0x70 > 0197f594 77cb23f7 01018ee2 0197f778 00000005 RPCRT4!Invoke+0x30 > 0197f994 77cb1a95 000cc2c8 000c25f4 000c0204 RPCRT4!NdrStubCall2+0x299 > 0197f9ec 7545e487 000cc2c8 000c0204 000c25f4 > RPCRT4!CStdStubBuffer_Invoke+0xc6 > 0197fa00 77608ec1 005d4d34 000c0204 000c25f4 > FastProx!CBaseStublet::Invoke+0x22 > 0197fa44 77608e74 000c0204 000b65b8 000af1a8 ole32!SyncStubInvoke+0x33 > 0197fa8c 7751b2b7 000c0204 000c3540 005d4d34 ole32!StubInvoke+0xa7 > 0197fb64 7751b0b5 000c25f4 00000000 005d4d34 > ole32!CCtxComChnl::ContextInvoke+0xe3 > 0197fb80 77609926 000c0204 00000001 005d4d34 ole32!MTAInvoke+0x1a > 0197fbb0 77608c33 d0908070 000c25f4 005d4d34 ole32!AppInvoke+0xa3 > > I set a breakpoint at msvcrt!malloc+0x6c and continued execution but > the breakpoint was never reached. After five minutes I broke in and > printed again a stack trace of this thread: > > ChildEBP RetAddr Args to Child > 0197ede4 77b8d08c 00030000 00000000 00000880 > ntdll!RtlAllocateHeap+0xa2f > 0197ee04 5dc1eb8c 00000880 72e96f00 0197ef10 msvcrt!malloc+0x6c > 0197ee14 5dbd30de 00000880 0078eb08 00792e00 cimwin32!operator > new[]+0xe > 0197ef10 5dbd37a7 0078eb08 0079b23e 0079b212 > cimwin32!CWin32Printer::GetDeviceCapabilities+0x5e > 0197ef6c 5dbd3c6a 0079b23e 00000001 00000000 > cimwin32!CWin32Printer::GetExpensiveProperties+0x33b > 0197efd8 5dbd3d8a 007b27c0 00000000 0197effc > cimwin32!CWin32Printer::DynInstancePrinters+0x17d > 0197efe8 6958b30f 007b27c0 00000000 007b27c0 > cimwin32!CWin32Printer::EnumerateInstances+0xf > 0197effc 69590556 007b27c0 00000000 00000000 > framedyn!Provider::CreateInstanceEnum+0x21 > 0197f4e8 01018ba7 00760598 0144719c 00000000 > framedyn!CWbemProviderGlue::CreateInstanceEnumAsync+0x1bc > 0197f52c 01018f52 00000000 00101e18 00000000 > wmiprvse!CInterceptor_IWbemSyncProvider::Helper_CreateInstanceEnumAsync+0x152 > 0197f56c 77c40f3b 00760598 0140bfec 00000000 > wmiprvse!CInterceptor_IWbemSyncProvider::CreateInstanceEnumAsync+0x70 > 0197f594 77cb23f7 01018ee2 0197f778 00000005 RPCRT4!Invoke+0x30 > 0197f994 77cb1a95 000cc2c8 000c25f4 000c0204 RPCRT4!NdrStubCall2+0x299 > 0197f9ec 7545e487 000cc2c8 000c0204 000c25f4 > RPCRT4!CStdStubBuffer_Invoke+0xc6 > 0197fa00 77608ec1 005d4d34 000c0204 000c25f4 > FastProx!CBaseStublet::Invoke+0x22 > 0197fa44 77608e74 000c0204 000b65b8 000af1a8 ole32!SyncStubInvoke+0x33 > 0197fa8c 7751b2b7 000c0204 000c3540 005d4d34 ole32!StubInvoke+0xa7 > 0197fb64 7751b0b5 000c25f4 00000000 005d4d34 > ole32!CCtxComChnl::ContextInvoke+0xe3 > 0197fb80 77609926 000c0204 00000001 005d4d34 ole32!MTAInvoke+0x1a > 0197fbb0 77608c33 d0908070 000c25f4 005d4d34 ole32!AppInvoke+0xa3 > > It was now evident that the AllocHeap function never returned. The > user mode time of this thread had reached over 11 hours: > > User Mode Time > Thread Time > 9:2740 0 days 11:38:13.828 > > Has any of you knowledge why AllocateHeap could hang? The version of > the ntdll.dll file is 5.2.3790.1830. > > Kind regards, > Dominik
Guest Dominik Rappaport Posted September 30, 2007 Posted September 30, 2007 Re: Win2K3R2SP1/wmiprivse consumes 50% cpu time/AllocateHeap never returns >Do you have SCOM 2007 installed ? Negative. But the Operations Manger 2005 agent is installed. Don't think that the error is related because the error is relative new and the agent was installed a year ago or so. Chears, Dominik
Guest Mathieu CHATEAU Posted September 30, 2007 Posted September 30, 2007 Re: Win2K3R2SP1/wmiprivse consumes 50% cpu time/AllocateHeap never returns Do you have a linux/samba on the network ? I came across this KB: High CPU usage occurs, and event 7023 is logged in Event Viewer in Windows Server 2003 http://support.microsoft.com/kb/888193 -- Cordialement, Mathieu CHATEAU English blog: http://lordoftheping.blogspot.com French blog: http://www.lotp.fr "Dominik Rappaport" <Dominik.Rappaport@rappaport.at> wrote in message news:4ijvf3lqcug6r7vk5rp59ef3v07n5h6i4a@4ax.com... > >Do you have SCOM 2007 installed ? > > Negative. But the Operations Manger 2005 agent is installed. Don't > think that the error is related because the error is relative new and > the agent was installed a year ago or so. > > Chears, > Dominik
Guest Dominik Rappaport Posted September 30, 2007 Posted September 30, 2007 Re: Win2K3R2SP1/wmiprivse consumes 50% cpu time/AllocateHeap never returns >Do you have a linux/samba on the network ? No Samba box on the net...
Recommended Posts