[RFC] print stack trace after each syscall
Luca Clementi
luca.clementi at gmail.com
Mon Jun 24 07:18:58 UTC 2013
This patch prints the stack trace of the traced process after
each system call when using -k flag. It uses libunwind to
unwind the stack and to obtain the function name pointed by
the IP.
Tested on Ubuntu 12.04 64 with the distribution version of
libunwind (0.99-0.3ubuntu1) and on CentOS 6.3 with libunwind
form the source code. On Ubuntu you need the libunwind and
libunwind-dev package to compile the stack trace feature in
the code.
This is still a development patch, please let me know if you
would consider pulling this patch and if so what do you think
should be modified (I will also write man page and better
autoconf script).
Some of this code was originally taken from strace-plus of
Philip J. Guo.
---
configure.ac | 24 +++++++
defs.h | 38 +++++++++++
mem.c | 12 ++++
process.c | 4 ++
strace.c | 45 +++++++++++++
syscall.c | 200 ++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
6 files changed, 323 insertions(+)
diff --git a/configure.ac b/configure.ac
index c4896f3..aa89399 100644
--- a/configure.ac
+++ b/configure.ac
@@ -261,6 +261,30 @@ AC_CHECK_MEMBERS([struct sigcontext.sc_hi2],,, [#include <signal.h>
# include <asm/sigcontext.h>
#endif])
+dnl libunwind tests
+AC_CHECK_HEADERS([libunwind-ptrace.h libunwind.h])
+
+if test "x$ac_cv_header_libunwind_ptrace_h" == "xyes" &&
+ test "x$ac_cv_header_libunwind_h" == "xyes"; then :
+
+ AC_CHECK_LIB([unwind], [backtrace],[],[
+ AC_MSG_FAILURE([Unable to find libunwind])
+ ])
+ AC_CHECK_LIB([unwind-$arch], [_U${arch}_create_addr_space],[], [
+ AC_MSG_FAILURE([Unable to find libunwind-$arch])
+ ])
+ AC_CHECK_LIB([unwind-ptrace], [_UPT_create],[], [
+ AC_MSG_FAILURE([Unable to find libunwind-ptrace])
+ ])
+
+ dnl everything is find we can activate stack tracing
+ AC_DEFINE([LIB_UNWIND], 1, [Compile stack tracing functionality])
+ AC_MSG_NOTICE([Enabled stack tracing])
+fi
+
+AM_CONDITIONAL([LIB_UNWIND], [test "x$ac_cv_lib_unwind_ptrace__UPT_create" == "xyes"])
+
+
AC_CHECK_MEMBERS([struct utsname.domainname],,, [#include <sys/utsname.h>])
AC_CHECK_DECLS([sys_errlist])
diff --git a/defs.h b/defs.h
index 3f07c4f..83d9a1e 100644
--- a/defs.h
+++ b/defs.h
@@ -392,6 +392,29 @@ typedef struct ioctlent {
unsigned long code;
} struct_ioctlent;
+
+#ifdef LIB_UNWIND
+#include <libunwind-ptrace.h>
+#include <libunwind.h>
+
+/* keep a sorted array of cache entries, so that we can binary search
+ * through it
+ */
+struct mmap_cache_t {
+ // example entry:
+ // 7fabbb09b000-7fabbb09f000 r--p 00179000 fc:00 1180246 /lib/libc-2.11.1.so
+ //
+ // start_addr is 0x7fabbb09b000
+ // end_addr is 0x7fabbb09f000
+ // mmap_offset is 0x179000
+ // binary_filename is "/lib/libc-2.11.1.so"
+ unsigned long start_addr;
+ unsigned long end_addr;
+ unsigned long mmap_offset;
+ char* binary_filename;
+};
+#endif
+
/* Trace Control Block */
struct tcb {
int flags; /* See below for TCB_ values */
@@ -417,6 +440,13 @@ struct tcb {
struct timeval etime; /* Syscall entry time */
/* Support for tracing forked processes: */
long inst[2]; /* Saved clone args (badly named) */
+
+#ifdef LIB_UNWIND
+ // keep a cache of /proc/<pid>/mmap contents to avoid unnecessary file reads
+ struct mmap_cache_t* mmap_cache;
+ int mmap_cache_size;
+ struct UPT_info* libunwind_ui;
+#endif
};
/* TCB flags */
@@ -710,6 +740,14 @@ extern void tv_sub(struct timeval *, struct timeval *, struct timeval *);
extern void tv_mul(struct timeval *, struct timeval *, int);
extern void tv_div(struct timeval *, struct timeval *, int);
+#ifdef LIB_UNWIND
+/**
+ * print stack (-k flag) memory allocation and deallocation
+ */
+extern void alloc_mmap_cache(struct tcb* tcp);
+extern void delete_mmap_cache(struct tcb* tcp);
+#endif
+
/* Strace log generation machinery.
*
* printing_tcp: tcb which has incomplete line being printed right now.
diff --git a/mem.c b/mem.c
index ef273c7..8c0663a 100644
--- a/mem.c
+++ b/mem.c
@@ -175,6 +175,10 @@ static int
print_mmap(struct tcb *tcp, long *u_arg, unsigned long long offset)
{
if (entering(tcp)) {
+#ifdef LIB_UNWIND
+ /* clean the cache */
+ delete_mmap_cache(tcp);
+#endif
/* addr */
if (!u_arg[0])
tprints("NULL, ");
@@ -304,6 +308,10 @@ sys_munmap(struct tcb *tcp)
tprintf("%#lx, %lu",
tcp->u_arg[0], tcp->u_arg[1]);
}
+#ifdef LIB_UNWIND
+ if (!entering(tcp))
+ delete_mmap_cache(tcp);
+#endif
return 0;
}
@@ -315,6 +323,10 @@ sys_mprotect(struct tcb *tcp)
tcp->u_arg[0], tcp->u_arg[1]);
printflags(mmap_prot, tcp->u_arg[2], "PROT_???");
}
+#ifdef LIB_UNWIND
+ if (!entering(tcp))
+ delete_mmap_cache(tcp);
+#endif
return 0;
}
diff --git a/process.c b/process.c
index 799a314..a370ba1 100644
--- a/process.c
+++ b/process.c
@@ -1197,6 +1197,10 @@ sys_waitid(struct tcb *tcp)
printrusage(tcp, tcp->u_arg[4]);
}
}
+#ifdef LIB_UNWIND
+ if (!entering(tcp))
+ delete_mmap_cache(tcp);
+#endif
return 0;
}
diff --git a/strace.c b/strace.c
index 6eab600..e972d5c 100644
--- a/strace.c
+++ b/strace.c
@@ -190,6 +190,15 @@ strerror(int err_no)
#endif /* HAVE_STERRROR */
+
+#ifdef LIB_UNWIND
+/* if this is 1, then do the stack trace for every system call
+ */
+int use_libunwind = 0;
+unw_addr_space_t libunwind_as;
+#endif
+
+
static void
usage(FILE *ofp, int exitval)
{
@@ -232,6 +241,10 @@ usage: strace [-CdffhiqrtttTvVxxy] [-I n] [-e expr]...\n\
-E var -- remove var from the environment for command\n\
-P path -- trace accesses to path\n\
"
+#ifdef LIB_UNWIND
+"-k obtain stack trace between each syscall\n\
+"
+#endif
/* ancient, no one should use it
-F -- attempt to follow vforks (deprecated, use -f)\n\
*/
@@ -685,6 +698,15 @@ alloctcb(int pid)
#if SUPPORTED_PERSONALITIES > 1
tcp->currpers = current_personality;
#endif
+
+#ifdef LIB_UNWIND
+ tcp->mmap_cache = NULL;
+ tcp->mmap_cache_size = 0;
+ if (use_libunwind) {
+ tcp->libunwind_ui = _UPT_create(tcp->pid);
+ }
+#endif
+
nprocs++;
if (debug_flag)
fprintf(stderr, "new tcb for pid %d, active tcbs:%d\n", tcp->pid, nprocs);
@@ -721,6 +743,12 @@ droptcb(struct tcb *tcp)
if (printing_tcp == tcp)
printing_tcp = NULL;
+#ifdef LIB_UNWIND
+ if (use_libunwind) {
+ delete_mmap_cache(tcp);
+ _UPT_destroy(tcp->libunwind_ui);
+ }
+#endif
memset(tcp, 0, sizeof(*tcp));
}
@@ -1578,6 +1606,9 @@ init(int argc, char *argv[])
qualify("signal=all");
while ((c = getopt(argc, argv,
"+b:cCdfFhiqrtTvVxyz"
+#ifdef LIB_UNWIND
+ "k"
+#endif
"D"
"a:e:o:O:p:s:S:u:E:P:I:")) != EOF) {
switch (c) {
@@ -1680,6 +1711,11 @@ init(int argc, char *argv[])
case 'u':
username = strdup(optarg);
break;
+#ifdef LIB_UNWIND
+ case 'k':
+ use_libunwind = 1;
+ break;
+#endif
case 'E':
if (putenv(optarg) < 0)
die_out_of_memory();
@@ -1711,6 +1747,15 @@ init(int argc, char *argv[])
error_msg_and_die("-D and -p are mutually exclusive");
}
+#ifdef LIB_UNWIND
+ if (use_libunwind) {
+ libunwind_as = unw_create_addr_space (&_UPT_accessors, 0);
+ if (!libunwind_as) {
+ error_msg_and_die("Fatal error: unable to create address space for stack tracing\n");
+ }
+ }
+#endif
+
if (!followfork)
followfork = optF;
diff --git a/syscall.c b/syscall.c
index 7efee0e..ff73118 100644
--- a/syscall.c
+++ b/syscall.c
@@ -1946,6 +1946,194 @@ get_syscall_args(struct tcb *tcp)
return 1;
}
+#ifdef LIB_UNWIND
+
+extern unw_addr_space_t libunwind_as;
+
+/*
+ * caching of /proc/ID/maps for each process to speed up stack tracing
+ *
+ * The cache must be refreshed after some syscall: mmap, mprotect, munmap, execve
+ */
+void alloc_mmap_cache(struct tcb* tcp) {
+
+ if ( tcp->mmap_cache)
+ perror_msg_and_die("Memory map cache is empty");
+ if ( tcp->mmap_cache_size)
+ perror_msg_and_die("Memory map cache is empty");
+
+ /* start with a small dynamically-allocated array and then expand it */
+ int cur_array_size = 10;
+ struct mmap_cache_t* cache_head = malloc(cur_array_size * sizeof(*cache_head));
+ char filename[sizeof ("/proc/0123456789/maps")];
+
+ sprintf(filename, "/proc/%d/maps", tcp->pid);
+
+ FILE* f = fopen(filename, "r");
+ if ( ! f )
+ perror_msg_and_die("Unable to open %s", filename);
+ char s[300];
+ while (fgets(s, sizeof(s), f) != NULL) {
+ unsigned long start_addr, end_addr, mmap_offset;
+ char binary_path[512];
+ binary_path[0] = '\0'; // 'reset' it just to be paranoid
+
+ sscanf(s, "%lx-%lx %*c%*c%*c%*c %lx %*x:%*x %*d %[^\n]", &start_addr,
+ &end_addr, &mmap_offset, binary_path);
+
+ /* ignore special 'fake files' like "[vdso]", "[heap]", "[stack]", */
+ if (binary_path[0] == '[' && binary_path[strlen(binary_path) - 1] == ']') {
+ continue;
+ }
+
+ if (binary_path[0] == '\0') {
+ continue;
+ }
+
+ if(end_addr < start_addr)
+ perror_msg_and_die("Unrecognized maps file format %s", filename);
+
+ struct mmap_cache_t* cur_entry = &cache_head[tcp->mmap_cache_size];
+ cur_entry->start_addr = start_addr;
+ cur_entry->end_addr = end_addr;
+ cur_entry->mmap_offset = mmap_offset;
+ cur_entry->binary_filename = strdup(binary_path);
+
+ /* sanity check to make sure that we're storing non-overlapping regions in
+ * ascending order
+ */
+ if (tcp->mmap_cache_size > 0) {
+ struct mmap_cache_t* prev_entry = &cache_head[tcp->mmap_cache_size - 1];
+ if (prev_entry->start_addr >= cur_entry->start_addr)
+ perror_msg_and_die("Overlaying memory region in %s", filename);
+ if (prev_entry->end_addr > cur_entry->start_addr)
+ perror_msg_and_die("Overlaying memory region in %s", filename);
+ }
+ tcp->mmap_cache_size++;
+
+ /* resize doubling its size */
+ if (tcp->mmap_cache_size >= cur_array_size) {
+ cur_array_size *= 2;
+ cache_head = realloc(cache_head, cur_array_size * sizeof(*cache_head));
+ }
+ }
+ fclose(f);
+ tcp->mmap_cache = cache_head;
+}
+
+/* deleting the cache */
+void delete_mmap_cache(struct tcb* tcp) {
+ int i;
+ for (i = 0; i < tcp->mmap_cache_size; i++) {
+ free(tcp->mmap_cache[i].binary_filename);
+ }
+ free(tcp->mmap_cache);
+ tcp->mmap_cache = NULL;
+ tcp->mmap_cache_size = 0;
+}
+
+
+
+/*
+ * use libunwind to unwind the stack and print a backtrace
+ *
+ * Pre-condition: tcp->mmap_cache is already initialized
+ */
+void print_libunwind_backtrace(struct tcb* tcp) {
+ unw_word_t ip;
+ unw_cursor_t cursor;
+ unw_word_t function_off_set;
+ int stack_depth = 0, ret_val;
+
+ /* these are used for the binary search through the mmap_chace */
+ int lower, upper, mid;
+
+ int symbol_name_size = 40;
+ char * symbol_name;
+ struct mmap_cache_t* cur_mmap_cache;
+ unsigned long true_offset;
+
+ symbol_name = malloc(symbol_name_size);
+ if ( !symbol_name )
+ perror_msg_and_die("Unable to allocate memory to hold symbol name");
+
+ if ( unw_init_remote(&cursor, libunwind_as, tcp->libunwind_ui) < 0 )
+ perror_msg_and_die("Unable to initiate libunwind");
+
+ do {
+ /* looping on the stack frame */
+ if ( unw_get_reg(&cursor, UNW_REG_IP, &ip) < 0 )
+ perror_msg_and_die("Unable to walk the stack of process %d",
+ tcp->pid);
+
+ lower = 0;
+ upper = tcp->mmap_cache_size;
+
+ while ( lower <= upper ) {
+ /* find the mmap_cache and print the stack frame */
+ mid = (int)((upper + lower) / 2);
+ cur_mmap_cache = &tcp->mmap_cache[mid];
+
+ if (ip >= cur_mmap_cache->start_addr &&
+ ip < cur_mmap_cache->end_addr) {
+
+ do {
+ symbol_name[0] = '\0';
+ ret_val = unw_get_proc_name(&cursor, symbol_name,
+ symbol_name_size, &function_off_set);
+ if ( ret_val != -UNW_ENOMEM )
+ break;
+ symbol_name_size *= 2;
+ symbol_name = realloc(symbol_name, symbol_name_size);
+ if ( !symbol_name )
+ perror_msg_and_die("Unable to allocate memory to hold the symbol name");
+ } while ( 1 );
+
+ true_offset = ip - cur_mmap_cache->start_addr + cur_mmap_cache->mmap_offset;
+ if ( symbol_name[0] ){
+ /*
+ * we want to keep the format used by backtrace_symbols from the glibc
+ *
+ * ./a.out() [0x40063d]
+ * ./a.out() [0x4006bb]
+ * ./a.out() [0x4006c6]
+ * /lib64/libc.so.6(__libc_start_main+0xed) [0x7fa2f8a5976d]
+ * ./a.out() [0x400569]
+ */
+ tprintf(" > %s(%s+0x%lx) [0x%lx]\n", cur_mmap_cache->binary_filename,
+ symbol_name, function_off_set, true_offset);
+ line_ended();
+ }
+ else{
+ tprintf(" > %s() [0x%lx]\n", cur_mmap_cache->binary_filename, true_offset);
+ line_ended();
+ }
+
+ break; /* stack frame printed */
+ }
+ else if ( ip < cur_mmap_cache->start_addr )
+ upper = mid - 1;
+
+ else
+ lower = mid + 1;
+
+ }
+ if ( lower > upper ){
+ tprintf(" > Unmapped_memory_area:0x%lx\n", ip);
+ line_ended();
+ }
+
+ ret_val = unw_step(&cursor);
+
+ if ( ++stack_depth > 255 ) {
+ /* guard against bad unwind info in old libraries... */
+ perror_msg("libunwind warning: too deeply nested---assuming bogus unwind\n");
+ break;
+ }
+ } while (ret_val > 0);
+}
+#endif
+
static int
trace_syscall_entering(struct tcb *tcp)
{
@@ -2700,6 +2888,18 @@ trace_syscall_exiting(struct tcb *tcp)
dumpio(tcp);
line_ended();
+#ifdef LIB_UNWIND
+ extern int use_libunwind;
+ if (use_libunwind) {
+ // caching for efficiency ...
+ if (!tcp->mmap_cache) {
+ alloc_mmap_cache(tcp);
+ }
+ // use libunwind to unwind the stack, which works even for code compiled
+ print_libunwind_backtrace(tcp);
+ }
+#endif
+
ret:
tcp->flags &= ~TCB_INSYSCALL;
return 0;
--
1.7.9.5
More information about the Strace-devel
mailing list