Three self tests fail on FreeBSD-9.0 amd64 (gperftools-2.0)

[alk]

Originally reported on Google Code with ID 420

Log says 3 of 41 tests failed, but there is also "death test" where log says FAILURE.

====> low_level_alloc_unittest (see stack trace below)
failure is in these lines:
  __asm__ __volatile__(
      "movq .curbrk(%%rip), %%rax;"
      "movq %%rax, %0;"
      : "=r" (curbrk)
      :: "%rax");

====> death test (says FAILURE, looks like it is part of debugallocation_test.sh)
debugallocation_test fails for argument<16 and succeeds for argument>=16.

For example:
# debugallocation_test 14
Expected regex:Memory was written to after being freed.
Found a corrupted memory buffer in MallocBlock (may be offset from user ptr): buffer
index: 0, buffer ptr: 0x73a400, size of buffer: 52
Buffer byte 32 is 0x01 (should be 0xcd).
Buffer byte 33 is 0x00 (should be 0xcd).
Buffer byte 34 is 0x00 (should be 0xcd).
Buffer byte 35 is 0x00 (should be 0xcd).
Deleted by thread 0x710020
*** WARNING: Cannot convert addresses to symbols in output below.
*** Reason: Cannot figure out the name of this executable (argv0)
*** If you cannot fix this, try running pprof directly.
    @ 0x8008961e3 
    @ 0x4016ff 
    @ 0x401144 
    @ 0x4011dc 
    @ 0x400e0e 
    @ 0x80063d000 
Memory was written to after being freed.  MallocBlock: 0x73a400, user ptr: 0x73a420,
size: 52.  If you can't find the source of the error, try using ASan (http://code.google.com/p/address-sanitizer/),
Valgrind, or Purify, or study the output of the deleter's stack printed above.
Abort trap: 6
# debugallocation_test 16
Massive size passed to malloc: 18446744073709551615
tcmalloc: large alloc 0 bytes == 0x0 @  0x8008742bb 0x80087439c 0x80087ae79 0x8008743dc
0x80087b0ad 0x8008965a5 0x40124e 0x401144 0x4011dc 0x400e0e 0x80063d000

Passed 11 tests

PASS

====> debugallocation_test.sh
See above

