Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

many false positive invalid heap args on 64-bit Chromium tests #1839

Open
derekbruening opened this issue Dec 31, 2015 · 1 comment
Open

Comments

@derekbruening
Copy link
Contributor

The 64-bit FYI test bot is now up and running, but there are many reported invalid heap args.

Xref #1831. These may similarly all be due to bad callstacks: xref #1222, #1833.

http://build.chromium.org/p/chromium.fyi/builders/Windows%20Tests%20%28DrMemory%20x64%29/builds/18

media:

[ RUN      ] FFmpegDemuxerTest.Initialize_OpenFails
~~Dr.M~~ 
~~Dr.M~~ Error #1: INVALID HEAP ARGUMENT: allocated with Windows API layer, freed with C library layer
~~Dr.M~~ # 0 replace_free                                                               [e:\b\build\slave\win-builder\drmemory\common\alloc_replace.c:2706]
~~Dr.M~~ # 1 base.dll!base::MessagePumpDefault::~MessagePumpDefault                     [base\message_loop\message_pump_default.cc:23]
~~Dr.M~~ # 2 media.dll!media::FFmpegGlue::~FFmpegGlue                                   [media\filters\ffmpeg_glue.cc:222]
~~Dr.M~~ # 3 media.dll!media::FFmpegDemuxer::~FFmpegDemuxer                             [media\filters\ffmpeg_demuxer.cc:763]
~~Dr.M~~ # 4 media::FFmpegDemuxer::`scalar deleting destructor'
~~Dr.M~~ # 5 media::FFmpegDemuxerTest::~FFmpegDemuxerTest                               [media\filters\ffmpeg_demuxer_unittest.cc:81]
~~Dr.M~~ # 6 media::FFmpegDemuxerTest_Initialize_OpenFails_Test::`scalar deleting destructor'
~~Dr.M~~ # 7 testing::TestInfo::Run                                                     [testing\gtest\src\gtest.cc:2662]
~~Dr.M~~ Note: @0:00:24.617 in thread 3732
[       OK ] FFmpegDemuxerTest.Initialize_OpenFails (72 ms)

ipc:

[ RUN      ] IPCAttachmentBrokerPrivilegedWinTest.SendHandle
~~Dr.M~~ 
~~Dr.M~~ Error #1: INVALID HEAP ARGUMENT: allocated with Windows API layer, freed with C library layer
~~Dr.M~~ # 0 replace_free                                                       [e:\b\build\slave\win-builder\drmemory\common\alloc_replace.c:2706]
~~Dr.M~~ # 1 base.dll!base::File::TakePlatformFile                              [base\files\file_win.cc:31]
~~Dr.M~~ # 2 MSVCP120.dll!std::_Locinfo::_Locinfo_ctor                         +0x43     (0x000007fef205e788 <MSVCP120.dll+0x3e788>)
~~Dr.M~~ # 3 MSVCP120.dll!std::_Locinfo::_Locinfo                              +0x9d     (0x000007fef2028faa <MSVCP120.dll+0x8faa>)
~~Dr.M~~ # 4 MSVCP120.dll!std::num_put<>::_Getcat                              +0x78     (0x000007fef2040b59 <MSVCP120.dll+0x20b59>)
~~Dr.M~~ # 5 MSVCP120.dll!std::time_get<>::_Getvals<>                          +0x6f9    (0x000007fef2033a9e <MSVCP120.dll+0x13a9e>)
~~Dr.M~~ # 6 MSVCP120.dll!std::basic_ostream<>::operator<<                     +0x60     (0x000007fef203ac3d <MSVCP120.dll+0x1ac3d>)
~~Dr.M~~ # 7 base.dll!logging::LogMessage::Init                                 [base\logging.cc:753]
~~Dr.M~~ # 8 base.dll!logging::LogMessage::LogMessage                           [base\logging.cc:493]
~~Dr.M~~ # 9 `anonymous namespace'::CommonPrivilegedProcessMain                 [ipc\attachment_broker_privileged_win_unittest.cc:443]
~~Dr.M~~ #10 multi_process_function_list::InvokeChildProcessTest                [testing\multiprocess_func_list.cc:51]
~~Dr.M~~ #11 base::TestSuite::Run                                               [base\test\test_suite.cc:222]
~~Dr.M~~ #12 base::internal::Invoker<>::Run                                     [base\bind_internal.h:350]
~~Dr.M~~ #13 base::`anonymous namespace'::LaunchUnitTestsInternal               [base\test\launcher\unit_test_launcher.cc:206]
~~Dr.M~~ #14 base::LaunchUnitTests                                              [base\test\launcher\unit_test_launcher.cc:450]
~~Dr.M~~ #15 main                                                               [ipc\run_all_unittests.cc:23]
~~Dr.M~~ Note: @0:00:01.000 in thread 196
[2760:196:1230/033853:2121519:INFO:attachment_broker_privileged_win_unittest.cc(443)] Privileged process start.
[2760:196:1230/033853:2121597:INFO:attachment_broker_privileged_win_unittest.cc(455)] Privileged process spinning run loop.
[2760:196:1230/033853:2121629:INFO:attachment_broker_privileged_win_unittest.cc(462)] Privileged process running callback.
[2760:196:1230/033853:2121629:INFO:attachment_broker_privileged_win_unittest.cc(464)] Privileged process finishing callback.
[2760:196:1230/033853:2121629:INFO:attachment_broker_privileged_win_unittest.cc(455)] Privileged process spinning run loop.
[2760:196:1230/033853:2121629:INFO:attachment_broker_privileged_win_unittest.cc(469)] Privileged process end.
[       OK ] IPCAttachmentBrokerPrivilegedWinTest.SendHandle (1649 ms)

