home *** CD-ROM | disk | FTP | other *** search
/ C/C++ Interactive Guide / c-cplusplus-interactive-guide.iso / c_ref / csource4 / 262_01 / profile.txt < prev    next >
Text File  |  1988-03-30  |  9KB  |  250 lines
  1. .ce 2
  2. Add an  Execution Time Profiler to your System
  3. by Robert Ramey
  4.  
  5. I really wanted to know how much computer time was consumed by
  6. each part of my program.  Without this information, I couldn't
  7. determine which sections (if any) should be recoded.
  8. For any test run, I wanted to be able to produce a table like
  9. table 1.  This shows the name of each function, the number of
  10. tenths of a second, as well as the percentage of total time
  11. the cpu spent executing that function.
  12. In short, I needed an execution time profiler.  So, I wrote one.
  13.  
  14. My equipment consists of CPM compatible SB-180 single board
  15. computer with 1 MB add on ram, 380K floppy, and a WYSE terminal.
  16. I use the Q/C C compiler from Quality Computer Systems and
  17. the ZAS and ZLINK assembler and linker from Mitek.
  18. The SB-180 uses a Z-80 compatible Hitachi 64180.
  19. The program presented here is hardware dependent.
  20. However, except for 17 lines of code, it is written in C so it
  21. should be adaptable to other environments.
  22.  
  23. 1. How to use the profiler.
  24.  
  25. Normally I link a program with the command:
  26.  
  27.     ZLINK <program name>,CRUNLIB/
  28.  
  29. and execute with the following:
  30.  
  31.     <program name> <command line>
  32.  
  33. When I want to generate an execution profile table, I link with
  34. the command:
  35.  
  36.     ZLINK PROFILE,<program name>,CRUNLIB/ $S
  37.  
  38. On encountering the $S in the link command line,  ZLINK generates
  39. a symbol table named PROFILE.SYM which is the key to generating
  40. the execution profile table.
  41. Finally, I execute with the following:
  42.  
  43.     PROFILE <command line>
  44.  
  45. When execution of PROFILE ends, my default disk contains a file
  46. named PROFILE which contains the execution profile table.  This
  47. can be displayed, printed, sorted, etc. as desired.
  48.  
  49. 2. How the execution profiler works.
  50.  
  51. The profiler depends on the clock interrupt facility of my machine.
  52. Ten times per second, any running program is interrupted and the
  53. clock is updated.
  54. When the profiler is in use, program execution can be summarized:
  55.  
  56.     Before program starts:
  57.         read file PROFILE.SYM into memory and sort by address.
  58.         redirect exit() to special windup() function.
  59.         redirect timer interrupt so that function tick()
  60.             is called instead of clock update function.
  61.         continue on to program execution.
  62.  
  63.     When timer interrupt occurs:
  64.         search table in memory using return address as a key.
  65.         increment counter associated with interrupted function.
  66.         continue normal interrupt processing.
  67.         return to point in program where timer interrupt
  68.             occured.
  69.  
  70.     When program exits:
  71.         enter windup() function.
  72.         write out file PROFILE containing symbols and counters.
  73.         continue with normal exit processing.
  74.  
  75.  
  76. 3. Installing the Profiler in Your Environment.
  77.  
  78. The profiler is written almost entirely in C.  This doesn't mean
  79. it is necessarily portable.  It is heavily dependent on the
  80. idiosyncracies of my machine and C compiler.  Never the less
  81. it could be implemented on many machines with very little change.
  82. The changes are small but do requier that the implementor have an
  83. intimate understanding of his machine and compiler.
  84. Below I'll describe the issues which have to be dealt with when
  85. this program is implemented on another machine.
  86.  
  87. 3.1. Getting Started.
  88.  
  89. The setup routine must execute before the rest of the program.
  90. An easy way to do this is to edit the program so that setup()
  91. is the first function called.  This will work fine in all environments.
  92. If you have access to the startup code in your library there is
  93. a much more elegant solution.
  94. I chose to alter my library startup code so that setup() is
  95. always called before main(). My library also contains a null
  96. setup() function which inmediatly returns.  This adds 4 bytes to
  97. all my programs which do not use the profiler.
  98. However, when I want to use the profiler I only have to relink
  99. not recompile.
  100.  
  101. On my machine as well as almost all Z-80 machines, the address of
  102. the clock interrupt function is found in a table.  The address of
  103. that table element is related to the IR register.  The ir() function
  104. retrieves that address so that clock interrupt can be redirected
  105. is entered.  This will almost certainly requiere modification
  106. for another machine.
  107.  
  108. In order to redirect exit() processing to windup(),  I simply
  109. copy a JP WINDUP instruction in to the first three bytes of
  110. the exit() function.  One of the things windup() does is to
  111. restore the original contents of the first three bytes of the
  112. exit function so that windup() can call exit() when it finishes.
  113. This or something similar will probably function on a
  114. variety of machines.
  115.  
  116. If you have access to the code of your exit() function you
  117. can include a modified 
  118. version of the original exit() which combines the functions
  119. of windup() and exit().
  120.  
  121. Finally, if your compiler is in accordance with Draft Proposed
  122. ANSI C, you can include the statement:
  123.  
  124.     atexit(windup);
  125.  
  126. in the function setup().  This will "register" windup() as a
  127. function to be called after exit() is called but before
  128. starting normal exit processing.
  129.  
  130. 3.2. Interrupt Processing
  131.  
  132. A timer interrupt is a function call which can take place anywhere
  133. within the program.  Like any function call, the return address
  134. is pushed on to the stack and control is passed to the called
  135. function.  By placing the address of tick() in the appropriate slot
  136. of the interrupt vector table  setup() makes sure that the called
  137. function is tick().  Unlike a normal function call, tick() must leave
  138. all registers in the same state it found them.
  139.  
  140. The principal function of tick() is to modify the stack so that
  141. normal timer interrupt processing will occur when tick() returns,
  142. and save and restore appropriate registers while bump()
  143. is called.  This is extremely dependent on the machine
  144. and compiler.  Fortunately, it is only 14 statements long.
  145.  
  146. bump() is the principle function of the profiler.  It does a
  147. binary search of the symbol table using the interrupt return
  148. address as the key.  The corresponding counter is incremented.
  149. My version of bump() uses only static variables.
  150. This means that I don't have to complicate the program with
  151. issues of stack frame management during interrupt processing.
  152. Also its faster on my machine.
  153.  
  154. 3.3. Finishing Up.
  155.  
  156. If you've come this far finishing up is trivial.  Its a straight
  157. forward C function which writes the execution profile to disk.
  158. For each function interrupted at least once, the name of the
  159. function, number of times interrupted and percentage of total
  160. interrupts is written to the file PROFILE.  This is completely
  161. portable to any C compiler.
  162.  
  163. 4. Summing Up.
  164.  
  165. The sample execution profile in the table corresponds to a program
  166. which reads a 22K text file from disk and writes out a table
  167. indicating how many times each word appears in the text file.
  168. All input/output was from/to ramdisk.
  169. Functions whose names start
  170. with ? implement primitive operations such as integer and stack
  171. manipulation.
  172. 20 percent of execution time was consumed by
  173. ?enr and ?exr which allocate and save register
  174. variables.  13 percent was consumed by putc() and getc().  There is
  175. not much point in trying to optimize this program until the
  176. performance of the C library is improved.
  177. Without the execution time profile,  many hours might have been
  178. wasted.
  179.  
  180. I think this shows how useful C can for a job which one would
  181. normally think to apply assembler programming.
  182. It also shows that being written in C doesn't necessarily make it
  183. portable.
  184. However, this program could be ported to many other environments
  185. with very little effort.  The utility of this tool is far out
  186. proportion to the size of the program and the effort requiered
  187. to implement it.
  188.  
  189. Bibliography
  190.  
  191. O'Connell, Patrick, Relocating Macro Assembler and Linker for Z-80
  192. and HD64180.  Echelon Inc. 101 First Street, Los Altos CA 94022
  193.  
  194. Colvin, Jim Q/C Users Manual. The Code Works. Santa Barabara,
  195. California
  196.  
  197. Harbison, Samuel P. and Steele, Guy L.   C:A Reference Manual.
  198. Prentice-Hall, Inc.  Englewood Cliffs, New Jersey 07632
  199. .bp
  200. .nf
  201. Table 1
  202.  
  203. MAIN?        1      0
  204. LDWORD        2      1
  205. GETWRD        9      3
  206. SYMDMP        1      0
  207. SYMLKU        6      2
  208. SYMADD        3      1
  209.