]> git.karo-electronics.de Git - karo-tx-redboot.git/blob - packages/services/profile/gprof/v2_0/doc/profile.sgml
55192d189a2596db5107537a2667574884004d74
[karo-tx-redboot.git] / packages / services / profile / gprof / v2_0 / doc / profile.sgml
1 <!-- DOCTYPE part  PUBLIC "-//OASIS//DTD DocBook V3.1//EN" -->
2
3 <!-- {{{ Banner                         -->
4
5 <!-- =============================================================== -->
6 <!--                                                                 -->
7 <!--     profile.sgml                                                -->
8 <!--                                                                 -->
9 <!--     gprof profiling documentation.                              -->
10 <!--                                                                 -->
11 <!-- =============================================================== -->
12 <!-- ####COPYRIGHTBEGIN####                                          -->
13 <!--                                                                 -->
14 <!-- =============================================================== -->
15 <!-- Copyright (C) 2003, 2005 eCosCentric Ltd.                       -->
16 <!-- This material may be distributed only subject to the terms      -->
17 <!-- and conditions set forth in the Open Publication License, v1.0  -->
18 <!-- or later (the latest version is presently available at          -->
19 <!-- http://www.opencontent.org/openpub/)                            -->
20 <!-- Distribution of the work or derivative of the work in any       -->
21 <!-- standard (paper) book form is prohibited unless prior           -->
22 <!-- permission obtained from the copyright holder                   -->
23 <!-- =============================================================== -->
24 <!--                                                                 -->      
25 <!-- ####COPYRIGHTEND####                                            -->
26 <!-- =============================================================== -->
27 <!-- =============================================================== -->
28 <!-- #####DESCRIPTIONBEGIN####                                       -->
29 <!--                                                                 -->
30 <!-- Author(s):   bartv                                              -->
31 <!-- Date:        2003/09/01                                         -->
32 <!-- Version:     0.01                                               -->
33 <!--                                                                 -->
34 <!-- ####DESCRIPTIONEND####                                          -->
35 <!-- =============================================================== -->
36
37 <!-- }}} -->
38
39 <part id="services-profile-gprof"><title>gprof Profiling Support</title> 
40
41 <refentry id="gprof">
42   <refmeta>
43     <refentrytitle>Profiling</refentrytitle>
44   </refmeta>
45   <refnamediv>
46     <refname><varname>CYGPKG_PROFILE_GPROF</varname></refname>
47     <refpurpose>eCos Support for the gprof profiling tool</refpurpose>
48   </refnamediv>
49
50   <refsect1 id="gprof-description"><title>Description</title>
51     <para>
52 The GNU gprof tool provides profiling support. After a test run it can
53 be used to find where the application spent most of its time, and that
54 information can then be used to guide optimization effort. Typical
55 gprof output will look something like this:
56     </para>
57     <screen>
58 Each sample counts as 0.003003 seconds.
59   %   cumulative   self              self     total           
60  time   seconds   seconds    calls  us/call  us/call  name    
61  14.15      1.45     1.45   120000    12.05    12.05  Proc_7
62  11.55      2.63     1.18   120000     9.84     9.84  Func_1
63   8.04      3.45     0.82                             main
64   7.60      4.22     0.78    40000    19.41    86.75  Proc_1
65   6.89      4.93     0.70    40000    17.60    28.99  Proc_6
66   6.77      5.62     0.69    40000    17.31    27.14  Func_2
67   6.62      6.30     0.68    40000    16.92    16.92  Proc_8
68   5.94      6.90     0.61                             strcmp
69   5.58      7.47     0.57    40000    14.26    26.31  Proc_3
70   5.01      7.99     0.51    40000    12.79    12.79  Proc_4
71   4.46      8.44     0.46    40000    11.39    11.39  Func_3
72   3.68      8.82     0.38    40000     9.40     9.40  Proc_5
73   3.32      9.16     0.34    40000     8.48     8.48  Proc_2
74 &hellip;
75     </screen>
76     <para>
77 This output is known as the flat profile. The data is obtained by
78 having a hardware timer generate regular interrupts. The interrupt
79 handler stores the program counter of the interrupted code. gprof
80 performs a statistical analysis of the resulting data and works out
81 where the time was spent.
82     </para>
83     <para>
84 gprof can also provide information about the call graph, for example:
85     </para>
86     <screen>
87 index % time    self  children    called     name
88 &hellip;
89                 0.78    2.69   40000/40000       main [1]
90 [2]     34.0    0.78    2.69   40000         Proc_1 [2]
91                 0.70    0.46   40000/40000       Proc_6 [5]
92                 0.57    0.48   40000/40000       Proc_3 [7]
93                 0.48    0.00   40000/120000      Proc_7 [3]
94     </screen>
95     <para>
96 This shows that function <function>Proc_1</function> was called only
97 from <function>main</function>, and <function>Proc_1</function> in
98 turn called three other functions. Callgraph information is obtained
99 only if the application code is compiled with the <option>-pg</option>
100 option. This causes the compiler to insert extra code into each
101 compiled function, specifically a call to <function>mcount</function>,
102 and the implementation of <function>mcount</function> stores away the
103 data for subsequent processing by gprof.
104     </para>
105     <caution><para>
106 There are a number of reasons why the output will not be 100%
107 accurate. Collecting the flat profile typically involves timer
108 interrupts so any code that runs with interrupts disabled will not
109 appear. The current host-side gprof implementation maps program
110 counter values onto symbols using a bin mechanism. When a bin spans
111 the end of one function and the start of the next gprof may report the
112 wrong function. This is especially likely on architectures with
113 single-byte instructions such as an x86. When examining gprof output
114 it may prove useful to look at a linker map or program disassembly.
115     </para></caution>
116     <para>
117 The eCos profiling package requires some additional support from the
118 HAL packages, and this may not be available on all platforms:
119     </para>
120     <orderedlist>
121       <listitem><para>
122 There must be an implementation of the profiling timer. Typically this
123 is provided by the variant or platform HAL using one of the hardware
124 timers. If there is no implementation then the configuration tools
125 will report an unresolved conflict related to
126 <varname>CYGINT_PROFILE_HAL_TIMER</varname> and profiling is not
127 possible. Some implementations overload the system clock, which means
128 that profiling is only possible in configurations containing the eCos
129 kernel and <varname>CYGVAR_KERNEL_COUNTERS_CLOCK</varname>.
130       </para></listitem>
131       <listitem><para>
132 There should be a hardware-specific implementation of
133 <function>mcount</function>, which in turn will call the generic
134 functionality provided by this package. It is still possible to do
135 some profiling without <function>mcount</function> but the resulting
136 data will be less useful. To check whether or not
137 <function>mcount</function> is available, look at the current value of
138 the CDL interface <varname>CYGINT_PROFILE_HAL_MCOUNT</varname> in the
139 graphical configuration tool or in an <filename>ecos.ecc</filename>
140 save file.
141       </para></listitem>
142     </orderedlist>
143     <para>
144 This document only describes the eCos profiling support. Full details
145 of gprof functionality and output formats can be found in the gprof
146 documentation. However it should be noted that that documentation
147 describes some functionality which cannot be implemented using current
148 versions of the gcc compiler: the section on annotated source listings
149 is not relevant, and neither are associated command line options like
150 <option>-A</option> and <option>-y</option>.
151     </para>
152   </refsect1>
153
154   <refsect1 id="gprof-process"><title>Building Applications for Profiling</title>
155     <para>
156 To perform application profiling the gprof package
157 <varname>CYGPKG_PROFILE_GPROF</varname> must first be added to the
158 eCos configuration. On the command line this can be achieved using:
159     </para>
160     <screen>
161 $ ecosconfig add profile_gprof
162 $ ecosconfig tree
163 $ make
164     </screen>
165     <para>
166 Alternatively the same steps can be performed using the graphical
167 configuration tool.
168     </para>
169     <para>
170 If the HAL packages implement <function>mcount</function> for the
171 target platform then usually application code should be compiled with
172 <option>-pg</option>. Optionally eCos itself can also be compiled with
173 this option by modifying the configuration option
174 <varname>CYGBLD_GLOBAL_CFLAGS</varname>. Compiling with
175 <option>-pg</option> is optional but gives more complete profiling
176 data.
177     </para>
178     <note><para>
179 The profiling package itself must not be compiled with
180 <option>-pg</option> because that could lead to infinite recursion
181 when doing <function>mcount</function> processing. This is handled
182 automatically by the package's CDL.
183     </para></note>
184     <para>
185 Profiling does not happen automatically. Instead it must be started
186 explicitly by the application, using a call to
187 <function>profile_on</function>. A typical example would be:
188     </para>
189     <programlisting>
190 #include &lt;pkgconf/system.h&gt;
191 #ifdef CYGPKG_PROFILE_GPROF
192 # include &lt;cyg/profile/profile.h&gt;
193 #endif
194 &hellip;
195 int
196 main(int argc, char** argv)
197 {
198     &hellip;
199 #ifdef CYGPKG_PROFILE_GPROF
200     {
201         extern char _stext[], _etext[];
202         profile_on(_stext, _etext, 16, 3500);
203     }
204 #endif
205     &hellip;
206 }
207     </programlisting>
208     <para>
209 The <function>profile_on</function> takes four arguments:
210     </para>
211     <variablelist>
212       <varlistentry>
213         <term><literal>start address</literal></term>
214         <term><literal>end address</literal></term>
215         <listitem><para>
216 These specify the range of addresses that will be profiled. Usually
217 profiling should cover the entire application. On most targets the
218 linker script will export symbols <varname>_stext</varname> and
219 <varname>_etext</varname> corresponding to the beginning and end of
220 code, so these can be used as the addresses. It is possible to
221 perform profiling on a subset of the code if that code is
222 located contiguously in memory.
223         </para></listitem>
224       </varlistentry>
225       <varlistentry>
226         <term><literal>bucket size</literal></term>
227         <listitem><para>
228 <function>profile_on</function> divides the range of addresses into a
229 number of buckets of this size. It then allocates a single array of
230 16-bit counters with one entry for each bucket. When the profiling
231 timer interrupts the interrupt handler will examine the program
232 counter of the interrupted code and, assuming it is within the range
233 of valid addresses, find the containing bucket and increment the
234 appropriate counter.
235         </para>
236         <para>
237 The size of the array counters is determined by the range of addresses
238 being profiled and by the bucket size. For a bucket size of 16, one
239 counter is needed for every 16 bytes of code. For an application with
240 say 512K of code that means dynamically allocating a 64K array. If the
241 target hardware is low on memory then this may be unacceptable, and
242 the requirements can be reduced by increasing the bucket size. However
243 this will affect the accuracy of the results and gprof is more likely
244 to report the wrong function. It also increases the risk of a counter
245 overflow.
246         </para>
247         <para>
248 For the sake of run-time efficiency the bucket size must be a power of
249 2, and it will be adjusted if necessary.
250         </para></listitem>
251       </varlistentry>
252       <varlistentry>
253         <term><literal>time interval</literal></term>
254         <listitem><para>
255 The final argument specifies the interval between profile timer
256 interrupts, in units of microseconds. Increasing the interrupt
257 frequency gives more accurate profiling results, but at the cost of
258 higher run-time overheads and a greater risk of a counter overflow.
259 The HAL package may modify this interval because of hardware
260 restrictions, and the generated profile data will contain the actual
261 interval that was used. Usually it is a good idea to use an interval
262 that is not a simple fraction of the system clock, typically 10000
263 microseconds. Otherwise there is a risk that the profiling timer will
264 disproportionally sample code that runs only in response to the system
265 clock.
266         </para></listitem>
267       </varlistentry>
268     </variablelist>
269     <para>
270 If the eCos configuration includes a TCP/IP stack and if a tftp daemon
271 will be used to <link linkend="gprof-extract">extract</link> the data
272 from the target then the call to <function>profile_on</function>
273 should happen after the network is up. <filename>profile_on</filename>
274 will attempt to start a tftp daemon thread, and this will fail if
275 networking has not yet been enabled.
276     </para>
277     <programlisting>
278 int
279 main(int argc, char** argv)
280 {
281     &hellip;
282     init_all_network_interfaces();
283     &hellip;
284 #ifdef CYGPKG_PROFILE_GPROF
285     {
286         extern char _stext[], _etext[];
287         profile_on(_stext, _etext, 16, 3000);
288     }
289 #endif
290     &hellip;
291 }
292     </programlisting>
293     <para>
294 The application can then be linked and run as usual.
295     </para>
296     <informalfigure PgWide=1>
297       <mediaobject>
298         <imageobject>
299           <imagedata fileref="gprofrun.png" Scalefit=1 Align="Center">
300         </imageobject>
301       </mediaobject>
302     </informalfigure>
303     <para>
304 When gprof is used for native development rather than for embedded
305 targets the profiling data will automatically be written out to a file
306 <filename>gmon.out</filename> when the program exits. This is not
307 possible on an embedded target because the code has no direct access
308 to the host's file system. Instead the <filename>gmon.out</filename>
309 file has to be <link linkend="gprof-extract">extracted</link> from
310 the target as described below. gprof can then be invoked normally:
311     </para>
312     <screen>
313 $ gprof dhrystone
314 Flat profile:
315  
316 Each sample counts as 0.003003 seconds.
317   %   cumulative   self              self     total
318  time   seconds   seconds    calls  us/call  us/call  name
319  14.15      1.45     1.45   120000    12.05    12.05  Proc_7
320  11.55      2.63     1.18   120000     9.84     9.84  Func_1
321   8.04      3.45     0.82                             main
322 &hellip;
323     </screen>
324     <para>
325 If <filename>gmon.out</filename> does not contain call graph data,
326 either because <function>mcount</function> is not supported or because
327 this functionality was explicitly disabled, then the
328 <option>-no-graph</option> must be used.
329     </para>
330     <screen>
331 $ gprof --no-graph dhrystone
332 Flat profile:
333  
334 Each sample counts as 0.003003 seconds.
335   %   cumulative   self              self     total
336  time   seconds   seconds    calls  us/call  us/call  name
337  14.15      1.45     1.45                             Proc_7
338  11.55      2.63     1.18                             Func_1
339   8.04      3.45     0.82                             main
340 &hellip;
341     </screen>
342   </refsect1>
343
344   <refsect1 id="gprof-extract"><title>Extracting the Data</title>
345     <para>
346 By default gprof expects to find the profiling data in a file
347 <function>gmon.out</function> in the current directory. This package
348 provides two ways of extracting data: a gdb macro or tftp transfers.
349 Using tftp is faster but requires a TCP/IP stack on the target. It
350 also consumes some additional target-side resources, including an
351 extra tftp daemon thread and its stack. The gdb macro can be used even
352 when the eCos configuration does not include a TCP/IP stack. However
353 it is much slower, typically taking tens of seconds to retrieve all
354 the data for a non-trivial application.
355     </para>
356     <para>
357 The gdb macro is called <command>gprof_dump</command>, and can be
358 found in the file <filename>gprof.gdb</filename> in the <filename
359 class="directory">host</filename> subdirectory of this package. A
360 typical way of using this macro is:
361     </para>
362     <screen>
363 (gdb) source &lt;repo&gt;/services/profile/gprof/&lt;version&gt;/host/gprof.gdb
364 (gdb) gprof_dump
365     </screen>
366     <para>
367 This macro can be used any time after the call to
368 <function>profile_on</function>. It will store the profiling data
369 accumulated so far to the file <filename>gmon.out</filename> in the
370 current directory, and then reset all counts. gprof uses only a 16 bit
371 counter for every bucket of code. These counters can easily saturate
372 if the profiling run goes on for a long time, or if the application
373 code spends nearly all its time in just a few tight inner loops. The
374 counters will not actually wrap around back to zero, instead they will
375 stick at 0xFFFF, but this will still affect the accuracy of the gprof
376 output. Hence it is desirable to reset the counters once the profiling
377 data has been extracted.
378     </para>
379     <para>
380 The file <filename>gprof.gdb</filename> contains two other macros
381 which may prove useful. <command>gprof_fetch</command> extracts the
382 profiling data and generates the file <filename>gmon.out</filename>,
383 but does not reset the counters. <command>gprof_reset</command> only
384 resets the counters, without extracting the data or overwriting
385 <filename>gmon.out</filename>.
386     </para>
387     <para>
388 If the configuration includes a TCP/IP stack then the profiling data
389 can be extracted using tftp instead. There are two relevant
390 configuration options. <varname>CYGPKG_PROFILE_TFTP</varname>
391 controls whether or not tftp is supported. It is enabled by default if
392 the configuration includes a TCP/IP stack, but can be disabled to save
393 target-side resources.
394 <varname>CYGNUM_PROFILE_TFTP_PORT</varname> controls the UDP
395 port which will be used. This port cannot be shared with other tftp
396 daemons. If neither application code nor any other package (for
397 example the gcov test coverage package) provides a tftp service then
398 the default port can be used. Otherwise it will be necessary to assign
399 unique ports to each daemon.
400     </para>
401     <para>
402 If enabled the tftp daemon will be started automatically by
403 <function>profile_on</function>. This should only happen once the
404 network is up and running, typically after the call to
405 <function>init_all_network_interfaces</function>.
406     </para>
407     <para>
408 The data can then be retrieved using a standard tftp client. There are
409 a number of such clients available with very different interfaces, but
410 a typical session might look something like this:
411     </para>
412     <screen>
413 $ tftp
414 tftp&gt; connect 10.1.1.134
415 tftp&gt; binary
416 tftp&gt; get gmon.out
417 Received 64712 bytes in 0.9 seconds
418 tftp&gt; quit
419     </screen>
420     <para>
421 The address <literal>10.1.1.134</literal> should be replaced with the
422 target's IP address. Extracting the profiling data by tftp will
423 automatically reset the counters.
424     </para>
425   </refsect1>
426
427   <refsect1 id="gprof-configuration"><title>Configuration Options</title>
428     <para>
429 This package contains a number of configuration options. Two of these,
430 <varname>CYGPKG_PROFILE_TFTP</varname> and
431 <varname>CYGNUM_PROFILE_TFTP_PORT</varname>, related to support for
432 <link linkend="gprof-extract">tftp transfers</link> and have already
433 been described.
434     </para>
435     <para>
436 Support for collecting the call graph data via
437 <function>mcount</function> is optional and can be controlled via
438 <varname>CYGPKG_PROFILE_CALLGRAPH</varname>. This option will only be
439 active if the HAL provides the underlying <function>mcount</function>
440 support and implements <varname>CYGINT_PROFILE_HAL_MCOUNT</varname>.
441 The call graph data allows gprof to produce more useful output, but at
442 the cost of extra run-time and memory overheads. If this option is
443 disabled then the <option>-pg</option> compiler flag should not be used.
444     </para>
445     <para>
446 If <varname>CYGPKG_PROFILE_CALLGRAPH</varname> is enabled then there
447 are two further options which can be used to control memory
448 requirements. Collecting the data requires two blocks of memory, a
449 simple hash table and an array of arc records. The
450 <function>mcount</function> code uses the program counter address to
451 index into the hash table, giving the first element of a singly linked
452 list. The array of arc records contains the various linked lists for
453 each hash slot. The required number of arc records depends on the
454 number of function calls in the application. For example if a function
455 <function>Proc_7</function> is called from three different places in
456 the application then three arc records will be needed.
457     </para>
458     <para>
459 <varname>CYGNUM_PROFILE_CALLGRAPH_HASH_SHIFT</varname> controls the
460 size of the hash table. The default value of 8 means that the program
461 counter is shifted right by eight places to give a hash table index.
462 Hence each hash table slot corresponds to 256 bytes of code, and for
463 an application with say 512K of code <filename>profile_on</filename>
464 will dynamically allocate an 8K hash table. Increasing the shift size
465 reduces the memory requirement, but means that each hash table slot
466 will correspond to more code and hence <function>mcount</function>
467 will need to traverse a longer linked list of arc records.
468     </para>
469     <para>
470 <varname>CYGNUM_PROFILE_CALLGRAPH_ARC_PERCENTAGE</varname> controls
471 how much memory <function>profile_on</function> will allocate for the
472 arc records. This uses a simple heuristic, a percentage of the overall
473 code size. By default the amount of arc record space allocated will be
474 5% of the code size, so for a 512K executable that requires
475 approximately 26K. This default should suffice for most applications.
476 In exceptional cases it may be insufficient and a diagnostic will be
477 generated when the profiling data is extracted.
478     </para>
479   </refsect1>
480
481   <refsect1 id="gprof-hal"><title>Implementing the HAL Support</title>
482     <para>
483 The profiling package requires HAL support: A function
484 <function>hal_enable_profile_timer</function> and an implementation
485 of <function>mcount</function>. The profile timer is required.
486 Typically it will be implemented by the variant or platform HAL
487 using a spare hardware timer, and that HAL package will also
488 implement the CDL interface
489 <varname>CYGINT_PROFILE_HAL_TIMER</varname>. Support for
490 <function>mcount</function> is optional but very desirable. Typically
491 it will be implemented by the architectural HAL, which will also
492 implement the CDL interface
493 <varname>CYGINT_PROFILE_HAL_MCOUNT</varname>. 
494     </para>
495     <programlisting>
496 #include &lt;pkgconf/system.h&gt;
497 #ifdef CYGPKG_PROFILE_GPROF
498 # include &lt;cyg/profile/profile.h&gt;
499 #endif
500
501 int
502 hal_enable_profile_timer(int resolution)
503 {
504     &hellip;
505     return actual_resolution;
506 }
507     </programlisting>
508     <para>
509 This function takes a single argument, a time interval in
510 microseconds. It should arrange for a timer interrupt to go off
511 after every interval. The timer VSR or ISR should then determine the
512 program counter of the interrupted code and register this with the
513 profiling package:
514     </para>
515     <programlisting>
516     &hellip;
517     __profile_hit(interrupted_pc);
518     &hellip;
519     </programlisting>
520     <para>
521 The exact details of how this is achieved, especially obtaining the
522 interrupted PC, are left to the HAL implementor. The HAL is allowed to
523 modify the requested time interval because of hardware constraints,
524 and should return the interval that is actually used.
525     </para>
526     <para>
527 <function>mcount</function> can be more difficult. The calls to
528 <function>mcount</function> are generated internally by the compiler
529 and the details depend on the target architecture. In fact
530 <function>mcount</function> may not use the standard calling
531 conventions at all. Typically implementing <function>mcount</function>
532 requires looking at the code that is actually generated, and possibly
533 at the sources of the appropriate compiler back end.
534     </para>
535     <para>
536 The HAL <function>mcount</function> function should call into the
537 profiling package using standard calling conventions:
538     </para>
539     <programlisting>
540     &hellip;
541     __profile_mcount((CYG_ADDRWORD) caller_pc, (CYG_ADDRWORD) callee_pc);
542     &hellip;
543     </programlisting>
544     <para>
545 If <function>mcount</function> was invoked because
546 <function>main</function> called <function>Proc_1</function> then the
547 caller pc should be an address inside <function>main</function>,
548 typically corresponding to the return location, and the callee pc
549 should be an address inside <function>Proc_1</function>, usually near
550 the start of the function.
551     </para>
552     <para>
553 For some targets the compiler does additional work, for example
554 automatically allocating a per-function word of memory to eliminate
555 the need for the hash table. This is too target-specific and hence
556 cannot easily be used by the generic profiling package.
557     </para>
558   </refsect1>
559
560 </refentry>
561 </part>