Code Monkey home page Code Monkey logo

log-malloc2's Introduction

log-malloc2

log-malloc2 is pre-loadable library tracking all memory allocations of a program. It produces simple text trace output, that makes it easy to find leaks and also identify their origin.

Build Status

Features

  • logging to file descriptor 1022 (if opened)
  • call stack backtrace (via GNU backtrace() or libunwind)
  • requested memory tracking (byte-exact)
  • allocated memory tracking (byte-exact - using malloc_usable_size())
  • process memory status tracking (from /proc/self/statm)
  • call counting
  • thread safe
  • optional C API for runtime memory usage checking

Usage

log-malloc -o /tmp/program.log command args

OR

LD_PRELOAD=./liblog-malloc2.so command args ... 1022>/tmp/program.log

Performance

There is (non-)small performance penalty related to writing to logfile. One can improve this by redirecting write to tmpfs or similar fast-write filesystem. If log-malloc2 is compiled without libunwind, additionally a synchronization mutex is used while writing to logfile, thus every memory allocation is acting as giant synchronization lock (slowed down by write to logfile).

Helper scripts

  • backtrace2line

    • Script to automatically convert backtrace in files and line numbers.
    • Can also deal with ASLR randomized addresses.
  • log-malloc-findleak

    • Script to discover possible program memory leaks from trace file
  • log-malloc-trackusage

    • Script to track program memory usage over time.

C API

  • size_t log_malloc_get_usage(void)

    • Get actual program memory usage in bytes
  • void log_malloc_trace_enable(void)

    • Enable trace messages to be printed to trace fd.
  • void log_malloc_trace_disable(void)

    • Disable trace messages.
  • int log_malloc_trace_printf(const char *fmt, ...)

    • Printf smth. to trace fd (message size is limited to 1024 bytes).
  • LOG_MALLOC_SAVE(name, trace) [MACRO]

    • Creates savepoint with given name that stores actual memory usage.
    • If trace is true, message will be logged to trace fd.
  • LOG_MALLOC_UPDATE(name, trace) [MACRO]

    • Updates actual memory usage in savepoint with given name.
    • If trace is true, trace message will be logged to trace fd.
  • LOG_MALLOC_COMPARE(name, trace) [MACRO]

    • Compares actual memory usage with the saved one under given name.
    • If trace is true, trace message will be logged to trace fd.
    • Call returns memory usage difference (size_t).
  • LOG_MALLOC_ASSERT(name, iter) [MACRO]

    • ASSERT with fail, if actual memory usage differs from the one saved in savepoint.
    • iter can specify that assertion should be checked first after given number of LOG_MALLOC_SAVE() iterations.
  • LOG_MALLOC_NDEBUG [MACRO]

    • If defined, above macros will generate no code.

C INLINE API

  • void log_malloc_backtrace_init(void)

    • Pre-initializes backtrace() function, to avoid later memory alocations. Use of this function is optional.
  • ssize_t log_malloc_backtrace(int fd)

    • Generate current backtrace including process memory map (/proc/self/maps) to make backtrace symbol conversion easier.
    • Generated output can be directly pasted to backtrace2line script.

Author

Licensing

  • LGPLv3 for C code (library)
  • GPLv3 for Perl code (scripts)

See Also

Examples

###Example Trace Output

$ log-malloc -o - ./examples/leak-01

*** log-malloc trace-fd = 1022 ***

