home *** CD-ROM | disk | FTP | other *** search
/ Amiga ISO Collection / AmigaUtilCD2.iso / Programming / C / SASC6571.LZX / examples / profile / READ.ME < prev    next >
Encoding:
Text File  |  1996-12-24  |  7.0 KB  |  181 lines
  1. Profiling Examples
  2. Copyright (c) 1993 SAS Institute, Inc, Cary, NC, USA
  3. All Rights Reserved
  4. ===================
  5.  
  6. This directory contains a test program which is built two ways - one
  7. suitable for profiling with SPROF, one suitable for profiling with 
  8. LPROF.  SPROF and LPROF both try to give you information you need
  9. to determine where your code is spending most of its time, but they
  10. do it in slightly different ways.
  11.  
  12. Before trying to use the profilers, build the test programs by typing
  13. "smake" in the Shell or double-clicking the Build icon from Workbench.
  14. Two different executables are built from the same source file.  "stest"
  15. is compiled with the PROFILE compiler option and is therefore suitable
  16. for use with SPROF.  "ltest" is compiled normally and is suitable for
  17. use with LPROF.
  18.  
  19. =============
  20. RUNNING SPROF
  21. =============
  22.  
  23. To run SPROF from the Workbench, double-click on the SPROF icon in the
  24. SC:C drawer, then double-click on the STEST program, or click on SPROF
  25. and then hold the SHIFT key and double-click on STEST.
  26.  
  27. To run SPROF from the Shell, enter the following command line:
  28.  
  29.    sprof stest
  30.  
  31. The program will take anywhere from a few seconds to a few minutes
  32. depending on the speed of your Amiga.  When it finishes running, SPROF
  33. will generate a report like this:
  34.  
  35.    SPROF Report
  36.    Status: Complete
  37.    Name                  Count ITime ETime Pct
  38.    \test.c\f100b\32       3000  5596  5596  72.8
  39.    \test.c\f100c\38        300   569   569   7.4
  40.    \test.c\f300\50         300   561   561   7.3
  41.    \test.c\f200\44         200   376   376   4.9
  42.    \test.c\f100\26         100   189   189   2.5
  43.    \test.c\f100static\20   100   186   186   2.4
  44.    \test.c\f30x100\56       30  5748   152   2.0
  45.    \test.c\main\85           1  7686    40   0.5
  46.    \test.c\f100x3\63       100   586    17   0.2
  47.                                      ----- -----
  48.                                       7686 100.0
  49.  
  50.    The "Name" field gives the function name in the format 
  51.    "\file\func\line".
  52.  
  53.    The "Count" field tells you how many times the function was called.
  54.  
  55.    The "ITime" field tells you how many microseconds the function was
  56.    on the stack - i.e. how much time was spent in the function Including
  57.    any subroutines called by the function.
  58.  
  59.    The "ETime" field tells you how many microseconds were spent executing
  60.    the function, Excluding time spent in subroutines.
  61.  
  62.    The "Pct" field tells you the percentage of the total time spent in the
  63.    program that was spent in the listed function.  The percentage is
  64.    calculated by dividing the ETime for this function by the sum of all
  65.    ETime values for all functions in the program.
  66.  
  67. *****
  68. You don't have to wait until the program finishes to get a report.  SPROF
  69. has the capability of producing intermediate reports.  To see an
  70. intermediate report, re-run SPROF from a Shell window.  Then, while the
  71. program is running, type a CTRL-F character in the Shell.  SPROF will
  72. produce a report the next time any function in your program is entered
  73. or returns, or the next time a PROFILE_ON() or PROFILE_OFF() macro is
  74. called.  There is no easy way to duplicate this feature when running
  75. from the WorkBench.
  76.  
  77. *****
  78. From either the Shell or the WorkBench, however, you can get continual
  79. reports by using the REPORT option on SPROF.  From the Shell, type
  80.  
  81.    sprof report 5 test
  82.  
  83. From the WorkBench, click on the SPROF icon, then select "Info" from
  84. the WorkBench menu.  Add the following line to the ToolTypes array
  85. for SPROF:
  86.  
  87.    report=5
  88.  
  89. The next time you run SPROF, it will automatically produce a report
  90. every 5 seconds.
  91.  
  92. *****
  93. A very useful feature of SPROF is that you can choose to exclude certain
  94. sections of your program if you like.  If you've looked at the source
  95. code to the test program (in "test.c") you will notice that if you
  96. provide a parameter, the program asks you to hit RETURN and waits until
  97. you do.  We don't want to count the time spent waiting, so the PROFILE_OFF
  98. and PROFILE_ON macros (defined in <include:sprof.h>) were added to
  99. surround the call to getch().
  100.  
  101. Try it by entering the following command from a Shell:
  102.  
  103.    sprof stest 10
  104.  
  105. 10 is a "delay factor" which determines how long the program will run.
  106. The default is also 10, so we should see no results in our profiling
  107. between the two runs.  The program will print the following lines:
  108.  
  109.    Using delay factor of 10
  110.    Hit RETURN to continue: 
  111.  
  112. Wait about 10 seconds, then hit RETURN.  When the report is generated,
  113. note that the total ETime value is very close to the one generated when
  114. no getch() was executed.  Time spent in getch() doesn't count against
  115. your program.
  116.  
  117. *****
  118. SPROF can be used to profile shared libraries, devices, tasks created by
  119. your tasks, and other hard-to-get-to tasks or processes.  The task to be
  120. profiled must execute one of the SAS/C provided startup modules so the
  121. SPROF autoinit/autoterm code is executed.  You should start SPROF running
  122. with no program name first, then start your task.
  123.  
  124. From the Shell, type this:
  125.  
  126.    sprof
  127.  
  128. From WorkBench, double-click on the SProf icon in SC:C.  Next, start
  129. your task.  Only one task in the system can be profiled at any one
  130. time.
  131.  
  132. For an example of profiling a shared library, see the directory
  133. SC:EXAMPLES/RESLIB.
  134.  
  135. =============
  136. RUNNING LPROF
  137. =============
  138.  
  139. To run the LPROF profiler, you must be in a Shell.  Lprof doesn't work
  140. from WorkBench.  Enter the following command:
  141.  
  142.    lprof ltest
  143.  
  144. A data file called "prof.out" is produced.  Run the LSTAT program on it:
  145.  
  146.    lstat ltest
  147.  
  148. Lstat automatically opens "prof.out" and uses the data in the executable
  149. "ltest" to associate the profiling data with filenames and line numbers.
  150. Lstat generates a report like this:
  151.  
  152.    SAS AMIGA 68000 Profile Analyzer V6.50
  153.    Copyright © 1992-1993 SAS Institute Inc.  All Rights Reserved.
  154.    Profile Statistics for ltest
  155.    217 run + 4 ready + 0 wait = 221
  156.     98.190% run,   1.8010% ready,   0.000% wait
  157.      0.460% samples (1) out of profile range
  158.    
  159.    counted = 216, RUN - NonTable 1
  160.    
  161.    Routine %   Total % Offset     Hits   Label
  162.     74.5371%  74.5371%    2a8      161 @f100b [lines 25-31 in Work:sc/examples/profile/test.c]
  163.                          Most hits - 74.5371% (161) on line 30
  164.      7.8703%  82.4075%    314       17 @f300 [lines 43-49 in Work:sc/examples/profile/test.c]
  165.                          Most hits -  5.5556% (12) on line 48
  166.      7.4075%  89.8148%    2cc       16 @f100c [lines 31-37 in Work:sc/examples/profile/test.c]
  167.                          Most hits -  4.6297% (10) on line 36
  168.      5.0925%  94.9075%    2f0       11 @f200 [lines 37-43 in Work:sc/examples/profile/test.c]
  169.                          Most hits -  3.7037% (8) on line 42
  170.      2.3148%  97.2222%    1c6        5 @_XCEXIT [lines 3-19 in c]
  171.                          Most hits -  2.3148% (5) on line 18
  172.      2.3148%  99.5371%    284        5 @f100 [lines 19-25 in Work:sc/examples/profile/test.c]
  173.                          Most hits -  1.3889% (3) on line 24
  174.      0.4629% 100.0000%   10cc        1 @__chkabort [lines 2-3 in _chkabort.c]
  175.                          Most hits -  0.4629% (1) on line 2
  176.  
  177. This report gives you actual line numbers that received the most hits,
  178. and it also includes link library functions in the profiling.  The results
  179. are very similar to SPROF's, as expected.
  180.  
  181.