Internet Explorer – Deadlocked!

This story starts off with a tricky little deadlock issue that I worked on recently. Let me set the stage by explaining the surface level symptom, and then we will get to the good stuff. Randomly when users running Vista would attempt to launch Internet Explorer nothing would happen. So they would again double-click the icon, and still nothing happened. So the users would reboot and go back to their web activities.

After some basic trouble shooting it was discovered that Iexplore.exe was running multiple times and every attempt to open the browser would result in another Iexplore.exe instance.  Since no UI was ever presented I went ahead and collected a few Iexplore.exe usermode process dumps along with a complete system dump.

Reviewing the process dumps didn’t prove to be terribly useful so I decided to move over to the complete memory dump.

Since I knew we had multiple IExplore.exe processes running I wanted to investigate them first.

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>

I decided to just start with the first one in the list (87289d90)

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

    ElapsedTime                       00:24:06.666

It appears this process has been around a while, so I wanted to look at the first thread in this process as it is responsible for the UI in Internet Explorer.  I am looking at this thread because the surface level problem illustrates that when we launch Iexplore.exe the UI is never displayed. Here I used the !thread command to display the specific 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  

Based on the tick count this thread has been waiting for 18 minutes.

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

Based on the call stack it appears this thread made an OLE call and is now waiting for some objects to signal.

What is IExplore doing in this thread?  It is waiting on another process to service this OLE request.   We can find the PID of the other process by digging into the ole32 SendReceive call.

I looked at the first argument:

0: kd> dd 003d3538

003d3538  77403a50 773f57b4 00000003 00000002

003d3548  00000000 00000000 003d2ef0 003d8840

003d3558  0038b1c0 003e05f8 77403980 00070005

This gives us a pointer to another data structure that contains the information we are attempting to locate.

0: kd> dd 003d2ef0

003d2ef0  774ee600 003d2e70 00000d34 00000000

003d2f00  862941fa c94cde09 55a88424 801a2601

003d2f10  55a88424 801a2601 0000c400 00000d34

Ah there it is! 0d34 is the process id servicing our OLE request.

I went back and reviewed the !process 0 0 output to locate the process containing PID 0D34. I’m dumping it here.

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

    DirBase: 7d66c7a0  ObjectTable: a5651a98  HandleCount: 170.

    Image: ieuser.exe

Ok, so the process handing this request is IEUSER.exe, which is the broker process used by Internet Explorer in Vista when running in protect mode.  This is new in Vista.

More on IEUser and Protected mode can be seen at the following location:
https://msdn.microsoft.com/en-us/library/bb250462.aspx

Now I needed to dig into the IEUser.exe process to find out what it was working on causing Iexplore to wait.

0: kd> !process 861a9d90

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

    DirBase: 7d66c7a0  ObjectTable: a5651a98  HandleCount: 170.

    Image: ieuser.exe

I discovered the thread in the ieuser.exe process working on our call from Iexplore.exe. However this thread is also waiting on access to something before it can complete.

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

I’m dumping the first parameter passed to KeWaitForSingleObject to determine the object type.

0: kd> !object 85e18510

Object: 85e18510  Type: (85484d40) Mutant

    ObjectHeader: 85e184f8 (old version)

    HandleCount: 3  PointerCount: 5

    Directory Object: 881f3030  Name: RasPbFile

Ok, we are waiting on a Mutex named RasPbFile. The big question in your mind now is, “who owns this lock”, right?

To determine this I’ll dump the structure for the mutex object:

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 ''

The owner of the mutex is 870b6398. The bad news is this is the same thread I started with in the Iexplore.exe process so we’re looking at a classic deadlock scenario. Thread 870b6398 running under Iexplore.exe has made an OLE call over to the IEuser.exe broker process. The IEuser process needs the mutex owned by the thread that called it in the first place.
This turned out to be a bug in the RasApi code, not the browser or IEuser process.  The RasAPI code was written in such a way that it would wait for an infinite period of time to gain the Mutex.

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

The good news is that we have created hotfix 951738 to address this issue please contact Product Support to obtain this fix.

(this Blog brought to you by Louis Shanks, a Senior Escalation Engineer for Internet Explorer)

Regards,

The IE Support Team

Comments

• Anonymous
  January 14, 2009
  Interesting article, although very poorly commented by the author. Not many outside the loop will understand why you selcted the different adresses and also explanations on the various commands would be helpful for most.Just a handy pointer to help you become a better tutor ;)
• Anonymous
  January 15, 2009
  Wow,that was great!!!i would like to work solving problems like these!!!
• Anonymous
  March 06, 2011
  Hi Dude, You are amazing. We are saved at last....