Closed
Bug 1121028
Opened 11 years ago
Closed 10 years ago
Intermittent test_browserElement_inproc_OpenMixedProcess.html | application crashed [@ base::win::PEImage::GetProcAddress(char const *)]
Categories
(Core :: Security: Process Sandboxing, defect)
Tracking
()
RESOLVED
WORKSFORME
People
(Reporter: RyanVM, Unassigned)
Details
(Keywords: crash, intermittent-failure)
02:47:04 INFO - 1355 INFO TEST-START | dom/browser-element/mochitest/test_browserElement_inproc_OpenMixedProcess.html
02:47:04 INFO - -*-*- UserCustomizations (parent): document created: http://mochi.test:8888/tests/dom/browser-element/mochitest/test_browserElement_inproc_OpenMixedProcess.html
02:47:04 INFO - -*-*- UserCustomizations (parent): _injectInWindow
02:47:04 INFO - -*-*- UserCustomizations (parent): principal status: 0
02:52:34 INFO - 1356 ERROR TEST-UNEXPECTED-TIMEOUT | dom/browser-element/mochitest/test_browserElement_inproc_OpenMixedProcess.html | application timed out after 330 seconds with no output
02:52:34 INFO - TEST-INFO | screenshot: exit status 0
02:52:34 INFO - Error 5 in VirtualAllocEx
02:52:34 INFO - TEST-INFO | crashinject: exit status 1
02:52:34 INFO - Can't trigger Breakpad, just killing process
02:52:34 INFO - Failed to kill process 1732: [Error 5] Access is denied
02:52:35 INFO - TEST-INFO | Main app process: exit status 1
02:52:35 INFO - 1357 ERROR TEST-UNEXPECTED-FAIL | dom/browser-element/mochitest/test_browserElement_inproc_OpenMixedProcess.html | application terminated with exit code 1
02:52:35 INFO - runtests.py | Application ran for: 0:13:19.852000
02:52:35 INFO - zombiecheck | Reading PID log: c:\users\cltbld~1.t-w\appdata\local\temp\tmpva74o4pidlog
02:52:35 INFO - ==> process 1732 launched child process 2636 ("C:\slave\test\build\application\firefox\plugin-container.exe" --channel=1732.3207170.1574859058 "c:\users\cltbld~1.t-w\appdata\local\temp\tmpcoubx7.mozrunner\plugins\nptest.dll" -greomni "C:\slave\test\build\application\firefox\omni.ja" -appomni "C:\slave\test\build\application\firefox\browser\omni.ja" -appdir "C:\slave\test\build\application\firefox\browser" - 1732 "\\.\pipe\gecko-crash-server-pipe.1732" plugin)
02:52:35 INFO - ==> process 1732 launched child process 884 ("C:\slave\test\build\application\firefox\plugin-container.exe" --channel=1732.3207170.318319836 "c:\users\cltbld~1.t-w\appdata\local\temp\tmpcoubx7.mozrunner\plugins\nptest.dll" -greomni "C:\slave\test\build\application\firefox\omni.ja" -appomni "C:\slave\test\build\application\firefox\browser\omni.ja" -appdir "C:\slave\test\build\application\firefox\browser" - 1732 "\\.\pipe\gecko-crash-server-pipe.1732" plugin)
02:52:35 INFO - mozcrash Downloading symbols from: https://ftp-ssl.mozilla.org/pub/mozilla.org/firefox/tinderbox-builds/fx-team-win64/1421139994/firefox-38.0a1.en-US.win64-x86_64.crashreporter-symbols.zip
02:52:40 INFO - mozcrash Saved minidump as C:\slave\test\build\blobber_upload_dir\80a9881c-ba49-4a6c-a40c-7f986993dcce.dmp
02:52:40 INFO - mozcrash Saved app info as C:\slave\test\build\blobber_upload_dir\80a9881c-ba49-4a6c-a40c-7f986993dcce.extra
02:52:40 WARNING - PROCESS-CRASH | dom/browser-element/mochitest/test_browserElement_inproc_OpenMixedProcess.html | application crashed [@ base::win::PEImage::GetProcAddress(char const *)]
02:52:40 INFO - Crash dump filename: c:\users\cltbld~1.t-w\appdata\local\temp\tmpcoubx7.mozrunner\minidumps\80a9881c-ba49-4a6c-a40c-7f986993dcce.dmp
02:52:40 INFO - Operating system: Windows NT
02:52:40 INFO - 6.2.9200
02:52:40 INFO - CPU: amd64
02:52:40 INFO - family 6 model 30 stepping 5
02:52:40 INFO - 8 CPUs
02:52:40 INFO - Crash reason: EXCEPTION_ACCESS_VIOLATION_READ
02:52:40 INFO - Crash address: 0x7f7439d1ea4
02:52:40 INFO - Thread 2 (crashed)
02:52:40 INFO - 0 sandboxbroker.dll!base::win::PEImage::GetProcAddress(char const *) [pe_image.cc:c9ff49636eef : 173 + 0x0]
02:52:40 INFO - rbx = 0x000000266e7de9f0 r12 = 0x0000000000000000
02:52:40 INFO - r13 = 0x000007f743960000 r14 = 0x000007f743960000
02:52:40 INFO - r15 = 0x000000266e7ded60 rip = 0x000007f9b31168d2
02:52:40 INFO - rsp = 0x000000266e7de9a0 rbp = 0x000000266e7deb10
02:52:40 INFO - Found by: given as instruction pointer in context
02:52:40 INFO - 1 sandboxbroker.dll!sandbox::ServiceResolverThunk::ResolveTarget(void const *,char const *,void * *) [service_resolver.cc:c9ff49636eef : 32 + 0x4]
02:52:40 INFO - rbx = 0x000000266e7de9f0 r12 = 0x0000000000000000
02:52:40 INFO - r13 = 0x000007f743960000 r14 = 0x000007f743960000
02:52:40 INFO - r15 = 0x000000266e7ded60 rip = 0x000007f9b312d731
02:52:40 INFO - rsp = 0x000000266e7de9d0 rbp = 0x000000266e7deb10
02:52:40 INFO - Found by: call frame info
02:52:40 INFO - 2 sandboxbroker.dll!sandbox::InterceptionManager::PatchClientFunctions(sandbox::DllInterceptionData *,unsigned __int64,sandbox::DllInterceptionData *) [interception.cc:c9ff49636eef : 508 + 0x1e]
02:52:40 INFO - rbx = 0x000000266e7de9f0 r12 = 0x0000000000000000
02:52:40 INFO - r13 = 0x000007f743960000 r14 = 0x000007f743960000
02:52:40 INFO - r15 = 0x000000266e7ded60 rip = 0x000007f9b312201b
02:52:40 INFO - rsp = 0x000000266e7dea10 rbp = 0x000000266e7deb10
02:52:40 INFO - Found by: call frame info
02:52:40 INFO - 3 sandboxbroker.dll!sandbox::InterceptionManager::PatchNtdll(bool) [interception.cc:c9ff49636eef : 418 + 0x15]
02:52:40 INFO - rbx = 0x000000266e7de9f0 r12 = 0x0000000000000000
02:52:40 INFO - r13 = 0x000007f743960000 r14 = 0x000007f743960000
02:52:40 INFO - r15 = 0x000000266e7ded60 rip = 0x000007f9b3122301
02:52:40 INFO - rsp = 0x000000266e7dec10 rbp = 0x000000266e7deb10
02:52:40 INFO - Found by: call frame info
02:52:40 INFO - 4 sandboxbroker.dll!sandbox::InterceptionManager::InitializeInterceptions() [interception.cc:c9ff49636eef : 133 + 0xa]
02:52:40 INFO - rbx = 0x000000266e7de9f0 r12 = 0x0000000000000000
02:52:40 INFO - r13 = 0x000007f743960000 r14 = 0x000007f743960000
02:52:40 INFO - r15 = 0x000000266e7ded60 rip = 0x000007f9b3121d22
02:52:40 INFO - rsp = 0x000000266e7dee00 rbp = 0x000000266e7deb10
02:52:40 INFO - Found by: call frame info
02:52:40 INFO - 5 sandboxbroker.dll!sandbox::PolicyBase::SetupAllInterceptions(sandbox::TargetProcess *) [sandbox_policy_base.cc:c9ff49636eef : 727 + 0x9]
02:52:40 INFO - rbx = 0x000000266e7de9f0 r12 = 0x0000000000000000
02:52:40 INFO - r13 = 0x000007f743960000 r14 = 0x000007f743960000
02:52:40 INFO - r15 = 0x000000266e7ded60 rip = 0x000007f9b312d5be
02:52:40 INFO - rsp = 0x000000266e7dee30 rbp = 0x000000266e7deb10
02:52:40 INFO - Found by: call frame info
02:52:40 INFO - 6 sandboxbroker.dll!sandbox::PolicyBase::AddTarget(sandbox::TargetProcess *) [sandbox_policy_base.cc:c9ff49636eef : 586 + 0xa]
02:52:40 INFO - rbx = 0x000000266e7de9f0 r12 = 0x0000000000000000
02:52:40 INFO - r13 = 0x000007f743960000 r14 = 0x000007f743960000
02:52:40 INFO - r15 = 0x000000266e7ded60 rip = 0x000007f9b312ca20
02:52:40 INFO - rsp = 0x000000266e7dee80 rbp = 0x000000266e7deb10
02:52:40 INFO - Found by: call frame info
02:52:40 INFO - 7 sandboxbroker.dll!sandbox::BrokerServicesBase::SpawnTarget(wchar_t const *,wchar_t const *,sandbox::TargetPolicy *,_PROCESS_INFORMATION *) [broker_services.cc:c9ff49636eef : 477 + 0xa]
02:52:40 INFO - rbx = 0x000000266e7de9f0 r12 = 0x0000000000000000
02:52:40 INFO - r13 = 0x000007f743960000 r14 = 0x000007f743960000
02:52:40 INFO - r15 = 0x000000266e7ded60 rip = 0x000007f9b311a4fd
02:52:40 INFO - rsp = 0x000000266e7deec0 rbp = 0x000000266e7deb10
02:52:40 INFO - Found by: call frame info
02:52:40 INFO - 8 sandboxbroker.dll!mozilla::SandboxBroker::LaunchApp(wchar_t const *,wchar_t const *,bool,void * *) [sandboxBroker.cpp:c9ff49636eef : 57 + 0x20]
02:52:40 INFO - rbx = 0x000000266e7de9f0 r12 = 0x0000000000000000
02:52:40 INFO - r13 = 0x000007f743960000 r14 = 0x000007f743960000
02:52:40 INFO - r15 = 0x000000266e7ded60 rip = 0x000007f9b31112d9
02:52:40 INFO - rsp = 0x000000266e7df080 rbp = 0x000000266e7deb10
02:52:40 INFO - Found by: call frame info
02:52:40 INFO - 9 xul.dll!mozilla::ipc::GeckoChildProcessHost::PerformAsyncLaunchInternal(std::vector<std::basic_string<char,std::char_traits<char>,std::allocator<char> >,std::allocator<std::basic_string<char,std::char_traits<char>,std::allocator<char> > > > &,base::ProcessArchitecture) [GeckoChildProcessHost.cpp:c9ff49636eef : 880 + 0x53]
02:52:40 INFO - rbx = 0x000000266e7de9f0 r12 = 0x0000000000000000
02:52:40 INFO - r13 = 0x000007f743960000 r14 = 0x000007f743960000
02:52:40 INFO - r15 = 0x000000266e7ded60 rip = 0x000007f9adeaf6da
02:52:40 INFO - rsp = 0x000000266e7df0e0 rbp = 0x000000266e7deb10
02:52:40 INFO - Found by: call frame info
02:52:40 INFO - 10 xul.dll!mozilla::ipc::GeckoChildProcessHost::PerformAsyncLaunch(std::vector<std::basic_string<char,std::char_traits<char>,std::allocator<char> >,std::allocator<std::basic_string<char,std::char_traits<char>,std::allocator<char> > > >,base::ProcessArchitecture) [GeckoChildProcessHost.cpp:c9ff49636eef : 448 + 0xd]
02:52:40 INFO - rbx = 0x000000266e7de9f0 r12 = 0x0000000000000000
02:52:40 INFO - r13 = 0x000007f743960000 r14 = 0x000007f743960000
02:52:40 INFO - r15 = 0x000000266e7ded60 rip = 0x000007f9adeaee94
02:52:40 INFO - rsp = 0x000000266e7df500 rbp = 0x000000266e7deb10
02:52:40 INFO - Found by: call frame info
| Comment hidden (Legacy TBPL/Treeherder Robot) |
| Comment hidden (Legacy TBPL/Treeherder Robot) |
Updated•11 years ago
|
Component: IPC → Security: Process Sandboxing
Judging by the nearby disassembly it must be trying to deref |export_entry|:
000007fa`0ef8401e 8b11 mov edx,dword ptr [rcx] ds:000007f7`034243a4=????????
0x7f..etc definitely looks like an address inside a code module. But there's nothing there:
0:002> !address @rcx
Usage: Free
Base Address: 000007f7`03401000
End Address: 000007f7`f51be000
Region Size: 00000000`f1dbd000
State: 00010000 MEM_FREE
Protect: 00000001 PAGE_NOACCESS
Type: <info not present at the target>
Did that module get unloaded? At first glance it seems like we have a LoadLibrary ref on it.
Maybe these are related but it's not clear how:
> 02:52:34 INFO - Error 5 in VirtualAllocEx
> 02:52:34 INFO - Failed to kill process 1732: [Error 5] Access is denied
Comment 4•11 years ago
|
||
(In reply to David Major [:dmajor] (UTC+13) from comment #3)
> Judging by the nearby disassembly it must be trying to deref |export_entry|:
> 000007fa`0ef8401e 8b11 mov edx,dword ptr [rcx]
> ds:000007f7`034243a4=????????
I'm probably missing something, but I don't see this instruction in GetProcAddress.
> 0x7f..etc definitely looks like an address inside a code module. But there's
> nothing there:
>
> 0:002> !address @rcx
> Usage: Free
> Base Address: 000007f7`03401000
> End Address: 000007f7`f51be000
> Region Size: 00000000`f1dbd000
> State: 00010000 MEM_FREE
> Protect: 00000001 PAGE_NOACCESS
> Type: <info not present at the target>
>
> Did that module get unloaded? At first glance it seems like we have a
> LoadLibrary ref on it.
>
> Maybe these are related but it's not clear how:
> > 02:52:34 INFO - Error 5 in VirtualAllocEx
> > 02:52:34 INFO - Failed to kill process 1732: [Error 5] Access is denied
I'm really not sure about a lot of this.
It is right in the middle of where the broker process is writing to the memory of the child process to setup the sandbox.
I was looking at the .dmp file from comment 1, at [1]. That build doesn't have full-symbols but I can guess with pretty good confidence.
000007f9`b31168b7 c3 ret
// I assume the above is the end of the previous function, so GetProcAddress starts here:
000007f9`b31168b8 48895c2408 mov qword ptr [rsp+8],rbx
000007f9`b31168bd 57 push rdi
000007f9`b31168be 4883ec20 sub rsp,20h
000007f9`b31168c2 488bd9 mov rbx,rcx
// I assume the |call| below is to GetExportEntry, followed by the usual retval checks
000007f9`b31168c5 e8b6feffff call sandboxbroker+0x6780 (000007f9`b3116780)
000007f9`b31168ca 488bc8 mov rcx,rax
000007f9`b31168cd 4885c0 test rax,rax
000007f9`b31168d0 7449 je sandboxbroker+0x691b (000007f9`b311691b)
// The crash was on this line:
000007f9`b31168d2 8b11 mov edx,dword ptr [rcx]
[1] http://mozilla-releng-blobs.s3.amazonaws.com/blobs/fx-team/sha512/92c4228d3f4a0bab78562e228cd58ff7cfdfe3da89566a99b816536ebcc0107d1b5bbe2f5cd8fa67fa31296b6612be336b545473ad1486ffec0f5b18874205be
Comment 6•11 years ago
|
||
(In reply to David Major [:dmajor] (UTC+13) from comment #5)
> I was looking at the .dmp file from comment 1, at [1]. That build doesn't
> have full-symbols but I can guess with pretty good confidence.
Ah right yeah, I was looking at a Nightly build and it looks like there must be some optimizations that caused the assembly code to be different.
I am pretty new to assembly debugging. :-)
I pushed the inbound version from comment 2 to try and enabled full symbols:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=90c88a33add7
You were of course correct that it looks like the deref that is blowing up.
I think that is supposed to be a pointer to a function within plugin-container.exe
While this is loaded the address seems to be after the end of plugin-container, don't know if it could have been to a different version.
It appears several times in the unloaded modules as well, when I debug a working start-up.
Looks like this is turning up on crash-stats as well:
https://crash-stats.mozilla.com/signature/?signature=base%3A%3Awin%3A%3APEImage%3A%3AGetProcAddress%28char+const*%29&_columns=date&_columns=product&_columns=version&_columns=build_id&_columns=platform&_columns=reason&_columns=address&page=1
Interesting that's it's only x64. (Unless x86 builds just have a different signature)
Comment 8•11 years ago
|
||
(In reply to David Major [:dmajor] (UTC+13) from comment #7)
> Interesting that's it's only x64. (Unless x86 builds just have a different
> signature)
I think that the signature would be the same (or at least very similar) if it were failing at this point on 32-bit.
I noticed the comment at the top of the page, which is ... er ... a little worrying:
https://dxr.mozilla.org/mozilla-central/source/security/sandbox/chromium/base/win/pe_image.cc#14
The warning has been removed in the latest Chromium code, but just to remove warning spew not because the concerns have been addressed.
The other thing that is worrying is that I believe that this part of the start-up on Firefox is using slightly different code to Chrome.
My understanding is that to do this patching, Chrome relies on the fact that they use the same binary for their child and broker processes.
As ours are different (again as I understand it) it uses the code in the SANDBOX_EXPORTS #ifs.
It's on my list to research and understand this part of the sandbox start-up better.
Clearly I need to do that sooner rather than later. :-)
| Reporter | ||
Comment 9•11 years ago
|
||
Also worth noting at this point that there haven't been any further instances since those first two?
| Comment hidden (Legacy TBPL/Treeherder Robot) |
| Comment hidden (Legacy TBPL/Treeherder Robot) |
| Comment hidden (Legacy TBPL/Treeherder Robot) |
| Comment hidden (Legacy TBPL/Treeherder Robot) |
| Comment hidden (Legacy TBPL/Treeherder Robot) |
| Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment 16•10 years ago
|
||
Inactive; closing (see bug 1180138).
Status: NEW → RESOLVED
Closed: 10 years ago
Resolution: --- → WORKSFORME
You need to log in
before you can comment on or make changes to this bug.
Description
•