There are many instances of invalid heap args involving RtlProcessFlsData:

ipc not visible in bot stdio, also base:

INVALID HEAP ARGUMENT: allocated with Windows API layer, freed with C library layer
#0 replace_free                                            [e:\b\build\slave\win-builder\drmemory\common\alloc_replace.c:2706]
#1 base.dll!base::MessagePumpForIO::~MessagePumpForIO      [base\message_loop\message_pump_win.cc:436]
#2 ntdll.dll!RtlProcessFlsData                            +0x83     (0x000000007735ac14 <ntdll.dll+0x2ac14>)
#3 ntdll.dll!LdrShutdownThread                            +0x4a     (0x000000007737381b <ntdll.dll+0x4381b>)
#4 KERNEL32.dll!BaseThreadInitThunk                       +0xc      (0x00000000772259cd <KERNEL32.dll+0x159cd>)
Note: @0:00:11.820 in thread 1956

Same thing in this particular test for net_:

[ RUN      ] NetworkQualityEstimatorTest.TestKbpsRTTUpdates
~~888~~ 
~~888~~ Error #1: INVALID HEAP ARGUMENT: allocated with Windows API layer, freed with C library layer
~~888~~ # 0 replace_free                                            [e:\b\build\slave\win-builder\drmemory\common\alloc_replace.c:2706]
~~888~~ # 1 base.dll!base::MessagePumpForIO::~MessagePumpForIO      [base\message_loop\message_pump_win.cc:436]
~~888~~ # 2 ntdll.dll!RtlProcessFlsData                            +0x83     (0x000000007735ac14 <ntdll.dll+0x2ac14>)
~~888~~ # 3 ntdll.dll!LdrShutdownThread                            +0x4a     (0x000000007737381b <ntdll.dll+0x4381b>)
~~888~~ # 4 KERNEL32.dll!BaseThreadInitThunk                       +0xc      (0x00000000772259cd <KERNEL32.dll+0x159cd>)
~~888~~ Note: @0:00:25.870 in thread 888
[       OK ] NetworkQualityEstimatorTest.TestKbpsRTTUpdates (501 ms)

Plus a bunch of other tests:

[ RUN      ] DiskCacheEntryTest.GetTimes
[ RUN      ] DiskCacheEntryTest.SizeChanges
[ RUN      ] DiskCacheEntryTest.NewEvictionDoomEntryNextToOpenEntry
[ RUN      ] DiskCacheEntryTest.SimpleCacheInternalAsyncIO
[ RUN      ] DiskCacheEntryTest.SimpleCacheDoomCreateRace
[ RUN      ] URLFetcherTest.DontRetryOnNetworkChangedByDefault
[ RUN      ] URLFetcherTest.FileTestOverwriteExisting
[ RUN      ] EmbeddedTestServerThreadingTestInstantiation/EmbeddedTestServerThreadingTest.RunTest/4

