Skip to content
GitLab
Open
Issue created by Derek Bruening@derekbrueningContributor

self-interpretation due to os_take_over_all_unknown_threads() on an already-caught early thread

From bruen...@google.com on May 07, 2014 10:22:48

This is the DR bug causing https://code.google.com/p/drmemory/issues/detail?id=1541 Analyzing the ldmp there: http://build.chromium.org/p/chromium.fyi/builders/Windows%20Browser%20%28DrMemory%20full%29%20%282%29/builds/3534/steps/memory%20test%3A%20browser_tests/logs/stdio UsbApiTest.ZeroLengthTransfer

[ RUN      ] UsbApiTest.ZeroLengthTransfer
[284:816:0506/111048:ERROR:gpu_info_collector_win.cc(103)] Can't retrieve a valid WinSAT assessment.
[1344:1948:0506/111203:ERROR:renderer_main.cc(227)] Running without renderer sandbox
~~360~~ 
~~360~~ Error `#1`: UNINITIALIZED READ: reading register edi
~~360~~ # 0 dynamorio.dll!intercept_ldr_init      [e:\b\build\slave\win-builder\drmemory\dynamorio\core\win32\callback.c:3202]
~~360~~ # 1 dynamorio.dll!interception_code_array
~~360~~ Note: @0:00:09.421 in thread 360
~~360~~ Note: instruction: mov    $0x00000000 -> (%edi)
~~360~~ 
~~360~~ Error `#2`: UNINITIALIZED READ: reading register edi
~~360~~ # 0 dynamorio.dll!asynch_take_over [e:\b\build\slave\win-builder\drmemory\dynamorio\core\win32\callback.c:2833]
~~360~~ Note: @0:00:09.422 in thread 360
~~360~~ Note: instruction: cmp    (%edi) $0x00
~~360~~ 
~~360~~ Error `#3`: UNADDRESSABLE ACCESS: reading 0x00000246-0x0000024a 4 byte(s)
~~360~~ # 0 dynamorio.dll!dispatch_enter_fcache [e:\b\build\slave\win-builder\drmemory\dynamorio\core\dispatch.c:488]
~~360~~ Note: @0:00:09.435 in thread 360
~~360~~ Note: instruction: pop    %esp (%esp) -> %ebp %esp
~~360~~ Note: memory dump created at C:\Users\chrome-bot\AppData\LocalLow\drmemory.logs\testcase.2280_4.logs\dynamorio\browser_tests.exe.2292.00000000.ldmp

0:000> kn 30
 # ChildEBP RetAddr  
00 2199e504 679b1eb9 dynamorio!os_dump_core_live_dump+0x26a [e:\b\build\slave\win-builder\drmemory\dynamorio\core\win32\os.c @ 7064]
01 2199e520 679a3a62 dynamorio!os_dump_core_live+0x39 [e:\b\build\slave\win-builder\drmemory\dynamorio\core\win32\os.c @ 7312]
02 2199e534 738479a6 dynamorio!dr_create_memory_dump+0x22 [e:\b\build\slave\win-builder\drmemory\dynamorio\core\x86\instrument.c @ 2268]
03 2199e924 73849a39 drmemorylib!report_core_dump+0x216 [e:\b\build\slave\win-builder\drmemory\drmemory\report.c @ 2620]
04 2199e9b4 7384a0f3 drmemorylib!report_error+0x369 [e:\b\build\slave\win-builder\drmemory\drmemory\report.c @ 2804]
05 2199eb04 73809c1f drmemorylib!report_unaddressable_access+0x103 [e:\b\build\slave\win-builder\drmemory\drmemory\report.c @ 3025]
06 2199eb74 7380a3c0 drmemorylib!handle_mem_ref_internal+0x61f [e:\b\build\slave\win-builder\drmemory\drmemory\readwrite.c @ 4882]
07 2199ebac 7380b39a drmemorylib!check_mem_opnd+0x760 [e:\b\build\slave\win-builder\drmemory\drmemory\readwrite.c @ 5054]
08 2199ed44 7380b9e7 drmemorylib!slow_path_with_mc+0x63a [e:\b\build\slave\win-builder\drmemory\drmemory\readwrite.c @ 3486]
09 2199eeb0 21f5003a drmemorylib!slow_path+0x47 [e:\b\build\slave\win-builder\drmemory\drmemory\readwrite.c @ 3706]
WARNING: Frame IP not in any known module. Following frames may be wrong.
0a 2199eee4 6795f1cf 0x21f5003a
0b 2199eef4 679609db dynamorio!heap_free+0x3f [e:\b\build\slave\win-builder\drmemory\dynamorio\core\heap.c @ 3710]
0c 2199ef18 67994adf dynamorio!instrlist_clear_and_destroy+0x1b [e:\b\build\slave\win-builder\drmemory\dynamorio\core\instrlist.c @ 106]
0d 2199efa0 00000000 dynamorio!build_basic_block_fragment+0x3ff [e:\b\build\slave\win-builder\drmemory\dynamorio\core\x86\interp.c @ 4703]

