Bug 378494 - Debugee terminates on any signal
Summary: Debugee terminates on any signal
Status: RESOLVED FIXED
Alias: None
Product: Heaptrack
Classification: Applications
Component: general (other bugs)
Version First Reported In: unspecified
Platform: Other Linux
: NOR normal
Target Milestone: ---
Assignee: Milian Wolff
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2017-04-06 08:58 UTC by Maksim Golov
Modified: 2017-04-07 12:24 UTC (History)
0 users

See Also:
Latest Commit:
Version Fixed/Implemented In:
Sentry Crash Report:


Attachments
A reproducer which handles SIGTERM (1.90 KB, text/plain)
2017-04-06 08:58 UTC, Maksim Golov
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Maksim Golov 2017-04-06 08:58:08 UTC
Created attachment 104899 [details]
A reproducer which handles SIGTERM

When running under heaptrack, a debuggee is terminated upon receiving any signal even when it handles that signal. As a result, no memory cleanup on shutdown happens and heaptrack reports false positives for memory leaks.

OS: Centos 7.2
Heaptrack version: c513793b

Reproduction steps:

# Build

~/work/heaptrack-eval $ g++ -std=c++11 -pthread test.cpp

# Interrupt by Ctrl-C

~/work/heaptrack-eval $ ./a.out
Started, press Ctrl-C to abort
^CInterrupted
Done.

# Interrrupt by "kill -TERM `pidof a.out`"

~/work/heaptrack-eval $ ./a.out
Started, press Ctrl-C to abort
Interrupted
Done.

# Run under heaptrack and interrupt by "kill -TERM `pidof a.out`"

~/work/heaptrack-eval $ heaptrack ./a.out
heaptrack output will be written to "/home/centos/work/heaptrack-eval/heaptrack.a.out.20509.gz"
starting application, this might take some time...
Started, press Ctrl-C to abort
heaptrack stats:
	allocations:          	2
	leaked allocations:   	2
	temporary allocations:	0
/usr/local/bin/heaptrack: line 195: 20525 Terminated              LD_PRELOAD=$LIBHEAPTRACK_PRELOAD${LD_PRELOAD:+:$LD_PRELOAD} DUMP_HEAPTRACK_OUTPUT="$pipe" "$client" "$@"
Heaptrack finished! Now run the following to investigate the data:

  heaptrack_print "/home/centos/work/heaptrack-eval/heaptrack.a.out.20509.gz" | less

# Check for leaks - `p` is not freed

centos@maxim-dev7 ~/work/heaptrack-eval $ heaptrack_print -l 1 "/home/centos/work/heaptrack-eval/heaptrack.a.out.20509.gz"
reading file "/home/centos/work/heaptrack-eval/heaptrack.a.out.20509.gz" - please wait, this might take some time...
Debuggee command was: ./a.out
Failed to read time stamp: c
finished reading file, now analyzing data:

MOST CALLS TO ALLOCATION FUNCTIONS
1 calls to allocation functions with 1000.00B peak consumption from
main
  in /home/centos/work/heaptrack-eval/a.out
1 calls with 1000.00B peak consumption from:

1 calls to allocation functions with 608B peak consumption from
_dl_allocate_tls
  in /lib64/ld-linux-x86-64.so.2
1 calls with 608B peak consumption from:
    __pthread_create_2_1
      in /lib64/libpthread.so.0
    main
      in /home/centos/work/heaptrack-eval/a.out


PEAK MEMORY CONSUMERS

WARNING - the data below is not an accurate calcuation of the total peak consumption and can easily be wrong.
 For an accurate overview, disable backtrace merging.
1000.00B peak memory consumed over 1 calls from
main
  in /home/centos/work/heaptrack-eval/a.out
1000.00B consumed over 1 calls from:

608B peak memory consumed over 1 calls from
_dl_allocate_tls
  in /lib64/ld-linux-x86-64.so.2
