1\" @(#)present.me 1.4 03/12/82 2.sh 1 "Data Presentation" 3.pp 4The data is presented to the user in two different formats. 5The first presentation simply lists the routines 6without regard to the amount of time their descendants use. 7The second presentation incorporates the call graph of the 8program. 9.sh 2 "The Flat Profile 10.pp 11The flat profile consists of a list of all the routines 12that are called during execution of the program, 13with the count of the number of times they are called 14and the number of seconds of execution time for which they 15are themselves accountable. 16The routines are listed in decreasing order of execution time. 17A list of the routines that are never called during execution of 18the program is also available 19to verify that nothing important is omitted by 20this execution. 21The flat profile gives a quick overview of the routines that are used, 22and shows the routines that are themselves responsible 23for large fractions of the execution time. 24In practice, 25this profile usually indicates that no single function 26is overwhelmingly responsible for 27the total time of the program. 28Notice that for this profile, 29the individual times sum to the total execution time. 30.sh 2 "The Call Graph Profile" 31.pp 32Ideally, we would like to print the call graph of the program, 33but we are limited by the two-dimensional nature of our output 34devices. 35We cannot assume that a call graph is planar, 36and even if it is, that we can print a planar version of it. 37Instead, we choose to print each routine, 38together with information about 39the routines that are its direct parents and children. 40This listing presents a window into the call graph. 41Based on our experience, 42both parent information and child information 43is important, 44and should be available without searching 45through the output. 46.pp 47The major entries of the call graph profile are the entries from the 48flat profile, augmented by the time propagated to each 49routine from its descendants. 50This profile is sorted by the sum of the time for the routine 51itself plus the time inherited from its descendants. 52The profile shows which of the higher level routines 53spend large portions of the total execution time 54in the routines that they call. 55For each routine, we show the amount of time passed by each child 56to the routine, which includes time for the child itself 57and for the descendants of the child 58(and thus the descendants of the routine). 59We also show the percentage these times represent of the total time 60accounted to the child. 61Similarly, the parents of each routine are listed, 62along with time, 63and percentage of total routine time, 64propagated to each one. 65.pp 66Cycles are handled as single entities. 67The cycle as a whole is shown as though it were a single routine, 68except that members of the cycle are listed in place of the children. 69Although the number of calls of each member 70from within the cycle are shown, 71they do not affect time propagation. 72When a child is a member of a cycle, 73the time shown is the appropriate fraction of the time 74for the whole cycle. 75Self-recursive routines have their calls broken 76down into calls from the outside and self-recursive calls. 77Only the outside calls affect the propagation of time. 78.pp 79The following example is a typical fragment of a call graph. 80.(b 81.TS 82center; 83c c c. 84 85Caller1 Caller2 86 87 88 Example 89 90 91Sub1 Sub2 Sub3 92 93.TE 94.)b 95This example would have the following form of entry 96in the profile listing. 97.(b 98.TS 99box center; 100c c c c c l l 101c c c c c l l 102c c c c c l l 103l n n n c l l. 104 called/total \ \ parents 105index %time self descendants called+self name index 106 called/total \ \ children 107_ 108 0.20 1.20 4/10 \ \ Caller1 [7] 109 0.30 1.80 6/10 \ \ Caller2 [1] 110[2] 41.5 0.50 3.00 10+4 Example [2] 111 1.50 1.00 20/40 \ \ Sub1 <cycle1> [4] 112 0.00 0.50 1/5 \ \ Sub2 [9] 113 0.00 0.00 0/5 \ \ Sub3 [11] 114.TE 115.)b 116.pp 117The entry is for routine Example, which has 118the Caller routines as its parents, 119and the Sub routines as its children. 120The reader should keep in mind that all information 121is given \fIwith respect to Example\fP. 122The index in the first column indicates that Example 123is the second entry in the profile listing. 124The Example routine is called ten times, four times by Caller1, 125and six times by Caller2. 126Consequently 40% of Example's time is propagated to Caller1, 127and 60% of Example's time is propagated to Caller2. 128The self and descendant fields of the parents 129show the amount of self and descendant time Example 130propagates to them (but not the time used by 131the parents directly). 132Note that Example calls itself recursively four times. 133The routine Example calls routine Sub1 twenty times, Sub2 once, 134and never calls Sub3. 135Since Sub2 is called a total of five times, 13620% of its self and descendant time is propagated to Example's 137descendant time field. 138Because Sub1 is a member of \fIcycle 1\fR, 139the self and descendant times are those for the cycle as a whole. 140Since Sub1 is called a total of forty times from outside 141of its cycle, it propagates 50% of the cycle's self and descendant 142time to Example's descendant time field. 143Finally each name is followed by an index that indicates 144where on the listing to find the entry for that routine. 145.sh 1 "Using the Profiles" 146.pp 147The profiler is a useful tool for improving 148a set of routines that implement an abstraction. 149It can be helpful in identifying poorly coded routines, 150and in evaluating the new algorithms and code that replace them. 151Taking full advantage of the profiler 152requires a careful examination of the call graph profile, 153and a thorough knowledge of the abstractions underlying 154the program. 155.pp 156One of the easiest optimizations that can be performed 157is a small change 158to a control construct or data structure that improves the 159running time of the program. 160An obvious starting point 161is a routine that is called many times. 162For example, suppose an output 163routine is the only parent 164of a routine that formats the data. 165If this format routine is expanded inline in the 166output routine, the overhead of a function call and 167return can be saved for each datum that needs to be formatted. 168.pp 169The drawback to inline expansion is that the data abstractions 170in the program may become less parameterized, 171hence less clearly defined. 172The profiling will also become less useful since the loss of 173routines will make its output more granular. 174For example, 175if the symbol table functions ``lookup'', ``insert'', and ``delete'' 176are all merged into a single parameterized routine, 177it will be impossible to determine the costs 178of any one of these individual functions from the profile. 179.pp 180Further potential for optimization lies in routines that 181implement data abstractions whose total execution 182time is long. 183For example, a lookup routine might be called only a few 184times, but use an inefficient linear search algorithm, 185that might be replaced with a binary search. 186Alternately, the discovery that a rehashing function is being 187called excessively, can lead to a different 188hash function or a larger hash table. 189If the data abstraction function cannot easily be speeded up, 190it may be advantageous to cache its results, 191and eliminate the need to rerun 192it for identical inputs. 193.pp 194This tool is best used in an iterative approach: 195profiling the program, 196eliminating one bottleneck, 197then finding some other part of the program 198that begins to dominate execution time. 199For instance, we have used \fBgprof\fR on itself; 200eliminating, rewriting, and inline expanding routines, 201until reading 202data files (hardly a target for optimization!) 203represents the dominating factor in its execution time. 204.pp 205Certain types of programs are not easily analyzed by \fBgprof\fR. 206They are typified by programs that exhibit a large degree of 207recursion, such as recursive descent compilers. 208The problem is that most of the major routines are grouped 209into a single monolithic cycle. 210As in the case of the symbol table abstraction that is placed 211in one routine, 212it is impossible to distinguish which members of the cycle are 213responsible for the execution time. 214Unfortunately there are no easy modifications to these programs that 215make them amenable to analysis. 216.pp 217A completely different use of the profiler is to analyze the control 218flow of an unfamiliar program. 219If you receive a program from another user that you need to modify 220in some small way, 221it is often unclear where the changes need to be made. 222By running the program on an example and then using \fBgprof\fR, 223you can get a view of the structure of the program. 224.pp 225Consider an example in which you need to change the output format 226of the program. 227For purposes of this example suppose that the call graph 228of the output portion of the program has the following structure: 229.(b 230.TS 231center; 232c c c. 233 234calc1 calc2 calc3 235 236 237format1 format2 238 239 240 ``write'' 241 242.TE 243.)b 244Initially you look through the \fBgprof\fR 245output for the system call ``write''. 246The format routine you will need to change is probably 247among the parents of the ``write'' procedure. 248The next step is to look at the profile entry for each 249of parents of ``write'', 250in this example either ``format1'' or ``format2'', 251to determine which one to change. 252Each format routine will have one or more parents, 253in this example ``calc1'', ``calc2'', and ``calc3''. 254By inspecting the source code for each of these routines 255you can determine which format routine generates the output that 256you wish to modify. 257Since the \fBgprof\fR entry indicates all the 258potential calls to the format routine you intend to change, 259you can determine if your modifications will affect output that 260should be left alone. 261If you desire to change the output of ``calc2'', but not ``calc3'', 262then formatting routine ``format2'' needs to be split 263into two separate routines, 264one of which implements the new format. 265You can then retarget just the call by ``calc2'' 266that needs the new format. 267It should be noted that the static call information is particularly 268useful in this case since the test case you run probably will not 269exercise the entire program. 270.sh 1 "Conclusions" 271.pp 272We have created a profiler that aids in the evaluation 273of modular programs. 274For each routine in the program, 275the profile shows the extent to which that routine 276helps support various abstractions, 277and how that routine uses other abstractions. 278The profile accurately assesses the cost of routines 279at all levels of the program decomposition. 280The profiler is easily used, 281and can be compiled into the program without any prior planning on the part 282of the programmer. 283It adds only five to thirty percent execution overhead to the program 284being profiled, 285produces no additional output until after the program finishes, 286and allows the program to be measured in its actual environment. 287Finally, the profiler runs on a time-sharing system 288using only the normal services provided by the operating system. 289