1Demonstrations of uflow. 2 3 4uflow traces method entry and exit events and prints a visual flow graph that 5shows how methods are entered and exited, similar to a tracing debugger with 6breakpoints. This can be useful for understanding program flow in high-level 7languages such as Java, Perl, PHP, Python, Ruby, and Tcl which provide USDT 8probes for method invocations. 9 10 11For example, trace all Ruby method calls in a specific process: 12 13# ./uflow -l ruby 27245 14Tracing method calls in ruby process 27245... Ctrl-C to quit. 15CPU PID TID TIME(us) METHOD 163 27245 27245 4.536 <- IO.gets 173 27245 27245 4.536 <- IRB::StdioInputMethod.gets 183 27245 27245 4.536 -> IRB::Context.verbose? 193 27245 27245 4.536 -> NilClass.nil? 203 27245 27245 4.536 <- NilClass.nil? 213 27245 27245 4.536 -> IO.tty? 223 27245 27245 4.536 <- IO.tty? 233 27245 27245 4.536 -> Kernel.kind_of? 243 27245 27245 4.536 <- Kernel.kind_of? 253 27245 27245 4.536 <- IRB::Context.verbose? 263 27245 27245 4.536 <- IRB::Irb.signal_status 273 27245 27245 4.536 -> String.chars 283 27245 27245 4.536 <- String.chars 29^C 30 31In the preceding output, indentation indicates the depth of the flow graph, 32and the <- and -> arrows indicate the direction of the event (exit or entry). 33 34Often, the amount of output can be overwhelming. You can filter specific 35classes or methods. For example, trace only methods from the Thread class: 36 37# ./uflow -C java/lang/Thread $(pidof java) 38Tracing method calls in java process 27722... Ctrl-C to quit. 39CPU PID TID TIME(us) METHOD 403 27722 27731 3.144 -> java/lang/Thread.<init> 413 27722 27731 3.144 -> java/lang/Thread.init 423 27722 27731 3.144 -> java/lang/Thread.init 433 27722 27731 3.144 -> java/lang/Thread.currentThread 443 27722 27731 3.144 <- java/lang/Thread.currentThread 453 27722 27731 3.144 -> java/lang/Thread.getThreadGroup 463 27722 27731 3.144 <- java/lang/Thread.getThreadGroup 473 27722 27731 3.144 -> java/lang/ThreadGroup.checkAccess 483 27722 27731 3.144 <- java/lang/ThreadGroup.checkAccess 493 27722 27731 3.144 -> java/lang/ThreadGroup.addUnstarted 503 27722 27731 3.144 <- java/lang/ThreadGroup.addUnstarted 513 27722 27731 3.145 -> java/lang/Thread.isDaemon 523 27722 27731 3.145 <- java/lang/Thread.isDaemon 533 27722 27731 3.145 -> java/lang/Thread.getPriority 543 27722 27731 3.145 <- java/lang/Thread.getPriority 553 27722 27731 3.145 -> java/lang/Thread.getContextClassLoader 563 27722 27731 3.145 <- java/lang/Thread.getContextClassLoader 573 27722 27731 3.145 -> java/lang/Thread.setPriority 583 27722 27731 3.145 -> java/lang/Thread.checkAccess 593 27722 27731 3.145 <- java/lang/Thread.checkAccess 603 27722 27731 3.145 -> java/lang/Thread.getThreadGroup 613 27722 27731 3.145 <- java/lang/Thread.getThreadGroup 623 27722 27731 3.145 -> java/lang/ThreadGroup.getMaxPriority 633 27722 27731 3.145 <- java/lang/ThreadGroup.getMaxPriority 643 27722 27731 3.145 -> java/lang/Thread.setPriority0 653 27722 27731 3.145 <- java/lang/Thread.setPriority0 663 27722 27731 3.145 <- java/lang/Thread.setPriority 673 27722 27731 3.145 -> java/lang/Thread.nextThreadID 683 27722 27731 3.145 <- java/lang/Thread.nextThreadID 693 27722 27731 3.145 <- java/lang/Thread.init 703 27722 27731 3.145 <- java/lang/Thread.init 713 27722 27731 3.145 <- java/lang/Thread.<init> 723 27722 27731 3.145 -> java/lang/Thread.start 733 27722 27731 3.145 -> java/lang/ThreadGroup.add 743 27722 27731 3.145 <- java/lang/ThreadGroup.add 753 27722 27731 3.145 -> java/lang/Thread.start0 763 27722 27731 3.145 <- java/lang/Thread.start0 773 27722 27731 3.146 <- java/lang/Thread.start 782 27722 27742 3.146 -> java/lang/Thread.run 79^C 80 81The reason that the CPU number is printed in the first column is that events 82from different threads can be reordered when running on different CPUs, and 83produce non-sensible output. By looking for changes in the CPU column, you can 84easily see if the events you're following make sense and belong to the same 85thread running on the same CPU. 86 87 88USAGE message: 89 90# ./uflow -h 91usage: uflow.py [-h] [-l {java,perl,php,python,ruby,tcl}] [-M METHOD] [-C CLAZZ] [-v] 92 pid 93 94Trace method execution flow in high-level languages. 95 96positional arguments: 97 pid process id to attach to 98 99optional arguments: 100 -h, --help show this help message and exit 101 -l {java,perl,php,python,ruby,tcl}, --language {java,perl,php,python,ruby,tcl} 102 language to trace 103 -M METHOD, --method METHOD 104 trace only calls to methods starting with this prefix 105 -C CLAZZ, --class CLAZZ 106 trace only calls to classes starting with this prefix 107 -v, --verbose verbose mode: print the BPF program (for debugging 108 purposes) 109 110examples: 111 ./uflow -l java 185 # trace Java method calls in process 185 112 ./uflow -l ruby 134 # trace Ruby method calls in process 134 113 ./uflow -M indexOf -l java 185 # trace only 'indexOf'-prefixed methods 114 ./uflow -C '<stdin>' -l python 180 # trace only REPL-defined methods 115