Profiling: what changed

Revision 1 to 2. Removed lines have a minus sign; added lines have a plus sign.

Old	New		Line
1	1		Profiling is a performance analysis technique that can be used to find bottlenecks in your application. In particular it encompasses measuring the frequency and duration of function calls.
2	2
3	3		## Profiling and optimization
4	4
5	5		Profiling can help to identify “critical” parts of your code, whose optimization could seriously improve the performance of your program. It is done best at times when you are preparing for a release and having a feature-freeze for your code. It is a waste of time and resources to optimize something that will be thrown away the next day during some code restructuring.
6	6
7	7		Be careful not to over-optimize your program. It is seldom worth it to spent days on getting only a 2% performance gain. It is mostly cutting down run-time with 30% in just half an hour of coding a few optimizations that will pay off.
8	8
9	9		Of course optimizing code that is reused very often is worth a little more effort for performance gain.
10	10
11	11		## Free Pascal profiler support
12	12
13	13		Free Pascal has built-in support for generating executables suitable for (at least) two profilers:
14	14
15	15		- gprof, the Gnu Profiler: enable with `-pg`.
16	16		- Availability: Most FPC target platforms
17	17		- Notes:
18	18		- Support for using gprof under Linux is broken in FPC 2.2.0-2.4.0; it is fixed in FPC 2.6+
19	19		- Under Windows, additional libraries are required to get gprof support working;
20	20		- Valgrind, using the plug-in Callgrind: enable with `-gv`.
21	21		- Availablility: Linux, Mac OS X 10.5 (10.6 in Valgrind development versions), and some other UNIXes.
22	22		- Notes
23	23		- Should work fine on all platforms supported by Valgrind, as it does not require any compiler support (other than that the profiled program should be dynamically linked, and that the compiler should not generate certain kinds of debug information -- both issues are taken care of by the `-gv` option)
24	24		- The `-gv` option implicitly includes the [[CMem]] unit; thus you need to remove it from your uses clause
25	25
26	26		There's also an FPC native profiler project called [[FPProfiler]]. Because the profiler is native to FPC it should work on all platforms that FPC supports.
27	27
28	28		A Lazarus IDE addon which enables you to profile your project with one click is also available: [[LazProfiler]]
29	29
30	30		## Using Valgrind/Callgrind
31	31
32	32		Valgrind was originally only a memory debugger, but now it also supports e.g. profiling using the Callgrind plug-in (which has replaced the Calltree plugin). To install Valgrind with Callgrind on Debian, run e.g.
33	33
34	34		` aptitude install valgrind valgrind-callgrind`
35	35
36	36		To profile your program, you need to do three steps:
37	37
38	38		- Compile your program with the `-gv` switch.
39	39		- Run your program using `valgrind`
40	40		- Analyze the output with `valgrind_annotate` or the GUI tool `KCacheGrind`
41	41
42	42		Compile your program with
43	43
44	44		` fpc -gv myprogram.pas`
45	45
46	46		Run Valgrind using e.g.
47	47
48	48		` valgrind --tool=callgrind ./myprogram --options --to --my --program`
49	49
50	50		You can also profile only specific parts of your program. For example you can start the program with
51	51
52	52		` valgrind --tool=callgrind --instr-atstart=no ./myprogram --options --to --my --program`
53	53
54	54		At the moment you want actual profiling to start, run
55	55
56	56		` callgrind_control -i on`
57	57
58	58		To stop the profiling, run the same command with `off` instead of `on`. To get only profiling information when you are inside a particular function, you can pass the `--toggle-collect=funcNamePrefix` option to valgrind. Refer to the Valgrind documentation for further details.
59	59
60	60		Callgrind has created a trace file with a typical name like `callgrind.out.12345`. To get a human-readable statistical report, run e.g.
61	61
62	62		` callgrind_annotate callgrind.out.12345`
63	63
64	64		Of course you can also experiment with the other tool plug-ins that ship with Valgrind. Cachegrind, for example, profiles the cache use. Other plug-ins can be used to profile or debug memory allocation or detect data race conditions.
65	65
66	66		## Using KCacheGrind
67	67
68	68		Though the output of `callgrind_annotate` can definitely shed some light on the performance characteristics of your program, the GUI tool KCacheGrind can give you even more interesting information, presented in different forms: caller/callee lists, caller/callee maps ans call graphs. To install it on Debian, run
69	69
70	70		` aptitude install kcachegrind graphviz`
71	71
72	72		(The `graphviz` package is required if you want KCacheGrind to generate call graphs.)
73	73
74		-	~~<figure>~~
75	74		<img src="KCacheGrind_Lazarus_Screenshot.png" title="Example of KCacheGrind showing profiling information for Lazarus (Click to enlarge)" width="500" />
76		-	~~<figcaption>Example of KCacheGrind showing profiling information for Lazarus (Click to enlarge)</figcaption>~~
77		-	~~</figure>~~
78	75
79	76		Run KCachegrind with a simple call to `kcachegrind`. You can now open a trace file using the GUI and all should be self-explanatory.
80	77
81	78		On the left, you will see a 'flat profile', which list for each function (in the top 100)
82	79
83	80		- Incl: amount of time spent in the function, including callees (functions called by the function).
84	81		- Self: amount of time spent within the function itself, excluding callees.
85	82		- Called: the number of the times the function has been called.
86	83
87	84		Note: if you click on one of the column headers to sort the list, you might need to do a reload (F5) to ensure that the top 100 with respect to that column will be shown. Another hint: in the configuration options, you can make the list longer than only the top 100.
88	85
89	86		> Note: "Time" in valgrind/callgrind is based on instructions/cycles executed. It is not exact. A CPU executing a function in real life (outside the profiler) may sometimes spent less time for more cycles.
90	87
91	88		On the right, you'll see a number of tabs, allowing you to see lists and maps of callers and callees, as well as a caller graph, which is very useful to see in a glance who calls whom the most.
92	89
93	90		## Memory Profiling
94	91
95	92		### Heaptrc, LineInfo
96	93
97	94		To spot memory leaks, simply compile with -gh. This will compile as if you added the heaptrc unit as first unit to the uses section of your program. Heaptrc links into the memory manager of fpc and checks various things. Together with the -gl option (adding the lineinfo unit) it will give you useful information and backtraces, where a memory block was allocated. It supports some options that can be controlled via environment option HEAPTRC containing keywords:
98	95
99	96		- keepreleased: Any freed memory, is kept and checked if overwritten.
100	97		- disabled: disable tracing. This is useful for program compiled with heaptrc and should work normally.
101	98		- nohalt: normally heaptrc stops on the first error it finds. Add this keyword if the program should continue (as it would normally do without heaptrc).
102	99		- haltonnotreleased: Normally heaptrc prints for every not freed block a backtrace, which can take a long time. Add this keyword to stop after first reported mem leak.
103	100		- log=\<filename\>: Instead of writing to stdout, you can give a log filename.
104	101
105	102		Note: heaptrc will conflict with cmem if you have to debug external libraries. Valgrind should be used in this case.
106	103
107	104		### Valgrind Memcheck
108	105
109	106		There are mem leaks which heaptrc does not find. The valgrind program has a tool called memcheck, which does a lot more bookkeeping than heaptrc and finds some more bugs. The drawback is that valgrind is snail slow, so do this only if heaptrc could not help you. Here is an example:
110	107
111	108		` valgrind --tool=memcheck --leak-check=summary --log-file=log.txt ./project1`
112	109
113	110		The log.txt will almost always find something, because it tries to check the used external libraries too and some common libraries are badly coded.
114	111
115	112		To get even more information run with
116	113
117	114		` valgrind --tool=memcheck --leak-check=full --log-file=log.txt --show-reachable=yes --num-callers=50 ./project1`
118	115
119	116		How to run massif:
120	117
121	118		`valgrind --tool=massif --run-libc-freeres=no ./project1`
122	119
123	120		## On macOS
124	121
125	122		Most of what is said above for Linux also applies on macOS. gprof is however not supported by FPC on Darwin/i386 and on Darwin/ARM at this time.
126	123
127	124		### Instruments
128	125
129	126		Instruments is a powerful performance analysis and testing tool that's part of Xcode toolset. Instruments can help you profile your apps on all platforms - iOS, macOS, watchOS, tvOS - in order to better understand and optimize their behavior and performance.
130	127
131	128		From Xcode's product menu, choose Profile. Although Instruments is embedded within and is often used with Xcode, Instruments is a separate app which may be used independently as needed. For example:
132	129
133	130		`open -a /Applications/Xcode.app/Contents/Applications/Instruments.app`
134	131
135	132		Apple documentation links:
136	133
137	134		- [Instruments Help](https://help.apple.com/instruments/mac/current/).
138	135		- [Getting Started with Instruments](https://developer.apple.com/videos/play/wwdc2019/411/) - WWDC 2019 Video
139	136		- [Creating Custom Instruments](https://developer.apple.com/videos/play/wwdc2018/410/) - WWDC 2018 Video
140	137
141	138		### Shark
142	139
143	140		> Note: Since macOS Lion 10.7, Shark is not on the Apple site any more and was replaced by Instruments above.
144	141
145	142		Shark is a sampling-based profiler. It supports time profiles, profiles based on performance counters (such as L2 cache misses), application-specific profiles and whole-system profiles. By default, it's installed at /Developer/Applications/Performance Tools/Shark.app
146	143
147	144		If you compile the profiled code with debug information (either Stabs or DWARF), Shark will display the (Pascal) source code in addition to the assembler code.
148	145
149	146		Shark only works for i386 and PowerPC. For 64 bit platforms, you have to use Instruments.app instead, which offers similar functionality.
150	147
151	148		### spindump
152	149
153	150		The macOS `spindump` utility can be used with the `-timeline` option to sample and profile your application in order to determine which QoS class applies as a specific portion of code executes at a given time. For more details, see the manual page by opening an Applications \> Utilities \> Terminal and typing `man spindump`.
154	151
155	152		### Valgrind
156	153
157	154		Valgrind has been ported to AMD64/macOS 10.12 (Sierra). There is also preliminary support for X86/macOS 10.13, AMD64/macOS 10.13 (High Sierra). For current details, check valgrind's [homepage](http://valgrind.org/).
158	155
159	156		If you experience the following issue:
160	157
161	158		` valgrind: ./test: cannot execute binary file`
162	159
163	160		Chances are that your valgrind only supports 64 bit while your FPC program is compiled for 32 bit. To make your application compatible simply add the switch -Px86_64.
164	161
165	162		### FPProfiler
166	163
167	164		FPProfiler has been ported to macOS as a fink package. For details see here: [[FPProfiler]]
168	165
169	166		## Simple profiling using ifdefs and timing routines
170	167
171	168		Another, simpler, way of profiling is simply adding ifdefs and time counting. For counting the time the simples way is just using Now() from SysUtils. Other possibilities are NowUTC() from lazutf8sysutils or [[EpikTimer]].
172	169
173	170		For example, to profile the following procedure:
174	171
175	172		``` pascal
176	173		procedure TMyClass.DoSomething;
177	174		begin
178	175		ReallyDoSomething;
179	176		end;
180	177		```
181	178
182	179		One would add the following extra code around it:
183	180
184	181		``` pascal
185	182		function DateTimeToMilliseconds(aDateTime: TDateTime): Int64;
186	183		var
187	184		TimeStamp: TTimeStamp;
188	185		begin
189	186		{Call DateTimeToTimeStamp to convert DateTime to TimeStamp:}
190	187		TimeStamp:= DateTimeToTimeStamp (aDateTime);
191	188		{Multiply and add to complete the conversion:}
192	189		Result:= TimeStamp.Time;
193	190		end;
194	191
195	192		procedure TMyClass.DoSomething;
196	193		var
197	194		{$IFDEF VerboseProfiler}
198	195		lTimeStart: TDateTime;
199	196		{$ENDIF}
200	197		...
201	198		begin
202	199		{$IFDEF VerboseProfiler}
203	200		lTimeStart := Now();
204	201		{$ENDIF}
205	202
206	203		ReallyDoSomething;
207	204
208	205		{$IFDEF VerboseProfiler}
209	206		DebugLn(Format('[TMyClass.DoSomething] Duration: %d ms', [DateTimeToMilliseconds(Now() - lTimeStart)]));
210	207		{$ENDIF}
211	208		end;
212	209		```
213	210
214	211		Activate the define to get the debug info in the [[DebugLn]] target.
215	212
216	213		---
217	214		From the Free Pascal wiki, page "Profiling", as it stood on 2021-11-07 after a change by Trev, out of the wiki's dump of 2024-05-26. Copyright stays with the author who wrote it, according to the old wiki's [[Licensing]] page. If you have concerns about this material, [message the admin](/wiki-contact).

Back to history