Also in components, device, cloud_print, mojo_system, cast, extensions,
google_apis, and unit_.

Different bogus callstack in net_:

[ RUN      ] ClientSocketPoolBaseTest.CancelBackupSocketAfterFinishingAllRequests
~~3608~~ 
~~3608~~ Error #7: INVALID HEAP ARGUMENT: allocated with Windows API layer, freed with C library layer
~~3608~~ # 0 replace_free                                            [e:\b\build\slave\win-builder\drmemory\common\alloc_replace.c:2706]
~~3608~~ # 1 net.dll!net::HostResolverImpl::ProcTask::DoLookup       [net\dns\host_resolver_impl.cc:729]
~~3608~~ # 2 ntdll.dll!RtlProcessFlsData                            +0x83     (0x000000007735ac14 <ntdll.dll+0x2ac14>)
~~3608~~ # 3 ntdll.dll!LdrShutdownThread                            +0x4a     (0x000000007737381b <ntdll.dll+0x4381b>)
~~3608~~ # 4 ntdll.dll!RtlExitUserThread                            +0x37     (0x00000000773736e8 <ntdll.dll+0x436e8>)
~~3608~~ # 5 ntdll.dll!TpDisassociateCallback                       +0x67d    (0x0000000077346a2e <ntdll.dll+0x16a2e>)
~~3608~~ # 6 KERNEL32.dll!BaseThreadInitThunk                       +0xc      (0x00000000772259cd <KERNEL32.dll+0x159cd>)
~~3608~~ Note: @0:03:44.033 in thread 3608
[       OK ] ClientSocketPoolBaseTest.CancelBackupSocketAfterFinishingAllRequests (388 ms)

Seems like MSVCR100D!_freefls should be on the callstack.
Xref #1278; xref #997 _getptd. Probably this is similar, with some
internal libc routine being called on alloc resulting in our first
interception being at the WinAPI layer.

Sure looks like a bogus callstack frame -- and maybe it becomes a
"potential error" w/ proper callstack?

In content_, missing some frames so doesn't match #960 suppression (xref #1831):

~~3124~~ Error #1: INVALID HEAP ARGUMENT: allocated with Windows API layer, freed with C library layer
~~3124~~ # 0 replace_free                      [e:\b\build\slave\win-builder\drmemory\common\alloc_replace.c:2706]
~~3124~~ # 1 KERNEL32.dll!BaseThreadInitThunk +0xc      (0x00000000772259cd <KERNEL32.dll+0x159cd>)
~~3124~~ Note: @0:00:14.966 in thread 3124

I can't repro any of these invalid heap args locally!

They may well only occur with a lack of libc symbols, so this is my template for attempting to reproduce:

% _NT_SYMBOL_PATH= bin64/drmemory -no_fetch_symbols -light -batch -pause_at_assert -dr d:/derek/dr/git/exports -- z:/derek/chromium/src/out/Release_x64/ipc_tests.exe --single-process-tests --gtest_filter=

I tried media and ipc individual and running full suite from bot, both w/ my build and w/ DrMem unpacked/.

Maybe it's best to just disable this feature on the bots? We already do this for Windows Release:

        proc += ["-no_check_delete_mismatch"]

So we'd add -no_check_heap_mismatch.

Xref #1838: add new option -malloc_callstacks to obtain malloc info for mismatch errors in light mode, and turn on for chrome?

@derekbruening
Copy link
Contributor Author

In fact we are also seeing false positives on smaller apps on some platforms:

Win8.1 on hello64:

C:\derek>DrMemory-Windows-1.9.1-RC1\bin64\drmemory -debug -- hello64.exe
~~Dr.M~~ Dr. Memory version 1.9.16821
~~Dr.M~~ (Uninitialized read checking is not yet supported for 64-bit)
~~Dr.M~~ Running "hello64.exe"
~~Dr.M~~
~~Dr.M~~ Error #1: INVALID HEAP ARGUMENT to free 0x00007ff9bc1d13b0
~~Dr.M~~ # 0 replace_NtdllpFreeStringRoutine               [d:\derek\drmemory\git\src\common\alloc_replace.c:4109]
~~Dr.M~~ # 1 ntdll.dll!RtlUserThreadStart                 +0x29     (0x00007ff9be3e544a <ntdll.dll+0x1544a>)
~~Dr.M~~ Note: @0:00:00.312 in thread 620

