1 | // Copyright 2014 The Flutter Authors. All rights reserved. |
2 | // Use of this source code is governed by a BSD-style license that can be |
3 | // found in the LICENSE file. |
4 | |
5 | import 'dart:developer'; |
6 | import 'dart:typed_data'; |
7 | |
8 | import 'package:meta/meta.dart' ; |
9 | |
10 | import '_timeline_io.dart' |
11 | if (dart.library.js_util) '_timeline_web.dart' as impl; |
12 | import 'constants.dart'; |
13 | |
14 | /// Measures how long blocks of code take to run. |
15 | /// |
16 | /// This class can be used as a drop-in replacement for [Timeline] as it |
17 | /// provides methods compatible with [Timeline] signature-wise, and it has |
18 | /// minimal overhead. |
19 | /// |
20 | /// Provides [debugReset] and [debugCollect] methods that make it convenient to use in |
21 | /// frame-oriented environment where collected metrics can be attributed to a |
22 | /// frame, then aggregated into frame statistics, e.g. frame averages. |
23 | /// |
24 | /// Forwards measurements to [Timeline] so they appear in Flutter DevTools. |
25 | abstract final class FlutterTimeline { |
26 | static _BlockBuffer _buffer = _BlockBuffer(); |
27 | |
28 | /// Whether block timings are collected and can be retrieved using the |
29 | /// [debugCollect] method. |
30 | /// |
31 | /// This is always false in release mode. |
32 | static bool get debugCollectionEnabled => _collectionEnabled; |
33 | |
34 | /// Enables metric collection. |
35 | /// |
36 | /// Metric collection can only be enabled in non-release modes. It is most |
37 | /// useful in profile mode where application performance is representative |
38 | /// of a deployed application. |
39 | /// |
40 | /// When disabled, resets collected data by calling [debugReset]. |
41 | /// |
42 | /// Throws a [StateError] if invoked in release mode. |
43 | static set debugCollectionEnabled(bool value) { |
44 | if (kReleaseMode) { |
45 | throw _createReleaseModeNotSupportedError(); |
46 | } |
47 | if (value == _collectionEnabled) { |
48 | return; |
49 | } |
50 | _collectionEnabled = value; |
51 | debugReset(); |
52 | } |
53 | |
54 | static StateError _createReleaseModeNotSupportedError() { |
55 | return StateError('FlutterTimeline metric collection not supported in release mode.' ); |
56 | } |
57 | |
58 | static bool _collectionEnabled = false; |
59 | |
60 | /// Start a synchronous operation labeled `name`. |
61 | /// |
62 | /// Optionally takes a map of `arguments`. This slice may also optionally be |
63 | /// associated with a [Flow] event. This operation must be finished by calling |
64 | /// [finishSync] before returning to the event queue. |
65 | /// |
66 | /// This is a drop-in replacement for [Timeline.startSync]. |
67 | static void startSync(String name, { Map<String, Object?>? arguments, Flow? flow }) { |
68 | Timeline.startSync(name, arguments: arguments, flow: flow); |
69 | if (!kReleaseMode && _collectionEnabled) { |
70 | _buffer.startSync(name, arguments: arguments, flow: flow); |
71 | } |
72 | } |
73 | |
74 | /// Finish the last synchronous operation that was started. |
75 | /// |
76 | /// This is a drop-in replacement for [Timeline.finishSync]. |
77 | static void finishSync() { |
78 | Timeline.finishSync(); |
79 | if (!kReleaseMode && _collectionEnabled) { |
80 | _buffer.finishSync(); |
81 | } |
82 | } |
83 | |
84 | /// Emit an instant event. |
85 | /// |
86 | /// This is a drop-in replacement for [Timeline.instantSync]. |
87 | static void instantSync(String name, { Map<String, Object?>? arguments }) { |
88 | Timeline.instantSync(name, arguments: arguments); |
89 | } |
90 | |
91 | /// A utility method to time a synchronous `function`. Internally calls |
92 | /// `function` bracketed by calls to [startSync] and [finishSync]. |
93 | /// |
94 | /// This is a drop-in replacement for [Timeline.timeSync]. |
95 | static T timeSync<T>(String name, TimelineSyncFunction<T> function, |
96 | { Map<String, Object?>? arguments, Flow? flow }) { |
97 | startSync(name, arguments: arguments, flow: flow); |
98 | try { |
99 | return function(); |
100 | } finally { |
101 | finishSync(); |
102 | } |
103 | } |
104 | |
105 | /// The current time stamp from the clock used by the timeline in |
106 | /// microseconds. |
107 | /// |
108 | /// When run on the Dart VM, uses the same monotonic clock as the embedding |
109 | /// API's `Dart_TimelineGetMicros`. |
110 | /// |
111 | /// When run on the web, uses `window.performance.now`. |
112 | /// |
113 | /// This is a drop-in replacement for [Timeline.now]. |
114 | static int get now => impl.performanceTimestamp.toInt(); |
115 | |
116 | /// Returns timings collected since [debugCollectionEnabled] was set to true, |
117 | /// since the previous [debugCollect], or since the previous [debugReset], |
118 | /// whichever was last. |
119 | /// |
120 | /// Resets the collected timings. |
121 | /// |
122 | /// This is only meant to be used in non-release modes, typically in profile |
123 | /// mode that provides timings close to release mode timings. |
124 | static AggregatedTimings debugCollect() { |
125 | if (kReleaseMode) { |
126 | throw _createReleaseModeNotSupportedError(); |
127 | } |
128 | if (!_collectionEnabled) { |
129 | throw StateError('Timeline metric collection not enabled.' ); |
130 | } |
131 | final AggregatedTimings result = AggregatedTimings(_buffer.computeTimings()); |
132 | debugReset(); |
133 | return result; |
134 | } |
135 | |
136 | /// Forgets all previously collected timing data. |
137 | /// |
138 | /// Use this method to scope metrics to a frame, a pointer event, or any |
139 | /// other event. To do that, call [debugReset] at the start of the event, then |
140 | /// call [debugCollect] at the end of the event. |
141 | /// |
142 | /// This is only meant to be used in non-release modes. |
143 | static void debugReset() { |
144 | if (kReleaseMode) { |
145 | throw _createReleaseModeNotSupportedError(); |
146 | } |
147 | _buffer = _BlockBuffer(); |
148 | } |
149 | } |
150 | |
151 | /// Provides [start], [end], and [duration] of a named block of code, timed by |
152 | /// [FlutterTimeline]. |
153 | @immutable |
154 | final class TimedBlock { |
155 | /// Creates a timed block of code from a [name], [start], and [end]. |
156 | /// |
157 | /// The [name] should be sufficiently unique and descriptive for someone to |
158 | /// easily tell which part of code was measured. |
159 | const TimedBlock({ |
160 | required this.name, |
161 | required this.start, |
162 | required this.end, |
163 | }) : assert(end >= start, 'The start timestamp must not be greater than the end timestamp.' ); |
164 | |
165 | /// A readable label for a block of code that was measured. |
166 | /// |
167 | /// This field should be sufficiently unique and descriptive for someone to |
168 | /// easily tell which part of code was measured. |
169 | final String name; |
170 | |
171 | /// The timestamp in microseconds that marks the beginning of the measured |
172 | /// block of code. |
173 | final double start; |
174 | |
175 | /// The timestamp in microseconds that marks the end of the measured block of |
176 | /// code. |
177 | final double end; |
178 | |
179 | /// How long the measured block of code took to execute in microseconds. |
180 | double get duration => end - start; |
181 | |
182 | @override |
183 | String toString() { |
184 | return 'TimedBlock( $name, $start, $end, $duration)' ; |
185 | } |
186 | } |
187 | |
188 | /// Provides aggregated results for timings collected by [FlutterTimeline]. |
189 | @immutable |
190 | final class AggregatedTimings { |
191 | /// Creates aggregated timings for the provided timed blocks. |
192 | AggregatedTimings(this.timedBlocks); |
193 | |
194 | /// All timed blocks collected between the last reset and [FlutterTimeline.debugCollect]. |
195 | final List<TimedBlock> timedBlocks; |
196 | |
197 | /// Aggregated timed blocks collected between the last reset and [FlutterTimeline.debugCollect]. |
198 | /// |
199 | /// Does not guarantee that all code blocks will be reported. Only those that |
200 | /// executed since the last reset are listed here. Use [getAggregated] for |
201 | /// graceful handling of missing code blocks. |
202 | late final List<AggregatedTimedBlock> aggregatedBlocks = _computeAggregatedBlocks(); |
203 | |
204 | List<AggregatedTimedBlock> _computeAggregatedBlocks() { |
205 | final Map<String, (double, int)> aggregate = <String, (double, int)>{}; |
206 | for (final TimedBlock block in timedBlocks) { |
207 | final (double, int) previousValue = aggregate.putIfAbsent(block.name, () => (0, 0)); |
208 | aggregate[block.name] = (previousValue.$1 + block.duration, previousValue.$2 + 1); |
209 | } |
210 | return aggregate.entries.map<AggregatedTimedBlock>( |
211 | (MapEntry<String, (double, int)> entry) { |
212 | return AggregatedTimedBlock(name: entry.key, duration: entry.value.$1, count: entry.value.$2); |
213 | } |
214 | ).toList(); |
215 | } |
216 | |
217 | /// Returns aggregated numbers for a named block of code. |
218 | /// |
219 | /// If the block in question never executed since the last reset, returns an |
220 | /// aggregation with zero duration and count. |
221 | AggregatedTimedBlock getAggregated(String name) { |
222 | return aggregatedBlocks.singleWhere( |
223 | (AggregatedTimedBlock block) => block.name == name, |
224 | // Handle the case where there are no recorded blocks of the specified |
225 | // type. In this case, the aggregated duration is simply zero, and so is |
226 | // the number of occurrences (i.e. count). |
227 | orElse: () => AggregatedTimedBlock(name: name, duration: 0, count: 0), |
228 | ); |
229 | } |
230 | } |
231 | |
232 | /// Aggregates multiple [TimedBlock] objects that share a [name]. |
233 | /// |
234 | /// It is common for the same block of code to be executed multiple times within |
235 | /// a frame. It is useful to combine multiple executions and report the total |
236 | /// amount of time attributed to that block of code. |
237 | @immutable |
238 | final class AggregatedTimedBlock { |
239 | /// Creates a timed block of code from a [name] and [duration]. |
240 | /// |
241 | /// The [name] should be sufficiently unique and descriptive for someone to |
242 | /// easily tell which part of code was measured. |
243 | const AggregatedTimedBlock({ |
244 | required this.name, |
245 | required this.duration, |
246 | required this.count, |
247 | }) : assert(duration >= 0); |
248 | |
249 | /// A readable label for a block of code that was measured. |
250 | /// |
251 | /// This field should be sufficiently unique and descriptive for someone to |
252 | /// easily tell which part of code was measured. |
253 | final String name; |
254 | |
255 | /// The sum of [TimedBlock.duration] values of aggretaged blocks. |
256 | final double duration; |
257 | |
258 | /// The number of [TimedBlock] objects aggregated. |
259 | final int count; |
260 | |
261 | @override |
262 | String toString() { |
263 | return 'AggregatedTimedBlock( $name, $duration, $count)' ; |
264 | } |
265 | } |
266 | |
267 | const int _kSliceSize = 500; |
268 | |
269 | /// A growable list of float64 values with predictable [add] performance. |
270 | /// |
271 | /// The list is organized into a "chain" of [Float64List]s. The object starts |
272 | /// with a `Float64List` "slice". When [add] is called, the value is added to |
273 | /// the slice. Once the slice is full, it is moved into the chain, and a new |
274 | /// slice is allocated. Slice size is static and therefore its allocation has |
275 | /// predictable cost. This is unlike the default [List] implementation, which, |
276 | /// when full, doubles its buffer size and copies all old elements into the new |
277 | /// buffer, leading to unpredictable performance. This makes it a poor choice |
278 | /// for recording performance because buffer reallocation would affect the |
279 | /// runtime. |
280 | /// |
281 | /// The trade-off is that reading values back from the chain is more expensive |
282 | /// compared to [List] because it requires iterating over multiple slices. This |
283 | /// is a reasonable trade-off for performance metrics, because it is more |
284 | /// important to minimize the overhead while recording metrics, than it is when |
285 | /// reading them. |
286 | final class _Float64ListChain { |
287 | _Float64ListChain(); |
288 | |
289 | final List<Float64List> _chain = <Float64List>[]; |
290 | Float64List _slice = Float64List(_kSliceSize); |
291 | int _pointer = 0; |
292 | |
293 | int get length => _length; |
294 | int _length = 0; |
295 | |
296 | /// Adds and [element] to this chain. |
297 | void add(double element) { |
298 | _slice[_pointer] = element; |
299 | _pointer += 1; |
300 | _length += 1; |
301 | if (_pointer >= _kSliceSize) { |
302 | _chain.add(_slice); |
303 | _slice = Float64List(_kSliceSize); |
304 | _pointer = 0; |
305 | } |
306 | } |
307 | |
308 | /// Returns all elements added to this chain. |
309 | /// |
310 | /// This getter is not optimized to be fast. It is assumed that when metrics |
311 | /// are read back, they do not affect the timings of the work being |
312 | /// benchmarked. |
313 | List<double> extractElements() { |
314 | final List<double> result = <double>[]; |
315 | _chain.forEach(result.addAll); |
316 | for (int i = 0; i < _pointer; i++) { |
317 | result.add(_slice[i]); |
318 | } |
319 | return result; |
320 | } |
321 | } |
322 | |
323 | /// Same as [_Float64ListChain] but for recording string values. |
324 | final class _StringListChain { |
325 | _StringListChain(); |
326 | |
327 | final List<List<String?>> _chain = <List<String?>>[]; |
328 | List<String?> _slice = List<String?>.filled(_kSliceSize, null); |
329 | int _pointer = 0; |
330 | |
331 | int get length => _length; |
332 | int _length = 0; |
333 | |
334 | /// Adds and [element] to this chain. |
335 | void add(String element) { |
336 | _slice[_pointer] = element; |
337 | _pointer += 1; |
338 | _length += 1; |
339 | if (_pointer >= _kSliceSize) { |
340 | _chain.add(_slice); |
341 | _slice = List<String?>.filled(_kSliceSize, null); |
342 | _pointer = 0; |
343 | } |
344 | } |
345 | |
346 | /// Returns all elements added to this chain. |
347 | /// |
348 | /// This getter is not optimized to be fast. It is assumed that when metrics |
349 | /// are read back, they do not affect the timings of the work being |
350 | /// benchmarked. |
351 | List<String> extractElements() { |
352 | final List<String> result = <String>[]; |
353 | for (final List<String?> slice in _chain) { |
354 | for (final String? element in slice) { |
355 | result.add(element!); |
356 | } |
357 | } |
358 | for (int i = 0; i < _pointer; i++) { |
359 | result.add(_slice[i]!); |
360 | } |
361 | return result; |
362 | } |
363 | } |
364 | |
365 | /// A buffer that records starts and ends of code blocks, and their names. |
366 | final class _BlockBuffer { |
367 | // Start-finish blocks can be nested. Track this nestedness by stacking the |
368 | // start timestamps. Finish timestamps will pop timings from the stack and |
369 | // add the (start, finish) tuple to the _block. |
370 | static const int _stackDepth = 1000; |
371 | static final Float64List _startStack = Float64List(_stackDepth); |
372 | static final List<String?> _nameStack = List<String?>.filled(_stackDepth, null); |
373 | static int _stackPointer = 0; |
374 | |
375 | final _Float64ListChain _starts = _Float64ListChain(); |
376 | final _Float64ListChain _finishes = _Float64ListChain(); |
377 | final _StringListChain _names = _StringListChain(); |
378 | |
379 | List<TimedBlock> computeTimings() { |
380 | assert( |
381 | _stackPointer == 0, |
382 | 'Invalid sequence of `startSync` and `finishSync`.\n' |
383 | 'The operation stack was not empty. The following operations are still ' |
384 | 'waiting to be finished via the `finishSync` method:\n' |
385 | ' ${List<String>.generate(_stackPointer, (int i) => _nameStack[i]!).join(', ' )}' |
386 | ); |
387 | |
388 | final List<TimedBlock> result = <TimedBlock>[]; |
389 | final int length = _finishes.length; |
390 | final List<double> starts = _starts.extractElements(); |
391 | final List<double> finishes = _finishes.extractElements(); |
392 | final List<String> names = _names.extractElements(); |
393 | |
394 | assert(starts.length == length); |
395 | assert(finishes.length == length); |
396 | assert(names.length == length); |
397 | |
398 | for (int i = 0; i < length; i++) { |
399 | result.add(TimedBlock( |
400 | start: starts[i], |
401 | end: finishes[i], |
402 | name: names[i], |
403 | )); |
404 | } |
405 | |
406 | return result; |
407 | } |
408 | |
409 | void startSync(String name, { Map<String, Object?>? arguments, Flow? flow }) { |
410 | _startStack[_stackPointer] = impl.performanceTimestamp; |
411 | _nameStack[_stackPointer] = name; |
412 | _stackPointer += 1; |
413 | } |
414 | |
415 | void finishSync() { |
416 | assert( |
417 | _stackPointer > 0, |
418 | 'Invalid sequence of `startSync` and `finishSync`.\n' |
419 | 'Attempted to finish timing a block of code, but there are no pending ' |
420 | '`startSync` calls.' |
421 | ); |
422 | |
423 | final double finishTime = impl.performanceTimestamp; |
424 | final double startTime = _startStack[_stackPointer - 1]; |
425 | final String name = _nameStack[_stackPointer - 1]!; |
426 | _stackPointer -= 1; |
427 | |
428 | _starts.add(startTime); |
429 | _finishes.add(finishTime); |
430 | _names.add(name); |
431 | } |
432 | } |
433 | |