My new laptop caused BSOD and I figured out I might have to update Wi-Fi driver (but not yet).
I opened the kernel dump generated with Windows Debugger.
Loading Dump File [C:\Temp\MEMORY.DMP]
Kernel Summary Dump File: Only kernel address space is available
Windows 7 Kernel Version 7600 MP (2 procs) Free x64
1: kd> !analyze -v
BAD_POOL_CALLER (c2)
The current thread is making a bad pool request. Typically this is at a bad IRQL level or double freeing the same allocation, etc.
Arguments:
Arg1: 0000000000000007, Attempt to free pool which was already freed
Arg2: 0000000000001097, (reserved)
Arg3: 00000000000c0018, Memory contents of the pool block
Arg4: fffffa800951f450, Address of the block of pool being deallocated
// so what happened is that someone freed pool twice.
Debugging Details:
------------------
POOL_ADDRESS: fffffa800951f450 Nonpaged pool
FREED_POOL_TAG: W3Rx
BUGCHECK_STR: 0xc2_7_W3Rx
DEFAULT_BUCKET_ID: VISTA_DRIVER_FAULT
PROCESS_NAME: wlmail.exe
CURRENT_IRQL: 0
LAST_CONTROL_TRANSFER: from fffff80002bc260e to fffff80002a90f00
STACK_TEXT:
fffff880`08404fb8 fffff800`02bc260e : 00000000`000000c2 00000000`00000007 00000000`00001097 00000000`000c0018 : nt!KeBugCheckEx
fffff880`08404fc0 fffff880`01642ad2 : fffffa80`0927c4a0 00000000`00000000 00000000`00000000 fffffa80`0951f470 : nt!ExFreePool+0xccb
fffff880`08405070 fffff880`04c0c523 : fffff780`00000014 fffffa80`05e7da80 fffffa80`09504fe0 fffff880`04a51e09 : ndis!NdisFreeNetBufferList+0x112
fffff880`084050a0 fffff880`04a4fadc : fffffa80`09504ff8 fffffa80`05e7da80 00000000`00000000 fffff880`04a51e09 : NETw1v64+0x1cb523 // suspicious driver which freed pool twice.
fffff880`084050d0 fffff880`04bfcde5 : fffffa80`09504fb0 fffffa80`09504fb0 00000000`00000018 00000000`00000000 : NETw1v64+0xeadc
fffff880`08405120 fffff880`04a44585 : 00000000`00000000 fffffa80`092df050 fffffa80`07310010 00000000`00000000 : NETw1v64+0x1bbde5
fffff880`08405180 fffff880`02d665bb : fffffa80`00000000 00000000`00000012 fffffa80`07310010 fffffa80`085cc180 : NETw1v64+0x3585
fffff880`084051b0 fffff880`02d68643 : fffffa80`092b96a0 fffffa80`092b96a0 fffffa80`092df050 00000000`00000000 : nwifi!WPP_SF_dll+0x3ab
fffff880`084051f0 fffff880`03bd5ed9 : 00000000`00000000 00000000`00000000 fffffa80`092b96a0 ffffffff`ffffffff : nwifi!MP6ReturnNBL+0x4b
fffff880`08405220 fffff880`016c9484 : fffffa80`05a8b1a0 00000000`00000000 00000000`00000000 00000000`00000000 : vpcnfltr!FilterReturnNetBufferLists+0x201
fffff880`08405270 fffff880`016ff17b : fffffa80`0784abb0 fffffa80`05a8b1a0 00000000`00000000 fffffa80`07ecc8a0 : ndis!ndisReturnNetBufferListsInternal+0x94
fffff880`084052b0 fffff880`01871ff5 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ndis!NdisReturnNetBufferLists+0x3b
fffff880`084052f0 fffff880`01735173 : 00000000`ffffffff 00000000`00000001 00000000`00000001 fffff800`02aa064a : tcpip!FlpReturnNetBufferListChain+0x95
fffff880`08405340 fffff880`0186bd41 : fffffa80`092b96a0 fffffa80`08db7500 fffff880`084053e0 00000000`00000000 : NETIO!NetioDereferenceNetBufferListChain+0xf3
fffff880`084053c0 fffff880`03ad760d : 00000000`ffffffff fffffa80`092b96a0 fffff880`08405c60 fffffa80`0914de50 : tcpip!TcpReleaseIndicationList+0x81
fffff880`084053f0 fffff880`03b18995 : fffff880`08405930 fffffa80`0914de50 00000000`ffffffff 00000000`00000000 : afd!AfdTLReleaseIndications+0x2d
fffff880`08405440 fffff880`03b01051 : fffffa80`04a5d010 fffff880`08405870 7969a55b`00000001 f1367ba8`57c99d30 : afd!AfdFastConnectionReceive+0xb65
fffff880`08405660 fffff800`02da9113 : 00000000`00002000 fffffa80`090e4c80 00000000`070bf9d8 fffffa80`08e4c501 : afd!AfdFastIoDeviceControl+0x1041
fffff880`084059d0 fffff800`02da9c06 : fffff880`08405b98 00000000`00000a9c 00000000`00000001 00000000`00000000 : nt!IopXxxControlFile+0x373
fffff880`08405b00 fffff800`02a90153 : 00000000`00000000 fffffa80`00000000 00000000`00000000 fffffa80`07be2160 : nt!NtDeviceIoControlFile+0x56
fffff880`08405b70 00000000`741a2dd9 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : nt!KiSystemServiceCopyEnd+0x13
00000000`071eee18 00000000`00000000 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : 0x741a2dd9
STACK_COMMAND: kb
FOLLOWUP_IP:
NETw1v64+1cb523
fffff880`04c0c523 83c8ff or eax,0FFFFFFFFh
SYMBOL_STACK_INDEX: 3
SYMBOL_NAME: NETw1v64+1cb523
FOLLOWUP_NAME: wintriag
MODULE_NAME: NETw1v64
IMAGE_NAME: NETw1v64.sys
DEBUG_FLR_IMAGE_TIMESTAMP: 4a64f0bf
FAILURE_BUCKET_ID: X64_0xc2_7_W3Rx_NETw1v64+1cb523
BUCKET_ID: X64_0xc2_7_W3Rx_NETw1v64+1cb523
Followup: wintriag
---------
1: kd> lmvm NETw1v64
start end module name
fffff880`04a41000 fffff880`05108000 NETw1v64 (no symbols)
Loaded symbol image file: NETw1v64.sys
Image path: \SystemRoot\system32\DRIVERS\NETw1v64.sys
Image name: NETw1v64.sys
Timestamp: Mon Jul 20 15:33:35 2009 (4A64F0BF)
CheckSum: 006BDF1C
ImageSize: 006C7000
Translations: 0000.04b0 0000.04e4 0409.04b0 0409.04e4
Then I checked the properties of NETw1v64.sys driver. It was Intel Wireless WiFi Link Driver for Intel(R) Wifi Link 1000. Version was 12.5.0.59.
I checked Acer's support page but the driver was not updated. So I went to Intel's support page. Intel already released WiFi Link 1000 driver version 13.0.0.107 for Windows 7 64 bit on 1/7/2010. I'll update when Acer lists it on their website. Or if same error occurs frequently.
Reference: How to Debug "Stop 0xC2" or "Stop 0x000000C2" Error Messages
(This entry was posted powered by Windows Live Writer)
Showing posts with label Debugging. Show all posts
Showing posts with label Debugging. Show all posts
Friday, February 19, 2010
My Acer Aspire 1420P (PDC Edition) restarted due to STOP 0xC2 error
Thursday, February 18, 2010
Unable to load .DLLs due to "Unable To Locate Component" with semi-colon path
I recently worked on a nasty problem which I couldn’t find anyone solved. I hope this helps someone who hits the same problem.
PROBLEM DESCRIPTION
PROBLEM
A process fails to load .DLL file due to the error c0000135 (STATUS_DLL_NOT_FOUND) if the .DLL file path contains semi colon(;).
This problem occurs if you meet all of the following conditions:
A process fails to load .DLL file due to the error c0000135 (STATUS_DLL_NOT_FOUND) if the .DLL file path contains semi colon(;).
This problem occurs if you meet all of the following conditions:
- The execution file (.EXE) and .DLL file are placed in the same path
- The file path of the .DLL contains semi colon (;).
- .EXE loads the DLL
- The .EXE file is executed from the different execution path than the file path of the .EXE file.
ERROR MESSAGE
Unable To Locate Component: This application has failed to start because xxx.dll was not found. Re-installing the application may fix the problem.
Notes: A dialog shows up even if you execute the process as a console application.
Unable To Locate Component: This application has failed to start because xxx.dll was not found. Re-installing the application may fix the problem.
Notes: A dialog shows up even if you execute the process as a console application.
REPRO
Download DllLoadFailureTest.zip from the link, extract it and run Repro.bat if you want.
Download DllLoadFailureTest.zip from the link, extract it and run Repro.bat if you want.
RESOLUTION
Do NOT use “;” as a file path.
Do NOT use “;” as a file path.
INVESTIGATION
I attached a debugger when an error message dialog showed up before closing it.
0:000> du 10000
00010000 "=C:=C:\WINDOWS\system32" // execution path = %WINDIR%\SYSTEM32
0:000> lmvm DllLoadFailureTest
Image path: C:\DllLoadFailure;Test\DllLoadFailureTest.exe // execution file
0:000> kbn4
# ChildEBP RetAddr Args to Child
00 0012f740 7c827779 7c84b905 c0000135 00000002 ntdll!KiFastSystemCallRet
01 0012f744 7c84b905 c0000135 00000002 00000003 ntdll!ZwRaiseHardError+0xc // STATUS_DLL_NOT_FOUND
02 0012f838 7c83304f 00020498 0012f884 7ffdfc00 ntdll!LdrpMapDll+0x1c4 // DLL path, DLL name
03 0012fa9c 7c832fa5 00020498 00402354 0012fac0 ntdll!LdrpLoadImportModule+0x17c
0:000> du poi(00020498)
00020498 "C:\DllLoadFailure;Test;C:\WINDOW" // DLL paths are separated with “;”
000204d8 "S\system32;C:\WINDOWS\system;C:\"
00020518 "WINDOWS;.;C:\WINDOWS\system32;C:" // Current directory (execution path).
00020558 "\WINDOWS;C:\WINDOWS\System32\Wbe"
0:000> du poi(7ffdfc00)
7ffdfc00 "MyDll.dll" // DLL being loaded. The full path is C:\DllLoadFailure;Test\MyDLL.dll
00010000 "=C:=C:\WINDOWS\system32" // execution path = %WINDIR%\SYSTEM32
0:000> lmvm DllLoadFailureTest
Image path: C:\DllLoadFailure;Test\DllLoadFailureTest.exe // execution file
0:000> kbn4
# ChildEBP RetAddr Args to Child
00 0012f740 7c827779 7c84b905 c0000135 00000002 ntdll!KiFastSystemCallRet
01 0012f744 7c84b905 c0000135 00000002 00000003 ntdll!ZwRaiseHardError+0xc // STATUS_DLL_NOT_FOUND
02 0012f838 7c83304f 00020498 0012f884 7ffdfc00 ntdll!LdrpMapDll+0x1c4 // DLL path, DLL name
03 0012fa9c 7c832fa5 00020498 00402354 0012fac0 ntdll!LdrpLoadImportModule+0x17c
0:000> du poi(00020498)
00020498 "C:\DllLoadFailure;Test;C:\WINDOW" // DLL paths are separated with “;”
000204d8 "S\system32;C:\WINDOWS\system;C:\"
00020518 "WINDOWS;.;C:\WINDOWS\system32;C:" // Current directory (execution path).
00020558 "\WINDOWS;C:\WINDOWS\System32\Wbe"
0:000> du poi(7ffdfc00)
7ffdfc00 "MyDll.dll" // DLL being loaded. The full path is C:\DllLoadFailure;Test\MyDLL.dll
The DLL path has a problem. C:\DllLoadFailure;Test got to be separated into C:\DllLoadFailure and Test because paths must be separated with “;”. Therefore Windows doesn’t understand the path ” C:\DllLoadFailure;Test”. When you execute a process from the path where .EXE is located, in other words, the execution path and .EXE file path is the same, Windows loads the DLL from current directory (.) using relative path.
You better not (actually shouldn’t) make a path which contains “;” even though Windows allows.
Tuesday, December 19, 2006
Outlook Express (msimn.exe) が応答なしになった (missing handle)
Outlook Express が応答なしのまま動かないので、ダンプを取っておきました。
0:000> kb
ChildEBP RetAddr Args to Child
0006a52c 7c94e9c0 7c8025db 000001a5 00000000 ntdll!KiFastSystemCallRet
0006a530 7c8025db 000001a5 00000000 00000000 ntdll!ZwWaitForSingleObject+0xc
0006a594 77e40acb 000001a5 ffffffff 00000000 kernel32!WaitForSingleObjectEx+0xa8
0006a5b0 77e40a81 0018808c 00000000 ffffffff rpcrt4!UTIL_WaitForSyncIO+0x20
0006a5d4 77e41289 00188058 0018808c 0006a618 rpcrt4!UTIL_GetOverlappedResultEx+0x1d
0006a5f0 77e41247 00188058 0018808c 0006a618 rpcrt4!UTIL_GetOverlappedResult+0x17
0006a610 77e40898 00000400 00000070 00166748 rpcrt4!NMP_SyncSendRecv+0x73
0006a630 77e40e8d 00166748 00000070 0006a748 rpcrt4!OSF_CCONNECTION::TransSendReceive+0x9e
0006a6ac 77e40e0d 00166748 05c3aa88 00000001 rpcrt4!OSF_CCONNECTION::SendFragment+0x226
0006a704 77e40c6f 00000000 00000058 0006a748 rpcrt4!OSF_CCALL::SendNextFragment+0x1d2
0006a74c 77e40bbc 0006a7d0 0006a78c 00000001 rpcrt4!OSF_CCALL::FastSendReceive+0x144
0006a768 77e4110b 0006a7d0 0006a78c 0006a7d0 rpcrt4!OSF_CCALL::SendReceiveHelper+0x58
0006a794 77e3a716 00166760 0006a7b4 77e3a747 rpcrt4!OSF_CCALL::SendReceive+0x41
0006a7a0 77e3a747 0006a7d0 75ec1aa0 0006abac rpcrt4!I_RpcSendReceive+0x24
0006a7b4 77eb3675 0006a7fc 001667b8 00000000 rpcrt4!NdrSendReceive+0x2b
0006ab90 75ec34a4 75ec1aa0 75ec17da 0006abac rpcrt4!NdrClientCall2+0x222
0006aba4 75ec42b9 000c1430 00000000 000bfbd0 davclnt!DavrCreateConnection+0x1b
0006ae58 71a54daa 00000000 0006bb18 00000000 davclnt!NPAddConnection3+0x17e
0006ae80 71a54d3c 00000000 0006baac 00000035 mpr!CUseConnection::TestProviderWorker+0x47
0006b750 71a525bd 0009cf78 0009ce20 0009cecc mpr!CUseConnection::TestProvider+0x62
WaitForSingleObjectEx で無制限に待っているので、何を待っているのかな？と調べてみると・・・
0:000> !handle 000001a5 f
Handle 000001a5
Type
unable to query object information
unable to query object information
No object specific information available
ハンドルがないです。これは困った。!handle で全部のハンドルを表示してみても 1a5 のハンドルがありません。
調べてみたのですが、
1. 待っている対象のハンドルを持ったスレッド／プロセスが不正に終了してしまった
→その場合はハンドルはクローズされ、待っているスレッドは待ち状態から解放される
2. 存在しないハンドルを指定した
→その場合は InvalidHandleException が起きるはず
となってしまいこの状態が説明できません。
今回のハングアップを調べるには、カーネル モード デバッグでハンドル状態をずっと監視していないといけないのですが、ハングアップを再度発生させることはできないのでこれ以上は不明です。
IIS 5.0 で動いていた ASP が IIS 5.1/6.0 で動作しない (WScript.Shell - Run/Exec)
こんな ASP スクリプトを作って IIS 5.1 で動かしてみたところ、エラーになりました。
IIS 5.0 では動いていたのに・・・
strCmd = "%windir%\system32\cmd.exe /c %windir%\system32\ping.exe localhost > C:\temp\pingtest.txt"
Set oShell = Server.CreateObject("WScript.Shell")
iRet = oShell.Run(strCmd, 0, True)
Response.Write(iRet)
ちなみにエラーは次のものでした。
Microsoft VBScript 実行時エラー (0x800A0046)
書き込みできません。
/test.asp, line 5
"書き込みできません" ってことは本当に書き込みができなかったんですけど、問題はどうして書き込みができなかったんだろう、ってことです。
多分アクセス権が足りなかったんだと思います。（IIS 5.1/6.0 は IIS 5.0 よりもセキュリティが厳しいので）
とりあえず IIS Out-Of-Process Pooled Application として実行されている dllhost.exe に windbg をアタッチして、SetLastError の第一引数に何が渡されているかを見ていきます。
0:023> bp kernel32!setlasterror "dd (esp+0x4) L1;g"
0:023> g
007efee0 00000102
006af0a0 000036b7
006af2bc 00000000
00e8f684 00000002
00e8f684 00000002
00e8ef28 000036b7
00e8e994 00000005
00e8e848 000036b7
（略）
E_ACCESSDENIED (0x5) がセットされているのが見えます。
怪しいのでこの時にブレークして中を見てみます。
0:023> bp kernel32!setlasterror "j poi(esp+0x4)==0x5 'kb1';'dd (esp+0x4) L1;g'"
0:023> g
007efee0 00000102
0076f0a0 000036b7
0076f2bc 00000000
00e8f684 00000002
00e8f684 00000002
00e8ef28 000036b7
（略）
ChildEBP RetAddr Args to Child
00e8e420 7c809392 00000005 7c95043d 00e8e4a0 kernel32!SetLastError
eax=00000005 ebx=c0000022 ecx=7c94fb71 edx=00000015 esi=00000005 edi=00000000
eip=7c8092c0 esp=00e8e424 ebp=00e8e430 iopl=0 nv up ei pl nz na po nc
cs=001b ss=0023 ds=0023 es=0023 fs=003b gs=0000 efl=00000206
kernel32!SetLastError:
7c8092c0 8bff mov edi,edi
ブレークしたのでスタックを見てみると、CreateFile でアクセス拒否されてます。
ちょっと前を見てみると、LoadLibraryEx が呼ばれています。
0:013> kb
ChildEBP RetAddr Args to Child
00e8e420 7c809392 00000005 7c95043d 00e8e4a0 kernel32!SetLastError
00e8e430 7c8112b2 c0000022 00e8e74c c0150008 kernel32!BaseSetLastNTError+0x17
00e8e4a0 7c814ade 00000000 80000000 00000005 kernel32!CreateFileW+0x390
00e8e708 7c801d3a 000d3130 00e8e730 00e8e74c kernel32!BasepLoadLibraryAsDataFile+0x125
00e8e76c 77bb13c2 00e8e914 00000000 00000002 kernel32!LoadLibraryExW+0x178
00e8e7bc 77f38c28 00e8e914 00e8e8fc 0014c888 VERSION!GetFileVersionInfoSizeW+0x31
00e8e8d8 77f38e05 00e8e914 00e8e8fc 00005021 SHLWAPI!GetFileVersionInfoSizeWrapW+0x54
00e8eb98 77f38d1d 0014c888 00000000 00000000 SHLWAPI!SHGetFileDescriptionW+0xa8
00e8eddc 77f38499 00e8ee84 00000000 00e8ee04 SHLWAPI!CAssocApplicationElement::_GetAppDisplayName+0xae
00e8edec 7d5e37db 0014c874 02170008 00000000 SHLWAPI!CAssocApplicationElement::QueryString+0x30
00e8ee04 7d5e3779 0014c874 02170008 00000000 SHELL32!_QueryString+0x17
00e8ee30 7d5e37bb 7d5e37c4 0000ffff 02170008 SHELL32!CAssocArray::_QueryElementAny<_FLAGGED_BYTE_BLOB * *>+0xb9
00e8ee50 7d5e3988 000c8a38 0000ffff 02170008 SHELL32!CAssocArray::QueryString+0x20
00e8ee74 77f3b800 000c8a40 00000042 00000004 SHELL32!CAssocArray::GetString+0x61
00e8eea0 7d5f218a 00000042 00000004 001424d4 SHLWAPI!AssocQueryStringW+0x5f
00e8f0f4 7d5f1df3 0013efe8 00000000 00e8f110 SHELL32!CShellExecute::_SetCommand+0x123
00e8f104 7d5f1dc5 0013efe8 00e8f124 7d5f18c4 SHELL32!CShellExecute::_DoExecCommand+0x19
00e8f110 7d5f18c4 00000001 00e8f1cc 0013efe8 SHELL32!CShellExecute::_TryInvokeApplication+0x49
00e8f124 7d5f17f6 000c1f98 00e8f1cc 00e8f164 SHELL32!CShellExecute::ExecuteNormal+0xb1
00e8f138 7d5f1792 00e8f164 0013c3cc 00e8f1cc SHELL32!ShellExecuteNormal+0x30
CreateFile のファイル パスは Null になっていますが、LoadLibraryEx でロードしようとしているモジュールを確認してみると、cmd.exe でした。
0:013> du 00e8e914
00e8e914 "C:\WINDOWS\system32\cmd.exe"
cmd.exe を実行しようとしてアクセス拒否にあっています。CreateFile は一時ファイルか何かなのでしょう。
cmd.exe の ACL をチェックしてみると、IUSR_computername（IIS 6.0 の場合は NETWORK SERVICE）に実行アクセス許可がありませんでした。ちなみにサイトには匿名アクセスを許可しています。
なので cmd.exe と、あわせて ping.exe に IUSR_computername の実行アクセス権を与えます。
そういやファイル出力先パス C:\temp にも IUSR_computername の書き込み許可が必要でしょう。これも許可します。
さらに実行していきます。
0:015> g
00f0d978 00000000
010cf70c 00000000
00f0d8c8 00000000
00f0d8c8 00000000
（略）
ChildEBP RetAddr Args to Child
00f0e98c 7c843606 00000005 00000000 00000000 kernel32!SetLastError
eax=00000005 ebx=00f0e9f0 ecx=7c94fb71 edx=00000015 esi=00000000 edi=00000018
eip=7c8092c0 esp=00f0e990 ebp=00f0e9c8 iopl=0 nv up ei pl nz na po nc
cs=001b ss=0023 ds=0023 es=0023 fs=003b gs=0000 efl=00000206
kernel32!SetLastError:
7c8092c0 8bff mov edi,edi
またブレークしました。何をしているか見ていきます。
0:015> kb
ChildEBP RetAddr Args to Child
00f0e98c 7c843606 00000005 00000000 00000000 kernel32!SetLastError
00f0e9c8 769bbda2 00000644 00f0e9f0 76971a60 kernel32!ProcessIdToSessionId+0x93
00f0e9e8 769bcadf 00000000 7697ca10 7697c6e0 ole32!AddHydraSessionID+0x54
00f0f190 7698faba 009b3c48 00000000 00000015 ole32!ICoCreateInstanceEx+0x202
00f0f1b8 7698fa89 009b3c48 00000000 00000015 ole32!CComActivator::DoCreateInstance+0x28
00f0f1dc 7698faf7 009b3c48 00000000 00000015 ole32!CoCreateInstanceEx+0x1e
00f0f20c 70e51ebf 009b3c48 00000000 00000015 ole32!CoCreateInstance+0x37
00f0f228 70e21a03 009b3c48 70e17708 009b3c44 asp!ViperCreateInstance+0x18
00f0f24c 70e22060 009b4140 00002000 009b3c28 asp!CComponentObject::TryInstantiate+0x78
00f0f288 70e22124 009b4140 70e59394 7c9410ed asp!CComponentObject::Instantiate+0x26
00f0f2a4 70e4fef7 00000004 00f0f318 00000000 asp!CPageComponentManager::AddScopedUnnamedInstantiated+0x5f
00f0f2ec 70e4288f 0111d698 009b4140 00f0f390 asp!CTypelibCache::CreateComponent+0xc6
00f0f32c 770d73d0 009aaecc 0111d698 00f0f390 asp!CServer::CreateObject+0x66
00f0f34c 770d79e0 009aaecc 00000024 00000004 OLEAUT32!DispCallFunc+0x16a
00f0f3dc 70e43244 00133f1c 009aaecc 00000000 OLEAUT32!CTypeInfo2::Invoke+0x234
00f0f404 7327ae0e 009aaecc 60020002 73254dd0 asp!CDispatchImpl::Invoke+0x4d
00f0f458 7326bb13 0003b880 009aaecc 60020002 vbscript!CatchIDispatchInvoke+0x46
00f0f4a4 732639f6 0003aee0 009aaecc 60020002 vbscript!IDispatchInvoke+0x95
00f0f5b8 73254b01 0003aee0 009aaecc 60020002 vbscript!InvokeDispatch+0x13a
00f0f5dc 7326391f 0003aee0 009aaecc 60020002 vbscript!InvokeByName+0x42
asp!CServer::CreateObject ということは ASP スクリプトの Server.CreateObject の箇所でしょう。
なので文字列の引数を持っているはずです。
ダンプしてみると・・・
0:015> du 0111d698
0111d698 "WScript.Shell"
やっぱりありました。
WScript.Shell の実体はレジストリから C:\WINDOWS\System32\wshom.ocx とわかります。
これにも IUSR_computername の実行アクセス許可を与えます。
そしてさらに続けます。
0:013> g
00e8e848 000036b7
ModLoad: 5cd80000 5cd98000 C:\WINDOWS\System32\wshom.ocx
おっ、読み込まれました。
無事に実行され、C:\temp\pingtest.txt に ping の結果が出力されてました。
このデバッグでは、cmd.exe を実行しようとして拒否されたことがわかったときに同様に ping.exe や c:\temp にアクセス許可を与えなければならないことに気づかないと、ハマります。
この２つに対してのアクセス拒否は cmd.exe プロセス内で発生するので、ASP がホストされるプロセスをいくらデバッグしても何も引っかかってこないためです。
IIS 5.0 では動いていたのに・・・
strCmd = "%windir%\system32\cmd.exe /c %windir%\system32\ping.exe localhost > C:\temp\pingtest.txt"
Set oShell = Server.CreateObject("WScript.Shell")
iRet = oShell.Run(strCmd, 0, True)
Response.Write(iRet)
ちなみにエラーは次のものでした。
Microsoft VBScript 実行時エラー (0x800A0046)
書き込みできません。
/test.asp, line 5
"書き込みできません" ってことは本当に書き込みができなかったんですけど、問題はどうして書き込みができなかったんだろう、ってことです。
多分アクセス権が足りなかったんだと思います。（IIS 5.1/6.0 は IIS 5.0 よりもセキュリティが厳しいので）
とりあえず IIS Out-Of-Process Pooled Application として実行されている dllhost.exe に windbg をアタッチして、SetLastError の第一引数に何が渡されているかを見ていきます。
0:023> bp kernel32!setlasterror "dd (esp+0x4) L1;g"
0:023> g
007efee0 00000102
006af0a0 000036b7
006af2bc 00000000
00e8f684 00000002
00e8f684 00000002
00e8ef28 000036b7
00e8e994 00000005
00e8e848 000036b7
（略）
E_ACCESSDENIED (0x5) がセットされているのが見えます。
怪しいのでこの時にブレークして中を見てみます。
0:023> bp kernel32!setlasterror "j poi(esp+0x4)==0x5 'kb1';'dd (esp+0x4) L1;g'"
0:023> g
007efee0 00000102
0076f0a0 000036b7
0076f2bc 00000000
00e8f684 00000002
00e8f684 00000002
00e8ef28 000036b7
（略）
ChildEBP RetAddr Args to Child
00e8e420 7c809392 00000005 7c95043d 00e8e4a0 kernel32!SetLastError
eax=00000005 ebx=c0000022 ecx=7c94fb71 edx=00000015 esi=00000005 edi=00000000
eip=7c8092c0 esp=00e8e424 ebp=00e8e430 iopl=0 nv up ei pl nz na po nc
cs=001b ss=0023 ds=0023 es=0023 fs=003b gs=0000 efl=00000206
kernel32!SetLastError:
7c8092c0 8bff mov edi,edi
ブレークしたのでスタックを見てみると、CreateFile でアクセス拒否されてます。
ちょっと前を見てみると、LoadLibraryEx が呼ばれています。
0:013> kb
ChildEBP RetAddr Args to Child
00e8e420 7c809392 00000005 7c95043d 00e8e4a0 kernel32!SetLastError
00e8e430 7c8112b2 c0000022 00e8e74c c0150008 kernel32!BaseSetLastNTError+0x17
00e8e4a0 7c814ade 00000000 80000000 00000005 kernel32!CreateFileW+0x390
00e8e708 7c801d3a 000d3130 00e8e730 00e8e74c kernel32!BasepLoadLibraryAsDataFile+0x125
00e8e76c 77bb13c2 00e8e914 00000000 00000002 kernel32!LoadLibraryExW+0x178
00e8e7bc 77f38c28 00e8e914 00e8e8fc 0014c888 VERSION!GetFileVersionInfoSizeW+0x31
00e8e8d8 77f38e05 00e8e914 00e8e8fc 00005021 SHLWAPI!GetFileVersionInfoSizeWrapW+0x54
00e8eb98 77f38d1d 0014c888 00000000 00000000 SHLWAPI!SHGetFileDescriptionW+0xa8
00e8eddc 77f38499 00e8ee84 00000000 00e8ee04 SHLWAPI!CAssocApplicationElement::_GetAppDisplayName+0xae
00e8edec 7d5e37db 0014c874 02170008 00000000 SHLWAPI!CAssocApplicationElement::QueryString+0x30
00e8ee04 7d5e3779 0014c874 02170008 00000000 SHELL32!_QueryString+0x17
00e8ee30 7d5e37bb 7d5e37c4 0000ffff 02170008 SHELL32!CAssocArray::_QueryElementAny<_FLAGGED_BYTE_BLOB * *>+0xb9
00e8ee50 7d5e3988 000c8a38 0000ffff 02170008 SHELL32!CAssocArray::QueryString+0x20
00e8ee74 77f3b800 000c8a40 00000042 00000004 SHELL32!CAssocArray::GetString+0x61
00e8eea0 7d5f218a 00000042 00000004 001424d4 SHLWAPI!AssocQueryStringW+0x5f
00e8f0f4 7d5f1df3 0013efe8 00000000 00e8f110 SHELL32!CShellExecute::_SetCommand+0x123
00e8f104 7d5f1dc5 0013efe8 00e8f124 7d5f18c4 SHELL32!CShellExecute::_DoExecCommand+0x19
00e8f110 7d5f18c4 00000001 00e8f1cc 0013efe8 SHELL32!CShellExecute::_TryInvokeApplication+0x49
00e8f124 7d5f17f6 000c1f98 00e8f1cc 00e8f164 SHELL32!CShellExecute::ExecuteNormal+0xb1
00e8f138 7d5f1792 00e8f164 0013c3cc 00e8f1cc SHELL32!ShellExecuteNormal+0x30
CreateFile のファイル パスは Null になっていますが、LoadLibraryEx でロードしようとしているモジュールを確認してみると、cmd.exe でした。
0:013> du 00e8e914
00e8e914 "C:\WINDOWS\system32\cmd.exe"
cmd.exe を実行しようとしてアクセス拒否にあっています。CreateFile は一時ファイルか何かなのでしょう。
cmd.exe の ACL をチェックしてみると、IUSR_computername（IIS 6.0 の場合は NETWORK SERVICE）に実行アクセス許可がありませんでした。ちなみにサイトには匿名アクセスを許可しています。
なので cmd.exe と、あわせて ping.exe に IUSR_computername の実行アクセス権を与えます。
そういやファイル出力先パス C:\temp にも IUSR_computername の書き込み許可が必要でしょう。これも許可します。
さらに実行していきます。
0:015> g
00f0d978 00000000
010cf70c 00000000
00f0d8c8 00000000
00f0d8c8 00000000
（略）
ChildEBP RetAddr Args to Child
00f0e98c 7c843606 00000005 00000000 00000000 kernel32!SetLastError
eax=00000005 ebx=00f0e9f0 ecx=7c94fb71 edx=00000015 esi=00000000 edi=00000018
eip=7c8092c0 esp=00f0e990 ebp=00f0e9c8 iopl=0 nv up ei pl nz na po nc
cs=001b ss=0023 ds=0023 es=0023 fs=003b gs=0000 efl=00000206
kernel32!SetLastError:
7c8092c0 8bff mov edi,edi
またブレークしました。何をしているか見ていきます。
0:015> kb
ChildEBP RetAddr Args to Child
00f0e98c 7c843606 00000005 00000000 00000000 kernel32!SetLastError
00f0e9c8 769bbda2 00000644 00f0e9f0 76971a60 kernel32!ProcessIdToSessionId+0x93
00f0e9e8 769bcadf 00000000 7697ca10 7697c6e0 ole32!AddHydraSessionID+0x54
00f0f190 7698faba 009b3c48 00000000 00000015 ole32!ICoCreateInstanceEx+0x202
00f0f1b8 7698fa89 009b3c48 00000000 00000015 ole32!CComActivator::DoCreateInstance+0x28
00f0f1dc 7698faf7 009b3c48 00000000 00000015 ole32!CoCreateInstanceEx+0x1e
00f0f20c 70e51ebf 009b3c48 00000000 00000015 ole32!CoCreateInstance+0x37
00f0f228 70e21a03 009b3c48 70e17708 009b3c44 asp!ViperCreateInstance+0x18
00f0f24c 70e22060 009b4140 00002000 009b3c28 asp!CComponentObject::TryInstantiate+0x78
00f0f288 70e22124 009b4140 70e59394 7c9410ed asp!CComponentObject::Instantiate+0x26
00f0f2a4 70e4fef7 00000004 00f0f318 00000000 asp!CPageComponentManager::AddScopedUnnamedInstantiated+0x5f
00f0f2ec 70e4288f 0111d698 009b4140 00f0f390 asp!CTypelibCache::CreateComponent+0xc6
00f0f32c 770d73d0 009aaecc 0111d698 00f0f390 asp!CServer::CreateObject+0x66
00f0f34c 770d79e0 009aaecc 00000024 00000004 OLEAUT32!DispCallFunc+0x16a
00f0f3dc 70e43244 00133f1c 009aaecc 00000000 OLEAUT32!CTypeInfo2::Invoke+0x234
00f0f404 7327ae0e 009aaecc 60020002 73254dd0 asp!CDispatchImpl::Invoke+0x4d
00f0f458 7326bb13 0003b880 009aaecc 60020002 vbscript!CatchIDispatchInvoke+0x46
00f0f4a4 732639f6 0003aee0 009aaecc 60020002 vbscript!IDispatchInvoke+0x95
00f0f5b8 73254b01 0003aee0 009aaecc 60020002 vbscript!InvokeDispatch+0x13a
00f0f5dc 7326391f 0003aee0 009aaecc 60020002 vbscript!InvokeByName+0x42
asp!CServer::CreateObject ということは ASP スクリプトの Server.CreateObject の箇所でしょう。
なので文字列の引数を持っているはずです。
ダンプしてみると・・・
0:015> du 0111d698
0111d698 "WScript.Shell"
やっぱりありました。
WScript.Shell の実体はレジストリから C:\WINDOWS\System32\wshom.ocx とわかります。
これにも IUSR_computername の実行アクセス許可を与えます。
そしてさらに続けます。
0:013> g
00e8e848 000036b7
ModLoad: 5cd80000 5cd98000 C:\WINDOWS\System32\wshom.ocx
おっ、読み込まれました。
無事に実行され、C:\temp\pingtest.txt に ping の結果が出力されてました。
このデバッグでは、cmd.exe を実行しようとして拒否されたことがわかったときに同様に ping.exe や c:\temp にアクセス許可を与えなければならないことに気づかないと、ハマります。
この２つに対してのアクセス拒否は cmd.exe プロセス内で発生するので、ASP がホストされるプロセスをいくらデバッグしても何も引っかかってこないためです。
WaitForSingleObject をデバッグする
Visual Studio を使っていて、F5 を押してデバッグしようと思ったらとまってしまったので Visual Studio をデバッグしてみました。
今回参考にしたページはこちらです。
How to find out on which thread a blocked thread is waiting
Adplus を使って devenv.exe のダンプをとり、調べてみると・・・
ビルド中で、何かを WaitForSingleObject で無制限に待っている状態です。
0:000> kb
ChildEBP RetAddr Args to Child
0012f184 7c94e9c0 7c8025db 000004fc 00000000 ntdll!KiFastSystemCallRet
0012f188 7c8025db 000004fc 00000000 00000000 ntdll!ZwWaitForSingleObject+0xc
0012f1ec 7c802542 000004fc ffffffff 00000000 kernel32!WaitForSingleObjectEx+0xa8
0012f200 53820169 000004fc ffffffff 00000000 kernel32!WaitForSingleObject+0x12
0012f288 537fc73d 00000000 09645e10 00000000 csproj!RunProcess+0x135
0012f3c8 537fbe13 096682e0 096740b0 0012f428 csproj!CLangSatelliteAssembly::CallLinker+0x2fb
0012f3e8 537ba073 096682e0 00000001 0012f428 csproj!CLangSatelliteAssembly::Build+0x9a
0012f420 5377c54d 00000000 00000001 043bfc60 csproj!CLangSatelliteManager::Build+0xdc
0012f448 5377c59f 00000000 5377ce5c 00000000 csproj!CLangCompiler::GenerateSatellites+0xac
0012f450 5377ce5c 00000000 00000001 043bfc60 csproj!CLangCompiler::DoPostCompile+0x16
0012f480 5377ce04 00000001 00000000 043b2104 csproj!CVsProjBuildableProjectCfg::EndBuildProcess+0x51
0012f490 5377af59 043bfc64 00000001 00000000 csproj!CVsProjBuildableProjectCfg::BuildEnd+0x3b
0012f4c0 5377b113 00000000 00000000 043bfc60 csproj!CCSharpBuildCompiler::DoMainBuild+0x18b
0012f4d0 5377b2f1 00000000 043bfc64 039be3f8 csproj!CLangCompiler::StartCompilation+0x5d
0012f4f4 5377b396 039be3b4 500128a5 043bfc60 csproj!CVsProjBuildableProjectCfg::StartBuildProcess+0x1d6
0012f4fc 500128a5 043bfc60 039be3bc 00000000 csproj!CVsProjBuildableProjectCfg::StartBuild+0x3f
0012f518 500127c4 039be3b4 502eaf38 500133ca msenv!CSUIBuilder::DoBuild+0xbf
0012f524 500133ca 00000000 00000000 0012f5d0 msenv!CSUIBuilder::Run+0x41
0012f540 50012ba0 0012f56c 500c9aa9 00000113 msenv!CSlnUpdate::RunBuild+0x60
0012f548 500c9aa9 00000113 00000157 00000000 msenv!CSlnUpdate::HandleMsg+0x58
WaitForSingleObject の第一パラメータはハンドルなので、何を待っているのか確認してみます。
0:000> !handle 000004fc f
Handle 000004fc
Type Process
Attributes 0
GrantedAccess 0x1f0fff:
Delete,ReadControl,WriteDac,WriteOwner,Synch
Terminate,CreateThread,,VMOp,VMRead,VMWrite,DupHandle,CreateProcess,SetQuota,SetInfo,QueryInfo,SetPort
HandleCount 3
PointerCount 61
Name
Object specific information
Process Id 2568
Parent Process 2364
Base Priority 8
PID 2568 のプロセスを待っています。
自分自身のプロセス情報を見てみると・・・
0:000> |
. 0 id: 93c examine name: G:\Program Files\Microsoft Visual Studio .NET 2003\Common7\IDE\devenv.exe
0:000> ?93c
Evaluate expression: 2364 = 0000093c
PID が違うので、他のプロセスを待っています。
ここで adplus が出力しているプロセス リストを見てみると・・・
0 64 2568 al.exe Title: C:\WINDOWS2\Microsoft.NET\Framework\v1.1.4322\al.exe
Command Line:
リンカを待っていることがわかりました。
RunProcess の引数を勘で適当にダンプしてみたら・・・
0:000> du 09645e10
09645e10 ""C:\WINDOWS2\Microsoft.NET\Frame"
09645e50 "work\v1.1.4322\al.exe" /nologo /"
（略）
リンカを起動して、al.exe の起動か処理が完了してないのでハングしたことがわかりました。
でも、今回は al.exe のダンプを取ってなかったので、これ以上はわかりません。
ちょこっと他のスレッドも除いてみることにしました。
0:000> ~2s
eax=791d24e3 ebx=049afea4 ecx=00000080 edx=00000002 esi=00000000 edi=7ffde000
eip=7c94eb94 esp=049afe7c ebp=049aff18 iopl=0 nv up ei pl zr na po nc
cs=001b ss=0023 ds=0023 es=0023 fs=003b gs=0000 efl=00000246
ntdll!KiFastSystemCallRet:
7c94eb94 c3 ret
0:002> kb
ChildEBP RetAddr Args to Child
049afe78 7c94e9ab 7c8094f2 00000003 049afea4 ntdll!KiFastSystemCallRet
049afe7c 7c8094f2 00000003 049afea4 00000001 ntdll!ZwWaitForMultipleObjects+0xc
049aff18 7c809c86 00000003 049aff58 00000000 kernel32!WaitForMultipleObjectsEx+0x12c
049aff34 791d1707 00000003 049aff58 00000000 kernel32!WaitForMultipleObjects+0x18
049aff9c 791d167e 00000000 7c953288 00000000 mscorwks!DebuggerRCThread::MainLoop+0x90
049affac 791d24ee 049affec 7c80b50b 047e1eb0 mscorwks!DebuggerRCThread::ThreadProc+0x68
049affb4 7c80b50b 047e1eb0 7c953288 00000000 mscorwks!DebuggerRCThread::ThreadProcStatic+0xb
049affec 00000000 791d24e3 047e1eb0 00000000 kernel32!BaseThreadStart+0x37
WaitForMultipleObjects が 3 つのハンドルを待っています。
ポインタの内容をダンプして、次の 3 つのハンドルを待っていることがわかります。
0:002> dd 049aff58 L3
049aff58 0000029c 000002a4 00000294
内容を見てみると・・・
0:002> !handle 0000029c f
Handle 0000029c
Type Event
Attributes 0
GrantedAccess 0x1f0003:
Delete,ReadControl,WriteDac,WriteOwner,Synch
QueryState,ModifyState
HandleCount 2
PointerCount 4
Name
No object specific information available
イベント ハンドルです。
他の 2 つも同じですけど、イベント ハンドルはカーネル デバッグをしないとわからないので今回はここまでになります。
今回参考にしたページはこちらです。
How to find out on which thread a blocked thread is waiting
Adplus を使って devenv.exe のダンプをとり、調べてみると・・・
ビルド中で、何かを WaitForSingleObject で無制限に待っている状態です。
0:000> kb
ChildEBP RetAddr Args to Child
0012f184 7c94e9c0 7c8025db 000004fc 00000000 ntdll!KiFastSystemCallRet
0012f188 7c8025db 000004fc 00000000 00000000 ntdll!ZwWaitForSingleObject+0xc
0012f1ec 7c802542 000004fc ffffffff 00000000 kernel32!WaitForSingleObjectEx+0xa8
0012f200 53820169 000004fc ffffffff 00000000 kernel32!WaitForSingleObject+0x12
0012f288 537fc73d 00000000 09645e10 00000000 csproj!RunProcess+0x135
0012f3c8 537fbe13 096682e0 096740b0 0012f428 csproj!CLangSatelliteAssembly::CallLinker+0x2fb
0012f3e8 537ba073 096682e0 00000001 0012f428 csproj!CLangSatelliteAssembly::Build+0x9a
0012f420 5377c54d 00000000 00000001 043bfc60 csproj!CLangSatelliteManager::Build+0xdc
0012f448 5377c59f 00000000 5377ce5c 00000000 csproj!CLangCompiler::GenerateSatellites+0xac
0012f450 5377ce5c 00000000 00000001 043bfc60 csproj!CLangCompiler::DoPostCompile+0x16
0012f480 5377ce04 00000001 00000000 043b2104 csproj!CVsProjBuildableProjectCfg::EndBuildProcess+0x51
0012f490 5377af59 043bfc64 00000001 00000000 csproj!CVsProjBuildableProjectCfg::BuildEnd+0x3b
0012f4c0 5377b113 00000000 00000000 043bfc60 csproj!CCSharpBuildCompiler::DoMainBuild+0x18b
0012f4d0 5377b2f1 00000000 043bfc64 039be3f8 csproj!CLangCompiler::StartCompilation+0x5d
0012f4f4 5377b396 039be3b4 500128a5 043bfc60 csproj!CVsProjBuildableProjectCfg::StartBuildProcess+0x1d6
0012f4fc 500128a5 043bfc60 039be3bc 00000000 csproj!CVsProjBuildableProjectCfg::StartBuild+0x3f
0012f518 500127c4 039be3b4 502eaf38 500133ca msenv!CSUIBuilder::DoBuild+0xbf
0012f524 500133ca 00000000 00000000 0012f5d0 msenv!CSUIBuilder::Run+0x41
0012f540 50012ba0 0012f56c 500c9aa9 00000113 msenv!CSlnUpdate::RunBuild+0x60
0012f548 500c9aa9 00000113 00000157 00000000 msenv!CSlnUpdate::HandleMsg+0x58
WaitForSingleObject の第一パラメータはハンドルなので、何を待っているのか確認してみます。
0:000> !handle 000004fc f
Handle 000004fc
Type Process
Attributes 0
GrantedAccess 0x1f0fff:
Delete,ReadControl,WriteDac,WriteOwner,Synch
Terminate,CreateThread,,VMOp,VMRead,VMWrite,DupHandle,CreateProcess,SetQuota,SetInfo,QueryInfo,SetPort
HandleCount 3
PointerCount 61
Name
Object specific information
Process Id 2568
Parent Process 2364
Base Priority 8
PID 2568 のプロセスを待っています。
自分自身のプロセス情報を見てみると・・・
0:000> |
. 0 id: 93c examine name: G:\Program Files\Microsoft Visual Studio .NET 2003\Common7\IDE\devenv.exe
0:000> ?93c
Evaluate expression: 2364 = 0000093c
PID が違うので、他のプロセスを待っています。
ここで adplus が出力しているプロセス リストを見てみると・・・
0 64 2568 al.exe Title: C:\WINDOWS2\Microsoft.NET\Framework\v1.1.4322\al.exe
Command Line:
リンカを待っていることがわかりました。
RunProcess の引数を勘で適当にダンプしてみたら・・・
0:000> du 09645e10
09645e10 ""C:\WINDOWS2\Microsoft.NET\Frame"
09645e50 "work\v1.1.4322\al.exe" /nologo /"
（略）
リンカを起動して、al.exe の起動か処理が完了してないのでハングしたことがわかりました。
でも、今回は al.exe のダンプを取ってなかったので、これ以上はわかりません。
ちょこっと他のスレッドも除いてみることにしました。
0:000> ~2s
eax=791d24e3 ebx=049afea4 ecx=00000080 edx=00000002 esi=00000000 edi=7ffde000
eip=7c94eb94 esp=049afe7c ebp=049aff18 iopl=0 nv up ei pl zr na po nc
cs=001b ss=0023 ds=0023 es=0023 fs=003b gs=0000 efl=00000246
ntdll!KiFastSystemCallRet:
7c94eb94 c3 ret
0:002> kb
ChildEBP RetAddr Args to Child
049afe78 7c94e9ab 7c8094f2 00000003 049afea4 ntdll!KiFastSystemCallRet
049afe7c 7c8094f2 00000003 049afea4 00000001 ntdll!ZwWaitForMultipleObjects+0xc
049aff18 7c809c86 00000003 049aff58 00000000 kernel32!WaitForMultipleObjectsEx+0x12c
049aff34 791d1707 00000003 049aff58 00000000 kernel32!WaitForMultipleObjects+0x18
049aff9c 791d167e 00000000 7c953288 00000000 mscorwks!DebuggerRCThread::MainLoop+0x90
049affac 791d24ee 049affec 7c80b50b 047e1eb0 mscorwks!DebuggerRCThread::ThreadProc+0x68
049affb4 7c80b50b 047e1eb0 7c953288 00000000 mscorwks!DebuggerRCThread::ThreadProcStatic+0xb
049affec 00000000 791d24e3 047e1eb0 00000000 kernel32!BaseThreadStart+0x37
WaitForMultipleObjects が 3 つのハンドルを待っています。
ポインタの内容をダンプして、次の 3 つのハンドルを待っていることがわかります。
0:002> dd 049aff58 L3
049aff58 0000029c 000002a4 00000294
内容を見てみると・・・
0:002> !handle 0000029c f
Handle 0000029c
Type Event
Attributes 0
GrantedAccess 0x1f0003:
Delete,ReadControl,WriteDac,WriteOwner,Synch
QueryState,ModifyState
HandleCount 2
PointerCount 4
Name
No object specific information available
イベント ハンドルです。
他の 2 つも同じですけど、イベント ハンドルはカーネル デバッグをしないとわからないので今回はここまでになります。
Subscribe to:
Posts (Atom)