[PATCHv2] print stack trace after each syscall
Denys Vlasenko
dvlasenk at redhat.com
Mon Jul 8 08:39:00 UTC 2013
On 07/08/2013 09:24 AM, Luca Clementi wrote:
> 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.
>
> Some of this code was originally taken from strace-plus of
> Philip J. Guo.
>
> v2:
> fixed several identation issues
> removed a strlen in alloc_mmap_cache (Denys)
> reload mmap_cache after execv
> fixed a bug in libunwind_backtrace binary search (Masatake)
> check return value of _UPT_create
> use die_out_of_memory after Xalloc
> use exiting instead of !entering
> created a new separate unwind.c file
> removed include from defs.h
> added --with-libunwind to autoconf script
> cleaned up defs.h from several inclusions
> ---
> Makefile.am | 10 ++-
> configure.ac | 57 +++++++++++++++
> defs.h | 45 ++++++++++++
> mem.c | 7 ++
> process.c | 8 +++
> strace.c | 43 ++++++++++++
> syscall.c | 9 +++
> unwind.c | 217 ++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
> 8 files changed, 395 insertions(+), 1 deletion(-)
> create mode 100644 unwind.c
>
> diff --git a/Makefile.am b/Makefile.am
> index 9d611f3..c8ad026 100644
> --- a/Makefile.am
> +++ b/Makefile.am
> @@ -12,7 +12,7 @@ ARCH = @arch@
>
> ACLOCAL_AMFLAGS = -I m4
> AM_CFLAGS = $(WARN_CFLAGS)
> -AM_CPPFLAGS = -I$(srcdir)/$(OS)/$(ARCH) -I$(srcdir)/$(OS) -I$(builddir)/$(OS)
> +AM_CPPFLAGS = -I$(srcdir)/$(OS)/$(ARCH) -I$(srcdir)/$(OS) -I$(builddir)/$(OS) $(libunwind_CPPFLAGS)
>
> strace_SOURCES = \
> bjm.c \
> @@ -43,6 +43,14 @@ strace_SOURCES = \
> util.c \
> vsprintf.c
>
> +
> +if LIB_UNWIND
> +strace_SOURCES += unwind.c
> +strace_LDADD = $(libunwind_LIBS)
> +AM_LDFLAGS = $(libunwind_LDFLAGS)
> +endif
> +
> +
> noinst_HEADERS = defs.h
> # Enable this to get link map generated
> #strace_CFLAGS = $(AM_CFLAGS) -Wl,-Map=strace.mapfile
> diff --git a/configure.ac b/configure.ac
> index 03e49fe..526fbda 100644
> --- a/configure.ac
> +++ b/configure.ac
> @@ -261,6 +261,63 @@ AC_CHECK_MEMBERS([struct sigcontext.sc_hi2],,, [#include <signal.h>
> # include <asm/sigcontext.h>
> #endif])
>
> +
> +dnl stack trace with libunwind
> +AC_ARG_WITH([libunwind],
> + [AS_HELP_STRING([--with-libunwind],
> + [libunwind is used to display system call stacktrace])],
> + [case "${withval}" in
> + (yes|no) enable_libunwind=$withval;;
> + (*) enable_libunwind=yes
> + libunwind_CPPFLAGS="${AM_CPPFLAGS} -I${withval}/include"
> + libunwind_LDFLAGS="-L${withval}/lib" ;;
> + esac],
> + [enable_libunwind=maybe])
> +
> +AS_IF([test "x$enable_libunwind" != xno],
> + [saved_CPPFLAGS="${CPPFLAGS}"
> + CPPFLAGS="${CPPFLAGS} ${libunwind_CPPFLAGS}"
> + AC_CHECK_HEADERS([libunwind-ptrace.h libunwind.h])
> + CPPFLAGS="${saved_CPPFLAGS}" ])
> +
> +if test "x$ac_cv_header_libunwind_ptrace_h" = "xyes" &&
> + test "x$ac_cv_header_libunwind_h" = "xyes"; then
> +
> + dnl code is taken from ltrace
> + case "${host_cpu}" in
> + arm*|sa110) UNWIND_ARCH="arm" ;;
> + i?86) UNWIND_ARCH="x86" ;;
> + powerpc) UNWIND_ARCH="ppc32" ;;
> + powerpc64) UNWIND_ARCH="ppc64" ;;
> + mips*) UNWIND_ARCH="mips" ;;
> + *) UNWIND_ARCH="${host_cpu}" ;;
> + esac
> +
> + saved_LDFLAGS="${LDFLAGS}"
> + LDFLAGS="${LDFLAGS} ${libunwind_LDFLAGS}"
> + AC_CHECK_LIB([unwind], [backtrace],
> + [libunwind_LIBS="-lunwind"],
> + [AC_MSG_FAILURE([Unable to find libunwind])])
> + AC_CHECK_LIB([unwind-generic], [_U${UNWIND_ARCH}_create_addr_space],
> + [libunwind_LIBS="-lunwind-generic $libunwind_LIBS"],
> + [AC_MSG_FAILURE([Unable to find libunwind-generic])],
> + [$libunwind_LIBS])
> + AC_CHECK_LIB([unwind-ptrace], [_UPT_create],
> + [libunwind_LIBS="-lunwind-ptrace $libunwind_LIBS"],
> + [AC_MSG_FAILURE([Unable to find libunwind-ptrace])],
> + [$libunwind_LIBS])
> + LDFLAGS="${saved_LDFLAGS}"
> +
> + dnl we have all the dependencies we need we can activate stack tracing
> + AC_SUBST(libunwind_LIBS)
> + AC_SUBST(libunwind_LDFLAGS)
> + AC_SUBST(libunwind_CPPFLAGS)
> + 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 64cfc8d..b314622 100644
> --- a/defs.h
> +++ b/defs.h
> @@ -405,6 +405,33 @@ typedef struct ioctlent {
> unsigned long code;
> } struct_ioctlent;
>
> +
> +#ifdef LIB_UNWIND
> +
> +/* 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;
> +};
> +
> +
> +/* if this is true do the stack trace for every system call */
> +extern bool use_libunwind;
> +#endif
> +
> /* Trace Control Block */
> struct tcb {
> int flags; /* See below for TCB_ values */
> @@ -430,6 +457,12 @@ struct tcb {
> struct timeval etime; /* Syscall entry time */
> /* Support for tracing forked processes: */
> long inst[2]; /* Saved clone args (badly named) */
> +
> +#ifdef LIB_UNWIND
> + struct mmap_cache_t* mmap_cache;
> + int mmap_cache_size;
> + struct UPT_info* libunwind_ui;
> +#endif
> };
>
> /* TCB flags */
> @@ -721,6 +754,18 @@ 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);
> +extern void print_stacktrace(struct tcb* tcp);
> +#else
> +# define alloc_mmap_cache(tcp) ((void)0)
> +# define delete_mmap_cache(tcp) ((void)0)
> +#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..a82b747 100644
> --- a/mem.c
> +++ b/mem.c
> @@ -175,6 +175,9 @@ static int
> print_mmap(struct tcb *tcp, long *u_arg, unsigned long long offset)
> {
> if (entering(tcp)) {
> + if (use_libunwind)
> + delete_mmap_cache(tcp);
> +
> /* addr */
> if (!u_arg[0])
> tprints("NULL, ");
> @@ -304,6 +307,8 @@ sys_munmap(struct tcb *tcp)
> tprintf("%#lx, %lu",
> tcp->u_arg[0], tcp->u_arg[1]);
> }
> + if (exiting(tcp) && use_libunwind)
> + delete_mmap_cache(tcp);
> return 0;
> }
>
> @@ -315,6 +320,8 @@ sys_mprotect(struct tcb *tcp)
> tcp->u_arg[0], tcp->u_arg[1]);
> printflags(mmap_prot, tcp->u_arg[2], "PROT_???");
> }
> + if (exiting(tcp) && use_libunwind)
> + delete_mmap_cache(tcp);
> return 0;
> }
>
> diff --git a/process.c b/process.c
> index e2fa25b..306aa23 100644
> --- a/process.c
> +++ b/process.c
> @@ -992,6 +992,10 @@ sys_execve(struct tcb *tcp)
> tprints("]");
> }
> }
> +
> + if (exiting(tcp) && use_libunwind)
> + delete_mmap_cache(tcp);
> +
> return 0;
> }
>
> @@ -1209,6 +1213,10 @@ sys_waitid(struct tcb *tcp)
> printrusage(tcp, tcp->u_arg[4]);
> }
> }
> +
> + if (exiting(tcp) && use_libunwind)
> + delete_mmap_cache(tcp);
> +
> return 0;
> }
>
> diff --git a/strace.c b/strace.c
> index a489db4..5956da6 100644
> --- a/strace.c
> +++ b/strace.c
> @@ -50,6 +50,13 @@ extern char **environ;
> extern int optind;
> extern char *optarg;
>
> +#ifdef LIB_UNWIND
> +# include <libunwind-ptrace.h>
> +
> +/* if this is true do the stack trace for every system call */
> +bool use_libunwind = false;
> +unw_addr_space_t libunwind_as;
> +#endif
>
> #if defined __NR_tkill
> # define my_tkill(tid, sig) syscall(__NR_tkill, (tid), (sig))
> @@ -231,6 +238,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 +696,15 @@ alloctcb(int pid)
> #if SUPPORTED_PERSONALITIES > 1
> tcp->currpers = current_personality;
> #endif
> +
> +#ifdef LIB_UNWIND
> + if (use_libunwind) {
> + tcp->libunwind_ui = _UPT_create(tcp->pid);
> + if (!tcp->libunwind_ui)
> + die_out_of_memory();
> + }
> +#endif
> +
> nprocs++;
> if (debug_flag)
> fprintf(stderr, "new tcb for pid %d, active tcbs:%d\n", tcp->pid, nprocs);
> @@ -721,6 +741,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));
> }
>
> @@ -1642,6 +1668,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) {
> @@ -1744,6 +1773,11 @@ init(int argc, char *argv[])
> case 'u':
> username = strdup(optarg);
> break;
> +#ifdef LIB_UNWIND
> + case 'k':
> + use_libunwind = true;
> + break;
> +#endif
> case 'E':
> if (putenv(optarg) < 0)
> die_out_of_memory();
> @@ -1775,6 +1809,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 f524b13..dee4c61 100644
> --- a/syscall.c
> +++ b/syscall.c
> @@ -2684,6 +2684,15 @@ trace_syscall_exiting(struct tcb *tcp)
> dumpio(tcp);
> line_ended();
>
> +#ifdef LIB_UNWIND
> + if (use_libunwind) {
> + if (!tcp->mmap_cache) {
> + alloc_mmap_cache(tcp);
> + }
> + print_stacktrace(tcp);
> + }
> +#endif
> +
> ret:
> tcp->flags &= ~TCB_INSYSCALL;
> return 0;
> diff --git a/unwind.c b/unwind.c
> new file mode 100644
> index 0000000..b7bd8ba
> --- /dev/null
> +++ b/unwind.c
> @@ -0,0 +1,217 @@
> +/*
> + * Copyright (c) 2013 Luca Clementi <luca.clementi at gmail.com>
> + *
> + * Redistribution and use in source and binary forms, with or without
> + * modification, are permitted provided that the following conditions
> + * are met:
> + * 1. Redistributions of source code must retain the above copyright
> + * notice, this list of conditions and the following disclaimer.
> + * 2. Redistributions in binary form must reproduce the above copyright
> + * notice, this list of conditions and the following disclaimer in the
> + * documentation and/or other materials provided with the distribution.
> + * 3. The name of the author may not be used to endorse or promote products
> + * derived from this software without specific prior written permission.
> + *
> + * THIS SOFTWARE IS PROVIDED BY THE AUTHOR ``AS IS'' AND ANY EXPRESS OR
> + * IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE IMPLIED WARRANTIES
> + * OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE ARE DISCLAIMED.
> + * IN NO EVENT SHALL THE AUTHOR BE LIABLE FOR ANY DIRECT, INDIRECT,
> + * INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT
> + * NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE,
> + * DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY
> + * THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
> + * (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE OF
> + * THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
> + */
> +
> +#include "defs.h"
> +
> +#include <libunwind.h>
> +
> +
> +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)
> +{
> + /* start with a small dynamically-allocated array and then expand it */
> + int cur_array_size = 10;
> + char filename[sizeof ("/proc/0123456789/maps")];
> + struct mmap_cache_t* cache_head = malloc(cur_array_size * sizeof(*cache_head));
> + if (!cache_head)
> + die_out_of_memory();
> +
> + sprintf(filename, "/proc/%d/maps", tcp->pid);
> +
> + FILE* f = fopen(filename, "r");
> + if (!f)
> + perror_msg_and_die("Can't 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] == '[') {
> + 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));
> + if (!cache_head)
> + die_out_of_memory();
> + }
> + }
> + 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_stacktrace(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)
> + die_out_of_memory();
Looks like you leak symbol_name.
> + if (unw_init_remote(&cursor, libunwind_as, tcp->libunwind_ui) < 0)
> + perror_msg_and_die("Can't initiate libunwind");
> +
> + do {
> + /* looping on the stack frame */
> + if (unw_get_reg(&cursor, UNW_REG_IP, &ip) < 0)
> + perror_msg_and_die("Can't walk the stack of process %d",
> + tcp->pid);
This can happen if process died while we play with it.
Shouldn't be fatal (so, _and_die is wrong).
> +
> + lower = 0;
> + upper = tcp->mmap_cache_size - 1;
> +
> +
> + while (lower <= upper) {
> + /* find the mmap_cache and print the stack frame */
> + mid = (int)((upper + lower) / 2);
Believe it or not, "int_var / 2" uses divide insn (!) if compiled by
gcc -Os on x86:
int main(int argc, char **argv) { return argc/2; }
compiles to
movl %edi, %eax
movl $2, %ecx
cltd
idivl %ecx
ret
Use unsigned for lower, upper, and mid...
And maybe make some noise about it here:
http://gcc.gnu.org/bugzilla/show_bug.cgi?id=30354
since the fix for it is trivial and it's been 5 years since
I posted it to gcc BZ.
> + 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 )
> + die_out_of_memory();
Please fix the if () style.
> + } while (1);
do {} while (1)?
Use "while (1) {}" or "for (;;) {}"
(some people like the latter, they read it as "forever")
> + 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){
style
> + 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");
Very deep callchains aren't hard to come by (recursion).
So it shouldn't be a "big" warning which goes to stderr,
emit it using tprintf().
> + break;
> + }
> + } while (ret_val > 0);
> +}
>
More information about the Strace-devel
mailing list