+ malloc 53 0x7f9bff564080 [85:160]!
+ calloc 1182 0x7f9bff5640e0 [1267:1384] (1182 1)!
+ malloc 53 0x7f9bff5645b0 [1320:1472]!
+ malloc 56 0x7f9bff564610 [1376:1560]!
+ calloc 360 0x7f9bff564670 [1736:1952] (15 24)!
+ calloc 32 0x7f9bff564030 [32:72] (1 32) #3183 168 131 1 0 84 0
/lib64/libdl.so.2(+0x1960)[0x7f9bfcfa8960]
/lib64/libdl.so.2(dlsym+0x5a)[0x7f9bfcfa843a]
/home/sam/devel/log-malloc2/scripts/../.libs/liblog-malloc2.so(+0x12e3)[0x7f9bfd7882e3]
/lib64/ld-linux-x86-64.so.2(+0xfa0b)[0x7f9bfd99ba0b]
/lib64/ld-linux-x86-64.so.2(+0xfb1c)[0x7f9bfd99bb1c]
/lib64/ld-linux-x86-64.so.2(+0x140a)[0x7f9bfd98d40a]
/lib64/libdl.so.2(+0x13a0)[0x7f9bfcfa83a0]
# PID 23451
# EXE /home/sam/devel/log-malloc2/examples/leak-01
# CWD /home/sam/devel/log-malloc2
+ INIT [1736:1952] malloc=3 calloc=3 realloc=0 memalign=0/0 valloc=0 free=0
+ malloc 2000 0x7f9bff564800 [3736:3992] #3183 168 131 1 0 84 0
./examples/leak-01(main+0x32)[0x7f9bfdbb1af2]
/lib64/libc.so.6(__libc_start_main+0x11b)[0x7f9bfd3f01cb]
./examples/leak-01(+0x9a9)[0x7f9bfdbb19a9]
[0x0]
+ malloc 100 0x7f9bff565000 [3836:4128] #3183 168 131 1 0 84 0
./examples/leak-01(main+0x40)[0x7f9bfdbb1b00]
/lib64/libc.so.6(__libc_start_main+0x11b)[0x7f9bfd3f01cb]
./examples/leak-01(+0x9a9)[0x7f9bfdbb19a9]
[0x0]
+ free -100 0x7f9bff565000 [3736:3992] #3183 168 131 1 0 84 0
+ FINI [3736:3992] malloc=5 calloc=3 realloc=0 memalign=0/0 valloc=0 free=1
# FILE /proc/self/maps
7f9bfcd90000-7f9bfcda6000 r-xp 00000000 fe:02 911050                     /usr/lib64/gcc/x86_64-pc-linux-gnu/4.8.3/libgcc_s.so.1
7f9bfcda6000-7f9bfcfa5000 ---p 00016000 fe:02 911050                     /usr/lib64/gcc/x86_64-pc-linux-gnu/4.8.3/libgcc_s.so.1
7f9bfcfa5000-7f9bfcfa6000 r--p 00015000 fe:02 911050                     /usr/lib64/gcc/x86_64-pc-linux-gnu/4.8.3/libgcc_s.so.1
7f9bfcfa6000-7f9bfcfa7000 rw-p 00016000 fe:02 911050                     /usr/lib64/gcc/x86_64-pc-linux-gnu/4.8.3/libgcc_s.so.1
7f9bfcfa7000-7f9bfcfaa000 r-xp 00000000 fe:02 819448                     /lib64/libdl-2.19.so
7f9bfcfaa000-7f9bfd1a9000 ---p 00003000 fe:02 819448                     /lib64/libdl-2.19.so
7f9bfd1a9000-7f9bfd1aa000 r--p 00002000 fe:02 819448                     /lib64/libdl-2.19.so
7f9bfd1aa000-7f9bfd1ab000 rw-p 00003000 fe:02 819448                     /lib64/libdl-2.19.so
7f9bfd1ab000-7f9bfd1c5000 r-xp 00000000 fe:02 818913                     /lib64/libpthread-2.19.so
7f9bfd1c5000-7f9bfd3c5000 ---p 0001a000 fe:02 818913                     /lib64/libpthread-2.19.so
7f9bfd3c5000-7f9bfd3c6000 r--p 0001a000 fe:02 818913                     /lib64/libpthread-2.19.so
7f9bfd3c6000-7f9bfd3c7000 rw-p 0001b000 fe:02 818913                     /lib64/libpthread-2.19.so
7f9bfd3c7000-7f9bfd3cb000 rw-p 00000000 00:00 0
7f9bfd3cb000-7f9bfd57d000 r-xp 00000000 fe:02 819451                     /lib64/libc-2.19.so
7f9bfd57d000-7f9bfd77d000 ---p 001b2000 fe:02 819451                     /lib64/libc-2.19.so
7f9bfd77d000-7f9bfd781000 r--p 001b2000 fe:02 819451                     /lib64/libc-2.19.so
7f9bfd781000-7f9bfd783000 rw-p 001b6000 fe:02 819451                     /lib64/libc-2.19.so
7f9bfd783000-7f9bfd787000 rw-p 00000000 00:00 0
7f9bfd787000-7f9bfd78b000 r-xp 00000000 fe:02 14619                      /home/sam/devel/log-malloc2/.libs/liblog-malloc2.so.1.0.0
7f9bfd78b000-7f9bfd98a000 ---p 00004000 fe:02 14619                      /home/sam/devel/log-malloc2/.libs/liblog-malloc2.so.1.0.0
7f9bfd98a000-7f9bfd98b000 r--p 00003000 fe:02 14619                      /home/sam/devel/log-malloc2/.libs/liblog-malloc2.so.1.0.0
7f9bfd98b000-7f9bfd98c000 rw-p 00004000 fe:02 14619                      /home/sam/devel/log-malloc2/.libs/liblog-malloc2.so.1.0.0
7f9bfd98c000-7f9bfd9ae000 r-xp 00000000 fe:02 818908                     /lib64/ld-2.19.so
7f9bfdb99000-7f9bfdb9d000 rw-p 00000000 00:00 0
7f9bfdbad000-7f9bfdbae000 rw-p 00000000 00:00 0
7f9bfdbae000-7f9bfdbaf000 r--p 00022000 fe:02 818908                     /lib64/ld-2.19.so
7f9bfdbaf000-7f9bfdbb0000 rw-p 00023000 fe:02 818908                     /lib64/ld-2.19.so
7f9bfdbb0000-7f9bfdbb1000 rw-p 00000000 00:00 0
7f9bfdbb1000-7f9bfdbb2000 r-xp 00000000 fe:02 15340                      /home/sam/devel/log-malloc2/examples/leak-01
7f9bfddb1000-7f9bfddb2000 r--p 00000000 fe:02 15340                      /home/sam/devel/log-malloc2/examples/leak-01
7f9bfddb2000-7f9bfddb3000 rw-p 00001000 fe:02 15340                      /home/sam/devel/log-malloc2/examples/leak-01
7f9bff564000-7f9bff585000 rw-p 00000000 00:00 0                          [heap]
7fffb5471000-7fffb5493000 rw-p 00000000 00:00 0                          [stack]
7fffb54cf000-7fffb54d1000 r-xp 00000000 00:00 0                          [vdso]
ffffffffff600000-ffffffffff601000 r-xp 00000000 00:00 0                  [vsyscall]

