Hang on NtFsControlFile |
|||||||
Issue descriptionThis persists after a system restart: 1) Watch Chrome Canary SyzyAsan analysis take a long time (like an hour). 2) Terminate the process 3) Relaunch Chrome Canary 4) Startup is now hung at... 0:000> kn20 # ChildEBP RetAddr 00 04cff0f4 77150605 ntdll!NtFsControlFile+0xc 01 04cff154 68ee5ed5 KERNELBASE!GetCurrentProcess+0x1bf35 02 04cff324 68ee595b syzyasan_rtl!crashpad::SendToCrashHandlerServer+0x305 [e:\b\build\slave\syzygy_official\build\src\third_party\crashpad\files\util\win\registration_protocol_win.cc @ 81] 03 04cff368 68eb6141 syzyasan_rtl!crashpad::CrashpadClient::UseHandler+0xab [e:\b\build\slave\syzygy_official\build\src\third_party\crashpad\files\client\crashpad_client_win.cc @ 409] 04 04cff3ac 68eb61c8 syzyasan_rtl!agent::asan::reporters::`anonymous namespace'::EnsureCrashpadConnected+0xd1 [e:\b\build\slave\syzygy_official\build\src\syzygy\agent\asan\reporters\crashpad_reporter.cc @ 64] 05 04cff3b4 68eaaeaf syzyasan_rtl!agent::asan::reporters::CrashpadReporter::Create+0x8 [e:\b\build\slave\syzygy_official\build\src\syzygy\agent\asan\reporters\crashpad_reporter.cc @ 79] 06 04cff3e4 68eab398 syzyasan_rtl!agent::asan::`anonymous namespace'::CreateCrashReporterWithTypeHint+0x2f [e:\b\build\slave\syzygy_official\build\src\syzygy\agent\asan\runtime.cc @ 436] 07 04cff544 68ea726e syzyasan_rtl!agent::asan::AsanRuntime::SetUp+0x228 [e:\b\build\slave\syzygy_official\build\src\syzygy\agent\asan\runtime.cc @ 525] 08 04cff628 68ea262c syzyasan_rtl!agent::asan::SetUpAsanRuntime+0x14e [e:\b\build\slave\syzygy_official\build\src\syzygy\agent\asan\runtime_util.cc @ 215] 09 04cff64c 68ee8155 syzyasan_rtl!DllMain+0x6c [e:\b\build\slave\syzygy_official\build\src\syzygy\agent\asan\syzyasan_rtl.cc @ 191] 0a 04cff68c 68ee823b syzyasan_rtl!dllmain_dispatch+0x7c [f:\dd\vctools\crt\vcstartup\src\startup\dll_dllmain.cpp @ 200] 0b 04cff6a0 77916b8e syzyasan_rtl!_DllMainCRTStartup+0x1c [f:\dd\vctools\crt\vcstartup\src\startup\dll_dllmain.cpp @ 258] 0c 04cff6c0 778e5ade ntdll!LdrxCallInitRoutine+0x16 0d 04cff710 778f8189 ntdll!LdrpCallInitRoutine+0x43 0e 04cff790 778f8049 ntdll!LdrpInitializeNode+0x101 0f 04cff7b4 778f8060 ntdll!LdrpInitializeGraphRecurse+0x71 10 04cff7dc 778d2240 ntdll!LdrpInitializeGraphRecurse+0x88 11 04cff7f8 778ee33f ntdll!LdrpPrepareModuleForExecution+0x8b 12 04cff840 778eadfe ntdll!LdrpLoadDllInternal+0x121 13 04cff98c 778ee739 ntdll!LdrpLoadDll+0x92 14 04cffa10 770fea08 ntdll!LdrLoadDll+0xd9 15 04cffa54 0020310f KERNELBASE!LoadLibraryExW+0x138 16 04cffa88 00203053 chrome!`anonymous namespace'::LoadModuleWithDirectory+0x50 [c:\b\build\slave\win-asan\build\src\chrome\app\main_dll_loader_win.cc Rinse, repeat.
,
Dec 19 2016
Do you mean it's hung after restarting but only trying to run chrome again? Or doing all the repro steps again? It looks like connecting to handler is blocking, perhaps because the handler is wedged.
,
Dec 19 2016
Doing all the repro steps again. This is a fresh run of Chrome.
,
Dec 19 2016
To clarify, Chrome.exe is not running on my system (As far as I can tell). Launching it again gets me to that stack.
,
Dec 20 2016
This just happened to me with 57.0.2956.1. I installed canary freshly, flipped asan-optin, got the update, then relaunched. I now have a DOA browser process. # ChildEBP RetAddr 00 008fedfc 743a9703 ntdll_76ee0000!NtFsControlFile+0xc 01 008fee5c 681e5ed5 KERNELBASE!GetIsImmersiveColorUsingHighContrast+0x19633 02 008ff02c 681e595b syzyasan_rtl!crashpad::SendToCrashHandlerServer(struct crashpad::ClientToServerMessage * message = 0x008ff03c, union crashpad::ServerToClientMessage * response = 0x008ff060)+0x305 [e:\b\build\slave\syzygy_official\build\src\third_party\crashpad\files\util\win\registration_protocol_win.cc @ 81] 03 008ff070 681b6141 syzyasan_rtl!crashpad::CrashpadClient::UseHandler(void)+0xab [e:\b\build\slave\syzygy_official\build\src\third_party\crashpad\files\client\crashpad_client_win.cc @ 409] 04 008ff0b4 681b61c8 syzyasan_rtl!agent::asan::reporters::`anonymous namespace'::EnsureCrashpadConnected(void)+0xd1 [e:\b\build\slave\syzygy_official\build\src\syzygy\agent\asan\reporters\crashpad_reporter.cc @ 64] 05 008ff0bc 681aaeaf syzyasan_rtl!agent::asan::reporters::CrashpadReporter::Create(void)+0x8 [e:\b\build\slave\syzygy_official\build\src\syzygy\agent\asan\reporters\crashpad_reporter.cc @ 79] 06 008ff0ec 681ab398 syzyasan_rtl!agent::asan::`anonymous namespace'::CreateCrashReporterWithTypeHint(class agent::asan::AsanLogger * logger = 0x04dfef48, agent::asan::`anonymous-namespace'::CrashReporterType reporter_type = kDefaultCrashReporterType (0n0))+0x2f [e:\b\build\slave\syzygy_official\build\src\syzygy\agent\asan\runtime.cc @ 436] 07 008ff24c 681a726e syzyasan_rtl!agent::asan::AsanRuntime::SetUp(class std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> > * flags_command_line = 0x008ff314 "")+0x228 [e:\b\build\slave\syzygy_official\build\src\syzygy\agent\asan\runtime.cc @ 525] 08 008ff330 681a262c syzyasan_rtl!agent::asan::SetUpAsanRuntime(void)+0x14e [e:\b\build\slave\syzygy_official\build\src\syzygy\agent\asan\runtime_util.cc @ 215] 09 008ff354 681e8155 syzyasan_rtl!DllMain(struct HINSTANCE__ * instance = 0x681a0000, unsigned long reason = 1, void * reserved = 0x00000000)+0x6c [e:\b\build\slave\syzygy_official\build\src\syzygy\agent\asan\syzyasan_rtl.cc @ 191] 0a 008ff394 681e823b syzyasan_rtl!dllmain_dispatch(struct HINSTANCE__ * instance = 0x681a0000, unsigned long reason = 1, void * reserved = 0x00000000)+0x7c [f:\dd\vctools\crt\vcstartup\src\startup\dll_dllmain.cpp @ 200] 0b 008ff3a8 76f4e58e syzyasan_rtl!_DllMainCRTStartup(struct HINSTANCE__ * instance = 0x681a0000, unsigned long reason = 1, void * reserved = 0x00000000)+0x1c [f:\dd\vctools\crt\vcstartup\src\startup\dll_dllmain.cpp @ 258] 0c 008ff3c8 76f20e46 ntdll_76ee0000!LdrxCallInitRoutine+0x16 0d 008ff418 76f0aafc ntdll_76ee0000!LdrpCallInitRoutine+0x43 0e 008ff498 76f0a99b ntdll_76ee0000!LdrpInitializeNode+0x10e 0f 008ff4bc 76f0a9b2 ntdll_76ee0000!LdrpInitializeGraphRecurse+0x5d 10 008ff4e4 76f10fb6 ntdll_76ee0000!LdrpInitializeGraphRecurse+0x74 11 008ff500 76f2029b ntdll_76ee0000!LdrpPrepareModuleForExecution+0x8f 12 008ff548 76f1cd94 ntdll_76ee0000!LdrpLoadDllInternal+0x124 13 008ff694 76f0a64f ntdll_76ee0000!LdrpLoadDll+0x93 14 008ff718 74359538 ntdll_76ee0000!LdrLoadDll+0x7f 15 008ff758 00c0310f KERNELBASE!LoadLibraryExW+0x138 16 008ff78c 00c03053 chrome!`anonymous namespace'::LoadModuleWithDirectory(class base::FilePath * module = 0x04f94ad8)+0x50 [c:\b\build\slave\win-asan\build\src\chrome\app\main_dll_loader_win.cc @ 62] 17 008ff880 00c02f00 chrome!MainDllLoader::Load(class base::FilePath * module = 0x008ff8e0)+0xd2 [c:\b\build\slave\win-asan\build\src\chrome\app\main_dll_loader_win.cc @ 110] 18 008ff914 00c0246a chrome!MainDllLoader::Launch(struct HINSTANCE__ * instance = 0x00bd0000, class base::TimeTicks exe_entry_point_ticks = class base::TimeTicks)+0x1b3 [c:\b\build\slave\win-asan\build\src\chrome\app\main_dll_loader_win.cc @ 166] 19 008ffa34 00c25f18 chrome!wWinMain(struct HINSTANCE__ * instance = 0x00bd0000, struct HINSTANCE__ * prev = 0x00000000, wchar_t * __formal = 0x04de0f2e "", int __formal = 0n5)+0x114 [c:\b\build\slave\win-asan\build\src\chrome\app\chrome_exe_main_win.cc @ 249] 1a (Inline) -------- chrome!invoke_main+0x1a [f:\dd\vctools\crt\vcstartup\src\startup\exe_common.inl @ 113] 1b 008ffa80 741c62c4 chrome!__scrt_common_main_seh(void)+0xf6 [f:\dd\vctools\crt\vcstartup\src\startup\exe_common.inl @ 253] 1c 008ffa94 76f40fd9 KERNEL32!BaseThreadInitThunk+0x24 1d 008ffadc 76f40fa4 ntdll_76ee0000!__RtlUserThreadStart+0x2f 1e 008ffaec 00000000 ntdll_76ee0000!_RtlUserThreadStart+0x1b
,
Dec 20 2016
Can you point me at what I need to set to opt in to SyzyAsan? (I think Seb is out until January, but I'm here one more day and might be my bug anyway.)
,
Dec 20 2016
Looks like this is probably de-synchronization between the SyzyASAN rtl registration, versus the handler initialization. For this to work, I think SyzyASAN will need to be able to get handler-initialized event.
,
Dec 20 2016
Re #6, I can never find the docs when I need them, but you need to go to key
"HKEY_CURRENT_USER\Software\Google\Update\ClientState\{4EA16AC7-FD5A-47C3-875B-DBF4A2008C20}\cohort" and add a new string value named "hint" with value "asan-optin".
,
Dec 20 2016
,
Dec 20 2016
Here's my guess at what's happening:
- chrome loads chrome_elf
- chrome_elf creates the pipe, gives it to a background thread that's going to CreateProcess the handler after DllMain.
- WinMain continues, getting to the chrome.dll load before that thread gets a slice
- syzyasan_rtl.dll loads, tries to connect. It doesn't fail because the pipe's already created, but it can't make progress because background thread will never get to run because the loader lock is still held.
0:000> ~
. 0 Id: 3b58.2454 Suspend: 1 Teb: 00582000 Unfrozen
1 Id: 3b58.241c Suspend: 1 Teb: 00585000 Unfrozen
# 2 Id: 3b58.2b74 Suspend: 1 Teb: 00588000 Unfrozen
0:000> ~0s
eax=00000000 ebx=00000000 ecx=00000000 edx=00000000 esi=00000000 edi=00000000
eip=77a3e96c esp=0075f260 ebp=0075f2bc iopl=0 nv up ei pl nz ac pe nc
cs=0023 ss=002b ds=002b es=002b fs=0053 gs=002b efl=00000216
ntdll!NtFsControlFile+0xc:
77a3e96c c22800 ret 28h
0:000> k
# ChildEBP RetAddr
00 0075f25c 76dd9703 ntdll!NtFsControlFile+0xc
01 0075f2bc 5d2a5ed5 KERNELBASE!GetIsImmersiveColorUsingHighContrast+0x19633
02 0075f48c 5d2a595b syzyasan_rtl!crashpad::SendToCrashHandlerServer+0x305 [e:\b\build\slave\syzygy_official\build\src\third_party\crashpad\files\util\win\registration_protocol_win.cc @ 81]
03 0075f4d0 5d276141 syzyasan_rtl!crashpad::CrashpadClient::UseHandler+0xab [e:\b\build\slave\syzygy_official\build\src\third_party\crashpad\files\client\crashpad_client_win.cc @ 409]
04 0075f514 5d2761c8 syzyasan_rtl!agent::asan::reporters::`anonymous namespace'::EnsureCrashpadConnected+0xd1 [e:\b\build\slave\syzygy_official\build\src\syzygy\agent\asan\reporters\crashpad_reporter.cc @ 64]
05 0075f51c 5d26aeaf syzyasan_rtl!agent::asan::reporters::CrashpadReporter::Create+0x8 [e:\b\build\slave\syzygy_official\build\src\syzygy\agent\asan\reporters\crashpad_reporter.cc @ 79]
06 0075f54c 5d26b398 syzyasan_rtl!agent::asan::`anonymous namespace'::CreateCrashReporterWithTypeHint+0x2f [e:\b\build\slave\syzygy_official\build\src\syzygy\agent\asan\runtime.cc @ 436]
07 0075f6ac 5d26726e syzyasan_rtl!agent::asan::AsanRuntime::SetUp+0x228 [e:\b\build\slave\syzygy_official\build\src\syzygy\agent\asan\runtime.cc @ 525]
08 0075f790 5d26262c syzyasan_rtl!agent::asan::SetUpAsanRuntime+0x14e [e:\b\build\slave\syzygy_official\build\src\syzygy\agent\asan\runtime_util.cc @ 215]
09 0075f7b4 5d2a8155 syzyasan_rtl!DllMain+0x6c [e:\b\build\slave\syzygy_official\build\src\syzygy\agent\asan\syzyasan_rtl.cc @ 191]
0a 0075f7f4 5d2a823b syzyasan_rtl!dllmain_dispatch+0x7c [f:\dd\vctools\crt\vcstartup\src\startup\dll_dllmain.cpp @ 200]
0b 0075f808 77a3e58e syzyasan_rtl!_DllMainCRTStartup+0x1c [f:\dd\vctools\crt\vcstartup\src\startup\dll_dllmain.cpp @ 258]
0c 0075f828 77a10e46 ntdll!LdrxCallInitRoutine+0x16
0d 0075f878 779faafc ntdll!LdrpCallInitRoutine+0x43
0e 0075f8f8 779fa99b ntdll!LdrpInitializeNode+0x10e
0f 0075f91c 779fa9b2 ntdll!LdrpInitializeGraphRecurse+0x5d
10 0075f944 77a00fb6 ntdll!LdrpInitializeGraphRecurse+0x74
11 0075f960 77a1029b ntdll!LdrpPrepareModuleForExecution+0x8f
12 0075f9a8 77a0cd94 ntdll!LdrpLoadDllInternal+0x124
13 0075faf4 779fa64f ntdll!LdrpLoadDll+0x93
14 0075fb78 76d89538 ntdll!LdrLoadDll+0x7f
15 0075fbbc 013d310f KERNELBASE!LoadLibraryExW+0x138
16 0075fbf0 013d3053 chrome!`anonymous namespace'::LoadModuleWithDirectory+0x50 [c:\b\build\slave\win-asan\build\src\chrome\app\main_dll_loader_win.cc @ 62]
17 0075fce4 013d2f00 chrome!MainDllLoader::Load+0xd2 [c:\b\build\slave\win-asan\build\src\chrome\app\main_dll_loader_win.cc @ 110]
18 0075fd78 013d246a chrome!MainDllLoader::Launch+0x1b3 [c:\b\build\slave\win-asan\build\src\chrome\app\main_dll_loader_win.cc @ 166]
19 0075fe98 013f5f88 chrome!wWinMain+0x114 [c:\b\build\slave\win-asan\build\src\chrome\app\chrome_exe_main_win.cc @ 249]
1a (Inline) -------- chrome!invoke_main+0x1a [f:\dd\vctools\crt\vcstartup\src\startup\exe_common.inl @ 113]
1b 0075fee4 752362c4 chrome!__scrt_common_main_seh+0xf6 [f:\dd\vctools\crt\vcstartup\src\startup\exe_common.inl @ 253]
1c 0075fef8 77a30fd9 KERNEL32!BaseThreadInitThunk+0x24
1d 0075ff40 77a30fa4 ntdll!__RtlUserThreadStart+0x2f
1e 0075ff50 00000000 ntdll!_RtlUserThreadStart+0x1b
0:000> ~1
1 Id: 3b58.241c Suspend: 1 Teb: 00585000 Unfrozen
Start: chrome_elf!crashpad::`anonymous namespace'::BackgroundHandlerStartThreadProc (610b69e0)
Priority: 0 Priority class: 32 Affinity: ffffffff
0:000> ~1s
eax=610b69e0 ebx=00000100 ecx=00000000 edx=00000000 esi=77adfb60 edi=00000000
eip=77a3e5fc esp=00b8f560 ebp=00b8f580 iopl=0 nv up ei pl nz ac pe nc
cs=0023 ss=002b ds=002b es=002b fs=0053 gs=002b efl=00000216
ntdll!NtWaitForSingleObject+0xc:
77a3e5fc c20c00 ret 0Ch
0:001> k
# ChildEBP RetAddr
00 00b8f55c 77a0d1a1 ntdll!NtWaitForSingleObject+0xc
01 00b8f580 77a10fc6 ntdll!LdrpDrainWorkQueue+0xbd
02 00b8f668 77a37636 ntdll!LdrpInitializeThread+0x8d
03 00b8f6bc 77a37590 ntdll!_LdrpInitialize+0x6a
04 00b8f6c4 00000000 ntdll!LdrInitializeThunk+0x10
,
Dec 20 2016
This makes sense to me. It's racy, which explains why I can't repro on my Win7 box here. The question is what to do about it for the holidays. While SyzyASAN's registration is redundant, I don't think we have daylight left in the year to remove it and re-route the exceptions.
,
Dec 20 2016
Is SyzyASAN a build time flag or only a build step?
If we have a #define, I think the easiest thing is to add
#if SYZYASAN
GetProcAddress("BlockUntilHandlerStartedImpl")();
#endif
to WinMain().
If that's not easy, then we could either revert the async startup https://codereview.chromium.org/2475863004/ (It should likely revert cleanly) or turn the asan percentage to 0 until January when we can make a better fix.
I don't believe this affects non-SyzyASAN startup (i.e. renderers) because the connection is not done during a DllMain, so the handler launch thread will eventually be able to make progress.
,
Dec 20 2016
SyzyASAN is both a flag and a build step. Blocking in WinMain should indeed do the trick for now. We're in the middle of refactoring the RTL to not connect to the crash handler in DllMain (in order to add support for the installer), but that will take a little longer to put in place.
,
Dec 20 2016
Totally untested: https://codereview.chromium.org/2591043002
,
Dec 20 2016
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/ddce5b16a68a6244dc5f7df0151db34f2d0bc6e6 commit ddce5b16a68a6244dc5f7df0151db34f2d0bc6e6 Author: scottmg <scottmg@chromium.org> Date: Tue Dec 20 23:20:33 2016 SyzyASAN: Block for crash handler startup as temporary workaround for startup hang TBR=grt@chromium.org BUG= 675710 Review-Url: https://codereview.chromium.org/2591043002 Cr-Commit-Position: refs/heads/master@{#439920} [modify] https://crrev.com/ddce5b16a68a6244dc5f7df0151db34f2d0bc6e6/chrome/app/chrome_exe_main_win.cc
,
Jan 11 2017
Do we need to do something else to address this or should we just stick with this fix?
,
Jan 24 2017
It's not P1 anymore (and it might be a WontFix if we're happy with the workaround)
,
Aug 10 2017
The workaround seems sufficient. |
|||||||
►
Sign in to add a comment |
|||||||
Comment 1 by robliao@chromium.org
, Dec 19 2016Labels: Hotlist-SyzyASAN