DynamoRIO's callstack walk fails on clang program

[Deng Deng]

 I am writing a tool to hook every printf call in the program and dump the program's stack. I don't care the printf in the external library, so I wrap the program's printf@plt stub in dynamorio. I use the ./api/samples/callstack.cpp as a template and modify the module_load_event function to the following:

static void
module_load_event(void *drcontext, const module_data_t *mod, bool loaded)
{
    size_t modoffs;
    drsym_error_t sym_res = drsym_lookup_symbol(
        mod->full_path, "main", &modoffs, DRSYM_DEMANGLE);
    if (sym_res == DRSYM_SUCCESS) {
        app_pc towrap = mod->start + [printf@plt offset];
        bool ok = drwrap_wrap(towrap, wrap_pre, NULL);
        DR_ASSERT(ok);
        dr_fprintf(STDERR, "wrapping %s!%s\n", mod->full_path,
                   "printf@plt");
    }
}

The [printf@plt offset] can be obtained from the objdump output for a program.

Then I write the following program to test the stack walk tool:

#include <stdio.h>

void recursive_call(int depth) {
    if (depth <= 0) {
        printf("Recursion end\n", depth);
        return;
    }
    printf("Recursion depth: %d %lx\n", depth, malloc(depth));
    recursive_call(depth - 1);
}

int main() {
    printf("Start\n");
    recursive_call(5);
    return 0;
}

If the program is compiled by gcc, it outputs the correct stack walk trace like:

printf@plt called from:

  gcc-clang-example!<unknown> // Because printf@plt is not an actual function symbol  so it prints <unknown>
  gcc-clang-example!recursive_call
  gcc-clang-example!main
  libc.so.6!__libc_start_call_main
  libc.so.6!__libc_start_main_alias_2
  gcc-clang-example!<unknown>

However, if the program is compiled by clang, the trace is:

printf@plt called from:
  clang-example!<unknown>
  <unknown module> @0x0000000500000005
  <unknown module> @0x00007ffec5126140

The detailed trace log is in attachment.

[Kai Luk]

Would you be able to check the expected module for 0x0000000500000005, 0x00007ffec5126140 based on the output of "readelf -a <clang complied binary>"? Or share the output of "readelf -a <clang complied binary>" ?

Regards,

Kai

[Deng Deng]

Sure. Here is the output of readelf.

[Kai Luk]

I modified the source file slightly as follows:

#include <stdio.h>
#include <stdlib.h>

void recursive_call(int depth) {
    if (depth <= 0) {

        printf("Recursion end\n");
        return;
    }
    printf("Recursion depth: %d %lx\n", depth, (unsigned long)malloc(depth));

    recursive_call(depth - 1);
}

int main() {
    printf("Start\n");
    recursive_call(5);
    return 0;
}

complied it using "clang recursive_printf.c -o recursive_printf.clang", and ran "bin64/drrun -code_api -c api/samples/../bin/libcallstack.so -trace_function printf -- ../recursive_printf.clang" without modifying callstack.cpp, and I got the correct result on x86:

build$ bin64/drrun -code_api -c api/samples/../bin/libcallstack.so -trace_function printf -- ../recursive_printf.clang
<Starting application /usr/local/google/home/kyluk/nudge/dynamorio/recursive_printf.clang (3391018)>
<Initial options = -no_dynamic_options -client_lib '/usr/local/google/home/kyluk/nudge/dynamorio/build/api/samples/../bin/libcallstack.so;0;"-trace_function" "printf"' -client_lib64 '/usr/local/google/home/kyluk/nudge/dynamorio/build/api/samples/../bin/libcallstack.so;0;"-trace_function" "printf"' -code_api -stack_size 56K -signal_stack_size 32K -max_elide_jmp 0 -max_elide_call 0 -early_inject -emulate_brk -no_inline_ignored_syscalls -native_exec_default_list '' -no_native_exec_managed_code -no_indcall2direct >
<Paste into GDB to debug DynamoRIO clients:
set confirm off
add-symbol-file '/usr/local/google/home/kyluk/nudge/dynamorio/build/api/samples/../bin/libcallstack.so' 0x00007f3689e04320
add-symbol-file '/usr/local/google/home/kyluk/nudge/dynamorio/build/lib64/debug/libdynamorio.so' 0x00007f36cde50000
add-symbol-file '/usr/local/google/home/kyluk/nudge/dynamorio/build/ext/lib64/debug/libdrwrap.so' 0x00007f3689e4c7d0
add-symbol-file '/usr/local/google/home/kyluk/nudge/dynamorio/build/ext/lib64/debug/libdrmgr.so' 0x00007f3689e5f660
add-symbol-file '/usr/local/google/home/kyluk/nudge/dynamorio/build/ext/lib64/debug/libdrcallstack.so' 0x00007f3689e6f080
add-symbol-file '/lib/x86_64-linux-gnu/libunwind.so.8' 0x00007f36ce3a9400
add-symbol-file '/lib/x86_64-linux-gnu/libc.so.6' 0x00007f36cda47400
add-symbol-file '/usr/lib64/ld-linux-x86-64.so.2' 0x00007f36ce36e000
add-symbol-file '/lib/x86_64-linux-gnu/liblzma.so.5' 0x00007f36ce33f5c0
add-symbol-file '/usr/local/google/home/kyluk/nudge/dynamorio/build/ext/lib64/debug/libdrsyms.so' 0x00007f3689e7be00
add-symbol-file '/lib/x86_64-linux-gnu/libz.so.1' 0x00007f36ce31d340
add-symbol-file '/lib/x86_64-linux-gnu/libstdc++.so.6' 0x00007f36cd859240
add-symbol-file '/lib/x86_64-linux-gnu/libm.so.6' 0x00007f36cdc312c0
add-symbol-file '/lib/x86_64-linux-gnu/libgcc_s.so.1' 0x00007f36ce2f03c0
>
<curiosity: rex.w on OPSZ_6_irex10_short4!>
wrapping /usr/lib/x86_64-linux-gnu/libc.so.6!printf
<spurious rep/repne prefix @0x00007f36ce406020 (f3 0f 1e fa): >
printf called from:
  libc.so.6!__printf
  libc.so.6!__libc_start_call_main
  libc.so.6!__libc_start_main_alias_2
  recursive_printf.clang!<unknown>
