Merge from vendor branch LIBSTDC++:
[dragonfly.git] / share / doc / papers / kerntune / 2.t
1 .\" Copyright (c) 1984 M. K. McKusick
2 .\" Copyright (c) 1984 The Regents of the University of California.
3 .\" All rights reserved.
4 .\"
5 .\" Redistribution and use in source and binary forms, with or without
6 .\" modification, are permitted provided that the following conditions
7 .\" are met:
8 .\" 1. Redistributions of source code must retain the above copyright
9 .\"    notice, this list of conditions and the following disclaimer.
10 .\" 2. Redistributions in binary form must reproduce the above copyright
11 .\"    notice, this list of conditions and the following disclaimer in the
12 .\"    documentation and/or other materials provided with the distribution.
13 .\" 3. All advertising materials mentioning features or use of this software
14 .\"    must display the following acknowledgement:
15 .\"     This product includes software developed by the University of
16 .\"     California, Berkeley and its contributors.
17 .\" 4. Neither the name of the University nor the names of its contributors
18 .\"    may be used to endorse or promote products derived from this software
19 .\"    without specific prior written permission.
20 .\"
32 .\"
33 .\"     @(#)2.t 1.3 (Berkeley) 11/8/90
34 .\"
35 .ds RH The \fIgprof\fP Profiler
36 .NH 1
37 The \fIgprof\fP Profiler
38 .PP
39 The purpose of the \fIgprof\fP profiling tool is to 
40 help the user evaluate alternative implementations
41 of abstractions.
42 The \fIgprof\fP design takes advantage of the fact that the kernel
43 though large, is structured and hierarchical.
44 We provide a profile in which the execution time
45 for a set of routines that implement an
46 abstraction is collected and charged
47 to that abstraction.
48 The profile can be used to compare and assess the costs of
49 various implementations [Graham82] [Graham83].
50 .NH 2
51 Data presentation
52 .PP
53 The data is presented to the user in two different formats.
54 The first presentation simply lists the routines
55 without regard to the amount of time their descendants use.
56 The second presentation incorporates the call graph of the
57 kernel.
58 .NH 3 
59 The Flat Profile
60 .PP
61 The flat profile consists of a list of all the routines 
62 that are called during execution of the kernel,
63 with the count of the number of times they are called
64 and the number of seconds of execution time for which they
65 are themselves accountable.
66 The routines are listed in decreasing order of execution time.
67 A list of the routines that are never called during execution of
68 the kernel is also available
69 to verify that nothing important is omitted by
70 this profiling run.
71 The flat profile gives a quick overview of the routines that are used,
72 and shows the routines that are themselves responsible
73 for large fractions of the execution time.
74 In practice,
75 this profile usually shows that no single function
76 is overwhelmingly responsible for 
77 the total time of the kernel.
78 Notice that for this profile,
79 the individual times sum to the total execution time.
80 .NH 3 
81 The Call Graph Profile
82 .PP
83 Ideally, we would like to print the call graph of the kernel,
84 but we are limited by the two-dimensional nature of our output
85 devices.
86 We cannot assume that a call graph is planar,
87 and even if it is, that we can print a planar version of it.
88 Instead, we choose to list each routine,
89 together with information about
90 the routines that are its direct parents and children.
91 This listing presents a window into the call graph.
92 Based on our experience,
93 both parent information and child information
94 is important,
95 and should be available without searching
96 through the output.
97 Figure 1 shows a sample \fIgprof\fP entry.
98 .KF
99 .DS L
100 .TS
101 box center;
102 c c c c c l l
103 c c c c c l l
104 c c c c c l l
105 l n n n c l l.
106                                 called/total    \ \ parents
107 index   %time   self    descendants     called+self     name    index
108                                 called/total    \ \ children
109 _
110                 0.20    1.20    4/10    \ \ \s-1CALLER1\s+1     [7]
111                 0.30    1.80    6/10    \ \ \s-1CALLER2\s+1     [1]
112 [2]     41.5    0.50    3.00    10+4    \s-1EXAMPLE\s+1 [2]
113                 1.50    1.00    20/40   \ \ \s-1SUB1\s+1 <cycle1>       [4]
114                 0.00    0.50    1/5     \ \ \s-1SUB2\s+1        [9]
115                 0.00    0.00    0/5     \ \ \s-1SUB3\s+1        [11]
116 .TE
117 .ce
118 Figure 1. Profile entry for \s-1EXAMPLE\s+1.
119 .DE
120 .KE
121 .PP
122 The major entries of the call graph profile are the entries from the
123 flat profile, augmented by the time propagated to each 
124 routine from its descendants.
125 This profile is sorted by the sum of the time for the routine
126 itself plus the time inherited from its descendants.
127 The profile shows which of the higher level routines 
128 spend large portions of the total execution time 
129 in the routines that they call.
130 For each routine, we show the amount of time passed by each child
131 to the routine, which includes time for the child itself
132 and for the descendants of the child
133 (and thus the descendants of the routine).
134 We also show the percentage these times represent of the total time
135 accounted to the child.
136 Similarly, the parents of each routine are listed, 
137 along with time,
138 and percentage of total routine time,
139 propagated to each one.
140 .PP
141 Cycles are handled as single entities.
142 The cycle as a whole is shown as though it were a single routine,
143 except that members of the cycle are listed in place of the children.
144 Although the number of calls of each member
145 from within the cycle are shown,
146 they do not affect time propagation.
147 When a child is a member of a cycle,
148 the time shown is the appropriate fraction of the time
149 for the whole cycle.
150 Self-recursive routines have their calls broken
151 down into calls from the outside and self-recursive calls.
152 Only the outside calls affect the propagation of time.
153 .PP
154 The example shown in Figure 2 is the fragment of a call graph
155 corresponding to the entry in the call graph profile listing
156 shown in Figure 1.
157 .KF
158 .DS L
159 .so fig2.pic
160 .ce
161 Figure 2. Example call graph fragment.
162 .DE
163 .KE
164 .PP
165 The entry is for routine \s-1EXAMPLE\s+1, which has
166 the Caller routines as its parents,
167 and the Sub routines as its children.
168 The reader should keep in mind that all information
169 is given \fIwith respect to \s-1EXAMPLE\s+1\fP.
170 The index in the first column shows that \s-1EXAMPLE\s+1
171 is the second entry in the profile listing.
172 The \s-1EXAMPLE\s+1 routine is called ten times, four times by \s-1CALLER1\s+1,
173 and six times by \s-1CALLER2\s+1.
174 Consequently 40% of \s-1EXAMPLE\s+1's time is propagated to \s-1CALLER1\s+1,
175 and 60% of \s-1EXAMPLE\s+1's time is propagated to \s-1CALLER2\s+1.
176 The self and descendant fields of the parents
177 show the amount of self and descendant time \s-1EXAMPLE\s+1
178 propagates to them (but not the time used by
179 the parents directly).
180 Note that \s-1EXAMPLE\s+1 calls itself recursively four times.
181 The routine \s-1EXAMPLE\s+1 calls routine \s-1SUB1\s+1 twenty times, \s-1SUB2\s+1 once,
182 and never calls \s-1SUB3\s+1.
183 Since \s-1SUB2\s+1 is called a total of five times,
184 20% of its self and descendant time is propagated to \s-1EXAMPLE\s+1's
185 descendant time field.
186 Because \s-1SUB1\s+1 is a member of \fIcycle 1\fR,
187 the self and descendant times
188 and call count fraction
189 are those for the cycle as a whole.
190 Since cycle 1 is called a total of forty times
191 (not counting calls among members of the cycle),
192 it propagates 50% of the cycle's self and descendant
193 time to \s-1EXAMPLE\s+1's descendant time field.
194 Finally each name is followed by an index that shows
195 where on the listing to find the entry for that routine.
196 .NH 2
197 Profiling the Kernel
198 .PP
199 It is simple to build a 4.2BSD kernel that will automatically
200 collect profiling information as it operates simply by specifying the
201 .B \-p
202 option to \fIconfig\fP\|(8) when configuring a kernel.
203 The program counter sampling can be driven by the system clock,
204 or by an alternate real time clock.
205 The latter is highly recommended as use of the system clock results
206 in statistical anomalies in accounting for
207 the time spent in the kernel clock routine.
208 .PP
209 Once a profiling system has been booted statistic gathering is
210 handled by \fIkgmon\fP\|(8).
211 \fIKgmon\fP allows profiling to be started and stopped
212 and the internal state of the profiling buffers to be dumped.
213 \fIKgmon\fP can also be used to reset the state of the internal
214 buffers to allow multiple experiments to be run without
215 rebooting the machine.
216 The profiling data can then be processed with \fIgprof\fP\|(1)
217 to obtain information regarding the system's operation.
218 .PP
219 A profiled system is about 5-10% larger in its text space because of
220 the calls to count the subroutine invocations.
221 When the system executes,
222 the profiling data is stored in a buffer that is 1.2
223 times the size of the text space.
224 All the information is summarized in memory,
225 it is not necessary to have a trace file
226 being continuously dumped to disk.
227 The overhead for running a profiled system varies;
228 under normal load we see anywhere from 5-25%
229 of the system time spent in the profiling code.
230 Thus the system is noticeably slower than an unprofiled system,
231 yet is not so bad that it cannot be used in a production environment.
232 This is important since it allows us to gather data
233 in a real environment rather than trying to
234 devise synthetic work loads.