天天看點

跟蹤多程序死鎖

我最近處理的一個棘手的死鎖問題開始。讓我先解釋一下表面症狀,然後我們就可以找到好東西了。當運作Vista的使用者嘗試啟動internetexplorer時,任何事情都不會發生。是以他們再次輕按兩下圖示,還是什麼也沒發生。是以使用者會重新啟動并傳回他們的網絡活動。

經過一些基本的故障排除後發現Iexplore.exe正在運作多次,每次嘗試打開浏覽器都會導緻另一個Iexplore.exe執行個體。因為沒有使用者界面,是以我繼續收集了一些Iexplore.exe程序轉儲以及完整的系統轉儲。

程序轉儲沒有被證明是非常有用的,是以我決定轉到完整的記憶體轉儲。

因為我知道我們有多個IExplore.exe運作的程序,我想先調查一下。

0: kd>!process 0 0

<snip>

PROCESS 87289d90 SessionId: 5 Cid: 0fdc Peb: 7ffdc000 ParentCid: 0968

    DirBase: 7d66c520 ObjectTable: a203a178 HandleCount: 205.

    Image: iexplore.exe

PROCESS 861a9d90 SessionId: 5 Cid: 0d34 Peb: 7ffd9000 ParentCid: 0fdc

    DirBase: 7d66c7a0 ObjectTable: a5651a98 HandleCount: 170.

    Image: ieuser.exe

PROCESS 86c175b0 SessionId: 5 Cid: 1250 Peb: 7ffd9000 ParentCid: 0968

    DirBase: 7d66c940 ObjectTable: a0853f10 HandleCount: 91.

    Image: iexplore.exe

PROCESS 861ac7a8 SessionId: 5 Cid: 1024 Peb: 7ffde000 ParentCid: 0968

    DirBase: 7d66c620 ObjectTable: a83f7898 HandleCount: 91.

Image: iexplore.exe
</snip>      

我決定從清單中的第一個開始(87289d90)

0: kd> !process 87289d90
Image: iexplore.exe

    ElapsedTime 00:24:06.666      

這個過程似乎已經有一段時間了,是以我想看看這個過程中的第一個線程,因為它負責internetexplorer中的UI。我看這個線程是因為表面問題說明當我們啟動時Iexplore.exe使用者界面從不顯示。我在這裡用了!thread顯示特定線程的指令。

THREAD 870b6398 Cid 0fdc.16a4 Teb: 7ffdf000 Win32Thread: fd850b78 WAIT: (UserRequest) UserMode Non-Alertable

            85e86cf0 SynchronizationEvent

            85cb35e0 SynchronizationEvent

        Not impersonating

        Attached Process 87289d90 Image: iexplore.exe

        Wait Start TickCount 10817197 Ticks: 69571 (0:00:18:05.314)

        UserTime 00:00:00.015

        KernelTime 00:00:00.093      

根據滴答數,這個線程已經等了18分鐘了。

0: kd> kvn

# ChildEBP RetAddr Args to Child

00 931208d8 81a940a1 870b6398 803d2120 870b6420 nt!KiSwapContext+0x26

01 9312091c 81a8dacc 870b6398 00000000 00000002 nt!KiSwapThread+0x44f

02 93120970 81bedb4f 00000002 93120aa8 00000001 nt!KeWaitForMultipleObjects+0x53d

03 93120bfc 81bee2e3 00000002 00000001 00000000 nt!ObpWaitForMultipleObjects+0x256

04 93120d48 81a30b3a 00000002 0027e9c4 00000001 nt!NtWaitForMultipleObjects+0xcc

05 93120d48 77568254 00000002 0027e9c4 00000001 nt!KiFastCallEntry+0x12a

06 0027e970 775679fc 7708c973 00000002 0027e9c4 ntdll!KiFastSystemCallRet

07 0027e974 7708c973 00000002 0027e9c4 00000001 ntdll!NtWaitForMultipleObjects+0xc

08 0027ea10 7608ff95 0027e9c4 0027ea38 00000000 kernel32!WaitForMultipleObjectsEx+0x11d

09 0027ea64 773d3a46 00000028 0027eaac ffffffff USER32!RealMsgWaitForMultipleObjectsEx+0x13c

