search

DynamoRIO / drmemory

Memory Debugger for Windows, Linux, Mac, and Android
Other
2.44k stars 262 forks source link

pattern mode has bogus callstack frame in ToolsSanityTest.AccessesToNewMemory #1271

Closed derekbruening closed 9 years ago

derekbruening commented 9 years ago

From bruen...@google.com on June 14, 2013 12:32:07

RUNNING_ON_VALGRIND=1 ~/drmemory/git/build_x86_dbg/bin/drmemory.exe -unaddr_only -suppress 'e:\derek\chromium\src\tools\valgrind\drmemory\suppressions.txt' -batch -dr d:/derek/dr/git/exports -- ./base_unittests.exe --gtest_filter=ToolsSanityTest.AccessesToNewMemory

[ RUN ] ToolsSanityTest.AccessesToNewMemory Dr.M Dr.M Error #1: UNADDRESSABLE ACCESS: reading 0x043863ab-0x043863ac 1 byte(s) Dr.M # 0 base::anonymous namespace'::ReadValueOutOfArrayBoundsRight [e:\derek\chromium\src\base\tools_sanity_unittest.cc:52] \~~Dr.M~~ # 1 LazyInstanceTest_ConstructorThreadSafety_Test::TestBody [e:\derek\chromium\src\base\lazy_instance_unittest.cc:98] \~~Dr.M~~ # 2 base::anonymous namespace'::MakeSomeErrors [e:\derek\chromium\src\base\tools_sanity_unittest.cc:71] Dr.M # 3 base::ToolsSanityTest_AccessesToNewMemory_Test::TestBody [e:\derek\chromium\src\base\tools_sanity_unittest.cc:113]

Frame #1 makes no sense.

doesn't happen w/ "-no_check_uninitialized -no_count_leaks", nor with "-light -no_replace_malloc".

Error #1: UNADDRESSABLE ACCESS: reading 0x042a2e5b-0x042a2e5c 1 byte(s)

0 base::`anonymous namespace'::ReadValueOutOfArrayBoundsRight [e:\derek\chromium\src\base\tools_sanity_unittest.cc:52] (0x0091d2f8 \<base_unittests.exe+0x51d2f8>) modid:2

# 1 LazyInstanceTest_ConstructorThreadSafety_Test::TestBody [e:\derek\chromium\src\base\lazy_instance_unittest.cc:98] (0x00640001 \<base_unittests.exe+0x240001>) modid:2 # 2 base::`anonymous namespace'::MakeSomeErrors [e:\derek\chromium\src\base\tools_sanity_unittest.cc:71](0x0091d46e <base_unittests.exe+0x51d46e) modid:2

3 base::ToolsSanityTest_AccessesToNewMemory_Test::TestBody [e:\derek\chromium\src\base\tools_sanity_unittest.cc:113](0x0091d537 <base_unittests.exe+0x51d537) modid:2

4 testing::internal::HandleExceptionsInMethodIfSupportedtesting::Test,void [e:\derek\chromium\src\testing\gtest\src\gtest.cc:2051](0x009ef805 <base_unittests.exe+0x5ef805) modid:2

5 testing::Test::Run [e:\derek\chromium\src\testing\gtest\src\gtest.cc:2068](0x009e2d47 <base_unittests.exe+0x5e2d47) modid:2

6 testing::TestInfo::Run [e:\derek\chromium\src\testing\gtest\src\gtest.cc:2244](0x009e34dd <base_unittests.exe+0x5e34dd) modid:2

7 testing::TestCase::Run [e:\derek\chromium\src\testing\gtest\src\gtest.cc:2351](0x009e3aef <base_unittests.exe+0x5e3aef) modid:2

8 testing::internal::UnitTestImpl::RunAllTests [e:\derek\chromium\src\testing\gtest\src\gtest.cc:4177](0x009e8bde <base_unittests.exe+0x5e8bde) modid:2

9 testing::internal::HandleExceptionsInMethodIfSupportedtesting::internal::UnitTestImpl,bool [e:\derek\chromium\src\testing\gtest\src\gtest.cc:2051](0x009effdd <base_unittests.exe+0x5effdd) modid:2

10 testing::UnitTest::Run [e:\derek\chromium\src\testing\gtest\src\gtest.cc:3812](0x009e7b16 <base_unittests.exe+0x5e7b16) modid:2

11 base:: TestSuite ::Run [e:\derek\chromium\src\base\test\test_suite.cc:167](0x00a035e2 <base_unittests.exe+0x6035e2) modid:2

Note: @0:06:55.310 in thread 4652 Note: refers to 1 bytes(s) beyond last valid byte in prior malloc Note: prev lower malloc: 0x042a2e50-0x042a2e5a Note: instruction: mov 0x01(%eax) -> %cl error end

