honggyukim / uftrace

Function graph tracer for C/C++/Rust/Python
https://uftrace.github.io/slide/
GNU General Public License v2.0
1 stars 0 forks source link

dwarf argument error #3

Open honggyukim opened 5 years ago

honggyukim commented 5 years ago

Possible problems are as follows: 1. struct copy

$ cat pr65358.c
/* { dg-do run } */
/* { dg-options "-O2" } */

struct pack
{
  int fine;
  int victim;
  int killer;
};

int __attribute__ ((__noinline__, __noclone__))
bar (int a, int b, struct pack p)
{
  if (a != 0x20 || b != 0x30)
    __builtin_abort ();
  if (p.fine != 0x40 || p.victim != 0x50 || p.killer != 0x60)
    __builtin_abort ();
  return 0;
}

int __attribute__ ((__noinline__, __noclone__))
foo (int arg1, int arg2, int arg3, struct pack p)
{
  return bar (arg2, arg3, p);
}

int main (void)
{
  struct pack p = { 0x40, 0x50, 0x60 };

  (void) foo (0x10, 0x20, 0x30, p);
  return 0;
}
$ gcc -pg -g pr65358.c

$ uftrace record -a a.out

$ uftrace replay
# DURATION     TID     FUNCTION
   1.906 us [ 84660] | __monstartup();
   1.110 us [ 84660] | __cxa_atexit();
            [ 84660] | main() {
            [ 84660] |   foo(16, 32, 48, 0x5000000040) {
   0.747 us [ 84660] |     bar(32, 48, 0x5000000040) = 0;
   4.367 us [ 84660] |   } = 0; /* foo */
   5.390 us [ 84660] | } = 0; /* main */
$ cat uftrace.data/a.out.dbg
F: 686 bar
L: 12 /home/honggyu/work/uftrace/pr65358.c
A: @arg1,arg2,arg3
R: @retval
F: 6d7 foo
L: 22 /home/honggyu/work/uftrace/pr65358.c
A: @arg1,arg2,arg3,arg4
R: @retval
F: 710 main
L: 27 /home/honggyu/work/uftrace/pr65358.c
R: @retval
00000000004006d7 <foo>:
  4006d7:       55                      push   %rbp
  4006d8:       48 89 e5                mov    %rsp,%rbp
  4006db:       48 83 ec 20             sub    $0x20,%rsp
  4006df:       e8 3c fe ff ff          callq  400520 <mcount@plt>
  4006e4:       89 7d fc                mov    %edi,-0x4(%rbp)
  4006e7:       89 75 f8                mov    %esi,-0x8(%rbp)
  4006ea:       89 55 f4                mov    %edx,-0xc(%rbp)
  4006ed:       48 89 c8                mov    %rcx,%rax
  4006f0:       44 89 c2                mov    %r8d,%edx
  4006f3:       48 89 45 e0             mov    %rax,-0x20(%rbp)
  4006f7:       89 55 e8                mov    %edx,-0x18(%rbp)
  4006fa:       48 8b 55 e0             mov    -0x20(%rbp),%rdx
  4006fe:       8b 4d e8                mov    -0x18(%rbp),%ecx
  400701:       8b 75 f4                mov    -0xc(%rbp),%esi
  400704:       8b 45 f8                mov    -0x8(%rbp),%eax
  400707:       89 c7                   mov    %eax,%edi
  400709:       e8 78 ff ff ff          callq  400686 <bar>
  40070e:       c9                      leaveq
  40070f:       c3                      retq

0000000000400710 <main>:
  400710:       55                      push   %rbp
  400711:       48 89 e5                mov    %rsp,%rbp
  400714:       48 83 ec 10             sub    $0x10,%rsp
  400718:       e8 03 fe ff ff          callq  400520 <mcount@plt>
  40071d:       c7 45 f4 40 00 00 00    movl   $0x40,-0xc(%rbp)
  400724:       c7 45 f8 50 00 00 00    movl   $0x50,-0x8(%rbp)
  40072b:       c7 45 fc 60 00 00 00    movl   $0x60,-0x4(%rbp)
  400732:       48 8b 45 f4             mov    -0xc(%rbp),%rax
  400736:       8b 55 fc                mov    -0x4(%rbp),%edx
  400739:       48 89 c1                mov    %rax,%rcx
  40073c:       41 89 d0                mov    %edx,%r8d
  40073f:       ba 30 00 00 00          mov    $0x30,%edx
  400744:       be 20 00 00 00          mov    $0x20,%esi
  400749:       bf 10 00 00 00          mov    $0x10,%edi
  40074e:       e8 84 ff ff ff          callq  4006d7 <foo>
  400753:       b8 00 00 00 00          mov    $0x0,%eax
  400758:       c9                      leaveq
  400759:       c3                      retq
  40075a:       66 0f 1f 44 00 00       nopw   0x0(%rax,%rax,1)