###Example leak

$ ./scripts/log-malloc-findleak.pl /tmp/lm2.trace
SUSPECTED 1 LEAKS:
 0x7f4688a04000 leaked 100 bytes (0.10 KiB) allocated by malloc (line: 1)
       FUNCTION             FILE                      SYMBOL
       main                 examples/leak-01.c:10     ./examples/leak-01(main+0x40)[0x7f4687a6fb50]
                                                      /lib64/libc.so.6(__libc_start_main+0x11b)[0x7f46872ae1cb]
       _start               ??:?                      ./examples/leak-01(+0x9f9)[0x7f4687a6f9f9]
                                                      [0x0]

log-malloc2's People

Contributors

samsk avatar

Stargazers

 avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar

Watchers

 avatar  avatar  avatar  avatar  avatar

log-malloc2's Issues

-lunwind missing

On Ubuntu 16.04 with gcc 5.4, log-malloc -o /tmp/log fails with:
symbol lookup error: /usr/local/lib/liblog-malloc2.so: undefined symbol: _Ux86_64_getcontext

git clone https://github.com/samsk/log-malloc2.git
cd log-malloc
.configure
make
sudo make install

ldd /usr/local/lib/liblog-malloc2.so linux-vdso.so.1 => (0x00007ffcf2ba6000)
libpthread.so.0 => /lib/x86_64-linux-gnu/libpthread.so.0 (0x00007fd5d9f4d000)
libdl.so.2 => /lib/x86_64-linux-gnu/libdl.so.2 (0x00007fd5d9d49000)
libc.so.6 => /lib/x86_64-linux-gnu/libc.so.6 (0x00007fd5d997f000)
/lib64/ld-linux-x86-64.so.2 (0x00007fd5da16a000)