0a 0027ea8c 773d3b7f 0027eaac ffffffff 0027eabc ole32!CCliModalLoop::BlockFn+0x97

0b 0027eab4 774e75be ffffffff 003ddf90 0027ebc0 ole32!ModalLoop+0x5b

0c 0027ead0 774e9294 00000000 0027ebd4 00000000 ole32!ThreadSendReceive+0x12c

0d 0027eaf8 774e9100 0027ebc0 003d3538 0027ec1c ole32!CRpcChannelBuffer::SwitchAptAndDispatchCall+0x194

0e 0027ebd8 773d3c25 003d3538 0027ecfc 0027ece4 ole32!CRpcChannelBuffer::SendReceive2+0xef

0f 0027ebf4 773d3bd7 0027ecfc 0027ece4 003d3538 ole32!CCliModalLoop::SendReceive+0x1e

10 0027ec6c 77403efb 003d3538 0027ecfc 0027ece4 ole32!CAptRpcChnl::SendReceive+0x73

11 0027ecc0 76052ff4 003d3538 0027ecfc 0027ece4 ole32!CCtxComChnl::SendReceive+0x1c5

12 0027ecd8 76053055 003e50a4 0027ede4 76052e0d RPCRT4!NdrProxySendReceive+0x43

13 0027ece4 76052e0d 09ea0d59 0027f1fc 070001f3 RPCRT4!NdrpProxySendReceive+0xc      

根據調用堆棧,這個線程似乎進行了OLE調用,現在正在等待一些對象發出信号。IExplore在這個線程中做什麼?它正在等待另一個程序為該OLE請求提供服務。通過深入研究ole32 SendReceive調用,我們可以找到另一個程序的PID。

我看了第一個點:

0: kd> dd 003d3538

003d3538 77403a50 773f57b4 00000003 00000002

003d3548 00000000 00000000 003d2ef0 003d8840

003d3558 0038b1c0 003e05f8 77403980 00070005      

這為我們提供了一個指向另一個資料結構的指針,其中包含我們正在嘗試定位的資訊。

0: kd> dd 003d2ef0

003d2ef0 774ee600 003d2e70 00000d34 00000000

003d2f00 862941fa c94cde09 55a88424 801a2601

003d2f10 55a88424 801a2601 0000c400 00000d34      

啊,在那裡!0d34是為OLE請求提供服務的程序id。我回去複習了!process 0 0的輸出,找到包含程序D34的程序。我要把它扔在這裡。

PROCESS 861a9d90 SessionId: 5 Cid: 0d34 Peb: 7ffd9000 ParentCid: 0fdc

    DirBase: 7d66c7a0 ObjectTable: a5651a98 HandleCount: 170.

    Image: ieuser.exe      

好的,那麼處理這個請求的過程是IEUSER.exe,這是Internet Explorer在Vista中以保護模式運作時使用的代理程序。這是Vista的新功能。

現在我需要深入研究IEUser.exe找出導緻Iexplore等待的原因的過程。

0: kd> !process 861a9d90

PROCESS 861a9d90 SessionId: 5 Cid: 0d34 Peb: 7ffd9000 ParentCid: 0fdc

    DirBase: 7d66c7a0 ObjectTable: a5651a98 HandleCount: 170.

    Image: ieuser.exe      

我發現了ieuser.exe正在處理來自Iexplore.exe的調用. 然而,這個線程也在等待對某個内容的通路才能完成。

0: kd> kvn+200

 # ChildEBP RetAddr Args to Child

00 a41b0c50 81a940a1 85ecbac0 85ecbb48 81af9920 nt!KiSwapContext+0x26

01 a41b0c94 81a2ddc8 85ecbac0 00000000 85e18510 nt!KiSwapThread+0x44f

02 a41b0ce8 81bf0d9f 85e18510 00000006 00000001 nt!KeWaitForSingleObject+0x492

03 a41b0d50 81a30b3a 00000224 00000000 00000000 nt!NtWaitForSingleObject+0xbe

04 a41b0d50 77568254 00000224 00000000 00000000 nt!KiFastCallEntry+0x12a

05 0163e8a4 77567a0c 7708c7c4 00000224 00000000 ntdll!KiFastSystemCallRet

