diff options
author | Allan Sandfeld Jensen <allan.jensen@qt.io> | 2019-08-30 10:22:43 +0200 |
---|---|---|
committer | Allan Sandfeld Jensen <allan.jensen@qt.io> | 2019-08-30 12:36:28 +0000 |
commit | 271a6c3487a14599023a9106329505597638d793 (patch) | |
tree | e040d58ffc86c1480b79ca8528020ca9ec919bf8 /chromium/third_party/catapult/tracing/tracing/metrics | |
parent | 7b2ffa587235a47d4094787d72f38102089f402a (diff) | |
download | qtwebengine-chromium-271a6c3487a14599023a9106329505597638d793.tar.gz |
BASELINE: Update Chromium to 77.0.3865.59
Change-Id: I1e89a5f3b009a9519a6705102ad65c92fe736f21
Reviewed-by: Michael BrĂ¼ning <michael.bruning@qt.io>
Diffstat (limited to 'chromium/third_party/catapult/tracing/tracing/metrics')
21 files changed, 1066 insertions, 647 deletions
diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/OWNERS b/chromium/third_party/catapult/tracing/tracing/metrics/OWNERS index 0d2ba153fd3..65ecfedda2f 100644 --- a/chromium/third_party/catapult/tracing/tracing/metrics/OWNERS +++ b/chromium/third_party/catapult/tracing/tracing/metrics/OWNERS @@ -1,2 +1 @@ -benjhayden@chromium.org crouleau@chromium.org diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/blink/OWNERS b/chromium/third_party/catapult/tracing/tracing/metrics/blink/OWNERS new file mode 100644 index 00000000000..65e7ba445cc --- /dev/null +++ b/chromium/third_party/catapult/tracing/tracing/metrics/blink/OWNERS @@ -0,0 +1,2 @@ +mlippautz@chromium.org +ulan@chromium.org diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/blink/gc_metric.html b/chromium/third_party/catapult/tracing/tracing/metrics/blink/gc_metric.html index 641c8bd0c9f..348804f4f10 100644 --- a/chromium/third_party/catapult/tracing/tracing/metrics/blink/gc_metric.html +++ b/chromium/third_party/catapult/tracing/tracing/metrics/blink/gc_metric.html @@ -15,26 +15,70 @@ found in the LICENSE file. 'use strict'; tr.exportTo('tr.metrics.blink', function() { - // Maps the Blink GC events in timeline to telemetry friendly names. - const BLINK_TOP_GC_EVENTS = { - 'BlinkGC.AtomicPhase': 'blink-gc-atomic-phase', + // Maps Blink GC foreground sweeping events in timeline to telemetry friendly + // names. + const BLINK_TOP_GC_FOREGROUND_SWEEPING_EVENTS = { 'BlinkGC.CompleteSweep': 'blink-gc-complete-sweep', - 'BlinkGC.IncrementalMarkingStartMarking': 'blink-gc-incremental-start', - 'BlinkGC.IncrementalMarkingStep': 'blink-gc-incremental-step', - 'BlinkGC.LazySweepInIdle': 'blink-gc-lazy-sweep-idle', - 'BlinkGC.LazySweepOnAllocation': 'blink-gc-lazy-sweep-allocation' + 'BlinkGC.LazySweepInIdle': 'blink-gc-sweep-task-foreground', + 'BlinkGC.LazySweepOnAllocation': 'blink-gc-sweep-allocation' + }; + + // Maps Blink GC background sweeping events in timeline to telemetry friendly + // names. + const BLINK_TOP_GC_BACKGROUND_SWEEPING_EVENTS = { + 'BlinkGC.ConcurrentSweep': 'blink-gc-sweep-task-background' }; + // Maps the all Blink GC events in timeline to telemetry friendly names. + const BLINK_TOP_GC_EVENTS = Object.assign({ + 'BlinkGC.AtomicPauseMarkEpilogue': 'blink-gc-atomic-pause-mark-epilogue', + 'BlinkGC.AtomicPauseMarkPrologue': 'blink-gc-atomic-pause-mark-prologue', + 'BlinkGC.AtomicPauseMarkRoots': 'blink-gc-atomic-pause-mark-roots', + 'BlinkGC.AtomicPauseMarkTransitiveClosure': + 'blink-gc-atomic-pause-mark-transitive-closure', + 'BlinkGC.AtomicPauseSweepAndCompact': + 'blink-gc-atomic-pause-sweep-and-compact', + 'BlinkGC.IncrementalMarkingStartMarking': 'blink-gc-incremental-start', + 'BlinkGC.IncrementalMarkingStep': 'blink-gc-incremental-step' + }, BLINK_TOP_GC_FOREGROUND_SWEEPING_EVENTS); + + // All events that should be summed up to 'blink-gc-atomic-pause'. Note that + // this events need to have an epoch counter in args.epoch. + const ATOMIC_PAUSE_EVENTS = [ + 'BlinkGC.AtomicPauseMarkEpilogue', + 'BlinkGC.AtomicPauseMarkPrologue', + 'BlinkGC.AtomicPauseMarkRoots', + 'BlinkGC.AtomicPauseMarkTransitiveClosure', + 'BlinkGC.AtomicPauseSweepAndCompact' + ]; + function blinkGarbageCollectionEventName(event) { return BLINK_TOP_GC_EVENTS[event.title]; } - function isNonForcedBlinkGarbageCollectionEvent(event) { - return event.title in BLINK_TOP_GC_EVENTS && - (!event.args || !event.args.forced) && + function isNonForcedEvent(event) { + return (!event.args || !event.args.forced) && !tr.metrics.v8.utils.isForcedGarbageCollectionEvent(event); } + function isNonForcedBlinkGarbageCollectionEvent(event) { + return event.title in BLINK_TOP_GC_EVENTS && isNonForcedEvent(event); + } + + function isNonForcedBlinkGarbageCollectionAtomicPauseEvent(event) { + return ATOMIC_PAUSE_EVENTS.includes(event.title) && isNonForcedEvent(event); + } + + function isNonForcedBlinkGarbageCollectionForegroundSweepingEvent(event) { + return event.title in BLINK_TOP_GC_FOREGROUND_SWEEPING_EVENTS && + isNonForcedEvent(event); + } + + function isNonForcedBlinkGarbageCollectionBackgroundSweepingEvent(event) { + return event.title in BLINK_TOP_GC_BACKGROUND_SWEEPING_EVENTS && + isNonForcedEvent(event); + } + function isNonNestedNonForcedBlinkGarbageCollectionEvent(event) { return isNonForcedBlinkGarbageCollectionEvent(event) && !tr.metrics.v8.utils.findParent(event, @@ -43,18 +87,17 @@ tr.exportTo('tr.metrics.blink', function() { function blinkGcMetric(histograms, model) { addDurationOfTopEvents(histograms, model); + addDurationOfAtomicPause(histograms, model); addTotalDurationOfTopEvents(histograms, model); - addIdleTimesOfTopEvents(histograms, model); - addTotalIdleTimesOfTopEvents(histograms, model); addTotalDurationOfBlinkAndV8TopEvents(histograms, model); + addTotalDurationOfForegroundSweeping(histograms, model); + addTotalDurationOfBackgroundSweeping(histograms, model); } tr.metrics.MetricRegistry.register(blinkGcMetric); const timeDurationInMs_smallerIsBetter = tr.b.Unit.byName.timeDurationInMs_smallerIsBetter; - const percentage_biggerIsBetter = - tr.b.Unit.byName.normalizedPercentage_biggerIsBetter; // 0.1 steps from 0 to 20 since it is the most common range. // Exponentially increasing steps from 20 to 200. @@ -103,34 +146,9 @@ tr.exportTo('tr.metrics.blink', function() { return n; } - function createNumericForIdleTime(name) { - const n = new tr.v.Histogram(name, - timeDurationInMs_smallerIsBetter, CUSTOM_BOUNDARIES); - n.customizeSummaryOptions({ - avg: true, - count: false, - max: true, - min: false, - std: false, - sum: true, - percentile: [] - }); - return n; - } - - function createPercentage(name, numerator, denominator) { - const histogram = new tr.v.Histogram(name, percentage_biggerIsBetter); - if (denominator === 0) { - histogram.addSample(0); - } else { - histogram.addSample(numerator / denominator); - } - return histogram; - } - /** * Example output: - * - blink-gc-atomic-phase + * - blink-gc-incremental-start */ function addDurationOfTopEvents(histograms, model) { tr.metrics.v8.utils.groupAndProcessEvents(model, @@ -148,6 +166,24 @@ tr.exportTo('tr.metrics.blink', function() { /** * Example output: + * - blink-gc-atomic-pause + */ + function addDurationOfAtomicPause(histograms, model) { + tr.metrics.v8.utils.groupAndProcessEvents(model, + isNonForcedBlinkGarbageCollectionAtomicPauseEvent, + event => event.args.epoch, + function(group, events) { + const cpuDuration = createNumericForTopEventTime( + 'blink-gc-atomic-pause'); + cpuDuration.addSample( + events.reduce((acc, current) => acc + current.cpuDuration, 0)); + histograms.addHistogram(cpuDuration); + } + ); + } + + /** + * Example output: * - blink-gc-total_sum */ function addTotalDurationOfTopEvents(histograms, model) { @@ -166,73 +202,40 @@ tr.exportTo('tr.metrics.blink', function() { /** * Example output: - * - blink-gc-atomic-phase_idle_deadline_overrun, - * - blink-gc-atomic-phase_outside_idle, - * - blink-gc-atomic-phase_percentage_idle. + * - blink-gc-sweep-foreground */ - function addIdleTimesOfTopEvents(histograms, model) { + function addTotalDurationOfForegroundSweeping(histograms, model) { tr.metrics.v8.utils.groupAndProcessEvents(model, - isNonForcedBlinkGarbageCollectionEvent, - blinkGarbageCollectionEventName, + isNonForcedBlinkGarbageCollectionForegroundSweepingEvent, + event => 'blink-gc-sweep-foreground', function(name, events) { - addIdleTimes(histograms, model, name, events); + const cpuDuration = createNumericForTotalEventTime(name); + for (const event of events) { + cpuDuration.addSample(event.cpuDuration); + } + histograms.addHistogram(cpuDuration); } ); } /** * Example output: - * - blink-gc-total_idle_deadline_overrun, - * - blink-gc-total_outside_idle, - * - blink-gc-total_percentage_idle. + * - blink-gc-sweep-background */ - function addTotalIdleTimesOfTopEvents(histograms, model) { + function addTotalDurationOfBackgroundSweeping(histograms, model) { tr.metrics.v8.utils.groupAndProcessEvents(model, - isNonForcedBlinkGarbageCollectionEvent, - event => 'blink-gc-total', + isNonForcedBlinkGarbageCollectionBackgroundSweepingEvent, + event => 'blink-gc-sweep-background', function(name, events) { - addIdleTimes(histograms, model, name, events); + const cpuDuration = createNumericForTotalEventTime(name); + for (const event of events) { + cpuDuration.addSample(event.cpuDuration); + } + histograms.addHistogram(cpuDuration); } ); } - function addIdleTimes(histograms, model, name, events) { - const cpuDuration = createNumericForIdleTime(name + '_cpu'); - const insideIdle = createNumericForIdleTime(name + '_inside_idle'); - const outsideIdle = createNumericForIdleTime(name + '_outside_idle'); - const idleDeadlineOverrun = createNumericForIdleTime( - name + '_idle_deadline_overrun'); - for (const event of events) { - const idleTask = tr.metrics.v8.utils.findParent( - event, tr.metrics.v8.utils.isIdleTask); - let inside = 0; - let overrun = 0; - if (idleTask) { - const allottedTime = idleTask.args.allotted_time_ms; - if (event.duration > allottedTime) { - overrun = event.duration - allottedTime; - // Don't count time over the deadline as being inside idle time. - // Since the deadline should be relative to wall clock we - // compare allotted_time_ms with wall duration instead of thread - // duration, and then assume the thread duration was inside idle - // for the same percentage of time. - inside = event.cpuDuration * allottedTime / event.duration; - } else { - inside = event.cpuDuration; - } - } - cpuDuration.addSample(event.cpuDuration); - insideIdle.addSample(inside); - outsideIdle.addSample(event.cpuDuration - inside); - idleDeadlineOverrun.addSample(overrun); - } - histograms.addHistogram(idleDeadlineOverrun); - histograms.addHistogram(outsideIdle); - const percentage = createPercentage( - name + '_percentage_idle', insideIdle.sum, cpuDuration.sum); - histograms.addHistogram(percentage); - } - function isV8OrBlinkTopLevelGarbageCollectionEvent(event) { return tr.metrics.v8.utils.isNotForcedTopGarbageCollectionEvent(event) || isNonNestedNonForcedBlinkGarbageCollectionEvent(event); diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/blink/gc_metric_test.html b/chromium/third_party/catapult/tracing/tracing/metrics/blink/gc_metric_test.html index 924527f126b..c79d04c122c 100644 --- a/chromium/third_party/catapult/tracing/tracing/metrics/blink/gc_metric_test.html +++ b/chromium/third_party/catapult/tracing/tracing/metrics/blink/gc_metric_test.html @@ -17,19 +17,16 @@ found in the LICENSE file. tr.b.unittest.testSuite(function() { function createModel(start, end, slices) { - const opts = { - customizeModelCallback(model) { - const process = model.getOrCreateProcess(1); - const thread = process.getOrCreateThread(2); - const group = thread.sliceGroup; - slices.forEach(function(slice) { - group.pushSlice(tr.c.TestUtils.newSliceEx(slice)); - }); - group.createSubSlices(); + return tr.e.chrome.ChromeTestUtils.newChromeModel(function(model) { + const rendererProcess = model.rendererProcess; + const mainThread = model.rendererMain; + const group = mainThread.sliceGroup; + for (const slice of slices) { + group.pushSlice(tr.c.TestUtils.newSliceEx(slice)); } - }; - const model = tr.c.TestUtils.newModelWithEvents([], opts); - return model; + group.createSubSlices(); + mainThread.updateBounds(); + }); } function constructName(name, suffix) { @@ -48,9 +45,18 @@ tr.b.unittest.testSuite(function() { test('topEvents', function() { const events = { - 'BlinkGC.AtomicPhase': 'blink-gc-atomic-phase', + 'BlinkGC.AtomicPauseMarkEpilogue': 'blink-gc-atomic-pause-mark-epilogue', + 'BlinkGC.AtomicPauseMarkPrologue': 'blink-gc-atomic-pause-mark-prologue', + 'BlinkGC.AtomicPauseMarkRoots': 'blink-gc-atomic-pause-mark-roots', + 'BlinkGC.AtomicPauseMarkTransitiveClosure': + 'blink-gc-atomic-pause-mark-transitive-closure', + 'BlinkGC.AtomicPauseSweepAndCompact': + 'blink-gc-atomic-pause-sweep-and-compact', + 'BlinkGC.IncrementalMarkingStartMarking': 'blink-gc-incremental-start', + 'BlinkGC.IncrementalMarkingStep': 'blink-gc-incremental-step', 'BlinkGC.CompleteSweep': 'blink-gc-complete-sweep', - 'BlinkGC.LazySweepInIdle': 'blink-gc-lazy-sweep-idle' + 'BlinkGC.LazySweepInIdle': 'blink-gc-sweep-task-foreground', + 'BlinkGC.LazySweepOnAllocation': 'blink-gc-sweep-allocation' }; for (const [timelineName, telemetryName] of Object.entries(events)) { const slices = [ @@ -61,155 +67,169 @@ tr.b.unittest.testSuite(function() { ]; const actual = run(slices); - let value = actual.getHistogramNamed(telemetryName); + const value = actual.getHistogramNamed(telemetryName); assert.strictEqual(value.running.sum, 100); assert.strictEqual(value.numValues, 1); assert.strictEqual(value.average, 100); assert.strictEqual(value.running.max, 100); assert.closeTo(value.getApproximatePercentile(0.90), 100, 1); - - value = actual.getHistogramNamed( - `${telemetryName}_idle_deadline_overrun`); - assert.strictEqual(value.running.sum, 0); - assert.strictEqual(value.numValues, 1); - assert.strictEqual(value.average, 0); - assert.strictEqual(value.running.max, 0); - - value = actual.getHistogramNamed(`${telemetryName}_outside_idle`); - assert.strictEqual(value.running.sum, 100); - assert.strictEqual(value.numValues, 1); - assert.strictEqual(value.average, 100); - - value = actual.getHistogramNamed(`${telemetryName}_percentage_idle`); - assert.strictEqual(value.average, 0); } }); - test('idleTimes', function() { + test('totalTimeForBlinkGC', function() { const histograms = new tr.v.HistogramSet(); const slices = [ { - title: 'SingleThreadIdleTaskRunner::RunTask', - args: {'allotted_time_ms': 100}, start: 100, end: 200, - cpuStart: 100, cpuEnd: 200 + title: 'BlinkGC.AtomicPauseMarkPrologue', args: {}, + start: 100, end: 110, cpuStart: 100, cpuEnd: 110 + }, + { + title: 'BlinkGC.AtomicPauseMarkRoots', args: {}, + start: 110, end: 120, cpuStart: 110, cpuEnd: 120 }, { - title: 'BlinkGC.AtomicPhase', args: {}, start: 110, end: 190, - cpuStart: 110, cpuEnd: 190 + title: 'BlinkGC.AtomicPauseMarkTransitiveClosure', args: {}, + start: 120, end: 130, cpuStart: 120, cpuEnd: 130 + }, + { + title: 'BlinkGC.AtomicPauseMarkEpilogue', args: {}, + start: 130, end: 140, cpuStart: 130, cpuEnd: 140 + }, + { + title: 'BlinkGC.AtomicPauseSweepAndCompact', args: {}, + start: 140, end: 200, cpuStart: 140, cpuEnd: 200 + }, + { + title: 'BlinkGC.LazySweepInIdle', args: {}, start: 210, + end: 290, cpuStart: 210, cpuEnd: 290 + }, + // Background events shouldn't contribute to total time. + { + title: 'BlinkGC.ConcurrentSweep', args: {}, start: 300, + end: 390, cpuStart: 300, cpuEnd: 390 } ]; const actual = run(slices); - let value = actual.getHistogramNamed('blink-gc-atomic-phase'); - assert.strictEqual(value.running.sum, 80); - assert.strictEqual(value.numValues, 1); - assert.strictEqual(value.average, 80); + const value = actual.getHistogramNamed('blink-gc-total'); + assert.strictEqual(value.running.sum, 180); + assert.strictEqual(value.numValues, 6); assert.strictEqual(value.running.max, 80); - - value = actual.getHistogramNamed( - 'blink-gc-atomic-phase_idle_deadline_overrun'); - assert.strictEqual(value.running.sum, 0); - assert.strictEqual(value.average, 0); - assert.strictEqual(value.running.max, 0); - - value = actual.getHistogramNamed('blink-gc-atomic-phase_outside_idle'); - assert.strictEqual(value.running.sum, 0); - assert.strictEqual(value.average, 0); - assert.strictEqual(value.running.max, 0); - - value = actual.getHistogramNamed('blink-gc-atomic-phase_percentage_idle'); - assert.strictEqual(value.average, 1); }); - test('idleTimeOverrun', function() { + test('totalForegroundSweepingTimeForBlinkGC', function() { const histograms = new tr.v.HistogramSet(); const slices = [ { - title: 'SingleThreadIdleTaskRunner::RunTask', - args: {'allotted_time_ms': 10}, start: 100, end: 200, - cpuStart: 100, cpuEnd: 200 + title: 'BlinkGC.AtomicPauseMarkPrologue', args: {}, + start: 100, end: 110, cpuStart: 100, cpuEnd: 110 }, { - title: 'BlinkGC.AtomicPhase', args: {}, start: 110, end: 190, - cpuStart: 110, cpuEnd: 190 + title: 'BlinkGC.AtomicPauseMarkRoots', args: {}, + start: 110, end: 120, cpuStart: 110, cpuEnd: 120 + }, + { + title: 'BlinkGC.AtomicPauseMarkTransitiveClosure', args: {}, + start: 120, end: 130, cpuStart: 120, cpuEnd: 130 + }, + { + title: 'BlinkGC.AtomicPauseMarkEpilogue', args: {}, + start: 130, end: 140, cpuStart: 130, cpuEnd: 140 + }, + { + title: 'BlinkGC.AtomicPauseSweepAndCompact', args: {}, + start: 140, end: 200, cpuStart: 140, cpuEnd: 200 + }, + { + title: 'BlinkGC.LazySweepInIdle', args: {}, + start: 210, end: 300, cpuStart: 210, cpuEnd: 300 + }, + { + title: 'BlinkGC.LazySweepOnAllocation', args: {}, + start: 310, end: 400, cpuStart: 310, cpuEnd: 400 + }, + { + title: 'BlinkGC.CompleteSweep', args: {}, + start: 410, end: 500, cpuStart: 410, cpuEnd: 500 } ]; const actual = run(slices); - let value = actual.getHistogramNamed('blink-gc-atomic-phase'); - assert.strictEqual(value.running.sum, 80); - assert.strictEqual(value.numValues, 1); - assert.strictEqual(value.average, 80); - assert.strictEqual(value.running.max, 80); - - value = actual.getHistogramNamed( - 'blink-gc-atomic-phase_idle_deadline_overrun'); - assert.strictEqual(value.running.sum, 70); - assert.strictEqual(value.average, 70); - assert.strictEqual(value.running.max, 70); - - value = actual.getHistogramNamed('blink-gc-atomic-phase_outside_idle'); - assert.strictEqual(value.running.sum, 70); - assert.strictEqual(value.average, 70); - assert.strictEqual(value.running.max, 70); - - value = actual.getHistogramNamed('blink-gc-atomic-phase_percentage_idle'); - assert.closeTo(value.average, 1 / 8, 1e-6); + const value = actual.getHistogramNamed('blink-gc-sweep-foreground'); + assert.strictEqual(value.running.sum, 270); + assert.strictEqual(value.numValues, 3); + assert.strictEqual(value.average, 90); + assert.strictEqual(value.running.max, 90); }); - test('totalTimeForBlinkGC', function() { + test('totalBackgroundSweepingTimeForBlinkGC', function() { const histograms = new tr.v.HistogramSet(); const slices = [ { - title: 'BlinkGC.AtomicPhase', args: {}, start: 100, end: 200, - cpuStart: 100, cpuEnd: 200 + title: 'BlinkGC.ConcurrentSweep', args: {}, + start: 100, end: 200, cpuStart: 100, cpuEnd: 200 }, { - title: 'BlinkGC.LazySweepInIdle', args: {}, start: 210, - end: 290, cpuStart: 210, cpuEnd: 290 + title: 'BlinkGC.LazySweepInIdle', args: {}, + start: 210, end: 300, cpuStart: 210, cpuEnd: 300 + }, + { + title: 'BlinkGC.ConcurrentSweep', args: {}, + start: 250, end: 300, cpuStart: 250, cpuEnd: 300 + }, + { + title: 'BlinkGC.CompleteSweep', args: {}, + start: 300, end: 400, cpuStart: 310, cpuEnd: 400 } ]; const actual = run(slices); - let value = actual.getHistogramNamed('blink-gc-total'); - assert.strictEqual(value.running.sum, 180); + const value = actual.getHistogramNamed('blink-gc-sweep-background'); + assert.strictEqual(value.running.sum, 150); assert.strictEqual(value.numValues, 2); - assert.strictEqual(value.average, 90); + assert.strictEqual(value.average, 75); assert.strictEqual(value.running.max, 100); - - value = actual.getHistogramNamed('blink-gc-total_idle_deadline_overrun'); - assert.strictEqual(value.running.sum, 0); - assert.strictEqual(value.average, 0); - assert.strictEqual(value.running.max, 0); - - value = actual.getHistogramNamed('blink-gc-total_outside_idle'); - assert.strictEqual(value.running.sum, 180); - assert.strictEqual(value.average, 90); - assert.strictEqual(value.running.max, 100); - - value = actual.getHistogramNamed('blink-gc-total_percentage_idle'); - assert.strictEqual(value.average, 0); }); test('totalTimeForUnifiedGC', function() { const histograms = new tr.v.HistogramSet(); const slices = [ { + title: 'BlinkGC.AtomicPauseMarkPrologue', args: {}, + start: 100, end: 110, cpuStart: 100, cpuEnd: 110 + }, + { + title: 'BlinkGC.AtomicPauseMarkRoots', args: {}, + start: 110, end: 120, cpuStart: 110, cpuEnd: 120 + }, + { + title: 'BlinkGC.AtomicPauseMarkTransitiveClosure', args: {}, + start: 120, end: 130, cpuStart: 120, cpuEnd: 130 + }, + { + title: 'BlinkGC.AtomicPauseMarkEpilogue', args: {}, + start: 130, end: 140, cpuStart: 130, cpuEnd: 140 + }, + { + title: 'BlinkGC.AtomicPauseSweepAndCompact', args: {}, + start: 140, end: 200, cpuStart: 140, cpuEnd: 200 + }, + { title: 'V8.GCFinalizeMC', args: {}, - start: 100, end: 300, cpuStart: 100, cpuEnd: 300 + start: 200, end: 300, cpuStart: 200, cpuEnd: 300 }, + // Background events shouldn't contribute to total time. { - title: 'BlinkGC.AtomicPhase', args: {}, - start: 310, end: 410, cpuStart: 310, cpuEnd: 410 + title: 'BlinkGC.ConcurrentSweep', args: {}, + start: 420, end: 520, cpuStart: 420, cpuEnd: 520 } ]; const actual = run(slices); const value = actual.getHistogramNamed('unified-gc-total'); - assert.strictEqual(value.running.sum, 300); - assert.strictEqual(value.numValues, 2); - assert.strictEqual(value.average, 150); - assert.strictEqual(value.running.max, 200); + assert.strictEqual(value.running.sum, 200); + assert.strictEqual(value.numValues, 6); + assert.strictEqual(value.running.max, 100); }); test('totalTimeForUnifiedGCBlinkNestedInV8', function() { @@ -271,9 +291,25 @@ tr.b.unittest.testSuite(function() { start: 310, end: 320, cpuStart: 310, cpuEnd: 320 }, { - title: 'BlinkGC.AtomicPhase', args: {'forced': false}, + title: 'BlinkGC.AtomicPauseMarkPrologue', args: {}, start: 320, end: 330, cpuStart: 320, cpuEnd: 330 }, + { + title: 'BlinkGC.AtomicPauseMarkRoots', args: {}, + start: 330, end: 340, cpuStart: 330, cpuEnd: 340 + }, + { + title: 'BlinkGC.AtomicPauseMarkTransitiveClosure', args: {}, + start: 340, end: 350, cpuStart: 340, cpuEnd: 350 + }, + { + title: 'BlinkGC.AtomicPauseMarkEpilogue', args: {}, + start: 350, end: 360, cpuStart: 350, cpuEnd: 360 + }, + { + title: 'BlinkGC.AtomicPauseSweepAndCompact', args: {}, + start: 360, end: 370, cpuStart: 360, cpuEnd: 370 + }, ]; } @@ -282,9 +318,8 @@ tr.b.unittest.testSuite(function() { const histograms = new tr.v.HistogramSet(); const actual = run(getSlicesWithForcedV8GCs()); const value = actual.getHistogramNamed('unified-gc-total'); - assert.strictEqual(value.running.sum, 20); - assert.strictEqual(value.numValues, 2); - assert.strictEqual(value.average, 10); + assert.strictEqual(value.running.sum, 60); + assert.strictEqual(value.numValues, 6); assert.strictEqual(value.running.max, 10); }); @@ -293,31 +328,59 @@ tr.b.unittest.testSuite(function() { const histograms = new tr.v.HistogramSet(); const actual = run(getSlicesWithForcedV8GCs()); const value = actual.getHistogramNamed('blink-gc-total'); - assert.strictEqual(value.running.sum, 20); - assert.strictEqual(value.numValues, 2); - assert.strictEqual(value.average, 10); + assert.strictEqual(value.running.sum, 60); + assert.strictEqual(value.numValues, 6); assert.strictEqual(value.running.max, 10); }); function getSlicesWithForcedBlinkGCs() { return [ - // Following nested events should be ignored. + // Following forced events should be ignored. { title: 'BlinkGC.CompleteSweep', args: {'forced': true}, start: 200, end: 270, cpuStart: 200, cpuEnd: 270 }, { - title: 'BlinkGC.AtomicPhase', args: {'forced': true}, - start: 280, end: 290, cpuStart: 280, cpuEnd: 290 + title: 'BlinkGC.AtomicPauseMarkPrologue', args: {'forced': true}, + start: 320, end: 330, cpuStart: 320, cpuEnd: 330 + }, + { + title: 'BlinkGC.AtomicPauseMarkRoots', args: {'forced': true}, + start: 330, end: 340, cpuStart: 330, cpuEnd: 340 + }, + { + title: 'BlinkGC.AtomicPauseMarkTransitiveClosure', + args: {'forced': true}, + start: 340, end: 350, cpuStart: 340, cpuEnd: 350 + }, + { + title: 'BlinkGC.AtomicPauseMarkEpilogue', args: {'forced': true}, + start: 350, end: 360, cpuStart: 350, cpuEnd: 360 + }, + { + title: 'BlinkGC.AtomicPauseSweepAndCompact', args: {'forced': true}, + start: 360, end: 370, cpuStart: 360, cpuEnd: 370 }, // Next events are not forced and should be accounted for. { - title: 'BlinkGC.AtomicPhase', args: {}, - start: 310, end: 320, cpuStart: 310, cpuEnd: 320 + title: 'BlinkGC.AtomicPauseMarkPrologue', args: {}, + start: 410, end: 420, cpuStart: 410, cpuEnd: 420 }, { - title: 'BlinkGC.AtomicPhase', args: {'forced': false}, - start: 320, end: 330, cpuStart: 320, cpuEnd: 330 + title: 'BlinkGC.AtomicPauseMarkRoots', args: {}, + start: 420, end: 430, cpuStart: 420, cpuEnd: 430 + }, + { + title: 'BlinkGC.AtomicPauseMarkTransitiveClosure', args: {}, + start: 430, end: 440, cpuStart: 430, cpuEnd: 440 + }, + { + title: 'BlinkGC.AtomicPauseMarkEpilogue', args: {}, + start: 440, end: 450, cpuStart: 440, cpuEnd: 450 + }, + { + title: 'BlinkGC.AtomicPauseSweepAndCompact', args: {}, + start: 450, end: 460, cpuStart: 450, cpuEnd: 460 }, ]; } @@ -327,9 +390,8 @@ tr.b.unittest.testSuite(function() { const histograms = new tr.v.HistogramSet(); const actual = run(getSlicesWithForcedBlinkGCs()); const value = actual.getHistogramNamed('unified-gc-total'); - assert.strictEqual(value.running.sum, 20); - assert.strictEqual(value.numValues, 2); - assert.strictEqual(value.average, 10); + assert.strictEqual(value.running.sum, 50); + assert.strictEqual(value.numValues, 5); assert.strictEqual(value.running.max, 10); }); @@ -338,9 +400,8 @@ tr.b.unittest.testSuite(function() { const histograms = new tr.v.HistogramSet(); const actual = run(getSlicesWithForcedBlinkGCs()); const value = actual.getHistogramNamed('blink-gc-total'); - assert.strictEqual(value.running.sum, 20); - assert.strictEqual(value.numValues, 2); - assert.strictEqual(value.average, 10); + assert.strictEqual(value.running.sum, 50); + assert.strictEqual(value.numValues, 5); assert.strictEqual(value.running.max, 10); }); }); diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/compare_samples.py b/chromium/third_party/catapult/tracing/tracing/metrics/compare_samples.py index 6fb10a34b6f..b56be2810b7 100644 --- a/chromium/third_party/catapult/tracing/tracing/metrics/compare_samples.py +++ b/chromium/third_party/catapult/tracing/tracing/metrics/compare_samples.py @@ -2,8 +2,13 @@ # Use of this source code is governed by a BSD-style license that can be # found in the LICENSE file. +from __future__ import absolute_import +from __future__ import division +from __future__ import print_function + import os +from six.moves import map # pylint: disable=redefined-builtin import tracing_project import vinn diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/compare_samples_unittest.py b/chromium/third_party/catapult/tracing/tracing/metrics/compare_samples_unittest.py index df58e8ba8ce..eae8e3be569 100644 --- a/chromium/third_party/catapult/tracing/tracing/metrics/compare_samples_unittest.py +++ b/chromium/third_party/catapult/tracing/tracing/metrics/compare_samples_unittest.py @@ -2,6 +2,8 @@ # Use of this source code is governed by a BSD-style license that can be # found in the LICENSE file. +from __future__ import absolute_import +from __future__ import division from __future__ import print_function import json @@ -11,6 +13,7 @@ import random import tempfile import unittest +from six.moves import range # pylint: disable=redefined-builtin from tracing.metrics import compare_samples diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/media_metric.html b/chromium/third_party/catapult/tracing/tracing/metrics/media_metric.html index 2e1ec342a5e..58a399de84e 100644 --- a/chromium/third_party/catapult/tracing/tracing/metrics/media_metric.html +++ b/chromium/third_party/catapult/tracing/tracing/metrics/media_metric.html @@ -41,19 +41,27 @@ tr.exportTo('tr.metrics', function() { const mainThread = rendererHelper.mainThread; if (mainThread === undefined) continue; + const videoThreads = rendererHelper.process.findAllThreadsMatching( + thread => (thread.name ? thread.name.startsWith( + 'ThreadPoolSingleThreadSharedForegroundBlocking') : false)); + const compositorThread = rendererHelper.compositorThread; + if (compositorThread !== undefined) { + videoThreads.push(compositorThread); + } const audioThreads = rendererHelper.process.findAllThreadsNamed('AudioOutputDevice'); - if (compositorThread === undefined && audioThreads.length === 0) continue; + + if (audioThreads.length === 0 && videoThreads.length === 0) continue; const processData = new PerProcessData(); processData.recordPlayStarts(mainThread); if (!processData.hasPlaybacks) continue; - if (compositorThread !== undefined) { - processData.calculateTimeToVideoPlays(compositorThread); - processData.calculateDroppedFrameCounts(compositorThread); + if (videoThreads.length !== 0) { + processData.calculateTimeToVideoPlays(videoThreads); + processData.calculateDroppedFrameCounts(videoThreads); } if (audioThreads.length !== 0) { @@ -95,11 +103,13 @@ tr.exportTo('tr.metrics', function() { return this.playbackIdToDataMap_.size > 0; } - calculateTimeToVideoPlays(compositorThread) { - for (const event of compositorThread.sliceGroup.getDescendantEvents()) { - if (event.title === 'VideoRendererImpl::Render') { - this.getPerPlaybackObject_(event.args.id) - .processVideoRenderTime(event.start); + calculateTimeToVideoPlays(videoThreads) { + for (const thread of videoThreads) { + for (const event of thread.sliceGroup.getDescendantEvents()) { + if (event.title === 'VideoRendererImpl::Render') { + this.getPerPlaybackObject_(event.args.id) + .processVideoRenderTime(event.start); + } } } } @@ -139,11 +149,13 @@ tr.exportTo('tr.metrics', function() { } } - calculateDroppedFrameCounts(compositorThread) { - for (const event of compositorThread.sliceGroup.getDescendantEvents()) { - if (event.title === 'VideoFramesDropped') { - this.getPerPlaybackObject_(event.args.id) - .processVideoFramesDropped(event.args.count); + calculateDroppedFrameCounts(videoThreads) { + for (const thread of videoThreads) { + for (const event of thread.sliceGroup.getDescendantEvents()) { + if (event.title === 'VideoFramesDropped') { + this.getPerPlaybackObject_(event.args.id) + .processVideoFramesDropped(event.args.count); + } } } } diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/metric_map_function.html b/chromium/third_party/catapult/tracing/tracing/metrics/metric_map_function.html index 1b9ac12e1cc..02f5dcf02b5 100644 --- a/chromium/third_party/catapult/tracing/tracing/metrics/metric_map_function.html +++ b/chromium/third_party/catapult/tracing/tracing/metrics/metric_map_function.html @@ -163,13 +163,6 @@ tr.exportTo('tr.metrics', function() { for (const metadata of model.metadata) { if (!metadata.value || !metadata.value.telemetry) continue; - const traceUrls = metadata.value.telemetry[ - tr.v.d.RESERVED_NAMES.TRACE_URLS]; - if (traceUrls && model.canonicalUrl !== traceUrls[0]) { - throw new Error(`canonicalUrl "${model.canonicalUrl}" != ` + - `traceUrl "${traceUrls[0]}"`); - } - for (const [name, value] of Object.entries(metadata.value.telemetry)) { const type = tr.v.d.RESERVED_NAMES_TO_TYPES.get(name); if (type === undefined) { @@ -191,6 +184,12 @@ tr.exportTo('tr.metrics', function() { model, options, result.addFailure.bind(result)); addTelemetryInfo(histograms, model); + if (model.canonicalUrl !== undefined) { + const info = tr.v.d.RESERVED_INFOS.TRACE_URLS; + histograms.addSharedDiagnosticToAllHistograms( + info.name, new info.type([model.canonicalUrl])); + } + result.addPair('histograms', histograms.asDicts()); const scalarDicts = []; diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/metric_map_function_test.html b/chromium/third_party/catapult/tracing/tracing/metrics/metric_map_function_test.html index 5be41925424..531f75e144e 100644 --- a/chromium/third_party/catapult/tracing/tracing/metrics/metric_map_function_test.html +++ b/chromium/third_party/catapult/tracing/tracing/metrics/metric_map_function_test.html @@ -118,21 +118,15 @@ tr.b.unittest.testSuite(function() { `"${tr.v.d.RESERVED_NAMES.BOTS}" on Histogram "a"`); }); - test('validateCanonicalUrl', function() { + test('setCanonicalUrl', function() { const result = new tr.mre.MreResult(); const m = TestUtils.newModel(model => { - model.canonicalUrl = 'canonical url'; - model.metadata = [{ - value: { - telemetry: { - traceUrls: ['trace url'], - }, - }, - }]; + model.canonicalUrl = 'url'; }); - assert.throw(function() { - tr.metrics.metricMapFunction(result, m, {metrics: ['sampleMetric']}); - }, Error, 'canonicalUrl "canonical url" != traceUrl "trace url"'); + tr.metrics.metricMapFunction(result, m, {metrics: ['sampleMetric']}); + assert.property(result.pairs, 'histograms'); + assert.strictEqual(result.pairs.histograms.length, 5); + assert.strictEqual(result.pairs.histograms[0].values[0], 'url'); }); function requiresDefaultCategoryMetric(histograms, model) { diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/metric_runner.py b/chromium/third_party/catapult/tracing/tracing/metrics/metric_runner.py index aa2566653fa..15cf85628a9 100644 --- a/chromium/third_party/catapult/tracing/tracing/metrics/metric_runner.py +++ b/chromium/third_party/catapult/tracing/tracing/metrics/metric_runner.py @@ -1,19 +1,24 @@ # Copyright 2016 The Chromium Authors. All rights reserved. # Use of this source code is governed by a BSD-style license that can be # found in the LICENSE file. +from __future__ import absolute_import +from __future__ import division +from __future__ import print_function + import os import sys +import six +from tracing.mre import file_handle from tracing.mre import function_handle from tracing.mre import gtest_progress_reporter +from tracing.mre import job as job_module from tracing.mre import map_runner from tracing.mre import map_single_trace -from tracing.mre import file_handle -from tracing.mre import job as job_module try: - StringTypes = basestring + StringTypes = six.string_types # pylint: disable=invalid-name except NameError: StringTypes = str diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/rendering/frame_time.html b/chromium/third_party/catapult/tracing/tracing/metrics/rendering/frame_time.html index d630d90f4da..1d6c2dd7fb6 100644 --- a/chromium/third_party/catapult/tracing/tracing/metrics/rendering/frame_time.html +++ b/chromium/third_party/catapult/tracing/tracing/metrics/rendering/frame_time.html @@ -11,6 +11,8 @@ found in the LICENSE file. <link rel="import" href="/tracing/metrics/rendering/cpu_utilization.html"> <link rel="import" href="/tracing/model/helpers/chrome_model_helper.html"> <link rel="import" href="/tracing/model/user_model/segment.html"> +<link rel="import" href="/tracing/value/diagnostics/generic_set.html"> +<link rel="import" href="/tracing/value/diagnostics/related_event_set.html"> <link rel="import" href="/tracing/value/histogram.html"> <script> @@ -81,6 +83,11 @@ tr.exportTo('tr.metrics.rendering', function() { // are shorter than half a vsync are ignored. const MIN_FRAME_LENGTH = 0.5; + // The least number of frames needed to report frame_times. + // Measurements done with very few frames tend to be unstable. + // See crbug.com/954984 for example. + const MIN_FRAME_COUNT = 10; + // In computing the number of janks, frame length differences that are at // least PAUSE_THRESHOLD vsyncs are considered pauses, not janks. const PAUSE_THRESHOLD = 20; @@ -88,6 +95,60 @@ tr.exportTo('tr.metrics.rendering', function() { const ASH_ENVIRONMENT = 'ash'; const BROWSER_ENVIRONMENT = 'browser'; + class FrameEvent { + constructor(event) { + this.event_ = event; + } + + get eventStart() { + return this.event_.start; + } + + get frameStart() { + if (this.event_.title !== DRM_EVENT) return this.event_.start; + const data = this.event_.args.data; + const TIME = tr.b.UnitScale.TIME; + return tr.b.convertUnit(data['vblank.tv_sec'], TIME.SEC, TIME.MILLI_SEC) + + tr.b.convertUnit( + data['vblank.tv_usec'], TIME.MICRO_SEC, TIME.MILLI_SEC); + } + + get event() { return this.event_; } + } + + class FrameSegment { + constructor(frameEvent, duration) { + this.frameEvent_ = frameEvent; + this.duration_ = duration; + this.segment_ = new tr.model.um.Segment(frameEvent.eventStart, duration); + this.length_ = undefined; + } + + updateLength(refreshPeriod) { + this.length_ = this.duration_ / refreshPeriod; + } + + get segment() { + return this.segment_; + } + + get boundsRange() { + return this.segment_.boundsRange; + } + + get length() { + return this.length_; + } + + get duration() { + return this.duration_; + } + + get event() { + return this.frameEvent_.event; + } + } + function getDisplayCompositorPresentationEventsExp_(modelHelper) { if (!modelHelper) return []; function findEventsFromProcess(process) { @@ -156,18 +217,21 @@ tr.exportTo('tr.metrics.rendering', function() { return legacyEvents; } - function computeFrameSegments_(timestamps, segments) { + function computeFrameSegments_(events, segments, opt_minFrameCount) { // We use filterArray for the sake of a cleaner code. The time complexity // will be O(m + n log m), where m is |timestamps| and n is |segments|. // Alternatively, we could directly loop through the timestamps and segments // here for a slightly better time complexity of O(m + n). + const minFrameCount = opt_minFrameCount || MIN_FRAME_COUNT; + const frameEvents = events.map(e => new FrameEvent(e)); const frameSegments = []; for (const segment of segments) { - const filtered = segment.boundsRange.filterArray(timestamps, x => x[0]); + const filtered = segment.boundsRange.filterArray( + frameEvents, x => x.eventStart); + if (filtered.length < minFrameCount) continue; for (let i = 1; i < filtered.length; i++) { - const duration = filtered[i][1] - filtered[i - 1][1]; - frameSegments.push( - new tr.model.um.Segment(filtered[i - 1][0], duration)); + const duration = filtered[i].frameStart - filtered[i - 1].frameStart; + frameSegments.push(new FrameSegment(filtered[i - 1], duration)); } } return frameSegments; @@ -176,7 +240,8 @@ tr.exportTo('tr.metrics.rendering', function() { function addBasicFrameTimeHistograms_(histograms, frameSegments, prefix) { // TODO(chiniforooshan): Figure out what kind of break down makes sense // here. Perhaps break down by tasks in the Viz/Browser process? - const frameTimes = frameSegments.map(x => x.duration); + const frameTimes = (frameSegments.length === 0) ? + [0] : frameSegments.map(x => x.duration); histograms.createHistogram( `${prefix}frame_times`, tr.b.Unit.byName.timeDurationInMs_smallerIsBetter, @@ -195,33 +260,27 @@ tr.exportTo('tr.metrics.rendering', function() { }); } - function addFrameTimeHistograms(histograms, model, segments) { + function addFrameTimeHistograms(histograms, model, segments, + opt_minFrameCount) { + const minFrameCount = opt_minFrameCount || MIN_FRAME_COUNT; const modelHelper = model.getOrCreateHelper( tr.model.helpers.ChromeModelHelper); const events = getDisplayCompositorPresentationEvents_(modelHelper); if (!events) return; - addFrameTimeHistogramsHelper(histograms, model, segments, events, '', true); + addFrameTimeHistogramsHelper(histograms, model, segments, events, '', true, + minFrameCount); const eventsExp = getDisplayCompositorPresentationEventsExp_(modelHelper); if (eventsExp && eventsExp.length > 0) { addFrameTimeHistogramsHelper(histograms, model, segments, eventsExp, - 'exp_'); + 'exp_', minFrameCount); } } function addFrameTimeHistogramsHelper( - histograms, model, segments, events, prefix, addCpuMetrics) { - // Presentation Timestamps should be sorted. - const timestamps = events.map( - event => [event.start, - event.title !== DRM_EVENT ? event.start : ( - tr.b.convertUnit( - event.args.data['vblank.tv_sec'], - tr.b.UnitScale.TIME.SEC, tr.b.UnitScale.TIME.MILLI_SEC) + - tr.b.convertUnit( - event.args.data['vblank.tv_usec'], - tr.b.UnitScale.TIME.MICRO_SEC, tr.b.UnitScale.TIME.MILLI_SEC))] - ); - const frameSegments = computeFrameSegments_(timestamps, segments); + histograms, model, segments, events, prefix, addCpuMetrics, + minFrameCount) { + const frameSegments = computeFrameSegments_(events, segments, + minFrameCount); addBasicFrameTimeHistograms_(histograms, frameSegments, prefix + ''); if (addCpuMetrics) { @@ -241,12 +300,14 @@ tr.exportTo('tr.metrics.rendering', function() { } const refreshPeriod = getRefreshPeriod(model, - frameSegments.map(s => s.boundsRange)); - let frameLengths = frameSegments.map(x => x.duration / refreshPeriod); - frameLengths = frameLengths.filter(length => length >= MIN_FRAME_LENGTH); + frameSegments.map(fs => fs.boundsRange)); + frameSegments.forEach(fs => fs.updateLength(refreshPeriod)); + const validFrames = frameSegments.filter( + fs => fs.length >= MIN_FRAME_LENGTH); const totalFrameDuration = - tr.b.math.Statistics.sum(frameSegments, x => x.duration); - addJankCountHistograms(histograms, frameLengths, prefix); + tr.b.math.Statistics.sum(frameSegments, fs => fs.duration); + addJankCountHistograms(histograms, validFrames, prefix); + const frameLengths = validFrames.map(frame => frame.length); histograms.createHistogram( prefix + 'frame_lengths', tr.b.Unit.byName.unitlessNumber_smallerIsBetter, @@ -266,30 +327,39 @@ tr.exportTo('tr.metrics.rendering', function() { }); } - function addUIFrameTimeHistograms(histograms, model, segments) { + function addUIFrameTimeHistograms(histograms, model, segments, + opt_minFrameCount) { + const minFrameCount = opt_minFrameCount || MIN_FRAME_COUNT; const events = getUIPresentationEvents_( model.getOrCreateHelper(tr.model.helpers.ChromeModelHelper)); if (events.length === 0) return; // Presentation Timestamps should be sorted. - const timestamps = events.map(event => [event.start, event.start]); - const frameSements = computeFrameSegments_(timestamps, segments); - addBasicFrameTimeHistograms_(histograms, frameSements, 'ui_'); + const frameSegments = computeFrameSegments_(events, segments, + minFrameCount); + addBasicFrameTimeHistograms_(histograms, frameSegments, 'ui_'); } - function addJankCountHistograms(histograms, frameLengths, prefix) { - let jankCount = 0; - for (let i = 1; i < frameLengths.length; i++) { - if (frameLengths[i] < MIN_FRAME_LENGTH) continue; + function addJankCountHistograms(histograms, validFrames, prefix) { + const jankEvents = []; + for (let i = 1; i < validFrames.length; i++) { const change = - Math.round((frameLengths[i] - frameLengths[i - 1])); - if (change > 0 && change < PAUSE_THRESHOLD) jankCount++; + Math.round((validFrames[i].length - validFrames[i - 1].length)); + if (change > 0 && change < PAUSE_THRESHOLD) { + jankEvents.push(validFrames[i].event); + } } + const jankCount = jankEvents.length; - histograms.createHistogram( + const diagnostics = new tr.v.d.DiagnosticMap(); + diagnostics.set('events', new tr.v.d.RelatedEventSet(jankEvents)); + diagnostics.set('timestamps', + new tr.v.d.GenericSet(jankEvents.map(e => e.start))); + + const histogram = histograms.createHistogram( prefix + 'jank_count', tr.b.Unit.byName.count_smallerIsBetter, - jankCount, + { value: jankCount, diagnostics}, { description: 'Number of changes in frame rate.', summaryOptions: {}, }); diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/rendering/frame_time_test.html b/chromium/third_party/catapult/tracing/tracing/metrics/rendering/frame_time_test.html index 0247cdfd0ed..dda043ab9be 100644 --- a/chromium/third_party/catapult/tracing/tracing/metrics/rendering/frame_time_test.html +++ b/chromium/third_party/catapult/tracing/tracing/metrics/rendering/frame_time_test.html @@ -34,10 +34,11 @@ tr.b.unittest.testSuite(function() { }); const histograms = new tr.v.HistogramSet(); tr.metrics.rendering.addFrameTimeHistograms( - histograms, model, [new tr.model.um.Segment(0, 20)]); + histograms, model, [new tr.model.um.Segment(0, 20)], 1); - // The fourth frame is outside the interaction perdiod and should be - // discarded. The durations between the remaining three frames are 1 and 17. + // The last frame is outside the interaction period and should be + // discarded. The durations between the remaining three frames are + // 1 and 17. let hist = histograms.getHistogramNamed('frame_times'); assert.closeTo(1, hist.min, 1e-6); assert.closeTo(17, hist.max, 1e-6); @@ -66,7 +67,7 @@ tr.b.unittest.testSuite(function() { }); const histograms = new tr.v.HistogramSet(); tr.metrics.rendering.addFrameTimeHistograms( - histograms, model, [new tr.model.um.Segment(0, 6)]); + histograms, model, [new tr.model.um.Segment(0, 6)], 1); // When computing frame times from DRM events, VBlank times should be used. const hist = histograms.getHistogramNamed('frame_times'); @@ -96,7 +97,7 @@ tr.b.unittest.testSuite(function() { }); const histograms = new tr.v.HistogramSet(); tr.metrics.rendering.addFrameTimeHistograms( - histograms, model, [new tr.model.um.Segment(0, 6)]); + histograms, model, [new tr.model.um.Segment(0, 6)], 1); // Data from the Surface Flinger process should be used if it exists. const hist = histograms.getHistogramNamed('frame_times'); @@ -135,7 +136,7 @@ tr.b.unittest.testSuite(function() { }); const histograms = new tr.v.HistogramSet(); tr.metrics.rendering.addFrameTimeHistograms( - histograms, model, [new tr.model.um.Segment(0, 20)]); + histograms, model, [new tr.model.um.Segment(0, 20)], 5); // Frame lengths are 3/3, 6/3, 3/3, and 1/3. The last one is too small and // should be filtered out. So, the final result is [1, 2, 1]. @@ -176,7 +177,7 @@ tr.b.unittest.testSuite(function() { }); const histograms = new tr.v.HistogramSet(); tr.metrics.rendering.addFrameTimeHistograms( - histograms, model, [new tr.model.um.Segment(0, 20)]); + histograms, model, [new tr.model.um.Segment(0, 20)], 5); // We have 3 frames (ignoring the very short ones) in 13 milliseconds. const hist = histograms.getHistogramNamed('avg_surface_fps'); @@ -216,7 +217,7 @@ tr.b.unittest.testSuite(function() { }); const histograms = new tr.v.HistogramSet(); tr.metrics.rendering.addFrameTimeHistograms( - histograms, model, [new tr.model.um.Segment(0, 500)]); + histograms, model, [new tr.model.um.Segment(0, 500)], 5); // There is 1 jank in [1, 1, 2, 1, 10]. The last long frame is a pause. const hist = histograms.getHistogramNamed('jank_count'); @@ -261,7 +262,7 @@ tr.b.unittest.testSuite(function() { }); const histograms = new tr.v.HistogramSet(); tr.metrics.rendering.addFrameTimeHistograms( - histograms, model, [new tr.model.um.Segment(0, 300)]); + histograms, model, [new tr.model.um.Segment(0, 300)], 5); // There is 1 jank in [1, 1, 2, 1, 10]. The last long frame is a pause. const hist = histograms.getHistogramNamed('jank_count'); @@ -285,9 +286,9 @@ tr.b.unittest.testSuite(function() { }); const histograms = new tr.v.HistogramSet(); tr.metrics.rendering.addUIFrameTimeHistograms( - histograms, model, [new tr.model.um.Segment(0, 20)]); + histograms, model, [new tr.model.um.Segment(0, 20)], 1); - // The fourth frame is outside the interaction perdiod and should be + // The fourth frame is outside the interaction period and should be // discarded. The durations between the remaining three frames are 1 and 17. let hist = histograms.getHistogramNamed('ui_frame_times'); assert.closeTo(1, hist.min, 1e-6); @@ -333,7 +334,7 @@ tr.b.unittest.testSuite(function() { }); const histograms = new tr.v.HistogramSet(); tr.metrics.rendering.addUIFrameTimeHistograms( - histograms, model, [new tr.model.um.Segment(0, 20)]); + histograms, model, [new tr.model.um.Segment(0, 20)], 1); // The 3rd frame is from 'browser' and should be discarded. Remaining // timestamps are 1, 2, and 19 which indicate frame times of 1 and 17. @@ -342,5 +343,49 @@ tr.b.unittest.testSuite(function() { assert.closeTo(17, hist.max, 1e-6); assert.closeTo(2, hist.numValues, 1e-6); }); + + test('frameTimesCountLessThanMinFrameCount', function() { + const model = tr.c.TestUtils.newModel((model) => { + const browserMain = model.getOrCreateProcess(0).getOrCreateThread(0); + browserMain.name = 'CrBrowserMain'; + for (let i = 1; i < 10; i++) { + browserMain.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx( + { title: 'BenchmarkInstrumentation::DisplayRenderingStats', + start: i, end: i })); + } + }); + const histograms = new tr.v.HistogramSet(); + tr.metrics.rendering.addFrameTimeHistograms( + histograms, model, [new tr.model.um.Segment(0, 20)]); + + // There is 9 frames but the min_frame_count is 10. So the frame_times + // should be empty as a result of not having enough data points. + const hist = histograms.getHistogramNamed('frame_times'); + assert.strictEqual(hist.min, 0); + assert.strictEqual(hist.max, 0); + assert.strictEqual(hist.average, 0); + }); + + test('frameTimesCountEqualToMinFrameCount', function() { + const model = tr.c.TestUtils.newModel((model) => { + const browserMain = model.getOrCreateProcess(0).getOrCreateThread(0); + browserMain.name = 'CrBrowserMain'; + for (let i = 1; i <= 10; i++) { + browserMain.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx( + { title: 'BenchmarkInstrumentation::DisplayRenderingStats', + start: i, end: i })); + } + }); + const histograms = new tr.v.HistogramSet(); + tr.metrics.rendering.addFrameTimeHistograms( + histograms, model, [new tr.model.um.Segment(0, 20)]); + + // There is 10 frames and the min_frame_count is 10. So the 10 frames each + // having duration of 1 will be reported. + const hist = histograms.getHistogramNamed('frame_times'); + assert.closeTo(1, hist.min, 1e-6); + assert.closeTo(1, hist.max, 1e-6); + assert.closeTo(1, hist.average, 1e-6); + }); }); </script> diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/rendering/rendering_metric.html b/chromium/third_party/catapult/tracing/tracing/metrics/rendering/rendering_metric.html index 134952a8d75..24697acd1c1 100644 --- a/chromium/third_party/catapult/tracing/tracing/metrics/rendering/rendering_metric.html +++ b/chromium/third_party/catapult/tracing/tracing/metrics/rendering/rendering_metric.html @@ -25,7 +25,10 @@ tr.exportTo('tr.metrics.rendering', function() { tr.model.helpers.ChromeModelHelper); if (!chromeHelper) return; - const segments = chromeHelper.telemetryHelper.segments; + let segments = chromeHelper.telemetryHelper.irSegments; + if (segments.length === 0) { + segments = chromeHelper.telemetryHelper.animationSegments; + } if (segments.length > 0) { tr.metrics.rendering.addFrameTimeHistograms(histograms, model, segments); tr.metrics.rendering.addImageDecodeTimeHistograms(histograms, model, diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/rendering/rendering_metric_test.html b/chromium/third_party/catapult/tracing/tracing/metrics/rendering/rendering_metric_test.html index 77e0a2d9dd1..1d30078252a 100644 --- a/chromium/third_party/catapult/tracing/tracing/metrics/rendering/rendering_metric_test.html +++ b/chromium/third_party/catapult/tracing/tracing/metrics/rendering/rendering_metric_test.html @@ -19,40 +19,27 @@ tr.b.unittest.testSuite(function() { rendererMain.name = 'CrRendererMain'; rendererMain.asyncSliceGroup.push( tr.c.TestUtils.newAsyncSliceNamed( - 'Interaction.Gesture_LoadAction', 10, 10)); + 'Interaction.Gesture_LoadAction', 10, 20)); const browserMain = model.getOrCreateProcess(0).getOrCreateThread(0); browserMain.name = 'CrBrowserMain'; browserMain.asyncSliceGroup.push( tr.c.TestUtils.newAsyncSliceNamed( - 'SyntheticGestureController::running', 0, 5)); - browserMain.asyncSliceGroup.push( - tr.c.TestUtils.newAsyncSliceNamed( - 'SyntheticGestureController::running', 10, 5)); - // Add four swap buffer events, at times 1, 2, 11, 13, 16 - browserMain.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx( - { title: 'BenchmarkInstrumentation::DisplayRenderingStats', - start: 1, end: 1 })); - browserMain.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx( - { title: 'BenchmarkInstrumentation::DisplayRenderingStats', - start: 2, end: 2 })); - browserMain.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx( - { title: 'BenchmarkInstrumentation::DisplayRenderingStats', - start: 11, end: 11 })); - browserMain.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx( - { title: 'BenchmarkInstrumentation::DisplayRenderingStats', - start: 13, end: 13 })); - browserMain.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx( - { title: 'BenchmarkInstrumentation::DisplayRenderingStats', - start: 16, end: 16 })); + 'SyntheticGestureController::running', 5, 30)); + // Add 23 swap buffer events, at times 7, 9, 11, 13, 15 ..., 29, 31 + for (let i = 7; i <= 31; i += 2) { + browserMain.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx( + { title: 'BenchmarkInstrumentation::DisplayRenderingStats', + start: i, end: i })); + } }); const histograms = new tr.v.HistogramSet(); tr.metrics.rendering.renderingMetric(histograms, model); - // The gesture interaction record should be adjusted to [10, 15]. So, the - // first two frames and the fifth frame are outside the interaction record - // and should be discarded. The remaining frames are 11 and 13 which result - // in a single frame time of 2 = 13 - 11. + // The gesture interaction record should be adjusted to [10, 30]. So, the + // first two frames and the last frame are outside the interaction record + // and should be discarded. The remaining frames are 11 to 29 which result + // in 9 frame times of 2. const hist = histograms.getHistogramNamed('frame_times'); assert.closeTo(2, hist.min, 1e-6); assert.closeTo(2, hist.max, 2e-6); diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/system_health/expected_queueing_time_metric.html b/chromium/third_party/catapult/tracing/tracing/metrics/system_health/expected_queueing_time_metric.html index b9ef3de7ebd..62c12e9271a 100644 --- a/chromium/third_party/catapult/tracing/tracing/metrics/system_health/expected_queueing_time_metric.html +++ b/chromium/third_party/catapult/tracing/tracing/metrics/system_health/expected_queueing_time_metric.html @@ -71,10 +71,6 @@ tr.exportTo('tr.metrics.sh', function() { * of size 500ms (WINDOW_SIZE_MS). The function produces four Histograms: * - total:500ms_window:renderer_eqt, * - total:500ms_window:renderer_eqt_cpu, - * - interactive:500ms_window:renderer_eqt. - * - interactive:500ms_window:renderer_eqt_cpu. - * The 'total' histograms are computed for the whole trace. The 'interactive' - * histograms are computed for the time while the page is interactive. * The 'cpu' histograms use the CPU time of the events instead of the wall- * clock times. Each renderer process adds one sample to the histograms. */ @@ -82,17 +78,10 @@ tr.exportTo('tr.metrics.sh', function() { const chromeHelper = model.getOrCreateHelper( tr.model.helpers.ChromeModelHelper); const rendererHelpers = Object.values(chromeHelper.rendererHelpers); - const rendererToInteractiveTimestamps = - tr.e.chrome.getInteractiveTimestamps(model); addExpectedQueueingTimeMetric_( 'renderer_eqt', event => {return {start: event.start, duration: event.duration};}, - false, rendererHelpers, rendererToInteractiveTimestamps, histograms, - model); - addExpectedQueueingTimeMetric_( - 'renderer_eqt_cpu', - event => {return {start: event.cpuStart, duration: event.cpuDuration};}, - true, rendererHelpers, rendererToInteractiveTimestamps, histograms, + false, rendererHelpers, histograms, model); } @@ -111,7 +100,7 @@ tr.exportTo('tr.metrics.sh', function() { * a map from renderer pid to an array of interactive timestamps. */ function addExpectedQueueingTimeMetric_(eqtName, getEventTimes, isCpuTime, - rendererHelpers, rendererToInteractiveTimestamps, histograms, model) { + rendererHelpers, histograms, model) { /** * Extracts tasks for EQT computation from the given renderer. * A task is a pair of {start, end} times. @@ -133,11 +122,6 @@ tr.exportTo('tr.metrics.sh', function() { `total:${WINDOW_SIZE_MS}ms_window:${eqtName}`, `The maximum EQT in a ${WINDOW_SIZE_MS}ms sliding window` + ' for a given renderer'); - const interactiveHistogram = getOrCreateHistogram_( - histograms, - `interactive:${WINDOW_SIZE_MS}ms_window:${eqtName}`, - `The maximum EQT in a ${WINDOW_SIZE_MS}ms sliding window` + - ' for a given renderer while the page is interactive'); for (const rendererHelper of rendererHelpers) { if (rendererHelper.isChromeTracingUI) continue; // Renderers with lifetime smaller than WINDOW_SIZE_MS do not have @@ -145,13 +129,11 @@ tr.exportTo('tr.metrics.sh', function() { if (rendererHelper.mainThread.bounds.duration < WINDOW_SIZE_MS) continue; const tasks = getTasks(rendererHelper); - const {totalBreakdown, interactiveBreakdown} = getV8Contribution_( + const totalBreakdown = getV8Contribution_( eqtName, getEventTimes, isCpuTime, totalHistogram, - interactiveHistogram, - rendererToInteractiveTimestamps, histograms, rendererHelper, model); @@ -160,21 +142,6 @@ tr.exportTo('tr.metrics.sh', function() { rendererHelper.mainThread.bounds.min, rendererHelper.mainThread.bounds.max, WINDOW_SIZE_MS, tasks), {v8: totalBreakdown}); - const interactiveTimestamps = - rendererToInteractiveTimestamps.get(rendererHelper.pid); - if (interactiveTimestamps.length === 0) continue; - if (interactiveTimestamps.length > 1) { - // TODO(ulan): Support multiple interactive time windows when - // https://crbug.com/692112 is fixed. - continue; - } - const interactiveWindow = - tr.b.math.Range.fromExplicitRange(interactiveTimestamps[0], Infinity) - .findIntersection(rendererHelper.mainThread.bounds); - interactiveHistogram.addSample( - tr.e.chrome.maxExpectedQueueingTimeInSlidingWindow( - interactiveWindow.min, interactiveWindow.max, - WINDOW_SIZE_MS, tasks), {v8: interactiveBreakdown}); } } @@ -187,34 +154,25 @@ tr.exportTo('tr.metrics.sh', function() { * - removing subevents shrinks a task by shifting its end time closer to * the start time. The start time does not change. * - * Similar to the expectedQueueingTime this function computes two histograms: - * total and interactive. For example: - * - total:500ms_window:renderer_eqt:v8, - * - interactive:500ms_window:renderer_eqt:v8. - * Each renderer process adds one sample to the histograms. - * Both histograms are added to the given histogram set. + * Example of an added histogram: + * - total:500ms_window:renderer_eqt:v8 + * Each renderer process adds one sample to the histogram. * * @param {!string} eqtName the metric name part of the histogram name. * @param {!EventTimesCallback} getEventTimes. * @param {boolean} isCpuTime * @param {!tr.v.Histogram} totalEqtHistogram - * @param {!tr.v.Histogram} interactiveEqtHistogram - * @param {!Map.<number, Array.<number>>} rendererToInteractiveTimestamps - * a map from renderer pid to an array of interactive timestamps. * @param {!tr.v.HistogramSet} histograms * @param {!tr.model.helpers.ChromeRendererHelper} rendererHelper * @param {!tr.model.Model} model - * @return {{totalBreakdown: !tr.v.d.Breakdown, - * interactiveBreakdown: !tr.v.d.Breakdown}} + * @return {!tr.v.d.Breakdown} */ function getV8Contribution_( - eqtName, getEventTimes, isCpuTime, totalEqtHistogram, - interactiveEqtHistogram, rendererToInteractiveTimestamps, histograms, + eqtName, getEventTimes, isCpuTime, totalEqtHistogram, histograms, rendererHelper, model) { - if (!model.categories.includes('v8')) return {}; + if (!model.categories.includes('v8')) return null; const totalBreakdown = new tr.v.d.Breakdown(); - const interactiveBreakdown = new tr.v.d.Breakdown(); // Include task extractors that use tracing. const eventNamesWithTaskExtractors = getV8EventNamesWithTaskExtractors_(getEventTimes); @@ -233,12 +191,6 @@ tr.exportTo('tr.metrics.sh', function() { totalNames = new tr.v.d.RelatedNameMap(); totalEqtHistogram.diagnostics.set('v8', totalNames); } - let interactiveNames = interactiveEqtHistogram.diagnostics.get('v8'); - if (!interactiveNames) { - interactiveNames = new tr.v.d.RelatedNameMap(); - interactiveEqtHistogram.diagnostics.set('v8', interactiveNames); - } - for (const [eventName, getTasks] of eventNamesWithTaskExtractors) { const totalHistogram = getOrCreateHistogram_(histograms, `total:${WINDOW_SIZE_MS}ms_window:${eqtName}:${eventName}`, @@ -246,14 +198,6 @@ tr.exportTo('tr.metrics.sh', function() { ' for a given renderer. It is computed as the maximum EQT in' + ` a ${WINDOW_SIZE_MS}ms sliding window after shrinking top-level` + ` tasks to contain only ${eventName} subevents`); - const interactiveHistogram = getOrCreateHistogram_(histograms, - `interactive:${WINDOW_SIZE_MS}ms_window:${eqtName}:${eventName}`, - `Contribution to the expected queueing time by ${eventName}` + - ' for a given renderer while the page is interactive. It is' + - ` computed as the maximum EQT in a ${WINDOW_SIZE_MS}ms sliding` + - ' window after shrinking top-level tasks to contain only' + - ` ${eventName} subevents`); - const tasks = getTasks(rendererHelper); const totalSample = tr.e.chrome.maxExpectedQueueingTimeInSlidingWindow( rendererHelper.mainThread.bounds.min, @@ -262,27 +206,8 @@ tr.exportTo('tr.metrics.sh', function() { totalHistogram.addSample(totalSample); totalBreakdown.set(eventName, totalSample); totalNames.set(eventName, totalHistogram.name); - - const interactiveTimestamps = - rendererToInteractiveTimestamps.get(rendererHelper.pid); - if (interactiveTimestamps.length === 0) continue; - if (interactiveTimestamps.length > 1) { - // TODO(ulan): Support multiple interactive time windows when - // https://crbug.com/692112 is fixed. - continue; - } - const interactiveWindow = - tr.b.math.Range.fromExplicitRange(interactiveTimestamps[0], Infinity) - .findIntersection(rendererHelper.mainThread.bounds); - const interactiveSample = - tr.e.chrome.maxExpectedQueueingTimeInSlidingWindow( - interactiveWindow.min, interactiveWindow.max, - WINDOW_SIZE_MS, tasks); - interactiveHistogram.addSample(interactiveSample); - interactiveBreakdown.set(eventName, interactiveSample); - interactiveNames.set(eventName, interactiveHistogram.name); } - return {totalBreakdown, interactiveBreakdown}; + return totalBreakdown; } /** @@ -355,26 +280,6 @@ tr.exportTo('tr.metrics.sh', function() { [ 'v8:gc', taskExtractor(tr.metrics.v8.utils.isGarbageCollectionEvent) - ], - [ - 'v8:gc:full-mark-compactor', - taskExtractor(tr.metrics.v8.utils.isFullMarkCompactorEvent) - ], - [ - 'v8:gc:incremental-marking', - taskExtractor(tr.metrics.v8.utils.isIncrementalMarkingEvent) - ], - [ - 'v8:gc:latency-mark-compactor', - taskExtractor(tr.metrics.v8.utils.isLatencyMarkCompactorEvent) - ], - [ - 'v8:gc:memory-mark-compactor', - taskExtractor(tr.metrics.v8.utils.isMemoryMarkCompactorEvent) - ], - [ - 'v8:gc:scavenger', - taskExtractor(tr.metrics.v8.utils.isScavengerEvent) ] ]); } @@ -440,16 +345,6 @@ tr.exportTo('tr.metrics.sh', function() { getEventTimes, tr.metrics.v8.utils.isCompileOptimizeRCSCategory, rendererHelper)); - extractors.set('v8:compile:parse_rcs', - rendererHelper => extractTaskRCS( - getEventTimes, - tr.metrics.v8.utils.isCompileParseRCSCategory, - rendererHelper)); - extractors.set('v8:compile:compile-unoptimize_rcs', - rendererHelper => extractTaskRCS( - getEventTimes, - tr.metrics.v8.utils.isCompileUnoptimizeRCSCategory, - rendererHelper)); return extractors; } diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/system_health/expected_queueing_time_metric_test.html b/chromium/third_party/catapult/tracing/tracing/metrics/system_health/expected_queueing_time_metric_test.html index b300c523964..af41d9a7891 100644 --- a/chromium/third_party/catapult/tracing/tracing/metrics/system_health/expected_queueing_time_metric_test.html +++ b/chromium/third_party/catapult/tracing/tracing/metrics/system_health/expected_queueing_time_metric_test.html @@ -16,47 +16,10 @@ found in the LICENSE file. 'use strict'; tr.b.unittest.testSuite(function() { - function addInteractiveTimestamp(rendererProcess, mainThread, timestamp) { - mainThread.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ - cat: 'blink.user_timing', - title: 'navigationStart', - start: timestamp, - duration: 0.0, - args: {frame: '0xdeadbeef'} - })); - mainThread.asyncSliceGroup.push(tr.c.TestUtils.newSliceEx({ - cat: 'disabled-by-default-network', - title: 'ResourceLoad', - start: timestamp, - duration: 5.0, - })); - rendererProcess.objects.addSnapshot( - 'ptr', 'loading', 'FrameLoader', timestamp, { - isLoadingMainFrame: true, - frame: {id_ref: '0xdeadbeef'}, - documentLoaderURL: 'http://example.com' - }); - mainThread.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ - cat: 'loading', - title: 'firstMeaningfulPaintCandidate', - start: timestamp + 1, - duration: 0.0, - args: {frame: '0xdeadbeef'} - })); - mainThread.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ - cat: 'blink.user_timing', - title: 'domContentLoadedEventEnd', - start: timestamp + 1, - duration: 0.0, - args: {frame: '0xdeadbeef'} - })); - } - test('expectedQueueingTime', function() { const model = tr.e.chrome.ChromeTestUtils.newChromeModel(function(model) { const rendererProcess = model.rendererProcess; const mainThread = model.rendererMain; - addInteractiveTimestamp(rendererProcess, mainThread, 200); mainThread.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ cat: 'toplevel', title: tr.e.chrome.SCHEDULER_TOP_LEVEL_TASK_TITLE, @@ -84,35 +47,18 @@ tr.b.unittest.testSuite(function() { }); const histograms = new tr.v.HistogramSet(); tr.metrics.sh.expectedQueueingTimeMetric(histograms, model); - const interactiveEqt = histograms.getHistogramNamed( - 'interactive:500ms_window:renderer_eqt'); - assert.strictEqual(0.1, interactiveEqt.average); const totalEqt = histograms.getHistogramNamed( 'total:500ms_window:renderer_eqt'); assert.strictEqual(10, totalEqt.average); - const interactiveEqtCpu = histograms.getHistogramNamed( - 'interactive:500ms_window:renderer_eqt_cpu'); - assert.strictEqual(0.025, interactiveEqtCpu.average); - const totalEqtCpu = histograms.getHistogramNamed( - 'total:500ms_window:renderer_eqt_cpu'); - assert.strictEqual(2.5, totalEqtCpu.average); }); - test('expectedQueueingTime_noInteractive', function() { + test('expectedQueueingTime_multipleRenderersAggregates', function() { const model = tr.e.chrome.ChromeTestUtils.newChromeModel(function(model) { const rendererProcess = model.rendererProcess; const mainThread = model.rendererMain; mainThread.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ cat: 'toplevel', title: tr.e.chrome.SCHEDULER_TOP_LEVEL_TASK_TITLE, - start: 0, - duration: 100, - cpuStart: 0, - cpuDuration: 100, - })); - mainThread.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ - cat: 'toplevel', - title: tr.e.chrome.SCHEDULER_TOP_LEVEL_TASK_TITLE, start: 3000, duration: 10, cpuStart: 3000, @@ -126,87 +72,17 @@ tr.b.unittest.testSuite(function() { cpuStart: 9000, cpuDuration: 10, })); - }); - const histograms = new tr.v.HistogramSet(); - tr.metrics.sh.expectedQueueingTimeMetric(histograms, model); - const interactiveEQT = histograms.getHistogramNamed( - 'interactive:500ms_window:renderer_eqt'); - assert.strictEqual(0, interactiveEQT.numValues); - }); - - test('expectedQueueingTime_multipleInteractive', function() { - const model = tr.e.chrome.ChromeTestUtils.newChromeModel(function(model) { - const rendererProcess = model.rendererProcess; - const mainThread = model.rendererMain; - addInteractiveTimestamp(rendererProcess, mainThread, 200); - addInteractiveTimestamp(rendererProcess, mainThread, 6000); - mainThread.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ - cat: 'toplevel', - title: tr.e.chrome.SCHEDULER_TOP_LEVEL_TASK_TITLE, - start: 0, - duration: 100, - cpuStart: 0, - cpuDuration: 100, - })); - mainThread.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ - cat: 'toplevel', - title: tr.e.chrome.SCHEDULER_TOP_LEVEL_TASK_TITLE, - start: 3000, - duration: 10, - cpuStart: 3000, - cpuDuration: 10, - })); - mainThread.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ - cat: 'toplevel', - title: tr.e.chrome.SCHEDULER_TOP_LEVEL_TASK_TITLE, - start: 12000, - duration: 10, - cpuStart: 9000, - cpuDuration: 10, - })); - }); - const histograms = new tr.v.HistogramSet(); - tr.metrics.sh.expectedQueueingTimeMetric(histograms, model); - const interactiveEQT = histograms.getHistogramNamed( - 'interactive:500ms_window:renderer_eqt'); - // TODO(ulan): Support multiple interactive time windows when - // https://crbug.com/692112 is fixed. - assert.strictEqual(0, interactiveEQT.numValues); - }); - - test('expectedQueueingTime_multipleRenderersAggregates', function() { - const model = tr.e.chrome.ChromeTestUtils.newChromeModel(function(model) { - const rendererProcess = model.rendererProcess; - const mainThread = model.rendererMain; - addInteractiveTimestamp(rendererProcess, mainThread, 200); - mainThread.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ - cat: 'toplevel', - title: tr.e.chrome.SCHEDULER_TOP_LEVEL_TASK_TITLE, - start: 0, - duration: 100, - cpuStart: 0, - cpuDuration: 100, - })); - mainThread.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ + const rendererProcess2 = model.getOrCreateProcess(1985); + const mainThread2 = rendererProcess2.getOrCreateThread(2); + mainThread2.name = 'CrRendererMain'; + mainThread2.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ cat: 'toplevel', title: tr.e.chrome.SCHEDULER_TOP_LEVEL_TASK_TITLE, start: 3000, - duration: 10, + duration: 0, cpuStart: 3000, - cpuDuration: 10, - })); - mainThread.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ - cat: 'toplevel', - title: tr.e.chrome.SCHEDULER_TOP_LEVEL_TASK_TITLE, - start: 9000, - duration: 10, - cpuStart: 9000, - cpuDuration: 10, + cpuDuration: 0, })); - const rendererProcess2 = model.getOrCreateProcess(1985); - const mainThread2 = rendererProcess2.getOrCreateThread(2); - mainThread2.name = 'CrRendererMain'; - addInteractiveTimestamp(rendererProcess2, mainThread2, 200); mainThread2.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ cat: 'toplevel', title: tr.e.chrome.SCHEDULER_TOP_LEVEL_TASK_TITLE, @@ -219,7 +95,7 @@ tr.b.unittest.testSuite(function() { const histograms = new tr.v.HistogramSet(); tr.metrics.sh.expectedQueueingTimeMetric(histograms, model); const eqt = histograms.getHistogramNamed( - 'interactive:500ms_window:renderer_eqt'); + 'total:500ms_window:renderer_eqt'); assert.strictEqual(0.05, eqt.average); }); @@ -227,23 +103,6 @@ tr.b.unittest.testSuite(function() { const model = tr.e.chrome.ChromeTestUtils.newChromeModel(function(model) { const rendererProcess = model.rendererProcess; const mainThread = model.rendererMain; - addInteractiveTimestamp(rendererProcess, mainThread, 200); - mainThread.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ - cat: 'toplevel', - title: tr.e.chrome.SCHEDULER_TOP_LEVEL_TASK_TITLE, - start: 0, - duration: 100, - cpuStart: 0, - cpuDuration: 100, - })); - mainThread.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ - cat: 'v8', - title: 'V8.GCFinalizeMC', - start: 50, - duration: 50, - cpuStart: 50, - cpuDuration: 50, - })); mainThread.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ cat: 'toplevel', title: tr.e.chrome.SCHEDULER_TOP_LEVEL_TASK_TITLE, @@ -280,35 +139,18 @@ tr.b.unittest.testSuite(function() { }); const histograms = new tr.v.HistogramSet(); tr.metrics.sh.expectedQueueingTimeMetric(histograms, model); - const eqt = histograms.getHistogramNamed( - 'interactive:500ms_window:renderer_eqt'); - assert.strictEqual('interactive:500ms_window:renderer_eqt:v8', + 'total:500ms_window:renderer_eqt'); + assert.strictEqual('total:500ms_window:renderer_eqt:v8', eqt.diagnostics.get('v8').get('v8')); assert.strictEqual(0.025, eqt.getBinForValue(0.1).diagnosticMaps[0].get('v8').get('v8')); - - const eqtCpu = histograms.getHistogramNamed( - 'interactive:500ms_window:renderer_eqt_cpu'); - assert.strictEqual('interactive:500ms_window:renderer_eqt_cpu:v8', - eqtCpu.diagnostics.get('v8').get('v8')); - assert.strictEqual(0.025, - eqtCpu.getBinForValue(0.1).diagnosticMaps[0].get('v8').get('v8')); }); test('expectedQueueingTimeRCS', function() { const model = tr.e.chrome.ChromeTestUtils.newChromeModel(function(model) { const rendererProcess = model.rendererProcess; const mainThread = model.rendererMain; - addInteractiveTimestamp(rendererProcess, mainThread, 200); - mainThread.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ - cat: 'toplevel', - title: tr.e.chrome.SCHEDULER_TOP_LEVEL_TASK_TITLE, - start: 0, - duration: 100, - cpuStart: 0, - cpuDuration: 100, - })); mainThread.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ cat: 'v8', title: 'V8.newInstance', @@ -393,17 +235,6 @@ tr.b.unittest.testSuite(function() { eqt.diagnostics.get('v8').get('v8:compile:optimize_rcs')); assert.strictEqual(1.6, eqt.getBinForValue(10).diagnosticMaps[0].get( 'v8').get('v8:compile:optimize_rcs')); - - assert.strictEqual('total:500ms_window:renderer_eqt:v8:compile:parse_rcs', - eqt.diagnostics.get('v8').get('v8:compile:parse_rcs')); - assert.strictEqual(0.1, eqt.getBinForValue(10).diagnosticMaps[0].get( - 'v8').get('v8:compile:parse_rcs')); - - assert.strictEqual( - 'total:500ms_window:renderer_eqt:v8:compile:compile-unoptimize_rcs', - eqt.diagnostics.get('v8').get('v8:compile:compile-unoptimize_rcs')); - assert.strictEqual(0.4, eqt.getBinForValue(10).diagnosticMaps[0].get( - 'v8').get('v8:compile:compile-unoptimize_rcs')); }); }); </script> diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/system_health/loading_metric.html b/chromium/third_party/catapult/tracing/tracing/metrics/system_health/loading_metric.html index dcc75923c42..49d9ecf28ed 100644 --- a/chromium/third_party/catapult/tracing/tracing/metrics/system_health/loading_metric.html +++ b/chromium/third_party/catapult/tracing/tracing/metrics/system_health/loading_metric.html @@ -7,7 +7,9 @@ found in the LICENSE file. <link rel="import" href="/tracing/base/category_util.html"> <link rel="import" href="/tracing/base/math/statistics.html"> +<link rel="import" href="/tracing/extras/chrome/cc/display_item_list.html"> <link rel="import" href="/tracing/extras/chrome/event_finder_utils.html"> +<link rel="import" href="/tracing/extras/chrome/largest_contentful_paint.html"> <link rel="import" href="/tracing/extras/chrome/time_to_interactive.html"> <link rel="import" href="/tracing/metrics/metric_registry.html"> <link rel="import" href="/tracing/metrics/system_health/breakdown_tree_helpers.html"> @@ -272,6 +274,182 @@ tr.exportTo('tr.metrics.sh', function() { return sample ? [sample] : []; } + + function lineSweep(lineSweepRects, viewport) { + const verticalSweepRects = []; + const horizontalSweepRects = []; + for (let i = 0; i < lineSweepRects.length; i++) { + const rect = lineSweepRects[i]; + let left = rect.left; + let right = rect.right; + let top = rect.top; + let bottom = rect.bottom; + if (left > viewport.x + viewport.width) continue; + if (right < viewport.x) continue; + if (top > viewport.y + viewport.height) continue; + if (bottom < viewport.y) continue; + + left = Math.max(left, viewport.y); + right = Math.min(right, viewport.y + viewport.width); + top = Math.max(top, viewport.y); + bottom = Math.min(bottom, viewport.y + viewport.height); + + verticalSweepRects.push({id: i, value: left, type: 'left'}, + {id: i, value: right, type: 'right'}); + horizontalSweepRects.push({id: i, value: top, type: 'top'}, + {id: i, value: bottom, type: 'bottom'}); + } + + verticalSweepRects.sort((a, b) => a.value - b.value); + horizontalSweepRects.sort((a, b) => a.value - b.value); + + // A rectangle becomes active once we enter + // it (encounter its left edge). And goes back to being + // inactive once we leave it (encounter its right edge). + const active = new Array(lineSweepRects.length).fill(0); + let area = 0; + // Begin vertical sweep from left to right. + active[verticalSweepRects[0].id] = 1; + for (let i = 1; i < verticalSweepRects.length; i++) { + const currentLine = verticalSweepRects[i]; + const previousLine = verticalSweepRects[i - 1]; + const deltaX = currentLine.value - previousLine.value; + // We could encounter this case if two rectangles start at + // the same x value. + if (deltaX === 0) continue; + let count = 0; + let firstRect; + // Begin horizontal sweep from top to bottom. + for (let j = 0; j < horizontalSweepRects.length; j++) { + // Check whether the current rectangle is active. + if (active[horizontalSweepRects[j].id] === 1) { + if (horizontalSweepRects[j].type === 'top') { + // If we just entered the rectangle and it's the first + // rectangle we enter then record its index. + if (count === 0) { + firstRect = j; + count++; + } + } else { + // If we are leaving a rectangle and it happens to + // be the last rectangle at this point (i.e: there's + // a gap before we get to the next recatngle) + // then calculate length (deltaY) and use it to + // calucate area so far. + if (count === 1) { + const deltaY = horizontalSweepRects[j].value - + horizontalSweepRects[firstRect].value; + area += deltaX * deltaY; + count--; + } + } + } + } + active[currentLine.id] = (currentLine.type === 'left'); + } + return area; + } + + /** + * Returns the percentage of pixels that reached their end state before a + * specific time after navigation start. + * + * We're considering a pixel to be updated if a layerRect + * in cc:DisplayItemList object snapshot contains that pixel. + * The pixel reaches its end state whenever it was last updated within a + * single navigation window. + * + */ + function addVisuallyCompleteBeforeSomeTimeSample(samples, rendererHelper, + navigationStart, loadDuration, frameID) { + const someTime = 2000; + if (loadDuration < someTime) return; + + let viewport; + for (const event of EventFinderUtils.getMainThreadEvents(rendererHelper, + 'viewport', 'loading')) { + if (event.args.data.frameID === frameID && + event.start > navigationStart && + event.start < navigationStart + loadDuration) { + viewport = event.args.data; + break; + } + } + if (!viewport) return; + + const ccDisplayItemListObjects = rendererHelper.process.objects + .getAllInstancesNamed('cc::DisplayItemList'); + if (!ccDisplayItemListObjects || !ccDisplayItemListObjects.length) return; + const RectsUpdatedAfterSomeTime = []; + for (let i = 0; i < ccDisplayItemListObjects.length; i++) { + const displayItemListSnapshots = + ccDisplayItemListObjects[i].snapshots; + for (let j = 0; j < displayItemListSnapshots.length; j++) { + const snapshot = displayItemListSnapshots[j]; + const timestamp = snapshot.ts; + + if (timestamp < navigationStart || + timestamp > navigationStart + loadDuration) { + continue; + } + if (timestamp - navigationStart > someTime) { + RectsUpdatedAfterSomeTime.push(snapshot.args.params.layerRect); + } + } + } + const areaUpdatedAfterSomeTime = RectsUpdatedAfterSomeTime.length ? + lineSweep(RectsUpdatedAfterSomeTime, viewport) : 0; + const pixelsLastUpdatedBeforeSomeTime = 1 - + areaUpdatedAfterSomeTime / (viewport.width * viewport.height); + samples.push({value: pixelsLastUpdatedBeforeSomeTime}); + } + + function addSpeedIndexSample(rendererHelper) { + const rects = []; + let totalArea = 0; + for (const event of EventFinderUtils.getMainThreadEvents(rendererHelper, + 'PaintTracker::LayoutObjectPainted', 'loading')) { + const rect = event.args.data.visible_new_visual_rect; + if (!rect) continue; + const area = areaOfQuad(rect); + if (!area) continue; + rects.push({rect, ts: event.start}); + totalArea += area; + } + const sample = []; + if (!totalArea) return sample; + let areaSoFar = 0; + const progress = new Array(rects.length); + for (let i = 0; i < rects.length; i++) { + const area = areaOfQuad(rects[i].rect); + areaSoFar += (area / totalArea); + progress[i] = {value: areaSoFar, ts: rects[i].ts}; + } + sample.push({value: calculateSpeedIndex(progress)}); + return sample; + } + + function areaOfQuad(quad) { + const width = Math.max(Math.abs(quad[0] - quad[2]), + Math.abs(quad[2] - quad[4])); + const height = Math.max(Math.abs(quad[1] - quad[3]), + Math.abs(quad[3] - quad[5])); + return width * height; + } + + function calculateSpeedIndex(progress) { + let lastMs = 0; + let lastProgress = 0; + let speedIndex = 0; + for (let i = 0; i < progress.length; i++) { + const elapsed = progress[i].ts - lastMs; + speedIndex += elapsed * (1.0 - lastProgress); + lastMs = progress[i].ts; + lastProgress = progress[i].value; + } + return speedIndex; + } + function addFirstMeaningfulPaintSample(samples, rendererHelper, navigationStart, fmpMarkerEvent, url) { const navStartToFMPRange = tr.b.math.Range.fromExplicitRange( @@ -435,6 +613,24 @@ tr.exportTo('tr.metrics.sh', function() { return collectTimeToEvent(rendererHelper, lastCandidateEvents); } + function findLargestContentfulPaintHistogramSamples(allBrowserEvents) { + const lcp = new tr.e.chrome.LargestContentfulPaint(allBrowserEvents); + const lcpSamples = lcp.findCandidates().map(candidate => { + const { durationInMilliseconds, size, type, inMainFrame, + mainFrameTreeNodeId } = candidate; + return { + value: durationInMilliseconds, + diagnostics: { + size: new tr.v.d.GenericSet([size]), + type: new tr.v.d.GenericSet([type]), + inMainFrame: new tr.v.d.GenericSet([inMainFrame]), + mainFrameTreeNodeId: new tr.v.d.GenericSet([mainFrameTreeNodeId]), + }, + }; + }); + return lcpSamples; + } + function collectLoadingMetricsForRenderer(rendererHelper) { const frameToNavStartEvents = EventFinderUtils.getSortedMainThreadEventsByFrame( @@ -465,6 +661,7 @@ tr.exportTo('tr.metrics.sh', function() { rendererHelper, frameToNavStartEvents, navIdToNavStartEvents); const layoutShiftSamples = findLayoutShiftSamples(rendererHelper); + const speedIndexSamples = addSpeedIndexSample(rendererHelper); return { frameToNavStartEvents, @@ -476,7 +673,8 @@ tr.exportTo('tr.metrics.sh', function() { firstViewportReadySamples, largestImagePaintSamples, largestTextPaintSamples, - layoutShiftSamples + layoutShiftSamples, + speedIndexSamples }; } @@ -486,6 +684,7 @@ tr.exportTo('tr.metrics.sh', function() { const firstCpuIdleSamples = []; const firstMeaningfulPaintSamples = []; const firstMeaningfulPaintCpuTimeSamples = []; + const visuallyCompleteBeforeSomeTimeSamples = []; for (const expectation of model.userModel.expectations) { if (!(expectation instanceof tr.model.um.LoadExpectation)) continue; if (tr.e.chrome.CHROME_INTERNAL_URLS.includes(expectation.url)) { @@ -493,6 +692,10 @@ tr.exportTo('tr.metrics.sh', function() { } const rendererHelper = chromeHelper.rendererHelpers[ expectation.renderProcess.pid]; + addVisuallyCompleteBeforeSomeTimeSample( + visuallyCompleteBeforeSomeTimeSamples, + rendererHelper, expectation.navigationStart.start, + expectation.duration, expectation.navigationStart.args.frame); if (expectation.fmpEvent !== undefined) { addFirstMeaningfulPaintSample(firstMeaningfulPaintSamples, rendererHelper, expectation.navigationStart, expectation.fmpEvent, @@ -522,6 +725,7 @@ tr.exportTo('tr.metrics.sh', function() { firstMeaningfulPaintCpuTimeSamples, firstCpuIdleSamples, interactiveSamples, + visuallyCompleteBeforeSomeTimeSamples, }; } @@ -639,6 +843,12 @@ tr.exportTo('tr.metrics.sh', function() { description: 'Time to Largest Text Paint', summaryOptions: SUMMARY_OPTIONS, }); + const largestContentfulPaintHistogram = histograms.createHistogram( + 'largestContentfulPaint', timeDurationInMs_smallerIsBetter, [], { + binBoundaries: LOADING_METRIC_BOUNDARIES, + description: 'Time to Largest Contentful Paint', + summaryOptions: SUMMARY_OPTIONS, + }); const layoutShiftHistogram = histograms.createHistogram( 'mainFrameCumulativeLayoutShift', unitlessNumber_smallerIsBetter, [], { binBoundaries: LAYOUT_SHIFT_SCORE_BOUNDARIES, @@ -646,6 +856,22 @@ tr.exportTo('tr.metrics.sh', function() { summaryOptions: SUMMARY_OPTIONS, }); + const visuallyCompleteBeforeSomeTimeHistogram = histograms.createHistogram( + 'visuallyCompleteBeforeSomeTime', unitlessNumber_smallerIsBetter, [], { + binBoundaries: LOADING_METRIC_BOUNDARIES, + description: 'Fraction of pixels in the initial viewport reaching ' + + 'final value within some time interval after navigation start.', + summaryOptions: SUMMARY_OPTIONS, + }); + + const speedIndexHistogram = histograms.createHistogram( + 'speedIndex', timeDurationInMs_smallerIsBetter, [], { + binBoundaries: LOADING_METRIC_BOUNDARIES, + description: ' the average time at which visible parts of the' + + ' page are displayed (in ms).', + summaryOptions: SUMMARY_OPTIONS, + }); + const chromeHelper = model.getOrCreateHelper( tr.model.helpers.ChromeModelHelper); for (const pid in chromeHelper.rendererHelpers) { @@ -655,6 +881,11 @@ tr.exportTo('tr.metrics.sh', function() { const samplesSet = collectLoadingMetricsForRenderer(rendererHelper); + const lcpSamples = findLargestContentfulPaintHistogramSamples( + chromeHelper.browserHelper.mainThread.sliceGroup.slices); + addSamplesToHistogram( + lcpSamples, largestContentfulPaintHistogram, histograms); + addSamplesToHistogram( samplesSet.firstPaintSamples, firstPaintHistogram, histograms); addSamplesToHistogram( @@ -685,6 +916,8 @@ tr.exportTo('tr.metrics.sh', function() { histograms); addSamplesToHistogram( samplesSet.layoutShiftSamples, layoutShiftHistogram, histograms); + addSamplesToHistogram( + samplesSet.speedIndexSamples, speedIndexHistogram, histograms); } const samplesSet = collectMetricsFromLoadExpectations(model, chromeHelper); @@ -704,6 +937,10 @@ tr.exportTo('tr.metrics.sh', function() { samplesSet.firstCpuIdleSamples, timeToFirstCpuIdleHistogram, histograms); + addSamplesToHistogram( + samplesSet.visuallyCompleteBeforeSomeTimeSamples, + visuallyCompleteBeforeSomeTimeHistogram, + histograms); } tr.metrics.MetricRegistry.register(loadingMetric); diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/system_health/loading_metric_test.html b/chromium/third_party/catapult/tracing/tracing/metrics/system_health/loading_metric_test.html index 8063fc79aec..8e28c08d7bc 100644 --- a/chromium/third_party/catapult/tracing/tracing/metrics/system_health/loading_metric_test.html +++ b/chromium/third_party/catapult/tracing/tracing/metrics/system_health/loading_metric_test.html @@ -253,7 +253,160 @@ tr.b.unittest.testSuite(function() { assert.strictEqual(800, hist.running.mean); }); - test('FCPPlusPlus_lastIsCandidateIsFinal', function() { + test('timeToLargestContentfulPaint', function() { + const model = tr.e.chrome.ChromeTestUtils.newChromeModel(function(model) { + const browerMain = model.browserMain; + browerMain.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ + cat: 'loading', + title: tr.e.chrome.LCP_CANDIDATE_EVENT_TITLE, + start: 200, + duration: 0.0, + args: { + data: { durationInMilliseconds: 100, type: 'text', size: 1000, + inMainFrame: true }, + main_frame_tree_node_id: 12345, + } + })); + }); + const histograms = new tr.v.HistogramSet(); + tr.metrics.sh.loadingMetric(histograms, model); + const hist = histograms.getHistogramNamed('largestContentfulPaint'); + assert.strictEqual(1, hist.running.count); + assert.strictEqual(100, hist.running.mean); + }); + + test('timeToLargestContentfulPaint_LastCandidate', function() { + const model = tr.e.chrome.ChromeTestUtils.newChromeModel(function(model) { + const browerMain = model.browserMain; + browerMain.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ + cat: 'loading', + title: tr.e.chrome.LCP_CANDIDATE_EVENT_TITLE, + start: 200, + duration: 0.0, + args: { + data: { durationInMilliseconds: 100, type: 'text', size: 1000, + inMainFrame: true }, + main_frame_tree_node_id: 12345, + } + })); + browerMain.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ + cat: 'loading', + title: tr.e.chrome.LCP_CANDIDATE_EVENT_TITLE, + start: 300, + duration: 0.0, + args: { + data: { durationInMilliseconds: 200, type: 'image', size: 2000, + inMainFrame: true }, + main_frame_tree_node_id: 12345, + } + })); + }); + const histograms = new tr.v.HistogramSet(); + tr.metrics.sh.loadingMetric(histograms, model); + const hist = histograms.getHistogramNamed('largestContentfulPaint'); + assert.strictEqual(1, hist.running.count); + assert.strictEqual(200, hist.running.mean); + }); + + test('timeToLargestContentfulPaint_AggregateSubframe', function() { + const model = tr.e.chrome.ChromeTestUtils.newChromeModel(function(model) { + const browerMain = model.browserMain; + browerMain.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ + cat: 'loading', + title: tr.e.chrome.LCP_CANDIDATE_EVENT_TITLE, + start: 200, + duration: 0.0, + args: { + data: { durationInMilliseconds: 100, type: 'text', size: 1000, + inMainFrame: true }, + main_frame_tree_node_id: 12345, + } + })); + browerMain.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ + cat: 'loading', + title: tr.e.chrome.LCP_CANDIDATE_EVENT_TITLE, + start: 300, + duration: 0.0, + args: { + data: { durationInMilliseconds: 200, type: 'image', size: 2000, + inMainFrame: false }, + main_frame_tree_node_id: 12345, + } + })); + }); + const histograms = new tr.v.HistogramSet(); + tr.metrics.sh.loadingMetric(histograms, model); + const hist = histograms.getHistogramNamed('largestContentfulPaint'); + assert.strictEqual(1, hist.running.count); + assert.strictEqual(200, hist.running.mean); + }); + + test('timeToLargestContentfulPaint_GroupByNavigation', function() { + const model = tr.e.chrome.ChromeTestUtils.newChromeModel(function(model) { + const browerMain = model.browserMain; + browerMain.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ + cat: 'loading', + title: tr.e.chrome.LCP_CANDIDATE_EVENT_TITLE, + start: 200, + duration: 0.0, + args: { + data: { durationInMilliseconds: 100, type: 'text', size: 1000, + inMainFrame: true }, + main_frame_tree_node_id: 1, + } + })); + browerMain.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ + cat: 'loading', + title: tr.e.chrome.LCP_CANDIDATE_EVENT_TITLE, + start: 300, + duration: 0.0, + args: { + data: { durationInMilliseconds: 200, type: 'image', size: 2000, + inMainFrame: true }, + main_frame_tree_node_id: 2, + } + })); + }); + const histograms = new tr.v.HistogramSet(); + tr.metrics.sh.loadingMetric(histograms, model); + const hist = histograms.getHistogramNamed('largestContentfulPaint'); + assert.strictEqual(2, hist.running.count); + assert.strictEqual(150, hist.running.mean); + }); + + test('timeToLargestContentfulPaint_Invalidate', function() { + const model = tr.e.chrome.ChromeTestUtils.newChromeModel(function(model) { + const browerMain = model.browserMain; + browerMain.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ + cat: 'loading', + title: tr.e.chrome.LCP_CANDIDATE_EVENT_TITLE, + start: 200, + duration: 0.0, + args: { + data: { durationInMilliseconds: 100, type: 'text', size: 1000, + inMainFrame: true }, + main_frame_tree_node_id: 12345, + } + })); + browerMain.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ + cat: 'loading', + title: tr.e.chrome.LCP_INVALIDATE_EVENT_TITLE, + start: 300, + duration: 0.0, + args: { + data: { durationInMilliseconds: 100, type: 'text', size: 1000, + inMainFrame: true }, + main_frame_tree_node_id: 12345, + } + })); + }); + const histograms = new tr.v.HistogramSet(); + tr.metrics.sh.loadingMetric(histograms, model); + const hist = histograms.getHistogramNamed('largestContentfulPaint'); + assert.strictEqual(0, hist.numValues); + }); + + test('FCPPlusPlus_lastCandidateIsFinal', function() { const model = tr.e.chrome.ChromeTestUtils.newChromeModel(function(model) { const rendererProcess = model.rendererProcess; const mainThread = model.rendererMain; @@ -1434,5 +1587,89 @@ tr.b.unittest.testSuite(function() { assert.strictEqual(1, hist.running.count); assert.strictEqual(3.5, hist.running.mean); }); + + test('visuallyCompleteBeforeSomeTime', function() { + const model = tr.e.chrome.ChromeTestUtils.newChromeModel(function(model) { + const rendererProcess = model.rendererProcess; + const mainThread = model.rendererMain; + + model.userModel.expectations.push(new tr.model.um.LoadExpectation( + model, tr.model.um.LOAD_SUBTYPE_NAMES.SUCCESSFUL, 300, 2100, + rendererProcess, { + cat: 'blink.user_timing', + title: 'navigationStart', + start: 200, + duration: 0.0, + args: {frame: '0xdeadbeef', data: {navigationId: '0xfirstnav'}}}, + {}, {}, {}, {}, ' ', 0xdeadbeef)); + + rendererProcess.objects.addSnapshot('ptr', + 'disabled-by-default-cc.debug.display_items', + 'cc::DisplayItemList', 400, {params: {layer_rect: [0, 0, 10, 10]}}, + 'cc::DisplayItemList'); + + mainThread.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ + cat: 'loading', + title: 'viewport', + start: 500, + duration: 0.0, + args: { + data: { + x: 0, + y: 0, + width: 20, + height: 20, + frameID: '0xdeadbeef'}} + })); + }); + const histograms = new tr.v.HistogramSet(); + tr.metrics.sh.loadingMetric(histograms, model); + const hist = histograms.getHistogramNamed('visuallyCompleteBeforeSomeTime'); + assert.strictEqual(1, hist.running.count); + assert.strictEqual(1, hist.running.mean); + }); + + test('speedIndex', function() { + const model = tr.e.chrome.ChromeTestUtils.newChromeModel(function(model) { + const rendererProcess = model.rendererProcess; + const mainThread = model.rendererMain; + + mainThread.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ + cat: 'loading', + title: 'PaintTracker::LayoutObjectPainted', + start: 500, + duration: 0.0, + args: { + data: { + visible_new_visual_rect: [50, 70, 60, 70, 60, 100, 50, 100] + } + } + })); + + mainThread.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ + cat: 'loading', + title: 'PaintTracker::LayoutObjectPainted', + start: 700, + duration: 0.0, + args: { + data: { + visible_new_visual_rect: [10, 30, 20, 30, 20, 50, 10, 50] + } + } + })); + }); + + const histograms = new tr.v.HistogramSet(); + tr.metrics.sh.loadingMetric(histograms, model); + const hist = histograms.getHistogramNamed('speedIndex'); + assert.strictEqual(1, hist.running.count); + // First rectangle area is: 300 + // Second rectangle area is: 200 + // Total area is: 500 + // visual completeness: time: 500 progress: 0.6 + // time: 700 progress: 1.0 + // => speedIndex = 500 * (1 - 0.0) + 200 * (1 - 0.6) = 580 + assert.strictEqual(580, hist.running.mean); + }); }); </script> diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/uma_metric.html b/chromium/third_party/catapult/tracing/tracing/metrics/uma_metric.html index f2ec288cd19..912a4bdff87 100644 --- a/chromium/third_party/catapult/tracing/tracing/metrics/uma_metric.html +++ b/chromium/third_party/catapult/tracing/tracing/metrics/uma_metric.html @@ -109,13 +109,18 @@ tr.exportTo('tr.metrics', function() { } function getHistogramBoundaries_(name) { - // Customize histogram boundaries here. - switch (name) { - case 'Event.Latency.ScrollUpdate.Touch.TimeToScrollUpdateSwapBegin4': - return tr.v.HistogramBinBoundaries.createExponential(1e3, 1e5, 50); - default: - return tr.v.HistogramBinBoundaries.createExponential(1e-3, 1e3, 50); + // Customize histogram boundaries here. Ideally, this would not be + // necessary. + // crbug.com/987273 + if (name.startsWith('Event.Latency.Scroll')) { + return tr.v.HistogramBinBoundaries.createExponential(1e3, 1e5, 50); } + + if (name.startsWith('Graphics.Smoothness.Throughput')) { + return tr.v.HistogramBinBoundaries.createLinear(0, 100, 101); + } + + return tr.v.HistogramBinBoundaries.createExponential(1e-3, 1e3, 50); } function umaMetric(histograms, model) { diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/v8/OWNERS b/chromium/third_party/catapult/tracing/tracing/metrics/v8/OWNERS new file mode 100644 index 00000000000..3ecc1606516 --- /dev/null +++ b/chromium/third_party/catapult/tracing/tracing/metrics/v8/OWNERS @@ -0,0 +1,3 @@ +mlippautz@chromium.org +mythria@chromium.org +ulan@chromium.org diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/v8/utils.html b/chromium/third_party/catapult/tracing/tracing/metrics/v8/utils.html index b9ec7ed80bd..91c52e35e3e 100644 --- a/chromium/third_party/catapult/tracing/tracing/metrics/v8/utils.html +++ b/chromium/third_party/catapult/tracing/tracing/metrics/v8/utils.html @@ -218,25 +218,48 @@ tr.exportTo('tr.metrics.v8.utils', function() { } /** + * Finds all threads in renderer processes of the given model that + * can execute JavaScript code (the main thread and web worker threads). + * These threads are relevant for computing GC metrics. + */ + function jsExecutionThreads(model) { + const chromeHelper = model.getOrCreateHelper( + tr.model.helpers.ChromeModelHelper); + let threads = []; + for (const rendererHelper of Object.values(chromeHelper.rendererHelpers)) { + if (rendererHelper.isChromeTracingUI) continue; + threads.push(rendererHelper.mainThread); + threads = threads.concat(rendererHelper.dedicatedWorkerThreads); + threads = threads.concat(rendererHelper.foregroundWorkerThreads); + } + return threads; + } + + /** * Filters events using the |filterCallback|, then groups events by the user - * the name computed using the |nameCallback|, and then invokes + * provided group using the |groupCallback|, and then invokes * the |processCallback| with the grouped events. * @param {Function} filterCallback Takes an event and returns a boolean. - * @param {Function} nameCallback Takes event and returns a string. - * @param {Function} processCallback Takes a name, and an array of events. + * @param {Function} groupCallback Takes event and a group object which can + * be a string or number. + * @param {Function} processCallback Takes a group, and an array of events. */ function groupAndProcessEvents(model, filterCallback, - nameCallback, processCallback) { - // Map: name -> [events]. - const nameToEvents = {}; - for (const event of model.getDescendantEvents()) { - if (!filterCallback(event)) continue; - const name = nameCallback(event); - nameToEvents[name] = nameToEvents[name] || []; - nameToEvents[name].push(event); + groupCallback, processCallback) { + // Map: group -> [events]. + const groupToEvents = {}; + const threads = jsExecutionThreads(model); + for (const thread of threads) { + for (const event of thread.sliceGroup.childEvents()) { + if (!filterCallback(event)) continue; + const group = groupCallback(event); + groupToEvents[group] = groupToEvents[group] || []; + groupToEvents[group].push(event); + } } - for (const [name, events] of Object.entries(nameToEvents)) { - processCallback(name, events); + + for (const [group, events] of Object.entries(groupToEvents)) { + processCallback(group, events); } } |