thousands of invalid heap arg errors in chrome production builds

[derekbruening]

From bruen...@google.com on April 24, 2014 17:58:56

I'm running a chrome production build and thus not a component
build and I'm seeing thousands of invalid heap args being reported, both
"allocated with C freed with Win" and "allocated with Win freed with C".
I am currently investigating.

Samples:

Error #1: INVALID HEAP ARGUMENT: allocated with C library layer, freed with Windows API layer
#0 replace_RtlFreeHeap [d:\drmemory_package\common\alloc_replace.c:3138]
#1 KERNEL32.dll!HeapFree +0x13 (0x74df14ad <KERNEL32.dll+0x114ad>)
#2 chrome.dll!std::_Locinfo::~_Locinfo [c:\b\depot_tools\win_toolchain\vs2013_files\vc\include\xlocinfo:96]
#3 chrome.dll!std::use_facet<> [c:\b\depot_tools\win_toolchain\vs2013_files\vc\include\xlocale:578]
#4 chrome.dll!std::basic_ios<>::init [c:\b\depot_tools\win_toolchain\vs2013_files\vc\include\ios:170]
#5 chrome.dll!std::basic_ostream<>::basic_ostream<> [c:\b\depot_tools\win_toolchain\vs2013_files\vc\include\ostream:55]
#6 chrome.dll!std::`dynamic initializer for 'cerr'' [f:\dd\vctools\crt\crtw32\stdcpp\cerr.cpp:16]
#7 chrome.dll!_cinit [f:\dd\vctools\crt\crtw32\startup\crt0dat.c:308]
#8 chrome.dll!_CRT_INIT [f:\dd\vctools\crt\crtw32\startup\dllcrt0.c:127]
#9 chrome.dll!__DllMainCRTStartup [f:\dd\vctools\crt\crtw32\startup\dllcrt0.c:371]
#10 chrome.dll!_DllMainCRTStartup [f:\dd\vctools\crt\crtw32\startup\dllcrt0.c:340]
#11 ntdll.dll!LdrpCallInitRoutine
Note: @0:00:58.691 in thread 7420

Error #14073: INVALID HEAP ARGUMENT: allocated with Windows API layer, freed with C library layer
#0 replace_free [d:\drmemory_package\common\alloc_replace.c:2380]
#1 chrome.dll!base::DefaultDeleter<>::operator() [c:\b\build\slave\win\build\src\base\memory\scoped_ptr.h:137]
#2 chrome.dll!ChromeMainDelegate::~ChromeMainDelegate [c:\b\build\slave\win\build\src\chrome\app\chrome_main_delegate.cc:398]
#3 MainDllLoader::Launch [c:\b\build\slave\win\build\src\chrome\app\client_util.cc:314]
#4 wWinMain [c:\b\build\slave\win\build\src\chrome\app\chrome_exe_main_win.cc:102]
Note: @0:02:19.394 in thread 7420

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

[derekbruening]

From bruen...@google.com on April 29, 2014 11:03:31

*** TODO analyze w/ more info

Error #1: INVALID HEAP ARGUMENT: allocated with C library layer, freed with Windows API layer

0 replace_RtlFreeHeap [d:\derek\drmemory\git\src\common\alloc_replace.c:3138]

1 KERNEL32.dll!HeapFree +0x13 (0x74df14ad <KERNEL32.dll+0x114ad>)

2 chrome.dll!std::_Locinfo::~_Locinfo [c:\b\depot_tools\win_toolchain\vs2013_files\vc\include\xlocinfo:96]

3 chrome.dll!std::use_facet<> [c:\b\depot_tools\win_toolchain\vs2013_files\vc\include\xlocale:578]

4 chrome.dll!std::basic_ios<>::init [c:\b\depot_tools\win_toolchain\vs2013_files\vc\include\ios:170]

5 chrome.dll!std::basic_ostream<>::basic_ostream<> [c:\b\depot_tools\win_toolchain\vs2013_files\vc\include\ostream:55]