2. function cloning The same function may be copied, and may reside as more than two functions in the binary.

3. incorrect argument number

00000000011108a0 W
v8::internal::ParserBase<v8::internal::Parser>::ParseFunctionBody(
        <<<this pointer>>>                                              arg1%rdi
        v8::internal::ZoneList<v8::internal::Statement*>*,              arg1%rsi
        v8::internal::AstRawString const*,                              arg2%rdx
        int,                                                            arg3%rcx
        v8::internal::ParserFormalParameters const&,                    arg4%r8
        v8::internal::FunctionKind,                                     arg6/e:FunctionKind%r9
        v8::internal::FunctionLiteral::FunctionType,                    arg7/e:FunctionType
        bool*)                                                          arg8%stack+2

F: d108a0 v8::internal::ParserBase::ParseFunctionBody
L: 4195 ../deps/v8/src/parsing/parser-base.h
A: @arg1%rdi,arg2%rsi,arg3%rdx,arg4%rcx,arg5%r8,arg6/e:FunctionKind%r9,arg7/e:FunctionType,arg8%stack+2

The above shows correct arguments as the order looks correct

F: d380e0 v8::internal::ParserBase::ParseFunctionBody L: 4195 ../deps/v8/src/parsing/parser-base.h A: @arg1%rdi,arg2,arg3%rcx,arg4%r9,arg5,arg6/e:FunctionKind%stack+2,arg7/e:FunctionType%stack+3,arg8%stack+4

But the above shows "incorrect" arguments and the order looks strange.
 - `arg1%rdi,arg2,arg3%rcx,arg4%r9,arg5,arg6/e:FunctionKind%stack+2,arg7/e:FunctionType%stack+3,arg8%stack+4`

DURATION TID ADDRESS FUNCTION

