home *** CD-ROM | disk | FTP | other *** search
/ CP/M / CPM_CDROM.iso / simtel / sigm / vols000 / vol071 / profile.doc < prev    next >
Encoding:
Text File  |  1984-04-29  |  6.4 KB  |  185 lines
  1.           Execution Profiling in PASCAL/Z
  2.  
  3.  
  4. A program's "execution profile" is a map showing the number
  5. of times each statement in the program was executed during a
  6. trial run.  The profile supplies the central information
  7. needed to analyze the program's performance.  With a small
  8. modification of the run-time support package, an execution
  9. profile can be obtained for any PASCAL/Z program.
  10.  
  11. Obtaining the Profile.
  12.  
  13. An execution profile is a dynamic count of statement
  14. executions.  It can only be obtained while the program is
  15. actually running.  The steps that must be taken are:
  16.  
  17.      1. The program must contain an array of integers, one
  18.     integer for each statement to be counted.
  19.  
  20.      2. The array must be set to zero when execution begins.
  21.  
  22.      3. Whenever statement J is executed, ARRAY[J] must be
  23.     incremented.
  24.  
  25.      4. At the end of the program, the array must be written
  26.     to disk for safe-keeping.
  27.  
  28.      5. The array must be formatted for human use -- a bar-
  29.     graph is the simplest format.
  30.  
  31. Steps 1-4 can be accomplished through modifications of the
  32. Pascal/Z run-time support module, MAIN.SRC.
  33.  
  34. The assembler source file produced by the compiler contains
  35. a call on the STMT macro at the beginning of the code for
  36. each compiled statement.  This macro call contains the
  37. number of the statement.  The macro is defined by MAIN.SRC.
  38. It can be modified to accomplish step 3, and to note the
  39. lowest and highest statement numbers being profiled.
  40.  
  41. The last line emitted by the compiler is a call on the FINI
  42. macro, also defined in MAIN.SRC.  That macro has been
  43. modified to perform step 1 (defining the array of integers)
  44. and step 4 (writing the array to disk).  MAIN.SRC also
  45. contains the initialization code for the program, which has
  46. been modified to perform step 2.
  47.  
  48. A Pascal program named PROFILE performs the formatting of
  49. the array.
  50.  
  51. Creating a Profile.
  52.  
  53. Do these things in order to create a program's profile:
  54.  
  55. Edit the Pascal source file and mark the sections to be
  56. profiled by turning on the Trace option around them
  57. ("{$T+}").  To profile the entire program, just set Trace on
  58. in the first line.  This is the only change to the program.
  59.  
  60. Compile the program in the normal way.    Then assemble it
  61. with PROMAIN rather than with MAIN:
  62.  
  63.     ASMBL PROMAIN,name/REL
  64.  
  65. and link it in the normal way.    The program will be a few
  66. hundred bytes larger than it would ordinarily be.
  67.  
  68. Execute the program.  It will run somewhat slower than
  69. usual.    The cost of profiling is about the same as the cost
  70. of the control-c check option.    At the end of the run, it
  71. will create a small file named A:PROFILER.DAT.    This must be
  72. written on the A-drive, so that must be read/write.
  73.  
  74. Execute the PROFILE command.  It will read A:PROFILER.DAT
  75. and write a file A:PROFILER.PRN.  This contains the
  76. execution profile bar-graph; it can be printed or displayed
  77. at the console.
  78.  
  79. Using the Profile.
  80.  
  81. The profile shows the absolute and relative execution
  82. intensity of the traced statements.  In most programs, this
  83. will be distributed according to the "80-20" rule -- 20% of
  84. the statements will account for 80% of the execution counts.
  85. Once you know which statements dominate the execution time,
  86. you can usually make a major improvement in the speed of the
  87. program.  Those are the statements to check for such obvious
  88. things as real-to-integer conversions, or unneeded array
  89. subscripting.  Those areas of the program are where space-time
  90. tradeoffs should be made.  In short, the profile highlights
  91. the parts of the program where your optimization efforts
  92. will be rewarded with the largest payoffs in time saved.
  93.  
  94. The profile can also reveal unsuspected program errors.
  95. Comparing the counts to the expected behaviour of the
  96. program might reveal that some statements were never
  97. executed, or were executed too often, due to incorrect
  98. logic.
  99.  
  100. Restrictions and Work Remaining.
  101.  
  102. The statement counts are kept as 16-bit integers.  The
  103. PROFILE command adjusts for counts that exceed 32,767 but it
  104. cannot tell if a count exceeded 65,536.  If the profile
  105. produces strange numbers, examine the program and the data
  106. to see if some statements might have been executed more than
  107. 65,536 times.
  108.  
  109. A profile can only be made for a main program; an external,
  110. linked module can't be profiled.  A person who
  111. made extensive use of external modules or of overlay modules
  112. might examine EMAIN.SRC to see if some similar facility
  113. could be added to it.
  114.  
  115. The PROFILE command is very simple.  Much more elaborate
  116. reports could be derived from the data.  For example, the
  117. program's .LST file could be read, and the profile bar graph
  118. merged with it, so that the profile information was
  119. reflected in the program listing.
  120.  
  121. An Example.
  122.  
  123. The following listing is a copy of PROFILER.PRN, showing the
  124. execution profile of PROFILE.PAS, taken while PROFILE was
  125. working on its own profile data.  As you can see, the program
  126. has two extremely hot spots.  Any simplification of those
  127. statements will be reflected directly in its execution time.
  128. In the case of PROFILE, total time is largely dominated by
  129. disk I/O, but in a more compute-bound program such a profile
  130. would allow an immediate, major, speed-up.
  131.  
  132.    1     56|                              |
  133.    2     56|                              |
  134.    3     56|                              |
  135.    4     56|                              |
  136.    5      0|                              |
  137.    6      0|                              |
  138.    7      0|                              |
  139.    8     53|                              |
  140.    9     53|                              |
  141.   10      0|                              |
  142.   11     53|                              |
  143.   12      1|                              |
  144.   13      1|                              |
  145.   14     53|                              |
  146.   15     53|                              |
  147.   16     53|                              |
  148.   17     53|                              |
  149.   18      1|                              |
  150.   19     53|                              |
  151.   20     53|                              |
  152.   21     53|                              |
  153.   22      1|                              |
  154.   23      1|                              |
  155.   24      1|                              |
  156.   25     53|                              |
  157.   26     53|                              |
  158.   27     53|                              |
  159.   28     53|                              |
  160.   29   2650|********************                  |
  161.   30     40|                              |
  162.   31   2610|********************                  |
  163.   32     53|                              |
  164.   33     53|                              |
  165.   34     53|                              |
  166.   35      1|                              |
  167.   36      1|                              |
  168.   37      1|                              |
  169.   38      1|                              |
  170.   39      1|                              |
  171.   40      1|                              |
  172.   41      1|                              |
  173.   42      1|                              |
  174.   43      1|                              |
  175.   44      1|                              |
  176.   45      1|                              |
  177.   46      1|                              |
  178.   47      1|                              |
  179.   48      1|                              |
  180.   49      1|                              |
  181.   50      1|                              |
  182.   51      0|                              |
  183.   52      0|                              |
  184.   53      0|                              |
  185.