]> git.kernelconcepts.de Git - karo-tx-redboot.git/blob - packages/services/profile/gprof/v2_0/doc/profile.sgml
unified MX27, MX25, MX37 trees
[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 <function>profile_on</function> can be invoked multiple times, and
271 on subsequent invocations, it will delete profiling data
272 and allocate a fresh profiling range.
273     </para>
274     <para>
275 Profiling can be turned off using the function
276 <function>profile_off</function>:
277 <programlisting>
278 void profile_off(void);
279 </programlisting>
280 This will also reset any existing profile data.
281     </para>
282     <para>
283 If the eCos configuration includes a TCP/IP stack and if a tftp daemon
284 will be used to <link linkend="gprof-extract">extract</link> the data
285 from the target then the call to <function>profile_on</function>
286 should happen after the network is up. <filename>profile_on</filename>
287 will attempt to start a tftp daemon thread, and this will fail if
288 networking has not yet been enabled.
289     </para>
290     <programlisting>
291 int
292 main(int argc, char** argv)
293 {
294     &hellip;
295     init_all_network_interfaces();
296     &hellip;
297 #ifdef CYGPKG_PROFILE_GPROF
298     {
299         extern char _stext[], _etext[];
300         profile_on(_stext, _etext, 16, 3000);
301     }
302 #endif
303     &hellip;
304 }
305     </programlisting>
306     <para>
307 The application can then be linked and run as usual.
308     </para>
309     <informalfigure PgWide=1>
310       <mediaobject>
311         <imageobject>
312           <imagedata fileref="gprofrun.png" Scalefit=1 Align="Center">
313         </imageobject>
314       </mediaobject>
315     </informalfigure>
316     <para>
317 When gprof is used for native development rather than for embedded
318 targets the profiling data will automatically be written out to a file
319 <filename>gmon.out</filename> when the program exits. This is not
320 possible on an embedded target because the code has no direct access
321 to the host's file system. Instead the <filename>gmon.out</filename>
322 file has to be <link linkend="gprof-extract">extracted</link> from
323 the target as described below. gprof can then be invoked normally:
324     </para>
325     <screen>
326 $ gprof dhrystone
327 Flat profile:
328  
329 Each sample counts as 0.003003 seconds.
330   %   cumulative   self              self     total
331  time   seconds   seconds    calls  us/call  us/call  name
332  14.15      1.45     1.45   120000    12.05    12.05  Proc_7
333  11.55      2.63     1.18   120000     9.84     9.84  Func_1
334   8.04      3.45     0.82                             main
335 &hellip;
336     </screen>
337     <para>
338 If <filename>gmon.out</filename> does not contain call graph data,
339 either because <function>mcount</function> is not supported or because
340 this functionality was explicitly disabled, then the
341 <option>-no-graph</option> must be used.
342     </para>
343     <screen>
344 $ gprof --no-graph dhrystone
345 Flat profile:
346  
347 Each sample counts as 0.003003 seconds.
348   %   cumulative   self              self     total
349  time   seconds   seconds    calls  us/call  us/call  name
350  14.15      1.45     1.45                             Proc_7
351  11.55      2.63     1.18                             Func_1
352   8.04      3.45     0.82                             main
353 &hellip;
354     </screen>
355   </refsect1>
356
357   <refsect1 id="gprof-extract"><title>Extracting the Data</title>
358     <para>
359 By default gprof expects to find the profiling data in a file
360 <function>gmon.out</function> in the current directory. This package
361 provides two ways of extracting data: a gdb macro or tftp transfers.
362 Using tftp is faster but requires a TCP/IP stack on the target. It
363 also consumes some additional target-side resources, including an
364 extra tftp daemon thread and its stack. The gdb macro can be used even
365 when the eCos configuration does not include a TCP/IP stack. However
366 it is much slower, typically taking tens of seconds to retrieve all
367 the data for a non-trivial application.
368     </para>
369     <para>
370 The gdb macro is called <command>gprof_dump</command>, and can be
371 found in the file <filename>gprof.gdb</filename> in the <filename
372 class="directory">host</filename> subdirectory of this package. A
373 typical way of using this macro is:
374     </para>
375     <screen>
376 (gdb) source &lt;repo&gt;/services/profile/gprof/&lt;version&gt;/host/gprof.gdb
377 (gdb) gprof_dump
378     </screen>
379     <para>
380 This macro can be used any time after the call to
381 <function>profile_on</function>. It will store the profiling data
382 accumulated so far to the file <filename>gmon.out</filename> in the
383 current directory, and then reset all counts. gprof uses only a 16 bit
384 counter for every bucket of code. These counters can easily saturate
385 if the profiling run goes on for a long time, or if the application
386 code spends nearly all its time in just a few tight inner loops. The
387 counters will not actually wrap around back to zero, instead they will
388 stick at 0xFFFF, but this will still affect the accuracy of the gprof
389 output. Hence it is desirable to reset the counters once the profiling
390 data has been extracted.
391     </para>
392     <para>
393 The file <filename>gprof.gdb</filename> contains two other macros
394 which may prove useful. <command>gprof_fetch</command> extracts the
395 profiling data and generates the file <filename>gmon.out</filename>,
396 but does not reset the counters. <command>gprof_reset</command> only
397 resets the counters, without extracting the data or overwriting
398 <filename>gmon.out</filename>.
399     </para>
400     <para>
401 If the configuration includes a TCP/IP stack then the profiling data
402 can be extracted using tftp instead. There are two relevant
403 configuration options. <varname>CYGPKG_PROFILE_TFTP</varname>
404 controls whether or not tftp is supported. It is enabled by default if
405 the configuration includes a TCP/IP stack, but can be disabled to save
406 target-side resources.
407 <varname>CYGNUM_PROFILE_TFTP_PORT</varname> controls the UDP
408 port which will be used. This port cannot be shared with other tftp
409 daemons. If neither application code nor any other package (for
410 example the gcov test coverage package) provides a tftp service then
411 the default port can be used. Otherwise it will be necessary to assign
412 unique ports to each daemon.
413     </para>
414     <para>
415 If enabled the tftp daemon will be started automatically by
416 <function>profile_on</function>. This should only happen once the
417 network is up and running, typically after the call to
418 <function>init_all_network_interfaces</function>.
419     </para>
420     <para>
421 The data can then be retrieved using a standard tftp client. There are
422 a number of such clients available with very different interfaces, but
423 a typical session might look something like this:
424     </para>
425     <screen>
426 $ tftp
427 tftp&gt; connect 10.1.1.134
428 tftp&gt; binary
429 tftp&gt; get gmon.out
430 Received 64712 bytes in 0.9 seconds
431 tftp&gt; quit
432     </screen>
433     <para>
434 The address <literal>10.1.1.134</literal> should be replaced with the
435 target's IP address. Extracting the profiling data by tftp will
436 automatically reset the counters.
437     </para>
438   </refsect1>
439
440   <refsect1 id="gprof-configuration"><title>Configuration Options</title>
441     <para>
442 This package contains a number of configuration options. Two of these,
443 <varname>CYGPKG_PROFILE_TFTP</varname> and
444 <varname>CYGNUM_PROFILE_TFTP_PORT</varname>, related to support for
445 <link linkend="gprof-extract">tftp transfers</link> and have already
446 been described.
447     </para>
448     <para>
449 Support for collecting the call graph data via
450 <function>mcount</function> is optional and can be controlled via
451 <varname>CYGPKG_PROFILE_CALLGRAPH</varname>. This option will only be
452 active if the HAL provides the underlying <function>mcount</function>
453 support and implements <varname>CYGINT_PROFILE_HAL_MCOUNT</varname>.
454 The call graph data allows gprof to produce more useful output, but at
455 the cost of extra run-time and memory overheads. If this option is
456 disabled then the <option>-pg</option> compiler flag should not be used.
457     </para>
458     <para>
459 If <varname>CYGPKG_PROFILE_CALLGRAPH</varname> is enabled then there
460 are two further options which can be used to control memory
461 requirements. Collecting the data requires two blocks of memory, a
462 simple hash table and an array of arc records. The
463 <function>mcount</function> code uses the program counter address to
464 index into the hash table, giving the first element of a singly linked
465 list. The array of arc records contains the various linked lists for
466 each hash slot. The required number of arc records depends on the
467 number of function calls in the application. For example if a function
468 <function>Proc_7</function> is called from three different places in
469 the application then three arc records will be needed.
470     </para>
471     <para>
472 <varname>CYGNUM_PROFILE_CALLGRAPH_HASH_SHIFT</varname> controls the
473 size of the hash table. The default value of 8 means that the program
474 counter is shifted right by eight places to give a hash table index.
475 Hence each hash table slot corresponds to 256 bytes of code, and for
476 an application with say 512K of code <filename>profile_on</filename>
477 will dynamically allocate an 8K hash table. Increasing the shift size
478 reduces the memory requirement, but means that each hash table slot
479 will correspond to more code and hence <function>mcount</function>
480 will need to traverse a longer linked list of arc records.
481     </para>
482     <para>
483 <varname>CYGNUM_PROFILE_CALLGRAPH_ARC_PERCENTAGE</varname> controls
484 how much memory <function>profile_on</function> will allocate for the
485 arc records. This uses a simple heuristic, a percentage of the overall
486 code size. By default the amount of arc record space allocated will be
487 5% of the code size, so for a 512K executable that requires
488 approximately 26K. This default should suffice for most applications.
489 In exceptional cases it may be insufficient and a diagnostic will be
490 generated when the profiling data is extracted.
491     </para>
492   </refsect1>
493
494   <refsect1 id="gprof-hal"><title>Implementing the HAL Support</title>
495     <para>
496 The profiling package requires HAL support: A function
497 <function>hal_enable_profile_timer</function> and an implementation
498 of <function>mcount</function>. The profile timer is required.
499 Typically it will be implemented by the variant or platform HAL
500 using a spare hardware timer, and that HAL package will also
501 implement the CDL interface
502 <varname>CYGINT_PROFILE_HAL_TIMER</varname>. Support for
503 <function>mcount</function> is optional but very desirable. Typically
504 it will be implemented by the architectural HAL, which will also
505 implement the CDL interface
506 <varname>CYGINT_PROFILE_HAL_MCOUNT</varname>. 
507     </para>
508     <programlisting>
509 #include &lt;pkgconf/system.h&gt;
510 #ifdef CYGPKG_PROFILE_GPROF
511 # include &lt;cyg/profile/profile.h&gt;
512 #endif
513
514 int
515 hal_enable_profile_timer(int resolution)
516 {
517     &hellip;
518     return actual_resolution;
519 }
520     </programlisting>
521     <para>
522 This function takes a single argument, a time interval in
523 microseconds. It should arrange for a timer interrupt to go off
524 after every interval. The timer VSR or ISR should then determine the
525 program counter of the interrupted code and register this with the
526 profiling package:
527     </para>
528     <programlisting>
529     &hellip;
530     __profile_hit(interrupted_pc);
531     &hellip;
532     </programlisting>
533     <para>
534 The exact details of how this is achieved, especially obtaining the
535 interrupted PC, are left to the HAL implementor. The HAL is allowed to
536 modify the requested time interval because of hardware constraints,
537 and should return the interval that is actually used.
538     </para>
539     <para>
540 <function>mcount</function> can be more difficult. The calls to
541 <function>mcount</function> are generated internally by the compiler
542 and the details depend on the target architecture. In fact
543 <function>mcount</function> may not use the standard calling
544 conventions at all. Typically implementing <function>mcount</function>
545 requires looking at the code that is actually generated, and possibly
546 at the sources of the appropriate compiler back end.
547     </para>
548     <para>
549 The HAL <function>mcount</function> function should call into the
550 profiling package using standard calling conventions:
551     </para>
552     <programlisting>
553     &hellip;
554     __profile_mcount((CYG_ADDRWORD) caller_pc, (CYG_ADDRWORD) callee_pc);
555     &hellip;
556     </programlisting>
557     <para>
558 If <function>mcount</function> was invoked because
559 <function>main</function> called <function>Proc_1</function> then the
560 caller pc should be an address inside <function>main</function>,
561 typically corresponding to the return location, and the callee pc
562 should be an address inside <function>Proc_1</function>, usually near
563 the start of the function.
564     </para>
565     <para>
566 For some targets the compiler does additional work, for example
567 automatically allocating a per-function word of memory to eliminate
568 the need for the hash table. This is too target-specific and hence
569 cannot easily be used by the generic profiling package.
570     </para>
571   </refsect1>
572
573 </refentry>
574 </part>