|
From: Philippe W. <phi...@sk...> - 2009-04-29 22:40:15
|
I am working on improving the performance of the leak search client request
(which has a quadratic aspect).
To do this, I have a.o. modified m_hashtable.c
The performances of some perf tests (typically bz2) then decreases significantly.
After much digging and removing one by one all my changes, I have identified a
single change which degrades the performance of perf/bz2.
I have done all what I can to understand the reason and
I reaaaaaallllly cannot understand why.
The only remaining change is in the function VG_(HT_to_array).
Instead of computing *n_elems by following the chains,
I am doing the following assignment:
*n_elems = table->n_elements;
(as the current nr of elements in the table is maintained, there is no need
to recompute it).
By which miracle replacing a loop on all chains by a single assignment can
degrade the performance of perf/bz2 is a real mystery to me.
Moreover, as far as I understand, the VG_(HT_to_array) is even not called
by perf/bz2 !!!!
(I have added a trace in HT_to_array, and effectively,
the below code is called only if --leak-check=yes is given. I think
running the memcheck performance test does not do leak-check.
This behaviour is reproductible: if I am
changing back the code and does
make; make install; perl perf/vgperf perf/bz2
it is faster with the loop than with the assignment !
I have compared between a SVN unmodified (9680 VEX 1888), and the same version with only the below
change, here is what it gives:
nice -n -20 perl perf/vg_perf --tools=memcheck --vg=../valgrind_elem --vg=../valgrind_orig --reps=5 perf/bz2
-- bz2 --
bz2 valgrind_elem:1.12s me:22.9s (20.5x, -----)
bz2 valgrind_orig:1.12s me:20.2s (18.0x, 12.1%)
== 1 programs, 2 timings =================
I have absolutely no clue. It looks like removing the loop changes
whatever which then makes the whole thing slower.
I have also run the modified and the orig version with debugging
and I have included below the two trace files.
I see that some addresses such as stack are different
(maybe due to address space randomisation ?) but apart of that, no difference.
[philippe@soleil valgrind_elem]$ ../install_elem/bin/valgrind --leak-check=no -d -d -d perf/bz2 > bz2_elem.out 2>&1
[philippe@soleil valgrind_elem]$ ../install_orig/bin/valgrind --leak-check=no -d -d -d perf/bz2 > bz2_orig.out 2>&1
[philippe@soleil valgrind_elem]$
All this has been done on
fedora 10
Linux soleil 2.6.27.21-170.2.56.fc10.i686 #1 SMP Mon Mar 23 23:37:54 EDT 2009 i686 i686 i386 GNU/Linux
processor : 1
vendor_id : GenuineIntel
cpu family : 15
model : 2
model name : Intel(R) Pentium(R) 4 CPU 3.00GHz
stepping : 9
cpu MHz : 3000.000
cache size : 512 KB
VgHashNode** VG_(HT_to_array) ( VgHashTable table, /*OUT*/ UInt* n_elems )
{
UInt i, j;
VgHashNode** arr;
VgHashNode* node;
#ifdef ihavenocluewhytheloopisfaster
*n_elems = 0;
for (i = 0; i < table->n_chains; i++) {
for (node = table->chains[i]; node != NULL; node = node->next) {
(*n_elems)++;
}
}
#endif
*n_elems = table->n_elements; //<<<<<<<< this replaces the above assign and loop.
if (*n_elems == 0)
return NULL;
arr = VG_(malloc)( "hashtable.Hta.1", *n_elems * sizeof(VgHashNode*) );
j = 0;
for (i = 0; i < table->n_chains; i++) {
for (node = table->chains[i]; node != NULL; node = node->next) {
arr[j++] = node;
}
}
vg_assert(j == *n_elems);
return arr;
}
--15498:1:debuglog DebugLog system started by Stage 1, level 3 logging requested
--15498:1:launcher no tool requested, defaulting to 'memcheck'
--15498:1:launcher selected platform 'x86-linux'
--15498:1:launcher launching /home/philippe/valq/install_elem/lib/valgrind/memcheck-x86-linux
--15498:1:debuglog DebugLog system started by Stage 2 (main), level 3 logging requested
--15498:1:main Welcome to Valgrind version 3.5.0.SVN debug logging
--15498:1:main Checking current stack is plausible
--15498:1:main Checking initial stack was noted
--15498:1:main Starting the address space manager
--15498:2:aspacem sp_at_startup = 0x00bf9bed80 (supplied)
--15498:2:aspacem minAddr = 0x0004000000 (computed)
--15498:2:aspacem maxAddr = 0x00bf9bdfff (computed)
--15498:2:aspacem cStart = 0x0004000000 (computed)
--15498:2:aspacem vStart = 0x0061cdf000 (computed)
--15498:2:aspacem suggested_clstack_top = 0x00be9befff (computed)
--15498:2:aspacem <<< SHOW_SEGMENTS: Initial layout (5 segments, 0 segnames)
--15498:2:aspacem 0: RSVN 0000000000-0003ffffff 64m ----- SmFixed
--15498:2:aspacem 1: 0004000000-0061cdefff 1500m
--15498:2:aspacem 2: RSVN 0061cdf000-0061cdffff 4096 ----- SmFixed
--15498:2:aspacem 3: 0061ce0000-00bf9bdfff 1500m
--15498:2:aspacem 4: RSVN 00bf9be000-00ffffffff 1030m ----- SmFixed
--15498:2:aspacem >>>
--15498:2:aspacem Reading /proc/self/maps
--15498:2:aspacem <<< SHOW_SEGMENTS: With contents of /proc/self/maps (12 segments, 1 segnames)
--15498:2:aspacem ( 0) /home/philippe/valq/install_elem/lib/valgrind/memcheck-x86-linux
--15498:2:aspacem 0: RSVN 0000000000-000040afff 4239360 ----- SmFixed
--15498:2:aspacem 1: ANON 000040b000-000040bfff 4096 r-x--
--15498:2:aspacem 2: RSVN 000040c000-0003ffffff 59m ----- SmFixed
--15498:2:aspacem 3: 0004000000-0037ffffff 832m
--15498:2:aspacem 4: FILE 0038000000-00381c6fff 1863680 r-x-- d=0xfd00 i=2648126 o=0 (0)
--15498:2:aspacem 5: FILE 00381c7000-00381c8fff 8192 rw--- d=0xfd00 i=2648126 o=1859584 (0)
--15498:2:aspacem 6: ANON 00381c9000-00388e9fff 7475200 rw---
--15498:2:aspacem 7: 00388ea000-0061cdefff 659m
--15498:2:aspacem 8: RSVN 0061cdf000-0061cdffff 4096 ----- SmFixed
--15498:2:aspacem 9: 0061ce0000-00bf9aafff 1500m
--15498:2:aspacem 10: ANON 00bf9ab000-00bf9bffff 86016 rw---
--15498:2:aspacem 11: RSVN 00bf9c0000-00ffffffff 1030m ----- SmFixed
--15498:2:aspacem >>>
--15498:1:main Address space manager is running
--15498:1:main Starting the dynamic memory manager
--15498:1:mallocfr newSuperblock at 0x61CE0000 (pszB 4194288) owner VALGRIND/tool
--15498:1:main Dynamic memory manager is running
--15498:1:main Initialise m_debuginfo
--15498:1:main Getting stage1's name
--15498:1:main Get hardware capabilities ...
--15498:1:main ... arch = X86, hwcaps = x86-sse1-sse2
--15498:1:main Getting the working directory at startup
--15498:1:main ... /home/philippe/valq/valgrind_elem
--15498:1:main Split up command line
--15498:1:main (early_) Process Valgrind's command line options
--15498:1:main Create initial image
--15498:1:initimg Loading client
--15498:1:initimg Setup client env
--15498:2:initimg preload_string:
--15498:2:initimg
"/home/philippe/valq/install_elem/lib/valgrind/vgpreload_core-x86-linux.so:/home/philippe/valq/install_elem/lib/valgrind/vgpreload_memcheck-x86-linux.so"
--15498:1:initimg Setup client stack: size will be 10485760
--15498:2:initimg stomping auxv entry 31
--15498:2:initimg Client info: initial_IP=0x26E850 initial_TOC=0x0 brk_base=0x8431000
--15498:2:initimg Client info: initial_SP=0xBE9BE400 max_stack_size=10485760
--15498:1:initimg Setup client data (brk) segment
--15498:1:main Setup file descriptors
--15498:1:main Create fake /proc/<pid>/cmdline
--15498:1:main Initialise the tool part 1 (pre_clo_init)
--15498:1:mallocfr newSuperblock at 0x620E0000 (pszB 1048560) owner VALGRIND/exectxt
--15498:1:main Print help and quit, if requested
--15498:1:main (main_) Process Valgrind's command line options, setup logging
--15498:1:mallocfr newSuperblock at 0x621E0000 (pszB 1048560) owner VALGRIND/core
--15498:1:main Print the preamble...
==15498== Memcheck, a memory error detector.
==15498== Copyright (C) 2002-2009, and GNU GPL'd, by Julian Seward et al.
==15498== Using LibVEX rev 1888, a library for dynamic binary translation.
==15498== Copyright (C) 2004-2009, and GNU GPL'd, by OpenWorks LLP.
==15498== Using valgrind-3.5.0.SVN, a dynamic binary instrumentation framework.
==15498== Copyright (C) 2000-2009, and GNU GPL'd, by Julian Seward et al.
==15498== For more details, rerun with: -v
==15498==
--15498:1:main ...finished the preamble
--15498:1:main Initialise the tool part 2 (post_clo_init)
--15498:1:main Initialise TT/TC
--15498:2:transtab cache: 8 sectors of 29772288 bytes each = 238178304 total
--15498:2:transtab table: 524168 total entries, max occupancy 419328 (80%)
--15498:1:main Initialise redirects
--15498:1:mallocfr newSuperblock at 0x6235B000 (pszB 1048560) owner VALGRIND/dinfo
--15498:1:main Load initial debug info
--15498:2:transtab discard_translations(0x287440, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 14
--15498:2:transtab discard_translations(0x3803d2c3, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 122
--15498:1:mallocfr newSuperblock at 0x6245B000 (pszB 1048560) owner VALGRIND/dinfo
--15498:1:mallocfr newSuperblock at 0x6255B000 (pszB 1048560) owner VALGRIND/dinfo
--15498:1:mallocfr newSuperblock at 0x6265B000 (pszB 2052080) owner VALGRIND/dinfo
--15498:1:redir transfer ownership V -> C of 0x3803d000 .. 0x3803dfff
--15498:1:main Initialise scheduler (phase 1)
--15498:1:sched sched_init_phase1
--15498:1:main Tell tool about initial permissions
--15498:2:main tell tool about 000026e000-000028dfff r-x
--15498:2:main tell tool about 000028f000-0000290fff rw-
--15498:2:main tell tool about 0008048000-000805bfff r-x
--15498:2:main tell tool about 000805c000-000805cfff rw-
--15498:2:main tell tool about 000805d000-0008430fff rw-
--15498:2:main tell tool about 0008431000-0008431fff rwx
--15498:2:main tell tool about 003803d000-003803dfff r-x
--15498:2:main tell tool about 00be9be000-00be9befff rwx
--15498:2:main mark stack inaccessible 00be9be000-00be9be3ff
--15498:1:main Initialise scheduler (phase 2)
--15498:1:sched sched_init_phase2: tid_main=1, cls_end=0xbe9befff, cls_sz=10485760
--15498:1:main Finalise initial image
--15498:1:main Initialise signal management
--15498:1:main Load suppressions
--15498:2:stacks register 0xBE9BE000-0xBE9BEFFF as stack 0
--15498:1:main
--15498:1:main
--15498:1:aspacem <<< SHOW_SEGMENTS: Memory layout at client startup (28 segments, 4 segnames)
--15498:1:aspacem ( 0) /home/philippe/valq/install_elem/lib/valgrind/memcheck-x86-linux
--15498:1:aspacem ( 1) /home/philippe/valq/valgrind_elem/perf/bz2
--15498:1:aspacem ( 2) /lib/ld-2.9.so
--15498:1:aspacem 0: RSVN 0000000000-000026dfff 2547712 ----- SmFixed
--15498:1:aspacem 1: file 000026e000-000028dfff 131072 r-x-- d=0xfd00 i=1155478 o=0 (2)
--15498:1:aspacem 2: RSVN 000028e000-000028efff 4096 ----- SmFixed
--15498:1:aspacem 3: file 000028f000-0000290fff 8192 rw--- d=0xfd00 i=1155478 o=131072 (2)
--15498:1:aspacem 4: RSVN 0000291000-000040afff 1548288 ----- SmFixed
--15498:1:aspacem 5: ANON 000040b000-000040bfff 4096 r-x--
--15498:1:aspacem 6: RSVN 000040c000-0003ffffff 59m ----- SmFixed
--15498:1:aspacem 7: 0004000000-0008047fff 64m
--15498:1:aspacem 8: file 0008048000-000805bfff 81920 r-x-- d=0xfd00 i=2624338 o=0 (1)
--15498:1:aspacem 9: file 000805c000-000805cfff 4096 rw--- d=0xfd00 i=2624338 o=81920 (1)
--15498:1:aspacem 10: anon 000805d000-0008430fff 4014080 rw---
--15498:1:aspacem 11: anon 0008431000-0008431fff 4096 rwx--
--15498:1:aspacem 12: RSVN 0008432000-0008c30fff 8384512 ----- SmLower
--15498:1:aspacem 13: 0008c31000-0037ffffff 755m
--15498:1:aspacem 14: FILE 0038000000-003803cfff 249856 r-x-- d=0xfd00 i=2648126 o=0 (0)
--15498:1:aspacem 15: file 003803d000-003803dfff 4096 r-x-- d=0xfd00 i=2648126 o=249856 (0)
--15498:1:aspacem 16: FILE 003803e000-00381c6fff 1609728 r-x-- d=0xfd00 i=2648126 o=253952 (0)
--15498:1:aspacem 17: FILE 00381c7000-00381c8fff 8192 rw--- d=0xfd00 i=2648126 o=1859584 (0)
--15498:1:aspacem 18: ANON 00381c9000-00388e9fff 7475200 rw---
--15498:1:aspacem 19: 00388ea000-0061cdefff 659m
--15498:1:aspacem 20: RSVN 0061cdf000-0061cdffff 4096 ----- SmFixed
--15498:1:aspacem 21: ANON 0061ce0000-006286ffff 11m rwx--
--15498:1:aspacem 22: 0062870000-00bdfbefff 1463m
--15498:1:aspacem 23: RSVN 00bdfbf000-00be9bdfff 9m ----- SmUpper
--15498:1:aspacem 24: anon 00be9be000-00be9befff 4096 rwx--
--15498:1:aspacem 25: 00be9bf000-00bf9aafff 15m
--15498:1:aspacem 26: ANON 00bf9ab000-00bf9bffff 86016 rw---
--15498:1:aspacem 27: RSVN 00bf9c0000-00ffffffff 1030m ----- SmFixed
--15498:1:aspacem >>>
--15498:1:main
--15498:1:main
--15498:1:main Running thread 1
--15498:1:syswrap- entering VG_(main_thread_wrapper_NORETURN)
--15498:1:aspacem allocated thread stack at 0x62870000 size 81920
--15498:1:syswrap- run_a_thread_NORETURN(tid=1): pre-thread_wrapper
--15498:1:syswrap- thread_wrapper(tid=1): entry
--15498:1:transtab allocate sector 0
--15498:1:mallocfr newSuperblock at 0x649A9000 (pszB 65520) owner VALGRIND/ttaux
--15498:1:signals extending a stack base 0xbe9be000 down by 4096
--15498:2:stacks change stack 0 from 0xBE9BE000-0xBE9BEFFF to 0xBE9BD000-0xBE9BEFFF
--15498:2:transtab discard_translations(0x287610, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 14
--15498:2:transtab discard_translations(0x4007460, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 14
--15498:2:transtab discard_translations(0x287a00, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 15
--15498:2:transtab discard_translations(0x40081b0, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 16
--15498:1:mallocfr newSuperblock at 0x649C5000 (pszB 1048560) owner VALGRIND/dinfo
--15498:1:mallocfr newSuperblock at 0x64AC5000 (pszB 1048560) owner VALGRIND/dinfo
--15498:1:mallocfr newSuperblock at 0x64BC5000 (pszB 1048560) owner VALGRIND/dinfo
--15498:1:mallocfr newSuperblock at 0x64CC5000 (pszB 2052080) owner VALGRIND/dinfo
--15498:2:transtab discard_translations(0x2c1180, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 130
--15498:2:transtab discard_translations(0x4008680, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 16
--15498:2:transtab discard_translations(0x2c12b0, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 130
--15498:2:transtab discard_translations(0x40086f0, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 16
--15498:2:transtab discard_translations(0x2c1770, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 130
--15498:2:transtab discard_translations(0x4008760, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 16
--15498:2:transtab discard_translations(0x302010, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 4
--15498:2:transtab discard_translations(0x4004a80, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 9
--15498:2:transtab discard_translations(0x303480, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 6
--15498:2:transtab discard_translations(0x4004890, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 9
--15498:2:transtab discard_translations(0x303880, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 7
--15498:2:transtab discard_translations(0x4004940, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 9
--15498:2:transtab discard_translations(0x3042c0, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 8
--15498:2:transtab discard_translations(0x4005aa0, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 11
--15498:2:transtab discard_translations(0x304550, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 8
--15498:2:transtab discard_translations(0x4004780, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 8
--15498:2:transtab discard_translations(0x3063a0, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 12
--15498:2:transtab discard_translations(0x4004d30, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 9
--15498:2:transtab discard_translations(0x3066d0, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 12
--15498:2:transtab discard_translations(0x4006c80, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 13
--15498:2:transtab discard_translations(0x3068a0, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 13
--15498:2:transtab discard_translations(0x4004b90, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 9
--15498:2:transtab discard_translations(0x306ae0, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 13
--15498:2:transtab discard_translations(0x4004cd0, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 9
--15498:2:transtab discard_translations(0x306b80, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 13
--15498:2:transtab discard_translations(0x4006d90, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 13
--15498:2:transtab discard_translations(0x3072e0, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 14
--15498:2:transtab discard_translations(0x4007010, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 14
--15498:2:transtab discard_translations(0x307470, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 14
--15498:2:transtab discard_translations(0x40048d0, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 9
--15498:2:transtab discard_translations(0x307660, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 14
--15498:2:transtab discard_translations(0x40048b0, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 9
--15498:2:transtab discard_translations(0x307800, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 15
--15498:2:transtab discard_translations(0x4004790, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 8
--15498:2:transtab discard_translations(0x307a80, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 15
--15498:2:transtab discard_translations(0x4004770, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 8
--15498:2:transtab discard_translations(0x309af0, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 19
--15498:2:transtab discard_translations(0x4007210, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 14
--15498:2:transtab discard_translations(0x309ca0, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 19
--15498:2:transtab discard_translations(0x4007180, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 14
--15498:2:transtab discard_translations(0x309e10, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 19
--15498:2:transtab discard_translations(0x4007740, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 14
--15498:2:transtab discard_translations(0x309e80, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 19
--15498:2:transtab discard_translations(0x40074a0, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 14
--15498:2:transtab discard_translations(0x30a380, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 20
--15498:2:transtab discard_translations(0x4007440, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 14
--15498:2:transtab discard_translations(0x30a430, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 20
--15498:2:transtab discard_translations(0x4007400, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 14
--15498:2:transtab discard_translations(0x30a4f0, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 20
--15498:2:transtab discard_translations(0x40072f0, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 14
--15498:2:transtab discard_translations(0x30a5a0, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 20
--15498:2:transtab discard_translations(0x40076b0, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 14
--15498:2:transtab discard_translations(0x30a6b0, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 20
--15498:2:transtab discard_translations(0x4007570, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 14
--15498:2:transtab discard_translations(0x30a800, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 21
--15498:2:transtab discard_translations(0x4007090, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 14
--15498:2:transtab discard_translations(0x30bbe0, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 23
--15498:2:transtab discard_translations(0x4007860, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 15
--15498:2:transtab discard_translations(0x30bd80, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 23
--15498:2:transtab discard_translations(0x4008040, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 16
--15498:2:transtab discard_translations(0x30c060, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 24
--15498:2:transtab discard_translations(0x4008a70, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 17
--15498:2:transtab discard_translations(0x30c070, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 24
--15498:2:transtab discard_translations(0x40083b0, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 16
--15498:2:transtab discard_translations(0x30c0e0, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 24
--15498:2:transtab discard_translations(0x4008350, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 16
--15498:2:transtab discard_translations(0x30c140, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 24
--15498:2:transtab discard_translations(0x4008480, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 16
--15498:2:transtab discard_translations(0x30c2d0, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 24
--15498:2:transtab discard_translations(0x40080e0, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 16
--15498:2:transtab discard_translations(0x30c5e0, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 24
--15498:2:transtab discard_translations(0x4008890, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 17
--15498:2:transtab discard_translations(0x30c5f0, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 24
--15498:2:transtab discard_translations(0x40078b0, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 15
--15498:2:transtab discard_translations(0x30f060, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 30
--15498:2:transtab discard_translations(0x4008460, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 16
--15498:2:transtab discard_translations(0x30f130, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 30
--15498:2:transtab discard_translations(0x4008420, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 16
--15498:2:transtab discard_translations(0x38dc20, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 27
--15498:2:transtab discard_translations(0x4008990, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 17
--15498:2:transtab discard_translations(0x38dcb0, 1) req by redir_new_DebugInfo(from_addr)
--15498:2:transtab FAST, ec = 27
--15498:2:transtab discard_translations(0x4008a00, 1) req by redir_new_DebugInfo(to_addr)
--15498:2:transtab FAST, ec = 17
--15498:1:mallocfr newSuperblock at 0x64EBA000 (pszB 65520) owner VALGRIND/errors
--15498:1:mallocfr newSuperblock at 0x4022000 (pszB 4194288) owner CLIENT/client
--15498:1:mallocfr newSuperblock at 0x4422000 (pszB 4194288) owner CLIENT/client
--15498:1:signals extending a stack base 0xbe9bd000 down by 4096
--15498:2:stacks change stack 0 from 0xBE9BD000-0xBE9BEFFF to 0xBE9BC000-0xBE9BEFFF
--15498:1:mallocfr newSuperblock at 0x4822000 (pszB 4194288) owner CLIENT/client
--15498:1:mallocfr newSuperblock at 0x4C22000 (pszB 4194288) owner CLIENT/client
22323 bytes read
block 1: crc = 0xA212ABF8, combined CRC = 0xA212ABF8, size = 22373
too repetitive; using fallback sorting algorithm
22373 in block, 13504 after MTF & 1-2 coding, 79+2 syms in use
pass 1: size is 17143, grp uses are 38 62 2 92 6 71
pass 2: size is 6506, grp uses are 28 71 0 86 9 77
pass 3: size is 6479, grp uses are 26 70 0 81 11 83
pass 4: size is 6469, grp uses are 26 69 0 74 17 85
bytes: mapping 19, selectors 66, code lengths 134, codes 6465
final combined CRC = 0xA212ABF8
6710 after compression
really ok!
really ok!
all ok
--15498:1:syswrap- thread_wrapper(tid=1): exit
--15498:1:syswrap- run_a_thread_NORETURN(tid=1): post-thread_wrapper
--15498:1:syswrap- run_a_thread_NORETURN(tid=1): last one standing
--15498:1:main entering VG_(shutdown_actions_NORETURN)
--15498:1:aspacem <<< SHOW_SEGMENTS: Memory layout at client shutdown (53 segments, 8 segnames)
--15498:1:aspacem ( 0) /home/philippe/valq/install_elem/lib/valgrind/memcheck-x86-linux
--15498:1:aspacem ( 1) /home/philippe/valq/valgrind_elem/perf/bz2
--15498:1:aspacem ( 2) /lib/ld-2.9.so
--15498:1:aspacem ( 3) /home/philippe/valq/install_elem/lib/valgrind/vgpreload_core-x86-linux.so
--15498:1:aspacem ( 4) /home/philippe/valq/install_elem/lib/valgrind/vgpreload_memcheck-x86-linux.so
--15498:1:aspacem ( 6) /lib/libc-2.9.so
--15498:1:aspacem 0: RSVN 0000000000-000026dfff 2547712 ----- SmFixed
--15498:1:aspacem 1: file 000026e000-000028dfff 131072 r-xT- d=0xfd00 i=1155478 o=0 (2)
--15498:1:aspacem 2: RSVN 000028e000-000028efff 4096 ----- SmFixed
--15498:1:aspacem 3: file 000028f000-000028ffff 4096 r---- d=0xfd00 i=1155478 o=131072 (2)
--15498:1:aspacem 4: file 0000290000-0000290fff 4096 rw--- d=0xfd00 i=1155478 o=135168 (2)
--15498:1:aspacem 5: RSVN 0000291000-0000292fff 8192 ----- SmFixed
--15498:1:aspacem 6: file 0000293000-0000400fff 1499136 r-xT- d=0xfd00 i=1156596 o=0 (6)
--15498:1:aspacem 7: file 0000401000-0000402fff 8192 r---- d=0xfd00 i=1156596 o=1499136 (6)
--15498:1:aspacem 8: file 0000403000-0000403fff 4096 rw--- d=0xfd00 i=1156596 o=1507328 (6)
--15498:1:aspacem 9: anon 0000404000-0000406fff 12288 rw---
--15498:1:aspacem 10: RSVN 0000407000-000040afff 16384 ----- SmFixed
--15498:1:aspacem 11: ANON 000040b000-000040bfff 4096 r-x--
--15498:1:aspacem 12: RSVN 000040c000-0003ffffff 59m ----- SmFixed
--15498:1:aspacem 13: anon 0004000000-0004000fff 4096 rw---
--15498:1:aspacem 14: file 0004001000-0004001fff 4096 r-xT- d=0xfd00 i=2648122 o=0 (3)
--15498:1:aspacem 15: file 0004002000-0004002fff 4096 rw--- d=0xfd00 i=2648122 o=0 (3)
--15498:1:aspacem 16: file 0004003000-0004008fff 24576 r-xT- d=0xfd00 i=2648127 o=0 (4)
--15498:1:aspacem 17: file 0004009000-0004009fff 4096 rw--- d=0xfd00 i=2648127 o=24576 (4)
--15498:1:aspacem 18: anon 000400a000-000400afff 4096 rw---
--15498:1:aspacem 19: 000400b000-0004020fff 90112
--15498:1:aspacem 20: anon 0004021000-0004021fff 4096 rw---
--15498:1:aspacem 21: anon 0004022000-0005021fff 16m rwx-H
--15498:1:aspacem 22: 0005022000-0008047fff 48m
--15498:1:aspacem 23: file 0008048000-000805bfff 81920 r-xT- d=0xfd00 i=2624338 o=0 (1)
--15498:1:aspacem 24: file 000805c000-000805cfff 4096 rw--- d=0xfd00 i=2624338 o=81920 (1)
--15498:1:aspacem 25: anon 000805d000-0008430fff 4014080 rw---
--15498:1:aspacem 26: anon 0008431000-0008431fff 4096 rwx--
--15498:1:aspacem 27: RSVN 0008432000-0008c30fff 8384512 ----- SmLower
--15498:1:aspacem 28: 0008c31000-0037ffffff 755m
--15498:1:aspacem 29: FILE 0038000000-003803cfff 249856 r-x-- d=0xfd00 i=2648126 o=0 (0)
--15498:1:aspacem 30: file 003803d000-003803dfff 4096 r-xT- d=0xfd00 i=2648126 o=249856 (0)
--15498:1:aspacem 31: FILE 003803e000-00381c6fff 1609728 r-x-- d=0xfd00 i=2648126 o=253952 (0)
--15498:1:aspacem 32: FILE 00381c7000-00381c8fff 8192 rw--- d=0xfd00 i=2648126 o=1859584 (0)
--15498:1:aspacem 33: ANON 00381c9000-00388e9fff 7475200 rw---
--15498:1:aspacem 34: 00388ea000-0061cdefff 659m
--15498:1:aspacem 35: RSVN 0061cdf000-0061cdffff 4096 ----- SmFixed
--15498:1:aspacem 36: ANON 0061ce0000-006286ffff 11m rwx--
--15498:1:aspacem 37: ANON 0062870000-0062871fff 8192 -----
--15498:1:aspacem 38: ANON 0062872000-0062881fff 65536 rwx--
--15498:1:aspacem 39: ANON 0062882000-0062883fff 8192 -----
--15498:1:aspacem 40: ANON 0062884000-0064f41fff 38m rwx--
--15498:1:aspacem 41: 0064f42000-0064f45fff 16384
--15498:1:aspacem 42: ANON 0064f46000-0064f59fff 81920 rwx--
--15498:1:aspacem 43: 0064f5a000-0064f7dfff 147456
--15498:1:aspacem 44: ANON 0064f7e000-0064f81fff 16384 rwx--
--15498:1:aspacem 45: 0064f82000-0064f89fff 32768
--15498:1:aspacem 46: ANON 0064f8a000-0064f8dfff 16384 rwx--
--15498:1:aspacem 47: 0064f8e000-00bdfbefff 1424m
--15498:1:aspacem 48: RSVN 00bdfbf000-00be9bbfff 9m ----- SmUpper
--15498:1:aspacem 49: anon 00be9bc000-00be9befff 12288 rwx--
--15498:1:aspacem 50: 00be9bf000-00bf9aafff 15m
--15498:1:aspacem 51: ANON 00bf9ab000-00bf9bffff 86016 rw---
--15498:1:aspacem 52: RSVN 00bf9c0000-00ffffffff 1030m ----- SmFixed
--15498:1:aspacem >>>
==15498==
==15498== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 12 from 1)
==15498== malloc/free: in use at exit: 0 bytes in 0 blocks.
==15498== malloc/free: 1,225 allocs, 1,225 frees, 925,895,544 bytes allocated.
==15498== For a detailed leak analysis, rerun with: --leak-check=yes
==15498== For counts of detected errors, rerun with: -v
--15498:1:core_os VG_(terminate_NORETURN)(tid=1)
--15509:1:debuglog DebugLog system started by Stage 1, level 3 logging requested
--15509:1:launcher no tool requested, defaulting to 'memcheck'
--15509:1:launcher selected platform 'x86-linux'
--15509:1:launcher launching /home/philippe/valq/install_orig/lib/valgrind/memcheck-x86-linux
--15509:1:debuglog DebugLog system started by Stage 2 (main), level 3 logging requested
--15509:1:main Welcome to Valgrind version 3.5.0.SVN debug logging
--15509:1:main Checking current stack is plausible
--15509:1:main Checking initial stack was noted
--15509:1:main Starting the address space manager
--15509:2:aspacem sp_at_startup = 0x00bfad9b90 (supplied)
--15509:2:aspacem minAddr = 0x0004000000 (computed)
--15509:2:aspacem maxAddr = 0x00bfad8fff (computed)
--15509:2:aspacem cStart = 0x0004000000 (computed)
--15509:2:aspacem vStart = 0x0061d6d000 (computed)
--15509:2:aspacem suggested_clstack_top = 0x00bead9fff (computed)
--15509:2:aspacem <<< SHOW_SEGMENTS: Initial layout (5 segments, 0 segnames)
--15509:2:aspacem 0: RSVN 0000000000-0003ffffff 64m ----- SmFixed
--15509:2:aspacem 1: 0004000000-0061d6cfff 1501m
--15509:2:aspacem 2: RSVN 0061d6d000-0061d6dfff 4096 ----- SmFixed
--15509:2:aspacem 3: 0061d6e000-00bfad8fff 1501m
--15509:2:aspacem 4: RSVN 00bfad9000-00ffffffff 1029m ----- SmFixed
--15509:2:aspacem >>>
--15509:2:aspacem Reading /proc/self/maps
--15509:2:aspacem <<< SHOW_SEGMENTS: With contents of /proc/self/maps (12 segments, 1 segnames)
--15509:2:aspacem ( 0) /home/philippe/valq/install_orig/lib/valgrind/memcheck-x86-linux
--15509:2:aspacem 0: RSVN 0000000000-0000f2bfff 15m ----- SmFixed
--15509:2:aspacem 1: ANON 0000f2c000-0000f2cfff 4096 r-x--
--15509:2:aspacem 2: RSVN 0000f2d000-0003ffffff 48m ----- SmFixed
--15509:2:aspacem 3: 0004000000-0037ffffff 832m
--15509:2:aspacem 4: FILE 0038000000-00381c6fff 1863680 r-x-- d=0xfd00 i=2542054 o=0 (0)
--15509:2:aspacem 5: FILE 00381c7000-00381c8fff 8192 rw--- d=0xfd00 i=2542054 o=1859584 (0)
--15509:2:aspacem 6: ANON 00381c9000-00388e9fff 7475200 rw---
--15509:2:aspacem 7: 00388ea000-0061d6cfff 660m
--15509:2:aspacem 8: RSVN 0061d6d000-0061d6dfff 4096 ----- SmFixed
--15509:2:aspacem 9: 0061d6e000-00bfac6fff 1501m
--15509:2:aspacem 10: ANON 00bfac7000-00bfadbfff 86016 rw---
--15509:2:aspacem 11: RSVN 00bfadc000-00ffffffff 1029m ----- SmFixed
--15509:2:aspacem >>>
--15509:1:main Address space manager is running
--15509:1:main Starting the dynamic memory manager
--15509:1:mallocfr newSuperblock at 0x61D6E000 (pszB 4194288) owner VALGRIND/tool
--15509:1:main Dynamic memory manager is running
--15509:1:main Initialise m_debuginfo
--15509:1:main Getting stage1's name
--15509:1:main Get hardware capabilities ...
--15509:1:main ... arch = X86, hwcaps = x86-sse1-sse2
--15509:1:main Getting the working directory at startup
--15509:1:main ... /home/philippe/valq/valgrind_elem
--15509:1:main Split up command line
--15509:1:main (early_) Process Valgrind's command line options
--15509:1:main Create initial image
--15509:1:initimg Loading client
--15509:1:initimg Setup client env
--15509:2:initimg preload_string:
--15509:2:initimg
"/home/philippe/valq/install_orig/lib/valgrind/vgpreload_core-x86-linux.so:/home/philippe/valq/install_orig/lib/valgrind/vgpreload_memcheck-x86-linux.so"
--15509:1:initimg Setup client stack: size will be 10485760
--15509:2:initimg stomping auxv entry 31
--15509:2:initimg Client info: initial_IP=0x26E850 initial_TOC=0x0 brk_base=0x8431000
--15509:2:initimg Client info: initial_SP=0xBEAD9400 max_stack_size=10485760
--15509:1:initimg Setup client data (brk) segment
--15509:1:main Setup file descriptors
--15509:1:main Create fake /proc/<pid>/cmdline
--15509:1:main Initialise the tool part 1 (pre_clo_init)
--15509:1:mallocfr newSuperblock at 0x6216E000 (pszB 1048560) owner VALGRIND/exectxt
--15509:1:main Print help and quit, if requested
--15509:1:main (main_) Process Valgrind's command line options, setup logging
--15509:1:mallocfr newSuperblock at 0x6226E000 (pszB 1048560) owner VALGRIND/core
--15509:1:main Print the preamble...
==15509== Memcheck, a memory error detector.
==15509== Copyright (C) 2002-2009, and GNU GPL'd, by Julian Seward et al.
==15509== Using LibVEX rev 1888, a library for dynamic binary translation.
==15509== Copyright (C) 2004-2009, and GNU GPL'd, by OpenWorks LLP.
==15509== Using valgrind-3.5.0.SVN, a dynamic binary instrumentation framework.
==15509== Copyright (C) 2000-2009, and GNU GPL'd, by Julian Seward et al.
==15509== For more details, rerun with: -v
==15509==
--15509:1:main ...finished the preamble
--15509:1:main Initialise the tool part 2 (post_clo_init)
--15509:1:main Initialise TT/TC
--15509:2:transtab cache: 8 sectors of 29772288 bytes each = 238178304 total
--15509:2:transtab table: 524168 total entries, max occupancy 419328 (80%)
--15509:1:main Initialise redirects
--15509:1:mallocfr newSuperblock at 0x623E9000 (pszB 1048560) owner VALGRIND/dinfo
--15509:1:main Load initial debug info
--15509:2:transtab discard_translations(0x287440, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 14
--15509:2:transtab discard_translations(0x3803d323, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 122
--15509:1:mallocfr newSuperblock at 0x624E9000 (pszB 1048560) owner VALGRIND/dinfo
--15509:1:mallocfr newSuperblock at 0x625E9000 (pszB 1048560) owner VALGRIND/dinfo
--15509:1:mallocfr newSuperblock at 0x626E9000 (pszB 2052080) owner VALGRIND/dinfo
--15509:1:redir transfer ownership V -> C of 0x3803d000 .. 0x3803dfff
--15509:1:main Initialise scheduler (phase 1)
--15509:1:sched sched_init_phase1
--15509:1:main Tell tool about initial permissions
--15509:2:main tell tool about 000026e000-000028dfff r-x
--15509:2:main tell tool about 000028f000-0000290fff rw-
--15509:2:main tell tool about 0008048000-000805bfff r-x
--15509:2:main tell tool about 000805c000-000805cfff rw-
--15509:2:main tell tool about 000805d000-0008430fff rw-
--15509:2:main tell tool about 0008431000-0008431fff rwx
--15509:2:main tell tool about 003803d000-003803dfff r-x
--15509:2:main tell tool about 00bead9000-00bead9fff rwx
--15509:2:main mark stack inaccessible 00bead9000-00bead93ff
--15509:1:main Initialise scheduler (phase 2)
--15509:1:sched sched_init_phase2: tid_main=1, cls_end=0xbead9fff, cls_sz=10485760
--15509:1:main Finalise initial image
--15509:1:main Initialise signal management
--15509:1:main Load suppressions
--15509:2:stacks register 0xBEAD9000-0xBEAD9FFF as stack 0
--15509:1:main
--15509:1:main
--15509:1:aspacem <<< SHOW_SEGMENTS: Memory layout at client startup (28 segments, 4 segnames)
--15509:1:aspacem ( 0) /home/philippe/valq/install_orig/lib/valgrind/memcheck-x86-linux
--15509:1:aspacem ( 1) /home/philippe/valq/valgrind_elem/perf/bz2
--15509:1:aspacem ( 2) /lib/ld-2.9.so
--15509:1:aspacem 0: RSVN 0000000000-000026dfff 2547712 ----- SmFixed
--15509:1:aspacem 1: file 000026e000-000028dfff 131072 r-x-- d=0xfd00 i=1155478 o=0 (2)
--15509:1:aspacem 2: RSVN 000028e000-000028efff 4096 ----- SmFixed
--15509:1:aspacem 3: file 000028f000-0000290fff 8192 rw--- d=0xfd00 i=1155478 o=131072 (2)
--15509:1:aspacem 4: RSVN 0000291000-0000f2bfff 12m ----- SmFixed
--15509:1:aspacem 5: ANON 0000f2c000-0000f2cfff 4096 r-x--
--15509:1:aspacem 6: RSVN 0000f2d000-0003ffffff 48m ----- SmFixed
--15509:1:aspacem 7: 0004000000-0008047fff 64m
--15509:1:aspacem 8: file 0008048000-000805bfff 81920 r-x-- d=0xfd00 i=2624338 o=0 (1)
--15509:1:aspacem 9: file 000805c000-000805cfff 4096 rw--- d=0xfd00 i=2624338 o=81920 (1)
--15509:1:aspacem 10: anon 000805d000-0008430fff 4014080 rw---
--15509:1:aspacem 11: anon 0008431000-0008431fff 4096 rwx--
--15509:1:aspacem 12: RSVN 0008432000-0008c30fff 8384512 ----- SmLower
--15509:1:aspacem 13: 0008c31000-0037ffffff 755m
--15509:1:aspacem 14: FILE 0038000000-003803cfff 249856 r-x-- d=0xfd00 i=2542054 o=0 (0)
--15509:1:aspacem 15: file 003803d000-003803dfff 4096 r-x-- d=0xfd00 i=2542054 o=249856 (0)
--15509:1:aspacem 16: FILE 003803e000-00381c6fff 1609728 r-x-- d=0xfd00 i=2542054 o=253952 (0)
--15509:1:aspacem 17: FILE 00381c7000-00381c8fff 8192 rw--- d=0xfd00 i=2542054 o=1859584 (0)
--15509:1:aspacem 18: ANON 00381c9000-00388e9fff 7475200 rw---
--15509:1:aspacem 19: 00388ea000-0061d6cfff 660m
--15509:1:aspacem 20: RSVN 0061d6d000-0061d6dfff 4096 ----- SmFixed
--15509:1:aspacem 21: ANON 0061d6e000-00628fdfff 11m rwx--
--15509:1:aspacem 22: 00628fe000-00be0d9fff 1463m
--15509:1:aspacem 23: RSVN 00be0da000-00bead8fff 9m ----- SmUpper
--15509:1:aspacem 24: anon 00bead9000-00bead9fff 4096 rwx--
--15509:1:aspacem 25: 00beada000-00bfac6fff 15m
--15509:1:aspacem 26: ANON 00bfac7000-00bfadbfff 86016 rw---
--15509:1:aspacem 27: RSVN 00bfadc000-00ffffffff 1029m ----- SmFixed
--15509:1:aspacem >>>
--15509:1:main
--15509:1:main
--15509:1:main Running thread 1
--15509:1:syswrap- entering VG_(main_thread_wrapper_NORETURN)
--15509:1:aspacem allocated thread stack at 0x628fe000 size 81920
--15509:1:syswrap- run_a_thread_NORETURN(tid=1): pre-thread_wrapper
--15509:1:syswrap- thread_wrapper(tid=1): entry
--15509:1:transtab allocate sector 0
--15509:1:mallocfr newSuperblock at 0x64A37000 (pszB 65520) owner VALGRIND/ttaux
--15509:1:signals extending a stack base 0xbead9000 down by 4096
--15509:2:stacks change stack 0 from 0xBEAD9000-0xBEAD9FFF to 0xBEAD8000-0xBEAD9FFF
--15509:2:transtab discard_translations(0x287610, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 14
--15509:2:transtab discard_translations(0x4007460, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 14
--15509:2:transtab discard_translations(0x287a00, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 15
--15509:2:transtab discard_translations(0x40081b0, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 16
--15509:1:mallocfr newSuperblock at 0x64A53000 (pszB 1048560) owner VALGRIND/dinfo
--15509:1:mallocfr newSuperblock at 0x64B53000 (pszB 1048560) owner VALGRIND/dinfo
--15509:1:mallocfr newSuperblock at 0x64C53000 (pszB 1048560) owner VALGRIND/dinfo
--15509:1:mallocfr newSuperblock at 0x64D53000 (pszB 2052080) owner VALGRIND/dinfo
--15509:2:transtab discard_translations(0x2c1180, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 130
--15509:2:transtab discard_translations(0x4008680, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 16
--15509:2:transtab discard_translations(0x2c12b0, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 130
--15509:2:transtab discard_translations(0x40086f0, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 16
--15509:2:transtab discard_translations(0x2c1770, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 130
--15509:2:transtab discard_translations(0x4008760, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 16
--15509:2:transtab discard_translations(0x302010, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 4
--15509:2:transtab discard_translations(0x4004a80, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 9
--15509:2:transtab discard_translations(0x303480, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 6
--15509:2:transtab discard_translations(0x4004890, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 9
--15509:2:transtab discard_translations(0x303880, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 7
--15509:2:transtab discard_translations(0x4004940, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 9
--15509:2:transtab discard_translations(0x3042c0, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 8
--15509:2:transtab discard_translations(0x4005aa0, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 11
--15509:2:transtab discard_translations(0x304550, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 8
--15509:2:transtab discard_translations(0x4004780, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 8
--15509:2:transtab discard_translations(0x3063a0, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 12
--15509:2:transtab discard_translations(0x4004d30, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 9
--15509:2:transtab discard_translations(0x3066d0, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 12
--15509:2:transtab discard_translations(0x4006c80, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 13
--15509:2:transtab discard_translations(0x3068a0, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 13
--15509:2:transtab discard_translations(0x4004b90, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 9
--15509:2:transtab discard_translations(0x306ae0, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 13
--15509:2:transtab discard_translations(0x4004cd0, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 9
--15509:2:transtab discard_translations(0x306b80, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 13
--15509:2:transtab discard_translations(0x4006d90, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 13
--15509:2:transtab discard_translations(0x3072e0, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 14
--15509:2:transtab discard_translations(0x4007010, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 14
--15509:2:transtab discard_translations(0x307470, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 14
--15509:2:transtab discard_translations(0x40048d0, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 9
--15509:2:transtab discard_translations(0x307660, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 14
--15509:2:transtab discard_translations(0x40048b0, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 9
--15509:2:transtab discard_translations(0x307800, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 15
--15509:2:transtab discard_translations(0x4004790, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 8
--15509:2:transtab discard_translations(0x307a80, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 15
--15509:2:transtab discard_translations(0x4004770, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 8
--15509:2:transtab discard_translations(0x309af0, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 19
--15509:2:transtab discard_translations(0x4007210, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 14
--15509:2:transtab discard_translations(0x309ca0, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 19
--15509:2:transtab discard_translations(0x4007180, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 14
--15509:2:transtab discard_translations(0x309e10, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 19
--15509:2:transtab discard_translations(0x4007740, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 14
--15509:2:transtab discard_translations(0x309e80, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 19
--15509:2:transtab discard_translations(0x40074a0, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 14
--15509:2:transtab discard_translations(0x30a380, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 20
--15509:2:transtab discard_translations(0x4007440, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 14
--15509:2:transtab discard_translations(0x30a430, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 20
--15509:2:transtab discard_translations(0x4007400, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 14
--15509:2:transtab discard_translations(0x30a4f0, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 20
--15509:2:transtab discard_translations(0x40072f0, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 14
--15509:2:transtab discard_translations(0x30a5a0, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 20
--15509:2:transtab discard_translations(0x40076b0, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 14
--15509:2:transtab discard_translations(0x30a6b0, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 20
--15509:2:transtab discard_translations(0x4007570, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 14
--15509:2:transtab discard_translations(0x30a800, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 21
--15509:2:transtab discard_translations(0x4007090, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 14
--15509:2:transtab discard_translations(0x30bbe0, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 23
--15509:2:transtab discard_translations(0x4007860, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 15
--15509:2:transtab discard_translations(0x30bd80, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 23
--15509:2:transtab discard_translations(0x4008040, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 16
--15509:2:transtab discard_translations(0x30c060, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 24
--15509:2:transtab discard_translations(0x4008a70, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 17
--15509:2:transtab discard_translations(0x30c070, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 24
--15509:2:transtab discard_translations(0x40083b0, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 16
--15509:2:transtab discard_translations(0x30c0e0, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 24
--15509:2:transtab discard_translations(0x4008350, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 16
--15509:2:transtab discard_translations(0x30c140, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 24
--15509:2:transtab discard_translations(0x4008480, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 16
--15509:2:transtab discard_translations(0x30c2d0, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 24
--15509:2:transtab discard_translations(0x40080e0, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 16
--15509:2:transtab discard_translations(0x30c5e0, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 24
--15509:2:transtab discard_translations(0x4008890, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 17
--15509:2:transtab discard_translations(0x30c5f0, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 24
--15509:2:transtab discard_translations(0x40078b0, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 15
--15509:2:transtab discard_translations(0x30f060, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 30
--15509:2:transtab discard_translations(0x4008460, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 16
--15509:2:transtab discard_translations(0x30f130, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 30
--15509:2:transtab discard_translations(0x4008420, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 16
--15509:2:transtab discard_translations(0x38dc20, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 27
--15509:2:transtab discard_translations(0x4008990, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 17
--15509:2:transtab discard_translations(0x38dcb0, 1) req by redir_new_DebugInfo(from_addr)
--15509:2:transtab FAST, ec = 27
--15509:2:transtab discard_translations(0x4008a00, 1) req by redir_new_DebugInfo(to_addr)
--15509:2:transtab FAST, ec = 17
--15509:1:mallocfr newSuperblock at 0x64F48000 (pszB 65520) owner VALGRIND/errors
--15509:1:mallocfr newSuperblock at 0x4022000 (pszB 4194288) owner CLIENT/client
--15509:1:mallocfr newSuperblock at 0x4422000 (pszB 4194288) owner CLIENT/client
--15509:1:signals extending a stack base 0xbead8000 down by 4096
--15509:2:stacks change stack 0 from 0xBEAD8000-0xBEAD9FFF to 0xBEAD7000-0xBEAD9FFF
--15509:1:mallocfr newSuperblock at 0x4822000 (pszB 4194288) owner CLIENT/client
--15509:1:mallocfr newSuperblock at 0x4C22000 (pszB 4194288) owner CLIENT/client
22323 bytes read
block 1: crc = 0xA212ABF8, combined CRC = 0xA212ABF8, size = 22373
too repetitive; using fallback sorting algorithm
22373 in block, 13504 after MTF & 1-2 coding, 79+2 syms in use
pass 1: size is 17143, grp uses are 38 62 2 92 6 71
pass 2: size is 6506, grp uses are 28 71 0 86 9 77
pass 3: size is 6479, grp uses are 26 70 0 81 11 83
pass 4: size is 6469, grp uses are 26 69 0 74 17 85
bytes: mapping 19, selectors 66, code lengths 134, codes 6465
final combined CRC = 0xA212ABF8
6710 after compression
really ok!
really ok!
all ok
--15509:1:syswrap- thread_wrapper(tid=1): exit
--15509:1:syswrap- run_a_thread_NORETURN(tid=1): post-thread_wrapper
--15509:1:syswrap- run_a_thread_NORETURN(tid=1): last one standing
--15509:1:main entering VG_(shutdown_actions_NORETURN)
--15509:1:aspacem <<< SHOW_SEGMENTS: Memory layout at client shutdown (53 segments, 8 segnames)
--15509:1:aspacem ( 0) /home/philippe/valq/install_orig/lib/valgrind/memcheck-x86-linux
--15509:1:aspacem ( 1) /home/philippe/valq/valgrind_elem/perf/bz2
--15509:1:aspacem ( 2) /lib/ld-2.9.so
--15509:1:aspacem ( 3) /home/philippe/valq/install_orig/lib/valgrind/vgpreload_core-x86-linux.so
--15509:1:aspacem ( 4) /home/philippe/valq/install_orig/lib/valgrind/vgpreload_memcheck-x86-linux.so
--15509:1:aspacem ( 6) /lib/libc-2.9.so
--15509:1:aspacem 0: RSVN 0000000000-000026dfff 2547712 ----- SmFixed
--15509:1:aspacem 1: file 000026e000-000028dfff 131072 r-xT- d=0xfd00 i=1155478 o=0 (2)
--15509:1:aspacem 2: RSVN 000028e000-000028efff 4096 ----- SmFixed
--15509:1:aspacem 3: file 000028f000-000028ffff 4096 r---- d=0xfd00 i=1155478 o=131072 (2)
--15509:1:aspacem 4: file 0000290000-0000290fff 4096 rw--- d=0xfd00 i=1155478 o=135168 (2)
--15509:1:aspacem 5: RSVN 0000291000-0000292fff 8192 ----- SmFixed
--15509:1:aspacem 6: file 0000293000-0000400fff 1499136 r-xT- d=0xfd00 i=1156596 o=0 (6)
--15509:1:aspacem 7: file 0000401000-0000402fff 8192 r---- d=0xfd00 i=1156596 o=1499136 (6)
--15509:1:aspacem 8: file 0000403000-0000403fff 4096 rw--- d=0xfd00 i=1156596 o=1507328 (6)
--15509:1:aspacem 9: anon 0000404000-0000406fff 12288 rw---
--15509:1:aspacem 10: RSVN 0000407000-0000f2bfff 11m ----- SmFixed
--15509:1:aspacem 11: ANON 0000f2c000-0000f2cfff 4096 r-x--
--15509:1:aspacem 12: RSVN 0000f2d000-0003ffffff 48m ----- SmFixed
--15509:1:aspacem 13: anon 0004000000-0004000fff 4096 rw---
--15509:1:aspacem 14: file 0004001000-0004001fff 4096 r-xT- d=0xfd00 i=2542020 o=0 (3)
--15509:1:aspacem 15: file 0004002000-0004002fff 4096 rw--- d=0xfd00 i=2542020 o=0 (3)
--15509:1:aspacem 16: file 0004003000-0004008fff 24576 r-xT- d=0xfd00 i=2542064 o=0 (4)
--15509:1:aspacem 17: file 0004009000-0004009fff 4096 rw--- d=0xfd00 i=2542064 o=24576 (4)
--15509:1:aspacem 18: anon 000400a000-000400afff 4096 rw---
--15509:1:aspacem 19: 000400b000-0004020fff 90112
--15509:1:aspacem 20: anon 0004021000-0004021fff 4096 rw---
--15509:1:aspacem 21: anon 0004022000-0005021fff 16m rwx-H
--15509:1:aspacem 22: 0005022000-0008047fff 48m
--15509:1:aspacem 23: file 0008048000-000805bfff 81920 r-xT- d=0xfd00 i=2624338 o=0 (1)
--15509:1:aspacem 24: file 000805c000-000805cfff 4096 rw--- d=0xfd00 i=2624338 o=81920 (1)
--15509:1:aspacem 25: anon 000805d000-0008430fff 4014080 rw---
--15509:1:aspacem 26: anon 0008431000-0008431fff 4096 rwx--
--15509:1:aspacem 27: RSVN 0008432000-0008c30fff 8384512 ----- SmLower
--15509:1:aspacem 28: 0008c31000-0037ffffff 755m
--15509:1:aspacem 29: FILE 0038000000-003803cfff 249856 r-x-- d=0xfd00 i=2542054 o=0 (0)
--15509:1:aspacem 30: file 003803d000-003803dfff 4096 r-xT- d=0xfd00 i=2542054 o=249856 (0)
--15509:1:aspacem 31: FILE 003803e000-00381c6fff 1609728 r-x-- d=0xfd00 i=2542054 o=253952 (0)
--15509:1:aspacem 32: FILE 00381c7000-00381c8fff 8192 rw--- d=0xfd00 i=2542054 o=1859584 (0)
--15509:1:aspacem 33: ANON 00381c9000-00388e9fff 7475200 rw---
--15509:1:aspacem 34: 00388ea000-0061d6cfff 660m
--15509:1:aspacem 35: RSVN ...
[truncated message content] |
|
From: Nicholas N. <n.n...@gm...> - 2009-04-29 23:01:52
|
On Thu, Apr 30, 2009 at 8:39 AM, Philippe Waroquiers <phi...@sk...> wrote: > I am working on improving the performance of the leak search client request > (which has a quadratic aspect). What's the quadratic aspect? > After much digging and removing one by one all my changes, I have identified a > single change which degrades the performance of perf/bz2. > I have done all what I can to understand the reason and > I reaaaaaallllly cannot understand why. > > The only remaining change is in the function VG_(HT_to_array). > Instead of computing *n_elems by following the chains, > I am doing the following assignment: > *n_elems = table->n_elements; > (as the current nr of elements in the table is maintained, there is no need > to recompute it). > > By which miracle replacing a loop on all chains by a single assignment can > degrade the performance of perf/bz2 is a real mystery to me. > > Moreover, as far as I understand, the VG_(HT_to_array) is even not called > by perf/bz2 !!!! > (I have added a trace in HT_to_array, and effectively, > the below code is called only if --leak-check=yes is given. I think > running the memcheck performance test does not do leak-check. You're right that the loop isn't necessary. You're also right that the perf tests don't do the leak check. I tried your experiment on my machine, and there was no difference in performance. If you have access to another machine, you could try it there. I'd blame "inscrutable cache effects" myself... Nick |
|
From: Philippe W. <phi...@sk...> - 2009-04-30 22:34:21
|
> > I am working on improving the performance of the leak search client request > > (which has a quadratic aspect). > What's the quadratic aspect? I have just filed bug report 191182 explaining the problem and a patch fixing this quadratic behaviour. (If the bug report or patch is raising questions, I might not be able to answer to my mail before sunday evening: this week-end, it will be family). > I tried your experiment on my machine, and there was no difference in > performance. If you have access to another machine, you could try it > there. I'd blame "inscrutable cache effects" myself... I am doing this at home, where I only have this single fedora x86 computer. I will try at work, but there, I have no pentium x86 which is similar to the home version. I am still puzzled by this behaviour. I can understand cache effects caused by code which is called, but cache effects caused by a (smaller) piece of code not being called is beyond my brain. A friend suggested to add some more such loops till I obtain a negative runtime for the perf test :). Philippe |
|
From: Nicholas N. <n.n...@gm...> - 2009-04-30 22:58:28
|
On Fri, May 1, 2009 at 8:34 AM, Philippe Waroquiers <phi...@sk...> wrote: > > I am still puzzled by this behaviour. I can understand cache effects caused > by code which is called, but cache effects caused by a (smaller) piece of > code not being called is beyond my brain. The extra code will change the code layout in memory, and possibly also the data layout. That could be enough to trigger some extra cache conflicts. You could try running Cachegrind on it (see README_DEVELOPERS for how) and see if you get significantly different results... it would take a while, but might answer your question. Or you could use something (oprofile?) that reads performance counters, which would be quicker but wouldn't give you the line-by-line cache results that Cachegrind does. Nick |