Win10 on 64-bit notepad where I opened the Save As dialog:

Hit several invalid heap args, due to callstack not matching auto-suppress?

~~Dr.M~~ Error #1: INVALID HEAP ARGUMENT: allocated with Windows API layer, freed with C library layer
~~Dr.M~~ # 0 replace_free                          [d:\derek\drmemory\git\src\common\alloc_replace.c:2706]
~~Dr.M~~ # 1 MSVCP120.dll!Mtx_destroy             +0x27     (0x00007ff9024dcea0 <MSVCP120.dll+0x3cea0>)
~~Dr.M~~ # 2 FileSyncShell64.DLL!DllUnregisterServer+0x7016   (0x00007ff8fe6c650f <FileSyncShell64.DLL+0x1650f>)
~~Dr.M~~ # 3 FileSyncShell64.DLL!DllUnregisterServer+0x74db   (0x00007ff8fe6c69d4 <FileSyncShell64.DLL+0x169d4>)
~~Dr.M~~ # 4 FileSyncShell64.DLL!DllUnregisterServer+0x10f43  (0x00007ff8fe6d043c <FileSyncShell64.DLL+0x2043c>)
~~Dr.M~~ # 5 FileSyncShell64.DLL!DllUnregisterServer+0xcb7    (0x00007ff8fe6c01b0 <FileSyncShell64.DLL+0x101b0>)
~~Dr.M~~ # 6 FileSyncShell64.DLL!DllUnregisterServer+0xf45    (0x00007ff8fe6c043e <FileSyncShell64.DLL+0x1043e>)
~~Dr.M~~ # 7 ntdll.dll!LdrpCallInitRoutine
~~Dr.M~~ # 8 ntdll.dll!LdrShutdownProcess
~~Dr.M~~ # 9 ntdll.dll!LdrShutdownProcess
~~Dr.M~~ #10 ntdll.dll!RtlExitUserProcess
~~Dr.M~~ #11 ntdll.dll!LdrGetDllHandle
~~Dr.M~~ #12 KERNELBASE.dll!BaseSetLastNTError
~~Dr.M~~ #13 KERNELBASE.dll!BasepGetModuleHandleExW
~~Dr.M~~ #14 KERNELBASE.dll!GetModuleHandleExW
~~Dr.M~~ #15 KERNEL32.dll!FatalExit   
~~Dr.M~~ #16 msvcrt.dll!_crtExitProcess
~~Dr.M~~ #17 msvcrt.dll!unlockexit
~~Dr.M~~ #18 msvcrt.dll!setmbcp_nolock
~~Dr.M~~ #19 notepad.exe!?                        +0x0      (0x00007ff668f390cc <notepad.exe+0x190cc>)
~~Dr.M~~ Note: @0:01:07.828 in thread 5272
~~Dr.M~~ Note: memory was allocated here:
~~Dr.M~~ Note: # 0 replace_RtlAllocateHeap               [d:\derek\drmemory\git\src\common\alloc_replace.c:3764]
~~Dr.M~~ Note: # 1 MSVCR120.dll!realloc                 +0x130    (0x00007ff901f67795 <MSVCR120.dll+0x67795>)
~~Dr.M~~ Note: # 2 MSVCR120.dll!calloc_crt              +0x32     (0x00007ff901f66ae7 <MSVCR120.dll+0x66ae7>)
~~Dr.M~~ Note: # 3 MSVCP120.dll!Mtx_init                +0x25     (0x00007ff9024dced6 <MSVCP120.dll+0x3ced6>)
~~Dr.M~~ Note: # 4 FileSyncShell64.DLL!DllUnregisterServer+0x6b86   (0x00007ff8fe6c607f <FileSyncShell64.DLL+0x1607f>)
<...>

