diff --git a/dev/devicelab/lib/tasks/perf_tests.dart b/dev/devicelab/lib/tasks/perf_tests.dart index 1c4e1349a0f..cc9ee9650e2 100644 --- a/dev/devicelab/lib/tasks/perf_tests.dart +++ b/dev/devicelab/lib/tasks/perf_tests.dart @@ -189,7 +189,6 @@ TaskFunction createColorFilterAndFadePerfTest() { ).run; } - /// Measure application startup performance. class StartupTest { const StartupTest(this.testDirectory, { this.reportMetrics = true }); @@ -281,6 +280,9 @@ class PerfTest { 'worst_frame_rasterizer_time_millis', '90th_percentile_frame_rasterizer_time_millis', '99th_percentile_frame_rasterizer_time_millis', + 'average_vsync_transitions_missed', + '90th_percentile_vsync_transitions_missed', + '99th_percentile_vsync_transitions_missed', if (needsMeasureCpuGPu) 'cpu_percentage', if (needsMeasureCpuGPu) 'gpu_percentage', ]); diff --git a/packages/flutter_driver/lib/src/driver/scene_display_lag_summarizer.dart b/packages/flutter_driver/lib/src/driver/scene_display_lag_summarizer.dart new file mode 100644 index 00000000000..c3cd2ec13b7 --- /dev/null +++ b/packages/flutter_driver/lib/src/driver/scene_display_lag_summarizer.dart @@ -0,0 +1,80 @@ +// Copyright 2014 The Flutter Authors. All rights reserved. +// Use of this source code is governed by a BSD-style license that can be +// found in the LICENSE file. + +import 'timeline.dart'; + +/// Key for SceneDisplayLag timeline events. +const String kSceneDisplayLagEvent = 'SceneDisplayLag'; + +const String _kVsyncTransitionsMissed = 'vsync_transitions_missed'; + +/// Returns the [p]-th percentile element from the [doubles]. +/// +/// Note: [doubles] will be sorted. +double findPercentile(List doubles, double p) { + assert(doubles.isNotEmpty); + doubles.sort(); + return doubles[((doubles.length - 1) * (p / 100)).round()]; +} + +/// Summarizes [TimelineEvents]s corresponding to [kSceneDisplayLagEvent] events. +/// +/// A sample event (some fields have been omitted for brewity): +/// ``` +/// { +/// "name": "SceneDisplayLag", +/// "ts": 408920509340, +/// "ph": "b", (this can be 'b' or 'e' for begin or end) +/// "args": { +/// "frame_target_time": "408920509340458", +/// "current_frame_target_time": "408920542689291", +/// "vsync_transitions_missed": "2" +/// } +/// }, +/// ``` +/// +/// `vsync_transitions_missed` corresponds to the elapsed number of frame budget +/// durations between when the frame was scheduled to be displayed, i.e, the +/// `frame_target_time` and the next vsync pulse timestamp, i.e, the +/// `current_frame_target_time`. +class SceneDisplayLagSummarizer { + /// Creates a SceneDisplayLagSummarizer given the timeline events. + SceneDisplayLagSummarizer(this.sceneDisplayLagEvents) { + for (final TimelineEvent event in sceneDisplayLagEvents) { + assert(event.name == kSceneDisplayLagEvent); + } + } + + /// The scene display lag events. + final List sceneDisplayLagEvents; + + /// Computes the average of the `vsync_transitions_missed` over the lag events. + double computeAverageVsyncTransitionsMissed() { + if (sceneDisplayLagEvents.isEmpty) { + return 0; + } + + final double total = sceneDisplayLagEvents + .map(_getVsyncTransitionsMissed) + .reduce((double a, double b) => a + b); + return total / sceneDisplayLagEvents.length; + } + + /// The [percentile]-th percentile `vsync_transitions_missed` over the lag events. + double computePercentileVsyncTransitionsMissed(double percentile) { + if (sceneDisplayLagEvents.isEmpty) { + return 0; + } + + final List doubles = + sceneDisplayLagEvents.map(_getVsyncTransitionsMissed).toList(); + return findPercentile(doubles, percentile); + } + + double _getVsyncTransitionsMissed(TimelineEvent e) { + assert(e.name == kSceneDisplayLagEvent); + assert(e.arguments.containsKey(_kVsyncTransitionsMissed)); + return (e.arguments[_kVsyncTransitionsMissed] as num).toDouble(); + } +} diff --git a/packages/flutter_driver/lib/src/driver/timeline_summary.dart b/packages/flutter_driver/lib/src/driver/timeline_summary.dart index 3ad60852482..ab8e9dceec1 100644 --- a/packages/flutter_driver/lib/src/driver/timeline_summary.dart +++ b/packages/flutter_driver/lib/src/driver/timeline_summary.dart @@ -10,6 +10,7 @@ import 'package:file/file.dart'; import 'package:path/path.dart' as path; import 'common.dart'; +import 'scene_display_lag_summarizer.dart'; import 'timeline.dart'; const JsonEncoder _prettyEncoder = JsonEncoder.withIndent(' '); @@ -85,6 +86,8 @@ class TimelineSummary { /// Encodes this summary as JSON. Map get summaryJson { + final SceneDisplayLagSummarizer sceneDisplayLagSummarizer = _sceneDisplayLagSummarizer(); + return { 'average_frame_build_time_millis': computeAverageFrameBuildTimeMillis(), '90th_percentile_frame_build_time_millis': computePercentileFrameBuildTimeMillis(90.0), @@ -105,7 +108,10 @@ class TimelineSummary { .toList(), 'frame_begin_times': _extractBeginTimestamps('Frame') .map((Duration duration) => duration.inMicroseconds) - .toList() + .toList(), + 'average_vsync_transitions_missed': sceneDisplayLagSummarizer.computeAverageVsyncTransitionsMissed(), + '90th_percentile_vsync_transitions_missed': sceneDisplayLagSummarizer.computePercentileVsyncTransitionsMissed(90.0), + '99th_percentile_vsync_transitions_missed': sceneDisplayLagSummarizer.computePercentileVsyncTransitionsMissed(99.0) }; } @@ -208,9 +214,7 @@ class TimelineSummary { throw ArgumentError('durations is empty!'); assert(percentile >= 0.0 && percentile <= 100.0); final List doubles = durations.map((Duration duration) => duration.inMicroseconds.toDouble() / 1000.0).toList(); - doubles.sort(); - return doubles[((doubles.length - 1) * (percentile / 100)).round()]; - + return findPercentile(doubles, percentile); } double _maxInMillis(Iterable durations) { @@ -221,6 +225,8 @@ class TimelineSummary { .reduce(math.max); } + SceneDisplayLagSummarizer _sceneDisplayLagSummarizer() => SceneDisplayLagSummarizer(_extractNamedEvents(kSceneDisplayLagEvent)); + List _extractGpuRasterizerDrawDurations() => _extractBeginEndEvents('GPURasterizer::Draw'); List _extractFrameDurations() => _extractBeginEndEvents('Frame'); diff --git a/packages/flutter_driver/test/src/real_tests/timeline_summary_test.dart b/packages/flutter_driver/test/src/real_tests/timeline_summary_test.dart index 9f101e5d818..9d47452ef15 100644 --- a/packages/flutter_driver/test/src/real_tests/timeline_summary_test.dart +++ b/packages/flutter_driver/test/src/real_tests/timeline_summary_test.dart @@ -7,6 +7,7 @@ import 'dart:convert' show json; import 'package:file/file.dart'; import 'package:flutter_driver/flutter_driver.dart'; import 'package:flutter_driver/src/driver/common.dart'; +import 'package:flutter_driver/src/driver/scene_display_lag_summarizer.dart'; import 'package:path/path.dart' as path; import '../../common.dart'; @@ -44,6 +45,24 @@ void main() { 'ts': timeStamp, }; + Map lagBegin(int timeStamp, int vsyncsMissed) => { + 'name': 'SceneDisplayLag', + 'ph': 'b', + 'ts': timeStamp, + 'args': { + 'vsync_transitions_missed': vsyncsMissed + } + }; + + Map lagEnd(int timeStamp, int vsyncsMissed) => { + 'name': 'SceneDisplayLag', + 'ph': 'e', + 'ts': timeStamp, + 'args': { + 'vsync_transitions_missed': vsyncsMissed + } + }; + List> rasterizeTimeSequenceInMillis(List sequence) { final List> result = >[]; int t = 0; @@ -356,6 +375,9 @@ void main() { 'frame_build_times': [17000, 9000, 19000], 'frame_rasterizer_times': [18000, 10000, 20000], 'frame_begin_times': [0, 18000, 28000], + 'average_vsync_transitions_missed': 0.0, + '90th_percentile_vsync_transitions_missed': 0.0, + '99th_percentile_vsync_transitions_missed': 0.0 }, ); }); @@ -391,6 +413,9 @@ void main() { frameBegin(1000), frameEnd(18000), frameBegin(19000), frameEnd(28000), frameBegin(29000), frameEnd(48000), + lagBegin(1000, 4), lagEnd(2000, 4), + lagBegin(1200, 12), lagEnd(2400, 12), + lagBegin(4200, 8), lagEnd(9400, 8), ]).writeSummaryToFile('test', destinationDirectory: tempDir.path); final String written = await fs.file(path.join(tempDir.path, 'test.timeline_summary.json')).readAsString(); @@ -409,8 +434,62 @@ void main() { 'frame_build_times': [17000, 9000, 19000], 'frame_rasterizer_times': [18000, 10000, 20000], 'frame_begin_times': [0, 18000, 28000], + 'average_vsync_transitions_missed': 8.0, + '90th_percentile_vsync_transitions_missed': 12.0, + '99th_percentile_vsync_transitions_missed': 12.0 }); }); }); + + group('SceneDisplayLagSummarizer tests', () { + SceneDisplayLagSummarizer summarize(List> traceEvents) { + final Timeline timeline = Timeline.fromJson({ + 'traceEvents': traceEvents, + }); + return SceneDisplayLagSummarizer(timeline.events); + } + + test('average_vsyncs_missed', () async { + final SceneDisplayLagSummarizer summarizer = summarize(>[ + lagBegin(1000, 4), lagEnd(2000, 4), + lagBegin(1200, 12), lagEnd(2400, 12), + lagBegin(4200, 8), lagEnd(9400, 8), + ]); + expect(summarizer.computeAverageVsyncTransitionsMissed(), 8.0); + }); + + test('all stats are 0 for 0 missed transitions', () async { + final SceneDisplayLagSummarizer summarizer = summarize(>[]); + expect(summarizer.computeAverageVsyncTransitionsMissed(), 0.0); + expect(summarizer.computePercentileVsyncTransitionsMissed(90.0), 0.0); + expect(summarizer.computePercentileVsyncTransitionsMissed(99.0), 0.0); + }); + + test('90th_percentile_vsyncs_missed', () async { + final SceneDisplayLagSummarizer summarizer = summarize(>[ + lagBegin(1000, 4), lagEnd(2000, 4), + lagBegin(1200, 12), lagEnd(2400, 12), + lagBegin(4200, 8), lagEnd(9400, 8), + lagBegin(6100, 14), lagEnd(11000, 14), + lagBegin(7100, 16), lagEnd(11500, 16), + lagBegin(7400, 11), lagEnd(13000, 11), + lagBegin(8200, 27), lagEnd(14100, 27), + lagBegin(8700, 7), lagEnd(14300, 7), + lagBegin(24200, 4187), lagEnd(39400, 4187), + ]); + expect(summarizer.computePercentileVsyncTransitionsMissed(90), 27.0); + }); + + test('99th_percentile_vsyncs_missed', () async { + final SceneDisplayLagSummarizer summarizer = summarize(>[ + lagBegin(1000, 4), lagEnd(2000, 4), + lagBegin(1200, 12), lagEnd(2400, 12), + lagBegin(4200, 8), lagEnd(9400, 8), + lagBegin(6100, 14), lagEnd(11000, 14), + lagBegin(24200, 4187), lagEnd(39400, 4187), + ]); + expect(summarizer.computePercentileVsyncTransitionsMissed(99), 4187.0); + }); + }); }); }