6 chrome.dll!std::`dynamic initializer for 'cerr'' [f:\dd\vctools\crt\crtw32\stdcpp\cerr.cpp:16]

# 7 chrome.dll!_cinit [f:\dd\vctools\crt\crtw32\startup\crt0dat.c:308]
# 8 chrome.dll!_CRT_INIT [f:\dd\vctools\crt\crtw32\startup\dllcrt0.c:127]
# 9 chrome.dll!__DllMainCRTStartup [f:\dd\vctools\crt\crtw32\startup\dllcrt0.c:371]
#10 chrome.dll!_DllMainCRTStartup [f:\dd\vctools\crt\crtw32\startup\dllcrt0.c:340]
#11 ntdll.dll!LdrpCallInitRoutine
Note: @0:00:15.357 in thread 4984
Note: memory was allocated here:
Note: # 0 replace_malloc [d:\derek\drmemory\git\src\common\alloc_replace.c:2320]
Note: # 1 chrome.dll!std::_Yarn<>::operator= [f:\dd\vctools\crt\crtw32\stdhpp\xutility:3376]
Note: # 2 chrome.dll!std::_Locinfo::_Locinfo_ctor [f:\dd\vctools\crt\crtw32\stdcpp\locale0.cpp:198]
Note: # 3 chrome.dll!std::_Locinfo::_Locinfo [c:\b\depot_tools\win_toolchain\vs2013_files\vc\include\xlocinfo:79]
Note: # 4 chrome.dll!std::ctype<>::_Getcat [c:\b\depot_tools\win_toolchain\vs2013_files\vc\include\xlocale:2473]
Note: # 5 chrome.dll!std::use_facet<> [c:\b\depot_tools\win_toolchain\vs2013_files\vc\include\xlocale:578]
Note: # 6 chrome.dll!std::basic_ios<>::init [c:\b\depot_tools\win_toolchain\vs2013_files\vc\include\ios:170]
Note: # 7 chrome.dll!std::basic_ostream<>::basic_ostream<> [c:\b\depot_tools\win_toolchain\vs2013_files\vc\include\ostream:55]
Note: # 8 chrome.dll!std::dynamic initializer for 'cerr'' [f:\dd\vctools\crt\crtw32\stdcpp\cerr.cpp:16] Note: # 9 chrome.dll!_cinit [f:\dd\vctools\crt\crtw32\startup\crt0dat.c:308] Note: #10chrome.dll!_CRT_INIT [f:\dd\vctools\crt\crtw32\startup\dllcrt0.c:127] Note:#11` chrome.dll!__DllMainCRTStartup [f:\dd\vctools\crt\crtw32\startup\dllcrt0.c:371]

With addresses:
Error #1: INVALID HEAP ARGUMENT: allocated with C library layer, freed with Windows API layer

0 replace_RtlFreeHeap [d:\derek\drmemory\git\src\common\alloc_replace.c:3138](0x739a8b00 <drmemorylib.dll+0x1a8b00) modid:5

1 KERNEL32.dll!HeapFree (0x74df14ad <KERNEL32.dll+0x114ad>) modid:14

2 chrome.dll!std::_Locinfo::~_Locinfo [c:\b\depot_tools\win_toolchain\vs2013_files\vc\include\xlocinfo:96](0x659ce188 <chrome.dll+0x4e188) modid:28

3 chrome.dll!std::use_facet<> [c:\b\depot_tools\win_toolchain\vs2013_files\vc\include\xlocale:578](0x659d121a <chrome.dll+0x5121a) modid:28

4 chrome.dll!std::basic_ios<>::init [c:\b\depot_tools\win_toolchain\vs2013_files\vc\include\ios:170](0x659d0303 <chrome.dll+0x50303) modid:28

Note: memory was allocated here:
Note: # 0 replace_malloc [d:\derek\drmemory\git\src\common\alloc_replace.c:2320](0x7398f640 <drmemorylib.dll+0x18f640) modid:5
Note: # 1 chrome.dll!std::_Yarn<>::operator= [f:\dd\vctools\crt\crtw32\stdhpp\xutility:3376](0x6692a15e <chrome.dll+0xfaa15e) modid:28
Note: # 2 chrome.dll!std::_Locinfo::_Locinfo_ctor [f:\dd\vctools\crt\crtw32\stdcpp\locale0.cpp:198](0x6692a2e3 <chrome.dll+0xfaa2e3) modid:28
Note: # 3 chrome.dll!std::_Locinfo::_Locinfo [c:\b\depot_tools\win_toolchain\vs2013_files\vc\include\xlocinfo:79](0x659ce124 <chrome.dll+0x4e124) modid:28
Note: # 4 chrome.dll!std::ctype<>::_Getcat [c:\b\depot_tools\win_toolchain\vs2013_files\vc\include\xlocale:2473](0x659ce451 <chrome.dll+0x4e451) modid:28

0:000> Uf chrome_62d60000!std::_Locinfo::_Locinfo
chrome_62d60000!std::_Locinfo::_Locinfo [c:\b\depot_tools\win_toolchain\vs2013_files\vc\include\xlocinfo @ 94]:
94 62dae150 51 push ecx
94 62dae151 56 push esi
94 62dae152 8bf1 mov esi,ecx
94 62dae154 57 push edi
95 62dae155 56 push esi
95 62dae156 e88bc1f500 call chrome_62d60000!std::_Locinfo::_Locinfo_dtor (63d0a2e6)
96 62dae15b 8b562c mov edx,dword ptr [esi+2Ch]
95 62dae15e 83c404 add esp,4
96 62dae161 8b3db0132564 mov edi,dword ptr [chrome_62d60000!_imp__HeapFree (642513b0)]
96 62dae167 8b0dd04c8b64 mov ecx,dword ptr [chrome_62d60000!allocator (648b4cd0)]
96 62dae16d 85d2 test edx,edx
96 62dae16f 7426 je chrome_62d60000!std::_Locinfo::~_Locinfo+0x47 (62dae197)