608B consumed over 1 calls from:
    __pthread_create_2_1
      in /lib64/libpthread.so.0
    main
      in /home/centos/work/heaptrack-eval/a.out

MEMORY LEAKS
1000.00B leaked over 1 calls from
main
  in /home/centos/work/heaptrack-eval/a.out
1000.00B leaked over 1 calls from:

608B leaked over 1 calls from
_dl_allocate_tls
  in /lib64/ld-linux-x86-64.so.2
608B leaked over 1 calls from:
    __pthread_create_2_1
      in /lib64/libpthread.so.0
    main
      in /home/centos/work/heaptrack-eval/a.out


MOST TEMPORARY ALLOCATIONS

total runtime: 2.73s.
bytes allocated in total (ignoring deallocations): 1.61KB (590B/s)
calls to allocation functions: 2 (0/s)
temporary memory allocations: 0 (0/s)
peak heap memory consumption: 1.61KB
peak RSS (including heaptrack overhead): 4.35MB
total memory leaked: 1.61KB

# Same scenario with "kill -HUP `pidof a.out`"

~/work/heaptrack-eval $ heaptrack ./a.out
heaptrack output will be written to "/home/centos/work/heaptrack-eval/heaptrack.a.out.21914.gz"
starting application, this might take some time...
Started, press Ctrl-C to abort
heaptrack stats:
  allocations:            2
  leaked allocations:     2
  temporary allocations:  0
/usr/local/bin/heaptrack: line 195: 21935 Hangup                  LD_PRELOAD=$LIBHEAPTRACK_PRELOAD${LD_PRELOAD:+:$LD_PRELOAD} DUMP_HEAPTRACK_OUTPUT="$pipe" "$client" "$@"
Heaptrack finished! Now run the following to investigate the data:

  heaptrack_print "/home/centos/work/heaptrack-eval/heaptrack.a.out.21914.gz" | less
Comment 1 Milian Wolff 2017-04-07 09:52:48 UTC
Confirmed, can reproduce. I'll try to write a proper test for this and fix it, once I get the time for that.

More information from Maxim that I think is valuable tohave here:

This happens even if the heaptrack_preload.so is injected manually
(so the heaptrack script is not involved); could not get any further.

Under gdb see this:

terminal 1 $ heaptrack ./a.out
heaptrack output will be written to
"/home/centos/work/heaptrack-eval/heaptrack.a.out.22665.gz"
starting application, this might take some time...
Started, press Ctrl-C to abort

(switch to terminal 2) $ gdb ./a.out `pidof a.out`
(gdb) handle SIGTERM nostop pass
Signal        Stop Print Pass to program Description
SIGTERM       No Yes Yes Terminated
(gdb) c
Continuing.

# in terminal 3: kill -TERM `pidof a.out`

[Thread 0x7fe831af1700 (LWP 22683) exited]
[Thread 0x7fe833b31780 (LWP 22681) exited]
[Inferior 1 (process 22681) exited normally]
(gdb)

In terminal 1:

Interrupted
Done.
heaptrack stats:
allocations:           2
leaked allocations:   1
temporary allocations: 0
Heaptrack finished! Now run the following to investigate the data:

  heaptrack_print
"/home/centos/work/heaptrack-eval/heaptrack.a.out.22665.gz" | less


So under GDB the signal is passed to the debuggee correctly if gdb is set
up for that.
Comment 2 Milian Wolff 2017-04-07 10:16:32 UTC
What's odd is that it does not happen when I disable the timer thread. Stracing the signals syscalls also doesn't reveal anything obvious. I still have no clue what's going on here.
Comment 3 Milian Wolff 2017-04-07 10:31:33 UTC
ah, I can reproduce the issue with your test code even without heaptrack, when I slightly modify it:

at the very start of main, add:

auto t = std::thread([]() { while(true) {std::this_thread::sleep_for(std::chrono::milliseconds(1000));} });

