namhyung / uftrace

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

graphviz bug for big programs #514

Closed honggyukim closed 6 years ago

honggyukim commented 6 years ago

I've tried to generate graphviz output for clang and v8, but failed.

$ dot -Tpng clang.dot -o clang.png
Error: clang.dot.old: syntax error in line 12 near '.'

Here is the dot file info.

$ cat clang.dot
   1 # version":"uftrace v0.9-22-gab2d2 ( dwarf python tui perf sched )",
   2 # command_line "uftrace record -t 1ms -d xxx ./clang++ -DNUM=25 -O2 s-fib-constexpr.cpp"
   3 digraph "/home/honggyu/work/llvm/release/build.release.g.pg/bin/clang-6.0" {
   4
   5         # Attributes
   6         splines=ortho;
   7         concentrate=true;
   8         node [shape="rect",fontsize="7",style="filled"];
   9         edge [fontsize="7"];
  10
  11         # Elements
  12         _GLOBAL__sub_I_cc1_main.cpp[xlabel = "Calls : 1"]
  13         _GLOBAL__sub_I_cc1_main.cpp->getenv[xlabel = "Calls : 1"]
  14         getenv->linux:schedule[xlabel = "Calls : 1"]
  15         _GLOBAL__sub_I_ARMFrameLowering.cpp[xlabel = "Calls : 1"]
  16         _GLOBAL__sub_I_ARMFrameLowering.cpp->linux:schedule[xlabel = "Calls : 1"]
  17         _GLOBAL__sub_I_ARMFrameLowering.cpp->"llvm::cl::Option::addArgument"[xlabel = "Calls : 1"]
  18         llvm::cl::Option::addArgument->linux:schedule[xlabel = "Calls : 1"]
  19         llvm::cl::Option::addArgument->llvm::ManagedStaticBase::RegisterManagedStatic[xlabel = "Calls : 1"]
  ...

I've made the following change, then those "Error" disapeared.

diff --git a/cmds/dump.c b/cmds/dump.c
index b1b3f44..577f97c 100644
--- a/cmds/dump.c
+++ b/cmds/dump.c
@@ -1173,9 +1173,9 @@ static void print_graph_to_graphviz(struct uftrace_graph_node *node,

                pr_out("\t");
                if (parent != NULL && parent->name != NULL) {
-                       pr_out("%s->", parent->name);
+                       pr_out("\"%s\"->", parent->name);
                }
-               pr_out("%s", node->name);
+               pr_out("\"%s\"", node->name);

                // Edge Attributes
                pr_out("[xlabel = \"Calls : %lu\"]\n", n_calls);

But this time, dot binary itself crashed.

$ dot -Tpng clang.dot -o clang.png
Segmentation fault (core dumped)
honggyukim commented 6 years ago

I also tried to generate graphviz output for v8 recorded data. But it gets crashed as follows:

$ uftrace record -t 1ms d8 --expose-gc -e 'gc()'

$ uftrace dump --graphviz
Segmentation fault (core dumped)

Here is the backtrace info.

$ gdb --args `which uftrace` dump --graphviz
(gdb) r
Starting program: /home/honggyu/usr/bin/uftrace dump --graphviz
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".

Thread 2.1 "uftrace" received signal SIGHUP, Hangup.
[Switching to Thread 0x7ffff7fc7740 (LWP 93551)]
0x00007ffff689c5b3 in select () from /lib/x86_64-linux-gnu/libc.so.6

(gdb) bt
#0  0x00007ffff689c5b3 in select () from /lib/x86_64-linux-gnu/libc.so.6
#1  0x000000000042f385 in start_command (argv=0x7fffffffe170) at /home/honggyu/work/uftrace/utils/pager.c:49
#2  0x000000000042f54c in start_pager () at /home/honggyu/work/uftrace/utils/pager.c:97
#3  0x00000000004073db in main (argc=3, argv=0x7fffffffe438) at /home/honggyu/work/uftrace/uftrace.c:1040
namhyung commented 6 years ago

Please do it without pager

honggyukim commented 6 years ago

Tested with --no-pager again.

$ uftrace dump --graphviz --no-pager
# version":"uftrace v0.9-22-gab2d2 ( dwarf python tui perf sched )",
# command_line "uftrace record -t 1ms d8 --expose-gc -e gc()"
digraph "/home/honggyu/work/v8/git/v8/out/x64.release.pg.g/d8" {

        # Attributes
        splines=ortho;
        concentrate=true;
        node [shape="rect",fontsize="7",style="filled"];
        edge [fontsize="7"];

Segmentation fault (core dumped)
honggyukim commented 6 years ago

Here is gdb backtrace info.

(gdb) r
Starting program: /home/honggyu/usr/bin/uftrace dump --graphviz --no-pager
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
# version":"uftrace v0.9-22-gab2d2 ( dwarf python tui perf sched )",
# command_line "uftrace record -t 1ms d8 --expose-gc -e gc()"
digraph "/home/honggyu/work/v8/git/v8/out/x64.release.pg.g/d8" {

        # Attributes
        splines=ortho;
        concentrate=true;
        node [shape="rect",fontsize="7",style="filled"];
        edge [fontsize="7"];

Program received signal SIGSEGV, Segmentation fault.
0x0000000000000000 in ?? ()
(gdb) bt
#0  0x0000000000000000 in ?? ()
#1  0x000000000041bdb5 in dump_replay_event (ops=0x7fffffffdf40, task=0xa03dc8) at /home/honggyu/work/uftrace/cmds/dump.c:1401
#2  0x000000000041bea3 in do_dump_replay (ops=0x7fffffffdf40, opts=0x7fffffffe200, handle=0x7fffffffdfc0) at /home/honggyu/work/uftrace/cmds/dum
p.c:1427
#3  0x000000000041c39a in command_dump (argc=0, argv=0x7fffffffe448, opts=0x7fffffffe200) at /home/honggyu/work/uftrace/cmds/dump.c:1535
#4  0x0000000000407554 in main (argc=0, argv=0x7fffffffe448) at /home/honggyu/work/uftrace/uftrace.c:1068
honggyukim commented 6 years ago

Here is the problematic source line.

1395│         else {
1396│                 struct uftrace_perf_reader *perf;
1397│
1398│                 assert(task->h->last_perf_idx >= 0);
1399│                 perf = &task->h->perf[task->h->last_perf_idx];
1400│
1401├───────────────> ops->perf_event(ops, perf, rec);
1402│         }
(gdb) p ops
$1 = (struct uftrace_dump_ops *) 0x7fffffffdf40

(gdb) p *ops
$2 = {
  header = 0x41b039 <print_graphviz_header>,
  task_start = 0x0,
  inverted_time = 0x0,
  task_rstack = 0x41b12c <print_graphviz_task_rstack>,
  task_event = 0x0,
  kernel_start = 0x0,
  cpu_start = 0x0,
  kernel_func = 0x0,
  kernel_event = 0x0,
  lost = 0x0,
  perf_start = 0x0,
  perf_event = 0x0,
  footer = 0x41b2d3 <print_graphviz_footer>
}
namhyung commented 6 years ago

OK, it should be converted to use call_if_nonull() too.

namhyung commented 6 years ago

@honggyukim I'd like to cook a patch to fix some problems in the dump command, can I have your sign-off for the above patch?

honggyukim commented 6 years ago

Sure, please do that. Thanks!

namhyung commented 6 years ago

It'd be nice if you could test check/dump branch whether I messed up something..

ParkHanbum commented 6 years ago

@honggyukim thank you for good work!! have you draw the clang CFG?? how about it?

honggyukim commented 6 years ago

Thanks @namhyung! But I got segfault when running dot again.

$ uftrace dump --graphviz > clang.dot

$ dot -Tpng clang.dot -o clang.png
Segmentation fault (core dumped)
honggyukim commented 6 years ago

Please download the dot file and test it - clang.dot.txt Thanks!

honggyukim commented 6 years ago

@honggyukim thank you for good work!! have you draw the clang CFG?? how about it?

@ParkHanbum I just run clang binary to compile a target program, but the recorded data cannot be converted to .png file.

namhyung commented 6 years ago

I'm not sure it's our fault or not

honggyukim commented 6 years ago

It seems that it could be a fault of dot program.

honggyukim commented 6 years ago

I've tried it with v8, but cannot get .png file as well.

$ uftrace dump --graphviz > v8.dot

$ dot -Tpng v8.dot -o v8.png
Warning: no position for edge with xlabel Calls : 1
Warning: no position for edge with xlabel Calls : 1
Warning: no position for edge with xlabel Calls : 1
Warning: no position for edge with xlabel Calls : 1
Warning: no position for edge with xlabel Calls : 1
Warning: no position for edge with xlabel Calls : 1
Warning: no position for edge with xlabel Calls : 1
Warning: no position for edge with xlabel Calls : 1
Warning: no position for edge with xlabel Calls : 1
Warning: no position for edge with xlabel Calls : 3
Warning: no position for edge with xlabel Calls : 20
Warning: no position for edge with xlabel Calls : 21
honggyukim commented 6 years ago

Oh.. The above output is just a warning so I got the png file. v8

ParkHanbum commented 6 years ago

@honggyukim Dots can not handle more than about 200 elements. recently master branch of dot is also same.

instead, you can use neato to draw huge size of dot document. but when neato drawing dot element, it does not align according to its hierarchy. so, the figure drawed by neato looks chaostic than the figure that drawed by dot.

Figure

namhyung commented 6 years ago

I don't know but they have different layout engines - you could also try fdp or sfdp.

honggyukim commented 6 years ago

Dots can not handle more than about 200 elements.

@ParkHanbum If so, why don't we add a warning message if there are too many elements?