chrome_62d60000!std::_Locinfo::_Locinfo+0x21 [c:\b\depot_tools\win_toolchain\vs2013_files\vc\include\xlocinfo @ 96]:
96 62dae171 85c9 test ecx,ecx
96 62dae173 7415 je chrome_62d60000!std::_Locinfo::_Locinfo+0x3a (62dae18a)

chrome_62d60000!std::_Locinfo::_Locinfo+0x25 [c:\b\depot_tools\win_toolchain\vs2013_files\vc\include\xlocinfo @ 96]:
96 62dae175 8d41ff lea eax,[ecx-1]
96 62dae178 83f801 cmp eax,1
96 62dae17b 771a ja chrome_62d60000!std::_Locinfo::_Locinfo+0x47 (62dae197)

chrome_62d60000!std::_Locinfo::_Locinfo+0x2d [c:\b\depot_tools\win_toolchain\vs2013_files\vc\include\xlocinfo @ 96]:
96 62dae17d 52 push edx
96 62dae17e 6a00 push 0
96 62dae180 ff35cc4c8b64 push dword ptr [chrome_62d60000!win_heap (648b4ccc)]
96 62dae186 ffd7 call edi
96 62dae188 eb07 jmp chrome_62d60000!std::_Locinfo::_Locinfo+0x41 (62dae191)

chrome_69990000!std::_Locinfo::~_Locinfo+0x10a [c:\b\depot_tools\win_toolchain\vs2013_files\vc\include\xlocinfo @ 96]:
96 699de25a 8bca mov ecx,edx
96 699de25c e82f90ffff call chrome_69990000!`anonymous namespace'::do_free_with_callback (699d7290)

<goes on to do the same with +0x24, +0x1c, etc.>

0:001> dt -v chrome_65980000!std::_locinfo
class std::_Locinfo, 37 elements, 0x34 bytes
+0x000 _Lock : class std::_Lockit, 12 elements, 0x4 bytes
+0x004 _Days : class std::_Yarn, 15 elements, 0x8 bytes
+0x00c _Months : class std::_Yarn, 15 elements, 0x8 bytes
+0x014 _W_Days : class std::_Yarn<wchar_t>, 15 elements, 0x8 bytes
+0x01c _W_Months : class std::_Yarn<wchar_t>, 15 elements, 0x8 bytes
+0x024 _Oldlocname : class std::_Yarn, 15 elements, 0x8 bytes
+0x02c _Newlocname : class std::_Yarn, 15 elements, 0x8 bytes

0:000> U poi(642513b0)
kernel32!HeapFree:

__CLR_OR_THIS_CALL ~_Locinfo() _NOEXCEPT
    {   // destroy the object
    _Locinfo_dtor(this);
    }

So Locinfo::~Locinfo frees each field (here, the std::_Yarn field
_Newlocname) by directly calling HeapFree on it. Hmm.

0:001> x chrome_65980000!free
659c7ac0 chrome_65980000!free (void *)

0:001> ln 659c7ac0
c:\b\build\slave\win\build\src\base\allocator\generic_allocators.cc(31)
(659c7ac0) chrome_65980000!operator delete[] | (659c7b00) chrome_65980000!realloc
Exact matches:
chrome_65980000!operator delete (void *)
chrome_65980000!operator delete[](void *)
chrome_65980000!free (void *)

0:001> Uf 659c7ac0
chrome_65980000!operator delete[] [c:\b\build\slave\win\build\src\base\allocator\generic_allocators.cc @ 31]:
31 659c7ac0 55 push ebp
31 659c7ac1 8bec mov ebp,esp
31 659c7ac3 51 push ecx
32 659c7ac4 a1d04c4d67 mov eax,dword ptr [chrome_65980000!allocator (674d4cd0)]
32 659c7ac9 85c0 test eax,eax
32 659c7acb 741a je chrome_65980000!operator delete[]+0x27 (659c7ae7)

chrome_65980000!operator delete[]+0xd [c:\b\build\slave\win\build\src\base\allocator\generic_allocators.cc @ 32]:
32 659c7acd 48 dec eax
32 659c7ace 83f801 cmp eax,1
32 659c7ad1 771c ja chrome_65980000!operator delete[]+0x2f (659c7aef)

chrome_65980000!operator delete[]+0x13 [c:\b\build\slave\win\build\src\base\allocator\generic_allocators.cc @ 32]:
32 659c7ad3 ff7508 ...

[derekbruening]

From bruen...@google.com on April 29, 2014 11:03:31

... push dword ptr [ebp+8]
32 659c7ad6 6a00 push 0
32 659c7ad8 ff35cc4c4d67 push dword ptr [chrome_65980000!win_heap (674d4ccc)]
32 659c7ade ff15b013e766 call dword ptr [chrome_65980000!_imp__HeapFree (66e713b0)]
32 659c7ae4 59 pop ecx
33 659c7ae5 5d pop ebp
33 659c7ae6 c3 ret

chrome_65980000!operator delete[]+0x27 [c:\b\build\slave\win\build\src\base\allocator\generic_allocators.cc @ 32]:
32 659c7ae7 8b4d08 mov ecx,dword ptr [ebp+8]
32 659c7aea e8a1f7ffff call chrome_65980000!`anonymous namespace'::do_free_with_callback (659c7290)