this is essentially what happens when `char *p = new char[1000];` is handled by heaptrack - we spin up the timer thread and that then messes with your code. I'm not a C person, and also have close to zero experience with signals. can you explain the behavior with the above change excluding heaptrack?
Comment 4 Maksim Golov 2017-04-07 10:50:24 UTC
I was not aware of timer thread, must have missed it in my reading of heaptrack code. Likely it has the signals enabled and gets to handle the signal instead of the signal thread.

Not sure how this can be addressed, maybe disable signals for the timer thread completely?
Comment 5 Maksim Golov 2017-04-07 10:55:26 UTC
What the code in the reproduce does is to ensure that all signals are handled by a single dedicated thread only, and all other threads have them disabled. This ensures that the signals are handled in well-defined manner.
Comment 6 Milian Wolff 2017-04-07 11:14:09 UTC
Indeed, that work-arounds this issue:

diff --git a/src/track/libheaptrack.cpp b/src/track/libheaptrack.cpp
index b21b00b..6df2101 100644
--- a/src/track/libheaptrack.cpp
+++ b/src/track/libheaptrack.cpp
@@ -30,6 +30,8 @@
 #include <fcntl.h>
 #include <link.h>
 #include <stdio_ext.h>
+#include <pthread.h>
+#include <signal.h>
 
 #include <atomic>
 #include <cinttypes>
@@ -487,6 +489,14 @@ private:
                 fprintf(stderr, "WARNING: Failed to open /proc/self/statm for reading.\n");
             }
             timerThread = thread([&]() {
+                sigset_t mask;
+                sigfillset(&mask);
+                int ret = pthread_sigmask(SIG_SETMASK, &mask, nullptr);
+                if (ret < 0) {
+                    perror("failed to block signals, disabling timer thread");
+                    return;
+                }
+
                 RecursionGuard::isActive = true;
                 debugLog<MinimalOutput>("%s", "timer thread started");
                 while (!stopTimerThread) {


I'm simply a bit reluctant applying it, as I don't know what else it could potentially break...
Comment 7 Milian Wolff 2017-04-07 11:17:20 UTC
Reading up a bit, I think this patch should actually quite safe to do. Can you confirm, considering you seem to have more knowledge around this idiom? If so, then I'd push it to master in the hope that it's not breaking anything else ;-)
Comment 8 Maksim Golov 2017-04-07 11:34:17 UTC
Confirm that it works for my case.

One thing to note, the proposed patch introduces a dependency on pthreads, which is probably quite safe in practice, and I'd expect CMake can probe for pthreads being available. I wouldn't be able to say if there are potential heaptrack users affected by this, though.

An alternative would be to somehow allow the application to expose a hook which heaptrack will call when starting the timer thread - not sure if this is worth the trouble.
Comment 9 Milian Wolff 2017-04-07 11:50:24 UTC
heaptrack already depends on pthread (for the timer thread). I also asked a colleague and he confirmed this is safe to do. I'll push it - thanks for the report and helpful test case!
Comment 10 Milian Wolff 2017-04-07 12:24:57 UTC
Git commit e203d56632b94e6607d6cdc8710f947d644fc764 by Milian Wolff.
Committed on 07/04/2017 at 12:24.
Pushed by mwolff into branch 'master'.

Disable signal handling in timer thread

When the host application sets up a custom signal handler thread
only that thread is supposed to handle the signals. But heaptrack
spawns up the timer thread on initialization, i.e. when it
first encounters a memory allocation. This usually happens before
the host application has setup the signal mask. As such, our timer
thread would still receive e.g. SIGTERM and then shutdown the whole
application.

Now, we disable signal handling in the helper thread to fix this
behavior for applications that rely on it.

M  +24   -0    src/track/libheaptrack.cpp
M  +3    -0    tests/manual/CMakeLists.txt
A  +110  -0    tests/manual/signals.cpp     [License: LGPL (v2+)]

https://commits.kde.org/heaptrack/e203d56632b94e6607d6cdc8710f947d644fc764