initial fp=0x00000000 vs sp=0x0018fbc0 def=0 find_next_fp b/c starting w/ non-fp ebp 0x00000000 (def=0 0) find_next_fp 0x0018fbc0 => 0x0018fbec, ra=0x00640001 print_callstack: pc=0x0018fbec => FP=0x00d50308, RA=0x00640001 find_next_fp 0x0018fbf4 b/c hit bad non-zero fp 0x00d50308 find_next_fp 0x0018fbf4 => 0x0018fc94, ra=0x0091d46e print_callstack: pc=0x0018fc94 => FP=0x0018fca4, RA=0x0091d46e print_callstack: pc=0x0018fca4 => FP=0x0018fcc4, RA=0x0091d537 print_callstack: pc=0x0018fcc4 => FP=0x0018fd3c, RA=0x009ef805 print_callstack: pc=0x0018fd3c => FP=0x0018fd64, RA=0x009e2d47 print_callstack: pc=0x0018fd64 => FP=0x0018fd8c, RA=0x009e34dd print_callstack: pc=0x0018fd8c => FP=0x0018fdb8, RA=0x009e3aef print_callstack: pc=0x0018fdb8 => FP=0x0018fdf8, RA=0x009e8bde print_callstack: pc=0x0018fdf8 => FP=0x0018fe74, RA=0x009effdd print_callstack: pc=0x0018fe74 => FP=0x0018fe90, RA=0x009e7b16 print_callstack: pc=0x0018fe90 => FP=0x0018ff00, RA=0x00a035e2 truncating callstack: hit max frames 12 12

callstack stack pc=0x0091d2f8 xsp=0x0018fbc0 xbp=0x00000000: 0x0018fbc0 0x11c953fb 0x0018fbc4 0x11c953f7 0x0018fbc8 0x00000000 0x0018fbcc 0x00000000 0x0018fbd0 0x00000000 0x0018fbd4 0x73a7ae27 drmemorylib.dll!replace_native_xfer 0x0018fbd8 0x00000000 0x0018fbdc 0x00000000 0x0018fbe0 0x00000000 0x0018fbe4 0x7efde000 0x0018fbe8 0x00140013 0x0018fbec 0x00d50308 base_unittests.exe!testing::FLAGS_gmock_catch_leaked_mocks 0x0018fbf0 0x00640001 base_unittests.exe!LazyInstanceTest_ConstructorThreadSafety_Test::TestBody 0x0018fbf4 0x0018fc20 0x0018fbf8 0x00000000 0x0018fbfc 0x00000000 ... 0x0018fc90 0xffffffff 0x0018fc94 0x0018fca4 0x0018fc98 0x0091d46e base_unittests.exe!base::`anonymous namespace'::MakeSomeErrors 0x0018fc9c 0x042a2e50

xref issue #666 which we chalked up to Release (pre-zero-retaddr):

"..." is needed due to https://code.google.com/p/drmemory/issues/detail?id=666 UNADDRESSABLE ACCESS

name=sanity test 06 (new/read left) base_unittests.exe!*ReadValueOutOfArrayBoundsLeft ... base_unittests.exe!base::ToolsSanityTest_AccessesToNewMemory_Test::TestBody

UNADDRESSABLE ACCESS name=sanity test 07 (new/read right) base_unittests.exe!_ReadValueOutOfArrayBoundsRight base_unittests.exe!_MakeSomeErrors base_unittests.exe!base::ToolsSanityTest_AccessesToNewMemory_Test::TestBody

first shows up here: new basic block @0x75d40a7e == KERNELBASE.dll!GetEnvironmentVariableA+0x14a replace_RtlFreeHeap heap=0x00e40000 flags=0x0 ptr=0x02dd3cc8 check_type_match: alloc flags=0x804 vs free=0x804 callstack stack pc=0x00000000 xsp=0x0018fa38 xbp=0x0018fbb0: 0x0018fa38 0x00000001 0x0018fa3c 0x1f401b3c ... 0x0018fbd8 0x75d40a94 KERNELBASE.dll!GetEnvironmentVariableA 0x0018fbdc 0x0018fbf8 0x0018fbe0 0x00000000 0x0018fbe4 0x7efde000 0x0018fbe8 0x00140013 0x0018fbec 0x00d50308 base_unittests.exe!testing::FLAGS_gmock_catch_leaked_mocks 0x0018fbf0 0x00640001 base_unittests.exe!LazyInstanceTest_ConstructorThreadSafety_Test::TestBody 0x0018fbf4 0x0018fc20 0x0018fbf8 0x00280026 0x0018fbfc 0x02dd3cc8 0x0018fc00 0x00c80002 base_unittests.exe!testing::internal::FunctionMockerBase<void __cdecl(enum base::SystemMonitor::DeviceT 0x0018fc04 0x02dd3d28 0x0018fc08 0x00000001 0x0018fc0c 0x0018fc90 0x0018fc10 0x009bef5b base_unittests.exe!GetRunningOnValgrind 0x0018fc14 0x00d50308 base_unittests.exe!testing::FLAGS_gmock_catch_leaked_mocks 0x0018fc18 0x0018fc20

if I rebuild w/ updated sources, this goes away.

going back to r204951 => no repro going back to r203969 => repro

0:000> U 0x00640001-5 base_unittests!LazyInstanceTest_ConstructorThreadSafety_Test::TestBody+0x31c [e:\derek\chromium\src\base\lazy_instance_unittest.cc @ 98]: 0063fffc e80fdc3900 call base_unittests!testing::internal::AssertHelper::AssertHelper (009ddc10) 00640001 8985a8feffff mov dword ptr [ebp-158h],eax

97: pool.JoinAll(); 98: EXPECT_EQ(1, SlowConstructor::constructed);

that code is not executed at all.

I see other similar addresses and a pattern emerges: 0x0018fd10 0x0044005c base_unittests.exe!base::anonymous namespace'::BindTest_ArityTest_Test::TestBody 0x0018fd14 0x00760065 base_unittests.exe!base::OverlayUserPrefStoreTest_NamesMapping_Test::TestBody 0x0018fd18 0x00630069 base_unittests.exe!base::anonymous namespace'::JSONValueSerializerTest_Roundtrip_Test::T estBody 0x0018fd1c 0x005c0065 base_unittests.exe!std::_Treestd::_Tset_traits<int,std::less<int,std::allocator,0>

::_Linsert 0x0018fd20 0x00610048 base_unittests.exe!base::JSONReaderTest_Reading_Test::TestBody 0x0018fd24 0x00640072 base_unittests.exe!LazyInstanceTest_ConstructorThreadSafety_Test::TestBody 0x0018fd28 0x00690064 base_unittests.exe!base::WeakPtrDeathTest_NonOwnerThreadReferencesObjectAfterDeletion_Test::TestBody 0x0018fd2c 0x006b0073 base_unittests.exe!base::`anonymous namespace'::RunTest_NonNestableInNestedLoop 0x0018fd30 0x006f0056 base_unittests.exe!testing::internal::TestFactoryImplbase::FieldTrialTest_RemainingProbability_Test::

