1HATARI_PROFILE(1) Hatari utilities HATARI_PROFILE(1)
2
6 hatari_profile - Post-processor for Hatari profiler data
7
9 hatari_profile.py [options] <datafiles>
10
12 A Python script to post-process data produced by Hatari profiler "save"
13 commands, both for CPU and DSP:
14 profile save <filename>
15 dspprofile save <filename>
16 It can provide function level (CPU and DSP) processor usage information
18 for anything Hatari profiler records: instruction counts, processor cy‐
19 cles and depending on processor, also instruction cache misses or cycle
20 differences.
21 This information can be provided as ASCII list of heaviest functions,
23 as callgraphs (if profile data includes caller information), or as
24 callgrind format export which can be viewed in (Linux) Kcachegrind GUI.
25
27 Invoking hatari_profile without arguments lists all of its options.
28
30 Regardless of whether profile data contains some symbol information,
31 you should always give script all relevant debug symbols, otherwise
32 costs might not get correctly assigned to symbols preceding those
33 costs.
34 This post-processes profile data for EmuTOS (ROM), with symbol file
36 having fixed/absolute addresses (-a), shows statistics (-s) and top
37 lists (-t), but limits list output to anything taking over 2% (-l 2)
38 and includes "propagated" subroutine call costs (-p):
39 -------------------------------------------------------------
40 $ hatari_profile.py -a etos1024k.sym -st -l 2 -p etos-boot.txt
41 Hatari profile data processor
43 Parsing absolute symbol address information from etos1024k.sym...
45 WARNING: replacing '_os_header' at 0xe00000 with '__text'
46 WARNING: replacing '_instruction_cache_kludge' at 0xe00660 with '_invalidate_instruction_cache'
47 1806 lines with 1187 code symbols/addresses parsed, 0 unknown.
48 Parsing profile information from etos-boot.txt...
50 18900 lines processed with 531 functions.
51 Of all 38474 switches, ignored 3731 for type(s) ['r', 'u', 'x'].
52 CPU profile information from 'etos-boot.txt':
54 - Hatari v2.3.1, WinUAE CPU core
55 Time spent in profile = 6.72122s.
57 Visits/calls:
59 - max = 1768, in _memcpy at 0xe46ea0, on line 7944
60 - 40800 in total
61 Executed instructions:
62 - max = 140992, in _timeout_gpip+22 at 0xe0b484, on line 4393
63 - 2566629 in total
64 Used cycles:
65 - max = 23997200, in _stop_until_interrupt+38 at 0xe4724a, on line 8213
66 - 53912568 in total
67 Visits/calls:
69 4.33% 4.38% 1768 1786 _memcpy
70 3.55% 0.40% 1450 165 _gsx2
71 3.55% 24.78% 1449 10112 _GSX_ENTRY
72 3.55% 3.58% 1449 1459 _get_vwk_by_handle
73 3.55% 21.17% 1449 8636 _screen
74 3.45% 27.77% 1407 11329 gemgsxif.o
75 2.98% 3.00% 1214 1222 _bconstat2
76 2.95% 2.95% 1203 1203 _kbshift
77 2.78% 2.79% 1134 1137 _bcostat4
78 2.51% 1024 vdi_blit.o
79 2.35% 3.25% 959 1327 _cputc
80 2.35% 5.60% 957 2283 _bconout2
81 2.29% 936 _just_rte
82 2.27% 927 kprint.o
83 2.23% 7.48% 911 3052 _biostrap
84 2.10% 2.10% 858 858 gemdosif.o
85 2.10% 2.12% 858 867 _enable_interrupts
86 Executed instructions:
88 32.96% 33.10% 33.19% 846043 849564 851784 _timeout_gpip
89 10.61% 10.66% 10.72% 272360 273633 275161 _blank_out
90 8.74% 8.81% 8.88% 224230 226006 227862 _draw_rect_common
91 5.94% 5.96% 5.96% 152525 152895 153039 _run_calibration
92 5.63% 144385 _ascii_out
93 3.52% 3.55% 22.77% 90398 91014 584547 _screen
94 2.62% 67293 ikbd.o
95 Used cycles:
97 44.62% 44.62% 45.46% 24057296 24057392 24509580 _stop_until_interrupt
98 18.87% 19.01% 19.06% 10171140 10248940 10277724 _timeout_gpip
99 4.77% 4.82% 4.85% 2571980 2597744 2616824 _blank_out
100 3.83% 3.89% 3.93% 2065076 2096668 2121104 _draw_rect_common
101 2.82% 1521072 _ascii_out
102 2.58% 2.60% 2.60% 1391076 1400236 1402000 _run_calibration
103 2.19% 2.21% 11.51% 1181264 1193784 6203852 _screen
104 -------------------------------------------------------------
105 This creates GraphViz callgraph files (-g) and Kcachegrind callgrind
107 data file (-k) from Bad Mood (Doom BSP viewer) profile. Symbols for
108 the program are TEXT section relative (-r), calls to some interrupt
109 routines in the program are ignored as they aren't real calls, call‐
110 graph nodes using over 2% are highlighted, and there are some options
111 to limit and simplify the graph:
112 -------------------------------------------------------------
113 $ hatari_profile.py -r bmsym.sym \
114 -k -g -p --emph-limit 2.0 --limit 0.5 \
115 --ignore-to framecounter,new_vbi,stabilizer_b \
116 --compact --no-leafs --no-intermediate \
117 badmood-profile.txt
118 Hatari profile data processor
120 Parsing TEXT relative symbol address information from bmsym.sym...
122 1023 lines with 392 code symbols/addresses parsed, 0 unknown.
123 Parsing profile information from badmood-profile.txt...
125 1420 lines processed with 63 functions.
126 Ignoring 29 switches to framecounter
127 Ignoring 9 switches to stabilizer_b
128 Ignoring 8 switches to new_vbi
129 Of all 1562 switches, ignored 56 for type(s) ['r', 'u', 'x'].
130 Generating callgrind file 'badmood-profile.cg'...
132 Generating 'badmood-profile-0.dot' DOT callgraph file...
134 Generating 'badmood-profile-1.dot' DOT callgraph file...
136 Generating 'badmood-profile-2.dot' DOT callgraph file...
138 Generating 'badmood-profile-3.dot' DOT callgraph file...
140 CPU profile information from 'badmood-profile.txt':
142 - Hatari v1.6.2+ (Apr 10 2013), WinUAE CPU core
143 -------------------------------------------------------------
144
146 hatari(1), gst2ascii(1), hconsole(1) hatariui(1)
147
149 Written by Eero Tamminen <oak at helsinkinet fi>.
150
152 This program is free software; you can redistribute it and/or modify it
153 under the terms of the GNU General Public License as published by the
154 Free Software Foundation; either version 2 of the License, or (at your
155 option) any later version.
156
158 This program is distributed in the hope that it will be useful, but
159 WITHOUT ANY WARRANTY; without even the implied warranty of MER‐
160 CHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU General
161 Public License for more details.
162Hatari 2013-04-15 HATARI_PROFILE(1)