chrome_65980000!operator delete[]+0x2f [c:\b\build\slave\win\build\src\base\allocator\generic_allocators.cc @ 32]:
32 659c7aef 59 pop ecx
33 659c7af0 5d pop ebp
33 659c7af1 c3 ret

OK, so we see that Locinfo::~Locinfo has the call to free() inlined inside it.

Allocated:
xutility:3376
_Myptr = (_Elem *)_CSTD malloc(_Count);

3376 6692a159 e8e2d809ff call chrome_65980000!malloc (659c7a40)

0:001> U 659c7a40
chrome_65980000!malloc [c:\b\build\slave\win\build\src\base\allocator\allocator_shim.cc @ 105]:
111 67657a5c ff15ac13b068 call dword ptr [chrome_67610000!_imp__HeapAlloc (68b013ac)]
U poi(68b013ac)
ntdll!RtlAllocateHeap:

The shim calls win_heap_malloc which calls HeapAlloc since I have
CHROME_ALLOCATOR=WINHEAP set.
(Remember that the allocator_shim is turned off for component build.)

0:001> x chrome_65980000!allocator
674d4cd0 chrome_65980000!allocator = WINHEAP (0n1)

Called from:
_MRTIMP2_PURE_NPURE void __CLRCALL_PURE_OR_CDECL _Locinfo::_Locinfo_ctor(_Locinfo *pLocinfo, const char *locname)
{ // switch to a named locale
const char *oldlocname = setlocale(LC_ALL, 0);

pLocinfo->_Oldlocname = oldlocname == 0 ? "" : oldlocname;
if (locname != 0)
    locname = setlocale(LC_ALL, locname);
pLocinfo->_Newlocname = locname == 0 ? "*" : locname;   \<---- here
}

Freed:
__CLR_OR_THIS_CALL ~_Yarn() _NOEXCEPT
{ // destroy the object
_Tidy();
}

void __CLR_OR_THIS_CALL _Tidy()
    {   // discard any string
    if (_Myptr != 0)

#ifdef _DEBUG
_free_dbg(_Myptr, _CRT_BLOCK);

#else /* _DEBUG _/
_CSTD free(Myptr);
#endif / _DEBUG */

    _Myptr = 0;
    }

So the source code is calling the malloc() and free() shims, but the free()
gets inlined in the binary.

*** TODO how solve? just cut off after N errors of this type?

I don't think we want to try and auto-detect inlining of free(), so I
propose that after N errors (a low default value: maybe 5) of this
mismatch type we stop reporting them with a message about potential
inlining? This app is after all built without following our
recommendations of turning off inlining. However, you could imagine a
3rd-party dll whose build process the app has no control over.

[derekbruening]

From zhao...@google.com on April 29, 2014 12:17:14

N cut-off might be the only solution if we cannot enforce the not inline build.
It would be better if we can delay the report, i.e., we only report the mismatch error if we see fewer than N mismatch at the end of execution.

Also, do we want a per-module filtering, i.e., if the mismatch from the same module?
Because different module might build the code differently.

[derekbruening]

From bruen...@google.com on April 29, 2014 15:15:03

How about: do not report C vs Win mismatch errors when libc is static:
i.e., only enable such errors for the malloc routines in msvc* dll.

How impl that?
Either:

A) Add edata.check_winapi_mismatch = module_imports_from_msvc(mod) and pass
to alloc_replace, who then has to make new routines replace_free_nomatch
and replace_malloc_nomatch (and replace_malloc_usable_size and
replace_realloc and replace_calloc: and we can't easily share code b/c
we don't want extra frames, so this is a little ugly).

B) At report time, look up whether the module should report or not.
But we might need to walk up several frames to find who we should look
up: skip over cur pc (replace_RtlFreeHeap) and kernel_.dll!_ (HeapFree) to
get to chrome.dll frame?

[derekbruening]

From derek.br...@gmail.com on April 29, 2014 18:10:26

This issue was closed by revision r1905 .

Status: Fixed