xref: /netbsd-src/external/cddl/dtracetoolkit/dist/Docs/Notes/ALLinclusive_notes.txt (revision c29d51755812ace2e87aeefdb06cb2b4dac7087a)
1**************************************************************************
2* Notes for all scripts that print inclusive function times (or method,
3* or subroutine).
4*
5* $Id: ALLinclusive_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 "inclusive" function time?
12
13This is the time of function execution, from when the function begins to
14when it completes. This includes the times from all child functions called.
15
16Inclusive function time is calculated in a very simple way,
17
18   inclusive function time = time(function end) - time(function start)
19
20Consider this Bourne shell program,
21
22     1  #!./sh
23     2
24     3  func_c()
25     4  {
26     5          echo "Function C"
27     6          sleep 1
28     7  }
29     8
30     9  func_b()
31    10  {
32    11          echo "Function B"
33    12          sleep 1
34    13          func_c
35    14  }
36    15
37    16  func_a()
38    17  {
39    18          echo "Function A"
40    19          sleep 1
41    20          func_b
42    21  }
43    22
44    23  func_a
45
46func_a() calls func_b() which calls func_c(). Tracing the flow using
47sh_flowtime.d shows,
48
49# ./sh_flowtime.d | cat -n
50     1    C TIME(us)         FILE             DELTA(us) -- NAME
51     2    0 3052991099265    func_abc.sh              2 -> func_a
52     3    0 3052991099324    func_abc.sh             59   > echo
53     4    0 3052992111638    func_abc.sh        1012314   | sleep
54     5    0 3052992111678    func_abc.sh             39   -> func_b
55     6    0 3052992111729    func_abc.sh             51     > echo
56     7    0 3052993121633    func_abc.sh        1009903     | sleep
57     8    0 3052993121693    func_abc.sh             60     -> func_c
58     9    0 3052993121745    func_abc.sh             52       > echo
59    10    0 3052994131634    func_abc.sh        1009888       | sleep
60    11    0 3052994131685    func_abc.sh             50     <- func_c
61    12    0 3052994131699    func_abc.sh             14   <- func_b
62    13    0 3052994131707    func_abc.sh              7 <- func_a
63
64the output of DTrace was piped through "cat -n" to enumerate the lines.
65
66Inclusive function time for func_a() in the above output would be the
67time from line 2 to line 13. This inclusive time includes the time
68for both func_b() and func_c().
69
70Looking back at the code, inclusive time for func_a() is the time spent
71in code lines 18, 19 and 20.
72
73See Notes/ALLexclusive_notes.txt for details on "exclusive" function time.
74
75