7.094 ms [ 74792] 11108b6 | v8::internal::ParserBase::ParseFunctionBody(0x7fff41c44360, 0xc3eae88, 0xc3ea5d0, 2227, 0x7fff41c43320, kNormalFunction, kNamedExpression, 0x7fff41c44196); [ 74792] 11108b6 | v8::internal::ParserBase::ParseFunctionBody(0x7fff41c44360, 0xc3ebb90, 0xc3ea5b0, 644, 0x7fff41c43320, kNormalFunction, kNamedExpression, 0x7fff41c44196) { 1.552 ms [ 74792] 11380f6 | v8::internal::ParserBase::ParseFunctionBody(0xc3e9cb0, 0, 0, -1, 0, kLastFunctionKind|kAsyncGeneratorFunction|kAsyncConciseGeneratorMethod|kConciseGeneratorMethod|kAsyncConciseMethod|kAsyncArrowFunction|kDefaultDerivedConstructor|kDefaultBaseConstructor|kClassFieldsInitializerFunction|kModule|kAsyncFunc 13.718 ms [ 74792] 11108b6 | } / v8::internal::ParserBase::ParseFunctionBody / 5.184 ms [ 74792] 11108b6 | v8::internal::ParserBase::ParseFunctionBody(0x7fff41c44400, 0xc3ebe88, 0xc3eb8f0, 1640, 0x7fff41c43db0, kNormalFunction, kDeclaration, 0x7fff41c441af);

honggyukim commented 5 years ago
$ cat -n clone.isra.cc
     1  #include <cstdio>
     2
     3  void func(int& a) { a *= 2; }
     4
     5  struct func_obj {
     6      void operator()(int& n) { n *= 2; }
     7  };
     8
     9  template<typename T, typename F>
    10  __attribute__((noinline))
    11  void xforeach(T first, T last, F f)
    12  {
    13      while (first != last) {
    14          f(*first);
    15          ++first;
    16      }
    17  }
    18
    19  void dump(int *x, int n)
    20  {
    21      for (int i = 0; i < 3; i++)
    22          printf("%d, ", x[i]);
    23  }
    24
    25  int main()
    26  {
    27      int x[] = { 1, 2, 3 };
    28      xforeach(x, x + 3, func);
    29      dump(x, 3);
    30
    31      func_obj fo;
    32      xforeach(x, x + 3, fo);
    33      dump(x, 3);
    34  }
$ g++ -pg -g -O2 clone.isra.cc

$ uftrace -a record a.out
2, 4, 6, 4, 8, 12, 

$ uftrace replay -f addr --demangle=full --no-libcall
#   ADDRESS     FUNCTION
       4005de | main() {
       400892 |   void xforeach<int*, void (*)(int&)>(int*, int*, void (*)(int&))(0x7ffcaec67dcc, 0x7ffcaec67dd8, &func(int&)) {
       400819 |     func(int&)(0x7ffcaec67dcc);
       400819 |     func(int&)(0x7ffcaec67dd0);
       400819 |     func(int&)(0x7ffcaec67dd4);
       400892 |   } /* void xforeach<int*, void (*)(int&)>(int*, int*, void (*)(int&)) */
       400829 |   void xforeach<int*, func_obj>(int*, int*, func_obj) [clone .isra.1](0x7ffcaec67dcc, 0x7ffcaec67dd8);
       4005de | } = 0; /* main */

$ cat uftrace.data/a.out.dbg | grep xforeach -A2
F: 820 xforeach
L: 11 /home/honggyu/work/uftrace/git/uftrace/new/uftrace/clone.isra.cc
A: @arg1%rdi,arg2%rsi
--
F: 880 xforeach
L: 11 /home/honggyu/work/uftrace/git/uftrace/new/uftrace/clone.isra.cc
A: @arg1%rdi,arg2%rsi,arg3/p%rdx

$ cat uftrace.data/a.out.sym | c++filt | grep xforeach
0000000000000820 t void xforeach<int*, func_obj>(int*, int*, func_obj) [clone .isra.1]
0000000000000880 w void xforeach<int*, void (*)(int&)>(int*, int*, void (*)(int&))
honggyukim commented 5 years ago
$ cat -n clone.isra.constprop.cc
     1  #include <cstdio>
     2
     3  void func(int& a) { a *= 2; }
     4
     5  struct func_obj {
     6      void operator()(int& n) { n *= 2; }
     7  };
     8
     9  template<typename T, typename F>
    10  __attribute__((noinline))
    11  void xforeach(T first, T last, F f)
    12  {
    13      while (first != last) {
    14          f(*first);
    15          ++first;
    16      }
    17  }
    18
    19  void dump(int *x, int n)
    20  {
    21      for (int i = 0; i < 3; i++)
    22          printf("%d, ", x[i]);
    23  }
    24
    25  int arr[] = { 1, 2, 3 };
    26
    27  int main()
    28  {
    29      xforeach(arr, arr + 3, func);
    30      dump(arr, 3);
    31
    32      func_obj fo;
    33      xforeach(arr, arr + 3, fo);
    34      dump(arr, 3);
    35  }
$ g++ -pg -g -O2 clone.isra.constprop.cc

$ uftrace -a record a.out
2, 4, 6, 4, 8, 12, 

$ uftrace replay -f addr --no-libcall
#   ADDRESS     FUNCTION
       400569 | main() {
       4007e2 |   xforeach(&arr, &called.4507, &func) {
       400769 |     func(&arr);
       400769 |     func(&arr+4);
       400769 |     func(&arr+8);
       4007e2 |   } /* xforeach */
       400779 |   xforeach(&realloc+1943080, 0x1bbfd80);
       400569 | } = 0; /* main */

$ uftrace replay -f addr --demangle=full --no-libcall
#   ADDRESS     FUNCTION
       400569 | main() {
       4007e2 |   void xforeach<int*, void (*)(int&)>(int*, int*, void (*)(int&))(&arr, &called.4507, &func(int&)) {
       400769 |     func(int&)(&arr);
       400769 |     func(int&)(&arr+4);
       400769 |     func(int&)(&arr+8);
       4007e2 |   } /* void xforeach<int*, void (*)(int&)>(int*, int*, void (*)(int&)) */
       400779 |   void xforeach<int*, func_obj>(int*, int*, func_obj) [clone .isra.1] [clone .constprop.2](&realloc+1943080, 0x1bbfd80);
       400569 | } = 0; /* main */

$ cat uftrace.data/a.out.dbg | grep xforeach -A2
F: 770 xforeach
L: 11 /home/honggyu/work/uftrace/git/uftrace/new/uftrace/clone.isra.constprop.cc
A: @arg1,arg2
--
F: 7d0 xforeach
L: 11 /home/honggyu/work/uftrace/git/uftrace/new/uftrace/clone.isra.constprop.cc
A: @arg1%rdi,arg2%rsi,arg3/p%rdx

$ cat uftrace.data/a.out.sym | c++filt | grep xforeach
0000000000000770 t void xforeach<int*, func_obj>(int*, int*, func_obj) [clone .isra.1] [clone .constprop.2]
00000000000007d0 w void xforeach<int*, void (*)(int&)>(int*, int*, void (*)(int&))
honggyukim commented 5 years ago

https://stackoverflow.com/questions/13963150/what-does-the-gcc-function-suffix-isra-mean

-fipa-sra

honggyukim commented 5 years ago

-fno-ipa-sra

$ g++ -pg -g -O2 clone.isra.constprop.cc -fno-ipa-sra

$ uftrace -a --no-libcall -f addr a.out
#   ADDRESS     FUNCTION
       400569 | main() {
       4007e2 |   xforeach(&arr, &called.4507, &func) {
       400789 |     func(&arr);
       400789 |     func(&arr+4);
       400789 |     func(&arr+8);
       4007e2 |   } /* xforeach */
       400819 |   xforeach(&arr, &called.4507, 0x7f3cd6c33780);
       400569 | } = 0; /* main */

$ uftrace -a --no-libcall --demangle=full -f addr a.out
#   ADDRESS     FUNCTION
       400569 | main() {
       4007e2 |   void xforeach<int*, void (*)(int&)>(int*, int*, void (*)(int&))(&arr, &called.4507, &func(int&)) {
       400789 |     func(int&)(&arr);
       400789 |     func(int&)(&arr+4);
       400789 |     func(int&)(&arr+8);
       4007e2 |   } /* void xforeach<int*, void (*)(int&)>(int*, int*, void (*)(int&)) */
       400819 |   void xforeach<int*, func_obj>(int*, int*, func_obj)(&arr, &called.4507, 0x7f627c450780);
       400569 | } = 0; /* main */
honggyukim commented 5 years ago

clang++ Function is cloned, but dwarf is correct in clang++.

$ clang++ -pg -g -O2 clone.isra.constprop.cc

$ uftrace -a --no-libcall -f addr a.out
#   ADDRESS     FUNCTION
       400779 | main() {
       400828 |   xforeach(&arr, &called.4507, &func) {
       40071e |     func(&arr);
       40071e |     func(&arr+4);
       40071e |     func(&arr+8);
       400828 |   } /* xforeach */
       400862 |   xforeach(&arr, &called.4507, 0);
       400779 | } = 0; /* main */

It looks okay with clang. It has DW_AT_location fields for each DW_TAG_formal_parameter unlike gcc compiled binary.

$ readelf -wi a.out
        ...
 <1><98e>: Abbrev Number: 27 (DW_TAG_subprogram)
    <98f>   DW_AT_low_pc      : 0x400810
    <997>   DW_AT_high_pc     : 0x109
    <99b>   DW_AT_frame_base  : 1 byte block: 56    (DW_OP_reg6 (rbp))
    <99d>   DW_AT_linkage_name: (indirect string, offset: 0x461): void xforeach<int*, func_obj>(int*, int*, func_obj)
    <9a1>   DW_AT_name        : (indirect string, offset: 0x483): xforeach<int *, func_obj>
    <9a5>   DW_AT_decl_file   : 1
    <9a6>   DW_AT_decl_line   : 11
    <9a7>   DW_AT_external    : 1
 <2><9a7>: Abbrev Number: 28 (DW_TAG_formal_parameter)
    <9a8>   DW_AT_location    : 0xd8 (location list)
    <9ac>   DW_AT_name        : (indirect string, offset: 0x4a2): first
    <9b0>   DW_AT_decl_file   : 1
    <9b1>   DW_AT_decl_line   : 11
    <9b2>   DW_AT_type        : <0x88a>
 <2><9b6>: Abbrev Number: 28 (DW_TAG_formal_parameter)
    <9b7>   DW_AT_location    : 0x121 (location list)
    <9bb>   DW_AT_name        : (indirect string, offset: 0x4a8): last
    <9bf>   DW_AT_decl_file   : 1
    <9c0>   DW_AT_decl_line   : 11
    <9c1>   DW_AT_type        : <0x88a>
 <2><9c5>: Abbrev Number: 30 (DW_TAG_formal_parameter)
    <9c6>   DW_AT_name        : (indirect string, offset: 0x3b2): f
    <9ca>   DW_AT_decl_file   : 1
    <9cb>   DW_AT_decl_line   : 11
    <9cc>   DW_AT_type        : <0x941>
honggyukim commented 5 years ago

gcc compiled binary doesn't have DW_AT_location fields for each DW_TAG_formal_parameter. It may be the problem why it cannot show the argument properly.

$ readelf -wi a.out
        ...
 <1><728>: Abbrev Number: 37 (DW_TAG_subprogram)
    <729>   DW_AT_external    : 1
    <729>   DW_AT_name        : (indirect string, offset: 0x289): xforeach<int*, func_obj>
    <72d>   DW_AT_decl_file   : 1
    <72e>   DW_AT_decl_line   : 11
    <72f>   DW_AT_linkage_name: (indirect string, offset: 0x2f0): void xforeach<int*, func_obj>(int*, int*, func_obj)
    <733>   DW_AT_inline      : 0   (not inlined)
    <734>   DW_AT_sibling     : <0x766>
 <2><738>: Abbrev Number: 38 (DW_TAG_template_type_param)
    <739>   DW_AT_name        : T
    <73b>   DW_AT_type        : <0x766>
 <2><73f>: Abbrev Number: 38 (DW_TAG_template_type_param)
    <740>   DW_AT_name        : F
    <742>   DW_AT_type        : <0x6a8>
 <2><746>: Abbrev Number: 34 (DW_TAG_formal_parameter)
    <747>   DW_AT_name        : (indirect string, offset: 0x312): first
    <74b>   DW_AT_decl_file   : 1
    <74c>   DW_AT_decl_line   : 11
    <74d>   DW_AT_type        : <0x766>
 <2><751>: Abbrev Number: 34 (DW_TAG_formal_parameter)
    <752>   DW_AT_name        : (indirect string, offset: 0x180): last
    <756>   DW_AT_decl_file   : 1
    <757>   DW_AT_decl_line   : 11
    <758>   DW_AT_type        : <0x766>
 <2><75c>: Abbrev Number: 32 (DW_TAG_formal_parameter)
    <75d>   DW_AT_name        : f
    <75f>   DW_AT_decl_file   : 1
    <760>   DW_AT_decl_line   : 11
    <761>   DW_AT_type        : <0x6a8>
honggyukim commented 5 years ago
static void add_location(char *spec, size_t len, Dwarf_Die *die,
             struct arg_data *ad)
{
    struct location_data data = {
        .type = ARG_TYPE_INDEX,
    };
    char buf[32];
    const char *reg;

    if (!get_arg_location(die, &data))
        return;

    switch (data.type) {
    case ARG_TYPE_REG:
        reg = arch_register_dwarf_name(host_cpu_arch(), data.reg);

        if (strcmp(reg, "invalid register")) {
            snprintf(buf, sizeof(buf), "%%%s", reg);
            strcat(spec, buf);
        }
        break;
    case ARG_TYPE_STACK:
        snprintf(buf, sizeof(buf), "%%stack+%d", data.offset);
        strcat(spec, buf);
        break;
    default:
        break;
    }
}
honggyukim commented 5 years ago

It was shown location: unknown twice for each args with below change.

diff --git a/utils/dwarf.c b/utils/dwarf.c
index 56299c0..2ae965f 100644
--- a/utils/dwarf.c
+++ b/utils/dwarf.c
@@ -635,6 +635,10 @@ static bool get_arg_location(Dwarf_Die *die, struct location_data *ld)
                        ld->reg = ops->number;
                        pr_dbg3("location: reg (%d)\n", ld->reg);
                        break;
+
+        default:
+                       pr_dbg3("location: unknown\n");
+                       break;
                }
        }
honggyukim commented 5 years ago

dwarf3 document: http://dwarfstd.org/doc/Dwarf3.pdf