diff options
Diffstat (limited to 'chromium/third_party/catapult/tracing/tracing/metrics')
45 files changed, 3924 insertions, 362 deletions
diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/__init__.py b/chromium/third_party/catapult/tracing/tracing/metrics/__init__.py index cffcee63c42..c115b7fe69d 100644 --- a/chromium/third_party/catapult/tracing/tracing/metrics/__init__.py +++ b/chromium/third_party/catapult/tracing/tracing/metrics/__init__.py @@ -2,6 +2,7 @@ # 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 import os import sys diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/all_metrics.html b/chromium/third_party/catapult/tracing/tracing/metrics/all_metrics.html index 694f443fab7..6ed6dd188fd 100644 --- a/chromium/third_party/catapult/tracing/tracing/metrics/all_metrics.html +++ b/chromium/third_party/catapult/tracing/tracing/metrics/all_metrics.html @@ -9,10 +9,14 @@ found in the LICENSE file. <link rel="import" href="/tracing/metrics/android_systrace_metric.html"> <link rel="import" href="/tracing/metrics/blink/gc_metric.html"> <link rel="import" href="/tracing/metrics/blink/leak_detection_metric.html"> +<link rel="import" href="/tracing/metrics/blink/resource_metric.html"> <link rel="import" href="/tracing/metrics/console_error_metric.html"> +<link rel="import" href="/tracing/metrics/core_web_vitals_metric.html"> +<link rel="import" href="/tracing/metrics/count_sum_metric.html"> <link rel="import" href="/tracing/metrics/cpu_process_metric.html"> +<link rel="import" href="/tracing/metrics/custom_metric.html"> <link rel="import" href="/tracing/metrics/media_metric.html"> -<link rel="import" href="/tracing/metrics/memory_ablation_metric.html"> +<link rel="import" href="/tracing/metrics/partition_alloc/pcscan_metric.html"> <link rel="import" href="/tracing/metrics/rendering/rendering_metric.html"> <link rel="import" href="/tracing/metrics/reported_by_page_metric.html"> <link rel="import" href="/tracing/metrics/sample_exception_metric.html"> @@ -32,6 +36,7 @@ found in the LICENSE file. <link rel="import" href="/tracing/metrics/system_health/rects_based_speed_index_metric.html"> <link rel="import" href="/tracing/metrics/system_health/responsiveness_metric.html"> <link rel="import" href="/tracing/metrics/system_health/screenshots_based_speed_index_metric.html"> +<link rel="import" href="/tracing/metrics/system_health/weblayer_startup_metric.html"> <link rel="import" href="/tracing/metrics/system_health/webview_startup_metric.html"> <link rel="import" href="/tracing/metrics/tabs_metric.html"> <link rel="import" href="/tracing/metrics/tracing_metric.html"> diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/android_startup_metric.html b/chromium/third_party/catapult/tracing/tracing/metrics/android_startup_metric.html index 702cdbf5fea..390b02df412 100644 --- a/chromium/third_party/catapult/tracing/tracing/metrics/android_startup_metric.html +++ b/chromium/third_party/catapult/tracing/tracing/metrics/android_startup_metric.html @@ -5,55 +5,113 @@ Use of this source code is governed by a BSD-style license that can be found in the LICENSE file. --> +<link rel="import" href="/tracing/extras/chrome/event_finder_utils.html"> <link rel="import" href="/tracing/metrics/metric_registry.html"> <link rel="import" href="/tracing/value/histogram.html"> <script> 'use strict'; -// The |androidStartupMetric| produces metrics that start counting at the -// earliest moment the Chrome code on Android is executed. -// A few histograms are produced with the names as described below: +// The |androidStartupMetric| produces metrics that (unless noted otherwise) +// start counting at the earliest moment the Chrome code on Android is +// executed. A few histograms are produced with the names as described below: // -// 1. messageloop_start_time - time till the message loop of the browser main -// starts processing posted tasts (after having loaded the Profile) -// 2. experimental_content_start_time - time when the renderer enters the main -// entrypoint. -// 3. experimental_navigation_start_time - This roughly corresponds to the time -// the initial navigation network request is sent. -// 4. navigation_commit_time - This is when the renderer has received the first -// part of the response from the network and started loading the page. -// 5. first_contentful_paint_time - time to the first contentful paint of the -// page loaded at startup +// * messageloop_start_time - Time till the message loop of the browser main +// starts processing posted tasks (after having loaded the Profile) +// +// * experimental_navigation_start_time - This roughly corresponds to the time +// the initial navigation network request is sent on the UI thread +// +// * experimental_network_request_start_time - Time until the first network +// request starts in the netlog. The actual bytes will be sent to the network +// slightly later: after disk cache responds. This metric can be used even for +// netowrk loads that are served from the disk cache. Currently relies on +// NetworkService running in the browser process. +// +// * navigation_commit_time - This is when the renderer has received the first +// part of the response from the network after all redirects and started +// loading the page. Recorded when the confirmation is received on the browser +// UI thread. +// +// * first_contentful_paint_time - Time to the first 'contentful' paint of the +// page loaded at startup +// +// * process_create_to_app_start_time - Time from process creation until the +// application starts. The end time of this event will be the same as the +// start time of messageloop_start_time. // // The metric also supports multiple browser restarts, in this case multiple // samples would be added to the histograms above. tr.exportTo('tr.metrics.sh', function() { const MESSAGE_LOOP_EVENT_NAME = 'Startup.BrowserMessageLoopStartTime'; - const CONTENT_START_EVENT_NAME = 'content::Start'; const NAVIGATION_EVENT_NAME = 'Navigation StartToCommit'; const FIRST_CONTENTFUL_PAINT_EVENT_NAME = 'firstContentfulPaint'; + const APPLICATION_START_EVENT_NAME = + 'Startup.LoadTime.ProcessCreateToApplicationStart'; + const REQUEST_ALIVE = 'REQUEST_ALIVE'; + + function isGetRequest(event) { + if (event.args && + event.args.params && + event.args.params.method == 'GET') { + return true; + } + return false; + } + + function findRequestEventAfterNavigation(networkEvents, range) { + let requestStart = range.max; + let requestEvent = null; + for (const event of networkEvents) { + if (isGetRequest(event)) { + for (const subSlice of event.subSlices) { + if (subSlice.title === REQUEST_ALIVE && + range.min <= subSlice.start && subSlice.start < requestStart) { + requestStart = subSlice.start; + requestEvent = subSlice; + } + } + } + } + return requestEvent; + } + function androidStartupMetric(histograms, model) { // Walk the browser slices, extract timestamps for the browser start, // message loop start. let messageLoopStartEvents = []; - let navigationEvents = []; + let applicationStartEvents = []; + let navigationPairs = []; + + function organizeBrowserEventByTitle(event, process) { + if (event.title === MESSAGE_LOOP_EVENT_NAME) { + messageLoopStartEvents.push(event); + } else if (event.title === APPLICATION_START_EVENT_NAME) { + applicationStartEvents.push(event); + } else if (event.title === NAVIGATION_EVENT_NAME) { + const networkEvents = + tr.e.chrome.EventFinderUtils.getNetworkEventsInRange(process, + event.range); + const requestEvent = findRequestEventAfterNavigation( + networkEvents, event.range); + navigationPairs.push({ + 'nav': event, + 'req': requestEvent, + }); + } + } + const chromeHelper = model.getOrCreateHelper(tr.model.helpers.ChromeModelHelper); if (!chromeHelper) return; for (const helper of chromeHelper.browserHelpers) { for (const ev of helper.mainThread.asyncSliceGroup.childEvents()) { - if (ev.title === MESSAGE_LOOP_EVENT_NAME) { - messageLoopStartEvents.push(ev); - } else if (ev.title === NAVIGATION_EVENT_NAME) { - navigationEvents.push(ev); - } + organizeBrowserEventByTitle(ev, helper.process); } } // Walk the renderer slices and extract the 'first contentful paint' // histogram samples. - let contentStartEvents = []; let firstContentfulPaintEvents = []; const rendererHelpers = chromeHelper.rendererHelpers; const pids = Object.keys(rendererHelpers); @@ -65,38 +123,28 @@ tr.exportTo('tr.metrics.sh', function() { // There are usually several 'First Contentful Paint' events recorded // for each page load. Take only the first one per renderer. break; - } else if (ev.title === CONTENT_START_EVENT_NAME) { - contentStartEvents.push(ev); } } } // Fallback to scanning all processes if important events are not found. let totalBrowserStarts = messageLoopStartEvents.length; - let totalContentStartEvents = contentStartEvents.length; let totalFcpEvents = firstContentfulPaintEvents.length; - let totalNavigations = navigationEvents.length; - if (totalFcpEvents !== totalBrowserStarts || - totalNavigations !== totalBrowserStarts || - totalContentStartEvents !== totalBrowserStarts || + if (totalBrowserStarts !== totalFcpEvents || + totalBrowserStarts !== navigationPairs.length || + totalBrowserStarts !== applicationStartEvents.length || totalBrowserStarts === 0) { - messageLoopStartEvents = []; - contentStartEvents = []; - navigationEvents = []; - firstContentfulPaintEvents = []; + messageLoopStartEvents.length = 0; + navigationPairs.length = 0; + firstContentfulPaintEvents.length = 0; + applicationStartEvents.length = 0; // Sometimes either the browser process or the renderer process does not // have the proper name attached. This often happens when both chrome // trace and systrace are merged. Other multi-process trickery, like // Perfetto, may also cause this. for (const proc of Object.values(model.processes)) { for (const ev of proc.getDescendantEvents()) { - if (ev.title === MESSAGE_LOOP_EVENT_NAME) { - messageLoopStartEvents.push(ev); - } else if (ev.title === NAVIGATION_EVENT_NAME) { - navigationEvents.push(ev); - } else if (ev.title === CONTENT_START_EVENT_NAME) { - contentStartEvents.push(ev); - } + organizeBrowserEventByTitle(ev, proc); } for (const ev of proc.getDescendantEvents()) { if (ev.title === FIRST_CONTENTFUL_PAINT_EVENT_NAME) { @@ -106,25 +154,65 @@ tr.exportTo('tr.metrics.sh', function() { } } totalBrowserStarts = messageLoopStartEvents.length; - totalContentStartEvents = contentStartEvents.length; - totalNavigations = navigationEvents.length; totalFcpEvents = firstContentfulPaintEvents.length; } - // Sometimes a number of early trace events are not recorded because tracing - // takes time to start. This leads to having more FCP events than - // messageloop_start events. As a workaround ignore the FCP events for which - // there are no browser starts. Navigation and content start events are - // recorded on a best effort basis if they are found in the trace; their - // absence doesn't cause FCP events to be dropped. + // Sort the events by start time. function orderEvents(event1, event2) { return event1.start - event2.start; } messageLoopStartEvents.sort(orderEvents); - contentStartEvents.sort(orderEvents); - navigationEvents.sort(orderEvents); + applicationStartEvents.sort(orderEvents); firstContentfulPaintEvents.sort(orderEvents); + function orderPairs(pair1, pair2) { + return pair1['nav'].start - pair2['nav'].start; + } + navigationPairs.sort(orderPairs); + + // Remove spurious navigation events. Only one 'Navigation StartToCommit' + // event should remain for each browser session. When multiple events are + // encountered for a browsing session, remove all except the first one. The + // first navigation event looked more realistic for the story + // maps_pwa:with_http_cache (http://crbug.com/1307774). + let filteredNavigationPairs = []; + let filteredRequestsFollowingNavigation = []; + let navigation_index = 0; + let messageloop_index = 0; + do { + // Set |browserStart| as the upper limit for the set of navigations to + // select from. + let browserStart = Number.POSITIVE_INFINITY; + if (messageloop_index < messageLoopStartEvents.length) { + browserStart = messageLoopStartEvents[messageloop_index].start; + } + // From navigation events preceding |browserStart| take the first one, + // skip others. + let navigationFound = false; + for (; navigation_index < navigationPairs.length; navigation_index++) { + // Each request event has to be at the same index as its corresponding + // navigation event. Take either both of them or none. + const navPair = navigationPairs[navigation_index]; + const navEvent = navPair['nav']; + const requestEvent = navPair['req']; + if (navEvent.start >= browserStart) { + break; + } + if (!navigationFound) { + if (messageloop_index === 0) { + throw new Error('Found a navigation event before browser start'); + } + filteredNavigationPairs.push(navPair); + navigationFound = true; + } + } + // Run the last iteration with |browserStart| as positive infinity. + } while (messageloop_index++ <= messageLoopStartEvents.length); + navigationPairs = filteredNavigationPairs; + + // Verify the number of FCP events to avoid pairing them to browser starts + // incorrectly. Absence of navigation events does not cause FCP events to be + // dropped. if (totalFcpEvents < totalBrowserStarts) { throw new Error('Found fewer FCP events (' + totalFcpEvents + ') than browser starts (' + totalBrowserStarts + ')'); @@ -135,47 +223,44 @@ tr.exportTo('tr.metrics.sh', function() { const messageLoopStartHistogram = histograms.createHistogram( 'messageloop_start_time', tr.b.Unit.byName.timeDurationInMs_smallerIsBetter, []); - const contentStartHistogram = histograms.createHistogram( - 'experimental_content_start_time', - tr.b.Unit.byName.timeDurationInMs_smallerIsBetter, []); const navigationStartHistogram = histograms.createHistogram( 'experimental_navigation_start_time', tr.b.Unit.byName.timeDurationInMs_smallerIsBetter, []); + const requestStartHistogram = histograms.createHistogram( + 'experimental_network_request_start_time', + tr.b.Unit.byName.timeDurationInMs_smallerIsBetter, []); const navigationCommitHistogram = histograms.createHistogram( 'navigation_commit_time', tr.b.Unit.byName.timeDurationInMs_smallerIsBetter, []); const firstContentfulPaintHistogram = histograms.createHistogram( 'first_contentful_paint_time', tr.b.Unit.byName.timeDurationInMs_smallerIsBetter, []); - // The earliest browser start is skipped because it is affected by the state - // of the system coming from the time before the benchmark started. Removing - // these influencing factors allows reducing measurement noise. - // Note: Two early starts are ignored below, the reasons for spurious - // slowdowns of the 2nd run are not known yet, see http://crbug.com/891797. - let contentIndex = 0; + const applicationStartHistogram = histograms.createHistogram( + 'process_create_to_app_start_time', + tr.b.Unit.byName.timeDurationInMs_smallerIsBetter, []); + // The earliest 2 browser starts are skipped to reduce measurement noise. + // See http://crbug.com/891797. let navIndex = 0; let fcpIndex = 0; for (let loopStartIndex = 0; loopStartIndex < totalBrowserStarts;) { - const startEvent = messageLoopStartEvents[loopStartIndex]; + const loopStartEvent = messageLoopStartEvents[loopStartIndex]; + // There should be a corresponding application start event for each + // message loop start event. + const applicationStartEvent = applicationStartEvents[loopStartIndex]; if (fcpIndex === totalFcpEvents) { break; } // Skip all events that appear before the next browser start. - const contentStartEvent = contentIndex < contentStartEvents.length ? - contentStartEvents[contentIndex] : null; - if (contentStartEvent && contentStartEvent.start < startEvent.start) { - contentIndex++; - continue; - } - const navEvent = navIndex < navigationEvents.length ? - navigationEvents[navIndex] : null; - if (navEvent && navEvent.start < startEvent.start) { + const navPair = navIndex < navigationPairs.length ? + navigationPairs[navIndex] : null; + const navEvent = navPair ? navPair['nav'] : null; + if (navEvent && navEvent.start < loopStartEvent.start) { navIndex++; continue; } const fcpEvent = firstContentfulPaintEvents[fcpIndex]; - if (fcpEvent.start < startEvent.start) { + if (fcpEvent.start < loopStartEvent.start) { fcpIndex++; continue; } @@ -190,25 +275,30 @@ tr.exportTo('tr.metrics.sh', function() { } // Record the histograms. - messageLoopStartHistogram.addSample(startEvent.duration, - {events: new tr.v.d.RelatedEventSet([startEvent])}); - if (contentStartEvent) { - contentStartHistogram.addSample( - contentStartEvent.start - startEvent.start, - {events: new tr.v.d.RelatedEventSet([startEvent, - contentStartEvent])}); - } + messageLoopStartHistogram.addSample(loopStartEvent.duration, + {events: new tr.v.d.RelatedEventSet([loopStartEvent])}); if (navEvent) { navigationStartHistogram.addSample( - navEvent.start - startEvent.start, - {events: new tr.v.d.RelatedEventSet([startEvent, navEvent])}); + navEvent.start - loopStartEvent.start, + {events: new tr.v.d.RelatedEventSet([loopStartEvent, navEvent])}); navigationCommitHistogram.addSample( - navEvent.end - startEvent.start, - {events: new tr.v.d.RelatedEventSet([startEvent, navEvent])}); + navEvent.end - loopStartEvent.start, + {events: new tr.v.d.RelatedEventSet([loopStartEvent, navEvent])}); + const requestEvent = navPair['req']; + if (!requestEvent) { + throw new Error('No network request after navigation'); + } + requestStartHistogram.addSample( + requestEvent.start - loopStartEvent.start, + {events: new tr.v.d.RelatedEventSet([navEvent, requestEvent])}); } firstContentfulPaintHistogram.addSample( - fcpEvent.end - startEvent.start, - {events: new tr.v.d.RelatedEventSet([startEvent, fcpEvent])}); + fcpEvent.end - loopStartEvent.start, + {events: new tr.v.d.RelatedEventSet([loopStartEvent, fcpEvent])}); + if (applicationStartEvent) { + applicationStartHistogram.addSample(applicationStartEvent.duration, + {events: new tr.v.d.RelatedEventSet([applicationStartEvent])}); + } } } diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/android_startup_metric_test.html b/chromium/third_party/catapult/tracing/tracing/metrics/android_startup_metric_test.html index af1dca98488..076cbfef83f 100644 --- a/chromium/third_party/catapult/tracing/tracing/metrics/android_startup_metric_test.html +++ b/chromium/third_party/catapult/tracing/tracing/metrics/android_startup_metric_test.html @@ -32,6 +32,34 @@ tr.b.unittest.testSuite(function() { return rendererMainThread; } + function addNetworkEvents(startTime, durationTime, process) { + const slice = tr.c.TestUtils.newAsyncSliceEx({ + cat: 'netlog', + title: 'http://bbc.co.uk', + start: startTime, + args: { params: { method: 'GET' } }, + duration: durationTime}); + slice.args.params['method'] = 'GET'; + const subSlice = tr.c.TestUtils.newAsyncSliceEx({ + cat: 'netlog', + title: 'REQUEST_ALIVE', + start: startTime, + duration: durationTime}); + slice.subSlices.push(subSlice); + const netThread = process.getOrCreateThread(tr.b.GUID.allocateSimple()); + netThread.name = 'NetLog'; + netThread.asyncSliceGroup.push(slice); + } + + function addNavigationEvent(threadForAdding, startTime, durationTime) { + threadForAdding.asyncSliceGroup.push( + tr.c.TestUtils.newAsyncSliceEx({ + cat: 'navigation', + title: 'Navigation StartToCommit', + start: startTime, + duration: durationTime})); + } + // Adds a browser and renderer to the process, with a few key events necessary // to calculate the |androidStartupMetric|. An |offset| can be added to all // events and the length of a few events can be extended by @@ -43,22 +71,20 @@ tr.b.unittest.testSuite(function() { browserMainThread.asyncSliceGroup.push( tr.c.TestUtils.newAsyncSliceEx({ cat: 'startup', + title: 'Startup.LoadTime.ProcessCreateToApplicationStart', + start: (offset + 5000), + duration: (incrementForMetrics + 100)})); + browserMainThread.asyncSliceGroup.push( + tr.c.TestUtils.newAsyncSliceEx({ + cat: 'startup', title: 'Startup.BrowserMessageLoopStartTime', start: (offset + 6800.125), duration: (incrementForMetrics + 1700.0625)})); - browserMainThread.asyncSliceGroup.push( - tr.c.TestUtils.newAsyncSliceEx({ - cat: 'navigation', - title: 'Navigation StartToCommit', - start: (offset + 9000.5 + incrementForMetrics), - duration: (incrementForMetrics + 2000.5)})); + const navigationStart = offset + 9000.5 + incrementForMetrics; + addNavigationEvent(browserMainThread, navigationStart, + incrementForMetrics + 2000.5); const rendererMainThread = createRendererThread(model); rendererMainThread.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ - cat: 'startup', - title: 'content::Start', - start: (offset + 9500.125 + incrementForMetrics), - duration: 10000.0})); - rendererMainThread.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ cat: 'loading,rail,devtools.timeline', title: 'firstContentfulPaint', start: (offset + 8400.125 + incrementForMetrics), @@ -73,6 +99,11 @@ tr.b.unittest.testSuite(function() { start: (offset + 8400.125 + incrementForMetrics + 0.125), duration: 0.0, args: {frame: '0x0'}})); + + // The metrics rely on having network access in netlog soon after the + // navigation starts. + addNetworkEvents(navigationStart + 110, 2, browserMainThread.parent); + return browserMainThread; } // Adds early messageloop and FCP events. The metric should ignore these very @@ -83,6 +114,12 @@ tr.b.unittest.testSuite(function() { browserMainThread.asyncSliceGroup.push( tr.c.TestUtils.newAsyncSliceEx({ cat: 'startup', + title: 'Startup.LoadTime.ProcessCreateToApplicationStart', + start: offset, + duration: 1.0})); + browserMainThread.asyncSliceGroup.push( + tr.c.TestUtils.newAsyncSliceEx({ + cat: 'startup', title: 'Startup.BrowserMessageLoopStartTime', start: (offset + 1.0), duration: 10.0})); @@ -123,9 +160,11 @@ tr.b.unittest.testSuite(function() { verifyHistogram(histograms, 'messageloop_start_time', 1, 1700.0625); verifyHistogram(histograms, 'experimental_navigation_start_time', 1, 2200.375); + verifyHistogram(histograms, 'experimental_network_request_start_time', 1, + 2200.375 + 110); verifyHistogram(histograms, 'navigation_commit_time', 1, 4200.875); - verifyHistogram(histograms, 'experimental_content_start_time', 1, 2700); verifyHistogram(histograms, 'first_contentful_paint_time', 1, 1600); + verifyHistogram(histograms, 'process_create_to_app_start_time', 1, 100); }); // Emulates loss of the initial message loop start event. Checks that this @@ -150,18 +189,10 @@ tr.b.unittest.testSuite(function() { title: 'Startup.BrowserMessageLoopStartTime', start: (20.0 + 1.0), duration: 10.0})); - browserMainThread.asyncSliceGroup.push( - tr.c.TestUtils.newAsyncSliceEx({ - cat: 'navigation', - title: 'Navigation StartToCommit', - start: (20.0 + 11.0), - duration: 10.0})); + const navigationStartTime = 20.0 + 11.0; + addNavigationEvent(browserMainThread, navigationStartTime, 10.0); + addNetworkEvents(navigationStartTime + 2, 2, browserMainThread.parent); const rendererMainThread = createRendererThread(model); - rendererMainThread.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ - cat: 'startup', - title: 'content::Start', - start: (20.0 + 1.75), - duration: 10.0})); rendererMainThread.sliceGroup.pushSlice( tr.c.TestUtils.newSliceEx({ cat: 'loading,rail,devtools.timeline', @@ -178,8 +209,9 @@ tr.b.unittest.testSuite(function() { verifyHistogram(histograms, 'messageloop_start_time', 1, 1700.0625); verifyHistogram(histograms, 'experimental_navigation_start_time', 1, 2200.375); + verifyHistogram(histograms, 'experimental_network_request_start_time', 1, + 2200.375 + 110); verifyHistogram(histograms, 'navigation_commit_time', 1, 4200.875); - verifyHistogram(histograms, 'experimental_content_start_time', 1, 2700); verifyHistogram(histograms, 'first_contentful_paint_time', 1, 1600); }); @@ -212,10 +244,12 @@ tr.b.unittest.testSuite(function() { verifyHistogram(histograms, 'messageloop_start_time', 1, 10); verifyHistogram(histograms, 'experimental_navigation_start_time', 0, undefined); - verifyHistogram(histograms, 'navigation_commit_time', 0, undefined); - verifyHistogram(histograms, 'experimental_content_start_time', 0, + verifyHistogram(histograms, 'experimental_network_request_start_time', 0, undefined); + verifyHistogram(histograms, 'navigation_commit_time', 0, undefined); verifyHistogram(histograms, 'first_contentful_paint_time', 1, 2); + verifyHistogram(histograms, 'process_create_to_app_start_time', 0, + undefined); }); // Checks the metrics after adding an offset to events in the model, and @@ -226,9 +260,11 @@ tr.b.unittest.testSuite(function() { verifyHistogram(histograms, 'messageloop_start_time', 1, 1707.0625); verifyHistogram(histograms, 'experimental_navigation_start_time', 1, 2207.375); + verifyHistogram(histograms, 'experimental_network_request_start_time', 1, + 2207.375 + 110); verifyHistogram(histograms, 'navigation_commit_time', 1, 4214.875); - verifyHistogram(histograms, 'experimental_content_start_time', 1, 2707); verifyHistogram(histograms, 'first_contentful_paint_time', 1, 1607); + verifyHistogram(histograms, 'process_create_to_app_start_time', 1, 107); }); test('androidStartupMetric_twoSessions', function() { @@ -249,12 +285,35 @@ tr.b.unittest.testSuite(function() { 2, 1700.0625, 1700.0625 + delta); verifyHistogramRange(histograms, 'experimental_navigation_start_time', 2, 2200.375, 2200.375 + delta); + verifyHistogramRange(histograms, 'experimental_network_request_start_time', + 2, 2200.375 + 110, 2200.375 + delta + 110); verifyHistogramRange(histograms, 'navigation_commit_time', 2, 4200.875, 4200.875 + delta * 2); - verifyHistogramRange(histograms, 'experimental_content_start_time', - 2, 2700, 2700 + delta); verifyHistogramRange(histograms, 'first_contentful_paint_time', 2, 1600, 1600 + delta); + verifyHistogramRange(histograms, 'process_create_to_app_start_time', 2, 100, + 100 + delta); + }); + + test('androidStartupMetric_extraNavigations', function() { + const histograms = new tr.v.HistogramSet(); + function makeTestModelWithExtraNavigations() { + return tr.c.TestUtils.newModel(function(model) { + const mainThread = fillModelWithOneBrowserSession(model, 0.0, 0.0); + addEarlyEventsToBeIgnored(model, 0.0); + addEarlyEventsToBeIgnored(model, 20.0); + // The first commit time is hardcoded to match how it is added in + // fillModelWithOneBrowserSession(). + const veryFirstCommitTime = 9000.5 + 2000.5; + addNavigationEvent(mainThread, veryFirstCommitTime + 20.0, 5.0); + }); + } + tr.metrics.sh.androidStartupMetric(histograms, makeTestModelWithExtraNavigations()); + verifyHistogram(histograms, 'messageloop_start_time', 1, 1700.0625); + verifyHistogram(histograms, 'experimental_navigation_start_time', 1, + 2200.375); + verifyHistogram(histograms, 'experimental_network_request_start_time', 1, + 2200.375 + 110); }); }); </script> 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 0c20030edc1..fba89459e00 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 @@ -6,6 +6,7 @@ found in the LICENSE file. --> <link rel="import" href="/tracing/core/test_utils.html"> +<link rel="import" href="/tracing/extras/chrome/chrome_test_utils.html"> <link rel="import" href="/tracing/extras/importer/trace_event_importer.html"> <link rel="import" href="/tracing/metrics/blink/gc_metric.html"> <link rel="import" href="/tracing/metrics/v8/utils.html"> diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/blink/resource_metric.html b/chromium/third_party/catapult/tracing/tracing/metrics/blink/resource_metric.html new file mode 100644 index 00000000000..bb186a74e9d --- /dev/null +++ b/chromium/third_party/catapult/tracing/tracing/metrics/blink/resource_metric.html @@ -0,0 +1,51 @@ +<!DOCTYPE html> +<!-- +Copyright 2021 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. +--> + +<link rel="import" href="/tracing/extras/chrome/event_finder_utils.html"> +<link rel="import" href="/tracing/metrics/metric_registry.html"> + +<script> +'use strict'; + +/** + * This metric is used for for blink network metrics + * - blinkRequestResourceCount: the count of requested resources + */ +tr.exportTo('tr.metrics', function() { + function blinkResourceMetric(histograms, model, opt_options) { + const chromeHelper = model.getOrCreateHelper( + tr.model.helpers.ChromeModelHelper); + if (!chromeHelper) { + // Chrome isn't present. + return; + } + const CATEGORY = 'blink.resource'; + const NAME = 'ResourceFetcher::requestResource'; + let count = 0; + // Collect trace events. + for (const helper of Object.values(chromeHelper.rendererHelpers)) { + if (helper.isChromeTracingUI) continue; + const events = tr.e.chrome.EventFinderUtils.getMainThreadEvents( + helper, NAME, CATEGORY); + for (const event of events) { + count++; + } + } + // Generate histograms. + histograms.createHistogram( + 'blinkRequestResourceCount', tr.b.Unit.byName.count, count); + } + + tr.metrics.MetricRegistry.register(blinkResourceMetric, { + supportsRangeOfInterest: false, + }); + + return { + blinkResourceMetric, + }; +}); +</script> diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/blink/resource_metric_test.html b/chromium/third_party/catapult/tracing/tracing/metrics/blink/resource_metric_test.html new file mode 100644 index 00000000000..c11530c46fe --- /dev/null +++ b/chromium/third_party/catapult/tracing/tracing/metrics/blink/resource_metric_test.html @@ -0,0 +1,45 @@ +<!DOCTYPE html> +<!-- +Copyright 2021 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. +--> + +<link rel="import" href="/tracing/core/test_utils.html"> +<link rel="import" href="/tracing/extras/chrome/chrome_test_utils.html"> +<link rel="import" href="/tracing/metrics/blink/resource_metric.html"> +<link rel="import" href="/tracing/value/histogram_set.html"> + +<script> +'use strict'; + +tr.b.unittest.testSuite(function() { + test('blinkRequestResourceCount_general', function() { + const model = tr.e.chrome.ChromeTestUtils.newChromeModel(function(model) { + const rendererProcess = model.rendererProcess; + const mainThread = model.rendererMain; + const mainFrame = { id: '0xdeadbeef', is_main: true }; + const emitEvent = (time, cat, title, url, duration) => { + mainThread.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ + cat, + title, + start: time, + duration, + args: {url}, + })); + }; + emitEvent(1000, 'blink.resource', 'ResourceFetcher::requestResource', 'A.js', 0.1); + emitEvent(2001, 'blink.resource', 'ignore', 'A.js', 0.1); + emitEvent(2002, 'ignore', 'ignore', 'A.js', 0.1); + emitEvent(3200, 'blink.resource', 'ResourceFetcher::requestResource', 'b.js', 0.1); + emitEvent(4201, 'ignore', 'ResourceFetcher::requestResource', 'b.js', 0.1); + }); + + const histograms = new tr.v.HistogramSet(); + tr.metrics.blinkResourceMetric(histograms, model); + const histogram = histograms.getHistogramNamed('blinkRequestResourceCount'); + assert.strictEqual(histogram.sampleValues.length, 1); + assert.strictEqual(histogram.running.count, 1); + assert.strictEqual(histogram.running.mean, 2); + }); +}); 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 2a766b2477c..c5a9817c522 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 @@ -91,7 +91,7 @@ class CompareSamplesUnittest(unittest.TestCase): prev_bucket += width for value in values: for bucket in buckets: - if value >= bucket['low'] and value < bucket['high']: + if bucket['low'] <= value < bucket['high']: bucket['count'] += 1 break charts = { diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/core_web_vitals_metric.html b/chromium/third_party/catapult/tracing/tracing/metrics/core_web_vitals_metric.html new file mode 100644 index 00000000000..34382936e44 --- /dev/null +++ b/chromium/third_party/catapult/tracing/tracing/metrics/core_web_vitals_metric.html @@ -0,0 +1,111 @@ +<!DOCTYPE html> +<!-- +Copyright 2022 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. +--> + +<!-- +These metrics are designed to read off Core Web Vitals metrics (and their +important diagnostic metrics like First Contentful Paint) from the trace events +generated by the UkmPageLoadMetricsObserver, doing as little post-processing as +possible. These should therefore automatically stay updated as the definitions +in chromium C++ code evolve. See http://go/cwv-ukm-lab-metrics for more details. +--> + +<link rel="import" href="/tracing/base/unit.html"> +<link rel="import" href="/tracing/metrics/metric_registry.html"> +<link rel="import" href="/tracing/model/helpers/chrome_model_helper.html"> +<link rel="import" href="/tracing/value/diagnostics/alert_groups.html"> +<link rel="import" href="/tracing/value/histogram.html"> + + +<script> +'use strict'; + +tr.exportTo('tr.metrics', function() { + const CWV_HISTOGRAM_NAMES = { + FCP_HISTOGRAM_NAME: 'cwv:first_contentful_paint', + LCP_HISTOGRAM_NAME: 'cwv:largest_contentful_paint', + CLS_HISTOGRAM_NAME: 'cwv:cumulative_layout_shift', + }; + + function coreWebVitalsMetric(histograms, model) { + const chromeHelper = model.getOrCreateHelper( + tr.model.helpers.ChromeModelHelper); + if (chromeHelper === undefined) return; + + const firstContentfulPaintHistogram = + histograms.createHistogram(CWV_HISTOGRAM_NAMES.FCP_HISTOGRAM_NAME, + tr.b.Unit.byName.timeDurationInMs_smallerIsBetter, [], { + alertGrouping: [tr.v.d.ALERT_GROUPS.LOADING_PAINT], + }); + const largestContentfulPaintHistogram = + histograms.createHistogram(CWV_HISTOGRAM_NAMES.LCP_HISTOGRAM_NAME, + tr.b.Unit.byName.timeDurationInMs_smallerIsBetter, [], { + alertGrouping: [tr.v.d.ALERT_GROUPS.LOADING_PAINT], + }); + const cumulativeLayoutShiftHistogram = + histograms.createHistogram(CWV_HISTOGRAM_NAMES.CLS_HISTOGRAM_NAME, + tr.b.Unit.byName.unitlessNumber_smallerIsBetter, [], { + alertGrouping: [tr.v.d.ALERT_GROUPS.LOADING_LAYOUT], + }); + + for (const browserHelper of Object.values(chromeHelper.browserHelpers)) { + const mainThread = browserHelper.mainThread; + const latestTimingBySourceId = new Map(); + + for (const event of mainThread.sliceGroup.childEvents()) { + if (event.category === 'loading' && + event.title === 'UkmPageLoadTimingUpdate') { + const timingUpdate = event.args['ukm_page_load_timing_update']; + const sourceId = timingUpdate['ukm_source_id']; + latestTimingBySourceId.set(sourceId, timingUpdate); + } + } + + for (const timingUpdate of latestTimingBySourceId.values()) { + const timingUpdateDiagnostic = { + 'page_load_timing': new tr.v.d.GenericSet([timingUpdate]), + }; + + // Note: This might always be a perfect round number because as of + // 2022/09/13, FCP values are clamped to 1ms resolution when sent to the + // browser process to prevent timing attacks. + const firstContentfulPaint = + timingUpdate['first_contentful_paint_ms']; + + // Do not add any core web vitals metrics if page did not reach FCP. + if (firstContentfulPaint === undefined) continue; + + firstContentfulPaintHistogram.addSample( + firstContentfulPaint, timingUpdateDiagnostic); + + // Note: this could be undefined if somehow the browser determined the + // LCP data is invalid. They should be exactly the same cases where we + // also do not report data to UKM. + largestContentfulPaintHistogram.addSample( + timingUpdate['latest_largest_contentful_paint_ms'], + timingUpdateDiagnostic); + + // Note: There is no need to specially handle the case when there are no + // layout shifts on the page. The latest_cumulative_layout_shift value + // should be reported as 0 in the trace event by the browser in that + // case, not undefined. Not that CLS can still be undefined if data + // is invalidated for some reason, e.g. see + // https://crsrc.org/c/components/page_load_metrics/browser/layout_shift_normalization.cc;l=25;drc=8d399817282e3c12ed54eb23ec42a5e418298ec6 + cumulativeLayoutShiftHistogram.addSample( + timingUpdate['latest_cumulative_layout_shift'], + timingUpdateDiagnostic); + } + } + } + + tr.metrics.MetricRegistry.register(coreWebVitalsMetric); + + return { + coreWebVitalsMetric, + CWV_HISTOGRAM_NAMES, + }; +}); +</script> diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/core_web_vitals_metric_test.html b/chromium/third_party/catapult/tracing/tracing/metrics/core_web_vitals_metric_test.html new file mode 100644 index 00000000000..25354674ae1 --- /dev/null +++ b/chromium/third_party/catapult/tracing/tracing/metrics/core_web_vitals_metric_test.html @@ -0,0 +1,174 @@ +<!DOCTYPE html> +<!-- +Copyright 2022 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. +--> + +<link rel="import" href="/tracing/base/utils.html"> +<link rel="import" href="/tracing/extras/chrome/chrome_test_utils.html"> +<link rel="import" href="/tracing/metrics/core_web_vitals_metric.html"> +<link rel="import" href="/tracing/value/histogram_set.html"> + +<script> +'use strict'; + +tr.b.unittest.testSuite(function() { + const { + FCP_HISTOGRAM_NAME, + LCP_HISTOGRAM_NAME, + CLS_HISTOGRAM_NAME, + } = tr.metrics.CWV_HISTOGRAM_NAMES; + + const timingUpdateEvent = (args) => { + return tr.c.TestUtils.newSliceEx({ + title: 'UkmPageLoadTimingUpdate', + cat: 'loading', + start: args.ts, + duration: 0, + args: { + ukm_page_load_timing_update: { + ukm_source_id: args.sourceId, + first_contentful_paint_ms: args.fcp, + latest_largest_contentful_paint_ms: args.lcp, + latest_cumulative_layout_shift: args.cls, + }, + }, + }); + }; + + test('histogramsAreAlwaysCreatedButCanBeEmpty', () => { + const model = tr.e.chrome.ChromeTestUtils.newChromeModel((model) => { + console.log(model); + model.browserMain.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx( + {title: 'SomeRandomEvent', start: 2, duration: 0})); + }); + + const histograms = new tr.v.HistogramSet(); + tr.metrics.coreWebVitalsMetric(histograms, model); + + assert.strictEqual( + 0, histograms.getHistogramNamed(FCP_HISTOGRAM_NAME).numValues); + assert.strictEqual( + 0, histograms.getHistogramNamed(LCP_HISTOGRAM_NAME).numValues); + assert.strictEqual( + 0, histograms.getHistogramNamed(CLS_HISTOGRAM_NAME).numValues); + }); + + test('metricIsReportedFromLatestEvent', () => { + const model = tr.e.chrome.ChromeTestUtils.newChromeModel((model) => { + model.browserMain.sliceGroup.pushSlice(timingUpdateEvent( + {sourceId: 42, ts: 11, fcp: 123, lcp: 300, cls: 2})); + model.browserMain.sliceGroup.pushSlice(timingUpdateEvent( + {sourceId: 42, ts: 12, fcp: 124, lcp: 301, cls: 3})); + }); + + const histograms = new tr.v.HistogramSet(); + tr.metrics.coreWebVitalsMetric(histograms, model); + + assert.strictEqual( + 1, histograms.getHistogramNamed(FCP_HISTOGRAM_NAME).numValues); + assert.strictEqual( + 124, histograms.getHistogramNamed(FCP_HISTOGRAM_NAME).max); + assert.strictEqual( + 1, histograms.getHistogramNamed(LCP_HISTOGRAM_NAME).numValues); + assert.strictEqual( + 301, histograms.getHistogramNamed(LCP_HISTOGRAM_NAME).max); + assert.strictEqual( + 1, histograms.getHistogramNamed(CLS_HISTOGRAM_NAME).numValues); + assert.strictEqual( + 3, histograms.getHistogramNamed(CLS_HISTOGRAM_NAME).max); + }); + + test('noMetricIsReportedIfFCPIsNotReached', () => { + const model = tr.e.chrome.ChromeTestUtils.newChromeModel((model) => { + model.browserMain.sliceGroup.pushSlice(timingUpdateEvent( + {sourceId: 42, ts: 11, lcp: 300, cls: 2})); // FCP missing. + }); + + const histograms = new tr.v.HistogramSet(); + tr.metrics.coreWebVitalsMetric(histograms, model); + + assert.strictEqual( + 0, histograms.getHistogramNamed(FCP_HISTOGRAM_NAME).numValues); + assert.strictEqual( + 0, histograms.getHistogramNamed(LCP_HISTOGRAM_NAME).numValues); + assert.strictEqual( + 0, histograms.getHistogramNamed(CLS_HISTOGRAM_NAME).numValues); + }); + + test('multipleNavigations', () => { + const modelClsMissing = + tr.e.chrome.ChromeTestUtils.newChromeModel((model) => { + // First navigation. + model.browserMain.sliceGroup.pushSlice(timingUpdateEvent( + {sourceId: 42, ts: 11, fcp: 123, lcp: 300, cls: 2})); + model.browserMain.sliceGroup.pushSlice(timingUpdateEvent( + {sourceId: 42, ts: 11, fcp: 123, lcp: 301, cls: 3})); + + // Second navigation. + model.browserMain.sliceGroup.pushSlice(timingUpdateEvent( + {sourceId: 43, ts: 11, fcp: 223, lcp: 400, cls: 12})); + model.browserMain.sliceGroup.pushSlice(timingUpdateEvent( + {sourceId: 43, ts: 11, fcp: 223, lcp: 401, cls: 13})); + }); + + const histograms = new tr.v.HistogramSet(); + tr.metrics.coreWebVitalsMetric(histograms, modelClsMissing); + + assert.strictEqual( + 2, histograms.getHistogramNamed(FCP_HISTOGRAM_NAME).numValues); + assert.strictEqual( + 123, histograms.getHistogramNamed(FCP_HISTOGRAM_NAME).min); + assert.strictEqual( + 223, histograms.getHistogramNamed(FCP_HISTOGRAM_NAME).max); + assert.strictEqual( + 2, histograms.getHistogramNamed(LCP_HISTOGRAM_NAME).numValues); + assert.strictEqual( + 301, histograms.getHistogramNamed(LCP_HISTOGRAM_NAME).min); + assert.strictEqual( + 401, histograms.getHistogramNamed(LCP_HISTOGRAM_NAME).max); + assert.strictEqual( + 2, histograms.getHistogramNamed(CLS_HISTOGRAM_NAME).numValues); + assert.strictEqual( + 3, histograms.getHistogramNamed(CLS_HISTOGRAM_NAME).min); + assert.strictEqual( + 13, histograms.getHistogramNamed(CLS_HISTOGRAM_NAME).max); + }); + + test('metricIsNotReportedIfMissingInLatestButPresentInEarlierEvent', () => { + // Metric can become missing in later update events if it's invalidated / + // tainted somehow in the browser. We do not report the metric when that + // happens (as opposed to reporting the last valid value of the metric.) + + const modelClsMissing = + tr.e.chrome.ChromeTestUtils.newChromeModel((model) => { + // First navigation. + model.browserMain.sliceGroup.pushSlice(timingUpdateEvent( + {sourceId: 42, ts: 11, fcp: 123, lcp: 300, cls: 2})); + model.browserMain.sliceGroup.pushSlice(timingUpdateEvent( + {sourceId: 42, ts: 11, fcp: 123, lcp: 301})); // CLS missing. + + // Second navigation. + model.browserMain.sliceGroup.pushSlice(timingUpdateEvent( + {sourceId: 43, ts: 11, fcp: 123, lcp: 300, cls: 2})); + model.browserMain.sliceGroup.pushSlice(timingUpdateEvent( + {sourceId: 43, ts: 11, fcp: 123, cls: 3})); // LCP missing. + }); + + const histograms = new tr.v.HistogramSet(); + tr.metrics.coreWebVitalsMetric(histograms, modelClsMissing); + + assert.strictEqual( + 2, histograms.getHistogramNamed(FCP_HISTOGRAM_NAME).numValues); + assert.strictEqual( + 1, histograms.getHistogramNamed(LCP_HISTOGRAM_NAME).numValues); + assert.strictEqual( + 301, histograms.getHistogramNamed(LCP_HISTOGRAM_NAME).max); + assert.strictEqual( + 1, histograms.getHistogramNamed(CLS_HISTOGRAM_NAME).numValues); + assert.strictEqual( + 3, histograms.getHistogramNamed(CLS_HISTOGRAM_NAME).max); + }); +}); +</script> diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/count_sum_metric.html b/chromium/third_party/catapult/tracing/tracing/metrics/count_sum_metric.html new file mode 100644 index 00000000000..35148fcce85 --- /dev/null +++ b/chromium/third_party/catapult/tracing/tracing/metrics/count_sum_metric.html @@ -0,0 +1,81 @@ +<!DOCTYPE html> +<!-- +Copyright 2021 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. +--> + +<link rel="import" href="/tracing/extras/chrome/event_finder_utils.html"> +<link rel="import" href="/tracing/metrics/metric_registry.html"> + +<script> +'use strict'; + +/** + * This metric is used for custom benchmarks which need to record counts + * or sums of events ocurring in the renderer threads of traces. This is useful + * for one-off cluster telemetry analysis. + * For trace events with category "benchmark", and name "count_sum" and a + * "counter" field with the name of the counter, it records one or two metrics: + * - [counter]_count: the count of trace events with the same counter field. + * - [counter]_sum: the sum of values of trace events with that field, if any + * have a value field. + */ +tr.exportTo('tr.metrics', function() { + function countSumMetric(histograms, model, opt_options) { + const chromeHelper = model.getOrCreateHelper( + tr.model.helpers.ChromeModelHelper); + if (!chromeHelper) { + // Chrome isn't present. + return; + } + + const CATEGORY = 'benchmark'; + const NAME = 'count_sum'; + const counts = new Map(); + const sums = new Map(); + // Collect trace events. + for (const pid in chromeHelper.rendererHelpers) { + const helper = chromeHelper.rendererHelpers[pid]; + if (helper.isChromeTracingUI) continue; + + const events = tr.e.chrome.EventFinderUtils.getMainThreadEvents( + helper, NAME, CATEGORY); + for (const event of events) { + const c = event.args.counter; + if (!c) { + continue; + } + if (!counts.get(c)) { + counts.set(c, 0); + } + counts.set(c, counts.get(c) + 1); + if (event.args.value) { + if (!sums.get(c)) { + sums.set(c, 0); + } + sums.set(c, sums.get(c) + event.args.value); + } + } + } + + // Generate histograms. + counts.forEach((value, key) => { + histograms.createHistogram( + 'count_' + key, tr.b.Unit.byName.count, value); + }); + sums.forEach((value, key) => { + histograms.createHistogram( + 'sum_' + key, tr.b.Unit.byName.unitlessNumber, value); + }); + } + + tr.metrics.MetricRegistry.register(countSumMetric, { + supportsRangeOfInterest: false, + }); + + return { + countSumMetric, + }; +}); +</script> diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/count_sum_metric_test.html b/chromium/third_party/catapult/tracing/tracing/metrics/count_sum_metric_test.html new file mode 100644 index 00000000000..a34fb9c7b84 --- /dev/null +++ b/chromium/third_party/catapult/tracing/tracing/metrics/count_sum_metric_test.html @@ -0,0 +1,61 @@ +<!DOCTYPE html> +<!-- +Copyright 2020 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. +--> + +<link rel="import" href="/tracing/core/test_utils.html"> +<link rel="import" href="/tracing/extras/chrome/chrome_test_utils.html"> +<link rel="import" href="/tracing/metrics/count_sum_metric.html"> +<link rel="import" href="/tracing/value/histogram_set.html"> + +<script> +'use strict'; + +tr.b.unittest.testSuite(function() { + test('countSumMetric_general', function() { + const model = tr.e.chrome.ChromeTestUtils.newChromeModel(function(model) { + const rendererProcess = model.rendererProcess; + const mainThread = model.rendererMain; + const mainFrame = { id: '0xdeadbeef', is_main: true }; + const subframe = { id: '0xdeadb33f', is_main: false }; + const emitEvent = (time, cat, title, counter, value) => { + mainThread.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ + cat, + title, + start: time, + duration: 0.0, + args: {counter, value} + })); + }; + emitEvent(1000, 'benchmark', 'count_sum', 'A', 2.1); + emitEvent(3000, 'benchmark', 'count_sum', 'B', null); + emitEvent(2000, 'benchmark', 'count_sum', 'A', 19.4); + emitEvent(4000, 'benchmark', 'count_sum', 'B', null); + emitEvent(4000, 'benchmark', 'count_sum', 'B', null); + emitEvent(4000, 'donotcount', 'count_sum', 'C', null); + emitEvent(4000, 'benchmark', 'foo', 'D', null); + }); + + const histograms = new tr.v.HistogramSet(); + tr.metrics.countSumMetric(histograms, model); + const histAc = histograms.getHistogramNamed('count_A'); + assert.strictEqual(histAc.sampleValues.length, 1); + assert.strictEqual(histAc.running.count, 1); + assert.strictEqual(histAc.running.mean, 2); + const histAs = histograms.getHistogramNamed('sum_A'); + assert.strictEqual(histAs.sampleValues.length, 1); + assert.strictEqual(histAs.running.count, 1); + assert.strictEqual(histAs.running.mean, 21.5); + const histBc = histograms.getHistogramNamed('count_B'); + assert.strictEqual(histBc.sampleValues.length, 1); + assert.strictEqual(histBc.running.count, 1); + assert.strictEqual(histBc.running.mean, 3); + assert.isUndefined(histograms.getHistogramNamed('sum_B')); + assert.isUndefined(histograms.getHistogramNamed('count_C')); + assert.isUndefined(histograms.getHistogramNamed('sum_C')); + assert.isUndefined(histograms.getHistogramNamed('count_D')); + assert.isUndefined(histograms.getHistogramNamed('sum_D')); + }); +}); diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/custom_metric.html b/chromium/third_party/catapult/tracing/tracing/metrics/custom_metric.html new file mode 100644 index 00000000000..63823b49cee --- /dev/null +++ b/chromium/third_party/catapult/tracing/tracing/metrics/custom_metric.html @@ -0,0 +1,155 @@ +<!DOCTYPE html> +<!-- +Copyright 2020 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. +--> + +<link rel="import" href="/tracing/metrics/metric_registry.html"> + +<script> +'use strict'; + +/** + * This metric is used for custom performance benchmark. + * It captures the following: + * - Metrics reported by telemetry in the format of + * performance.mark('custom_metric:manifest:[{"name":<METRIC_NAME1>},{"name":<METRIC_NAME2>}...]'); + * - Duration between performance.mark('<METRIC_NAME>:metric_begin') + * and performance.mark('<METRIC_NAME>:metric_end') on the JS side. + * - performance.mark('<METRIC_NAME>:<METRIC_VALUE>:metric_value') + * on the JS side. + */ +tr.exportTo('tr.metrics', function() { + function customMetric(histograms, model, opt_options) { + const chromeHelper = model.getOrCreateHelper( + tr.model.helpers.ChromeModelHelper); + if (!chromeHelper) { + // Chrome isn't present. + return; + } + + const metrics = getMetrics(chromeHelper); + const traces = new Map(); + const benchmarkValues = new Map(); + // Collect trace events. + for (const helper of chromeHelper.browserHelpers) { + helper.iterAllThreads(function(thread) { + for (const slice of thread.sliceGroup.slices.concat( + thread.asyncSliceGroup.slices)) { + if (!slice.error && metrics.has(slice.title)) { + if (!traces.has(slice.title)) { + traces.set(slice.title, []); + } + traces.get(slice.title).push(slice.duration); + } + } + }); + } + + // Collect performance.mark(). + const METRIC_BEGIN = 'metric_begin'; + const METRIC_END = 'metric_end'; + const METRIC_VALUE = 'metric_value'; + const marks = new Map(); + for (const helper of Object.values(chromeHelper.rendererHelpers)) { + if (!helper.mainThread) continue; + for (const event of helper.mainThread.sliceGroup.childEvents()) { + if (!event.category.includes('blink.user_timing')) continue; + const {title} = event; + const index = title.lastIndexOf(':'); + if (index === -1) { + continue; + } + const name = title.substring(0, index); + const lastPart = title.substring(index + 1); + if (lastPart === METRIC_BEGIN) { + marks.set(name, event); + } else if (lastPart === METRIC_END) { + if (!marks.has(name)) { + continue; + } + const range = tr.b.math.Range.fromExplicitRange( + marks.get(name).start, event.start); + if (!traces.has(name)) { + traces.set(name, []); + } + traces.get(name).push(range.duration); + marks.delete(name); + } else if (lastPart === METRIC_VALUE) { + const index2 = name.lastIndexOf(':'); + if (index2 === -1) { + continue; + } + const key = name.substring(0, index2); + const value = Number(name.substring(index2 + 1)); + if (key && !isNaN(value)) { + if (!benchmarkValues.has(key)) { + benchmarkValues.set(key, []); + } + benchmarkValues.get(key).push(value); + } + } + } + } + + // Generate histograms. + traces.forEach((value, key) => { + createMetricHistogram(histograms, + key, + tr.b.Unit.byName.timeDurationInMs_smallerIsBetter, + value, + metrics.get(key)); + }); + benchmarkValues.forEach((value, key) => { + createMetricHistogram(histograms, + key, + tr.b.Unit.byName.unitlessNumber_smallerIsBetter, + value, + metrics.get(key)); + }); + } + + // Get metrics from performance.mark() + function getMetrics(chromeHelper) { + const CUSTOM_METRIC_MANIFEST_PREFIX = 'custom_metric:manifest:' + for (const helper of Object.values(chromeHelper.rendererHelpers)) { + if (!helper.mainThread) continue; + for (const event of helper.mainThread.sliceGroup.childEvents()) { + if (!event.category.includes('blink.user_timing')) continue; + const {title} = event; + if (title.startsWith(CUSTOM_METRIC_MANIFEST_PREFIX)) { + const result = JSON.parse(title.substring(CUSTOM_METRIC_MANIFEST_PREFIX.length)); + return new Map(result.map(event => [event.name, event])); + } + } + } + return new Map(); + } + + // Create histogram with default unit and + // read unit and description from the metric manifest if available. + function createMetricHistogram(histograms, key, defaultUnit, value, metric) { + let unit = metric && metric.unit; + if (unit) { + unit = tr.b.Unit.fromJSON(unit); + } + const description = metric && metric.description; + const histogram = histograms.createHistogram(key, + unit || defaultUnit, + value); + if (description) { + histogram.description = description; + } + return histogram; + } + + tr.metrics.MetricRegistry.register(customMetric, { + supportsRangeOfInterest: false, + }); + + return { + customMetric, + }; +}); +</script> diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/custom_metric_test.html b/chromium/third_party/catapult/tracing/tracing/metrics/custom_metric_test.html new file mode 100644 index 00000000000..4a90395a6ef --- /dev/null +++ b/chromium/third_party/catapult/tracing/tracing/metrics/custom_metric_test.html @@ -0,0 +1,273 @@ +<!DOCTYPE html> +<!-- +Copyright 2020 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. +--> + +<link rel="import" href="/tracing/core/test_utils.html"> +<link rel="import" href="/tracing/metrics/custom_metric.html"> +<link rel="import" href="/tracing/value/histogram_set.html"> + +<script> +'use strict'; + +tr.b.unittest.testSuite(function() { + test('customMetric_collectTrace', function() { + const model = tr.c.TestUtils.newModel((model) => { + const browserThread = setUpBrowserThread(model); + addTraces(browserThread); + addSingleTrace(setUpOtherBrowserThread(model)); + addSingleTrace(setUpOtherRendererThread(model)); + const rendererMainThread = setUpRendererMainThread(model); + setMetrics(rendererMainThread); + }); + const histograms = new tr.v.HistogramSet(); + tr.metrics.customMetric(histograms, model); + const hist1 = histograms.getHistogramNamed('metric1'); + assert.strictEqual(hist1.numValues, 2); + assert.strictEqual(hist1.unit.asJSON(), 'ms_smallerIsBetter'); + const hist2 = histograms.getHistogramNamed('metric2'); + assert.strictEqual(hist2.numValues, 1); + assert.strictEqual(hist2.unit.asJSON(), 'ms_biggerIsBetter'); + assert.strictEqual(hist2.description, 'This is metric2'); + const hist3 = histograms.getHistogramNamed('metric3'); + // metric3 is not collected because its name isn't reported. + assert.isUndefined(hist3); + const hist4 = histograms.getHistogramNamed('metric4'); + assert.strictEqual(hist4.numValues, 2); + // metric5 is collected from both other browser thread and + // other renderer thread. + const hist5 = histograms.getHistogramNamed('metric5'); + assert.strictEqual(hist5.numValues, 2); + }); + + test('customMetric_collectPerformanceMark', function() { + const model = tr.c.TestUtils.newModel((model) => { + const rendererMainThread = setUpRendererMainThread(model); + addPerformanceMark(rendererMainThread); + }); + const histograms = new tr.v.HistogramSet(); + tr.metrics.customMetric(histograms, model); + const hist1 = histograms.getHistogramNamed('metric1'); + assert.strictEqual(hist1.numValues, 2); + assert.strictEqual(hist1.max, 5.0); + assert.strictEqual(hist1.min, 2.0); + assert.strictEqual(hist1.average, 3.5); + const hist2 = histograms.getHistogramNamed('metric2'); + assert.strictEqual(hist2.numValues, 1); + assert.strictEqual(hist2.max, 18.0); + assert.strictEqual(hist2.min, 18.0); + assert.strictEqual(hist2.average, 18.0); + // metric3 is not collected because + // ":metric_begin" and ":metric_end" are missing. + assert.isUndefined(histograms.getHistogramNamed('metric3')); + // metric4 is not collected because + // ":metric_end" is missing. + assert.isUndefined(histograms.getHistogramNamed('metric4')); + // metric5 is not collected because + // ":metric_begin" is missing. + assert.isUndefined(histograms.getHistogramNamed('metric5')); + const hist3 = histograms.getHistogramNamed('metric6'); + assert.strictEqual(hist3.numValues, 2); + assert.strictEqual(hist3.max, 51); + assert.strictEqual(hist3.min, 49); + assert.strictEqual(hist3.average, 50); + // metric7 is not collected because + // benmark value is invalid. + assert.isUndefined(histograms.getHistogramNamed('metric7')); + // metric8 is not collected because + // benchmark value is missing. + assert.isUndefined(histograms.getHistogramNamed('metric8')); + }); + + function setUpBrowserThread(model) { + const BROWSER_PROCESS_ID = 1234; + const browserProcess = model.getOrCreateProcess(BROWSER_PROCESS_ID); + const browserThread = browserProcess.getOrCreateThread(2); + browserThread.name = 'CrBrowserMain'; + return browserThread; + } + + function setUpRendererMainThread(model) { + const RENDERER_PROCESS_ID = 2345; + const rendererProcess = model.getOrCreateProcess(RENDERER_PROCESS_ID); + const mainThread = rendererProcess.getOrCreateThread(23); + mainThread.name = 'CrRendererMain'; + return mainThread; + } + + function setUpOtherBrowserThread(model) { + const BROWSER_PROCESS_ID = 1234; + const browserProcess = model.getOrCreateProcess(BROWSER_PROCESS_ID); + const thread = browserProcess.getOrCreateThread(3); + thread.name = 'Other'; + return thread; + } + + function setUpOtherRendererThread(model) { + const RENDERER_PROCESS_ID = 2345; + const rendererProcess = model.getOrCreateProcess(RENDERER_PROCESS_ID); + const thread = rendererProcess.getOrCreateThread(4); + thread.name = 'Other'; + return thread; + } + + function addEvent(mainThread, event) { + mainThread.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ + cat: 'blink.user_timing', + title: event.title, + start: event.start, + duration: 0.0, + })); + } + + function addTraces(thread) { + [ + { + cat: 'browser', + title: 'metric1', + start: 1, + duration: 1, + }, + { + cat: 'browser', + title: 'metric1', + start: 2, + duration: 2, + }, + { + cat: 'browser', + title: 'metric2', + start: 3, + duration: 3, + }, + { + cat: 'browser', + title: 'metric3', + start: 4, + duration: 4, + } + ].forEach(slice => { + thread.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx(slice)); + }); + + [ + { + cat: 'browser', + title: 'metric4', + start: 1, + duration: 1, + }, + { + cat: 'browser', + title: 'metric4', + start: 2, + duration: 2, + } + ].forEach(slice => { + thread.asyncSliceGroup.push(tr.c.TestUtils.newAsyncSliceEx(slice)); + }); + } + + function addSingleTrace(thread) { + const slice = { + cat: 'browser', + title: 'metric5', + start: 1, + duration: 1, + }; + thread.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx(slice)); + } + + function setMetrics(thread) { + const traceEvents = [ + { + name: "metric1", + }, + { + name: "metric2", + unit: "ms_biggerIsBetter", + description: "This is metric2" + }, + { + name: "metric4", + }, + { + name: "metric5", + }, + ] + const report = `custom_metric:manifest:${JSON.stringify(traceEvents)}`; + thread.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ + cat: 'blink.user_timing', + title: report, + start: 0, + duration: 0, + })); + } + + function addPerformanceMark(thread) { + [ + { + title: 'metric1:metric_begin', + start: 10, + }, + { + title: 'metric1:metric_end', + start: 15, + }, + { + title: 'metric1:metric_begin', + start: 17, + }, + { + title: 'metric1:metric_end', + start: 19, + }, + { + title: 'metric2:metric_begin', + start: 2, + }, + { + title: 'metric2:metric_end', + start: 20, + }, + { + title: 'metric3', + start: 25, + }, + { + title: 'metric4:metric_begin', + start: 5, + }, + { + title: 'metric5:metric_end', + start: 10, + }, + { + title: 'metric6:49:metric_value', + start: 10, + }, + { + title: 'metric6:51:metric_value', + start: 20, + }, + { + title: 'metric7:invalid value:metric_value', + start: 10, + }, + { + title: 'metric8:metric_value', + start: 10, + } + ].forEach(slice => { + thread.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ + cat: 'blink.user_timing', + title: slice.title, + start: slice.start, + duration: 0, + })); + }); + } +}); +</script> diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/discover.py b/chromium/third_party/catapult/tracing/tracing/metrics/discover.py index ef532c6d0df..75802db5d06 100644 --- a/chromium/third_party/catapult/tracing/tracing/metrics/discover.py +++ b/chromium/third_party/catapult/tracing/tracing/metrics/discover.py @@ -30,5 +30,4 @@ def DiscoverMetrics(modules_to_load): if res.returncode != 0: raise RuntimeError('Error running metrics_discover_cmdline: ' + res.stdout) - else: - return [str(m) for m in json.loads(res.stdout)] + return [str(m) for m in json.loads(res.stdout)] diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/discover_unittest.py b/chromium/third_party/catapult/tracing/tracing/metrics/discover_unittest.py index 10b81b547c8..978a9146d28 100644 --- a/chromium/third_party/catapult/tracing/tracing/metrics/discover_unittest.py +++ b/chromium/third_party/catapult/tracing/tracing/metrics/discover_unittest.py @@ -11,7 +11,7 @@ class MetricsDiscoverUnittest(unittest.TestCase): self.assertFalse(discover.DiscoverMetrics([])) def testMetricsDiscoverNonEmpty(self): - self.assertEquals(['sampleMetric'], discover.DiscoverMetrics( + self.assertEqual(['sampleMetric'], discover.DiscoverMetrics( ['/tracing/metrics/sample_metric.html'])) def testMetricsDiscoverMultipleMetrics(self): 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 9ec388ec862..0b11d30142b 100644 --- a/chromium/third_party/catapult/tracing/tracing/metrics/media_metric.html +++ b/chromium/third_party/catapult/tracing/tracing/metrics/media_metric.html @@ -71,6 +71,14 @@ tr.exportTo('tr.metrics', function() { processData.calculateSeekTimes(mainThread); processData.calculateBufferingTimes(mainThread); + // Roughness metrics are output from a thread pool worker, so we don't + // have a convenient name for the thread. Check all threads. + const allThreads = + rendererHelper.process.findAllThreadsMatching(function() { + return true; + }); + processData.calculateVideoPlaybackQuality(allThreads); + processData.addMetricToHistograms(histograms); } } @@ -160,6 +168,20 @@ tr.exportTo('tr.metrics', function() { } } + calculateVideoPlaybackQuality(threads) { + for (const thread of threads) { + for (const event of thread.sliceGroup.getDescendantEvents()) { + if (event.title === 'VideoPlaybackRoughness') { + this.getPerPlaybackObject_(event.args.id) + .processVideoRoughness(event.args.roughness); + } else if (event.title === 'VideoPlaybackFreezing') { + this.getPerPlaybackObject_(event.args.id) + .processVideoFreezing(event.args.freezing); + } + } + } + } + addMetricToHistograms(histograms) { for (const [id, playbackData] of this.playbackIdToDataMap_) { playbackData.addMetricToHistograms(histograms); @@ -191,6 +213,8 @@ tr.exportTo('tr.metrics', function() { this.seekError_ = false; this.seekTimes_ = new Map(); this.currentSeek_ = undefined; + this.roughness_ = undefined; + this.freezing_ = undefined; } // API methods for retrieving metric values. Each method returns undefined @@ -245,6 +269,16 @@ tr.exportTo('tr.metrics', function() { return this.seekTimes_; } + // Reports aggregate roughness. + get roughness() { + return this.roughness_; + } + + // Reports aggregate freezing. + get freezing() { + return this.freezing_; + } + // API methods for processing data from trace events. processVideoRenderTime(videoRenderTime) { @@ -359,6 +393,20 @@ tr.exportTo('tr.metrics', function() { } } + processVideoRoughness(roughness) { + // Record the worst roughness. + if (this.roughness_ === undefined || this.roughness_ > roughness) { + this.roughness_ = roughness; + } + } + + processVideoFreezing(freezing) { + // Record the worst freezing. + if (this.freezing_ === undefined || this.freezing_ > freezing) { + this.freezing_ = freezing; + } + } + addMetricToHistograms(histograms) { this.addSample_(histograms, 'time_to_video_play', tr.b.Unit.byName.timeDurationInMs_smallerIsBetter, @@ -384,6 +432,12 @@ tr.exportTo('tr.metrics', function() { this.addSample_(histograms, 'buffering_time', tr.b.Unit.byName.timeDurationInMs_smallerIsBetter, this.bufferingTime); + this.addSample_(histograms, 'roughness', + tr.b.Unit.byName.count_smallerIsBetter, + this.roughness); + this.addSample_(histograms, 'freezing', + tr.b.Unit.byName.timeDurationInMs_smallerIsBetter, + this.freezing); } // @private 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 02f5dcf02b5..0cb63b11c8d 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 @@ -147,6 +147,12 @@ tr.exportTo('tr.metrics', function() { function validateDiagnosticNames(histograms) { for (const hist of histograms) { for (const name of hist.diagnostics.keys()) { + if (name === tr.v.d.RESERVED_NAMES.ALERT_GROUPING) { + // Metrics can set alert grouping when they create histogram. It's + // still a reserved diagnostic because that helps us enforce the right + // diagnostic shape. + continue; + } if (tr.v.d.RESERVED_NAMES_SET.has(name)) { throw new Error( `Illegal diagnostic name "${name}" on Histogram "${hist.name}"`); diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/partition_alloc/OWNERS b/chromium/third_party/catapult/tracing/tracing/metrics/partition_alloc/OWNERS new file mode 100644 index 00000000000..228f0c3184b --- /dev/null +++ b/chromium/third_party/catapult/tracing/tracing/metrics/partition_alloc/OWNERS @@ -0,0 +1,2 @@ +bikineev@chromium.org +mlippautz@chromium.org diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/partition_alloc/pcscan_metric.html b/chromium/third_party/catapult/tracing/tracing/metrics/partition_alloc/pcscan_metric.html new file mode 100644 index 00000000000..33743f757a5 --- /dev/null +++ b/chromium/third_party/catapult/tracing/tracing/metrics/partition_alloc/pcscan_metric.html @@ -0,0 +1,195 @@ +<!DOCTYPE html> +<!-- +Copyright 2020 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. +--> + +<link rel="import" href="/tracing/base/math/range.html"> +<link rel="import" href="/tracing/base/unit.html"> +<link rel="import" href="/tracing/extras/chrome/chrome_processes.html"> +<link rel="import" href="/tracing/metrics/metric_registry.html"> +<link rel="import" href="/tracing/model/helpers/chrome_model_helper.html"> +<link rel="import" href="/tracing/value/histogram.html"> + +<script> +'use strict'; + +/** + * @fileoverview This file contains implementations of PCScan metrics. PCScan + * is the algorithm that eliminates use-after-free bugs by verifying that there + * are no pointers in memory which point to explicitly freed objects before + * actually releasing their memory. + * + * pa:pcscan:<process_name>:<scanner|mutator> + * ======================== + * The overall time spent on scanning the partition alloc heap for a specific + * process either in the scanner or mutator thread (process_name can be either 'browser_process' or 'renderer_processes'). + * + * pa:pcscan:<process_name>:<scanner|mutator>:<phase> + * ======================== + * Time spent on a certain PCScan phase ('clear', 'scan' or 'sweep'). + */ +tr.exportTo('tr.metrics.pa', function() { + function pcscanMetric(histograms, model) { + function createTimeNumericForProcess(name, processName, context, desc) { + function createNumeric(name, desc) { + const n = new tr.v.Histogram(name, + tr.b.Unit.byName.timeDurationInMs_smallerIsBetter); + n.description = desc; + n.customizeSummaryOptions({ + avg: true, + count: true, + max: true, + min: true, + std: true, + sum: true}); + return n; + } + const scheme = ['pa', 'pcscan', processName, context]; + if (name) scheme.push(name); + return createNumeric(scheme.join(':'), desc); + } + + function createSizeNumericForProcess(name, processName, desc) { + function createNumeric(name, desc) { + const n = new tr.v.Histogram(name, + tr.b.Unit.byName.sizeInBytes_smallerIsBetter); + n.description = desc; + n.customizeSummaryOptions({ + avg: true, + count: true, + max: true, + min: true, + std: true, + sum: true}); + return n; + } + const scheme = ['pa', 'pcscan', processName, name]; + return createNumeric(scheme.join(':'), desc); + } + + function createPercentNumericForProcess(name, processName, desc) { + function createNumeric(name, desc) { + const n = new tr.v.Histogram(name, + tr.b.Unit.byName.normalizedPercentage_smallerIsBetter); + n.description = desc; + n.customizeSummaryOptions({ + avg: true, + count: true, + max: true, + min: true, + std: true, + sum: true}); + return n; + } + const scheme = ['pa', 'pcscan', processName, name]; + return createNumeric(scheme.join(':'), desc); + } + + + function createHistsForProcess(processName) { + return { + scanner_scan: createTimeNumericForProcess('scan', processName, 'scanner', + 'Time for scanning heap for quarantine pointers on concurrent threads'), + scanner_sweep: createTimeNumericForProcess('sweep', processName, 'scanner', + 'Time for sweeping quarantine'), + scanner_clear: createTimeNumericForProcess('clear', processName, 'scanner', + 'Time for clearing quarantine entries'), + scanner_total: createTimeNumericForProcess('', processName, 'scanner', + 'Total time for PCScan execution on concurrent threads'), + mutator_scan_stack: createTimeNumericForProcess('scan_stack', processName, 'mutator', + 'Time for scanning stack for quarantine pointers on mutator threads'), + mutator_scan: createTimeNumericForProcess('scan', processName, 'mutator', + 'Time for scanning heap for quarantine pointers on mutator threads'), + mutator_clear: createTimeNumericForProcess('clear', processName, 'mutator', + 'Time for clearing heap quarantine entries on mutator threads'), + mutator_total: createTimeNumericForProcess('', processName, 'mutator', + 'Total time for PCScan execution on mutator threads (inside safepoints)'), + survived_quarantine_size: createSizeNumericForProcess( + 'survived_quarantine_size', processName, + 'Size in bytes of survived quarantined objects after each *Scan cycle'), + survived_quarantine_percent: createPercentNumericForProcess( + 'survived_quarantine_percent', processName, + 'Percent of survived quarantined objects after a *Scan cycle relative ' + + 'to the size of quarantined objects before the cycle'), + }; + } + + function addSliceSample(hists, slice) { + if (slice.category !== 'partition_alloc') return; + if (!(slice instanceof tr.model.ThreadSlice)) return; + + if (slice.title === 'PCScan.Scanner.Scan') { + hists.scanner_scan.addSample(slice.duration); + } else if (slice.title === 'PCScan.Scanner.Sweep') { + hists.scanner_sweep.addSample(slice.duration); + } else if (slice.title === 'PCScan.Scanner.Clear') { + hists.scanner_clear.addSample(slice.duration); + } else if (slice.title === 'PCScan.Scanner') { + hists.scanner_total.addSample(slice.duration); + } else if (slice.title === 'PCScan.Mutator.ScanStack') { + hists.mutator_scan_stack.addSample(slice.duration); + } else if (slice.title === 'PCScan.Mutator.Scan') { + hists.mutator_scan.addSample(slice.duration); + } else if (slice.title === 'PCScan.Mutator.Clear') { + hists.mutator_clear.addSample(slice.duration); + } else if (slice.title === 'PCScan.Mutator') { + hists.mutator_total.addSample(slice.duration); + } + } + + function addCounterSample(hists, counter) { + if (counter.category !== 'partition_alloc') return; + if (!(counter instanceof tr.model.Counter)) return; + + for (const series of counter.series) { + for (const sample of series.samples) { + if (counter.name === 'PCScan.SurvivedQuarantineSize') { + hists.survived_quarantine_size.addSample(sample.value); + } else if (counter.name === 'PCScan.SurvivedQuarantinePercent') { + // Divide by 1000, since StatsCollector multiplies it by 1000. + hists.survived_quarantine_percent.addSample(sample.value / 1000); + } + } + } + } + + function addHistsForProcess(processHists, processHelpers) { + for (const helper of Object.values(processHelpers)) { + const processName = tr.e.chrome.chrome_processes. + canonicalizeProcessName(helper.process.name); + if (!processHists.has(processName)) { + processHists.set(processName, createHistsForProcess(processName)); + } + for (const slice of helper.process.getDescendantEvents()) { + addSliceSample(processHists.get(processName), slice); + } + for (const tid in helper.process.counters) { + addCounterSample(processHists.get(processName), helper.process.counters[tid]); + } + } + } + + const helper = + model.getOrCreateHelper(tr.model.helpers.ChromeModelHelper); + + const processHists = new Map(); + addHistsForProcess(processHists, helper.browserHelpers); + addHistsForProcess(processHists, helper.rendererHelpers); + + for (const hists of processHists.values()) { + for (const hist of Object.values(hists)) { + histograms.addHistogram(hist); + } + } + } + + tr.metrics.MetricRegistry.register(pcscanMetric); + + return { + pcscanMetric, + }; +}); + +</script> diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/partition_alloc/pcscan_metric_test.html b/chromium/third_party/catapult/tracing/tracing/metrics/partition_alloc/pcscan_metric_test.html new file mode 100644 index 00000000000..ca43e546b56 --- /dev/null +++ b/chromium/third_party/catapult/tracing/tracing/metrics/partition_alloc/pcscan_metric_test.html @@ -0,0 +1,138 @@ +<!DOCTYPE html> +<!-- +Copyright 2020 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. +--> + +<link rel="import" href="/tracing/core/test_utils.html"> +<link rel="import" href="/tracing/extras/chrome/chrome_processes.html"> +<link rel="import" href="/tracing/extras/chrome/chrome_test_utils.html"> +<link rel="import" href="/tracing/metrics/partition_alloc/pcscan_metric.html"> +<link rel="import" href="/tracing/value/histogram_set.html"> + +<script> +'use strict'; + +tr.b.unittest.testSuite(function() { + const CHROME_PROCESS_NAMES = + tr.e.chrome.chrome_processes.CHROME_PROCESS_NAMES; + + function makeTestModelFor(processName) { + return tr.e.chrome.ChromeTestUtils.newChromeModel(function(model) { + const process = (processName === CHROME_PROCESS_NAMES.RENDERER ? + model.rendererProcess : model.browserProcess); + const thread = process.getOrCreateThread(2); + // Create slices. + thread.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ + cat: 'partition_alloc', + title: 'PCScan.Scanner', + start: 200, + duration: 100, + cpuStart: 200, + cpuDuration: 100 + })); + thread.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ + cat: 'partition_alloc', + title: 'PCScan.Mutator', + start: 200, + duration: 50, + cpuStart: 200, + cpuDuration: 50 + })); + thread.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ + cat: 'partition_alloc', + title: 'PCScan.Scanner.Clear', + start: 200, + duration: 16, + cpuStart: 200, + cpuDuration: 16 + })); + thread.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ + cat: 'partition_alloc', + title: 'PCScan.Scanner.Scan', + start: 216, + duration: 32, + cpuStart: 216, + cpuDuration: 32 + })); + thread.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ + cat: 'partition_alloc', + title: 'PCScan.Mutator.Clear', + start: 210, + duration: 8, + cpuStart: 210, + cpuDuration: 8 + })); + thread.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ + cat: 'partition_alloc', + title: 'PCScan.Mutator.ScanStack', + start: 218, + duration: 14, + cpuStart: 218, + cpuDuration: 14 + })); + thread.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ + cat: 'partition_alloc', + title: 'PCScan.Mutator.Scan', + start: 232, + duration: 16, + cpuStart: 232, + cpuDuration: 16 + })); + thread.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ + cat: 'partition_alloc', + title: 'PCScan.Scanner.Sweep', + start: 248, + duration: 42, + cpuStart: 248, + cpuDuration: 42 + })); + // Create counters. + const quarantineSizeCounter = process.getOrCreateCounter('partition_alloc', 'PCScan.SurvivedQuarantineSize'); + const quarantineSizeSeries = new tr.model.CounterSeries('value', 0); + quarantineSizeSeries.addCounterSample(1, 200000); + quarantineSizeSeries.addCounterSample(3, 300000); + quarantineSizeCounter.addSeries(quarantineSizeSeries); + const quarantineRateCounter = process.getOrCreateCounter('partition_alloc', 'PCScan.SurvivedQuarantinePercent'); + const quarantineRateSeries = new tr.model.CounterSeries('value', 0); + quarantineRateSeries.addCounterSample(1, 0.14 * 1000); + quarantineRateSeries.addCounterSample(3, 0.21 * 1000); + quarantineRateCounter.addSeries(quarantineRateSeries); + }); + } + + function testPCScanMetrics(processName) { + const histograms = new tr.v.HistogramSet(); + tr.metrics.pa.pcscanMetric(histograms, makeTestModelFor(processName)); + assert.closeTo(100, histograms.getHistogramNamed( + 'pa:pcscan:' + processName + ':scanner').average, 1e-2); + assert.closeTo(50, histograms.getHistogramNamed( + 'pa:pcscan:' + processName + ':mutator').average, 1e-2); + assert.closeTo(16, histograms.getHistogramNamed( + 'pa:pcscan:' + processName + ':scanner:clear').average, 1e-2); + assert.closeTo(32, histograms.getHistogramNamed( + 'pa:pcscan:' + processName + ':scanner:scan').average, 1e-2); + assert.closeTo(8, histograms.getHistogramNamed( + 'pa:pcscan:' + processName + ':mutator:clear').average, 1e-2); + assert.closeTo(14, histograms.getHistogramNamed( + 'pa:pcscan:' + processName + ':mutator:scan_stack').average, 1e-2); + assert.closeTo(16, histograms.getHistogramNamed( + 'pa:pcscan:' + processName + ':mutator:scan').average, 1e-2); + assert.closeTo(42, histograms.getHistogramNamed( + 'pa:pcscan:' + processName + ':scanner:sweep').average, 1e-2); + assert.closeTo(250000, histograms.getHistogramNamed( + 'pa:pcscan:' + processName + ':survived_quarantine_size').average, 1e-2); + assert.closeTo(0.175, histograms.getHistogramNamed( + 'pa:pcscan:' + processName + ':survived_quarantine_percent').average, 1e-2); + } + + test('pcscanMetricForBrowser', function() { + testPCScanMetrics(CHROME_PROCESS_NAMES.BROWSER); + }); + + test('pcscanMetricForRenderer', function() { + testPCScanMetrics(CHROME_PROCESS_NAMES.RENDERER); + }); +}); +</script> diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/rendering/cpu_utilization.html b/chromium/third_party/catapult/tracing/tracing/metrics/rendering/cpu_utilization.html index 16e185c172e..e6d55984e27 100644 --- a/chromium/third_party/catapult/tracing/tracing/metrics/rendering/cpu_utilization.html +++ b/chromium/third_party/catapult/tracing/tracing/metrics/rendering/cpu_utilization.html @@ -7,6 +7,9 @@ found in the LICENSE file. <link rel="import" href="/tracing/base/math/statistics.html"> <link rel="import" href="/tracing/base/unit.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/histogram.html"> <script> @@ -15,7 +18,7 @@ found in the LICENSE file. /** * @fileoverview This file contains implementations of the following metrics. * - * The addCpuUtilizationHistograms method can generate the following sets of + * The addCpuSegmentCostHistograms method can generate the following sets of * metrics, dependeing on the input values for segments, and segmentCostFunc. * * thread_{thread group}_cpu_time_per_frame @@ -34,6 +37,13 @@ found in the LICENSE file. * This set of metrics show the distribution of the number of task in each * display compositor's frame of a thread group. * + * The addCpuWallTimeHistogram method generates the metric: + * cpu_wall_time_ratio + * ================== + * segments: display compositor's frames + * + * This metric shows the ratio of cpu usage to wall time. + * * Note: the CPU usage in all above-mentioned metrics, is approximated from * top-level trace events in each thread; it does not come from the OS. So, the * metric may be noisy and not be very meaningful for threads that do not have a @@ -86,7 +96,7 @@ tr.exportTo('tr.metrics.rendering', function() { if (isOther) yield 'other'; } - function addCpuUtilizationHistograms( + function addCpuSegmentCostHistograms( histograms, model, segments, segmentCostFunc, histogramNameFunc, description) { const categoryValues = new Map(); @@ -120,14 +130,26 @@ tr.exportTo('tr.metrics.rendering', function() { } } - const SUMMARY_OPTIONS = { - percentile: [0.90, 0.95], - ci: [0.95], - }; + function addCpuWallTimeHistogram(histograms, model, segments) { + let totalWallTime = 0; + let totalCpuTime = 0; + for (const segment of segments) { + for (const thread of model.getAllThreads()) { + totalCpuTime += thread.getCpuTimeForRange(segment.boundsRange); + totalWallTime += thread.getWallTimeForRange(segment.boundsRange); + } + } + histograms.createHistogram('cpu_wall_time_ratio', + tr.b.Unit.byName.unitlessNumber_biggerIsBetter, + totalWallTime ? totalCpuTime / totalWallTime : NaN, + { description: 'Ratio of total cpu-time vs. wall-time.', + summaryOptions: {}, + }); + } return { - addCpuUtilizationHistograms, - SUMMARY_OPTIONS, + addCpuSegmentCostHistograms, + addCpuWallTimeHistogram, }; }); </script> diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/rendering/cpu_utilization_test.html b/chromium/third_party/catapult/tracing/tracing/metrics/rendering/cpu_utilization_test.html index 9c3e0d21def..a5aab4912fc 100644 --- a/chromium/third_party/catapult/tracing/tracing/metrics/rendering/cpu_utilization_test.html +++ b/chromium/third_party/catapult/tracing/tracing/metrics/rendering/cpu_utilization_test.html @@ -38,7 +38,7 @@ tr.b.unittest.testSuite(function() { { start: 5, end: 6, cpuStart: 1, cpuEnd: 2 })); }); const histograms = new tr.v.HistogramSet(); - tr.metrics.rendering.addCpuUtilizationHistograms( + tr.metrics.rendering.addCpuSegmentCostHistograms( histograms, model, [new tr.model.um.Segment(0, 10)], (thread, segment) => thread.getCpuTimeForRange(segment.boundsRange), category => `thread_${category}_cpu_time_per_frame`, 'description'); @@ -95,7 +95,7 @@ tr.b.unittest.testSuite(function() { { start: 5, end: 6, cpuStart: 1, cpuEnd: 2 })); }); const histograms = new tr.v.HistogramSet(); - tr.metrics.rendering.addCpuUtilizationHistograms( + tr.metrics.rendering.addCpuSegmentCostHistograms( histograms, model, [new tr.model.um.Segment(0, 5), new tr.model.um.Segment(5, 5)], (thread, segment) => thread.getCpuTimeForRange(segment.boundsRange), @@ -134,7 +134,7 @@ tr.b.unittest.testSuite(function() { { start: 5, end: 6, cpuStart: 1, cpuEnd: 2 })); }); const histograms = new tr.v.HistogramSet(); - tr.metrics.rendering.addCpuUtilizationHistograms( + tr.metrics.rendering.addCpuSegmentCostHistograms( histograms, model, [new tr.model.um.Segment(0, 10)], (thread, segment) => thread.getCpuTimeForRange(segment.boundsRange), category => `thread_${category}_cpu_time_per_frame`, 'description'); @@ -176,7 +176,7 @@ tr.b.unittest.testSuite(function() { { start: 5, end: 6, cpuStart: 1, cpuEnd: 2 })); }); const histograms = new tr.v.HistogramSet(); - tr.metrics.rendering.addCpuUtilizationHistograms( + tr.metrics.rendering.addCpuSegmentCostHistograms( histograms, model, [new tr.model.um.Segment(0, 10)], (thread, segment) => thread.getNumToplevelSlicesForRange(segment.boundsRange), diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/rendering/frame_segment_filter.html b/chromium/third_party/catapult/tracing/tracing/metrics/rendering/frame_segment_filter.html new file mode 100644 index 00000000000..9ebaa87d003 --- /dev/null +++ b/chromium/third_party/catapult/tracing/tracing/metrics/rendering/frame_segment_filter.html @@ -0,0 +1,112 @@ +<!DOCTYPE html> +<!-- +Copyright 2022 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. +--> + +<link rel="import" href="/tracing/base/math/statistics.html"> +<link rel="import" href="/tracing/base/unit.html"> +<link rel="import" href="/tracing/base/unit_scale.html"> +<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> +'use strict'; + +/** + * @fileoverview This file contains helper methods to filter Segments to just + * those for the displaying of frames. + */ +tr.exportTo('tr.metrics.rendering', function() { + // Various tracing events. + const DISPLAY_EVENT = 'BenchmarkInstrumentation::DisplayRenderingStats'; + const DRM_EVENT = 'DrmEventFlipComplete'; + const SURFACE_FLINGER_EVENT = 'vsync_before'; + + + // 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; + + + 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_; } + } + + + function getDisplayCompositorPresentationEvents_(model) { + const modelHelper = model.getOrCreateHelper( + tr.model.helpers.ChromeModelHelper); + if (!modelHelper || !modelHelper.browserProcess) return []; + // On ChromeOS, DRM events, if they exist, are the source of truth. On + // Android, Surface Flinger events are the source of truth. Otherwise, look + // for display rendering stats. With viz, display rendering stats are + // emitted from the GPU process; otherwise, they are emitted from the + // browser process. + let events = []; + if (modelHelper.surfaceFlingerProcess) { + events = [...modelHelper.surfaceFlingerProcess.findTopmostSlicesNamed( + SURFACE_FLINGER_EVENT)]; + if (events.length > 0) return events; + } + if (modelHelper.gpuHelper) { + const gpuProcess = modelHelper.gpuHelper.process; + events = [...gpuProcess.findTopmostSlicesNamed(DRM_EVENT)]; + if (events.length > 0) return events; + events = [...gpuProcess.findTopmostSlicesNamed(DISPLAY_EVENT)]; + if (events.length > 0) return events; + } + return [...modelHelper.browserProcess.findTopmostSlicesNamed( + DISPLAY_EVENT)]; + } + + + function computeFrameSegments(model, segments) { + const events = getDisplayCompositorPresentationEvents_(model); + if (!events) return []; + // 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 frameEvents = events.map(e => new FrameEvent(e)); + const frameSegments = []; + for (const segment of segments) { + const filtered = segment.boundsRange.filterArray( + frameEvents, x => x.eventStart); + if (filtered.length < MIN_FRAME_COUNT) continue; + for (let i = 1; i < filtered.length; i++) { + const duration = filtered[i].frameStart - filtered[i - 1].frameStart; + frameSegments.push(new tr.model.um.Segment(filtered[i - 1].eventStart, duration)); + } + } + return frameSegments; + } + + return { + computeFrameSegments, + }; +}); +</script> diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/rendering/queueing_duration.html b/chromium/third_party/catapult/tracing/tracing/metrics/rendering/queueing_duration.html index 386bd444658..aa690649f66 100644 --- a/chromium/third_party/catapult/tracing/tracing/metrics/rendering/queueing_duration.html +++ b/chromium/third_party/catapult/tracing/tracing/metrics/rendering/queueing_duration.html @@ -22,8 +22,8 @@ found in the LICENSE file. * ScheduledActionSendBeginMainFrame event in the compositor thread and the * corresponding BeginMainFrame event in the main thread. * - * TODO(chiniforooshan): Does it make sense to just ignore data from OOPIF - * processes, like what we are doing here? + * For OOPIF they might send a BeginMainFrame with the same ID, in those cases + * the earliest slice's time is used. */ tr.exportTo('tr.metrics.rendering', function() { // Various tracing events. @@ -38,7 +38,12 @@ tr.exportTo('tr.metrics.rendering', function() { if (slice.title !== title) continue; const id = slice.args.begin_frame_id; if (id === undefined) throw new Error('Event is missing begin_frame_id'); - if (out.has(id)) throw new Error(`There must be exactly one ${title}`); + // If we've already seen an even with this name, we only track the first. + // Multiple ThreadProxy::BeginMainFrames can occur when OOPIF share the + // same origin and get routed to the same RendererMain. + if (out.has(id) && out[id] <= slice.start) { + continue; + } out.set(id, slice.start); } return out; 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 b7d292eec14..0944c00c049 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 @@ -6,7 +6,8 @@ found in the LICENSE file. --> <link rel="import" href="/tracing/metrics/metric_registry.html"> -<link rel="import" href="/tracing/metrics/rendering/frame_time.html"> +<link rel="import" href="/tracing/metrics/rendering/cpu_utilization.html"> +<link rel="import" href="/tracing/metrics/rendering/frame_segment_filter.html"> <link rel="import" href="/tracing/metrics/rendering/image_decode_time.html"> <link rel="import" href="/tracing/metrics/rendering/pixels.html"> <link rel="import" href="/tracing/metrics/rendering/queueing_duration.html"> @@ -28,19 +29,28 @@ tr.exportTo('tr.metrics.rendering', function() { segments = chromeHelper.telemetryHelper.animationSegments; } if (segments.length > 0) { - tr.metrics.rendering.addFrameTimeHistograms(histograms, model, segments); + const frameSegments = tr.metrics.rendering.computeFrameSegments(model, segments); + if (frameSegments.length > 0) { + tr.metrics.rendering.addCpuSegmentCostHistograms( + histograms, model, frameSegments, + (thread, segment) => thread.getCpuTimeForRange(segment.boundsRange), + category => `thread_${category}_cpu_time_per_frame`, + 'CPU cores of a thread group per frame'); + tr.metrics.rendering.addCpuSegmentCostHistograms( + histograms, model, frameSegments, + (thread, segment) => + thread.getNumToplevelSlicesForRange(segment.boundsRange), + category => `tasks_per_frame_${category}`, + 'Number of tasks of a thread group per frame'); + tr.metrics.rendering.addCpuWallTimeHistogram(histograms, model, frameSegments); + } + tr.metrics.rendering.addImageDecodeTimeHistograms(histograms, model, segments); tr.metrics.rendering.addPixelsHistograms(histograms, model, segments); tr.metrics.rendering.addQueueingDurationHistograms( histograms, model, segments); } - - const uiSegments = chromeHelper.telemetryHelper.uiSegments; - if (uiSegments.length > 0) { - tr.metrics.rendering.addUIFrameTimeHistograms( - histograms, model, chromeHelper.telemetryHelper.uiSegments); - } } tr.metrics.MetricRegistry.register(renderingMetric, { 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 1d30078252a..8cdf4b42b5c 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 @@ -39,11 +39,11 @@ tr.b.unittest.testSuite(function() { // 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); - assert.closeTo(2, hist.average, 1e-6); + // in 9 frames which have 1 task each. + const hist = histograms.getHistogramNamed('tasks_per_frame_total_all'); + 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/system_health/breakdown_tree_helpers_test.html b/chromium/third_party/catapult/tracing/tracing/metrics/system_health/breakdown_tree_helpers_test.html index b40db0341b4..30f9dbe2cee 100644 --- a/chromium/third_party/catapult/tracing/tracing/metrics/system_health/breakdown_tree_helpers_test.html +++ b/chromium/third_party/catapult/tracing/tracing/metrics/system_health/breakdown_tree_helpers_test.html @@ -33,7 +33,7 @@ tr.b.unittest.testSuite(function() { // Add layout categories mainThread.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ cat: 'blink', - title: 'HTMLDocumentParser::didReceiveParsedChunkFromBackgroundParser', + title: 'HTMLDocumentParser::DeferredPumpTokenizerIfPossible', start: 200, duration: 200, cpuStart: 1160, @@ -102,7 +102,7 @@ tr.b.unittest.testSuite(function() { assert.deepEqual({ total: 150, events: { - 'HTMLDocumentParser::didReceiveParsedChunkFromBackgroundParser': 150 + 'HTMLDocumentParser::DeferredPumpTokenizerIfPossible': 150 } }, breakdownTree.parseHTML); assert.deepEqual({ @@ -147,7 +147,7 @@ tr.b.unittest.testSuite(function() { assert.deepEqual({ total: 100, events: { - 'HTMLDocumentParser::didReceiveParsedChunkFromBackgroundParser': 100 + 'HTMLDocumentParser::DeferredPumpTokenizerIfPossible': 100 } }, breakdownTree.parseHTML); assert.deepEqual({ @@ -181,7 +181,7 @@ tr.b.unittest.testSuite(function() { assert.deepEqual({ total: 120, events: { - 'HTMLDocumentParser::didReceiveParsedChunkFromBackgroundParser': 120 + 'HTMLDocumentParser::DeferredPumpTokenizerIfPossible': 120 } }, breakdownTree.parseHTML); assert.deepEqual({ @@ -226,7 +226,7 @@ tr.b.unittest.testSuite(function() { assert.deepEqual({ total: 80, events: { - 'HTMLDocumentParser::didReceiveParsedChunkFromBackgroundParser': 80 + 'HTMLDocumentParser::DeferredPumpTokenizerIfPossible': 80 } }, breakdownTree.parseHTML); assert.deepEqual({ diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/system_health/cpu_time_metric.html b/chromium/third_party/catapult/tracing/tracing/metrics/system_health/cpu_time_metric.html index f8a63e84ba7..2d22034dbad 100644 --- a/chromium/third_party/catapult/tracing/tracing/metrics/system_health/cpu_time_metric.html +++ b/chromium/third_party/catapult/tracing/tracing/metrics/system_health/cpu_time_metric.html @@ -8,6 +8,7 @@ found in the LICENSE file. <link rel="import" href="/tracing/metrics/metric_registry.html"> <link rel="import" href="/tracing/model/helpers/chrome_model_helper.html"> <link rel="import" href="/tracing/model/helpers/chrome_renderer_helper.html"> +<link rel="import" href="/tracing/value/diagnostics/alert_groups.html"> <link rel="import" href="/tracing/value/histogram.html"> <script> @@ -78,6 +79,7 @@ tr.exportTo('tr.metrics.sh', function() { cpuTimeHist.description = 'Percent CPU utilization, normalized against a single core. Can be ' + 'greater than 100% if machine has multiple cores.'; + cpuTimeHist.setAlertGrouping([tr.v.d.ALERT_GROUPS.CPU_USAGE]); cpuTimeHist.customizeSummaryOptions({ avg: true, count: false, 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 d6884fa43c4..2c5ab4b2d03 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 @@ -18,6 +18,7 @@ found in the LICENSE file. <link rel="import" href="/tracing/model/helpers/chrome_model_helper.html"> <link rel="import" href="/tracing/model/helpers/chrome_thread_helper.html"> <link rel="import" href="/tracing/model/timed_event.html"> +<link rel="import" href="/tracing/value/diagnostics/alert_groups.html"> <link rel="import" href="/tracing/value/diagnostics/diagnostic_map.html"> <link rel="import" href="/tracing/value/histogram.html"> @@ -186,7 +187,14 @@ tr.exportTo('tr.metrics.sh', function() { const frameIdRef = targetEvent.args.frame; const snapshot = findFrameLoaderSnapshotAt( rendererHelper, frameIdRef, targetEvent.start); - if (snapshot === undefined || !snapshot.args.isLoadingMainFrame) continue; + if (snapshot === undefined) continue; + // If isOutermostMainFrame is available, use it, if not use + // isLoadingMainFrame. + const isOutermostMainFrame = + (snapshot.args.isOutermostMainFrame !== undefined) ? + snapshot.args.isOutermostMainFrame : + snapshot.args.isLoadingMainFrame; + if (!isOutermostMainFrame) continue; const url = snapshot.args.documentLoaderURL; if (tr.e.chrome.CHROME_INTERNAL_URLS.includes(url)) continue; let navigationStartEvent; @@ -264,7 +272,7 @@ tr.exportTo('tr.metrics.sh', function() { return samples; } - function findLayoutShiftSamples(rendererHelper) { + function findMainFrameLayoutShiftSamples(rendererHelper) { let sample; EventFinderUtils.getSortedMainThreadEventsByFrame(rendererHelper, 'LayoutShift', 'loading').forEach((events) => { @@ -274,7 +282,34 @@ tr.exportTo('tr.metrics.sh', function() { sample = {value: evData.cumulative_score}; } }); - return sample ? [sample] : []; + // When there is no layout shift event on found on the page, CLS is 0. + return sample ? [sample] : [{value: 0}]; + } + + function findAllLayoutShiftSamples(chromeHelper) { + let total = 0; + let foundMainFrame = false; + for (const pid in chromeHelper.rendererHelpers) { + const rendererHelper = chromeHelper.rendererHelpers[pid]; + if (rendererHelper.isChromeTracingUI) continue; + + tr.e.chrome.EventFinderUtils.getSortedMainThreadEventsByFrame( + rendererHelper, 'LayoutShift', 'loading').forEach((events) => { + // Add up the scores for main frames and weighted scores for subframes. + for (const event of events) { + const evData = event.args.data; + if (evData.is_main_frame) { + total += evData.score; + foundMainFrame = true; + } else { + total += evData.weighted_score_delta; + } + } + }); + } + + // If no CLS is found, report value as 0 instead of null. + return foundMainFrame ? [{value: total}] : [{value: 0}]; } function addFirstMeaningfulPaintSample(samples, rendererHelper, @@ -487,7 +522,8 @@ tr.exportTo('tr.metrics.sh', function() { const largestTextPaintSamples = findLargestTextPaintSamples( rendererHelper, frameToNavStartEvents, navIdToNavStartEvents); - const layoutShiftSamples = findLayoutShiftSamples(rendererHelper); + const mainFrameLayoutShiftSamples = findMainFrameLayoutShiftSamples( + rendererHelper); const navigationStartSamples = timeToFCPEntries.map(entry => { return { value: entry.navigationStartEvent.start}; }); @@ -502,7 +538,7 @@ tr.exportTo('tr.metrics.sh', function() { firstViewportReadySamples, largestImagePaintSamples, largestTextPaintSamples, - layoutShiftSamples, + mainFrameLayoutShiftSamples, navigationStartSamples, }; } @@ -568,40 +604,6 @@ tr.exportTo('tr.metrics.sh', function() { function addSamplesToHistogram(samples, histogram, histograms) { for (const sample of samples) { histogram.addSample(sample.value, sample.diagnostics); - - // Only add breakdown histograms for FCP. - // http://crbug.com/771610 - if (histogram.name !== 'timeToFirstContentfulPaint') continue; - - if (!sample.breakdownTree) continue; - for (const [category, breakdown] of Object.entries( - sample.breakdownTree)) { - const relatedName = `${histogram.name}:${category}`; - let relatedHist = histograms.getHistogramsNamed(relatedName)[0]; - if (!relatedHist) { - relatedHist = histograms.createHistogram( - relatedName, histogram.unit, [], { - binBoundaries: LOADING_METRIC_BOUNDARIES, - summaryOptions: { - count: false, - max: false, - min: false, - sum: false, - }, - }); - - let relatedNames = histogram.diagnostics.get('breakdown'); - if (!relatedNames) { - relatedNames = new tr.v.d.RelatedNameMap(); - histogram.diagnostics.set('breakdown', relatedNames); - } - relatedNames.set(category, relatedName); - } - relatedHist.addSample(breakdown.total, { - breakdown: tr.v.d.Breakdown.fromEntries( - Object.entries(breakdown.events)), - }); - } } } @@ -611,18 +613,21 @@ tr.exportTo('tr.metrics.sh', function() { binBoundaries: LOADING_METRIC_BOUNDARIES, description: 'time to first paint', summaryOptions: SUMMARY_OPTIONS, + alertGrouping: [tr.v.d.ALERT_GROUPS.LOADING_PAINT], }); const firstContentfulPaintHistogram = histograms.createHistogram( 'timeToFirstContentfulPaint', timeDurationInMs_smallerIsBetter, [], { binBoundaries: LOADING_METRIC_BOUNDARIES, description: 'time to first contentful paint', summaryOptions: SUMMARY_OPTIONS, + alertGrouping: [tr.v.d.ALERT_GROUPS.LOADING_PAINT], }); const firstContentfulPaintCpuTimeHistogram = histograms.createHistogram( 'cpuTimeToFirstContentfulPaint', timeDurationInMs_smallerIsBetter, [], { binBoundaries: LOADING_METRIC_BOUNDARIES, description: 'CPU time to first contentful paint', summaryOptions: SUMMARY_OPTIONS, + alertGrouping: [tr.v.d.ALERT_GROUPS.LOADING_PAINT], }); const onLoadHistogram = histograms.createHistogram( 'timeToOnload', timeDurationInMs_smallerIsBetter, [], { @@ -636,30 +641,36 @@ tr.exportTo('tr.metrics.sh', function() { binBoundaries: LOADING_METRIC_BOUNDARIES, description: 'time to first meaningful paint', summaryOptions: SUMMARY_OPTIONS, + alertGrouping: [tr.v.d.ALERT_GROUPS.LOADING_PAINT], }); const firstMeaningfulPaintCpuTimeHistogram = histograms.createHistogram( 'cpuTimeToFirstMeaningfulPaint', timeDurationInMs_smallerIsBetter, [], { binBoundaries: LOADING_METRIC_BOUNDARIES, description: 'CPU time to first meaningful paint', summaryOptions: SUMMARY_OPTIONS, + alertGrouping: [tr.v.d.ALERT_GROUPS.LOADING_PAINT], }); const timeToInteractiveHistogram = histograms.createHistogram( 'timeToInteractive', timeDurationInMs_smallerIsBetter, [], { binBoundaries: TIME_TO_INTERACTIVE_BOUNDARIES, description: 'Time to Interactive', summaryOptions: SUMMARY_OPTIONS, + alertGrouping: [tr.v.d.ALERT_GROUPS.LOADING_PAINT], + alertGrouping: [tr.v.d.ALERT_GROUPS.LOADING_INTERACTIVITY], }); const totalBlockingTimeHistogram = histograms.createHistogram( 'totalBlockingTime', timeDurationInMs_smallerIsBetter, [], { binBoundaries: TIME_TO_INTERACTIVE_BOUNDARIES, description: 'Total Blocking Time', summaryOptions: SUMMARY_OPTIONS, + alertGrouping: [tr.v.d.ALERT_GROUPS.LOADING_INTERACTIVITY], }); const timeToFirstCpuIdleHistogram = histograms.createHistogram( 'timeToFirstCpuIdle', timeDurationInMs_smallerIsBetter, [], { binBoundaries: TIME_TO_INTERACTIVE_BOUNDARIES, description: 'Time to First CPU Idle', summaryOptions: SUMMARY_OPTIONS, + alertGrouping: [tr.v.d.ALERT_GROUPS.LOADING_INTERACTIVITY], }); const aboveTheFoldLoadedToVisibleHistogram = histograms.createHistogram( 'aboveTheFoldLoadedToVisible', timeDurationInMs_smallerIsBetter, [], { @@ -690,12 +701,21 @@ tr.exportTo('tr.metrics.sh', function() { binBoundaries: LOADING_METRIC_BOUNDARIES, description: 'Time to Largest Contentful Paint', summaryOptions: SUMMARY_OPTIONS, + alertGrouping: [tr.v.d.ALERT_GROUPS.LOADING_PAINT], }); - const layoutShiftHistogram = histograms.createHistogram( + const mainFrameLayoutShiftHistogram = histograms.createHistogram( 'mainFrameCumulativeLayoutShift', unitlessNumber_smallerIsBetter, [], { binBoundaries: LAYOUT_SHIFT_SCORE_BOUNDARIES, description: 'Main Frame Document Cumulative Layout Shift Score', summaryOptions: SUMMARY_OPTIONS, + alertGrouping: [tr.v.d.ALERT_GROUPS.LOADING_LAYOUT], + }); + const allLayoutShiftHistogram = histograms.createHistogram( + 'overallCumulativeLayoutShift', unitlessNumber_smallerIsBetter, [], { + binBoundaries: LAYOUT_SHIFT_SCORE_BOUNDARIES, + description: 'Document Cumulative Layout Shift Score with iframes', + summaryOptions: SUMMARY_OPTIONS, + alertGrouping: [tr.v.d.ALERT_GROUPS.LOADING_LAYOUT], }); const navigationStartHistogram = histograms.createHistogram( 'navigationStart', timeDurationInMs_smallerIsBetter, [], { @@ -707,6 +727,20 @@ tr.exportTo('tr.metrics.sh', function() { const chromeHelper = model.getOrCreateHelper( tr.model.helpers.ChromeModelHelper); + + // Layout Shift and LCP are reported in the browser process, so we do not + // need to loop over the renderers to add samples. + const allLayoutShiftSamples = findAllLayoutShiftSamples(chromeHelper); + addSamplesToHistogram( + allLayoutShiftSamples, + allLayoutShiftHistogram, + histograms); + + const lcpSamples = findLargestContentfulPaintHistogramSamples( + chromeHelper.browserHelper.mainThread.sliceGroup.slices); + addSamplesToHistogram( + lcpSamples, largestContentfulPaintHistogram, histograms); + for (const pid in chromeHelper.rendererHelpers) { const rendererHelper = chromeHelper.rendererHelpers[pid]; if (rendererHelper.isChromeTracingUI) continue; @@ -714,11 +748,6 @@ 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( @@ -748,7 +777,9 @@ tr.exportTo('tr.metrics.sh', function() { largestTextPaintHistogram, histograms); addSamplesToHistogram( - samplesSet.layoutShiftSamples, layoutShiftHistogram, histograms); + samplesSet.mainFrameLayoutShiftSamples, + mainFrameLayoutShiftHistogram, + histograms); addSamplesToHistogram( samplesSet.navigationStartSamples, navigationStartHistogram, 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 f27187f5cb0..8d7f4eb53ef 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 @@ -30,6 +30,7 @@ tr.b.unittest.testSuite(function() { })); rendererProcess.objects.addSnapshot('ptr', 'loading', 'FrameLoader', 300, { + isOutermostMainFrame: true, isLoadingMainFrame: true, frame: {id_ref: '0xdeadbeef'}, documentLoaderURL: 'http://example.com' @@ -63,6 +64,7 @@ tr.b.unittest.testSuite(function() { })); rendererProcess.objects.addSnapshot('ptr', 'loading', 'FrameLoader', 300, { + isOutermostMainFrame: true, isLoadingMainFrame: true, frame: {id_ref: '0xdeadbeef'}, documentLoaderURL: 'http://example.com' @@ -88,15 +90,6 @@ tr.b.unittest.testSuite(function() { const hist = histograms.getHistogramNamed('timeToFirstContentfulPaint'); assert.strictEqual(1, hist.running.count); assert.strictEqual(800, hist.running.mean); - const fcpResourceLoading = histograms.getHistogramNamed( - 'timeToFirstContentfulPaint:resource_loading'); - assert.strictEqual( - hist.diagnostics.get('breakdown').get( - 'resource_loading'), - 'timeToFirstContentfulPaint:resource_loading'); - assert.strictEqual(fcpResourceLoading.sum, 100); - assert.strictEqual(tr.b.getOnlyElement(hist.getBinForValue( - 800).diagnosticMaps).get('breakdown').get('resource_loading'), 100); }); test('timeToLargestImagePaint', function() { @@ -112,6 +105,7 @@ tr.b.unittest.testSuite(function() { })); rendererProcess.objects.addSnapshot('ptr', 'loading', 'FrameLoader', 300, { + isOutermostMainFrame: true, isLoadingMainFrame: true, frame: {id_ref: '0xdeadbeef'}, documentLoaderURL: 'http://example.com' @@ -147,6 +141,7 @@ tr.b.unittest.testSuite(function() { })); rendererProcess.objects.addSnapshot('ptr', 'loading', 'FrameLoader', 300, { + isOutermostMainFrame: true, isLoadingMainFrame: true, frame: {id_ref: '0xdeadbeef'}, documentLoaderURL: 'http://example.com' @@ -190,6 +185,7 @@ tr.b.unittest.testSuite(function() { })); rendererProcess.objects.addSnapshot('ptr', 'loading', 'FrameLoader', 300, { + isOutermostMainFrame: true, isLoadingMainFrame: true, frame: {id_ref: '0xdeadbeef'}, documentLoaderURL: 'http://example.com' @@ -232,6 +228,7 @@ tr.b.unittest.testSuite(function() { })); rendererProcess.objects.addSnapshot('ptr', 'loading', 'FrameLoader', 300, { + isOutermostMainFrame: true, isLoadingMainFrame: true, frame: {id_ref: '0xdeadbeef'}, documentLoaderURL: 'http://example.com' @@ -275,6 +272,45 @@ tr.b.unittest.testSuite(function() { assert.strictEqual(100, hist.running.mean); }); + test('timeToLargestContentfulPaint_NoMultipleReporting', function() { + // Test that we do not report the same sample value multiple times if there + // is more than one renderer. + 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: 400, + duration: 0.0, + args: { + data: { durationInMilliseconds: 100, type: 'text', size: 1000, + inMainFrame: true }, + main_frame_tree_node_id: 12345, + } + })); + + const rendererProcess1 = model.rendererProcess; + const mainThread1 = model.rendererMain; + addNavigationStart_(mainThread1, 50, + { isOutermostMainFrame: true, isLoadingMainFrame: true, + documentLoaderURL: 'http://example.com'}); + + const rendererProcess2 = model.getOrCreateProcess(10); + const mainThread2 = rendererProcess2.getOrCreateThread(10); + mainThread2.name = 'CrRendererMain'; + + addNavigationStart_(mainThread2, 100, + { isOutermostMainFrame: true, isLoadingMainFrame: true, + documentLoaderURL: 'http://example.com'}); + }); + + 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; @@ -452,6 +488,7 @@ tr.b.unittest.testSuite(function() { })); rendererProcess.objects.addSnapshot('ptr', 'loading', 'FrameLoader', 300, { + isOutermostMainFrame: true, isLoadingMainFrame: true, frame: {id_ref: '0xdeadbeef'}, documentLoaderURL: 'http://example.com' @@ -504,6 +541,7 @@ tr.b.unittest.testSuite(function() { })); rendererProcess.objects.addSnapshot('ptr', 'loading', 'FrameLoader', 300, { + isOutermostMainFrame: true, isLoadingMainFrame: true, frame: {id_ref: 'firstframeid'}, documentLoaderURL: 'http://example.com' @@ -526,6 +564,7 @@ tr.b.unittest.testSuite(function() { })); rendererProcess.objects.addSnapshot('ptr', 'loading', 'FrameLoader', 2300, { + isOutermostMainFrame: true, isLoadingMainFrame: true, frame: {id_ref: 'secondframeid'}, documentLoaderURL: 'http://example.com' @@ -636,6 +675,7 @@ tr.b.unittest.testSuite(function() { })); rendererProcess.objects.addSnapshot('ptr', 'loading', 'FrameLoader', 300, { + isOutermostMainFrame: true, isLoadingMainFrame: true, frame: {id_ref: '0xdeadbeef'}, documentLoaderURL: 'http://example.com' @@ -664,6 +704,7 @@ tr.b.unittest.testSuite(function() { })); rendererProcess.objects.addSnapshot('ptr', 'loading', 'FrameLoader', 2100, { + isOutermostMainFrame: true, isLoadingMainFrame: true, frame: {id_ref: '0xdeadbeef'}, documentLoaderURL: 'http://example.com' @@ -696,6 +737,7 @@ tr.b.unittest.testSuite(function() { })); rendererProcess.objects.addSnapshot('ptr', 'loading', 'FrameLoader', 300, { + isOutermostMainFrame: true, isLoadingMainFrame: true, frame: {id_ref: '0xdeadbeef'}, documentLoaderURL: 'http://example.com' @@ -745,6 +787,7 @@ tr.b.unittest.testSuite(function() { })); rendererProcess.objects.addSnapshot('ptr', 'loading', 'FrameLoader', 300, { + isOutermostMainFrame: true, isLoadingMainFrame: true, frame: {id_ref: '0xdeadbeef'}, documentLoaderURL: 'http://example.com' @@ -770,15 +813,6 @@ tr.b.unittest.testSuite(function() { const hist = histograms.getHistogramNamed('timeToFirstContentfulPaint'); assert.strictEqual(1, hist.running.count); assert.strictEqual(800, hist.running.mean); - const fcpResourceLoading = histograms.getHistogramNamed( - 'timeToFirstContentfulPaint:resource_loading'); - assert.strictEqual( - hist.diagnostics.get('breakdown').get( - 'resource_loading'), - 'timeToFirstContentfulPaint:resource_loading'); - assert.strictEqual(fcpResourceLoading.sum, 100); - assert.strictEqual(tr.b.getOnlyElement(hist.getBinForValue( - 800).diagnosticMaps).get('breakdown').get('resource_loading'), 100); }); test('timeToFirstMeaningfulPaint', function() { @@ -794,6 +828,7 @@ tr.b.unittest.testSuite(function() { })); rendererProcess.objects.addSnapshot('ptr', 'loading', 'FrameLoader', 300, { + isOutermostMainFrame: true, isLoadingMainFrame: true, frame: {id_ref: '0xdeadbeef'}, documentLoaderURL: 'http://example.com' @@ -842,6 +877,7 @@ tr.b.unittest.testSuite(function() { })); rendererProcess.objects.addSnapshot('ptr', 'loading', 'FrameLoader', 300, { + isOutermostMainFrame: true, isLoadingMainFrame: true, frame: {id_ref: '0xdeadbeef'}, documentLoaderURL: 'http://example.com' @@ -904,6 +940,7 @@ tr.b.unittest.testSuite(function() { })); rendererProcess.objects.addSnapshot('ptr', 'loading', 'FrameLoader', 300, { + isOutermostMainFrame: true, isLoadingMainFrame: true, frame: {id_ref: '0xdeadbeef'}, documentLoaderURL: 'http://example.com' @@ -973,6 +1010,7 @@ tr.b.unittest.testSuite(function() { })); rendererProcess1.objects.addSnapshot('ptr', 'loading', 'FrameLoader', 300, { + isOutermostMainFrame: true, isLoadingMainFrame: true, frame: {id_ref: '0xdeadbeef'}, documentLoaderURL: 'http://example.com' @@ -1009,6 +1047,7 @@ tr.b.unittest.testSuite(function() { })); rendererProcess2.objects.addSnapshot('ptr', 'loading', 'FrameLoader', 300, { + isOutermostMainFrame: true, isLoadingMainFrame: true, frame: {id_ref: '0xdeadbeef'}, documentLoaderURL: 'http://example.com' @@ -1046,6 +1085,7 @@ tr.b.unittest.testSuite(function() { function addFrameLoaderObject_(rendererProcess, timestamp) { rendererProcess.objects.addSnapshot( 'ptr', 'loading', 'FrameLoader', timestamp, { + isOutermostMainFrame: true, isLoadingMainFrame: true, frame: {id_ref: '0xdeadbeef'}, documentLoaderURL: 'http://example.com', }); @@ -1119,13 +1159,15 @@ tr.b.unittest.testSuite(function() { const mainThread = model.rendererMain; addNavigationStart_(mainThread, 200, - {isLoadingMainFrame: true, documentLoaderURL: 'http://example.com'}); + { isOutermostMainFrame: true, isLoadingMainFrame: true, + documentLoaderURL: 'http://example.com'}); addNetworkRequest_(mainThread, 200, 250); // FrameLoader creation time after navigation start. rendererProcess.objects.idWasCreated( 'ptr', 'loading', 'FrameLoader', 250); rendererProcess.objects.addSnapshot( 'ptr', 'loading', 'FrameLoader', 300, { + isOutermostMainFrame: true, isLoadingMainFrame: true, frame: {id_ref: '0xdeadbeef'}, documentLoaderURL: 'http://example.com', }); @@ -1136,7 +1178,8 @@ tr.b.unittest.testSuite(function() { // New navigation to close the search window. addNavigationStart_(mainThread, 7000, - {isLoadingMainFrame: true, documentLoaderURL: 'http://example.com'}); + { isOutermostMainFrame: true, isLoadingMainFrame: true, + documentLoaderURL: 'http://example.com'}); }); const histograms = new tr.v.HistogramSet(); @@ -1401,6 +1444,7 @@ tr.b.unittest.testSuite(function() { // DomContentLoadedEnd and NavigationStart for a different frame. rendererProcess.objects.addSnapshot( 'ptr', 'loading', 'FrameLoader', 4000, { + isOutermostMainFrame: true, isLoadingMainFrame: true, frame: {id_ref: '0xffffffff'}, documentLoaderURL: 'http://example.com' }); @@ -1474,6 +1518,7 @@ tr.b.unittest.testSuite(function() { })); process.objects.addSnapshot('ptr', 'loading', 'FrameLoader', 300, { + isOutermostMainFrame: true, isLoadingMainFrame: true, frame: {id_ref: '0xdeadbeef'}, documentLoaderURL: 'http://example.com' @@ -1600,6 +1645,32 @@ tr.b.unittest.testSuite(function() { partialNetworkEvents); }); + test('noLayoutShiftEventMeansZeroCLS', 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: 'blink.user_timing', + title: 'navigationStart', + start: 10, + duration: 510, + args: {frame: '0xdeadbeef'} + })); + }); + const histograms = new tr.v.HistogramSet(); + tr.metrics.sh.loadingMetric(histograms, model); + const mainHist = + histograms.getHistogramNamed('mainFrameCumulativeLayoutShift'); + assert.strictEqual(1, mainHist.sampleValues.length); + assert.strictEqual(1, mainHist.running.count); + assert.strictEqual(0, mainHist.running.mean); + const overallHist = + histograms.getHistogramNamed('overallCumulativeLayoutShift'); + assert.strictEqual(1, overallHist.sampleValues.length); + assert.strictEqual(1, overallHist.running.count); + assert.strictEqual(0, overallHist.running.mean); + }); + test('mainFrameCumulativeLayoutShift', function() { const model = tr.e.chrome.ChromeTestUtils.newChromeModel(function(model) { const rendererProcess = model.rendererProcess; @@ -1632,6 +1703,44 @@ tr.b.unittest.testSuite(function() { assert.strictEqual(3.5, hist.running.mean); }); + test('overallCumulativeLayoutShift', function() { + const model = tr.e.chrome.ChromeTestUtils.newChromeModel(function(model) { + const rendererProcess = model.rendererProcess; + const mainThread = model.rendererMain; + const mainFrame = {id: '0xdeadbeef', is_main: true}; + const subframe = {id: '0xdeadb33f', is_main: false}; + const emitEvent = (thread, time, score, weightedScore, frame) => { + const data = { + is_main_frame: frame.is_main, + score, + weighted_score_delta: weightedScore + }; + thread.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ + cat: 'loading', + title: 'LayoutShift', + start: time, + duration: 0.0, + args: {frame: frame.id, data} + })); + }; + emitEvent(mainThread, 1000, 1.5, 1000, mainFrame); + emitEvent(mainThread, 3000, 3.5, 1000, mainFrame); + emitEvent(mainThread, 2000, 3.0, 1000, mainFrame); + emitEvent(mainThread, 4000, 4000, 4.0, subframe); + const rendererProcess2 = model.getOrCreateProcess(10); + const mainThread2 = rendererProcess2.getOrCreateThread(20); + mainThread2.name = 'CrRendererMain'; + const subframe2 = { id: '0xdeadb33f', is_main: false }; + emitEvent(mainThread2, 2500, 1000, 2.0, subframe2); + }); + const histograms = new tr.v.HistogramSet(); + tr.metrics.sh.loadingMetric(histograms, model); + const hist = histograms.getHistogramNamed('overallCumulativeLayoutShift'); + assert.strictEqual(1, hist.sampleValues.length); + assert.strictEqual(1, hist.running.count); + assert.strictEqual(14, hist.running.mean); + }); + test('speedIndexIsAddedToHistograms', function() { // The speed index code is fully tested in // rects_based_speed_index_metric_test. diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/system_health/memory_metric.html b/chromium/third_party/catapult/tracing/tracing/metrics/system_health/memory_metric.html index fea57533ba6..188000809ea 100644 --- a/chromium/third_party/catapult/tracing/tracing/metrics/system_health/memory_metric.html +++ b/chromium/third_party/catapult/tracing/tracing/metrics/system_health/memory_metric.html @@ -390,6 +390,28 @@ tr.exportTo('tr.metrics.sh', function() { } }; + const MAX_ALLOCATED_SIZE = { + name: 'max_allocated_size', + unit: sizeInBytes_smallerIsBetter, + buildDescriptionPrefix(componentPath, processName) { + return buildChromeValueDescriptionPrefix(componentPath, processName, { + userFriendlyPropertyName: 'max size of all allocations', + componentPreposition: 'of' + }); + } + }; + + const MAX_COMMITTED_SIZE = { + name: 'max_committed_size', + unit: sizeInBytes_smallerIsBetter, + buildDescriptionPrefix(componentPath, processName) { + return buildChromeValueDescriptionPrefix(componentPath, processName, { + userFriendlyPropertyName: 'max size of all committed memory', + componentPreposition: 'of' + }); + } + }; + const SHIM_ALLOCATED_OBJECTS_SIZE = { name: 'shim_allocated_objects_size', unit: sizeInBytes_smallerIsBetter, @@ -451,6 +473,8 @@ tr.exportTo('tr.metrics.sh', function() { EFFECTIVE_SIZE, ALLOCATED_OBJECTS_SIZE, SHIM_ALLOCATED_OBJECTS_SIZE, + MAX_ALLOCATED_SIZE, + MAX_COMMITTED_SIZE, LOCKED_SIZE, PEAK_SIZE ]; diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/system_health/memory_metric_test.html b/chromium/third_party/catapult/tracing/tracing/metrics/system_health/memory_metric_test.html index e3a6c40d327..6cac038fad7 100644 --- a/chromium/third_party/catapult/tracing/tracing/metrics/system_health/memory_metric_test.html +++ b/chromium/third_party/catapult/tracing/tracing/metrics/system_health/memory_metric_test.html @@ -397,6 +397,8 @@ tr.b.unittest.testSuite(function() { size: 8, allocated_objects_size: 4, shim_allocated_objects_size: 3, + max_allocated_size: 5, + max_committed_size: 8 }}) ]; pmdBrowser1.totals = { @@ -565,7 +567,9 @@ tr.b.unittest.testSuite(function() { newAllocatorDump(pmdBrowser3, 'malloc', {numerics: { size: 8000, allocated_objects_size: 4000, - shim_allocated_objects_size: 3000 + shim_allocated_objects_size: 3000, + max_allocated_size: 4000, + max_committed_size: 8000 }}) ]; const pmdRendererB3 = addProcessMemoryDump(gmd3, pRendererB, {ts: 61}); @@ -656,6 +660,18 @@ tr.b.unittest.testSuite(function() { description: 'total size of all allocated objects reported by Chrome ' + 'for all processes in Chrome' }, + 'memory:chrome:all_processes:reported_by_chrome:max_allocated_size': { + value: [5, 0, 4000, 0], + unit: sizeInBytes_smallerIsBetter, + description: 'total max size of all allocations reported by Chrome ' + + 'for all processes in Chrome' + }, + 'memory:chrome:all_processes:reported_by_chrome:max_committed_size': { + value: [8, 0, 8000, 0], + unit: sizeInBytes_smallerIsBetter, + description: 'total max size of all committed memory reported by Chrome ' + + 'for all processes in Chrome' + }, 'memory:chrome:all_processes:reported_by_chrome:blinkgc:BlinkObject:heap_category_size': { value: [0, 0, 1687992 + 1252376, 0], @@ -765,6 +781,18 @@ tr.b.unittest.testSuite(function() { description: 'size of all objects allocated through shim by malloc in ' + 'all processes in Chrome' }, + 'memory:chrome:all_processes:reported_by_chrome:malloc:max_allocated_size': { + value: [5, 0, 4000, 0], + unit: sizeInBytes_smallerIsBetter, + description: 'max size of all allocations of malloc ' + + 'in all processes in Chrome' + }, + 'memory:chrome:all_processes:reported_by_chrome:malloc:max_committed_size': { + value: [8, 0, 8000, 0], + unit: sizeInBytes_smallerIsBetter, + description: 'max size of all committed memory of malloc ' + + 'in all processes in Chrome' + }, 'memory:chrome:all_processes:reported_by_chrome:malloc:allocated_objects_size': { value: [4, 40 + 750, 4000, 0], @@ -994,6 +1022,18 @@ tr.b.unittest.testSuite(function() { description: 'total size of all allocated objects through shim ' + 'reported by Chrome for the browser process in Chrome' }, + 'memory:chrome:browser_process:reported_by_chrome:max_allocated_size': { + value: [5, 0, 4000, 0], + unit: sizeInBytes_smallerIsBetter, + description: 'total max size of all allocations reported by Chrome ' + + 'for the browser process in Chrome' + }, + 'memory:chrome:browser_process:reported_by_chrome:max_committed_size': { + value: [8, 0, 8000, 0], + unit: sizeInBytes_smallerIsBetter, + description: 'total max size of all committed memory reported by Chrome ' + + 'for the browser process in Chrome' + }, 'memory:chrome:browser_process:reported_by_chrome:malloc:effective_size': { value: [8, 120 - 40, 8000, 80000], unit: sizeInBytes_smallerIsBetter, @@ -1020,6 +1060,18 @@ tr.b.unittest.testSuite(function() { description: 'size of all objects allocated through shim by malloc in ' + 'the browser process in Chrome' }, + 'memory:chrome:browser_process:reported_by_chrome:malloc:max_allocated_size': { + value: [5, 0, 4000, 0], + unit: sizeInBytes_smallerIsBetter, + description: 'max size of all allocations of malloc ' + + 'in the browser process in Chrome' + }, + 'memory:chrome:browser_process:reported_by_chrome:malloc:max_committed_size': { + value: [8, 0, 8000, 0], + unit: sizeInBytes_smallerIsBetter, + description: 'max size of all committed memory of malloc ' + + 'in the browser process in Chrome' + }, 'memory:chrome:browser_process:reported_by_chrome:tracing:effective_size': { value: [0, 40, 0, 0], unit: sizeInBytes_smallerIsBetter, diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/system_health/persecond_metric_test.html b/chromium/third_party/catapult/tracing/tracing/metrics/system_health/persecond_metric_test.html index f57d06da7dd..b34e7399322 100644 --- a/chromium/third_party/catapult/tracing/tracing/metrics/system_health/persecond_metric_test.html +++ b/chromium/third_party/catapult/tracing/tracing/metrics/system_health/persecond_metric_test.html @@ -29,6 +29,7 @@ tr.b.unittest.testSuite(function() { })); rendererProcess.objects.addSnapshot('ptr', 'loading', 'FrameLoader', 300, { + isOutermostMainFrame: true, isLoadingMainFrame: true, frame: {id_ref: '0xdeadbeef'}, documentLoaderURL: 'http://example.com' @@ -112,6 +113,7 @@ tr.b.unittest.testSuite(function() { })); rendererProcess.objects.addSnapshot('ptr', 'loading', 'FrameLoader', 300, { + isOutermostMainFrame: true, isLoadingMainFrame: true, frame: {id_ref: '0xdeadbeef'}, documentLoaderURL: 'http://example.com' @@ -164,6 +166,7 @@ tr.b.unittest.testSuite(function() { })); rendererProcess.objects.addSnapshot('ptr', 'loading', 'FrameLoader', 300, { + isOutermostMainFrame: true, isLoadingMainFrame: true, frame: {id_ref: '0xdeadbeef'}, documentLoaderURL: 'http://example.com' @@ -188,6 +191,7 @@ tr.b.unittest.testSuite(function() { })); rendererProcess.objects.addSnapshot('ptr2', 'loading', 'FrameLoader', 1200, { + isOutermostMainFrame: true, isLoadingMainFrame: true, frame: {id_ref: '0xlivebeef'}, documentLoaderURL: 'http://example.com' @@ -240,6 +244,7 @@ tr.b.unittest.testSuite(function() { })); rendererProcess.objects.addSnapshot('ptr', 'loading', 'FrameLoader', 300, { + isOutermostMainFrame: true, isLoadingMainFrame: true, frame: {id_ref: '0xdeadbeef'}, documentLoaderURL: 'http://example.com' @@ -295,6 +300,7 @@ tr.b.unittest.testSuite(function() { })); rendererProcess.objects.addSnapshot('ptr', 'loading', 'FrameLoader', 300, { + isOutermostMainFrame: true, isLoadingMainFrame: true, frame: {id_ref: '0xdeadbeef'}, documentLoaderURL: 'http://example.com' diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/system_health/weblayer_startup_metric.html b/chromium/third_party/catapult/tracing/tracing/metrics/system_health/weblayer_startup_metric.html new file mode 100644 index 00000000000..914f4cef743 --- /dev/null +++ b/chromium/third_party/catapult/tracing/tracing/metrics/system_health/weblayer_startup_metric.html @@ -0,0 +1,54 @@ +<!DOCTYPE html> +<!-- +Copyright 2020 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. +--> + +<link rel="import" href="/tracing/metrics/metric_registry.html"> +<link rel="import" href="/tracing/metrics/system_health/utils.html"> +<link rel="import" href="/tracing/value/histogram.html"> + +<script> +'use strict'; + +tr.exportTo('tr.metrics.sh', function() { + function weblayerStartupMetric(histograms, model) { + const startupWallHist = new tr.v.Histogram('weblayer_startup_wall_time', + tr.b.Unit.byName.timeDurationInMs_smallerIsBetter); + startupWallHist.description = 'WebLayer startup wall time'; + const loadWallHist = new tr.v.Histogram('weblayer_url_load_wall_time', + tr.b.Unit.byName.timeDurationInMs_smallerIsBetter); + loadWallHist.description = 'WebLayer blank URL load wall time'; + + // TODO(alexandermont): Only iterate over the processes and threads that + // could contain these events. + for (const slice of model.getDescendantEvents()) { + if (!(slice instanceof tr.model.ThreadSlice)) continue; + + // WebLayerStartupInterval is the title of the section of code that is + // entered (via android.os.Trace.beginSection) when WebLayer is started + // up. This value is defined in TelemetryActivity.java. + if (slice.title === 'WebLayerStartupInterval') { + startupWallHist.addSample(slice.duration); + } + + // WebLayerBlankUrlLoadInterval is the title of the section of code + // that is entered (via android.os.Trace.beginSection) when WebLayer + // is started up. This value is defined in TelemetryActivity.java. + if (slice.title === 'WebLayerBlankUrlLoadInterval') { + loadWallHist.addSample(slice.duration); + } + } + + histograms.addHistogram(startupWallHist); + histograms.addHistogram(loadWallHist); + } + + tr.metrics.MetricRegistry.register(weblayerStartupMetric); + + return { + weblayerStartupMetric, + }; +}); +</script> diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/system_health/weblayer_startup_metric_test.html b/chromium/third_party/catapult/tracing/tracing/metrics/system_health/weblayer_startup_metric_test.html new file mode 100644 index 00000000000..acc5a8dc1c1 --- /dev/null +++ b/chromium/third_party/catapult/tracing/tracing/metrics/system_health/weblayer_startup_metric_test.html @@ -0,0 +1,46 @@ +<!DOCTYPE html> +<!-- +Copyright 2020 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. +--> + +<link rel="import" href="/tracing/core/test_utils.html"> +<link rel="import" href="/tracing/metrics/system_health/weblayer_startup_metric.html"> +<link rel="import" href="/tracing/value/histogram_set.html"> + +<script> +'use strict'; +tr.b.unittest.testSuite(function() { + function makeTestModel() { + return tr.c.TestUtils.newModel(function(model) { + const mainThread = model.getOrCreateProcess(1).getOrCreateThread(2); + mainThread.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ + cat: 'weblayer', + title: 'WebLayerStartupInterval', + start: 200, + duration: 42.0, + cpuStart: 150, + cpuDuration: 32.0 + })); + mainThread.sliceGroup.pushSlice(tr.c.TestUtils.newSliceEx({ + cat: 'weblayer', + title: 'WebLayerBlankUrlLoadInterval', + start: 250, + duration: 27.0, + cpuStart: 190, + cpuDuration: 17.0 + })); + }); + } + + test('weblayerStartupMetric', function() { + const histograms = new tr.v.HistogramSet(); + tr.metrics.sh.weblayerStartupMetric(histograms, makeTestModel()); + assert.closeTo(42, histograms.getHistogramNamed( + 'weblayer_startup_wall_time').average, 1e-2); + assert.closeTo(27, histograms.getHistogramNamed( + 'weblayer_url_load_wall_time').average, 1e-2); + }); +}); +</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 8f741b9cf7f..959006e9749 100644 --- a/chromium/third_party/catapult/tracing/tracing/metrics/uma_metric.html +++ b/chromium/third_party/catapult/tracing/tracing/metrics/uma_metric.html @@ -20,15 +20,12 @@ found in the LICENSE file. * * UMA histograms are logged in trace events titled 'UMAHistogramSamples'. The * event arguments contain the histogram name and the base-64 coded of an - * snapshot of histogram samples serialized in a pickle. + * snapshot of histogram samples serialized in a pickle. These are emitted at + * the end of tracing, and represent the difference in the UMA histograms from + * when the tracing began. * * If there are several processes that have snapshots of the same histogram, * the snapshots will be merged. - * - * If there are two snapshots of the same histogram in the same process, we - * assume that the first snapshot is taken when tracing started and the second - * snapshot is taken when tracing is stopped. So, we compute the difference to - * show the samples added during the tracing session. */ tr.exportTo('tr.metrics', function() { function parseBuckets_(event, processName) { @@ -78,36 +75,16 @@ tr.exportTo('tr.metrics', function() { } } - function subtractBins_(x, y) { - x.sum -= y.sum; - let p1 = 0; - let p2 = 0; - while (p2 < y.bins.length) { - while (p1 < x.bins.length && x.bins[p1].min !== y.bins[p2].min) { - p1++; - } - if (p1 === x.bins.length) throw new Error('Cannot subtract'); - if (x.bins[p1].max !== y.bins[p2].max) { - throw new Error('Incompatible bins'); - } - if (x.bins[p1].count < y.bins[p2].count) { - throw new Error('Cannot subtract'); - } - x.bins[p1].count -= y.bins[p2].count; - for (const event of y.bins[p2].events) { - x.bins[p1].events.add(event); - } - const processName = tr.b.getOnlyElement(x.bins[p1].processes)[0]; - x.bins[p1].processes.set(processName, x.bins[p1].count); - p2++; - } - } - function getHistogramUnit_(name) { // Customize histogram units here. return tr.b.Unit.byName.unitlessNumber_smallerIsBetter; } + function getIsHistogramBinsLinear_(histogramName) { + return histogramName.startsWith('Graphics.Smoothness.Throughput') || + histogramName.startsWith('Memory.Memory.GPU.PeakMemoryUsage'); + } + function getHistogramBoundaries_(name) { // Customize histogram boundaries here. Ideally, this would not be // necessary. @@ -150,13 +127,10 @@ tr.exportTo('tr.metrics', function() { if (!histogramValues.has(name)) histogramValues.set(name, values); const endValues = parseBuckets_(events[events.length - 1], processName); if (events.length === 1) { - mergeBins_(values, endValues); - } else if (events.length === 2) { - subtractBins_(endValues, parseBuckets_(events[0], processName)); - mergeBins_(values, endValues); + mergeBins_(values, endValues, name); } else { - throw new Error('There should be at most two snapshots of an UMA ' + - 'histogram in each process'); + throw new Error('There should be at most one snapshot of UMA ' + + `histogram for ${name} in each process.`); } } } @@ -164,6 +138,7 @@ tr.exportTo('tr.metrics', function() { for (const [name, values] of histogramValues) { const histogram = new tr.v.Histogram( name, getHistogramUnit_(name), getHistogramBoundaries_(name)); + const isLinear = getIsHistogramBinsLinear_(name); // If we just put samples at the middle of the bins, their sum may not // match the sum we read from traces. Compute how much samples should be // shifted so that their sum matches what we expect. @@ -173,16 +148,45 @@ tr.exportTo('tr.metrics', function() { sumOfMiddles += bin.count * (bin.min + bin.max) / 2; sumOfBinLengths += bin.count * (bin.max - bin.min); } + + if (name.startsWith('CompositorLatency.Type')) { + let histogramBoundaries = tr.v.HistogramBinBoundaries.createLinear(0, 100, 101); + let histogramUnit = getHistogramUnit_(name); + let presentedCount = values.bins[0] ? values.bins[0].count : 0; + let delayedCount = values.bins[1] ? values.bins[1].count : 0; + let droppedCount = values.bins[2] ? values.bins[2].count : 0; + let inTimeCount = presentedCount - delayedCount; + let totalCount = presentedCount + droppedCount; + + const inTimeHistogram = new tr.v.Histogram( + name+'.Percentage_of_in_time_frames', histogramUnit, histogramBoundaries); + inTimeHistogram.addSample(100.0 * inTimeCount / totalCount); + histograms.addHistogram(inTimeHistogram); + + const delayedHistogram = new tr.v.Histogram( + name+'.Percentage_of_delayed_frames', histogramUnit, histogramBoundaries); + delayedHistogram.addSample(100.0 * delayedCount / totalCount); + histograms.addHistogram(delayedHistogram); + + const droppedHistogram = new tr.v.Histogram( + name+'.Percentage_of_dropped_frames', histogramUnit, histogramBoundaries); + droppedHistogram.addSample(100.0 * droppedCount / totalCount); + histograms.addHistogram(droppedHistogram); + } + const shift = (values.sum - sumOfMiddles) / sumOfBinLengths; - // Note: if shift is less than -0.5, it means that even if we put all - // samples at the lowest value of their bins their sum will be less than - // the sum we read from traces. So, there is an inconsistency: either the - // bins are reported incorrectly, or the sum is reported incorrectly. + // Note: for linear bins, if shift is less than -0.5, it means that even + // if we put all samples at the lowest value of their bins their sum will + // be less than the sum we read from traces. So, there is an + // inconsistency: either the bins are reported incorrectly, or the sum is + // reported incorrectly. // // Similarly, if shift is greater than 0.5, the sum of samples cannot add // up to the sum we read from traces, even if we put all samples at the // highest value of their bins. - if (Math.abs(shift) > 0.5) throw new Error('Samples sum is wrong'); + if (isLinear && Math.abs(shift) > 0.5) { + throw new Error(`Samples sum is wrong for ${name}.`); + } for (const bin of values.bins) { if (bin.count === 0) continue; diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/uma_metric_test.html b/chromium/third_party/catapult/tracing/tracing/metrics/uma_metric_test.html index ae512c6b4ef..e11aca5c4f8 100644 --- a/chromium/third_party/catapult/tracing/tracing/metrics/uma_metric_test.html +++ b/chromium/third_party/catapult/tracing/tracing/metrics/uma_metric_test.html @@ -15,13 +15,11 @@ found in the LICENSE file. tr.b.unittest.testSuite(function() { // 1 sample in [1, 3) and 2 samples in [3, 7). - const BROWSER_BUCKETS1 = + const BROWSER_BUCKETS = 'LAAAAAwAAAAAAAAAAwAAAAEAAAADAAAAAAAAAAEAAAADAAAABwAAAAAAAAACAAAA'; // 1 sample in [3, 7). - const BROWSER_BUCKETS2 = 'HAAAAAUAAAAAAAAAAQAAAAMAAAAHAAAAAAAAAAEAAAA='; - // 2 samples in [7, 9). const RENDERER_BUCKETS = 'HAAAABAAAAAAAAAAAgAAAAcAAAAJAAAAAAAAAAIAAAA='; - // 1 sample in [8, 10). + // 2 samples in [8, 10). const RENDERER_INCOMPATIBLE_BUCKETS = 'HAAAAAkAAAAAAAAAAQAAAAgAAAAKAAAAAAAAAAEAAAA='; // 1 sample in [1, 3) and 2 samples in [3, 7). The sum is 9. @@ -38,7 +36,7 @@ tr.b.unittest.testSuite(function() { title: 'UMAHistogramSamples', start: 2, args: { name: 'metric1', - buckets: BROWSER_BUCKETS1}})); + buckets: BROWSER_BUCKETS}})); }); const histograms = new tr.v.HistogramSet(); tr.metrics.umaMetric(histograms, model); @@ -57,47 +55,15 @@ tr.b.unittest.testSuite(function() { assert.closeTo(2, processes.get('browser_process_1'), 1e-6); }); - test('twoUMASnapshots', function() { - const model = tr.c.TestUtils.newModel((model) => { - const browserProcess = model.getOrCreateProcess(0); - browserProcess.getOrCreateThread(0).name = 'CrBrowserMain'; - browserProcess.instantEvents.push(tr.c.TestUtils.newInstantEvent({ - title: 'UMAHistogramSamples', start: 1, - args: { - name: 'metric1', - buckets: BROWSER_BUCKETS2}})); - browserProcess.instantEvents.push(tr.c.TestUtils.newInstantEvent({ - title: 'UMAHistogramSamples', start: 2, - args: { - name: 'metric1', - buckets: BROWSER_BUCKETS1}})); - }); - const histograms = new tr.v.HistogramSet(); - tr.metrics.umaMetric(histograms, model); - const hist = histograms.getHistogramNamed('metric1'); - - // (BROWSER_BUCKETS1 - BROWSER_BUCKETS2) looks like - // * * - // 1 2 3 4 5 6 7 - assert.closeTo(2, hist.min, 1e-6); - assert.closeTo(5, hist.max, 1e-6); - assert.closeTo(3.5, hist.average, 1e-6); - }); - test('twoUMASnapshotsInDifferentProcesses', function() { const model = tr.c.TestUtils.newModel((model) => { const browserProcess = model.getOrCreateProcess(0); browserProcess.getOrCreateThread(0).name = 'CrBrowserMain'; browserProcess.instantEvents.push(tr.c.TestUtils.newInstantEvent({ - title: 'UMAHistogramSamples', start: 1, - args: { - name: 'metric1', - buckets: BROWSER_BUCKETS2}})); - browserProcess.instantEvents.push(tr.c.TestUtils.newInstantEvent({ title: 'UMAHistogramSamples', start: 2, args: { name: 'metric1', - buckets: BROWSER_BUCKETS1}})); + buckets: BROWSER_BUCKETS}})); const process = model.getOrCreateProcess(1); process.instantEvents.push(tr.c.TestUtils.newInstantEvent({ title: 'UMAHistogramSamples', start: 2, @@ -110,12 +76,12 @@ tr.b.unittest.testSuite(function() { const hist = histograms.getHistogramNamed('metric1'); // The aggregated histogram looks like - // * + // * * // * * * // 1 2 3 4 5 6 7 8 9 assert.closeTo(2, hist.min, 1e-6); assert.closeTo(8, hist.max, 1e-6); - assert.closeTo(5.75, hist.average, 1e-6); + assert.closeTo(5.6, hist.average, 1e-6); const bin = hist.getBinForValue(8); for (const diagnostics of bin.diagnosticMaps) { @@ -188,27 +154,5 @@ tr.b.unittest.testSuite(function() { tr.metrics.umaMetric(histograms, model); }, 'Incompatible bins'); }); - - test('badStartStopUMASnapshots', function() { - const model = tr.c.TestUtils.newModel((model) => { - const browserProcess = model.getOrCreateProcess(0); - browserProcess.getOrCreateThread(0).name = 'CrBrowserMain'; - browserProcess.instantEvents.push(tr.c.TestUtils.newInstantEvent({ - title: 'UMAHistogramSamples', start: 1, - args: { - name: 'metric1', - buckets: BROWSER_BUCKETS1}})); - browserProcess.instantEvents.push(tr.c.TestUtils.newInstantEvent({ - title: 'UMAHistogramSamples', start: 2, - args: { - name: 'metric1', - buckets: BROWSER_BUCKETS2}})); - }); - const histograms = new tr.v.HistogramSet(); - - assert.throws(function() { - tr.metrics.umaMetric(histograms, model); - }, 'Cannot subtract'); - }); }); </script> diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/v8/OWNERS b/chromium/third_party/catapult/tracing/tracing/metrics/v8/OWNERS index 3ecc1606516..1de8cc86062 100644 --- a/chromium/third_party/catapult/tracing/tracing/metrics/v8/OWNERS +++ b/chromium/third_party/catapult/tracing/tracing/metrics/v8/OWNERS @@ -1,3 +1,2 @@ mlippautz@chromium.org -mythria@chromium.org -ulan@chromium.org +omerkatz@chromium.org diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/v8/gc_metric.html b/chromium/third_party/catapult/tracing/tracing/metrics/v8/gc_metric.html index 75cae51c2e1..5390adb2eb2 100644 --- a/chromium/third_party/catapult/tracing/tracing/metrics/v8/gc_metric.html +++ b/chromium/third_party/catapult/tracing/tracing/metrics/v8/gc_metric.html @@ -22,6 +22,795 @@ tr.exportTo('tr.metrics.v8', function() { const TARGET_FPS = 60; const MS_PER_SECOND = 1000; const WINDOW_SIZE_MS = MS_PER_SECOND / TARGET_FPS; + const EPSILON = 1e-6; + + /** + * A list of metrics that are measured and tracked. + * + * See https://bit.ly/v8-gc-stats-collection for the metric naming convention. + * You can add a variant of an existing metric by simply adding its name to + * this list. E.g. v8:gc:cycle:background_threads:full:atomic:mark:cpp. + * + * If you want to add a completely new metric with its own TRACE_EVENT then + * you also need to add the corresponding rule to the RULES list below. + * + * @const {!Array<string>} + */ + const METRICS = [ + 'v8:gc:cycle:full', + 'v8:gc:cycle:full:cpp', + 'v8:gc:cycle:full:mark', + 'v8:gc:cycle:full:mark:cpp', + 'v8:gc:cycle:full:weak', + 'v8:gc:cycle:full:weak:cpp', + 'v8:gc:cycle:full:sweep', + 'v8:gc:cycle:full:sweep:cpp', + 'v8:gc:cycle:full:compact', + 'v8:gc:cycle:full:compact:cpp', + 'v8:gc:cycle:main_thread:full', + 'v8:gc:cycle:main_thread:full:cpp', + 'v8:gc:cycle:main_thread:full:mark', + 'v8:gc:cycle:main_thread:full:mark:cpp', + 'v8:gc:cycle:main_thread:full:weak', + 'v8:gc:cycle:main_thread:full:weak:cpp', + 'v8:gc:cycle:main_thread:full:sweep', + 'v8:gc:cycle:main_thread:full:sweep:cpp', + 'v8:gc:cycle:main_thread:full:compact', + 'v8:gc:cycle:main_thread:full:compact:cpp', + 'v8:gc:cycle:main_thread:full:atomic', + 'v8:gc:cycle:main_thread:full:atomic:cpp', + 'v8:gc:cycle:main_thread:full:atomic:mark', + 'v8:gc:cycle:main_thread:full:atomic:mark:cpp', + 'v8:gc:cycle:main_thread:full:atomic:weak', + 'v8:gc:cycle:main_thread:full:atomic:weak:cpp', + 'v8:gc:cycle:main_thread:full:atomic:sweep', + 'v8:gc:cycle:main_thread:full:atomic:sweep:cpp', + 'v8:gc:cycle:main_thread:full:atomic:compact', + 'v8:gc:cycle:main_thread:full:atomic:compact:cpp', + 'v8:gc:cycle:main_thread:full:incremental', + 'v8:gc:cycle:main_thread:full:incremental:cpp', + 'v8:gc:cycle:main_thread:full:incremental:mark', + 'v8:gc:cycle:main_thread:full:incremental:mark:cpp', + 'v8:gc:cycle:main_thread:full:incremental:sweep', + 'v8:gc:cycle:main_thread:full:incremental:sweep:cpp', + 'v8:gc:event:main_thread:full:atomic', + 'v8:gc:event:main_thread:full:atomic:cpp', + 'v8:gc:event:main_thread:full:atomic:mark', + 'v8:gc:event:main_thread:full:atomic:mark:cpp', + 'v8:gc:event:main_thread:full:atomic:weak', + 'v8:gc:event:main_thread:full:atomic:weak:cpp', + 'v8:gc:event:main_thread:full:atomic:sweep', + 'v8:gc:event:main_thread:full:atomic:sweep:cpp', + 'v8:gc:event:main_thread:full:atomic:compact', + 'v8:gc:event:main_thread:full:atomic:compact:cpp', + 'v8:gc:event:main_thread:full:incremental', + 'v8:gc:event:main_thread:full:incremental:cpp', + 'v8:gc:event:main_thread:full:incremental:mark', + 'v8:gc:event:main_thread:full:incremental:mark:cpp', + 'v8:gc:event:main_thread:full:incremental:sweep', + 'v8:gc:event:main_thread:full:incremental:sweep:cpp', + 'v8:gc:cycle:young', + 'v8:gc:cycle:young:mark', + 'v8:gc:cycle:young:weak', + 'v8:gc:cycle:young:sweep', + 'v8:gc:cycle:young:compact', + 'v8:gc:cycle:main_thread:young', + 'v8:gc:cycle:main_thread:young:mark', + 'v8:gc:cycle:main_thread:young:weak', + 'v8:gc:cycle:main_thread:young:sweep', + 'v8:gc:cycle:main_thread:young:compact', + 'v8:gc:cycle:main_thread:young:atomic', + 'v8:gc:cycle:main_thread:young:atomic:mark', + 'v8:gc:cycle:main_thread:young:atomic:weak', + 'v8:gc:cycle:main_thread:young:atomic:sweep', + 'v8:gc:cycle:main_thread:young:atomic:compact', + 'v8:gc:cycle:main_thread:young:incremental', + 'v8:gc:cycle:main_thread:young:incremental:mark', + 'v8:gc:cycle:main_thread:young:incremental:sweep', + 'v8:gc:event:main_thread:young:atomic', + 'v8:gc:event:main_thread:young:atomic:mark', + 'v8:gc:event:main_thread:young:atomic:weak', + 'v8:gc:event:main_thread:young:atomic:sweep', + 'v8:gc:event:main_thread:young:atomic:compact', + 'v8:gc:event:main_thread:young:incremental', + 'v8:gc:event:main_thread:young:incremental:mark', + 'v8:gc:event:main_thread:young:incremental:sweep', + ]; + + /** + * Shorthands for various event groups to be used in RULES below. + */ + const V8_FULL_ATOMIC_EVENTS = [ + 'V8.GC_MARK_COMPACTOR' + ]; + + const V8_FULL_MARK_EVENTS = [ + 'V8.GC_MC_BACKGROUND_MARKING', + 'V8.GC_MC_MARK', + 'V8.GC_MC_INCREMENTAL', + 'V8.GC_MC_INCREMENTAL_START', + ]; + + const V8_FULL_COMPACT_EVENTS = [ + 'V8.GC_MC_BACKGROUND_EVACUATE_COPY', + 'V8.GC_MC_BACKGROUND_EVACUATE_UPDATE_POINTERS', + 'V8.GC_MC_EVACUATE', + ]; + + const V8_FULL_SWEEP_EVENTS = [ + 'V8.GC_MC_BACKGROUND_SWEEPING', + 'V8.GC_MC_SWEEP', + 'V8.GC_MC_COMPLETE_SWEEPING', + ]; + + const V8_FULL_WEAK_EVENTS = [ + 'V8.GC_MC_CLEAR', + ]; + + const V8_YOUNG_ATOMIC_EVENTS = [ + 'V8.GC_SCAVENGER_BACKGROUND_SCAVENGE_PARALLEL', + 'V8.GC_SCAVENGER', + 'V8.GC_MINOR_MARK_COMPACTOR', + ]; + + const V8_YOUNG_MARK_EVENTS = [ + 'V8.GC_MINOR_MC_BACKGROUND_MARKING', + 'V8.GC_MINOR_MC_MARK', + 'V8.GC_MINOR_MC_INCREMENTAL', + 'V8.GC_MINOR_MC_INCREMENTAL_START', + ]; + + const V8_YOUNG_COMPACT_EVENTS = [ + 'V8.GC_MINOR_MC_BACKGROUND_EVACUATE_COPY', + 'V8.GC_MINOR_MC_BACKGROUND_EVACUATE_UPDATE_POINTERS', + 'V8.GC_MINOR_MC_EVACUATE', + ]; + + const V8_YOUNG_SWEEP_EVENTS = [ + 'V8.GC_MINOR_MC_BACKGROUND_SWEEPING', + 'V8.GC_MINOR_MC_SWEEP', + ]; + + const V8_YOUNG_WEAK_EVENTS = [ + 'V8.GC_MINOR_MC_CLEAR', + ]; + + const CPP_GC_FULL_MARK_EVENTS = [ + 'BlinkGC.AtomicPauseMarkEpilogue', + 'BlinkGC.AtomicPauseMarkPrologue', + 'BlinkGC.AtomicPauseMarkRoots', + 'BlinkGC.AtomicPauseMarkTransitiveClosure', + 'BlinkGC.ConcurrentMarkingStep', + 'BlinkGC.IncrementalMarkingStartMarking', + 'BlinkGC.IncrementalMarkingStep', + 'BlinkGC.MarkBailOutObjects', + 'BlinkGC.MarkFlushEphemeronPairs', + 'BlinkGC.MarkFlushV8References', + 'BlinkGC.UnifiedMarkingStep', + 'CppGC.AtomicMark', + 'CppGC.IncrementalMark', + 'CppGC.ConcurrentMark', + ]; + + const CPP_GC_FULL_COMPACT_EVENTS = [ + 'BlinkGC.AtomicPauseSweepAndCompact', + 'CppGC.AtomicCompact', + ]; + + const CPP_GC_FULL_SWEEP_EVENTS = [ + 'BlinkGC.CompleteSweep', + 'BlinkGC.ConcurrentSweepingStep', + 'BlinkGC.LazySweepInIdle', + 'BlinkGC.LazySweepOnAllocation', + 'CppGC.AtomicSweep', + 'CppGC.IncrementalSweep', + 'CppGC.ConcurrentSweep', + ]; + + const CPP_GC_FULL_WEAK_EVENTS = [ + 'BlinkGC.MarkWeakProcessing', + 'CppGC.AtomicWeak', + ]; + + /** + * A Rule object describes a mapping from events to metrics. + * + * For each event in a single GC cycle there can be at most one rule that + * that applies to that event. An event E applies to a rule R if all the + * following conditions hold: + * + * 1. R.events contains E.title. + * + * 2. if R.inside is not empty, then at least one event X specified by + * R.inside exists on some thread and fully encloses E: + * X.start <= E.start && E.end <= X.end. + * Note that X and E don't have to be on the same thread, which allows + * us to find background thread events that happen during atomic pause. + * + * 3. if R.outside is not empty, then there is no such event X specified + * by R.outside that fully encloses E. This is useful for background + * events that happen during incremental phases. + * + * TODO(chromium:1056170): Currently event names of V8 and CppGC do not + * collide because V8 events are prefixed with 'V8' and CppGC events are + * prefixed with 'CppGC'. Revisit this it before switching to the library. + * We may need to either include the category to rules or keep the prefixes. + * + * @typedef {Object} Rule + * @property {!Array<string>} events - Event names selected by this rule. + * @property {?Array<string>} inside - Allowlist of enclosing event names. + * @property {?Array<string>} outside - Blocklist of enclosing event names. + * @property {string} contribute_to - The most specific target metric name. + * The rule automatically applies to all more general metrics that can + * be derived by dropping parts of the target metric name. + * Note that the metric name does not include granularity and threads. + */ + + /** + * @const {!Array<!Rule>} + */ + const RULES = [ + { + events: V8_FULL_ATOMIC_EVENTS, + contribute_to: 'full:atomic', + }, + { + events: V8_FULL_MARK_EVENTS, + inside: V8_FULL_ATOMIC_EVENTS, + contribute_to: 'full:atomic:mark', + }, + { + events: CPP_GC_FULL_MARK_EVENTS, + inside: V8_FULL_ATOMIC_EVENTS, + contribute_to: 'full:atomic:mark:cpp', + }, + { + events: V8_FULL_MARK_EVENTS, + outside: V8_FULL_ATOMIC_EVENTS, + contribute_to: 'full:incremental:mark', + }, + { + events: CPP_GC_FULL_MARK_EVENTS, + outside: V8_FULL_ATOMIC_EVENTS, + contribute_to: 'full:incremental:mark:cpp', + }, + { + events: V8_FULL_COMPACT_EVENTS, + inside: V8_FULL_ATOMIC_EVENTS, + contribute_to: 'full:atomic:compact', + }, + { + events: CPP_GC_FULL_COMPACT_EVENTS, + inside: V8_FULL_ATOMIC_EVENTS, + contribute_to: 'full:atomic:compact:cpp', + }, + { + events: V8_FULL_SWEEP_EVENTS, + inside: V8_FULL_ATOMIC_EVENTS, + outside: V8_FULL_COMPACT_EVENTS, + contribute_to: 'full:atomic:sweep', + }, + { + events: CPP_GC_FULL_SWEEP_EVENTS, + inside: V8_FULL_ATOMIC_EVENTS, + contribute_to: 'full:atomic:sweep:cpp', + }, + { + events: V8_FULL_WEAK_EVENTS, + inside: V8_FULL_ATOMIC_EVENTS, + contribute_to: 'full:atomic:weak', + }, + { + events: CPP_GC_FULL_WEAK_EVENTS, + inside: V8_FULL_ATOMIC_EVENTS, + contribute_to: 'full:atomic:weak:cpp', + }, + { + events: V8_FULL_SWEEP_EVENTS, + outside: V8_FULL_ATOMIC_EVENTS.concat(V8_FULL_COMPACT_EVENTS), + contribute_to: 'full:incremental:sweep', + }, + { + events: CPP_GC_FULL_SWEEP_EVENTS, + outside: V8_FULL_ATOMIC_EVENTS, + contribute_to: 'full:incremental:sweep:cpp', + }, + { + events: V8_YOUNG_ATOMIC_EVENTS, + contribute_to: 'young:atomic', + }, + { + events: V8_YOUNG_MARK_EVENTS, + inside: V8_YOUNG_ATOMIC_EVENTS, + contribute_to: 'young:atomic:mark', + }, + { + events: V8_YOUNG_MARK_EVENTS, + outside: V8_YOUNG_ATOMIC_EVENTS, + contribute_to: 'young:incremental:mark', + }, + { + events: V8_YOUNG_COMPACT_EVENTS, + inside: V8_YOUNG_ATOMIC_EVENTS, + contribute_to: 'young:atomic:compact', + }, + { + events: V8_YOUNG_SWEEP_EVENTS, + inside: V8_YOUNG_ATOMIC_EVENTS, + outside: V8_YOUNG_COMPACT_EVENTS, + contribute_to: 'young:atomic:sweep', + }, + { + events: V8_YOUNG_WEAK_EVENTS, + inside: V8_YOUNG_ATOMIC_EVENTS, + contribute_to: 'young:atomic:weak', + }, + { + events: V8_YOUNG_SWEEP_EVENTS, + outside: V8_YOUNG_ATOMIC_EVENTS.concat(V8_YOUNG_COMPACT_EVENTS), + contribute_to: 'young:incremental:sweep', + }, + ]; + + /** + * A part of the metric name that defines how the events contributing to + * the metric are aggregated. See Metric.apply() below. + * @enum {string} + */ + const Granularity = { + CYCLE: 'cycle', + EVENT: 'event', + }; + + /** + * A thread of a V8 isolate is considered a main thread including: + * + * - the main thread of the renderer. + * - the main thread of a dedicated worker. + * - the main thread of a service worker. + * + * A thread that runs background tasks is considered a background + * thread. See jsExecutionThreadsWithTypes() below. + * + * @enum {string} + */ + const ThreadType = { + MAIN: 'main', + BACKGROUND: 'background', + ALL_THREADS: 'all_threads', + }; + + /** + * Represents a single metric together with its histogram of measurements. + */ + class Metric { + /** + * @param{string} name The name of the metric. + * See https://bit.ly/v8-gc-stats-collection for the metric naming + * convention and the meanining of name parts. + */ + constructor(name) { + const parts = name.split(':'); + + /** @private @const {Granularity} */ + this.granularity_ = parts[2]; + assert(this.granularity_ === Granularity.CYCLE || + this.granularity_ === Granularity.EVENT); + + /** @private @const {?ThreadType} */ + this.thread_ = ThreadType.ALL_THREADS; + let phasesIndex = 3; + if (parts[3] === 'main_thread') { + this.thread_ = ThreadType.MAIN; + phasesIndex = 4; + } + if (parts[3] === 'background_threads') { + this.thread_ = ThreadType.BACKGROUND; + phasesIndex = 4; + } + + /** @private @const {!Array<string>} */ + this.phases_ = parts.slice(phasesIndex); + + const maxValue = this.isPerCycleMetric() ? 10000 : 1000; + const boundaries = + tr.v.HistogramBinBoundaries.createExponential(0.1, maxValue, 100); + + /** @package @const {!tr.v.Histogram} */ + this.histogram = new tr.v.Histogram(name, + tr.b.Unit.byName.timeDurationInMs_smallerIsBetter, boundaries); + this.histogram.customizeSummaryOptions({ + avg: true, + count: true, + max: true, + min: false, + std: false, + sum: this.isPerCycleMetric(), + }); + } + + /** + * @return {boolean} Whether the granularity of this metric is per cycle. + */ + isPerCycleMetric() { + return this.granularity_ === Granularity.CYCLE; + } + + /** + * @param {!Array<string>} phases - A list of metric phases. + * @return {boolean} Whether the phases of this metric are more general + * than (or equal to) the given phases. + */ + isMoreGeneralThanOrEqualTo(phases) { + // Check that this.phases_ is a subset of phases. + const phasesSet = new Set(phases.split(':')); + return this.phases_.every(phase => phasesSet.has(phase)); + } + + /** + * @param {!Array<!Rule>} rules - Rules that map events to metrics. + * @param {!Array<!tr.model.Slice>} events - All events of a single GC cycle + * including the events of the main and background threads. + * @return {!Array<!tr.model.Slice>} A subset of the given events that + * contribute to this metric. + */ + contributingEvents(rules, events) { + // A map from an event name to the events with that name. + // It is used to speed up enclosing checks below. + const eventsByName = groupBy(events, e => e.title); + + // Checks if the given rule matches (or applies) to the given event. + function matches(rule, event) { + // Checks if there is an event with the given name that encloses + // |event|. + function isEnclosing(name) { + if (!eventsByName.has(name)) return false; + return eventsByName.get(name).some(e => encloses(e, event)); + } + if (!rule.events.includes(event.title)) { + return false; + } + if (rule.inside && !rule.inside.some(isEnclosing)) { + return false; + } + if (rule.outside && rule.outside.some(isEnclosing)) { + return false; + } + return true; + } + + // For each event find the applying rule and check if the rule also + // applies to this metric. + const result = []; + for (const event of events) { + const matching = rules.filter(r => matches(r, event)); + if (matching.length === 0) { + continue; + } + assert(matching.length === 1, + `${event.userFriendlyName} matches more than one rule: ` + + JSON.stringify(matching)); + if (this.isMoreGeneralThanOrEqualTo(matching[0].contribute_to)) { + result.push(event); + } + } + return result; + } + + /** + * Finds all events that contribute to this metric and aggregates them + * in the metric's histogram. + * + * @param {!Array<!Rule>} rules - Rules that map events to metrics. + * @param {!Array<!tr.model.Slice>} events - All events of a single GC cycle + * including the events of the main and background threads. + * @param {!Map<number, ThreadType>} threadTypes - A map from a thread-id + * to a thread type. + */ + apply(rules, events, threadTypes) { + // Find all events that are relevant for this metric. + const filtered = this.contributingEvents(rules, events); + + // Group the events by thread. + const eventsByThread = groupBy(filtered, e => e.parentContainer.tid); + + // Drop events nested in other events and also drop events from + // the irrelevant threads. + let flattened = []; + for (const [tid, threadEvents] of eventsByThread) { + if (this.thread_ === ThreadType.ALL_THREADS || + this.thread_ === threadTypes.get(tid)) { + flattened = flattened.concat(flatten(threadEvents)); + } + } + + // Aggregate events in the histogram. + if (this.isPerCycleMetric()) { + let sum = 0; + for (const event of flattened) { + sum += event.cpuDuration; + } + if (flattened.length > 0) { + this.histogram.addSample(sum); + } + } else { + for (const event of flattened) { + this.histogram.addSample(event.cpuDuration); + } + } + } + } + + /** + * A helper for checking the condition. + * @param {boolean} condition + * @param {string} message + */ + function assert(condition, message) { + if (!condition) { + throw new Error(message); + } + } + + /** + * A helper for grouping objects by the custom key. + * @param {!Array<!Object>} objects + * @param {!function(!Object): !Object} keyCallback + * @param {!Map<!Object, !Array<!Object>>} Objects grouped by the key. + */ + function groupBy(objects, keyCallback) { + const result = new Map(); + for (const object of objects) { + const group = keyCallback(object); + if (result.has(group)) { + result.get(group).push(object); + } else { + result.set(group, [object]); + } + } + return result; + } + + /** + * A helper for getting all events relevant for the rules. + * @param {!Array<Rule>} rules + * @return {!Array<string>} Event names. + */ + function eventsMentionedIn(rules) { + let result = []; + for (const rule of rules) { + result = result.concat(rule.events); + if (rule.inside) { + result = result.concat(rule.inside); + } + if (rule.outside) { + result = result.concat(rule.outside); + } + } + return result; + } + + + /** + * Performs thread-independent check for event nesting. + * + * @param {!Array<!tr.model.Slice>} event1 + * @param {!Array<!tr.model.Slice>} event2 + * @return {boolean} Whether the first event encloses the second event. + */ + function encloses(event1, event2) { + return (event1.start - EPSILON <= event2.start && + event2.end <= event1.end + EPSILON); + } + + /** + * Finds all threads that may execute JS code in the given renderer + * and return them together with the thread-id to thread type mapping. + * + * @param {!tr.model.helpers.ChromeRendererHelper} rendererHelper + * @return {[!Array<tr.model.Thread>, !Map<number, ThreadType>] A pair + * of a thread list and a thread type mapping. + */ + function jsExecutionThreadsWithTypes(rendererHelper) { + const mainThreads = ([rendererHelper.mainThread] + .concat(rendererHelper.dedicatedWorkerThreads) + .concat(rendererHelper.serviceWorkerThreads)); + const backgroundThreads = rendererHelper.foregroundWorkerThreads; + const threadTypes = new Map(); + for (const thread of mainThreads) { + threadTypes.set(thread.tid, ThreadType.MAIN); + } + for (const thread of backgroundThreads) { + threadTypes.set(thread.tid, ThreadType.BACKGROUND); + } + return [mainThreads.concat(backgroundThreads), threadTypes]; + } + + /** + * Drops all events that are nested in other events. + * + * @param {!Array<!tr.model.Slice>} events - Events on the same thread. + * @return {!Array<!tr.model.Slice>} Top-level events. + */ + function flatten(events) { + function compareWithEpsilon(a, b) { + if (a.start < b.start - EPSILON) return -1; + if (a.start > b.start + EPSILON) return 1; + return b.end - a.end; + } + events.sort(compareWithEpsilon); + let last = events[0]; + const result = [last]; + for (const e of events) { + if (e.end > last.end + EPSILON) { + assert(e.start >= last.end - EPSILON, + 'Overlapping events: ' + + e.userFriendlyName + ' ' + + last.userFriendlyName); + result.push(e); + last = e; + } + } + return result; + } + + /** + * Groups the events by GC cycle using the epoch argument of events. + * + * The function is more complex than expected for two reasons: + * + * 1. V8 and CppGC do not syncronize their epoch counters (yet). + * 2. V8 adds the epoch argument only to the top-level events. Nested + * events are not requred to have the epoch. + * + * The function first finds the mapping from CppGC epoch to V8 epoch assuming + * that there will always be a CppGC event nested in a V8 event. + * Then it finds the V8 epoch for each nested V8 event and CppGC event. + * Finally, it groups the events by their V8 epoch. + * + * @param {!Array<!tr.model.Slice>} events - Events from multiple GC cycles + * and multiple threads. + * @return {!Map<string, !Array<!tr.model.Slice>>} Grouped events. + */ + function groupByEpoch(events) { + function isV8Event(event) { + // TODO(1056170): Adjust this if the CppGC library uses a v8 category + // for trace events. + return event.category && event.category.includes('v8'); + } + + // Finds the V8 and CppGC epoch arguments in the given event and its + // ancestors. + function getEpoch(event) { + function checkEpochConsistency(epoch, event) { + if (epoch === null) return; + assert(epoch === event.args.epoch, + `${event.userFriendlyName} has epoch ${event.args.epoch} ` + + `which contradicts the epoch of nested events ${epoch}`); + } + const result = {v8: null, cpp: null}; + while (event) { + if ('epoch' in event.args) { + if (isV8Event(event)) { + checkEpochConsistency(result.v8, event); + result.v8 = event.args.epoch; + } else { + checkEpochConsistency(result.cpp, event); + result.cpp = event.args.epoch; + } + } + event = event.parentSlice; + } + return result; + } + + // The following two functions combine V8 and CppGC epoch into a single + // global epoch. We give V8 even global epochs and CppGC odd global epochs. + function GlobalEpochFromV8(v8Epoch) { + return 2 * v8Epoch; + } + + function GlobalEpochFromCpp(cppEpoch) { + return 2 * cppEpoch + 1; + } + + // Find the mapping from a CppGC epoch to a V8 epoch. + const cppToV8 = new Map(); + for (const event of events) { + const epoch = getEpoch(event); + if (epoch.cpp !== null && epoch.v8 !== null) { + // The start of V8 incremental marking may finalize GppGC sweeping + // of the previous garbage collection cycle. Thus it may happen that + // the same CppGC epoch maps to two V8 epoch. In such a conflict + // the smaller V8 epoch wins, essentially mapping the event back to + // the previous V8 cycle. + if (!cppToV8.has(epoch.cpp) || cppToV8.get(epoch.cpp) > epoch.v8) { + cppToV8.set(epoch.cpp, epoch.v8); + } + } + } + + // For each event infer its V8 epoch and group by that. + const result = new Map(); + for (const event of events) { + const epoch = getEpoch(event); + if (epoch.cpp === null && epoch.v8 === null) { + continue; + } + let globalEpoch; + if (epoch.v8 !== null) { + // Case 1: either a V8 event or a CppGC event nested in a V8 event. + globalEpoch = GlobalEpochFromV8(epoch.v8); + } else if (cppToV8.has(epoch.cpp)) { + // Case 2: A CppGC event of a unified garbage collection. + globalEpoch = GlobalEpochFromV8(cppToV8.get(epoch.cpp)); + } else { + // Case 3: An event from a standalone CppGC garbage collection. + globalEpoch = GlobalEpochFromCpp(epoch.cpp); + } + if (result.has(globalEpoch)) { + result.get(globalEpoch).push(event); + } else { + result.set(globalEpoch, [event]); + } + } + return result; + } + + /** + * The main entry point of GC metric computation. + * + * @param {!Array<string} metricNames - A list of metric names to be computed. + * @param {!tr.v.HistogramSet} histograms - The histogram set where the new + * histograms will be added. + * @param {!tr.Model} model + */ + function addGarbageCollectionMetrics(metricNames, histograms, model) { + // Parse the metric names and store them in a list. + const metrics = metricNames.map(name => new Metric(name)); + + // Compute the set of GC related event names. + const gcEventNames = new Set(eventsMentionedIn(RULES)); + + // Iterate all renderer processes. + const chromeHelper = model.getOrCreateHelper( + tr.model.helpers.ChromeModelHelper); + for (const rendererHelper of Object.values(chromeHelper.rendererHelpers)) { + if (rendererHelper.isChromeTracingUI) continue; + + const [threads, threadTypes] = + jsExecutionThreadsWithTypes(rendererHelper); + + // Get all GC related events. + const events = []; + for (const thread of threads) { + for (const event of thread.sliceGroup.childEvents()) { + if (gcEventNames.has(event.title)) { + events.push(event); + } + } + } + + // Group events by GC cycle and consider each cycle separately. + for (const cycleEvents of groupByEpoch(events).values()) { + // If any event is in the cycle is forced, then the whole cycle + // is considered forced. Skip all events in the cycle. + if (cycleEvents.some( + tr.metrics.v8.utils.isForcedGarbageCollectionEvent)) { + continue; + } + + for (const metric of metrics) { + metric.apply(RULES, cycleEvents, threadTypes); + } + } + } + + // Add the new histograms to the resulting histogram set. + for (const metric of metrics) { + histograms.addHistogram(metric.histogram); + } + } function gcMetric(histograms, model, options) { options = options || {}; @@ -36,6 +825,7 @@ tr.exportTo('tr.metrics.v8', function() { addTotalMarkCompactorTime(histograms, model); addTotalMarkCompactorMarkingTime(histograms, model); addScavengerSurvivedFromStackEvents(histograms, model); + addGarbageCollectionMetrics(METRICS, histograms, model); } tr.metrics.MetricRegistry.register(gcMetric); @@ -380,6 +1170,7 @@ tr.exportTo('tr.metrics.v8', function() { return { gcMetric, WINDOW_SIZE_MS, // For testing purposes only. + addGarbageCollectionMetrics, // For testing purposes only. }; }); </script> diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/v8/gc_metric_test.html b/chromium/third_party/catapult/tracing/tracing/metrics/v8/gc_metric_test.html index 4d0d3beca88..d542c1e25dd 100644 --- a/chromium/third_party/catapult/tracing/tracing/metrics/v8/gc_metric_test.html +++ b/chromium/third_party/catapult/tracing/tracing/metrics/v8/gc_metric_test.html @@ -16,16 +16,21 @@ found in the LICENSE file. 'use strict'; tr.b.unittest.testSuite(function() { - function createModel(start, end, slices) { - return tr.e.chrome.ChromeTestUtils.newChromeModel(function(model) { - const rendererProcess = model.rendererProcess; - const mainThread = model.rendererMain; - const group = mainThread.sliceGroup; + function createModel(slices, backgroundSlices) { + function addSlices(thread, slices) { + const group = thread.sliceGroup; for (const slice of slices) { group.pushSlice(tr.c.TestUtils.newSliceEx(slice)); } group.createSubSlices(); - mainThread.updateBounds(); + thread.updateBounds(); + } + return tr.e.chrome.ChromeTestUtils.newChromeModel(function(model) { + const rendererProcess = model.rendererProcess; + addSlices(model.rendererMain, slices); + if (backgroundSlices) { + addSlices(model.foregroundWorker1, backgroundSlices); + } }); } @@ -35,21 +40,24 @@ tr.b.unittest.testSuite(function() { function run(slices) { const histograms = new tr.v.HistogramSet(); - const startTime = slices.reduce( - (acc, slice) => (Math.min(acc, slice.start))); - const endTime = slices.reduce((acc, slice) => (Math.max(acc, slice.end))); - const model = createModel(startTime - 1, endTime + 1, slices); + const model = createModel(slices); tr.metrics.v8.gcMetric(histograms, model, {include_sub_events: true}); return histograms; } + function addGarbageCollectionMetrics(metrics, slices, backgroundSlices) { + const histograms = new tr.v.HistogramSet(); + const model = createModel(slices, backgroundSlices); + tr.metrics.v8.addGarbageCollectionMetrics(metrics, histograms, model); + return histograms; + } + test('topEvents', function() { const events = { 'V8.GCCompactor': 'v8-gc-full-mark-compactor', 'V8.GCFinalizeMC': 'v8-gc-latency-mark-compactor', 'V8.GCFinalizeMCReduceMemory': 'v8-gc-memory-mark-compactor', 'V8.GCIncrementalMarking': 'v8-gc-incremental-step', - 'V8.GCIncrementalMarkingFinalize': 'v8-gc-incremental-finalize', 'V8.GCIncrementalMarkingStart': 'v8-gc-incremental-start', 'V8.GCPhantomHandleProcessingCallback': 'v8-gc-phantom-handle-callback', 'V8.GCScavenger': 'v8-gc-scavenger' @@ -147,11 +155,6 @@ tr.b.unittest.testSuite(function() { cpuStart: 150, cpuEnd: 160 }, { - title: 'V8.GCIncrementalMarkingFinalize', - args: {}, start: 200, end: 220, - cpuStart: 200, cpuEnd: 220 - }, - { title: 'V8.GCFinalizeMC', args: {}, start: 250, end: 300, cpuStart: 250, cpuEnd: 300 @@ -160,7 +163,7 @@ tr.b.unittest.testSuite(function() { const histograms = run(slices); const mmu = histograms.getHistogramNamed( 'v8-gc-mark-compactor-mmu-100ms_window'); - assert.closeTo(0.3, mmu.min, 1e-3); + assert.closeTo(0.5, mmu.min, 1e-3); assert.strictEqual(mmu.summaryOptions.get('min'), true); assert.strictEqual(mmu.summaryOptions.get('max'), false); }); @@ -244,5 +247,685 @@ tr.b.unittest.testSuite(function() { 'v8-gc-scavenger-survived-percentage-from-stack'); assert.closeTo(0.375, percentageFromStack.average, 1e-3); }); + + test('cycleAndEvent', function() { + const mainSlices = [ + { + title: 'V8.GC_MC_INCREMENTAL', + cat: 'v8', + args: {'epoch': 0}, + start: 100, cpuStart: 100, end: 110, cpuEnd: 110, + }, + { + title: 'V8.GC_MC_INCREMENTAL', + cat: 'v8', + args: {'epoch': 0}, + start: 200, cpuStart: 200, end: 220, cpuEnd: 220, + }, + { + title: 'V8.GC_MARK_COMPACTOR', + cat: 'v8', + args: {'epoch': 0}, + start: 300, cpuStart: 300, end: 400, cpuEnd: 400, + }, + { + title: 'V8.GC_MC_MARK', + cat: 'v8.gc', + start: 300, cpuStart: 300, end: 340, cpuEnd: 340, + }, + ]; + const backgroundSlices = []; + const expectedAverages = [ + ['v8:gc:cycle:main_thread:full:atomic:mark', 40], + ['v8:gc:cycle:main_thread:full:incremental:mark', 10 + 20], + ['v8:gc:event:main_thread:full:atomic:mark', 40], + ['v8:gc:event:main_thread:full:incremental:mark', (10 + 20) / 2], + ]; + const metrics = expectedAverages.map(pair => pair[0]); + const histograms = addGarbageCollectionMetrics( + metrics, mainSlices, backgroundSlices); + for (const [name, expectedAverage] of expectedAverages) { + const h = histograms.getHistogramNamed(name); + assert.closeTo(expectedAverage, h.average, 1e-3); + } + }); + + test('nested', function() { + const mainSlices = [ + { + title: 'V8.GC_MARK_COMPACTOR', + cat: 'v8', + args: {'epoch': 0}, + start: 100, cpuStart: 100, end: 900, cpuEnd: 900, + }, + { + title: 'V8.GC_MC_MARK', + cat: 'v8.gc', + start: 100, cpuStart: 100, end: 300, cpuEnd: 300, + }, + { + title: 'V8.GC_MC_MARK', + cat: 'v8.gc', + start: 110, cpuStart: 110, end: 120, cpuEnd: 120, + }, + { + title: 'BlinkGC.AtomicPauseMarkTransitiveClosure', + cat: 'blink.gc', + args: {'epoch': 1}, + start: 110, cpuStart: 110, end: 111, cpuEnd: 111, + }, + { + title: 'CppGC.AtomicMark', + cat: 'cpp.gc', + args: {'epoch': 1}, + start: 111, cpuStart: 111, end: 112, cpuEnd: 112, + }, + { + title: 'V8.GC_MC_MARK', + cat: 'v8.gc', + start: 230, cpuStart: 230, end: 250, cpuEnd: 250, + }, + { + title: 'BlinkGC.AtomicPauseMarkTransitiveClosure', + cat: 'blink.gc', + args: {'epoch': 1}, + start: 230, cpuStart: 230, end: 232, cpuEnd: 232, + }, + { + title: 'CppGC.AtomicMark', + cat: 'cpp.gc', + args: {'epoch': 1}, + start: 232, cpuStart: 232, end: 234, cpuEnd: 234, + }, + { + title: 'V8.GC_MC_MARK', + cat: 'v8.gc', + start: 400, cpuStart: 400, end: 500, cpuEnd: 500, + }, + { + title: 'BlinkGC.AtomicPauseMarkTransitiveClosure', + cat: 'blink.gc', + args: {'epoch': 1}, + start: 400, cpuStart: 400, end: 403, cpuEnd: 403, + }, + { + title: 'CppGC.AtomicMark', + cat: 'cpp.gc', + args: {'epoch': 1}, + start: 403, cpuStart: 403, end: 406, cpuEnd: 406, + }, + ]; + const backgroundSlices = []; + const expectedAverages = [ + ['v8:gc:cycle:main_thread:full:atomic:mark', 200 + 100], + ['v8:gc:event:main_thread:full:atomic:mark', (200 + 100) / 2], + ['v8:gc:cycle:main_thread:full:atomic:mark:cpp', 1 + 2 + 3 + 1 + 2 + 3], + ['v8:gc:event:main_thread:full:atomic:mark:cpp', + (1 + 2 + 3 + 1 + 2 + 3) / 6], + ]; + const metrics = expectedAverages.map(pair => pair[0]); + const histograms = addGarbageCollectionMetrics( + metrics, mainSlices, backgroundSlices); + for (const [name, expectedAverage] of expectedAverages) { + const h = histograms.getHistogramNamed(name); + assert.closeTo(expectedAverage, h.average, 1e-3); + } + }); + + test('phases', function() { + const mainSlices = [ + { + title: 'V8.GC_MARK_COMPACTOR', + cat: 'v8', + args: {'epoch': 0}, + start: 100, cpuStart: 100, end: 900, cpuEnd: 900, + }, + { + title: 'V8.GC_MC_MARK', + cat: 'v8.gc', + start: 100, cpuStart: 100, end: 110, cpuEnd: 110, + }, + { + title: 'V8.GC_MC_CLEAR', + cat: 'v8.gc', + start: 200, cpuStart: 200, end: 220, cpuEnd: 220, + }, + { + title: 'V8.GC_MC_EVACUATE', + cat: 'v8.gc', + start: 300, cpuStart: 300, end: 330, cpuEnd: 330, + }, + { + title: 'V8.GC_MC_SWEEP', + cat: 'v8.gc', + start: 400, cpuStart: 400, end: 440, cpuEnd: 440, + }, + ]; + const backgroundSlices = []; + const expectedAverages = [ + ['v8:gc:cycle:main_thread:full:atomic:mark', 10], + ['v8:gc:cycle:main_thread:full:atomic:weak', 20], + ['v8:gc:cycle:main_thread:full:atomic:compact', 30], + ['v8:gc:cycle:main_thread:full:atomic:sweep', 40], + ]; + const metrics = expectedAverages.map(pair => pair[0]); + const histograms = addGarbageCollectionMetrics( + metrics, mainSlices, backgroundSlices); + for (const [name, expectedAverage] of expectedAverages) { + const h = histograms.getHistogramNamed(name); + assert.closeTo(expectedAverage, h.average, 1e-3); + } + }); + + test('minorPhases', function() { + const mainSlices = [ + { + title: 'V8.GC_MINOR_MARK_COMPACTOR', + cat: 'v8', + args: {'epoch': 0}, + start: 100, cpuStart: 100, end: 900, cpuEnd: 900, + }, + { + title: 'V8.GC_MINOR_MC_MARK', + cat: 'v8.gc', + start: 100, cpuStart: 100, end: 110, cpuEnd: 110, + }, + { + title: 'V8.GC_MINOR_MC_CLEAR', + cat: 'v8.gc', + start: 200, cpuStart: 200, end: 220, cpuEnd: 220, + }, + { + title: 'V8.GC_MINOR_MC_EVACUATE', + cat: 'v8.gc', + start: 300, cpuStart: 300, end: 330, cpuEnd: 330, + }, + { + title: 'V8.GC_MINOR_MC_SWEEP', + cat: 'v8.gc', + start: 400, cpuStart: 400, end: 440, cpuEnd: 440, + }, + ]; + const backgroundSlices = []; + const expectedAverages = [ + ['v8:gc:cycle:main_thread:young:atomic:mark', 10], + ['v8:gc:cycle:main_thread:young:atomic:weak', 20], + ['v8:gc:cycle:main_thread:young:atomic:compact', 30], + ['v8:gc:cycle:main_thread:young:atomic:sweep', 40], + ]; + const metrics = expectedAverages.map(pair => pair[0]); + const histograms = addGarbageCollectionMetrics( + metrics, mainSlices, backgroundSlices); + for (const [name, expectedAverage] of expectedAverages) { + const h = histograms.getHistogramNamed(name); + assert.closeTo(expectedAverage, h.average, 1e-3); + } + }); + + test('fullAndYoung', function() { + const mainSlices = [ + { + title: 'V8.GC_MARK_COMPACTOR', + cat: 'v8', + args: {'epoch': 0}, + start: 100, cpuStart: 100, end: 110, cpuEnd: 110, + }, + { + title: 'V8.GC_SCAVENGER', + cat: 'v8', + args: {'epoch': 1}, + start: 200, cpuStart: 200, end: 220, cpuEnd: 220, + }, + { + title: 'V8.GC_SCAVENGER', + cat: 'v8', + args: {'epoch': 2}, + start: 300, cpuStart: 300, end: 330, cpuEnd: 330, + }, + { + title: 'V8.GC_MARK_COMPACTOR', + cat: 'v8', + args: {'epoch': 4}, + start: 400, cpuStart: 400, end: 440, cpuEnd: 440, + }, + { + title: 'V8.GC_MINOR_MARK_COMPACTOR', + cat: 'v8', + args: {'epoch': 5}, + start: 500, cpuStart: 500, end: 550, cpuEnd: 550, + }, + ]; + const backgroundSlices = []; + const expectedAverages = [ + ['v8:gc:cycle:main_thread:full:atomic', (10 + 40) / 2], + ['v8:gc:cycle:main_thread:full', (10 + 40) / 2], + ['v8:gc:cycle:full', (10 + 40) / 2], + ['v8:gc:cycle:main_thread:young:atomic', (20 + 30 + 50) / 3], + ['v8:gc:cycle:main_thread:young', (20 + 30 + 50) / 3], + ['v8:gc:cycle:young', (20 + 30 + 50) / 3], + ['v8:gc:cycle:main_thread', (10 + 20 + 30 + 40 + 50) / 5], + ['v8:gc:cycle', (10 + 20 + 30 + 40 + 50) / 5], + ]; + const metrics = expectedAverages.map(pair => pair[0]); + const histograms = addGarbageCollectionMetrics( + metrics, mainSlices, backgroundSlices); + for (const [name, expectedAverage] of expectedAverages) { + const h = histograms.getHistogramNamed(name); + assert.closeTo(expectedAverage, h.average, 1e-3); + } + }); + + test('cpp', function() { + const mainSlices = [ + { + title: 'V8.GC_MC_INCREMENTAL', + cat: 'v8', + args: {'epoch': 0}, + start: 100, cpuStart: 100, end: 200, cpuEnd: 200, + }, + { + title: 'BlinkGC.IncrementalMarkingStep', + cat: 'blink.gc', + args: {'epoch': 1}, + start: 100, cpuStart: 100, end: 110, cpuEnd: 110, + }, + { + title: 'CppGC.IncrementalMark', + cat: 'cpp.gc', + args: {'epoch': 1}, + start: 110, cpuStart: 110, end: 120, cpuEnd: 120, + }, + { + title: 'V8.GC_MARK_COMPACTOR', + cat: 'v8', + args: {'epoch': 0}, + start: 200, cpuStart: 200, end: 300, cpuEnd: 300, + }, + { + title: 'BlinkGC.AtomicPauseMarkTransitiveClosure', + cat: 'blink.gc', + args: {'epoch': 1}, + start: 200, cpuStart: 200, end: 220, cpuEnd: 220, + }, + { + title: 'CppGC.AtomicMark', + cat: 'cpp.gc', + args: {'epoch': 1}, + start: 220, cpuStart: 220, end: 240, cpuEnd: 240, + }, + ]; + const backgroundSlices = [ + { + title: 'BlinkGC.ConcurrentMarkingStep', + cat: 'blink.gc', + args: {'epoch': 1}, + start: 100, cpuStart: 100, end: 130, cpuEnd: 130, + }, + { + title: 'CppGC.ConcurrentMark', + cat: 'cpp.gc', + args: {'epoch': 1}, + start: 130, cpuStart: 130, end: 160, cpuEnd: 160, + }, + { + title: 'BlinkGC.ConcurrentMarkingStep', + cat: 'blink.gc', + args: {'epoch': 1}, + start: 200, cpuStart: 200, end: 240, cpuEnd: 240, + }, + { + title: 'CppGC.ConcurrentMark', + cat: 'cpp.gc', + args: {'epoch': 1}, + start: 240, cpuStart: 240, end: 280, cpuEnd: 280, + }, + ]; + const expectedAverages = [ + ['v8:gc:cycle:main_thread:full:atomic:mark:cpp', 20 + 20], + ['v8:gc:cycle:main_thread:full:incremental:mark:cpp', 10 + 10], + ['v8:gc:cycle:full:atomic:mark:cpp', 20 + 40 + 20 + 40], + ['v8:gc:cycle:full:incremental:mark:cpp', 10 + 30 + 10 + 30], + ]; + const metrics = expectedAverages.map(pair => pair[0]); + const histograms = addGarbageCollectionMetrics( + metrics, mainSlices, backgroundSlices); + for (const [name, expectedAverage] of expectedAverages) { + const h = histograms.getHistogramNamed(name); + assert.closeTo(expectedAverage, h.average, 1e-3); + } + }); + + test('atomicAndIncremental', function() { + const mainSlices = [ + { + title: 'V8.GC_MC_COMPLETE_SWEEPING', + cat: 'v8', + args: {'epoch': 0}, + start: 80, cpuStart: 80, end: 100, cpuEnd: 100, + }, + { + title: 'V8.GC_MC_INCREMENTAL', + cat: 'v8', + args: {'epoch': 1}, + start: 100, cpuStart: 100, end: 110, cpuEnd: 110, + }, + { + title: 'V8.GC_MARK_COMPACTOR', + cat: 'v8', + args: {'epoch': 1}, + start: 200, cpuStart: 200, end: 300, cpuEnd: 300, + }, + { + title: 'V8.GC_MC_MARK', + cat: 'v8', + start: 200, cpuStart: 200, end: 220, cpuEnd: 220, + }, + ]; + const backgroundSlices = [ + { + title: 'V8.GC_MC_BACKGROUND_MARKING', + cat: 'v8', + args: {'epoch': 1}, + start: 100, cpuStart: 100, end: 130, cpuEnd: 130, + }, + { + title: 'V8.GC_MC_BACKGROUND_MARKING', + cat: 'v8', + args: {'epoch': 1}, + start: 200, cpuStart: 200, end: 240, cpuEnd: 240, + }, + ]; + const expectedAverages = [ + ['v8:gc:cycle:main_thread:full:incremental:sweep', 20], + ['v8:gc:cycle:main_thread:full:atomic:mark', 20], + ['v8:gc:cycle:main_thread:full:incremental:mark', 10], + ['v8:gc:cycle:background_threads:full:atomic:mark', 40], + ['v8:gc:cycle:background_threads:full:incremental:mark', 30], + ['v8:gc:cycle:full:atomic:mark', 20 + 40], + ['v8:gc:cycle:full:incremental:mark', 10 + 30], + ]; + const metrics = expectedAverages.map(pair => pair[0]); + const histograms = addGarbageCollectionMetrics( + metrics, mainSlices, backgroundSlices); + for (const [name, expectedAverage] of expectedAverages) { + const h = histograms.getHistogramNamed(name); + assert.closeTo(expectedAverage, h.average, 1e-3); + } + }); + + test('multipleCycles', function() { + const mainSlices = [ + { + title: 'V8.GC_MC_INCREMENTAL', + cat: 'v8', + args: {'epoch': 0}, + start: 100, cpuStart: 100, end: 110, cpuEnd: 110, + }, + { + title: 'BlinkGC.IncrementalMarkingStep', + cat: 'blink.gc', + args: {'epoch': 1}, + start: 200, cpuStart: 200, end: 220, cpuEnd: 220, + }, + { + title: 'CppGC.IncrementalMark', + cat: 'cpp.gc', + args: {'epoch': 1}, + start: 220, cpuStart: 220, end: 240, cpuEnd: 240, + }, + { + title: 'V8.GC_MARK_COMPACTOR', + cat: 'v8', + args: {'epoch': 0}, + start: 300, cpuStart: 300, end: 400, cpuEnd: 400, + }, + { + title: 'BlinkGC.AtomicPauseMarkTransitiveClosure', + cat: 'blink.gc', + args: {'epoch': 1}, + start: 300, cpuStart: 300, end: 330, cpuEnd: 330, + }, + { + title: 'CppGC.AtomicMark', + cat: 'cpp.gc', + args: {'epoch': 1}, + start: 330, cpuStart: 330, end: 360, cpuEnd: 360, + }, + { + title: 'V8.GC_MC_INCREMENTAL', + cat: 'v8', + args: {'epoch': 1}, + start: 600, cpuStart: 600, end: 640, cpuEnd: 640, + }, + { + title: 'V8.GC_MARK_COMPACTOR', + cat: 'v8', + args: {'epoch': 1}, + start: 700, cpuStart: 700, end: 900, cpuEnd: 900, + }, + { + title: 'BlinkGC.AtomicPauseMarkTransitiveClosure', + cat: 'blink.gc', + args: {'epoch': 2}, + start: 700, cpuStart: 700, end: 750, cpuEnd: 750, + }, + { + title: 'CppGC.AtomicMark', + cat: 'cpp.gc', + args: {'epoch': 2}, + start: 750, cpuStart: 750, end: 800, cpuEnd: 800, + }, + ]; + const expectedAverages = [ + ['v8:gc:cycle:full', ((10 + 20 + 20 + 100) + (40 + 200)) / 2], + ['v8:gc:cycle:full:cpp', ((20 + 30 + 20 + 30) + (50 + 50)) / 2], + ]; + const metrics = expectedAverages.map(pair => pair[0]); + const histograms = addGarbageCollectionMetrics(metrics, mainSlices, []); + for (const [name, expectedAverage] of expectedAverages) { + const h = histograms.getHistogramNamed(name); + assert.closeTo(expectedAverage, h.average, 1e-3); + } + }); + + test('standaloneCppGC', function() { + const mainSlices = [ + { + title: 'BlinkGC.IncrementalMarkingStep', + cat: 'blink.gc', + args: {'epoch': 1}, + start: 200, cpuStart: 200, end: 220, cpuEnd: 220, + }, + { + title: 'CppGC.IncrementalMark', + cat: 'cpp.gc', + args: {'epoch': 1}, + start: 220, cpuStart: 220, end: 240, cpuEnd: 240, + }, + { + title: 'BlinkGC.AtomicPauseMarkTransitiveClosure', + cat: 'blink.gc', + args: {'epoch': 1}, + start: 300, cpuStart: 300, end: 330, cpuEnd: 330, + }, + { + title: 'CppGC.AtomicMark', + cat: 'cpp.gc', + args: {'epoch': 1}, + start: 330, cpuStart: 330, end: 360, cpuEnd: 360, + }, + { + title: 'BlinkGC.AtomicPauseMarkTransitiveClosure', + cat: 'blink.gc', + args: {'epoch': 2}, + start: 700, cpuStart: 700, end: 750, cpuEnd: 750, + }, + { + title: 'CppGC.AtomicMark', + cat: 'cpp.gc', + args: {'epoch': 2}, + start: 750, cpuStart: 750, end: 800, cpuEnd: 800, + }, + ]; + const expectedAverages = [ + ['v8:gc:cycle:full', ((20 + 30 + 20 + 30) + (50 + 50)) / 2], + ['v8:gc:cycle:full:cpp', ((20 + 30 + 20 + 30) + (50 + 50)) / 2], + ]; + const metrics = expectedAverages.map(pair => pair[0]); + const histograms = addGarbageCollectionMetrics(metrics, mainSlices, []); + for (const [name, expectedAverage] of expectedAverages) { + const h = histograms.getHistogramNamed(name); + assert.closeTo(expectedAverage, h.average, 1e-3); + } + }); + + test('ambigousEpoch', function() { + const mainSlices = [ + { + title: 'V8.GC_MARK_COMPACTOR', + cat: 'v8', + args: {'epoch': 0}, + start: 300, cpuStart: 300, end: 400, cpuEnd: 400, + }, + { + title: 'BlinkGC.AtomicPauseMarkTransitiveClosure', + cat: 'blink.gc', + args: {'epoch': 1}, + start: 300, cpuStart: 300, end: 330, cpuEnd: 330, + }, + { + title: 'V8.GC_MC_INCREMENTAL', + cat: 'v8', + args: {'epoch': 3}, + start: 600, cpuStart: 600, end: 640, cpuEnd: 640, + }, + { + title: 'BlinkGC.CompleteSweep', + cat: 'blink.gc', + args: {'epoch': 1}, + start: 600, cpuStart: 600, end: 610, cpuEnd: 610, + }, + { + title: 'CppGC.IncrementalMark', + cat: 'cpp.gc', + args: {'epoch': 2}, + start: 610, cpuStart: 610, end: 640, cpuEnd: 640, + }, + ]; + const expectedAverages = [ + ['v8:gc:cycle:full', ((100) + (40)) / 2], + ['v8:gc:cycle:full:cpp', ((30 + 10) + (30)) / 2], + ]; + const metrics = expectedAverages.map(pair => pair[0]); + const histograms = addGarbageCollectionMetrics(metrics, mainSlices, []); + for (const [name, expectedAverage] of expectedAverages) { + const h = histograms.getHistogramNamed(name); + assert.closeTo(expectedAverage, h.average, 1e-3); + } + }); + + test('sweepingInEvacuation', function() { + const mainSlices = [ + { + title: 'V8.GC_MARK_COMPACTOR', + cat: 'v8', + args: {'epoch': 0}, + start: 100, cpuStart: 100, end: 200, cpuEnd: 200, + }, + { + title: 'V8.GC_MC_EVACUATE', + cat: 'v8', + args: {'epoch': 0}, + start: 110, cpuStart: 110, end: 150, cpuEnd: 150, + }, + { + title: 'V8.GC_MC_SWEEP', + cat: 'v8', + args: {'epoch': 0}, + start: 120, cpuStart: 120, end: 140, cpuEnd: 140, + }, + { + title: 'V8.GC_MC_SWEEP', + cat: 'v8', + args: {'epoch': 0}, + start: 160, cpuStart: 160, end: 190, cpuEnd: 190, + }, + { + title: 'V8.GC_MINOR_MARK_COMPACTOR', + cat: 'v8', + args: {'epoch': 1}, + start: 200, cpuStart: 200, end: 300, cpuEnd: 300, + }, + { + title: 'V8.GC_MINOR_MC_EVACUATE', + cat: 'v8', + args: {'epoch': 1}, + start: 210, cpuStart: 210, end: 250, cpuEnd: 250, + }, + { + title: 'V8.GC_MINOR_MC_SWEEP', + cat: 'v8', + args: {'epoch': 1}, + start: 220, cpuStart: 220, end: 240, cpuEnd: 240, + }, + { + title: 'V8.GC_MINOR_MC_SWEEP', + cat: 'v8', + args: {'epoch': 1}, + start: 260, cpuStart: 260, end: 290, cpuEnd: 290, + }, + ]; + const backgroundSlices = [ + { + title: 'V8.GC_MC_BACKGROUND_EVACUATE_COPY', + cat: 'v8', + args: {'epoch': 0}, + start: 110, cpuStart: 110, end: 150, cpuEnd: 150, + }, + { + title: 'V8.GC_MC_BACKGROUND_SWEEPING', + cat: 'v8', + args: {'epoch': 0}, + start: 120, cpuStart: 120, end: 140, cpuEnd: 140, + }, + { + title: 'V8.GC_MC_BACKGROUND_SWEEPING', + cat: 'v8', + args: {'epoch': 0}, + start: 160, cpuStart: 160, end: 190, cpuEnd: 190, + }, + { + title: 'V8.GC_MINOR_MC_BACKGROUND_EVACUATE_COPY', + cat: 'v8', + args: {'epoch': 1}, + start: 210, cpuStart: 210, end: 250, cpuEnd: 250, + }, + { + title: 'V8.GC_MINOR_MC_BACKGROUND_SWEEPING', + cat: 'v8', + args: {'epoch': 1}, + start: 220, cpuStart: 220, end: 240, cpuEnd: 240, + }, + { + title: 'V8.GC_MINOR_MC_BACKGROUND_SWEEPING', + cat: 'v8', + args: {'epoch': 1}, + start: 260, cpuStart: 260, end: 290, cpuEnd: 290, + }, + ]; + const expectedAverages = [ + ['v8:gc:cycle:full:compact', 40 + 40], + ['v8:gc:cycle:full:sweep', 30 + 30], + ['v8:gc:cycle:young:compact', 40 + 40], + ['v8:gc:cycle:young:sweep', 30 + 30], + ]; + const metrics = expectedAverages.map(pair => pair[0]); + const histograms = addGarbageCollectionMetrics( + metrics, mainSlices, backgroundSlices); + for (const [name, expectedAverage] of expectedAverages) { + const h = histograms.getHistogramNamed(name); + assert.closeTo(expectedAverage, h.average, 1e-3); + } + }); }); </script> 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 cb5e9fe2f3a..1c06d3a590a 100644 --- a/chromium/third_party/catapult/tracing/tracing/metrics/v8/utils.html +++ b/chromium/third_party/catapult/tracing/tracing/metrics/v8/utils.html @@ -41,7 +41,6 @@ tr.exportTo('tr.metrics.v8.utils', function() { 'V8.GCFinalizeMC': 'v8-gc-latency-mark-compactor', 'V8.GCFinalizeMCReduceMemory': 'v8-gc-memory-mark-compactor', 'V8.GCIncrementalMarking': 'v8-gc-incremental-step', - 'V8.GCIncrementalMarkingFinalize': 'v8-gc-incremental-finalize', 'V8.GCIncrementalMarkingStart': 'v8-gc-incremental-start', 'V8.GCPhantomHandleProcessingCallback': 'v8-gc-phantom-handle-callback', 'V8.GCScavenger': 'v8-gc-scavenger' @@ -52,7 +51,6 @@ tr.exportTo('tr.metrics.v8.utils', function() { 'V8.GCFinalizeMC', 'V8.GCFinalizeMCReduceMemory', 'V8.GCIncrementalMarking', - 'V8.GCIncrementalMarkingFinalize', 'V8.GCIncrementalMarkingStart', 'V8.GCPhantomHandleProcessingCallback' ]); diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/v8/v8_metrics.html b/chromium/third_party/catapult/tracing/tracing/metrics/v8/v8_metrics.html index 507d23e6119..524814d55af 100644 --- a/chromium/third_party/catapult/tracing/tracing/metrics/v8/v8_metrics.html +++ b/chromium/third_party/catapult/tracing/tracing/metrics/v8/v8_metrics.html @@ -9,6 +9,7 @@ found in the LICENSE file. <link rel="import" href="/tracing/metrics/system_health/memory_metric.html"> <link rel="import" href="/tracing/metrics/v8/execution_metric.html"> <link rel="import" href="/tracing/metrics/v8/gc_metric.html"> +<link rel="import" href="/tracing/metrics/v8/runtime_stats_metric.html"> <script> 'use strict'; @@ -17,6 +18,7 @@ tr.exportTo('tr.metrics.v8', function() { function v8AndMemoryMetrics(histograms, model) { tr.metrics.v8.executionMetric(histograms, model); tr.metrics.v8.gcMetric(histograms, model); + tr.metrics.v8.runtimeStatsTotalMetric(histograms, model); tr.metrics.sh.memoryMetric(histograms, model, {rangeOfInterest: tr.metrics.v8.utils.rangeForMemoryDumps(model)}); } diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/v8/wasm_metric.html b/chromium/third_party/catapult/tracing/tracing/metrics/v8/wasm_metric.html index b9e500c50fd..6e12457e664 100644 --- a/chromium/third_party/catapult/tracing/tracing/metrics/v8/wasm_metric.html +++ b/chromium/third_party/catapult/tracing/tracing/metrics/v8/wasm_metric.html @@ -38,6 +38,52 @@ tr.exportTo('tr.metrics.v8', function() { histograms.addHistogram(wasmSyncInstantiationTimeWall); } + function computeSyncCompileTimeMetric(histograms, wasmEvents) { + if (!wasmEvents.hasOwnProperty('wasm.SyncCompile')) return; + + const wasmSyncCompileTimeCPU = new tr.v.Histogram( + 'v8:wasm:sync_compile:cpu_time', + tr.b.Unit.byName.timeDurationInMs_smallerIsBetter); + wasmSyncCompileTimeCPU.description = + 'cpu time spent compiling a WebAssembly module synchronously'; + const wasmSyncCompileTimeWall = new tr.v.Histogram( + 'v8:wasm:sync_compile:wall_time', + tr.b.Unit.byName.timeDurationInMs_smallerIsBetter); + wasmSyncCompileTimeWall.description = + 'wall time spent compiling a WebAssembly module synchronously'; + + for (const e of wasmEvents['wasm.SyncCompile']) { + wasmSyncCompileTimeCPU.addSample(e.cpuDuration); + wasmSyncCompileTimeWall.addSample(e.duration); + } + + histograms.addHistogram(wasmSyncCompileTimeCPU); + histograms.addHistogram(wasmSyncCompileTimeWall); + } + + function computeDeserializeTimeMetric(histograms, wasmEvents) { + if (!wasmEvents.hasOwnProperty('wasm.Deserialize')) return; + + const wasmDeserializeTimeCPU = new tr.v.Histogram( + 'v8:wasm:deserialize:cpu_time', + tr.b.Unit.byName.timeDurationInMs_smallerIsBetter); + wasmDeserializeTimeCPU.description = + 'cpu time spent deserializing a WebAssembly module'; + const wasmDeserializeTimeWall = new tr.v.Histogram( + 'v8:wasm:deserialize:wall_time', + tr.b.Unit.byName.timeDurationInMs_smallerIsBetter); + wasmDeserializeTimeWall.description = + 'wall time spent deserializing a WebAssembly module'; + + for (const e of wasmEvents['wasm.Deserialize']) { + wasmDeserializeTimeCPU.addSample(e.cpuDuration); + wasmDeserializeTimeWall.addSample(e.duration); + } + + histograms.addHistogram(wasmDeserializeTimeCPU); + histograms.addHistogram(wasmDeserializeTimeWall); + } + function computeStreamingBaselineCompileTimeMetric(histograms, wasmEvents) { // With streaming compilation, baseline compilation happens from when the // first bytes get received until when baseline compilation finishes. If @@ -51,12 +97,14 @@ tr.exportTo('tr.metrics.v8', function() { 'v8:wasm:streaming_baseline_compilation:wall_time', tr.b.Unit.byName.timeDurationInMs_smallerIsBetter); - const compilationStart = - wasmEvents['wasm.StartStreamingCompilation'][0].start; - - const compilationEnd = wasmEvents['wasm.BaselineFinished'][0].end; - - histogram.addSample(compilationEnd - compilationStart); + for (const endEvent of wasmEvents['wasm.BaselineFinished']) { + const compilationEnd = endEvent.end; + const startEvent = wasmEvents['wasm.StartStreamingCompilation'].find( + e => e.args.id === endEvent.args.id); + if (!startEvent) continue; + const compilationStart = startEvent.start; + histogram.addSample(compilationEnd - compilationStart); + } histograms.addHistogram(histogram); } @@ -70,10 +118,14 @@ tr.exportTo('tr.metrics.v8', function() { 'v8:wasm:compilation_tierup:wall_time', tr.b.Unit.byName.timeDurationInMs_smallerIsBetter); - const tierupStart = wasmEvents['wasm.BaselineFinished'][0].start; - const tierupEnd = wasmEvents['wasm.TopTierFinished'][0].end; - - histogram.addSample(tierupEnd - tierupStart); + for (const endEvent of wasmEvents['wasm.TopTierFinished']) { + const tierupEnd = endEvent.end; + const startEvent = wasmEvents['wasm.BaselineFinished'].find( + e => e.args.id === endEvent.args.id); + if (!startEvent) continue; + const tierupStart = startEvent.start; + histogram.addSample(tierupEnd - tierupStart); + } histograms.addHistogram(histogram); } @@ -90,6 +142,8 @@ tr.exportTo('tr.metrics.v8', function() { const wasmEvents = collectWasmEvents(model); computeSyncInstantiationTimeMetric(histograms, wasmEvents); + computeSyncCompileTimeMetric(histograms, wasmEvents); + computeDeserializeTimeMetric(histograms, wasmEvents); computeStreamingBaselineCompileTimeMetric(histograms, wasmEvents); computeCompilationTierupWallTimeMetric(histograms, wasmEvents); } diff --git a/chromium/third_party/catapult/tracing/tracing/metrics/v8/wasm_metric_test.html b/chromium/third_party/catapult/tracing/tracing/metrics/v8/wasm_metric_test.html index 0681b6ddf3b..573c02d4ff3 100644 --- a/chromium/third_party/catapult/tracing/tracing/metrics/v8/wasm_metric_test.html +++ b/chromium/third_party/catapult/tracing/tracing/metrics/v8/wasm_metric_test.html @@ -67,14 +67,70 @@ tr.b.unittest.testSuite(function() { assert.strictEqual(wallValue.running.max, 30); }); + test('testSyncCompileMetric', function() { + const slices = [ + { + title: 'wasm.SyncCompile', args: {}, start: 10, end: 20, + cpuStart: 100, cpuEnd: 200 + }, + { + title: 'wasm.SyncCompile', args: {}, start: 30, end: 60, + cpuStart: 300, cpuEnd: 600 + } + ]; + const histograms = runMetrics(slices); + + const cpuValue = + histograms.getHistogramNamed('v8:wasm:sync_compile:cpu_time'); + assert.strictEqual(cpuValue.running.sum, 400); + assert.strictEqual(cpuValue.numValues, 2); + assert.strictEqual(cpuValue.average, 200); + assert.strictEqual(cpuValue.running.max, 300); + + const wallValue = + histograms.getHistogramNamed('v8:wasm:sync_compile:wall_time'); + assert.strictEqual(wallValue.running.sum, 40); + assert.strictEqual(wallValue.numValues, 2); + assert.strictEqual(wallValue.average, 20); + assert.strictEqual(wallValue.running.max, 30); + }); + + test('testDeserializeMetric', function() { + const slices = [ + { + title: 'wasm.Deserialize', args: {}, start: 10, end: 20, + cpuStart: 100, cpuEnd: 200 + }, + { + title: 'wasm.Deserialize', args: {}, start: 30, end: 60, + cpuStart: 300, cpuEnd: 600 + } + ]; + const histograms = runMetrics(slices); + + const cpuValue = + histograms.getHistogramNamed('v8:wasm:deserialize:cpu_time'); + assert.strictEqual(cpuValue.running.sum, 400); + assert.strictEqual(cpuValue.numValues, 2); + assert.strictEqual(cpuValue.average, 200); + assert.strictEqual(cpuValue.running.max, 300); + + const wallValue = + histograms.getHistogramNamed('v8:wasm:deserialize:wall_time'); + assert.strictEqual(wallValue.running.sum, 40); + assert.strictEqual(wallValue.numValues, 2); + assert.strictEqual(wallValue.average, 20); + assert.strictEqual(wallValue.running.max, 30); + }); + test('testStreamingBaselineCompileTime', function() { const slices = [ { - title: 'wasm.StartStreamingCompilation', args: {}, start: 10, end: 20, - cpuStart: 10, cpuEnd: 20 + title: 'wasm.StartStreamingCompilation', args: {id: 0}, start: 10, + end: 20, cpuStart: 10, cpuEnd: 20 }, { - title: 'wasm.BaselineFinished', args: {}, start: 100, end: 110, + title: 'wasm.BaselineFinished', args: {id: 0}, start: 100, end: 110, cpuStart: 100, cpuEnd: 110 }, ]; @@ -87,10 +143,38 @@ tr.b.unittest.testSuite(function() { assert.strictEqual(compileTime.running.max, 100); }); + test('testStreamingBaselineCompileTimeTwoCompilations', function() { + const slices = [ + { + title: 'wasm.StartStreamingCompilation', args: {id: 0}, start: 10, + end: 20, cpuStart: 10, cpuEnd: 20 + }, + { + title: 'wasm.StartStreamingCompilation', args: {id: 1}, start: 110, + end: 120, cpuStart: 110, cpuEnd: 120 + }, + { + title: 'wasm.BaselineFinished', args: {id: 1}, start: 200, end: 210, + cpuStart: 200, cpuEnd: 210 + }, + { + title: 'wasm.BaselineFinished', args: {id: 0}, start: 100, end: 110, + cpuStart: 100, cpuEnd: 110 + }, + ]; + const histograms = runMetrics(slices); + + const compileTime = histograms.getHistogramNamed( + 'v8:wasm:streaming_baseline_compilation:wall_time'); + assert.strictEqual(compileTime.numValues, 2); + assert.strictEqual(compileTime.average, 100); + assert.strictEqual(compileTime.running.max, 100); + }); + test('testStreamingBaselineCompileTimeNoStartEvent', function() { const slices = [ { - title: 'wasm.BaselineFinished', args: {}, start: 100, end: 110, + title: 'wasm.BaselineFinished', args: {id: 0}, start: 100, end: 110, cpuStart: 100, cpuEnd: 110 }, ]; @@ -104,8 +188,8 @@ tr.b.unittest.testSuite(function() { test('testStreamingBaselineCompileTimeNoEndEvent', function() { const slices = [ { - title: 'wasm.StartStreamingCompilation', args: {}, start: 100, end: 110, - cpuStart: 100, cpuEnd: 110 + title: 'wasm.StartStreamingCompilation', args: {id: 0}, start: 100, + end: 110, cpuStart: 100, cpuEnd: 110 }, ]; const histograms = runMetrics(slices); @@ -118,11 +202,11 @@ tr.b.unittest.testSuite(function() { test('testTierupWallTime', function() { const slices = [ { - title: 'wasm.BaselineFinished', args: {}, start: 100, end: 110, + title: 'wasm.BaselineFinished', args: {id: 0}, start: 100, end: 110, cpuStart: 100, cpuEnd: 110 }, { - title: 'wasm.TopTierFinished', args: {}, start: 200, end: 210, + title: 'wasm.TopTierFinished', args: {id: 0}, start: 200, end: 210, cpuStart: 200, cpuEnd: 210 }, ]; @@ -136,10 +220,39 @@ tr.b.unittest.testSuite(function() { assert.strictEqual(tierupTime.running.max, 110); }); + test('testTierupWallTimeTwoTierups', function() { + const slices = [ + { + title: 'wasm.BaselineFinished', args: {id: 0}, start: 100, end: 110, + cpuStart: 100, cpuEnd: 110 + }, + { + title: 'wasm.BaselineFinished', args: {id: 1}, start: 200, end: 210, + cpuStart: 200, cpuEnd: 210 + }, + { + title: 'wasm.TopTierFinished', args: {id: 1}, start: 300, end: 310, + cpuStart: 200, cpuEnd: 210 + }, + { + title: 'wasm.TopTierFinished', args: {id: 0}, start: 200, end: 210, + cpuStart: 200, cpuEnd: 210 + }, + ]; + + const histograms = runMetrics(slices); + + const tierupTime = histograms.getHistogramNamed( + 'v8:wasm:compilation_tierup:wall_time'); + assert.strictEqual(tierupTime.numValues, 2); + assert.strictEqual(tierupTime.average, 110); + assert.strictEqual(tierupTime.running.max, 110); + }); + test('testTierupNoStartEvent', function() { const slices = [ { - title: 'wasm.TopTierFinished', args: {}, start: 200, end: 210, + title: 'wasm.TopTierFinished', args: {id: 0}, start: 200, end: 210, cpuStart: 200, cpuEnd: 210 }, ]; @@ -154,7 +267,7 @@ tr.b.unittest.testSuite(function() { test('testTierupNoEndEvent', function() { const slices = [ { - title: 'wasm.BaselineFinished', args: {}, start: 100, end: 110, + title: 'wasm.BaselineFinished', args: {id: 0}, start: 100, end: 110, cpuStart: 100, cpuEnd: 110 }, ]; |