06 0163e8a8 7708c7c4 00000224 00000000 00000000 ntdll!NtWaitForSingleObject+0xc

07 0163e918 7708c732 00000224 ffffffff 00000000 kernel32!WaitForSingleObjectEx+0xbe

08 0163e92c 747e60aa 00000224 ffffffff 00000000 kernel32!WaitForSingleObject+0x12

09 0163e948 747e5fe0 0163ec48 00497b38 00000000 RASAPI32!ReadPhonebookFileEx+0x1a4

0a 0163e968 747e4e9d 0163ec48 00000000 00000000 RASAPI32!ReadPhonebookFile+0x1b

0b 0163e9a8 747e52d3 0163ec48 0048f660 0163e9e0 RASAPI32!DwEnumEntriesFromPhonebook+0x35

0c 0163ee58 747e4fd4 0163ee9c 00000001 0048f660 RASAPI32!DwEnumEntriesInDir+0x1cc

0d 0163f0ac 747e677e 00000001 0048f660 0163f0f4 RASAPI32!DwEnumEntriesForPbkMode+0xab

0e 0163f0e0 76e534b9 00000000 00004180 0048f660 RASAPI32!RasEnumEntriesW+0xb0

0f 0163f10c 76e5342a 76ecc2dc 00000000 00000000 WININET!RasEnumHelp::RasEnumHelp+0x55

10 0163f120 76e533a3 00000001 00000000 00000001 WININET!DoConnectoidsExist+0x2b

11 0163f14c 76e534ff 76ecf02c 76ecc2dc 00000000 WININET!GetRasConnections+0x34

12 0163f168 76e4196e 00000000 0163f180 6ee3228c WININET!IsDialUpConnection+0xa9

13 0163f184 76e70564 00000001 00000000 00000000 WININET!FixProxySettingsForCurrentConnection+0x31

14 0163f1a8 6ec2db3b 00000000 0163f1bc 0163f3d4 WININET!InternetInitializeAutoProxyDll+0x6c

15 0163f1b8 75fe9142 004884a0 00000202 0047e900 ieframe!CShdocvwBroker::StartAutoProxyDetection+0x4d

16 0163f1d0 76054294 6ec2daf8 0163f3d8 00000001 RPCRT4!Invoke+0x2a

17 0163f5fc 76054a49 004858d0 0046e4e0 0047e900 RPCRT4!NdrStubCall2+0x27b

18 0163f64c 774e86d7 004858d0 0047e900 0046e4e0 RPCRT4!CStdStubBuffer_Invoke+0xa0

19 0163f694 774e877d 0047e900 0047f968 00480b38 ole32!SyncStubInvoke+0x3c

1a 0163f6e0 7740249e 0047e900 0047f860 004858d0 ole32!StubInvoke+0xb9

1b 0163f7bc 774023af 0046e4e0 00000000 004858d0 ole32!CCtxComChnl::ContextInvoke+0xfa

1c 0163f7d8 774e85df 0047e900 00000001 004858d0 ole32!MTAInvoke+0x1a

1d 0163f808 774e8a18 d0908070 0046e4e0 004858d0 ole32!AppInvoke+0xaa

1e 0163f8e4 774e85ef 0047e8a8 00474118 0047ebc0 ole32!ComInvokeWithLockAndIPID+0x32c

1f 0163f930 75fe94b0 0047ebc0 08ac70b7 0047ebc0 ole32!ThreadInvoke+0x2fd      
0: kd> !object 85e18510

Object: 85e18510 Type: (85484d40) Mutant

    ObjectHeader: 85e184f8 (old version)

    HandleCount: 3 PointerCount: 5

    Directory Object: 881f3030 Name: RasPbFile      
0: kd> dt _KMUTANT 85e18510

nt!_KMUTANT

   +0x000 Header : _DISPATCHER_HEADER

   +0x010 MutantListEntry : _LIST_ENTRY [ 0x870b6564 - 0x870b6564 ]

   +0x018 OwnerThread : 0x870b6398 _KTHREAD

   +0x01c Abandoned : 0 ''

   +0x01d ApcDisable : 0 ''      
0163e92c 747e60aa 00000224 ffffffff 00000000 kernel32!WaitForSingleObject+0x12