could be a wide string. this one isn't at the same location on the stack, but could the 0x00640001 be from a string that had 0x0064.... in it and then later someone wr...

Original issue: http://code.google.com/p/drmemory/issues/detail?id=1271

derekbruening commented 9 years ago

From bruen...@google.com on June 14, 2013 14:48:44

here's what writes this value -- it's not a string but just a sub-word write w/ the rest uninit:

0018fbf0 00002c93 0:000> ba w4 0018fbf0 0018fbf0 00642c93 base_unittests!logging::`anonymous namespace'::LoggingTest_BasicLogging_Test::TestBody+0x353 [e:\derek\chromium\src\base\logging_unittest.cc @ 69] 0018fbf4 0018fc20 KERNELBASE!GetEnvironmentVariableA+0x12a: 75d40a5e 8975e8 mov dword ptr [ebp-18h],esi 75d40a61 66897de6 mov word ptr [ebp-1Ah],di <==== written here 75d40a65 ff150010d375 call dword ptr [KERNELBASE!_imp__RtlUnicodeStringToAnsiString (75d31000)] 0:000> ? ebp-1a Evaluate expression: 1637362 = 0018fbf2 0:000> dds esp 0018fbd0 0018fbf0 0018fbd4 0018fc00

so it sets MaximumLength to 0x64 and leaves Length uninit for RtlUnicodeStringToAnsiString, who then writes Length of 1:

0018fbf0 00640001 base_unittests!LazyInstanceTest_ConstructorThreadSafety_Test::TestBody+0x321 [e:\derek\chromium\src\base\lazy_instance_unittest.cc @ 98] 0018fbf4 0018fc20 0:000> da 0018fc20 0018fc20 "1"

derekbruening commented 9 years ago

From bruen...@google.com on June 14, 2013 17:08:13

xref issue #625 : string interpreted as malloc anchor => possible leak xref issue #703 : skipped frames due to FPO

possible solutions:

derekbruening commented 9 years ago

From bruen...@google.com on February 04, 2014 07:30:45

I'm seeing other instances of *TestBody bogus frames. I don't have the raw addresses so it's not for sure but it seems likely:

**\ DONE uninit in unit full NtDeviceIoControlFile: callstack has bogus frames? CLOSED: [2014-02-03 Mon 12:50]

At the end of unit 3 of 6: http://build.chromium.org/p/chromium.fyi/builders/Windows%20Unit%20%28DrMemory%20full%29%20%284%29/builds/170/steps/memory%20test%3A%20unit_2/logs/stdio [==========] 1168 tests from 647 test cases ran. (1069817 ms total) [ PASSED ] 1168 tests.

YOU HAVE 43 DISABLED TESTS

Dr.M Dr.M Error #1: UNINITIALIZED READ: reading 0x040dfb4c-0x040dfb50 4 byte(s) within 0x040dfb40-0x040dfba8 Dr.M # 0 system call NtDeviceIoControlFile InputBuffer
Dr.M # 1 bcrypt.dll!BCryptFreeBuffer +0xdb (0x72ad229b <bcrypt.dll+0x229b>) Dr.M # 2 extensions::WebRequestRulesRegistrySimpleTest_HostPermissionsChecker_Test::TestBody [chrome\browser\extensions\api\declarative_webrequest\webrequest_rules_registry_unittest.cc:725] Dr.M # 3 bcrypt.dll!BCryptUnregisterConfigChangeNotify +0x87 (0x72ad38b5 <bcrypt.dll+0x38b5>) Dr.M # 4 bcrypt.dll!BCryptGetFipsAlgorithmMode +0x6a0 (0x72ad37d8 <bcrypt.dll+0x37d8>) Dr.M # 5 ntdll.dll!RtlQueryEnvironmentVariable +0x240 (0x77889950 <ntdll.dll+0x39950>) Dr.M # 6 ntdll.dll!LdrShutdownProcess +0x140 (0x7789d6b2 <ntdll.dll+0x4d6b2>) Dr.M # 7 ntdll.dll!RtlExitUserProcess +0x73 (0x7789d554 <ntdll.dll+0x4d554>) Dr.M # 8 KERNEL32.dll!ExitProcess +0x14 (0x752179f5 <KERNEL32.dll+0x179f5>) Dr.M # 9 MSVCR100.dll!__crtExitProcess Dr.M #10 MSVCR100.dll!_cinit
Dr.M #11 MSVCR100.dll!exit
Dr.M #12 __tmainCRTStartup [f:\dd\vctools\crt_bld\self_x86\crt\src\crtexe.c:566] Dr.M #13 KERNEL32.dll!BaseThreadInitThunk +0x11 (0x7521339a <KERNEL32.dll+0x1339a>)

Looks like issue #748 but w/ 2 extra frames on top (and is frame#2 just bogus?):

Improperly handled ioctl in bcrypt.

UNINITIALIZED READ name= https://code.google.com/p/drmemory/issues/detail?id=748 system call NtDeviceIoControlFile InputBuffer bcrypt.dll!BCryptUnregisterConfigChangeNotify bcrypt.dll!BCryptGetFipsAlgorithmMode ntdll.dll!RtlQueryEnvironmentVariable

=> I widened the suppression.

But if we fix issue #1271 -- narrow it again?

**\ TODO unit_ full Release uninit: callstack has bogus frames? http://build.chromium.org/p/chromium.fyi/builders/Windows%20Unit%20%28DrMemory%20full%29%20%283%29/builds/271 [ RUN ] PrintJobTest.SimplePrint Error #1: UNINITIALIZED READ: reading 0x040de16c-0x040de170 4 byte(s) within 0x040de168-0x040de180

0 system call NtSecureConnectPort parameter #3

1 GDI32.dll!ExtEscape +0x563 (0x74fa091b <GDI32.dll+0x2091b>)

2 SearchProviderTest_QueryKeywordProvider_Test::TestBody [chrome\browser\autocomplete\search_provider_unittest.cc:563]

3 SearchProviderTest_QueryKeywordProvider_Test::TestBody [chrome\browser\autocomplete\search_provider_unittest.cc:563]

4 GDI32.dll!ExtEscape +0x265 (0x74fa061d <GDI32.dll+0x2061d>)

5 GDI32.dll!GdiIsPlayMetafileDC +0xd91 (0x74f9fdc6 <GDI32.dll+0x1fdc6>)

6 GDI32.dll!GdiIsPlayMetafileDC +0xcb2 (0x74f9fce7 <GDI32.dll+0x1fce7>)

7 GDI32.dll!SetICMMode +0x2ad (0x74f9c003 <GDI32.dll+0x1c003>)

8 GDI32.dll!CreateDCW +0x17 (0x74f9e75b <GDI32.dll+0x1e75b>)

9 COMDLG32.dll!PrintDlgA +0x72e (0x7476f02e <COMDLG32.dll+0x1f02e>)

10 COMDLG32.dll!DllCanUnloadNow +0x7ba (0x747532de <COMDLG32.dll+0x32de>)

11 COMDLG32.dll!DllCanUnloadNow +0x27d (0x74752da1 <COMDLG32.dll+0x2da1>)

12 COMDLG32.dll!PrintDlgW +0x4a (0x747533ee <COMDLG32.dll+0x33ee>)

13 printing.dll!printing::PrintingContextWin::UseDefaultSettings [printing\printing_context_win.cc:256]

14 `anonymous namespace'::TestOwner::DetachWorker [chrome\browser\printing\print_job_unittest.cc:45]