0:000> kn
  **\* Stack trace for last set context - .thread/.cxr resets it
 # ChildEBP RetAddr  
00 00000246 00000000 dynamorio!dispatch_enter_fcache+0x1f4 [e:\b\build\slave\win-builder\drmemory\dynamorio\core\dispatch.c @ 488]
0:000> r
Last set context:
eax=2339e601 ebx=00000000 ecx=2339e6cc edx=2339e6cc esi=214d6d40 edi=0531f5e0
eip=67953864 esp=00000246 ebp=00000246 iopl=0         nv up ei pl nz na po nc
cs=0023  ss=002b  ds=0000  es=0000  fs=0000  gs=0000             efl=00000202
dynamorio!dispatch_enter_fcache+0x1f4:
67953864 5d              pop     ebp

So enter_fcache returned, and ebp is messed up which messes up esp: enter_fcache(dcontext, fcache_enter, FCACHE_ENTRY_PC(targetf)); ASSERT_NOT_REACHED();

CommandLine:  '"E:\b\build\slave\windows-browser-drm-full-2\build\src\build\Release\browser_tests.exe" --type=renderer --dom-automation --enable-logging=stderr --log-level=0 --no-sandbox --test-type=browser --enable-deferred-image-decoding --lang=en-US --force-fieldtrials=Prerender/PrerenderMulti/UMA-New-Install-Uniformity-Trial/Experiment/UMA-Session-Randomized-Uniformity-Trial-5-Percent/default/UMA-Uniformity-Trial-1-Percent/group_63/UMA-Uniformity-Trial-10-Percent/group_09/UMA-Uniformity-Trial-100-Percent/group_01/UMA-Uniformity-Trial-20-Percent/group_04/UMA-Uniformity-Trial-5-Percent/group_15/UMA-Uniformity-Trial-50-Percent/default/ --noerrdialogs --user-data-dir="C:\Users\CHROME~2\AppData\Local\Temp\scoped_dir856_6693\d856_10514" --extension-process --enable-threaded-compositing --enable-delegated-renderer --enable-impl-side-painting --channel="284.2.432510063\130175343" /prefetch:673131151'

Only 2 threads. Other thread is here -- but wrong syms!:

Here are the real symbols, but they seem suspect as this is not FtpBrowserTest!

