Last week I was trying to get prints of some photos I had from a good friend's wedding. I had success with Internet photo printing before at a different store so I decided to use the service offered by a nearby store for quick pickup. I go to the website and begin to upload the pictures and while navigating around my browser (IE7) became unresponsive and gave me the faded white screen for a while (at least a minute). NOOOO, you were working so well until just now! What was causing this behavior?
In cases where you have processor time spikes or hanging apps you can use the !runaway command to see what threads are taking the most time. In the debugger output below you can see that thread 3 is taking a considerable chunk of the CPU time compared to the other threads.
0:020> !runaway
User Mode Time
Thread Time
3:25c 0 days 0:00:21.044
0:158c 0 days 0:00:02.012
5:17fc 0 days 0:00:01.450
6:e60 0 days 0:00:01.216
4:10f0 0 days 0:00:00.046
14:1470 0 days 0:00:00.015
13:4b8 0 days 0:00:00.015
8:14c8 0 days 0:00:00.015
7:e74 0 days 0:00:00.015
1:1630 0 days 0:00:00.015
20:5bc 0 days 0:00:00.000
19:17f0 0 days 0:00:00.000
18:10c8 0 days 0:00:00.000
17:c04 0 days 0:00:00.000
16:12bc 0 days 0:00:00.000
15:1674 0 days 0:00:00.000
12:1248 0 days 0:00:00.000
11:5f0 0 days 0:00:00.000
10:ecc 0 days 0:00:00.000
9:16b8 0 days 0:00:00.000
2:14e4 0 days 0:00:00.000
We switch to thread 3 and get a stack backtrace with extended frame count so that the whole stack is present (without this you will not get the last 2 frames). Looking the call stack you can see that some component (1BA7) had made a HTTP request and is now waiting on a response. Ok, now this makes sense because it seems that the HTTP response is taking a longer than desired.
0:020> ~3s
eax=05f9a000 ebx=75f7c54c ecx=05f99fe8 edx=00001000 esi=0433c154 edi=00000000
eip=77579a94 esp=0433c10c ebp=0433c17c iopl=0 nv up ei ng nz ac pe cy
cs=001b ss=0023 ds=0023 es=0023 fs=003b gs=0000 efl=00000297
ntdll!KiFastSystemCallRet:
77579a94 c3 ret
0:003> kn250
# ChildEBP RetAddr
00 0433c108 77579254 ntdll!KiFastSystemCallRet
01 0433c10c 75f7c244 ntdll!ZwWaitForSingleObject+0xc
02 0433c17c 75f7c1b2 kernel32!WaitForSingleObjectEx+0xbe
03 0433c190 76fc165d kernel32!WaitForSingleObject+0x12
04 0433c1d0 76f88b0e wininet!CServerInfo::GetConnection_Fsm+0x34f
05 0433c1e8 76f83f49 wininet!CFsm_GetConnection::RunSM+0x61
06 0433c200 76f86441 wininet!CFsm::Run+0x39
07 0433c218 76f8873b wininet!DoFsm+0x25
08 0433c250 76f885d3 wininet!HTTP_REQUEST_HANDLE_OBJECT::OpenConnection_Fsm+0x1bb
09 0433c25c 76f83f49 wininet!CFsm_OpenConnection::RunSM+0x33
0a 0433c274 76f86441 wininet!CFsm::Run+0x39
0b 0433c28c 76f88569 wininet!DoFsm+0x25
0c 0433c29c 76f88500 wininet!HTTP_REQUEST_HANDLE_OBJECT::OpenConnection+0x2f
0d 0433c2c0 76f8847d wininet!HTTP_REQUEST_HANDLE_OBJECT::MakeConnection_Fsm+0x81
0e 0433c2cc 76f83f49 wininet!CFsm_MakeConnection::RunSM+0x37
0f 0433c2e4 76f86441 wininet!CFsm::Run+0x39
10 0433c2fc 76f89125 wininet!DoFsm+0x25
11 0433c33c 76f89082 wininet!HTTP_REQUEST_HANDLE_OBJECT::SendRequest_Fsm+0xc2
12 0433c348 76f83f49 wininet!CFsm_SendRequest::RunSM+0x37
13 0433c360 76f86441 wininet!CFsm::Run+0x39
14 0433c378 76f86940 wininet!DoFsm+0x25
15 0433c394 76f8401d wininet!HTTP_REQUEST_HANDLE_OBJECT::HttpSendRequest_Start+0x474
16 0433c3a8 76f83f49 wininet!CFsm_HttpSendRequest::RunSM+0xa0
17 0433c3c0 76f86441 wininet!CFsm::Run+0x39
18 0433c3d8 76faf7af wininet!DoFsm+0x25
19 0433c400 76f9d34e wininet!HttpWrapSendRequest+0x148
*** ERROR: Symbol file could not be found. Defaulted to export symbols for 1BA7.tmp -
1a 0433c438 06e477c5 wininet!HttpSendRequestW+0x5e
WARNING: Stack unwind information not available. Following frames may be wrong.
1b 0433efa4 06e14502 1BA7!ffStart+0x23df5
1c 00000000 00000000 1BA7+0x4502
What is 1BA7? It's the Snapfish control which is on the website that I was using to upload the pictures.
0:003> lm vm 1BA7
start end module name
06e10000 06f18000 1BA7 (export symbols) 1BA7.tmp
Loaded symbol image file: 1BA7.tmp
Image path: C:\Users\bryangr\AppData\Local\Temp\Low\1BA7.tmp
Image name: 1BA7.tmp
Timestamp: Thu Jul 03 11:56:02 2008 (486D20C2)
CheckSum: 0010DF3F
ImageSize: 00108000
File version: 2.5.0.5
Product version: 2.5.0.5
File flags: 0 (Mask 17)
File OS: 4 Unknown Win32
File type: 2.0 Dll
File date: 00000000.00000000
Translations: 0409.04b0
CompanyName: Snapfish Inc.
ProductName: Snapfish File Upload ActiveX Control
InternalName: Snapfish File Upload ActiveX Control - Application maintained by Aaron Chan
OriginalFilename: QuickUploader.iaa
ProductVersion: 2, 5, 0, 5
FileVersion: 2, 5, 0, 5
FileDescription: Snapfish File Upload ActiveX Control
LegalCopyright: Copyright (C) 2004-2005 Snapfish Inc.
Comments: Snapfish File Upload ActiveX Control
I g'd the debugee and after a minute or so it began to respond again so I continued to order my prints. So what can be done to correct issues like this?