15 printing::PrintJob::Initialize [chrome\browser\printing\print_job.cc:71]

16 PrintJobTest_SimplePrint_Test::TestBody [chrome\browser\printing\print_job_unittest.cc:107]

17 testing::internal::HandleExceptionsInMethodIfSupported<> [testing\gtest\src\gtest.cc:2045]

Note: @0:06:19.380 in thread 2212 [ OK ] PrintJobTest.SimplePrint (4336 ms)

Looks like this one w/ bogus frames?

UNINITIALIZED READ name= https://code.google.com/p/drmemory/issues/detail?id=502 a system call NtSecureConnectPort parameter #3 GDI32.dll! GDI32.dll!

derekbruening commented 9 years ago

From bruen...@google.com on February 05, 2014 19:09:15

\ TODO unit_ full Release uninit: callstack has bogus frames => confirmed as issue #1271 *** TODO happened again in build 248819 => repro locally: issue #1271 confirmed! ****\ DONE analysis CLOSED: [2014-02-05 Wed 19:13]

I grabbed that build from the bot and analyzed it:

0:000> x unit_tests!extensions::CountingPolicyTest_DuplicateRows_Test::TestBody 0167fb30 unit_tests!extensions::CountingPolicyTest_DuplicateRows_Test::TestBody (void)

