1 Demonstrations of uflow. 2 3 4 uflow traces method entry and exit events and prints a visual flow graph that 5 shows how methods are entered and exited, similar to a tracing debugger with 6 breakpoints. This can be useful for understanding program flow in high-level 7 languages such as Java, Perl, PHP, Python, Ruby, and Tcl which provide USDT 8 probes for method invocations. 9 10 11 For example, trace all Ruby method calls in a specific process: 12 13 # ./uflow -l ruby 27245 14 Tracing method calls in ruby process 27245... Ctrl-C to quit. 15 CPU PID TID TIME(us) METHOD 16 3 27245 27245 4.536 <- IO.gets 17 3 27245 27245 4.536 <- IRB::StdioInputMethod.gets 18 3 27245 27245 4.536 -> IRB::Context.verbose? 19 3 27245 27245 4.536 -> NilClass.nil? 20 3 27245 27245 4.536 <- NilClass.nil? 21 3 27245 27245 4.536 -> IO.tty? 22 3 27245 27245 4.536 <- IO.tty? 23 3 27245 27245 4.536 -> Kernel.kind_of? 24 3 27245 27245 4.536 <- Kernel.kind_of? 25 3 27245 27245 4.536 <- IRB::Context.verbose? 26 3 27245 27245 4.536 <- IRB::Irb.signal_status 27 3 27245 27245 4.536 -> String.chars 28 3 27245 27245 4.536 <- String.chars 29 ^C 30 31 In the preceding output, indentation indicates the depth of the flow graph, 32 and the <- and -> arrows indicate the direction of the event (exit or entry). 33 34 Often, the amount of output can be overwhelming. You can filter specific 35 classes or methods. For example, trace only methods from the Thread class: 36 37 # ./uflow -C java/lang/Thread $(pidof java) 38 Tracing method calls in java process 27722... Ctrl-C to quit. 39 CPU PID TID TIME(us) METHOD 40 3 27722 27731 3.144 -> java/lang/Thread.<init> 41 3 27722 27731 3.144 -> java/lang/Thread.init 42 3 27722 27731 3.144 -> java/lang/Thread.init 43 3 27722 27731 3.144 -> java/lang/Thread.currentThread 44 3 27722 27731 3.144 <- java/lang/Thread.currentThread 45 3 27722 27731 3.144 -> java/lang/Thread.getThreadGroup 46 3 27722 27731 3.144 <- java/lang/Thread.getThreadGroup 47 3 27722 27731 3.144 -> java/lang/ThreadGroup.checkAccess 48 3 27722 27731 3.144 <- java/lang/ThreadGroup.checkAccess 49 3 27722 27731 3.144 -> java/lang/ThreadGroup.addUnstarted 50 3 27722 27731 3.144 <- java/lang/ThreadGroup.addUnstarted 51 3 27722 27731 3.145 -> java/lang/Thread.isDaemon 52 3 27722 27731 3.145 <- java/lang/Thread.isDaemon 53 3 27722 27731 3.145 -> java/lang/Thread.getPriority 54 3 27722 27731 3.145 <- java/lang/Thread.getPriority 55 3 27722 27731 3.145 -> java/lang/Thread.getContextClassLoader 56 3 27722 27731 3.145 <- java/lang/Thread.getContextClassLoader 57 3 27722 27731 3.145 -> java/lang/Thread.setPriority 58 3 27722 27731 3.145 -> java/lang/Thread.checkAccess 59 3 27722 27731 3.145 <- java/lang/Thread.checkAccess 60 3 27722 27731 3.145 -> java/lang/Thread.getThreadGroup 61 3 27722 27731 3.145 <- java/lang/Thread.getThreadGroup 62 3 27722 27731 3.145 -> java/lang/ThreadGroup.getMaxPriority 63 3 27722 27731 3.145 <- java/lang/ThreadGroup.getMaxPriority 64 3 27722 27731 3.145 -> java/lang/Thread.setPriority0 65 3 27722 27731 3.145 <- java/lang/Thread.setPriority0 66 3 27722 27731 3.145 <- java/lang/Thread.setPriority 67 3 27722 27731 3.145 -> java/lang/Thread.nextThreadID 68 3 27722 27731 3.145 <- java/lang/Thread.nextThreadID 69 3 27722 27731 3.145 <- java/lang/Thread.init 70 3 27722 27731 3.145 <- java/lang/Thread.init 71 3 27722 27731 3.145 <- java/lang/Thread.<init> 72 3 27722 27731 3.145 -> java/lang/Thread.start 73 3 27722 27731 3.145 -> java/lang/ThreadGroup.add 74 3 27722 27731 3.145 <- java/lang/ThreadGroup.add 75 3 27722 27731 3.145 -> java/lang/Thread.start0 76 3 27722 27731 3.145 <- java/lang/Thread.start0 77 3 27722 27731 3.146 <- java/lang/Thread.start 78 2 27722 27742 3.146 -> java/lang/Thread.run 79 ^C 80 81 The reason that the CPU number is printed in the first column is that events 82 from different threads can be reordered when running on different CPUs, and 83 produce non-sensible output. By looking for changes in the CPU column, you can 84 easily see if the events you're following make sense and belong to the same 85 thread running on the same CPU. 86 87 88 USAGE message: 89 90 # ./uflow -h 91 usage: uflow.py [-h] [-l {java,perl,php,python,ruby,tcl}] [-M METHOD] [-C CLAZZ] [-v] 92 pid 93 94 Trace method execution flow in high-level languages. 95 96 positional arguments: 97 pid process id to attach to 98 99 optional 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 110 examples: 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