~~Dr.M~~ Error #2: INVALID HEAP ARGUMENT: allocated with Windows API layer, freed with C library layer
~~Dr.M~~ # 0 replace_free                                              [d:\derek\drmemory\git\src\common\alloc_replace.c:2706]
~~Dr.M~~ # 1 MSVCP120.dll!std::ctype<>::`default constructor closure' +0x66     (0x00007ff9024aac63 <MSVCP120.dll+0xac63>)
~~Dr.M~~ # 2 MSVCP120.dll!Xp_subx                                     +0x65c6   (0x00007ff9024f4ea3 <MSVCP120.dll+0x54ea3>)
~~Dr.M~~ # 3 MSVCP120.dll!Xp_subx                                     +0x5af    (0x00007ff9024eee8c <MSVCP120.dll+0x4ee8c>)
~~Dr.M~~ # 4 MSVCP120.dll!Xp_subx                                     +0x831    (0x00007ff9024ef10e <MSVCP120.dll+0x4f10e>)
~~Dr.M~~ # 5 ntdll.dll!LdrpCallInitRoutine
~~Dr.M~~ # 6 ntdll.dll!LdrShutdownProcess
~~Dr.M~~ # 7 ntdll.dll!LdrShutdownProcess
~~Dr.M~~ # 8 ntdll.dll!RtlExitUserProcess
~~Dr.M~~ # 9 ntdll.dll!LdrGetDllHandle
~~Dr.M~~ #10 KERNELBASE.dll!BaseSetLastNTError
~~Dr.M~~ #11 KERNELBASE.dll!BasepGetModuleHandleExW
~~Dr.M~~ #12 KERNELBASE.dll!GetModuleHandleExW
~~Dr.M~~ #13 KERNEL32.dll!FatalExit   
~~Dr.M~~ #14 msvcrt.dll!_crtExitProcess
~~Dr.M~~ #15 msvcrt.dll!unlockexit
~~Dr.M~~ #16 msvcrt.dll!setmbcp_nolock
~~Dr.M~~ #17 notepad.exe!?                                            +0x0      (0x00007ff668f390cc <notepad.exe+0x190cc>)
~~Dr.M~~ #18 KERNEL32.dll!BaseThreadInitThunk
~~Dr.M~~ Note: @0:01:07.860 in thread 5272
~~Dr.M~~ Note: memory was allocated here:
~~Dr.M~~ Note: # 0 replace_RtlAllocateHeap                             [d:\derek\drmemory\git\src\common\alloc_replace.c:3764]
~~Dr.M~~ Note: # 1 MSVCR120.dll!realloc                               +0x130    (0x00007ff901f67795 <MSVCR120.dll+0x67795>)
~~Dr.M~~ Note: # 2 MSVCR120.dll!calloc_crt                            +0x32     (0x00007ff901f66ae7 <MSVCR120.dll+0x66ae7>)
~~Dr.M~~ Note: # 3 MSVCP120.dll!Getctype                              +0x20     (0x00007ff9024de161 <MSVCP120.dll+0x3e161>)
~~Dr.M~~ Note: # 4 MSVCP120.dll!std::ctype<>::_Getcat                 +0x9f     (0x00007ff9024aa6d8 <MSVCP120.dll+0xa6d8>)
~~Dr.M~~ Note: # 5 MSVCP120.dll!std::basic_ostream<>::_Osfx           +0x26d    (0x00007ff9024ad5ca <MSVCP120.dll+0xd5ca>)
~~Dr.M~~ Note: # 6 MSVCP120.dll!std::ios_base::getloc                 +0x18     (0x00007ff9024ab5f1 <MSVCP120.dll+0xb5f1>)
~~Dr.M~~ Note: # 7 MSVCP120.dll!std::basic_ios<>::init                +0x45     (0x00007ff9024d41da <MSVCP120.dll+0x341da>)
~~Dr.M~~ Note: # 8 MSVCP120.dll!std::basic_ostream<>::basic_ostream<> +0x71     (0x00007ff9024b53d2 <MSVCP120.dll+0x153d2>)
~~Dr.M~~ Note: # 9 MSVCP120.dll!?                                     +0x0      (0x00007ff9024a1668 <MSVCP120.dll+0x1668>)
~~Dr.M~~ Note: #10 MSVCR120.dll!initterm                              +0x3e     (0x00007ff901f2276b <MSVCR120.dll+0x2276b>)
~~Dr.M~~ Note: #11 MSVCR120.dll!cexit                                 +0x4e     (0x00007ff901f2265b <MSVCR120.dll+0x2265b>)

+2 more

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

1 participant