Start
printf called from:
  libc.so.6!__printf
  recursive_printf.clang!<unknown>
  libc.so.6!__libc_start_call_main
  libc.so.6!__libc_start_main_alias_2
  recursive_printf.clang!<unknown>
Recursion depth: 5 7f36c9e006b0
printf called from:
  libc.so.6!__printf
  recursive_printf.clang!<unknown>
  recursive_printf.clang!<unknown>
  libc.so.6!__libc_start_call_main
  libc.so.6!__libc_start_main_alias_2
  recursive_printf.clang!<unknown>
Recursion depth: 4 7f36c9e006d0
printf called from:
  libc.so.6!__printf
  recursive_printf.clang!<unknown>
  recursive_printf.clang!<unknown>
  recursive_printf.clang!<unknown>
  libc.so.6!__libc_start_call_main
  libc.so.6!__libc_start_main_alias_2
  recursive_printf.clang!<unknown>
Recursion depth: 3 7f36c9e006f0
printf called from:
  libc.so.6!__printf
  recursive_printf.clang!<unknown>
  recursive_printf.clang!<unknown>
  recursive_printf.clang!<unknown>
  recursive_printf.clang!<unknown>
  libc.so.6!__libc_start_call_main
  libc.so.6!__libc_start_main_alias_2
  recursive_printf.clang!<unknown>
Recursion depth: 2 7f36c9e00710
printf called from:
  libc.so.6!__printf
  recursive_printf.clang!<unknown>
  recursive_printf.clang!<unknown>
  recursive_printf.clang!<unknown>
  recursive_printf.clang!<unknown>
  recursive_printf.clang!<unknown>
  libc.so.6!__libc_start_call_main
  libc.so.6!__libc_start_main_alias_2
  recursive_printf.clang!<unknown>
Recursion depth: 1 7f36c9e00730
printf called from:
  libc.so.6!__printf
  recursive_printf.clang!<unknown>
  recursive_printf.clang!<unknown>
  recursive_printf.clang!<unknown>
  recursive_printf.clang!<unknown>
  recursive_printf.clang!<unknown>
  recursive_printf.clang!<unknown>
  libc.so.6!__libc_start_call_main
  libc.so.6!__libc_start_main_alias_2
  recursive_printf.clang!<unknown>
Recursion end
<Stopping application /usr/local/google/home/kyluk/nudge/dynamorio/recursive_printf.clang (3391018)>

And I tried that with malloc, and it worked as well:

