Commit 8a9326ce authored by Stephen Chenney's avatar Stephen Chenney Committed by Commit Bot

Add UKM for ScrollingCoordinator.

ScrollingCoordinator accounts for some of the time in MainFrame
update time. Record how much.

As a side effect, move the macro for local frame UKM scoped recording
into the aggregator class so that it can be shared across classes.
This is to avoid relocating the UMA metric recording site in a way that
would skew the data toward zero, a lot.

R=pdr@chromium.org,rkaplow@chromium.org
BUG=910635

Change-Id: Id527efb7f30cc69de8ee45e27c616621059ef544
Reviewed-on: https://chromium-review.googlesource.com/c/1356888
Commit-Queue: Stephen Chenney <schenney@chromium.org>
Reviewed-by: default avatarPhilip Rogers <pdr@chromium.org>
Reviewed-by: default avatarRobert Kaplow <rkaplow@chromium.org>
Cr-Commit-Position: refs/heads/master@{#612880}
parent 3528b550
...@@ -18,8 +18,8 @@ class CustomCountHistogram; ...@@ -18,8 +18,8 @@ class CustomCountHistogram;
// This class aggregaties and records time based UKM and UMA metrics // This class aggregaties and records time based UKM and UMA metrics
// for LocalFrameView. The simplest way to use it is via the // for LocalFrameView. The simplest way to use it is via the
// SCOPED_UMA_AND_UKM_HIERARCHICAL_TIMER macro in LocalFrameView combined // SCOPED_UMA_AND_UKM_TIMER macro combined with
// with LocalFrameView::RecordEndOfFrameMetrics. // LocalFrameView::RecordEndOfFrameMetrics.
// //
// It takes the following constructor parameters: // It takes the following constructor parameters:
// - source_id: UKM Source ID associated with the events. // - source_id: UKM Source ID associated with the events.
...@@ -42,7 +42,7 @@ class CustomCountHistogram; ...@@ -42,7 +42,7 @@ class CustomCountHistogram;
// //
// When the primary timed execution completes, this aggregator stores the // When the primary timed execution completes, this aggregator stores the
// primary time and computes metrics that depend on it. The results are // primary time and computes metrics that depend on it. The results are
// aggregated. UMA metrics are updated at this time. A UKM event is // aggregated. UMA metrics are updated at this time. A UKM event is
// generated in one of two situations: // generated in one of two situations:
// - If a sample is added that lies in the next event frequency interval (this // - If a sample is added that lies in the next event frequency interval (this
// will generate an event for the previous interval) // will generate an event for the previous interval)
...@@ -52,7 +52,7 @@ class CustomCountHistogram; ...@@ -52,7 +52,7 @@ class CustomCountHistogram;
// Note that no event is generated if there were no primary samples in an // Note that no event is generated if there were no primary samples in an
// interval. // interval.
// //
// Sample usage (see also SCOPED_UMA_AND_UKM_HIERARCHICAL_TIMER): // Sample usage (see also SCOPED_UMA_AND_UKM_TIMER):
// std::unique_ptr<UkmHierarchicalTimeAggregator> aggregator( // std::unique_ptr<UkmHierarchicalTimeAggregator> aggregator(
// new UkmHierarchicalTimeAggregator( // new UkmHierarchicalTimeAggregator(
// GetSourceId(), // GetSourceId(),
...@@ -101,6 +101,23 @@ class CustomCountHistogram; ...@@ -101,6 +101,23 @@ class CustomCountHistogram;
// //
// If the source_id/recorder changes then a new // If the source_id/recorder changes then a new
// UkmHierarchicalTimeAggregator has to be created. // UkmHierarchicalTimeAggregator has to be created.
// Defines a UKM that is part of a hierarchical ukm, recorded in
// microseconds equal to the duration of the current lexical scope after
// declaration of the macro. Example usage:
//
// void LocalFrameView::DoExpensiveThing() {
// SCOPED_UMA_AND_UKM_TIMER(kUkmEnumName);
// // Do computation of expensive thing
//
// }
//
// |ukm_enum| should be an entry in LocalFrameUkmAggregator's enum of
// metric names (which in turn corresponds to names in from ukm.xml).
#define SCOPED_UMA_AND_UKM_TIMER(aggregator, ukm_enum) \
auto scoped_ukm_hierarchical_timer = \
aggregator.GetScopedTimer(static_cast<size_t>(ukm_enum));
class CORE_EXPORT LocalFrameUkmAggregator { class CORE_EXPORT LocalFrameUkmAggregator {
public: public:
// Changing these values requires changing the names of metrics specified // Changing these values requires changing the names of metrics specified
...@@ -114,6 +131,7 @@ class CORE_EXPORT LocalFrameUkmAggregator { ...@@ -114,6 +131,7 @@ class CORE_EXPORT LocalFrameUkmAggregator {
kPrePaint, kPrePaint,
kStyleAndLayout, kStyleAndLayout,
kForcedStyleAndLayout, kForcedStyleAndLayout,
kScrollingCoordinator,
kCount kCount
}; };
...@@ -123,9 +141,15 @@ class CORE_EXPORT LocalFrameUkmAggregator { ...@@ -123,9 +141,15 @@ class CORE_EXPORT LocalFrameUkmAggregator {
// Add an entry in this arrray every time a new metric is added. // Add an entry in this arrray every time a new metric is added.
static const Vector<String>& metric_strings() { static const Vector<String>& metric_strings() {
// Leaky construction to avoid exit-time destruction. // Leaky construction to avoid exit-time destruction.
static const Vector<String>* strings = new Vector<String>{ static const Vector<String>* strings =
"Compositing", "CompositingCommit", "IntersectionObservation", "Paint", new Vector<String>{"Compositing",
"PrePaint", "StyleAndLayout", "ForcedStyleAndLayout"}; "CompositingCommit",
"IntersectionObservation",
"Paint",
"PrePaint",
"StyleAndLayout",
"ForcedStyleAndLayout",
"ScrollingCoordinator"};
return *strings; return *strings;
} }
......
...@@ -123,6 +123,8 @@ TEST_F(LocalFrameUkmAggregatorTest, EventsRecordedPerSecond) { ...@@ -123,6 +123,8 @@ TEST_F(LocalFrameUkmAggregatorTest, EventsRecordedPerSecond) {
auto entries = recorder().GetEntriesByName("Blink.UpdateTime"); auto entries = recorder().GetEntriesByName("Blink.UpdateTime");
EXPECT_EQ(entries.size(), 4u); EXPECT_EQ(entries.size(), 4u);
float expected_average_ratio =
floor(100.0 / (float)LocalFrameUkmAggregator::kCount);
for (auto* entry : entries) { for (auto* entry : entries) {
for (int i = 0; i < LocalFrameUkmAggregator::kCount; ++i) { for (int i = 0; i < LocalFrameUkmAggregator::kCount; ++i) {
EXPECT_TRUE( EXPECT_TRUE(
...@@ -142,7 +144,7 @@ TEST_F(LocalFrameUkmAggregatorTest, EventsRecordedPerSecond) { ...@@ -142,7 +144,7 @@ TEST_F(LocalFrameUkmAggregatorTest, EventsRecordedPerSecond) {
const int64_t* metric1_average_ratio = const int64_t* metric1_average_ratio =
ukm::TestUkmRecorder::GetEntryMetric(entry, ukm::TestUkmRecorder::GetEntryMetric(entry,
GetAverageRatioMetricName(i)); GetAverageRatioMetricName(i));
EXPECT_NEAR(*metric1_average_ratio, 14.0, 0.001); EXPECT_NEAR(*metric1_average_ratio, expected_average_ratio, 0.001);
EXPECT_TRUE(ukm::TestUkmRecorder::EntryHasMetric( EXPECT_TRUE(ukm::TestUkmRecorder::EntryHasMetric(
entry, GetWorstCaseRatioMetricName(i))); entry, GetWorstCaseRatioMetricName(i)));
......
...@@ -193,22 +193,6 @@ void LogCursorSizeCounter(LocalFrame* frame, const Cursor& cursor) { ...@@ -193,22 +193,6 @@ void LogCursorSizeCounter(LocalFrame* frame, const Cursor& cursor) {
} // namespace } // namespace
// Defines a UKM that is part of a hierarchical ukm, recorded in
// microseconds equal to the duration of the current lexical scope after
// declaration of the macro. Example usage:
//
// void LocalFrameView::DoExpensiveThing() {
// SCOPED_UMA_AND_UKM_TIMER(kUkmEnumName);
// // Do computation of expensive thing
//
// }
//
// |ukm_enum| should be an entry in LocalFrameUkmAggregator's enum of
// metric names (which in turn corresponds to names in from ukm.xml).
#define SCOPED_UMA_AND_UKM_TIMER(ukm_enum) \
auto scoped_ukm_hierarchical_timer = \
EnsureUkmAggregator().GetScopedTimer(static_cast<size_t>(ukm_enum));
// The maximum number of updatePlugins iterations that should be done before // The maximum number of updatePlugins iterations that should be done before
// returning. // returning.
static const unsigned kMaxUpdatePluginsIterations = 2; static const unsigned kMaxUpdatePluginsIterations = 2;
...@@ -2394,7 +2378,8 @@ bool LocalFrameView::UpdateLifecyclePhases( ...@@ -2394,7 +2378,8 @@ bool LocalFrameView::UpdateLifecyclePhases(
if (target_state == DocumentLifecycle::kPaintClean) { if (target_state == DocumentLifecycle::kPaintClean) {
TRACE_EVENT0("blink,benchmark", TRACE_EVENT0("blink,benchmark",
"LocalFrameView::UpdateViewportIntersectionsForSubtree"); "LocalFrameView::UpdateViewportIntersectionsForSubtree");
SCOPED_UMA_AND_UKM_TIMER(LocalFrameUkmAggregator::kIntersectionObservation); SCOPED_UMA_AND_UKM_TIMER(EnsureUkmAggregator(),
LocalFrameUkmAggregator::kIntersectionObservation);
UpdateViewportIntersectionsForSubtree(); UpdateViewportIntersectionsForSubtree();
} }
...@@ -2451,7 +2436,8 @@ bool LocalFrameView::RunStyleAndLayoutLifecyclePhases( ...@@ -2451,7 +2436,8 @@ bool LocalFrameView::RunStyleAndLayoutLifecyclePhases(
TRACE_EVENT0("blink,benchmark", TRACE_EVENT0("blink,benchmark",
"LocalFrameView::RunStyleAndLayoutLifecyclePhases"); "LocalFrameView::RunStyleAndLayoutLifecyclePhases");
{ {
SCOPED_UMA_AND_UKM_TIMER(LocalFrameUkmAggregator::kStyleAndLayout); SCOPED_UMA_AND_UKM_TIMER(EnsureUkmAggregator(),
LocalFrameUkmAggregator::kStyleAndLayout);
UpdateStyleAndLayoutIfNeededRecursive(); UpdateStyleAndLayoutIfNeededRecursive();
} }
DCHECK(Lifecycle().GetState() >= DocumentLifecycle::kLayoutClean); DCHECK(Lifecycle().GetState() >= DocumentLifecycle::kLayoutClean);
...@@ -2518,7 +2504,8 @@ bool LocalFrameView::RunCompositingLifecyclePhase( ...@@ -2518,7 +2504,8 @@ bool LocalFrameView::RunCompositingLifecyclePhase(
DCHECK(layout_view); DCHECK(layout_view);
if (!RuntimeEnabledFeatures::CompositeAfterPaintEnabled()) { if (!RuntimeEnabledFeatures::CompositeAfterPaintEnabled()) {
SCOPED_UMA_AND_UKM_TIMER(LocalFrameUkmAggregator::kCompositing); SCOPED_UMA_AND_UKM_TIMER(EnsureUkmAggregator(),
LocalFrameUkmAggregator::kCompositing);
layout_view->Compositor()->UpdateIfNeededRecursive(target_state); layout_view->Compositor()->UpdateIfNeededRecursive(target_state);
} else { } else {
ForAllNonThrottledLocalFrameViews([](LocalFrameView& frame_view) { ForAllNonThrottledLocalFrameViews([](LocalFrameView& frame_view) {
...@@ -2562,7 +2549,8 @@ bool LocalFrameView::RunPrePaintLifecyclePhase( ...@@ -2562,7 +2549,8 @@ bool LocalFrameView::RunPrePaintLifecyclePhase(
}); });
{ {
SCOPED_UMA_AND_UKM_TIMER(LocalFrameUkmAggregator::kPrePaint); SCOPED_UMA_AND_UKM_TIMER(EnsureUkmAggregator(),
LocalFrameUkmAggregator::kPrePaint);
PrePaintTreeWalk().WalkTree(*this); PrePaintTreeWalk().WalkTree(*this);
} }
...@@ -2788,7 +2776,8 @@ static void PaintGraphicsLayerRecursively(GraphicsLayer* layer) { ...@@ -2788,7 +2776,8 @@ static void PaintGraphicsLayerRecursively(GraphicsLayer* layer) {
} }
void LocalFrameView::PaintTree() { void LocalFrameView::PaintTree() {
SCOPED_UMA_AND_UKM_TIMER(LocalFrameUkmAggregator::kPaint); SCOPED_UMA_AND_UKM_TIMER(EnsureUkmAggregator(),
LocalFrameUkmAggregator::kPaint);
DCHECK(GetFrame().IsLocalRoot()); DCHECK(GetFrame().IsLocalRoot());
...@@ -2929,7 +2918,8 @@ void LocalFrameView::PushPaintArtifactToCompositor( ...@@ -2929,7 +2918,8 @@ void LocalFrameView::PushPaintArtifactToCompositor(
paint_artifact_compositor_->RootLayer(), &GetFrame()); paint_artifact_compositor_->RootLayer(), &GetFrame());
} }
SCOPED_UMA_AND_UKM_TIMER(LocalFrameUkmAggregator::kCompositingCommit); SCOPED_UMA_AND_UKM_TIMER(EnsureUkmAggregator(),
LocalFrameUkmAggregator::kCompositingCommit);
paint_artifact_compositor_->Update( paint_artifact_compositor_->Update(
paint_controller_->GetPaintArtifactShared(), composited_element_ids, paint_controller_->GetPaintArtifactShared(), composited_element_ids,
......
...@@ -690,6 +690,9 @@ class CORE_EXPORT LocalFrameView final ...@@ -690,6 +690,9 @@ class CORE_EXPORT LocalFrameView final
return *paint_timing_detector_; return *paint_timing_detector_;
} }
// Return the UKM aggregator for this frame, creating it if necessary.
LocalFrameUkmAggregator& EnsureUkmAggregator();
protected: protected:
void NotifyFrameRectsChangedIfNeeded(); void NotifyFrameRectsChangedIfNeeded();
...@@ -832,8 +835,6 @@ class CORE_EXPORT LocalFrameView final ...@@ -832,8 +835,6 @@ class CORE_EXPORT LocalFrameView final
void LayoutFromRootObject(LayoutObject& root); void LayoutFromRootObject(LayoutObject& root);
LocalFrameUkmAggregator& EnsureUkmAggregator();
LayoutSize size_; LayoutSize size_;
typedef HashSet<scoped_refptr<LayoutEmbeddedObject>> EmbeddedObjectSet; typedef HashSet<scoped_refptr<LayoutEmbeddedObject>> EmbeddedObjectSet;
......
...@@ -41,6 +41,7 @@ ...@@ -41,6 +41,7 @@
#include "third_party/blink/renderer/core/frame/event_handler_registry.h" #include "third_party/blink/renderer/core/frame/event_handler_registry.h"
#include "third_party/blink/renderer/core/frame/local_dom_window.h" #include "third_party/blink/renderer/core/frame/local_dom_window.h"
#include "third_party/blink/renderer/core/frame/local_frame.h" #include "third_party/blink/renderer/core/frame/local_frame.h"
#include "third_party/blink/renderer/core/frame/local_frame_ukm_aggregator.h"
#include "third_party/blink/renderer/core/frame/local_frame_view.h" #include "third_party/blink/renderer/core/frame/local_frame_view.h"
#include "third_party/blink/renderer/core/frame/page_scale_constraints_set.h" #include "third_party/blink/renderer/core/frame/page_scale_constraints_set.h"
#include "third_party/blink/renderer/core/frame/settings.h" #include "third_party/blink/renderer/core/frame/settings.h"
...@@ -191,7 +192,8 @@ void ScrollingCoordinator::UpdateAfterPaint(LocalFrameView* frame_view) { ...@@ -191,7 +192,8 @@ void ScrollingCoordinator::UpdateAfterPaint(LocalFrameView* frame_view) {
return; return;
} }
SCOPED_BLINK_UMA_HISTOGRAM_TIMER("Blink.ScrollingCoordinator.UpdateTime"); SCOPED_UMA_AND_UKM_TIMER(frame_view->EnsureUkmAggregator(),
LocalFrameUkmAggregator::kScrollingCoordinator);
TRACE_EVENT0("input", "ScrollingCoordinator::UpdateAfterPaint"); TRACE_EVENT0("input", "ScrollingCoordinator::UpdateAfterPaint");
// TODO(pdr): Move the scroll gesture region logic to use touch action rects. // TODO(pdr): Move the scroll gesture region logic to use touch action rects.
......
...@@ -819,6 +819,40 @@ be describing additional metrics about the same event. ...@@ -819,6 +819,40 @@ be describing additional metrics about the same event.
the sample window. An int in the range [0,100]. the sample window. An int in the range [0,100].
</summary> </summary>
</metric> </metric>
<metric name="ScrollingCoordinator.Average">
<summary>
The average time taken by the style and layout phases in microseconds in
the event period.
</summary>
<aggregation>
<history>
<index fields="profile.country"/>
<statistics>
<quantiles type="std-percentiles"/>
</statistics>
</history>
</aggregation>
</metric>
<metric name="ScrollingCoordinator.AverageRatio">
<summary>
The average over frames within the event period of the ratio of time taken
to update the scrolling coordinator after painting to the total time for
the main frame, expressed as a percentage. An int in the range [0,100].
</summary>
</metric>
<metric name="ScrollingCoordinator.WorstCase">
<summary>
The longest single time within the event period that was used to update
the ScrollingCoordinator after painting (in microseconds).
</summary>
</metric>
<metric name="ScrollingCoordinator.WorstCaseRatio">
<summary>
The highest proportion of a frame within the event period that was used to
update the ScrollingCoordinator after painting, expressed as a percentage.
An int in the range [0,100].
</summary>
</metric>
<metric name="StyleAndLayout.Average"> <metric name="StyleAndLayout.Average">
<summary> <summary>
The average time taken by the style and layout phases in microseconds in The average time taken by the style and layout phases in microseconds in
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment