Menu
▾
▴
[Valgrind-users] Code memchecks clean, but core dumps under callgrind - help?
|
From: Dave S. <dgs...@nu...> - 2006-11-01 18:30:09
|
Hi Folks, First of all, I'd like to express my appreciation for valgrind and all its various tools. Valgrind has proven to be superior, in both performance and in support, to several commercial "code quality analysis" products we've tried. Thanks very, very much. Now on to my problem, which is annoying, and possibly disturbing. I'll describe it first, and give the details later. Any insight anyone can offer is much appreciated. I've just added a new capability into our product, which is a large, extremely mathematical C++ thing; valgrind / memcheck says the code is clean (no errors). Now I'm profiling the code with callgrind and kcachegrind (_seriously_ cool tools), running our product on a variety of scenarios to see how the runtime performance of the new code scales. On some scenarios (the simpler and less interesting), everything works fine. However, on more interesting scenarios, the program core dumps when run under callgrind. To emphasize the odd thing: it runs fine on its own, and memcheck finds no errors. Looking in the vgcore with GDB shows the core dump happening in the compiler-defined copy constructor of a perfectly innocuous POD class, so that's not helpful. Maybe it's a bug in callgrind. Maybe it's something really subtle in our code. Maybe it's an interaction between our compiler and OS. Maybe it's... ??? One thing I'm pretty sure it isn't, is running out of memory (a problem we occasionally have on really challenging data sets); peak memory usage is about 2%. One additional piece of information: I haven't verified this yet, but it looks like there's just a wee bit of difference in the floating point results between running it normally and running it under memcheck; we're talking a few units-in-last-place, or numbers that are extremely close to zero. I'm not panicking about this... yet... but it makes me nervous. Thanks for any ideas or input! Grungy details: System: uname -a gives Linux uranium 2.6.10numerica #3 SMP Wed Mar 16 11:03:17 MST 2005 i686 Intel(R) Xeon(TM) CPU 2.80GHz unknown GNU/Linux Compiler: GCC 3.4.6 Reading specs from /scratch/dgsteffen/local/lib/gcc/i686-pc-linux-gnu/3.4.6/specs Configured with: ../gcc-3.4.6/configure --prefix=/scratch/dgsteffen/local Thread model: posix gcc version 3.4.6 Compile options: -ansi -pipe -fPIC -ftemplate-depth-150 -Wno-long-long -W -Wall -Werror -pedantic -Woverloaded-virtual -Wredundant-decls -ggdb -O0 -DUSE_ABORT -march=i686 -DBOOST_DISABLE_THREADS Result of running valgrind (memcheck): valgrind --tool=memcheck --leak-check=yes --suppressions=$HOME/.valg-supress -v MFAFusionTracker param/tracker.param.EXAMPLE -window.useWorkQueue false -IO.basePath MPT_B1_10sec. ==7122== Memcheck, a memory error detector. ==7122== Copyright (C) 2002-2006, and GNU GPL'd, by Julian Seward et al. ==7122== Using LibVEX rev 1658, a library for dynamic binary translation. ==7122== Copyright (C) 2004-2006, and GNU GPL'd, by OpenWorks LLP. ==7122== Using valgrind-3.2.1, a dynamic binary instrumentation framework. ==7122== Copyright (C) 2000-2006, and GNU GPL'd, by Julian Seward et al. ==7122== --7122-- Command line --7122-- MFAFusionTracker --7122-- param/tracker.param.EXAMPLE --7122-- -window.useWorkQueue --7122-- false --7122-- -IO.basePath --7122-- MPT_B1_10sec. --7122-- Startup, with flags: --7122-- --tool=memcheck --7122-- --leak-check=yes --7122-- --suppressions=/home/users/a/dgsteffen/.valg-supress --7122-- -v --7122-- Contents of /proc/version: --7122-- Linux version 2.6.10numerica (root@uranium) (gcc version 3.4.1 (Mandrakelinux 10.1 3.4.1-4mdk)) #3 SMP Wed Mar 16 11:03:17 MST 2005 --7122-- Arch and hwcaps: X86, x86-sse1-sse2 --7122-- Valgrind library directory: /scratch/dgsteffen/local/lib/valgrind --7122-- Reading syms from /lib/ld-2.3.3.so (0x4000000) --7122-- Reading syms from /home/users/a/dgsteffen/Numerica/ProfileWQ2/onir/MFAFusionTracker (0x8048000) --7122-- Reading syms from /scratch/dgsteffen/local/lib/valgrind/x86-linux/memcheck (0x38000000) --7122-- object doesn't have a dynamic symbol table --7122-- Reading suppressions file: /home/users/a/dgsteffen/.valg-supress --7122-- Reading suppressions file: /scratch/dgsteffen/local/lib/valgrind/default.supp --7122-- REDIR: 0x40100D0 (index) redirected to 0x38022D2F (vgPlain_x86_linux_REDIR_FOR_index) --7122-- Reading syms from /scratch/dgsteffen/local/lib/valgrind/x86-linux/vgpreload_core.so (0x4016000) --7122-- Reading syms from /scratch/dgsteffen/local/lib/valgrind/x86-linux/vgpreload_memcheck.so (0x4018000) ==7122== WARNING: new redirection conflicts with existing -- ignoring it --7122-- new: 0x040100D0 (index ) R-> 0x0401B180 index --7122-- REDIR: 0x40102F0 (strlen) redirected to 0x401B400 (strlen) --7122-- Reading syms from /scratch/dgsteffen/local/lib/libg2c.so.0.0.0 (0x401F000) --7122-- Reading syms from /usr/lib/libstdc++.so.5.0.6 (0x403D000) --7122-- Reading syms from /lib/tls/libm-2.3.3.so (0x410C000) --7122-- object doesn't have a symbol table --7122-- Reading syms from /scratch/dgsteffen/local/lib/libgcc_s.so.1 (0x412F000) --7122-- Reading syms from /lib/tls/libc-2.3.3.so (0x4138000) --7122-- object doesn't have a symbol table --7122-- REDIR: 0x41A0D70 (rindex) redirected to 0x401B060 (rindex) --7122-- REDIR: 0x41A04E0 (strcpy) redirected to 0x401B440 (strcpy) --7122-- REDIR: 0x41A2020 (memcpy) redirected to 0x401B790 (memcpy) --7122-- REDIR: 0x41A0A70 (strnlen) redirected to 0x401B3B0 (strnlen) --7122-- REDIR: 0x40D3C80 (operator new[](unsigned)) redirected to 0x4019E93 (operator new[](unsigned)) --7122-- REDIR: 0x40D3B30 (operator new(unsigned)) redirected to 0x4019A29 (operator new(unsigned)) --7122-- REDIR: 0x419A960 (malloc) redirected to 0x401966C (malloc) --7122-- REDIR: 0x41A09C0 (strlen) redirected to 0x401B3E0 (strlen) --7122-- REDIR: 0x40D2570 (operator delete(void*)) redirected to 0x401A4D5 (operator delete(void*)) --7122-- REDIR: 0x40D25D0 (operator delete[](void*)) redirected to 0x401A835 (operator delete[](void*)) --7122-- REDIR: 0x419AD50 (free) redirected to 0x401A205 (free) --7122-- REDIR: 0x41A1AC0 (memmove) redirected to 0x401BDA0 (memmove) --7122-- REDIR: 0x41A1B20 (memset) redirected to 0x401BD80 (memset) --7122-- REDIR: 0x41A1640 (memchr) redirected to 0x401B760 (memchr) --7122-- REDIR: 0x419AE30 (realloc) redirected to 0x401AB2A (realloc) WARNING: [pid 7122][components/util/io/LogFile.C:16] Channel MDPR is being used without being set up. No output will be written. ==7122== ==7122== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 21 from 1) --7122-- --7122-- supp: 21 Ubuntu-stripped-ld.so ==7122== malloc/free: in use at exit: 16,527,800 bytes in 111 blocks. ==7122== malloc/free: 40,399,006 allocs, 40,398,895 frees, 248,575,492 bytes allocated. ==7122== ==7122== searching for pointers to 111 not-freed blocks. ==7122== checked 17,278,128 bytes. ==7122== ==7122== LEAK SUMMARY: ==7122== definitely lost: 0 bytes in 0 blocks. ==7122== possibly lost: 0 bytes in 0 blocks. ==7122== still reachable: 0 bytes in 0 blocks. ==7122== suppressed: 16,527,800 bytes in 111 blocks. ==7122== Reachable blocks (those to which a pointer was found) are not shown. ==7122== To see them, rerun with: --show-reachable=yes --7122-- memcheck: sanity checks: 1078308 cheap, 43133 expensive --7122-- memcheck: auxmaps: 0 auxmap entries (0k, 0M) in use --7122-- memcheck: auxmaps: 0 searches, 0 comparisons --7122-- memcheck: SMs: n_issued = 4292 (68672k, 67M) --7122-- memcheck: SMs: n_deissued = 1689 (27024k, 26M) --7122-- memcheck: SMs: max_noaccess = 65535 (1048560k, 1023M) --7122-- memcheck: SMs: max_undefined = 14 (224k, 0M) --7122-- memcheck: SMs: max_defined = 123 (1968k, 1M) --7122-- memcheck: SMs: max_non_DSM = 2639 (42224k, 41M) --7122-- memcheck: max sec V bit nodes: 32 (1k, 0M) --7122-- memcheck: set_sec_vbits8 calls: 63 (new: 32, updates: 31) --7122-- memcheck: max shadow mem size: 42529k, 41M --7122-- translate: fast SP updates identified: 162,860 ( 87.9%) --7122-- translate: generic_known SP updates identified: 18,910 ( 10.2%) --7122-- translate: generic_unknown SP updates identified: 3,318 ( 1.7%) --7122-- tt/tc: 224,469,777 tt lookups requiring 849,011,527 probes --7122-- tt/tc: 224,469,777 fast-cache updates, 4 flushes --7122-- transtab: new 58,725 (1,479,551 -> 27,590,817; ratio 186:10) [0 scs] --7122-- transtab: dumped 0 (0 -> ??) --7122-- transtab: discarded 8 (162 -> ??) --7122-- scheduler: 107,830,813,170 jumps (bb entries). --7122-- scheduler: 1,078,308/307,526,143 major/minor sched events. --7122-- sanity: 1078309 cheap, 43133 expensive checks. --7122-- exectx: 30,011 lists, 9,198 contexts (avg 0 per list) --7122-- exectx: 80,789,174 searches, 86,348,323 full compares (1,068 per 1000) --7122-- exectx: 110 cmp2, 55 cmp4, 0 cmpAll Now, here's what happens (fairly quickly) when I run it with callgrind: callgrind --dump-instr=yes --dump-line=yes -v MFAFusionTracker param/tracker.param.EXAMPLE -window.useWorkQueue false -IO.basePath MPT_B1_10sec. ==26931== Callgrind, a call-graph generating cache profiler. ==26931== Copyright (C) 2002-2006, and GNU GPL'd, by Josef Weidendorfer et al. ==26931== Using LibVEX rev 1658, a library for dynamic binary translation. ==26931== Copyright (C) 2004-2006, and GNU GPL'd, by OpenWorks LLP. ==26931== Using valgrind-3.2.1, a dynamic binary instrumentation framework. ==26931== Copyright (C) 2000-2006, and GNU GPL'd, by Julian Seward et al. ==26931== --26931-- Command line --26931-- MFAFusionTracker --26931-- param/tracker.param.EXAMPLE --26931-- -window.useWorkQueue --26931-- false --26931-- -IO.basePath --26931-- MPT_B1_10sec. --26931-- Startup, with flags: --26931-- --tool=callgrind --26931-- --dump-instr=yes --26931-- --dump-line=yes --26931-- -v --26931-- Contents of /proc/version: --26931-- Linux version 2.6.10numerica (root@uranium) (gcc version 3.4.1 (Mandrakelinux 10.1 3.4.1-4mdk)) #3 SMP Wed Mar 16 11:03:17 MST 2005 --26931-- Arch and hwcaps: X86, x86-sse1-sse2 --26931-- Valgrind library directory: /scratch/dgsteffen/local/lib/valgrind ==26931== For interactive control, run 'callgrind_control -h'. --26931-- Reading syms from /lib/ld-2.3.3.so (0x4000000) --26931-- Reading syms from /home/users/a/dgsteffen/Numerica/ProfileWQ2/onir/MFAFusionTracker (0x8048000) --26931-- Reading syms from /scratch/dgsteffen/local/lib/valgrind/x86-linux/callgrind (0x38000000) --26931-- object doesn't have a dynamic symbol table --26931-- Code check found runtime_resolve: ld-2.3.3.so +0xAB70=0x400AB70, length 24 --26931-- Reading syms from /scratch/dgsteffen/local/lib/valgrind/x86-linux/vgpreload_core.so (0x4016000) --26931-- Reading syms from /scratch/dgsteffen/local/lib/libg2c.so.0.0.0 (0x4018000) --26931-- Reading syms from /usr/lib/libstdc++.so.5.0.6 (0x4037000) --26931-- Reading syms from /lib/tls/libm-2.3.3.so (0x4106000) --26931-- object doesn't have a symbol table --26931-- Reading syms from /scratch/dgsteffen/local/lib/libgcc_s.so.1 (0x4129000) --26931-- Reading syms from /lib/tls/libc-2.3.3.so (0x4132000) --26931-- object doesn't have a symbol table --26931-- Symbol match: found runtime_resolve: ld-2.3.3.so +0xAB70=0x400AB70 ==26931== ==26931== Process terminating with default action of signal 6 (SIGABRT): dumping core ==26931== at 0x4159805: raise (in /lib/tls/libc-2.3.3.so) ==26931== by 0x415B1E8: abort (in /lib/tls/libc-2.3.3.so) ==26931== by 0x40CD7C4: __cxxabiv1::__terminate(void (*)()) (in /usr/lib/libstdc++.so.5.0.6) ==26931== by 0x40CD801: std::terminate() (in /usr/lib/libstdc++.so.5.0.6) ==26931== by 0x40CD981: __cxa_throw (in /usr/lib/libstdc++.so.5.0.6) ==26931== by 0x40CDBC2: operator new(unsigned) (in /usr/lib/libstdc++.so.5.0.6) ==26931== by 0x817BA03: boost::any::any<float>(float const&) (any.hpp:33) ==26931== by 0x817B9D9: Numerica::PropertyWrapper::PropertyWrapper<float>(float) (Properties.h:64) ==26931== by 0x817B968: void Numerica::Properties::setProperty<float>(std::string const&, float) (Properties.h:115) ==26931== by 0x81797A4: void Numerica::ExternalProperties::setExternalProperty<float>(std::string const&, float) (ExternalProperties.h:53) ==26931== by 0x81782D6: Numerica::ONIRMessageTranslator::translateReturn(Messages::ReturnMsg const&, boost::shared_ptr<Numerica::ONIRSensorCommon> const&, double, Numerica::Matrix const&, Messages::FrameMsgheader const&) (ONIRMessageTranslator.C:181) ==26931== by 0x8176FA9: Numerica::ONIRMessageTranslator::translateFrameMsg(Messages::FrameMsg const&, double, Numerica::Matrix const&) (ONIRMessageTranslator.C:27) ==26931== --26931-- Start dumping at BB 243901199 (Prg.Term.)... --26931-- Dump to /home/users/a/dgsteffen/Numerica/ProfileWQ2/onir/callgrind.out.26931 --26931-- Dumping done. --26931-- --26931-- Distinct objects: 7 --26931-- Distinct files: 363 --26931-- Distinct fns: 8360 --26931-- Distinct contexts:8360 --26931-- Distinct BBs: 38629 --26931-- Cost entries: 39229 (Chunks 1) --26931-- Distinct BBCCs: 41210 --26931-- Distinct JCCs: 22217 --26931-- Distinct skips: 3629 --26931-- BB lookups: 38629 --26931-- With full debug info: 85% (32861) --26931-- With file/line debug info: 0% (53) --26931-- With fn name debug info: 10% (4044) --26931-- With no debug info: 4% (1671) --26931-- BBCC Clones: 2581 --26931-- BBs Retranslated: 0 --26931-- Distinct instrs: 194073 --26931-- --26931-- LRU Contxt Misses: 8360 --26931-- LRU BBCC Misses: 2459 --26931-- LRU JCC Misses: 31208 --26931-- BBs Executed: 243901200 --26931-- Calls: 72958647 --26931-- CondJMP followed: 0 --26931-- Boring JMPs: 0 --26931-- Recursive calls: 621849 --26931-- Returns: 72958647 --26931-- ==26931== Events : Ir ==26931== Collected : 1094941170 ==26931== ==26931== I refs: 1,094,941,170 --26931-- translate: fast SP updates identified: 0 ( --%) --26931-- translate: generic_known SP updates identified: 0 ( --%) --26931-- translate: generic_unknown SP updates identified: 0 ( --%) --26931-- tt/tc: 1,667,236 tt lookups requiring 7,257,791 probes --26931-- tt/tc: 1,667,236 fast-cache updates, 2 flushes --26931-- transtab: new 38,629 (610,096 -> 4,486,433; ratio 73:10) [0 scs] --26931-- transtab: dumped 0 (0 -> ??) --26931-- transtab: discarded 0 (0 -> ??) --26931-- scheduler: 243,901,199 jumps (bb entries). --26931-- scheduler: 2,439/1,633,133 major/minor sched events. --26931-- sanity: 2440 cheap, 98 expensive checks. --26931-- exectx: 30,011 lists, 0 contexts (avg 0 per list) --26931-- exectx: 0 searches, 0 full compares (0 per 1000) --26931-- exectx: 0 cmp2, 0 cmp4, 0 cmpAll Aborted Any thoughts, ideas, hints, or even hunches and uneducated guesses, would be welcome. Thanks! ---------------------------------------------------------------------- Dave Steffen, Ph.D. Software Engineer IV Disobey this command! Numerica Corporation ph (970) 419-8343 x27 fax (970) 223-6797 - Douglas Hofstadter dgs...@nu... |