$ bin/symquery.exe -e ../full-build-win32/browser_tests.exe -f -a 0x00dd84cc 0x00ddd932 0x00dda19f 0x00dde7a2 0x000684e2 0x019a8ac7
std::find_if<std::_Vector_iterator<std::_Vector_val<std::_Simple_types<testing::TestCase *> > >,testing::internal::TestCaseNameIs>+0x5c
e:\b\depot_tools\win_toolchain\vs2013_files\vc\include\algorithm:56+0x35
testing::internal::UnitTestImpl::GetTestCase+0xa2
e:\b\build\slave\drm-cr\build\src\testing\gtest\src\gtest.cc:3930+0x6c
testing::internal::UnitTestImpl::AddTestInfo+0x10f
e:\b\build\slave\drm-cr\build\src\testing\gtest\src\gtest-internal-inl.h:668+0x2b
testing::internal::MakeAndRegisterTestInfo+0x182
e:\b\build\slave\drm-cr\build\src\testing\gtest\src\gtest.cc:2140+0x0
`dynamic initializer for 'FtpBrowserTest_DirectoryListing_Test::test_info_''+0x42
e:\b\build\slave\drm-cr\build\src\chrome\browser\net\ftp_browsertest.cc:23+0x42
__tmainCRTStartup+0x9e
f:\dd\vctools\crt\crtw32\dllstuff\crtexe.c:550+0xf

the thread start addresses: bad one is in chrome_elf.dll (other is in browser_tests.exe): so not a nudge thread

unable to set thread start address to 681F53B0

0:000> ? 681F53B0-chrome_elf
Evaluate expression: 21424 = 000053b0
&#37; ~/drmemory/releases/DrMemory-Windows-1.6.1-2/bin/symquery.exe -e full-build-win32/chrome_elf.dll -f -a 0x53b0
google_breakpad::ExceptionHandler::ExceptionHandlerThreadMain+0x0
e:\b\build\slave\drm-cr\build\src\breakpad\src\client\windows\handler\exception_handler.cc:383+0x0

why are there so few threads? I thought renderers always had at least a dozen threads (xref issue #130 (closed) data). this must be early on, with the process just starting up? also in that issue #130 (closed) data: 2nd thread is in base.dll, not chrome_elf.

In a local run of UsbApiTest.ZeroLengthTransfer there are 2 renderer processes: one has --extension-process and the other doesn't. The ldmp is from the extension thread. For that one locally:

&#37; grep ^Thread DrMemory-browser_tests.exe.5980.000/global.5980.log 
Thread `#2` @0:00:14.774 #bbs=35507 start=0x0223ffc0  browser_tests.exe!sandbox::BrokerServicesBase::TargetEventsThread+0x0
Thread `#3` @0:00:15.652 #bbs=41763 start=0x71b3d990  base.dll!base::`anonymous namespace'::ThreadFunc+0x0
Thread`#4`@0:00:15.858 #bbs=42882 start=0x77b72e65  ntdll.dll!TppWaiterpThread+0x0
Thread`#5`@0:00:15.900 #bbs=43134 start=0x77b73e85  ntdll.dll!TppWorkerThread+0x0
Thread`#6`@0:00:21.596 #bbs=64926 start=0x6ef0bfb4  MSVCR120.dll!_threadstartex+0x0
Thread`#7`@0:00:21.605 #bbs=64975 start=0x6ef0bfb4  MSVCR120.dll!_threadstartex+0x0
Thread`#8`@0:00:21.611 #bbs=65024 start=0x6ef0bfb4  MSVCR120.dll!_threadstartex+0x0
Thread`#9`@0:00:21.617 #bbs=65073 start=0x6ef0bfb4  MSVCR120.dll!_threadstartex+0x0
Thread`#10`@0:00:21.623 #bbs=65101 start=0x6ef0bfb4  MSVCR120.dll!_threadstartex+0x0
Thread`#11`@0:00:22.397 #bbs=67684 start=0x71b3d990  base.dll!base::`anonymous namespace'::ThreadFunc+0x0
Thread `#12` @0:00:36.785 #bbs=154239 start=0x71b3d990  base.dll!base::`anonymous namespace'::ThreadFunc+0x0
Thread`#13` @0:01:01.742 #bbs=318511 start=0x111de189 

0:000> dt -b dynamorio!stats
&#37; grep -E 'single_stat_t|value' ~/x
   +0x2f4 num_threads_pair : _single_stat_t
      +0x034 value            : 0n2
   +0x32c peak_num_threads_pair : _single_stat_t
      +0x034 value            : 0n2
   +0x364 num_threads_created_pair : _single_stat_t
      +0x034 value            : 0n2
   +0x39c num_callbacks_pair : _single_stat_t
      +0x034 value            : 0n0
   +0x3d4 num_APCs_pair    : _single_stat_t
      +0x034 value            : 0n0
   +0x40c num_exceptions_pair : _single_stat_t
      +0x034 value            : 0n6
   +0x444 pre_syscall_pair : _single_stat_t
      +0x034 value            : 0n118
   ...

Original issue: http://code.google.com/p/dynamorio/issues/detail?id=1443