$ nm /usr/lib/x86_64-linux-gnu/libunwind.a | grep _Ux86_64_getcontext
U _Ux86_64_getcontext
U _Ux86_64_getcontext_trace
U _Ux86_64_getcontext
U _Ux86_64_getcontext
U _Ux86_64_getcontext
U _Ux86_64_getcontext
U _Ux86_64_getcontext
0000000000000000 T _Ux86_64_getcontext
0000000000000071 T _Ux86_64_getcontext_trace

I patched LDFLAGS as:
LDFLAGS="$LDFLAGS -lunwind-generic -lunwind"

$ ldd -v /usr/local/lib/liblog-malloc2.so
linux-vdso.so.1 => (0x00007ffe80496000)
libunwind.so.8 => /usr/lib/x86_64-linux-gnu/libunwind.so.8 (0x00007f4a910bc000)
libpthread.so.0 => /lib/x86_64-linux-gnu/libpthread.so.0 (0x00007f4a90e9f000)
libdl.so.2 => /lib/x86_64-linux-gnu/libdl.so.2 (0x00007f4a90c9b000)
libc.so.6 => /lib/x86_64-linux-gnu/libc.so.6 (0x00007f4a908d1000)
/lib64/ld-linux-x86-64.so.2 (0x00007f4a912d7000)
liblzma.so.5 => /lib/x86_64-linux-gnu/liblzma.so.5 (0x00007f4a906af000)

Now I go on to fail with:
MEMORY-ERROR: [25619]: GSlice: failed to allocate 1008 bytes (alignment: 1024): Cannot allocate memory

Invalid log in multithreaded app on Linux

I am trying to run log-malloc-2 on the CentOS 7 with my highly-multithreaded applications (runs tens of threads) and getting strange, invalid output in the log (executable name and most function names in stack traces are intentionally obfuscated):

+ malloc 24 0x1e65f40 [895997:990912] #84410 3015 2364 2746 0 34282 0
/lib64/libstdc++.so.6(_Znwm+0x1d)[0x7f54d1cde18d]
+ malloc 43 0x7f54c00008e0 [895973:990856] #84410 3015 2364 2746 0 34282 0
+ malloc 56 0x7f54c0000940 [896053:991000] #84410 3015 2364 2746 0 34282 0
+ malloc 31 0x7f54c00009a0 [896084:991072] #84410 3015 2364 2746 0 34282 0
+ malloc 31 0x7f54c00009f0 [896115:991144] #84410 3015 2364 2746 0 34282 0
+ malloc 37 0x7f54c0000a40 [896152:991216] #84410 3015 2364 2746 0 34282 0
+ free -31 0x7f54c00009f0 [896121:991144] #84410 3015 2364 2746 0 34282 0
+ malloc 49 0x7f54c0000a90 [896170:991232] #84410 3015 2364 2746 0 34282 0
+ free -37 0x7f54c0000a40 [896133:991160] #84410 3015 2364 2746 0 34282 0
+ free -31 0x7f54c00009a0 [896102:991088] #84410 3015 2364 2746 0 34282 0
+ free -49 0x7f54c0000a90 [896053:991000] #84410 3015 2364 2746 0 34282 0
+ malloc 376 0x7f54c0000af0 [896429:991408] #84410 3015 2364 2746 0 34282 0
+ malloc 40 0x7f54c00009a0 [896469:991480] #84410 3015 2364 2746 0 34282 0
./my_application(_myf2+0x33a)[0x68500a]
+ malloc 537 0x7f54c0000c90 [897006:992064] #84410 3015 2364 2746 0 34282 0
+ malloc 70 0x7f54c0000ee0 [897076:992168] #84410 3015 2364 2746 0 34282 0
+ free -70 0x7f54c0000ee0 [897006:992064] #84410 3015 2364 2746 0 34282 0
+ malloc 68 0x7f54c0000ee0 [897074:992168] #84410 3015 2364 2746 0 34282 0
+ free -68 0x7f54c0000ee0 [897006:992064] #84410 3015 2364 2746 0 34282 0
./my_application(_myf1+0xbf)[0x6858af]
./my_application(_myf00+0x59b)[0x6841fb]
./my_application(_myf000+0x33)[0x690ed3]
./my_application(_myf0000+0xb7)[0xac683b]
[0x0]