build$ bin64/drrun -code_api -c api/samples/../bin/libcallstack.so -trace_function malloc -- ../recursive_printf.clang
<Starting application /usr/local/google/home/kyluk/nudge/dynamorio/recursive_printf.clang (3398745)>
<Initial options = -no_dynamic_options -client_lib '/usr/local/google/home/kyluk/nudge/dynamorio/build/api/samples/../bin/libcallstack.so;0;"-trace_function" "malloc"' -client_lib64 '/usr/local/google/home/kyluk/nudge/dynamorio/build/api/samples/../bin/libcallstack.so;0;"-trace_function" "malloc"' -code_api -stack_size 56K -signal_stack_size 32K -max_elide_jmp 0 -max_elide_call 0 -early_inject -emulate_brk -no_inline_ignored_syscalls -native_exec_default_list '' -no_native_exec_managed_code -no_indcall2direct >
<Paste into GDB to debug DynamoRIO clients:
set confirm off
add-symbol-file '/usr/local/google/home/kyluk/nudge/dynamorio/build/api/samples/../bin/libcallstack.so' 0x00007fb9b9004320
add-symbol-file '/usr/local/google/home/kyluk/nudge/dynamorio/build/lib64/debug/libdynamorio.so' 0x00007fb9fd050000
add-symbol-file '/usr/local/google/home/kyluk/nudge/dynamorio/build/ext/lib64/debug/libdrwrap.so' 0x00007fb9b904c7d0
add-symbol-file '/usr/local/google/home/kyluk/nudge/dynamorio/build/ext/lib64/debug/libdrmgr.so' 0x00007fb9b905f660
add-symbol-file '/usr/local/google/home/kyluk/nudge/dynamorio/build/ext/lib64/debug/libdrcallstack.so' 0x00007fb9b906f080
add-symbol-file '/lib/x86_64-linux-gnu/libunwind.so.8' 0x00007fb9fd622400
add-symbol-file '/lib/x86_64-linux-gnu/libc.so.6' 0x00007fb9fcc47400
add-symbol-file '/usr/lib64/ld-linux-x86-64.so.2' 0x00007fb9fd5e7000
add-symbol-file '/lib/x86_64-linux-gnu/liblzma.so.5' 0x00007fb9fd5b85c0
add-symbol-file '/usr/local/google/home/kyluk/nudge/dynamorio/build/ext/lib64/debug/libdrsyms.so' 0x00007fb9b907be00
add-symbol-file '/lib/x86_64-linux-gnu/libz.so.1' 0x00007fb9fd596340
add-symbol-file '/lib/x86_64-linux-gnu/libstdc++.so.6' 0x00007fb9fca59240
add-symbol-file '/lib/x86_64-linux-gnu/libm.so.6' 0x00007fb9fce312c0
add-symbol-file '/lib/x86_64-linux-gnu/libgcc_s.so.1' 0x00007fb9fd5693c0
>
<curiosity: rex.w on OPSZ_6_irex10_short4!>
wrapping /usr/lib/x86_64-linux-gnu/libc.so.6!malloc
<spurious rep/repne prefix @0x00007fb9fd67f020 (f3 0f 1e fa): >
malloc called from:
  libc.so.6!__GI___libc_malloc
Start
malloc called from:
  libc.so.6!__GI___libc_malloc
  recursive_printf.clang!<unknown>
  libc.so.6!__libc_start_call_main
  libc.so.6!__libc_start_main_alias_2
  recursive_printf.clang!<unknown>
Recursion depth: 5 7fb9f90006b0
malloc called from:
  libc.so.6!__GI___libc_malloc
  recursive_printf.clang!<unknown>
  recursive_printf.clang!<unknown>
  libc.so.6!__libc_start_call_main
  libc.so.6!__libc_start_main_alias_2
  recursive_printf.clang!<unknown>
Recursion depth: 4 7fb9f90006d0
malloc called from:
  libc.so.6!__GI___libc_malloc
  recursive_printf.clang!<unknown>
  recursive_printf.clang!<unknown>
  recursive_printf.clang!<unknown>
  libc.so.6!__libc_start_call_main
  libc.so.6!__libc_start_main_alias_2
  recursive_printf.clang!<unknown>
Recursion depth: 3 7fb9f90006f0
malloc called from:
  libc.so.6!__GI___libc_malloc
  recursive_printf.clang!<unknown>
  recursive_printf.clang!<unknown>
  recursive_printf.clang!<unknown>
  recursive_printf.clang!<unknown>
  libc.so.6!__libc_start_call_main
  libc.so.6!__libc_start_main_alias_2
  recursive_printf.clang!<unknown>
Recursion depth: 2 7fb9f9000710
malloc called from:
  libc.so.6!__GI___libc_malloc
  recursive_printf.clang!<unknown>
  recursive_printf.clang!<unknown>
  recursive_printf.clang!<unknown>
  recursive_printf.clang!<unknown>
  recursive_printf.clang!<unknown>
  libc.so.6!__libc_start_call_main
  libc.so.6!__libc_start_main_alias_2
  recursive_printf.clang!<unknown>
Recursion depth: 1 7fb9f9000730
Recursion end
<Stopping application /usr/local/google/home/kyluk/nudge/dynamorio/recursive_printf.clang (3398745)>

I tested it with gcc and it worked too. Here's my clang version:

dynamorio$ clang -v
Debian clang version 19.1.7 (3+build4)

Target: x86_64-pc-linux-gnu

Can you try "build$ bin64/drrun -code_api -c api/samples/../bin/libcallstack.so -trace_function printf --  <binary>" and see if it makes any difference?

[Deng Deng]

Thank you for your help! I have also tried your method, which is a little different with my code.  While your code wraps the library function printf (i.e, inside the library module), my code wraps the program's printf@plt (i.e., inside the main program module). Your method works both in gcc and clang, but my code fails in clang. I guess the bug may comes from the error unwind information in clang. Maybe I should contact the libunwind or llvm-project about this thing?