invalid heap arg errors in msvcp100d.dll suddenly raised on chromium tests

[derekbruening]

From [email protected] on January 29, 2014 12:00:22

After getting our win7-cr bot green, it went back red with a bunch of
invalid heap arg errors in msvcp100d.dll: http://build.chromium.org/p/client.drmemory/builders/win7-cr/builds/4910/steps/Chromium%20%27url%27%20tests/logs/stdio The errors are like this and happen on just about every test:

Dr.M Error #1: INVALID HEAP ARGUMENT to free 0x03471a60
Dr.M # 0 replace_free [e:\b\build\slave\win-builder\drmemory\common\alloc_replace.c:2352]
Dr.M # 1 MSVCP100D.dll!std::_Yarn<>::_Tidy +0x1e (0x6cca247f <MSVCP100D.dll+0x1247f>)
Dr.M # 2 MSVCP100D.dll!std::_Yarn<>::_Yarn<> +0x10 (0x6cca1731 <MSVCP100D.dll+0x11731>)
Dr.M # 3 MSVCP100D.dll!std::_Locinfo::_Locinfo +0x49 (0x6cc9bb7a <MSVCP100D.dll+0xbb7a>)
Dr.M # 4 MSVCP100D.dll!std::num_put<>::_Getcat +0xe4 (0x6ccafa05 <MSVCP100D.dll+0x1fa05>)
Dr.M # 5 MSVCP100D.dll!std::time_put<>::do_put +0x41ee (0x6ccd649f <MSVCP100D.dll+0x4649f>)
Dr.M # 6 MSVCP100D.dll!std::basic_ostream<>::operator<< +0x85 (0x6ccbc2a6 <MSVCP100D.dll+0x2c2a6>)
Dr.M # 7 testing::Message::operator<<<> [testing\gtest\include\gtest\gtest-message.h:131]
Dr.M # 8 testing::internal::StreamableToString<> [testing\gtest\include\gtest\gtest-message.h:244]
Dr.M # 9 testing::FormatCountableNoun [testing\gtest\src\gtest.cc:2382]
Dr.M #10 testing::FormatTestCaseCount [testing\gtest\src\gtest.cc:2392]
Dr.M #11 testing::internal::PrettyUnitTestResultPrinter::OnTestIterationStart [testing\gtest\src\gtest.cc:2643]
Dr.M #12 testing::internal::TestEventRepeater::OnTestIterationStart [testing\gtest\src\gtest.cc:2888]
Dr.M #13 testing::internal::UnitTestImpl::RunAllTests [testing\gtest\src\gtest.cc:4051]
Dr.M #14 testing::internal::HandleExceptionsInMethodIfSupported<> [testing\gtest\src\gtest.cc:2045]
Dr.M Note: @0:00:00.889 in thread 196

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

[derekbruening]

From [email protected] on January 31, 2014 15:46:15

Like issue #1427 , this is due to symcache problems -- but it seems to be
multiple files this time, and they cropped up pretty quickly (in just a few
runs).

I can repro only by pointing at that symcache dir:

$ unpacked/bin/drmemory.exe -symcache_dir C:/Users//AppData/LocalLow/drmemory.symcache -light ../../win7-cr-builder/build/src/out/Debug/url_unittests.exe --gtest_filter=GURLTest.Types --single-process-tests

freshly made:
$ ls
ADVAPI32.dll.txt icuuc.dll.txt msvcrt.dll.txt PSAPI.DLL.txt url_unittests.exe.txt
base.dll.txt IMM32.dll.txt NETAPI32.dll.txt RPCRT4.dll.txt USER32.dll.txt
base_i18n.dll.txt KERNEL32.dll.txt netutils.dll.txt SECHOST.dll.txt USERENV.dll.txt
CRYPTBASE.dll.txt KERNELBASE.dll.txt NSI.dll.txt SHELL32.dll.txt USP10.dll.txt
drmemorylib.dll.txt LPK.dll.txt ntdll.dll.txt SHLWAPI.dll.txt VERSION.dll.txt
dynamorio.dll.txt MSCTF.dll.txt ole32.dll.txt srvcli.dll.txt WINMM.dll.txt
GDI32.dll.txt MSVCP100D.dll.txt OLEAUT32.dll.txt SspiCli.dll.txt wkscli.dll.txt
icui18n.dll.txt MSVCR100D.dll.txt profapi.dll.txt url_lib.dll.txt WS2_32.dll.txt

$ diff -qr ../drmemory.i1428.copy/ ./ | grep -v 'Only in ../drm'
Files ../drmemory.i1428.copy/base.dll.txt and ./base.dll.txt differ
Files ../drmemory.i1428.copy/GDI32.dll.txt and ./GDI32.dll.txt differ
Files ../drmemory.i1428.copy/IMM32.dll.txt and ./IMM32.dll.txt differ
Files ../drmemory.i1428.copy/KERNEL32.dll.txt and ./KERNEL32.dll.txt differ
Files ../drmemory.i1428.copy/KERNELBASE.dll.txt and ./KERNELBASE.dll.txt differ
Files ../drmemory.i1428.copy/LPK.dll.txt and ./LPK.dll.txt differ
Files ../drmemory.i1428.copy/MSVCR100D.dll.txt and ./MSVCR100D.dll.txt differ
Files ../drmemory.i1428.copy/NSI.dll.txt and ./NSI.dll.txt differ
Files ../drmemory.i1428.copy/PSAPI.DLL.txt and ./PSAPI.DLL.txt differ
Files ../drmemory.i1428.copy/RPCRT4.dll.txt and ./RPCRT4.dll.txt differ
Files ../drmemory.i1428.copy/srvcli.dll.txt and ./srvcli.dll.txt differ
Files ../drmemory.i1428.copy/USER32.dll.txt and ./USER32.dll.txt differ
Files ../drmemory.i1428.copy/USP10.dll.txt and ./USP10.dll.txt differ
Files ../drmemory.i1428.copy/wkscli.dll.txt and ./wkscli.dll.txt differ
Files ../drmemory.i1428.copy/WS2_32.dll.txt and ./WS2_32.dll.txt differ

GDI32:
a lot like this:
< operator delete,0x67110

operator delete,0x0

IMM32, kernelbase, LPK have some where the bad one has a non-zero value and
the fresh one has zero.

Check this one out:

diff -r drmemory.i1428.copy/MSVCR100D.dll.txt test.symcache/MSVCR100D.dll.txt
2c2
< 1788,1505104,11320643484190900224,11320643484190900224,1543614,1307754039,1519616

  1765,1505104,11320643484190900224,11320643484190900224,1543614,1307754039,1519616

7d6
< posix_memalign,0x0
9a9

posix_memalign,0x0
24c24
< _CrtDbgReportW,0x1151e0

---

_CrtDbgReportW,0x115670
44c44
< operator delete[],0x0

---

operator delete[],0x107ee0
57c57,58
< operator new,0x488f0

---

operator new,0x475f0
,0x107da0
63c64
< operator delete,0x48900

---

operator delete,0x116570
68c69
< _malloc_dbg,0x31e4c6

---

_malloc_dbg,0x116660

$ ls -a ../drmemory.logs/symbols/
. ..
$ ls -l MSVCR100D.dll.txt
-rwx------ 1 1788 Jan 29 02:10 MSVCR100D.dll.txt
$ find /cygdrive/c -iname msvcr100d.i386.pdb
/cygdrive/c/Windows/symbols/dll/msvcr100d.i386.pdb
$ ls -l /cygdrive/c/Windows/symbols/dll/msvcr100d.i386.pdb
-rwx------+ 1 SYSTEM SYSTEM 7900160 Jun 10 2011 /cygdrive/c/Windows/symbols/dll/msvcr100d.i386.pdb
$ find /cygdrive/c -iname gdi32.i386.pdb

windbg thinks that dll matches this:
% ll ~/symbols/msvcr100d.i386.pdb/EFFAF8EBABC3479683B82EEE5B6EA9111/msvcr100d.i386.pdb
-rwx------+ 1 Domain Users 1346560 Jun 12 2011 /c/src/symbols/msvcr100d.i386.pdb/EFFAF8EBABC3479683B82EEE5B6EA9111/msvcr100d.i386.pdb

0:000> lm
start end module name
10200000 10373000 msvcr100d (private pdb symbols) c:\src\drmemory\bugs\cygdrive\c\windows\syswow64\msvcr100d.i386.pdb
0:000> x msvcr100d!_malloc_dbg
10316660 msvcr100d!_malloc_dbg (unsigned int, int, char _, int)
0:000> x msvcr100d!_CrtDbgReportW
10315670 msvcr100d!_CrtDbgReportW (int, unsigned short *, int, unsigned short *, unsigned short *)
103151e0 msvcr100d!CrtDbgReportW (int, wchar_t *, int, wchar_t *, wchar_t *)
0:000> x msvcr100d!operator delete
10316570 msvcr100d!operator delete (void *)
10245940 msvcr100d!operator delete (void *, void *)
10281540 msvcr100d!operator delete (void *, class _ConcRTNewMoniker, char *, int)
10307ee0 msvcr100d!operator delete[](void *)

0:000> .sympath c:\src\symbols
Symbol search path is: c:\src\symbols
Expanded Symbol search path is: c:\src\symbols
0:000> .reload /f /i msvcr100d.dll
0:000> lm
start end module name
10200000 10373000 msvcr100d (pdb symbols) c:\src\symbols\msvcr100d.i386.pdb\EFFAF8EBABC3479683B82EEE5B6EA9111\msvcr100d.i386.pdb
0:000> x msvcr100d!operator delete*
10307ee0 msvcr100d!operator delete[](no parameter info)
10316570 msvcr100d!operator delete ()
10245940 msvcr100d!operator delete ()
10281540 msvcr100d!operator delete ()
0:000> x msvcr100d!_malloc_dbg
10316660 msvcr100d!_malloc_dbg ()
0:000> x msvcr100d!_CrtDbgReportW
10315670 msvcr100d!_CrtDbgReportW ()
103151e0 msvcr100d!_CrtDbgReportW ()

Stumped.