It is ASLR: Dynamic base

01380000 05155000 unit_tests C (private pdb symbols) E:\derek\tmp\build_248819\full-build-win32\unit_tests.exe.pdb

0:000> ? 0167fb30 - unit_tests Evaluate expression: 3144496 = 002ffb30

Here's a candidate call:

unit_tests!extensions::CountingPolicyTest_DuplicateRows_Test::TestBody+0x58f [e:\b\build\slave\drm-cr\build\src\chrome\browser\extensions\activity_log\counting_policy_unittest.cc @ 1106]: 1106 016800bf 8b4dd4 mov ecx,dword ptr [ebp-2Ch] 1106 016800c2 51 push ecx 1106 016800c3 e8189b3e02 call unit_tests!operator delete (03a69be0) 1106 016800c8 83c404 add esp,4

0:000> ? 016800c8 - unit_tests Evaluate expression: 3145928 = 003000c8

So imagine unit_tests was loaded at 0x0014000. Then we'd have:

0:000> ? 00140000 + 003000c8 Evaluate expression: 4456648 = 004400c8

Or for something more like a *_STRING:

0:000> ? 00a40000 + 003000c8 Evaluate expression: 13893832 = 00d400c8

And there are many post-call addresses to choose from, but these are the most likely:

grep '^ 1' ~/x | grep -A 1 ' call ' | grep -vE '^--|call' | awk '{print $2}' | grep '[^0]00'

00b10006 00b1002d 00b10050 00b1005c 00b10076 00b10091 00b100a9 00b100c8 00b100f7

So the issue #1247, or issue #1331, hypotheses seem reasonable.

Running w/o suppressions and with "-pause_at_error -lib_blacklist_frames 0" so we can examine the stack at this uninit:

Error #1: UNINITIALIZED READ: reading 0x0429e218-0x0429e21c 4 byte(s) within 0x0429e214-0x0429e22c

0 system call NtSecureConnectPort parameter #3

1 GDI32.dll!PROXYPORT::PROXYPORT (0x76c9091b <GDI32.dll+0x2091b>) modid:136

2 GDI32.dll!LoadUserModePrinterDriverEx (0x76c9061d <GDI32.dll+0x2061d>) modid:136

3 GDI32.dll!LoadUserModePrinterDriver (0x76c8fdc6 <GDI32.dll+0x1fdc6>) modid:136

4 GDI32.dll!hdcCreateDCW (0x76c8fce7 <GDI32.dll+0x1fce7>) modid:136

5 GDI32.dll!bCreateDCW (0x76c8c003 <GDI32.dll+0x1c003>) modid:136

6 GDI32.dll!CreateDCW (0x76c8e75b <GDI32.dll+0x1e75b>) modid:136

