1************************************************************************** 2* Notes for all scripts that print exclusive function times (or method, 3* or subroutine). 4* 5* $Id: ALLexclusive_notes.txt,v 1.1.1.1 2015/09/30 22:01:08 christos Exp $ 6* 7* COPYRIGHT: Copyright (c) 2007 Brendan Gregg. 8************************************************************************** 9 10 11* What is "exclusive" function time? 12 13This is the time of function execution, from when the function begins to 14when it completes, excluding the time spent executing any child function. 15 16Exclusive function time can be calculated like this, 17 18 exclusive function time = time(function end) - time(function start) - 19 time(total child exclusive time) 20 21To do this, the DTrace script needs to keep trace of child function execution 22time, so that it can be subtracted from the parent execution time. 23 24Consider this Bourne shell program, 25 1 #!./sh 26 2 27 3 func_c() 28 4 { 29 5 echo "Function C" 30 6 sleep 1 31 7 } 32 8 33 9 func_b() 34 10 { 35 11 echo "Function B" 36 12 sleep 1 37 13 func_c 38 14 } 39 15 40 16 func_a() 41 17 { 42 18 echo "Function A" 43 19 sleep 1 44 20 func_b 45 21 } 46 22 47 23 func_a 48 49func_a() calls func_b() which calls func_c(). Tracing the flow using 50sh_flowtime.d shows, 51 52# ./sh_flowtime.d | cat -n 53 1 C TIME(us) FILE DELTA(us) -- NAME 54 2 0 3052991099265 func_abc.sh 2 -> func_a 55 3 0 3052991099324 func_abc.sh 59 > echo 56 4 0 3052992111638 func_abc.sh 1012314 | sleep 57 5 0 3052992111678 func_abc.sh 39 -> func_b 58 6 0 3052992111729 func_abc.sh 51 > echo 59 7 0 3052993121633 func_abc.sh 1009903 | sleep 60 8 0 3052993121693 func_abc.sh 60 -> func_c 61 9 0 3052993121745 func_abc.sh 52 > echo 62 10 0 3052994131634 func_abc.sh 1009888 | sleep 63 11 0 3052994131685 func_abc.sh 50 <- func_c 64 12 0 3052994131699 func_abc.sh 14 <- func_b 65 13 0 3052994131707 func_abc.sh 7 <- func_a 66 67the output of DTrace was piped through "cat -n" to enumerate the lines. 68 69Exclusive function time for func_a() in the above output would be the 70time from line 2 to line 13 minus the time from line 5 to 12 to subtract 71the time spent in both func_b() and func_c(). Or, you could say that 72exclusive time for func_a() is the time from lines 2 to 4. 73 74Looking back at the code, exclusive time for func_a() is the time spent 75in code lines 18 and 19 (and not line 20). 76 77See Notes/ALLinclusive_notes.txt for details on "inclusive" function time. 78 79