====> profiler_unittest.sh
Failure seems intermittent (doesn't happen every time).

--- stack trace for low_level_alloc_unittest ---
#0  do_sbrk (increment=0) at src/malloc_hook_mmap_freebsd.h:91
#1  0x000000000040a85e in sbrk (increment=0) at src/malloc_hook_mmap_freebsd.h:141
#2  0x000000080100fef0 in ?? () from /lib/libc.so.7
#3  0x0000000801015fe5 in malloc () from /lib/libc.so.7
#4  0x000000080092747d in operator new(unsigned long) () from /usr/lib/libstdc++.so.6
#5  0x0000000000407925 in __gnu_cxx::new_allocator<std::_Rb_tree_node<std::pair<int
const, BlockDesc> > >::allocate (this=0x7fffffffcf00, __n=1) at /usr/include/c++/4.2/ext/new_allocator.h:91
#6  0x0000000000407952 in std::_Rb_tree<int, std::pair<int const, BlockDesc>, std::_Select1st<std::pair<int
const, BlockDesc> >, std::less<int>, std::allocator<std::pair<int const, BlockDesc>
> >::_M_get_node (this=0x7fffffffcf00) at /usr/include/c++/4.2/bits/stl_tree.h:367
#7  0x00000000004079ca in std::_Rb_tree<int, std::pair<int const, BlockDesc>, std::_Select1st<std::pair<int
const, BlockDesc> >, std::less<int>, std::allocator<std::pair<int const, BlockDesc>
> >::_M_create_node (this=0x7fffffffcf00, __x=...) at /usr/include/c++/4.2/bits/stl_tree.h:376
#8  0x0000000000407a92 in std::_Rb_tree<int, std::pair<int const, BlockDesc>, std::_Select1st<std::pair<int
const, BlockDesc> >, std::less<int>, std::allocator<std::pair<int const, BlockDesc>
> >::_M_insert (this=0x7fffffffcf00, __x=0x0, __p=0x7fffffffcf08, __v=...) at /usr/include/c++/4.2/bits/stl_tree.h:838
#9  0x0000000000407c0c in std::_Rb_tree<int, std::pair<int const, BlockDesc>, std::_Select1st<std::pair<int
const, BlockDesc> >, std::less<int>, std::allocator<std::pair<int const, BlockDesc>
> >::_M_insert_unique (this=0x7fffffffcf00, __v=...) at /usr/include/c++/4.2/bits/stl_tree.h:986
#10 0x0000000000407e2d in std::_Rb_tree<int, std::pair<int const, BlockDesc>, std::_Select1st<std::pair<int
const, BlockDesc> >, std::less<int>, std::allocator<std::pair<int const, BlockDesc>
> >::_M_insert_unique (this=0x7fffffffcf00, __position=..., __v=...) at /usr/include/c++/4.2/bits/stl_tree.h:1008
#11 0x00000000004081d5 in std::map<int, BlockDesc, std::less<int>, std::allocator<std::pair<int
const, BlockDesc> > >::insert (this=0x7fffffffcf00, __position=..., __x=...) at /usr/include/c++/4.2/bits/stl_map.h:427
#12 0x0000000000408293 in std::map<int, BlockDesc, std::less<int>, std::allocator<std::pair<int
const, BlockDesc> > >::operator[] (this=0x7fffffffcf00, __k=@0x7fffffffcf3c: 101027544)
at /usr/include/c++/4.2/bits/stl_map.h:350
#13 0x00000000004069a9 in Test (use_new_arena=false, call_malloc_hook=false, n=50000)
at src/tests/low_level_alloc_unittest.cc:118
#14 0x0000000000406c64 in main (argc=1, argv=0x7fffffffd048) at src/tests/low_level_alloc_unittest.cc:176

Reported by yurivict@yahoo.com on 2012-03-24 22:27:28

---

- _Attachment: [self-test-failures.log.gz](https://storage.googleapis.com/google-code-attachments/gperftools/issue-420/comment-0/self-test-failures.log.gz)_

[alk]

low_level_alloc_unittest

    Seems like an odd place for a crash to occur. Can you provide the output of 'info

    reg' and also try to narrow down which specific instruction is failing.

death test
debugallocation_test.sh

    debug_allocation_test 16

    Isn't the failure actually occuring here. I count this as the 15th (0-based)  

    invocation of the IF_DEBUG_EXPECT_DEATH macro.

    TEST(DebugAllocationTest, StackTraceWithDanglingWriteAtExitTest) {
      int *x = new int;
      delete x;
      int old_x_value = *x;
      *x = 1;
      // verify that we also get a stack trace when we have a dangling write.
      // The " @ " is part of the stack trace output.
      IF_DEBUG_EXPECT_DEATH(exit(0), " @ .*main");
      *x = old_x_value;  // restore x so that the test can exit successfully.
    }

Reported by chappedm on 2012-04-21 02:54:18

[alk]

Reported by chappedm on 2012-05-04 17:45:32

• Status changed: Accepted
• Labels added: Priority-High
• Labels removed: Priority-Medium

[alk]

Now I see 2 failures on FreeBSD 9.1
* low_level_alloc_unittest: same segmentation fault

(gdb) info reg
rax            0x0  0
rbx            0x8012b8d70  34379369840
rcx            0x16 22
rdx            0x6  6
rsi            0x3f9000 4165632
rdi            0x0  0
rbp            0x7fffffffc570   0x7fffffffc570
rsp            0x7fffffffc540   0x7fffffffc540
r8             0x7000   28672
r9             0xd  13
r10            0x7  7
r11            0x9  9
r12            0x7fffffffd078   140737488343160
r13            0x0  0
r14            0x0  0
r15            0x7fffffffc630   140737488340528
rip            0x403324 0x403324 <do_sbrk+20>
eflags         0x10202  66050
cs             0x43 67
ss             0x3b 59
ds             0x0  0
es             0x0  0
fs             0x0  0
gs             0x0  0

Failing instruction:
    0x0000000000403324 <do_sbrk+20>:        mov    -0x40332b(%rip),%rax (failing)

I think sbrk wasn't overloaded in 1.8.3 and this testcase worked. Even though this
function existed in seemingly i386 form only, it was never called in 1.8.3. Now when
it is overloaded this code fails. Who rewrote it and why?

I think you need to disable this sbrk overload until you test it and make sure it works.

* debugallocation_test.sh -- still a failure.

segmentation fault stack is
(gdb) bt
#0  0x000000080145f12c in thr_kill () from /lib/libc.so.7
#1  0x00000008015016bb in abort () from /lib/libc.so.7
#2  0x00000008008492e9 in LogPrintf (severity=-4, pat=0x800867468 "Memory was written
to after being freed.  MallocBlock: %p, user ptr: %p, size: %zd.  If you can't find
the source of the error, try using ASan (http://code.google.com/p/address-sanitizer/),
Valgrind, "..., ap=0x7fffffffc670) at logging.h:208
#3  0x00000008008493f5 in RAW_LOG (lvl=-4, pat=0x800867468 "Memory was written to after
being freed.  MallocBlock: %p, user ptr: %p, size: %zd.  If you can't find the source
of the error, try using ASan (http://code.google.com/p/address-sanitizer/), Valgrind,
"...) at logging.h:227
#4  0x000000080084a3fb in MallocBlock::CheckForCorruptedBuffer (queue_entry=@0x7fffffffc9e0,
buffer_idx=0, buffer=0x73a440 '
#5  0x000000080084a4bd in MallocBlock::CheckForDanglingWrites (queue_entry=@0x7fffffffc9e0)
at src/debugallocation.cc:648
#6  0x000000080084a7d5 in MallocBlock::ProcessFreeQueue (b=0x0, size=0, max_free_queue_size=0)
at src/debugallocation.cc:615
#7  0x0000000800843c88 in DanglingWriteChecker () at src/debugallocation.cc:807
#8  0x0000000800843ca7 in google_destruct_module_debugallocation () at src/debugallocation.cc:1089
#9  0x0000000800849ac0 in ~GoogleInitializer (this=0x800a7a0a0) at googleinit.h:50
#10 0x00000008008432f8 in __tcf_3 () at src/debugallocation.cc:1089
#11 0x00000008014de173 in __cxa_finalize () from /lib/libc.so.7
#12 0x0000000800842ee3 in __do_global_dtors_aux () from .libs/libtcmalloc_debug.so.5
#13 0x000000080081a5a0 in ?? () from /libexec/ld-elf.so.1
#14 0x0000000800866b29 in _fini () from .libs/libtcmalloc_debug.so.5
#15 0x000000080061b6c0 in ?? ()
#16 0x00000008006098a7 in dlinfo () from /libexec/ld-elf.so.1
#17 0x000000080060c1e5 in dlsym () from /libexec/ld-elf.so.1
#18 0x00000008014de184 in __cxa_finalize () from /lib/libc.so.7
#19 0x0000000801487217 in exit () from /lib/libc.so.7
#20 0x00000000004016d5 in Test_DebugAllocationTest_StackTraceWithDanglingWriteAtExitTest::Run
() at src/tests/debugallocation_test.cc:227
#21 0x0000000000401144 in RUN_ALL_TESTS () at src/tests/debugallocation_test.cc:55
#22 0x00000000004011dc in main (argc=2, argv=0x7fffffffd038) at src/tests/debugallocation_test.cc:312

Reported by yurivict@yahoo.com on 2012-08-15 22:03:53

[alk]

Hi Yuri,

Sorry for the delay on this one. I actually wrote this section of the freebsd port.
It is complicated because freebsd doesn't provide any _sbrk symbol. I am pretty sure
I tested this against all permutations of i386/x86_64 freebsd6/8/9 and that the unit
tests were clean when I submitted but it is possible that I missed something. Any inkling
of what could be wrong with how it is overridden? I am not a super assembly guy :)

Reported by chappedm on 2012-09-17 23:25:06

[alk]

With a bit more spare time on my hands over the holidays I am going to be working on
this. Hoping to get a release out for early January.

Reported by chappedm on 2012-12-23 14:46:36

[alk]

any news?

Reported by unexplained on 2013-02-03 16:04:02