i.e. multiple malloc appear w/o stack trace at all, first malloc has only one frame of the stack trace and later on, more frames appear after free. It looks to me as output synchronization issue, but I've tried to look at log-malloc sources and seems like synchronization is present and properly done. So what could be the reason?

Configuration: log-malloc compiled with GCC 4.8.5 on CentOS 7. I have pthreads, libunwind but don't have "unwind details". Application under log-malloc compiled with GCC 7.3.1 (from the RedHat Devtoolset 7) on CentOS 7 and actively uses pthreads.

GSlice: Cannot allocate memory (with _posix_memalign)

Applications that use cv::fastMalloc to call posix_memalign(&ptr, CV_MALLOC_ALIGN, size) fail during dl_init with:
MEMORY-ERROR: [20699]: GSlice: failed to allocate 1008 bytes (alignment: 1024): Cannot allocate memory

#include <opencv2/core/core.hpp>
int main(int argc, char* argv[]) {
// cv::fastMalloc(1024);
return 0;
}

Reference: https://github.com/opencv/opencv/blob/master/modules/core/src/alloc.cpp

$ LD_PRELOAD=/usr/local/lib/liblog-malloc2.so lldb-8 -- ./WS/build/test/OcvMatcherTest
*** log-malloc trace-fd = 1022 ***
*** log-malloc trace-fd = 1022 ***
*** log-malloc trace-fd = 1022 ***

(lldb) r
...
MEMORY-ERROR: [20871]: GSlice: failed to allocate 1008 bytes (alignment: 1024): Cannot allocate memory

Process 20871 stopped

  • thread #1, name = 'OcvMatcherTest', stop reason = signal SIGABRT
    frame #0: 0x00007fffc25ca428 libc.so.6`__GI_raise(sig=6) at raise.c:54
    (lldb) bt
  • thread #1, name = 'OcvMatcherTest', stop reason = signal SIGABRT
    • frame #0: 0x00007fffc25ca428 libc.so.6__GI_raise(sig=6) at raise.c:54 frame #1: 0x00007fffc25cc02a libc.so.6__GI_abort at abort.c:89
      frame #2: 0x00007fffbf84a961 libglib-2.0.so.0___lldb_unnamed_symbol277$$libglib-2.0.so.0 + 273 frame #3: 0x00007fffbf84b406 libglib-2.0.so.0___lldb_unnamed_symbol282$$libglib-2.0.so.0 + 518
      frame #4: 0x00007fffbf84bfba libglib-2.0.so.0g_slice_alloc + 1594 frame #5: 0x00007fffbf81d74e libglib-2.0.so.0g_hash_table_new_full + 30
      frame #6: 0x00007fffbf83e94b libglib-2.0.so.0___lldb_unnamed_symbol241$$libglib-2.0.so.0 + 75 frame #7: 0x00007ffff7de76ca ld-2.23.socall_init(l=, argc=1, argv=0x00007fffffffde78, env=0x00007fffffffde88) at dl-init.c:72
      frame #8: 0x00007ffff7de77db ld-2.23.so_dl_init at dl-init.c:30 frame #9: 0x00007ffff7de77c5 ld-2.23.so_dl_init(main_map=0x00007ffff7ffe168, argc=1, argv=0x00007fffffffde78, env=0x00007fffffffde88) at dl-init.c:120
      frame #10: 0x00007ffff7dd7c6a ld-2.23.so`_dl_start_user + 50