0:000> ?? mc->ebp unsigned int 0x429e47c 0:000> dds @@(mc->esp) L100 0429e1bc 76c9091b GDI32!PROXYPORT::PROXYPORT+0x23e 0429e1c0 06707558 0429e1c4 0429e20c 0429e1c8 0429e24c 0429e1cc 0429e214 0429e1d0 06707f28 0429e1d4 00000000 0429e1d8 0429e208 0429e1dc 00000000 0429e1e0 00000000 0429e1e4 06706b78 0429e1e8 06707368 0429e1ec 000001d0 0429e1f0 00000103 0429e1f4 00000000 0429e1f8 ffffffff 0429e1fc 00000000 0429e200 00002a54 0429e204 00000f78 0429e208 00000000 0429e20c 004c004a unit_tests!testing::internal::CmpHelperFloatingPointEQ+0x1fa [e:\b\build\slave\drm-cr\build\src\testing\gtest\include\gtest\gtest.h @ 1656] 0429e210 0429e270 0429e214 00000030 0429e218 00000000 0429e21c 0000031c 0429e220 00000000 0429e224 00000000 0429e228 0429e25c 0429e22c 00200000 0429e230 00000000 0429e234 00000000 0429e238 00000000 0429e23c 00000000 0429e240 00000000 0429e244 00200000 0429e248 00000000 0429e24c 00000000 0429e250 00000002 0429e254 00000101 0429e258 0429e2bc 0429e25c 00000002 0429e260 00061504 0429e264 00000000 0429e268 00002000 0429e26c 00000000 0429e270 0052005c unit_tests!extensions::anonymous namespace'::ActiveTabTest_GrantToSinglePage_Test::TestBody+0x46c [e:\b\build\slave\drm-cr\build\src\chrome\browser\extensions\active_tab_unittest.cc @ 179] 0429e274 00430050 unit_tests!component_updater::ComponentUpdaterTest_InstallCrx_Test::TestBody+0x1060 [e:\b\build\slave\drm-cr\build\src\chrome\browser\component_updater\test\component_updater_service_unittest.cc @ 413] 0429e278 00430020 unit_tests!component_updater::ComponentUpdaterTest_InstallCrx_Test::TestBody+0x1030 [e:\b\build\slave\drm-cr\build\src\chrome\browser\component_updater\test\component_updater_service_unittest.cc @ 413] 0429e27c 006e006f unit_tests!extensions::ExtensionPrefsDelayedInstallInfo::Verify+0x45f [e:\b\build\slave\drm-cr\build\src\chrome\browser\extensions\extension_prefs_unittest.cc @ 563] 0429e280 00720074 unit_tests!ExtensionServiceTest_InstallObserverNotified_Test::TestBody+0x84 [e:\b\build\slave\drm-cr\build\src\chrome\browser\extensions\extension_service_unittest.cc @ 1756] 0429e284 006c006f unit_tests!extensions::anonymous namespace'::ExtensionActionIconFactoryTest::CreateExtension+0x71f 0429e288 0055005c unit_tests!extensions::UmaPolicyTest_SiteUrlTest_Test::TestBody+0x25c [e:\b\build\slave\drm-cr\build\src\chrome\browser\extensions\activity_log\uma_policy_unittest.cc @ 107] 0429e28c 0070006d unit_tests!MockProviderVisitor::OnExternalExtensionFileFound+0x22d [e:\b\build\slave\drm-cr\build\src\chrome\browser\extensions\extension_service_unittest.cc @ 378] 0429e290 00500064 unit_tests!drive::`anonymous namespace'::FakeDriveServiceTest_DeleteResource_ETagMatch_Test::TestBody+0x3f4 [e:\b\build\slave\drm-cr\build\src\chrome\browser\drive\fake_drive_service_unittest.cc @ 940] 0429e294 006f0072 unit_tests!ExtensionServiceTest_SetUnsetBlacklistInPrefs_Test::TestBody+0x2302 [e:\b\build\slave\drm-cr\build\src\chrome\browser\extensions\extension_service_unittest.cc @ 3432] 0429e298 00790078 unit_tests!testing::internal::PrintTostd::basic_string<char,std::char_traits<char,std::allocator > const &,enum extensions::ExtensionDownloaderDelegate::Error,extensions::ExtensionDownloaderDelegate::PingResult const &,std::set<int,std::less,std::allocator > const &>+0x8 [e:\b\build\slave\drm-cr\build\src\testing\gtest\include\gtest\gtest-printers.h @ 518] 0429e29c 0032005f unit_tests!HistoryQuickProviderTest_Spans_Test::TestBody+0x31f [e:\b\build\slave\drm-cr\build\src\chrome\browser\autocomplete\history_quick_provider_unittest.cc @ 430] 0429e2a0 0036005f unit_tests!SearchProviderTest_KeywordFetcherSuggestRelevanceWithReorder_Test::TestBody+0x1bdf [e:\b\build\slave\drm-cr\build\src\chrome\browser\autocomplete\search_provider_unittest.cc @ 2369] 0429e2a4 00350031 unit_tests!SearchProviderTest_KeywordFetcherSuggestRelevance_Test::TestBody+0x35b1 [e:\b\build\slave\drm-cr\build\src\chrome\browser\autocomplete\search_provider_unittest.cc @ 2168] 0429e2a8 00340030 unit_tests!SearchProviderTest::RunTest+0x760 [e:\b\build\slave\drm-cr\build\src\chrome\browser\autocomplete\search_provider_unittest.cc @ 313] 0429e2ac 0030005f unit_tests!testing::internal::DefaultPrintTostd::set<std::basic_string<char,std::char_traits<char,std::allocator >,std::lessstd::basic_string<char,std::char_traits<char,std::allocator > >,std::allocatorstd::basic_string<char,std::char_traits<char,std::allocator > > > >+0xaf [e:\b\build\slave\drm-cr\build\src\testing\gtest\include\gtest\gtest-printers.h @ 293] 0429e2b0 0032005f unit_tests!HistoryQuickProviderTest_Spans_Test::TestBody+0x31f [e:\b\build\slave\drm-cr\build\src\chrome\browser\autocomplete\history_quick_provider_unittest.cc @ 430] 0429e2b4 00300030 unit_tests!testing::internal::DefaultPrintTostd::set<std::basic_string<char,std::char_traits<char,std::allocator >,std::lessstd::basic_string<char,std::char_traits<char,std::allocator > >,std::allocatorstd::basic_string<char,std::char_traits<char,std::allocator > > > >+0x80 [e:\b\build\slave\drm-cr\build\src\testing\gtest\include\gtest\gtest-printers.h @ 276] 0429e2b8 00000030 0429e2bc 00000000 0429e2c0 00000000 0429e2c4 00000000 ... 0429e474 00000000 0429e478 bd46e979 0429e47c 0429e4b4 0429e480 ...

derekbruening commented 9 years ago

From bruen...@google.com on February 05, 2014 19:09:15

...76c9061d GDI32!LoadUserModePrinterDriverEx+0x10c

0:000> du 0429e270
0429e270 "\RPC Control\UmpdProxy_2_61504_0" 0429e2b0 "_2000"

So it's a string: so it's issue #1331?

****\ DONE Q1: why is it scanning when the top fp is good? => always skips fp for syscall CLOSED: [2014-02-05 Wed 14:53]

For Chromium we pass -no_callstack_use_top_fp_selectively so it shouldn't scan, right?

ifdef WINDOWS

     /\* don't trust ebp when in Windows syscall wrapper */
     (pcs != NULL && pcs->first_is_syscall) ||

endif

That's from issue #1191: "required for good syscalls for DC creation: b/c the -callstack_use_top_fp_selectively feature only applies to the primary error report callstack"

****\ DONE Q2: why didn't it match the issue #1331 wide-string heuristic? => b/c it's issue #1271! CLOSED: [2014-02-05 Wed 15:41]

These are the two addresses that match:

00b10050 => 00430050 00b1005c => 0052005c, 0055005c

0046e100 00061504 00000000 00002000 00000000 ......... ...... 0046e110 0052005c 00430050 00430020 006e006f .R.P.C. .C.o.n. 0046e120 00720074 006c006f 0055005c 0070006d t.r.o.l..U.m.p. 0046e130 00500064 006f0072 00790078 0032005f d.P.r.o.x.y..2. 0046e140 0036005f 00350031 00340030 0030005f .6.1.5.0.4..0. 0046e150 0032005f 00300030 00000030 00000000 .2.0.0.0.......

The stack offset seems to vary. The only theory I can come up with is that there's a page boundary in the 1st 16 chars of the string? => no, it's issue #1271

****\ DONE live repro CLOSED: [2014-02-05 Wed 19:13]

On iter #16:

Error #1: UNINITIALIZED READ: reading 0x0020e0c4-0x0020e0c8 4 byte(s) within 0x0020e0c0-0x0020e0d8

0 system call NtSecureConnectPort parameter #3

1 GDI32.dll!PROXYPORT::PROXYPORT (0x76c9091b <GDI32.dll+0x2091b>) modid:136

2 BookmarkIndexTest::AddBookmarksWithTitles [e:\b\build\slave\drm-cr\build\src\chrome\browser\bookmarks\bookmark_index_unittest.cc:40](0x004c004a <unit_tests.exe+0x15004a) modid:1

3 GDI32.dll!LoadUserModePrinterDriverEx (0x76c9061d <GDI32.dll+0x2061d>) modid:136

4 GDI32.dll!LoadUserModePrinterDriver (0x76c8fdc6 <GDI32.dll+0x1fdc6>) modid:136

5 GDI32.dll!hdcCreateDCW (0x76c8fce7 <GDI32.dll+0x1fce7>) modid:136

6 GDI32.dll!bCreateDCW (0x76c8c003 <GDI32.dll+0x1c003>) modid:136

7 GDI32.dll!CreateDCW (0x76c8e75b <GDI32.dll+0x1e75b>) modid:136

Hmm, it's not the wide string sequence, it's earlier -- the two size fields followed by the pointer to the wide string:

0:000> dds @@(mc->esp) L100 0020e068 76c9091b GDI32!PROXYPORT::PROXYPORT+0x23e 0020e06c 06587558 0020e070 0020e0b8 0020e074 0020e0f8 0020e078 0020e0c0 0020e07c 06587f28 0020e080 00000000 0020e084 0020e0b4 0020e088 00000000 0020e08c 00000000 0020e090 06586b78 0020e094 06587368 0020e098 000001d0 0020e09c 00000103 0020e0a0 00000000 0020e0a4 ffffffff 0020e0a8 00000000 0020e0ac 0001f4bc 0020e0b0 000215e0 0020e0b4 00000000 0020e0b8 004c004a unit_tests!BookmarkIndexTest::AddBookmarksWithTitles+0x6a [e:\b\build\slave\drm-cr\build\src\chrome\browser\bookmarks\bookmark_index_unittest.cc @ 40] 0020e0bc 0020e11c 0020e0c0 00000030 0020e0c4 00000000 ... 0020e118 00000000 0020e11c 0052005c unit_tests!testing::internal::TestFactoryImpl<`anonymous namespace'::CookiesTreeModelTest_RemoveSingleCookieNode_Test>::CreateTest+0x1c [e:\b\build\slave\drm-cr\build\src\testing\gtest\include\gtest\internal\gtest-internal.h @ 443]

