Show More
@@ -1,358 +1,361 | |||
|
1 | 1 | # profiling.py - profiling functions |
|
2 | 2 | # |
|
3 | 3 | # Copyright 2016 Gregory Szorc <gregory.szorc@gmail.com> |
|
4 | 4 | # |
|
5 | 5 | # This software may be used and distributed according to the terms of the |
|
6 | 6 | # GNU General Public License version 2 or any later version. |
|
7 | 7 | |
|
8 | 8 | from __future__ import annotations |
|
9 | 9 | |
|
10 | 10 | import contextlib |
|
11 | 11 | import os |
|
12 | 12 | import signal |
|
13 | 13 | import subprocess |
|
14 | 14 | import sys |
|
15 | 15 | |
|
16 | 16 | from .i18n import _ |
|
17 | 17 | from . import ( |
|
18 | 18 | encoding, |
|
19 | 19 | error, |
|
20 | 20 | extensions, |
|
21 | 21 | pycompat, |
|
22 | 22 | util, |
|
23 | 23 | ) |
|
24 | 24 | |
|
25 | 25 | |
|
26 | 26 | def _loadprofiler(ui, profiler): |
|
27 | 27 | """load profiler extension. return profile method, or None on failure""" |
|
28 | 28 | extname = profiler |
|
29 | 29 | extensions.loadall(ui, whitelist=[extname]) |
|
30 | 30 | try: |
|
31 | 31 | mod = extensions.find(extname) |
|
32 | 32 | except KeyError: |
|
33 | 33 | return None |
|
34 | 34 | else: |
|
35 | 35 | return getattr(mod, 'profile', None) |
|
36 | 36 | |
|
37 | 37 | |
|
38 | 38 | @contextlib.contextmanager |
|
39 | 39 | def lsprofile(ui, fp): |
|
40 | 40 | format = ui.config(b'profiling', b'format') |
|
41 | 41 | field = ui.config(b'profiling', b'sort') |
|
42 | 42 | limit = ui.configint(b'profiling', b'limit') |
|
43 | 43 | climit = ui.configint(b'profiling', b'nested') |
|
44 | 44 | |
|
45 | 45 | if format not in [b'text', b'kcachegrind']: |
|
46 | 46 | ui.warn(_(b"unrecognized profiling format '%s' - Ignored\n") % format) |
|
47 | 47 | format = b'text' |
|
48 | 48 | |
|
49 | 49 | try: |
|
50 | 50 | from . import lsprof |
|
51 | 51 | except ImportError: |
|
52 | 52 | raise error.Abort( |
|
53 | 53 | _( |
|
54 | 54 | b'lsprof not available - install from ' |
|
55 | 55 | b'http://codespeak.net/svn/user/arigo/hack/misc/lsprof/' |
|
56 | 56 | ) |
|
57 | 57 | ) |
|
58 | 58 | p = lsprof.Profiler() |
|
59 | 59 | try: |
|
60 | 60 | p.enable(subcalls=True) |
|
61 | 61 | except ValueError as exc: |
|
62 | 62 | if str(exc) != "Another profiling tool is already active": |
|
63 | 63 | raise |
|
64 | 64 | if not hasattr(sys, "monitoring"): |
|
65 | 65 | raise |
|
66 | 66 | # python >=3.12 prevent more than one profiler to run at the same |
|
67 | 67 | # time, tries to improve the report to help the user understand |
|
68 | 68 | # what is going on. |
|
69 | 69 | other_tool_name = sys.monitoring.get_tool(sys.monitoring.PROFILER_ID) |
|
70 | 70 | if other_tool_name == "cProfile": |
|
71 | 71 | msg = b'cannot recursively call `lsprof`' |
|
72 | 72 | raise error.Abort(msg) from None |
|
73 | 73 | else: |
|
74 | 74 | tool = b'<unknown>' |
|
75 | 75 | if other_tool_name: |
|
76 | 76 | tool = encoding.strtolocal(other_tool_name) |
|
77 | 77 | m = b'failed to start "lsprofile"; another profiler already running: %s' |
|
78 | 78 | raise error.Abort(_(m) % tool) from None |
|
79 | 79 | try: |
|
80 | 80 | yield |
|
81 | 81 | finally: |
|
82 | 82 | p.disable() |
|
83 | 83 | |
|
84 | 84 | if format == b'kcachegrind': |
|
85 | 85 | from . import lsprofcalltree |
|
86 | 86 | |
|
87 | 87 | calltree = lsprofcalltree.KCacheGrind(p) |
|
88 | 88 | calltree.output(fp) |
|
89 | 89 | else: |
|
90 | 90 | # format == 'text' |
|
91 | 91 | stats = lsprof.Stats(p.getstats()) |
|
92 | 92 | stats.sort(pycompat.sysstr(field)) |
|
93 | 93 | stats.pprint(limit=limit, file=fp, climit=climit) |
|
94 | 94 | fp.flush() |
|
95 | 95 | |
|
96 | 96 | |
|
97 | 97 | @contextlib.contextmanager |
|
98 | 98 | def flameprofile(ui, fp): |
|
99 | 99 | try: |
|
100 | 100 | from flamegraph import flamegraph # pytype: disable=import-error |
|
101 | 101 | except ImportError: |
|
102 | 102 | raise error.Abort( |
|
103 | 103 | _( |
|
104 | 104 | b'flamegraph not available - install from ' |
|
105 | 105 | b'https://github.com/evanhempel/python-flamegraph' |
|
106 | 106 | ) |
|
107 | 107 | ) |
|
108 | 108 | # developer config: profiling.freq |
|
109 | 109 | freq = ui.configint(b'profiling', b'freq') |
|
110 | 110 | filter_ = None |
|
111 | 111 | collapse_recursion = True |
|
112 | 112 | thread = flamegraph.ProfileThread( |
|
113 | 113 | fp, 1.0 / freq, filter_, collapse_recursion |
|
114 | 114 | ) |
|
115 | 115 | start_time = util.timer() |
|
116 | 116 | try: |
|
117 | 117 | thread.start() |
|
118 | 118 | yield |
|
119 | 119 | finally: |
|
120 | 120 | thread.stop() |
|
121 | 121 | thread.join() |
|
122 | 122 | m = b'Collected %d stack frames (%d unique) in %2.2f seconds.' |
|
123 | 123 | m %= ( |
|
124 | 124 | ( |
|
125 | 125 | util.timer() - start_time, |
|
126 | 126 | thread.num_frames(), |
|
127 | 127 | thread.num_frames(unique=True), |
|
128 | 128 | ), |
|
129 | 129 | ) |
|
130 | 130 | print(m, flush=True) |
|
131 | 131 | |
|
132 | 132 | |
|
133 | 133 | @contextlib.contextmanager |
|
134 | 134 | def statprofile(ui, fp): |
|
135 | 135 | from . import statprof |
|
136 | 136 | |
|
137 | 137 | freq = ui.configint(b'profiling', b'freq') |
|
138 | 138 | if freq > 0: |
|
139 | 139 | # Cannot reset when profiler is already active. So silently no-op. |
|
140 | 140 | if statprof.state.profile_level == 0: |
|
141 | 141 | statprof.reset(freq) |
|
142 | 142 | else: |
|
143 | 143 | ui.warn(_(b"invalid sampling frequency '%s' - ignoring\n") % freq) |
|
144 | 144 | |
|
145 | 145 | track = ui.config( |
|
146 | 146 | b'profiling', b'time-track', pycompat.iswindows and b'cpu' or b'real' |
|
147 | 147 | ) |
|
148 | 148 | statprof.start(mechanism=b'thread', track=track) |
|
149 | 149 | |
|
150 | 150 | try: |
|
151 | 151 | yield |
|
152 | 152 | finally: |
|
153 | 153 | data = statprof.stop() |
|
154 | 154 | |
|
155 | 155 | profformat = ui.config(b'profiling', b'statformat') |
|
156 | 156 | |
|
157 | 157 | formats = { |
|
158 | 158 | b'byline': statprof.DisplayFormats.ByLine, |
|
159 | 159 | b'bymethod': statprof.DisplayFormats.ByMethod, |
|
160 | 160 | b'hotpath': statprof.DisplayFormats.Hotpath, |
|
161 | 161 | b'json': statprof.DisplayFormats.Json, |
|
162 | 162 | b'chrome': statprof.DisplayFormats.Chrome, |
|
163 | 163 | } |
|
164 | 164 | |
|
165 | 165 | if profformat in formats: |
|
166 | 166 | displayformat = formats[profformat] |
|
167 | 167 | else: |
|
168 | 168 | ui.warn(_(b'unknown profiler output format: %s\n') % profformat) |
|
169 | 169 | displayformat = statprof.DisplayFormats.Hotpath |
|
170 | 170 | |
|
171 | 171 | kwargs = {} |
|
172 | 172 | |
|
173 | 173 | def fraction(s): |
|
174 | 174 | if isinstance(s, (float, int)): |
|
175 | 175 | return float(s) |
|
176 | 176 | if s.endswith(b'%'): |
|
177 | 177 | v = float(s[:-1]) / 100 |
|
178 | 178 | else: |
|
179 | 179 | v = float(s) |
|
180 | 180 | if 0 <= v <= 1: |
|
181 | 181 | return v |
|
182 | 182 | raise ValueError(s) |
|
183 | 183 | |
|
184 | 184 | if profformat == b'chrome': |
|
185 | 185 | showmin = ui.configwith(fraction, b'profiling', b'showmin', 0.005) |
|
186 | 186 | showmax = ui.configwith(fraction, b'profiling', b'showmax') |
|
187 | 187 | kwargs.update(minthreshold=showmin, maxthreshold=showmax) |
|
188 | 188 | elif profformat == b'hotpath': |
|
189 | 189 | # inconsistent config: profiling.showmin |
|
190 | 190 | limit = ui.configwith(fraction, b'profiling', b'showmin', 0.05) |
|
191 | 191 | kwargs['limit'] = limit |
|
192 | 192 | showtime = ui.configbool(b'profiling', b'showtime') |
|
193 | 193 | kwargs['showtime'] = showtime |
|
194 | 194 | |
|
195 | 195 | statprof.display(fp, data=data, format=displayformat, **kwargs) |
|
196 | 196 | fp.flush() |
|
197 | 197 | |
|
198 | 198 | |
|
199 | 199 | @contextlib.contextmanager |
|
200 | 200 | def pyspy_profile(ui, fp): |
|
201 | 201 | exe = ui.config(b'profiling', b'py-spy.exe') |
|
202 | 202 | |
|
203 | 203 | freq = ui.configint(b'profiling', b'py-spy.freq') |
|
204 | 204 | |
|
205 | 205 | format = ui.config(b'profiling', b'py-spy.format') |
|
206 | 206 | |
|
207 | 207 | fd = fp.fileno() |
|
208 | 208 | |
|
209 | 209 | output_path = "/dev/fd/%d" % (fd) |
|
210 | 210 | |
|
211 | 211 | my_pid = os.getpid() |
|
212 | 212 | |
|
213 | 213 | cmd = [ |
|
214 | 214 | exe, |
|
215 | 215 | "record", |
|
216 | 216 | "--pid", |
|
217 | 217 | str(my_pid), |
|
218 | 218 | "--native", |
|
219 | 219 | "--rate", |
|
220 | 220 | str(freq), |
|
221 | 221 | "--output", |
|
222 | 222 | output_path, |
|
223 | 223 | ] |
|
224 | 224 | |
|
225 | 225 | if format: |
|
226 | 226 | cmd.extend(["--format", format]) |
|
227 | 227 | |
|
228 | 228 | proc = subprocess.Popen( |
|
229 | 229 | cmd, |
|
230 | 230 | pass_fds={fd}, |
|
231 | 231 | stdout=subprocess.PIPE, |
|
232 | 232 | ) |
|
233 | 233 | |
|
234 | 234 | _ = proc.stdout.readline() |
|
235 | 235 | |
|
236 | 236 | try: |
|
237 | 237 | yield |
|
238 | 238 | finally: |
|
239 | 239 | os.kill(proc.pid, signal.SIGINT) |
|
240 | 240 | proc.communicate() |
|
241 | 241 | |
|
242 | 242 | |
|
243 | 243 | class profile: |
|
244 | 244 | """Start profiling. |
|
245 | 245 | |
|
246 | 246 | Profiling is active when the context manager is active. When the context |
|
247 | 247 | manager exits, profiling results will be written to the configured output. |
|
248 | 248 | """ |
|
249 | 249 | |
|
250 | 250 | def __init__(self, ui, enabled=True): |
|
251 | 251 | self._ui = ui |
|
252 | 252 | self._output = None |
|
253 | 253 | self._fp = None |
|
254 | 254 | self._fpdoclose = True |
|
255 | 255 | self._flushfp = None |
|
256 | 256 | self._profiler = None |
|
257 | 257 | self._enabled = enabled |
|
258 | 258 | self._entered = False |
|
259 | 259 | self._started = False |
|
260 | 260 | |
|
261 | 261 | def __enter__(self): |
|
262 | 262 | self._entered = True |
|
263 | 263 | if self._enabled: |
|
264 | 264 | self.start() |
|
265 | 265 | return self |
|
266 | 266 | |
|
267 | 267 | def start(self): |
|
268 | 268 | """Start profiling. |
|
269 | 269 | |
|
270 | 270 | The profiling will stop at the context exit. |
|
271 | 271 | |
|
272 | 272 | If the profiler was already started, this has no effect.""" |
|
273 | 273 | if not self._entered: |
|
274 | 274 | raise error.ProgrammingError(b'use a context manager to start') |
|
275 | 275 | if self._started: |
|
276 | 276 | return |
|
277 | 277 | self._started = True |
|
278 | 278 | profiler = encoding.environ.get(b'HGPROF') |
|
279 | 279 | proffn = None |
|
280 | 280 | if profiler is None: |
|
281 | 281 | profiler = self._ui.config(b'profiling', b'type') |
|
282 | 282 | if profiler not in (b'ls', b'stat', b'flame', b'py-spy'): |
|
283 | 283 | # try load profiler from extension with the same name |
|
284 | 284 | proffn = _loadprofiler(self._ui, profiler) |
|
285 | 285 | if proffn is None: |
|
286 | 286 | self._ui.warn( |
|
287 | 287 | _(b"unrecognized profiler '%s' - ignored\n") % profiler |
|
288 | 288 | ) |
|
289 | 289 | profiler = b'stat' |
|
290 | 290 | |
|
291 | 291 | self._output = self._ui.config(b'profiling', b'output') |
|
292 | 292 | |
|
293 | 293 | try: |
|
294 | 294 | if self._output == b'blackbox': |
|
295 | 295 | self._fp = util.stringio() |
|
296 | 296 | elif self._output: |
|
297 | 297 | path = util.expandpath(self._output) |
|
298 | 298 | self._fp = open(path, 'wb') |
|
299 | 299 | elif pycompat.iswindows: |
|
300 | 300 | # parse escape sequence by win32print() |
|
301 | 301 | class uifp: |
|
302 | 302 | def __init__(self, ui): |
|
303 | 303 | self._ui = ui |
|
304 | 304 | |
|
305 | 305 | def write(self, data): |
|
306 | 306 | self._ui.write_err(data) |
|
307 | 307 | |
|
308 | 308 | def flush(self): |
|
309 | 309 | self._ui.flush() |
|
310 | 310 | |
|
311 | 311 | self._fpdoclose = False |
|
312 | 312 | self._fp = uifp(self._ui) |
|
313 | 313 | else: |
|
314 | 314 | self._fpdoclose = False |
|
315 | 315 | self._fp = self._ui.ferr |
|
316 | 316 | # Ensure we've flushed fout before writing to ferr. |
|
317 | 317 | self._flushfp = self._ui.fout |
|
318 | 318 | |
|
319 | 319 | if proffn is not None: |
|
320 | 320 | pass |
|
321 | 321 | elif profiler == b'ls': |
|
322 | 322 | proffn = lsprofile |
|
323 | 323 | elif profiler == b'flame': |
|
324 | 324 | proffn = flameprofile |
|
325 | 325 | elif profiler == b'py-spy': |
|
326 | 326 | proffn = pyspy_profile |
|
327 | 327 | else: |
|
328 | 328 | proffn = statprofile |
|
329 | 329 | |
|
330 | 330 | self._profiler = proffn(self._ui, self._fp) |
|
331 | 331 | self._profiler.__enter__() |
|
332 | 332 | except: # re-raises |
|
333 | 333 | self._closefp() |
|
334 | 334 | raise |
|
335 | 335 | |
|
336 | 336 | def __exit__(self, exception_type, exception_value, traceback): |
|
337 | 337 | propagate = None |
|
338 | 338 | if self._profiler is not None: |
|
339 | 339 | self._uiflush() |
|
340 | 340 | propagate = self._profiler.__exit__( |
|
341 | 341 | exception_type, exception_value, traceback |
|
342 | 342 | ) |
|
343 | 343 | if self._output == b'blackbox': |
|
344 |
|
|
|
344 | fp = self._fp | |
|
345 | # Help pytype: blackbox output uses io.BytesIO instead of a file | |
|
346 | assert isinstance(fp, util.stringio) | |
|
347 | val = b'Profile:\n%s' % fp.getvalue() | |
|
345 | 348 | # ui.log treats the input as a format string, |
|
346 | 349 | # so we need to escape any % signs. |
|
347 | 350 | val = val.replace(b'%', b'%%') |
|
348 | 351 | self._ui.log(b'profile', val) |
|
349 | 352 | self._closefp() |
|
350 | 353 | return propagate |
|
351 | 354 | |
|
352 | 355 | def _closefp(self): |
|
353 | 356 | if self._fpdoclose and self._fp is not None: |
|
354 | 357 | self._fp.close() |
|
355 | 358 | |
|
356 | 359 | def _uiflush(self): |
|
357 | 360 | if self._flushfp: |
|
358 | 361 | self._flushfp.flush() |
General Comments 0
You need to be logged in to leave comments.
Login now