The problem could be related to dl_init of libopencv_core.so.3.4 (walking on thin ice here). For instance, running under G_SLICE=always-malloc, my application (or the reproducer) recurses to failure in cv::fastMalloc (OpenCV 3.4.5, gcc 5.4 and CUDA 8.0 on 16.04) OR (OpenCV 3.4.5, gcc 7.3 without CUDA on 18.04).

(lldb) thread backtrace -c 11 -s 17080

  • thread #1, name = 'MidasATAdjust', stop reason = signal SIGSEGV: invalid address (fault address: 0x7fffff7feff8)
    frame #17080: 0x00007ffff6effb8a libopencv_core.so.3.4cv::fastMalloc(unsigned long) + 90 frame #17081: 0x00007ffff6e6de1d libopencv_core.so.3.4cv::String::allocate(unsigned long) + 29
    frame #17082: 0x00007ffff7021759 libopencv_core.so.3.4cv::format(char const*, ...) + 521 frame #17083: 0x00007ffff6effb8a libopencv_core.so.3.4cv::fastMalloc(unsigned long) + 90
    frame #17084: 0x00007ffff6efcb12 libopencv_core.so.3.4cvRegisterType + 434 frame #17085: 0x00007ffff6e36774 libopencv_core.so.3.4CvType::CvType(char const*, int ()(void const), void ()(void**), void ()(CvFileStorage, CvFileNode*), void ()(CvFileStorage, char const*, void const*, CvAttrList), void* ()(void const)) + 100
    frame #17086: 0x00007ffff6e367dd libopencv_core.so.3.4_GLOBAL__sub_I_persistence_types.cpp + 61 frame #17087: 0x00007ffff7de76ca ld-2.23.socall_init(l=, argc=7, argv=0x00007fffffffdcb8, env=0x00007fffffffdcf8) at dl-init.c:72
    frame #17088: 0x00007ffff7de77db ld-2.23.so_dl_init at dl-init.c:30 frame #17089: 0x00007ffff7de77c5 ld-2.23.so_dl_init(main_map=0x00007ffff7ffe168, argc=7, argv=0x00007fffffffdcb8, env=0x00007fffffffdcf8) at dl-init.c:120
    frame #17090: 0x00007ffff7dd7c6a ld-2.23.so`_dl_start_user + 50

Recommend Projects

  • React photo React

    A declarative, efficient, and flexible JavaScript library for building user interfaces.

  • Vue.js photo Vue.js

    ๐Ÿ–– Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.

  • Typescript photo Typescript

    TypeScript is a superset of JavaScript that compiles to clean JavaScript output.

  • TensorFlow photo TensorFlow

    An Open Source Machine Learning Framework for Everyone

  • Django photo Django

    The Web framework for perfectionists with deadlines.

  • D3 photo D3

    Bring data to life with SVG, Canvas and HTML. ๐Ÿ“Š๐Ÿ“ˆ๐ŸŽ‰

Recommend Topics

  • javascript

    JavaScript (JS) is a lightweight interpreted programming language with first-class functions.

  • web

    Some thing interesting about web. New door for the world.

  • server

    A server is a program made to process requests and deliver data to clients.

  • Machine learning

    Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.

  • Game

    Some thing interesting about game, make everyone happy.

Recommend Org

  • Facebook photo Facebook

    We are working to build community through open source technology. NB: members must have two-factor auth.

  • Microsoft photo Microsoft

    Open source projects and samples from Microsoft.

  • Google photo Google

    Google โค๏ธ Open Source for everyone.

  • D3 photo D3

    Data-Driven Documents codes.