So it is issue #1271 and not a page boundary.

****\ TODO write test: how?

Running:

for ((i=0; i<100; i++)); do echo $i; ~/drmemory/git/build_x86_dbg/bin/drmemory.exe -pause_at_error -pause_at_assert $DRMEM_CHROME_ARGS -dr d:/derek/dr/git/exports -batch -- ./unit_tests.exe --gtest_filter=PrintJobTest.SimplePrint --ui-test-action-timeout=12000000 --ui-test-action-max-timeout=28000000 --ui-test-terminate-timeout=12000000; done

Results in 3 hits for strings, one for _STRING struct:

% grep structs logs/DrMemory-unittests.exe./g_ logs/DrMemory-unit_tests.exe.102944.000/global.102944.log:callstack strings: 0, structs: 0 logs/DrMemory-unit_tests.exe.109988.000/global.109988.log:callstack strings: 0, structs: 0 logs/DrMemory-unit_tests.exe.124084.000/global.124084.log:callstack strings: 0, structs: 0 logs/DrMemory-unit_tests.exe.125644.000/global.125644.log:callstack strings: 0, structs: 0 logs/DrMemory-unit_tests.exe.125708.000/global.125708.log:callstack strings: 0, structs: 0 logs/DrMemory-unit_tests.exe.129708.000/global.129708.log:callstack strings: 0, structs: 0 logs/DrMemory-unit_tests.exe.13012.000/global.13012.log:callstack strings: 0, structs: 0 logs/DrMemory-unit_tests.exe.26140.000/global.26140.log:callstack strings: 0, structs: 0 logs/DrMemory-unit_tests.exe.29064.000/global.29064.log:callstack strings: 0, structs: 0 logs/DrMemory-unit_tests.exe.38216.000/global.38216.log:callstack strings: 0, structs: 0 logs/DrMemory-unit_tests.exe.40144.000/global.40144.log:callstack strings: 0, structs: 0 logs/DrMemory-unit_tests.exe.54936.000/global.54936.log:callstack strings: 0, structs: 0 logs/DrMemory-unit_tests.exe.55384.000/global.55384.log:callstack strings: 0, structs: 0 logs/DrMemory-unit_tests.exe.56232.000/global.56232.log:callstack strings: 1, structs: 1 logs/DrMemory-unit_tests.exe.56296.000/global.56296.log:callstack strings: 0, structs: 0 logs/DrMemory-unit_tests.exe.56480.000/global.56480.log:callstack strings: 0, structs: 0 logs/DrMemory-unit_tests.exe.58224.000/global.58224.log:callstack strings: 0, structs: 0 logs/DrMemory-unit_tests.exe.59376.000/global.59376.log:callstack strings: 0, structs: 0 logs/DrMemory-unit_tests.exe.61004.000/global.61004.log:callstack strings: 0, structs: 0 logs/DrMemory-unit_tests.exe.65052.000/global.65052.log:callstack strings: 0, structs: 0 logs/DrMemory-unit_tests.exe.65400.000/global.65400.log:callstack strings: 0, structs: 0 logs/DrMemory-unit_tests.exe.65484.000/global.65484.log:callstack strings: 1, structs: 0 logs/DrMemory-unit_tests.exe.67488.000/global.67488.log:callstack strings: 0, structs: 0 logs/DrMemory-unit_tests.exe.70076.000/global.70076.log:callstack strings: 0, structs: 0 logs/DrMemory-unit_tests.exe.70128.000/global.70128.log:callstack strings: 0, structs: 0 logs/DrMemory-unit_tests.exe.71212.000/global.71212.log:callstack strings: 1, structs: 0 logs/DrMemory-unit_tests.exe.72836.000/global.72836.log:callstack strings: 0, structs: 0 logs/DrMemory-unit_tests.exe.74428.000/global.74428.log:callstack strings: 0, structs: 0

The struct hit: SUPPRESSIONS USED: 1x: https://code.google.com/p/drmemory/issues/detail?id=502 a ERRORS IGNORED: 2 user-suppressed, 0 default-suppressed error(s)

Hmm, is that supp not incremented for dup callstack?

***\ INFO happened in build 248869 as well

derekbruening commented 9 years ago

From derek.br...@gmail.com on February 07, 2014 19:25:00

This issue was closed by revision r1693 .

Status: Fixed