Skip to content

Commit

Permalink
Initial commit of a queueing delay metric:
Browse files Browse the repository at this point in the history
- Adds new Queueing Delay metric to Smoothness
- Moves BMF and SBMF TRACE_EVENT strings from thread_proxy.cc to benchmark_instrumentation.cc

Review URL: https://codereview.chromium.org/301973011

git-svn-id: svn://svn.chromium.org/chrome/trunk/src@281647 0039d316-1c4b-4281-b951-d872f2087c98
  • Loading branch information
ariblue@google.com committed Jul 8, 2014
1 parent 006e384 commit 1bbed7a
Show file tree
Hide file tree
Showing 11 changed files with 323 additions and 18 deletions.
8 changes: 4 additions & 4 deletions cc/debug/benchmark_instrumentation.cc
Original file line number Diff line number Diff line change
Expand Up @@ -6,25 +6,25 @@
#include "cc/debug/benchmark_instrumentation.h"

namespace cc {
namespace benchmark_instrumentation {

// Please do not change the trace events in this file without updating
// tools/perf/measurements/rendering_stats.py accordingly.
// The benchmarks search for events and their arguments by name.

void BenchmarkInstrumentation::IssueMainThreadRenderingStatsEvent(
const MainThreadRenderingStats& stats) {
void IssueMainThreadRenderingStatsEvent(const MainThreadRenderingStats& stats) {
TRACE_EVENT_INSTANT1("benchmark",
"BenchmarkInstrumentation::MainThreadRenderingStats",
TRACE_EVENT_SCOPE_THREAD,
"data", stats.AsTraceableData());
}

void BenchmarkInstrumentation::IssueImplThreadRenderingStatsEvent(
const ImplThreadRenderingStats& stats) {
void IssueImplThreadRenderingStatsEvent(const ImplThreadRenderingStats& stats) {
TRACE_EVENT_INSTANT1("benchmark",
"BenchmarkInstrumentation::ImplThreadRenderingStats",
TRACE_EVENT_SCOPE_THREAD,
"data", stats.AsTraceableData());
}

} // namespace benchmark_instrumentation
} // namespace cc
38 changes: 33 additions & 5 deletions cc/debug/benchmark_instrumentation.h
Original file line number Diff line number Diff line change
Expand Up @@ -8,15 +8,43 @@
#include "cc/debug/rendering_stats.h"

namespace cc {
namespace benchmark_instrumentation {

class CC_EXPORT BenchmarkInstrumentation {
// Please do not change the trace events in this file without updating
// tools/perf/measurements/rendering_stats.py accordingly.
// The benchmarks search for events and their arguments by name.

namespace internal {
const char kCategory[] = "cc,benchmark";
const char kBeginFrameId[] = "begin_frame_id";
} // namespace internal

const char kSendBeginFrame[] = "ThreadProxy::ScheduledActionSendBeginMainFrame";
const char kDoBeginFrame[] = "ThreadProxy::BeginMainFrame";

class ScopedBeginFrameTask {
public:
static void IssueMainThreadRenderingStatsEvent(
const MainThreadRenderingStats& stats);
static void IssueImplThreadRenderingStatsEvent(
const ImplThreadRenderingStats& stats);
ScopedBeginFrameTask(const char* event_name, unsigned int begin_frame_id)
: event_name_(event_name) {
TRACE_EVENT_BEGIN1(internal::kCategory,
event_name_,
internal::kBeginFrameId,
begin_frame_id);
}
~ScopedBeginFrameTask() {
TRACE_EVENT_END0(internal::kCategory, event_name_);
}

private:
const char* event_name_;

DISALLOW_COPY_AND_ASSIGN(ScopedBeginFrameTask);
};

void IssueMainThreadRenderingStatsEvent(const MainThreadRenderingStats& stats);
void IssueImplThreadRenderingStatsEvent(const ImplThreadRenderingStats& stats);

} // namespace benchmark_instrumentation
} // namespace cc

#endif // CC_DEBUG_BENCHMARK_INSTRUMENTATION_H_
2 changes: 1 addition & 1 deletion cc/trees/layer_tree_host_impl.cc
Original file line number Diff line number Diff line change
Expand Up @@ -1498,7 +1498,7 @@ void LayerTreeHostImpl::DrawLayers(FrameData* frame,
active_tree_->root_layer()->ResetAllChangeTrackingForSubtree();

devtools_instrumentation::DidDrawFrame(id_);
BenchmarkInstrumentation::IssueImplThreadRenderingStatsEvent(
benchmark_instrumentation::IssueImplThreadRenderingStatsEvent(
rendering_stats_instrumentation_->impl_thread_rendering_stats());
rendering_stats_instrumentation_->AccumulateAndClearImplThreadStats();
}
Expand Down
2 changes: 1 addition & 1 deletion cc/trees/single_thread_proxy.cc
Original file line number Diff line number Diff line change
Expand Up @@ -177,7 +177,7 @@ void SingleThreadProxy::DoCommit(scoped_ptr<ResourceUpdateQueue> queue) {

RenderingStatsInstrumentation* stats_instrumentation =
layer_tree_host_->rendering_stats_instrumentation();
BenchmarkInstrumentation::IssueMainThreadRenderingStatsEvent(
benchmark_instrumentation::IssueMainThreadRenderingStatsEvent(
stats_instrumentation->main_thread_rendering_stats());
stats_instrumentation->AccumulateAndClearMainThreadStats();
}
Expand Down
13 changes: 10 additions & 3 deletions cc/trees/thread_proxy.cc
Original file line number Diff line number Diff line change
Expand Up @@ -32,6 +32,8 @@ namespace {
// Measured in seconds.
const double kSmoothnessTakesPriorityExpirationDelay = 0.25;

unsigned int nextBeginFrameId = 0;

class SwapPromiseChecker {
public:
explicit SwapPromiseChecker(cc::LayerTreeHost* layer_tree_host)
Expand Down Expand Up @@ -688,9 +690,12 @@ void ThreadProxy::FinishAllRenderingOnImplThread(CompletionEvent* completion) {
}

void ThreadProxy::ScheduledActionSendBeginMainFrame() {
TRACE_EVENT0("cc", "ThreadProxy::ScheduledActionSendBeginMainFrame");
unsigned int begin_frame_id = nextBeginFrameId++;
benchmark_instrumentation::ScopedBeginFrameTask begin_frame_task(
benchmark_instrumentation::kSendBeginFrame, begin_frame_id);
scoped_ptr<BeginMainFrameAndCommitState> begin_main_frame_state(
new BeginMainFrameAndCommitState);
begin_main_frame_state->begin_frame_id = begin_frame_id;
begin_main_frame_state->monotonic_frame_begin_time =
impl().layer_tree_host_impl->CurrentFrameTimeTicks();
begin_main_frame_state->scroll_info =
Expand All @@ -717,7 +722,9 @@ void ThreadProxy::ScheduledActionSendBeginMainFrame() {

void ThreadProxy::BeginMainFrame(
scoped_ptr<BeginMainFrameAndCommitState> begin_main_frame_state) {
TRACE_EVENT0("cc", "ThreadProxy::BeginMainFrame");
benchmark_instrumentation::ScopedBeginFrameTask begin_frame_task(
benchmark_instrumentation::kDoBeginFrame,
begin_main_frame_state->begin_frame_id);
TRACE_EVENT_SYNTHETIC_DELAY_BEGIN("cc.BeginMainFrame");
DCHECK(IsMainThread());

Expand Down Expand Up @@ -871,7 +878,7 @@ void ThreadProxy::BeginMainFrame(

RenderingStatsInstrumentation* stats_instrumentation =
layer_tree_host()->rendering_stats_instrumentation();
BenchmarkInstrumentation::IssueMainThreadRenderingStatsEvent(
benchmark_instrumentation::IssueMainThreadRenderingStatsEvent(
stats_instrumentation->main_thread_rendering_stats());
stats_instrumentation->AccumulateAndClearMainThreadStats();
}
Expand Down
1 change: 1 addition & 0 deletions cc/trees/thread_proxy.h
Original file line number Diff line number Diff line change
Expand Up @@ -47,6 +47,7 @@ class CC_EXPORT ThreadProxy : public Proxy,
BeginMainFrameAndCommitState();
~BeginMainFrameAndCommitState();

unsigned int begin_frame_id;
base::TimeTicks monotonic_frame_begin_time;
scoped_ptr<ScrollAndScaleSet> scroll_info;
size_t memory_allocation_limit_bytes;
Expand Down
85 changes: 85 additions & 0 deletions tools/telemetry/telemetry/web_perf/metrics/rendering_frame.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,85 @@
# Copyright 2014 The Chromium Authors. All rights reserved.
# Use of this source code is governed by a BSD-style license that can be
# found in the LICENSE file.

from collections import defaultdict
from telemetry.timeline import bounds
from telemetry.timeline import slice as slice_module


class MissingData(Exception):
pass


class NoBeginFrameIdException(Exception):
pass


class RenderingFrame(object):
"""Object with information about the triggering of a BeginMainFrame event."""
send_begin_frame_event = 'ThreadProxy::ScheduledActionSendBeginMainFrame'
begin_main_frame_event = 'ThreadProxy::BeginMainFrame'

def __init__(self, events):
all_send_begin_frame_events = [e for e in events
if e.name == self.send_begin_frame_event]
if len(all_send_begin_frame_events) != 1:
raise MissingData('There must be at exactly one %s event.' %
self.send_begin_frame_event)

all_begin_main_frame_events = [e for e in events
if e.name == self.begin_main_frame_event]
if not all_begin_main_frame_events:
raise MissingData('There must be at least one %s event.' %
self.begin_main_frame_event)
all_begin_main_frame_events.sort(key=lambda e: e.start)

self._send_begin_frame = all_send_begin_frame_events[0]
self._begin_main_frame = all_begin_main_frame_events[-1]

self._bounds = bounds.Bounds()
self._bounds.AddEvent(self._begin_main_frame)
self._bounds.AddEvent(self._send_begin_frame)

@staticmethod
def IsEventUseful(event):
return event.name in [RenderingFrame.send_begin_frame_event,
RenderingFrame.begin_main_frame_event]

@property
def bounds(self):
return self._bounds

@property
def queueing_duration(self):
return self._begin_main_frame.start - self._send_begin_frame.start


def GetFrameEventsInsideRange(renderer_process, timeline_range):
"""Returns RenderingFrames for all relevant events in the timeline_range."""
# First filter all events from the renderer_process and turn them into a
# dictonary of the form:
# {0: [send_begin_frame, begin_main_frame, begin_main_frame],
# 1: [begin_main_frame, send_begin_frame],
# 2: [send_begin_frame, begin_main_frame]}
begin_frame_events_by_id = defaultdict(list)
for event in renderer_process.IterAllEvents(
event_type_predicate=lambda t: t == slice_module.Slice,
event_predicate=RenderingFrame.IsEventUseful):
begin_frame_id = event.args.get('begin_frame_id', None)
if begin_frame_id is None:
raise NoBeginFrameIdException('Event is missing a begin_frame_id.')
begin_frame_events_by_id[begin_frame_id].append(event)

# Now, create RenderingFrames for events wherever possible.
frames = []
for events in begin_frame_events_by_id.values():
try:
frame = RenderingFrame(events)
if frame.bounds.Intersects(timeline_range):
frames.append(frame)
except MissingData:
continue
frames.sort(key=lambda frame: frame.bounds.min)

return frames
162 changes: 162 additions & 0 deletions tools/telemetry/telemetry/web_perf/metrics/rendering_frame_unittest.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,162 @@
# Copyright 2014 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.

import unittest

from telemetry.timeline import model
import telemetry.timeline.bounds as timeline_bounds
import telemetry.timeline.slice as tracing_slice
from telemetry.web_perf.metrics.rendering_frame import GetFrameEventsInsideRange
from telemetry.web_perf.metrics.rendering_frame import MissingData
from telemetry.web_perf.metrics.rendering_frame import RenderingFrame


class RenderingFrameTestData(object):

def __init__(self):
self._begin_frame_id = 0
self._events = []
self._renderer_process = model.TimelineModel().GetOrCreateProcess(pid=1)
self._main_thread = self._renderer_process.GetOrCreateThread(tid=11)
self._compositor_thread = self._renderer_process.GetOrCreateThread(tid=12)

@property
def events(self):
return self._events

@property
def renderer_process(self):
return self._renderer_process

def AddSendEvent(self, ts=0, duration=1):
self._begin_frame_id += 1
event = self._CreateEvent(
RenderingFrame.send_begin_frame_event, ts, duration)
self._compositor_thread.PushSlice(event)

def AddBeginMainFrameEvent(self, ts=0, duration=1):
event = self._CreateEvent(
RenderingFrame.begin_main_frame_event, ts, duration)
self._main_thread.PushSlice(event)

def FinalizeImport(self):
self._renderer_process.FinalizeImport()

def _CreateEvent(self, event_name, ts, duration):
event = tracing_slice.Slice(None, 'cc,benchmark', event_name, ts,
duration=duration, args={'begin_frame_id': self._begin_frame_id})
self._events.append(event)
return event


def GenerateTimelineRange(start=0, end=100):
timeline_range = timeline_bounds.Bounds()
timeline_range.AddValue(start)
timeline_range.AddValue(end)
return timeline_range


class RenderingFrameUnitTest(unittest.TestCase):

def testRenderingFrame(self):
d = RenderingFrameTestData()
d.AddSendEvent(ts=10)
d.AddBeginMainFrameEvent(ts=20)
d.FinalizeImport()

frame = RenderingFrame(d.events)
self.assertEquals(10, frame.queueing_duration)

def testRenderingFrameMissingSendBeginFrameEvents(self):
d = RenderingFrameTestData()
d.AddBeginMainFrameEvent(ts=10)
d.FinalizeImport()

self.assertRaises(MissingData, RenderingFrame, d.events)

def testRenderingFrameDuplicateSendBeginFrameEvents(self):
d = RenderingFrameTestData()
d.AddSendEvent(ts=10)
d.AddBeginMainFrameEvent(ts=20)
d.AddSendEvent(ts=30)
d.FinalizeImport()

self.assertRaises(MissingData, RenderingFrame, d.events)

def testRenderingFrameMissingBeginMainFrameEvents(self):
d = RenderingFrameTestData()
d.AddSendEvent(ts=10)
d.FinalizeImport()

self.assertRaises(MissingData, RenderingFrame, d.events)

def testRenderingFrameDuplicateBeginMainFrameEvents(self):
d = RenderingFrameTestData()
d.AddSendEvent(ts=10)
d.AddBeginMainFrameEvent(ts=20)
d.AddBeginMainFrameEvent(ts=30)
d.AddBeginMainFrameEvent(ts=40)
d.FinalizeImport()

frame = RenderingFrame(d.events)
self.assertEquals(30, frame.queueing_duration)

def testFrameEventMissingBeginFrameId(self):
timeline = model.TimelineModel()
process = timeline.GetOrCreateProcess(pid=1)
main_thread = process.GetOrCreateThread(tid=11)
timeline_range = timeline_bounds.Bounds()

# Create an event without the begin_frame_id argument
event = tracing_slice.Slice(
None, 'cc,benchmark', RenderingFrame.begin_main_frame_event, 0)
main_thread.PushSlice(event)
process.FinalizeImport()
self.assertRaises(Exception, GetFrameEventsInsideRange, process,
timeline_range)

def testGetFrameEventsInsideRange(self):
"""Test a basic sequenece, with expected frame queueing delays A and B.
|----A----| |--B--|
Main: [1] [1] [2]
Compositor: [1] [2]
"""
d = RenderingFrameTestData()
d.AddSendEvent(ts=10)
d.AddBeginMainFrameEvent(ts=20)
d.AddBeginMainFrameEvent(ts=30)
d.AddSendEvent(ts=40)
d.AddBeginMainFrameEvent(ts=50)
d.FinalizeImport()

timeline_range = GenerateTimelineRange()
frame_events = GetFrameEventsInsideRange(d.renderer_process, timeline_range)

self.assertEquals(2, len(frame_events))
self.assertEquals(20, frame_events[0].queueing_duration)
self.assertEquals(10, frame_events[1].queueing_duration)

def testFrameEventsMissingDataNotIncluded(self):
"""Test a sequenece missing an initial SendBeginFrame.
Only one frame should be returned, with expected frame queueing delay A.
|--A--|
Main: [0] [0] [2]
Compositor: [2]
"""
d = RenderingFrameTestData()
d.AddBeginMainFrameEvent(ts=20)
d.AddBeginMainFrameEvent(ts=30)
d.AddSendEvent(ts=40)
d.AddBeginMainFrameEvent(ts=50)
d.FinalizeImport()

timeline_range = GenerateTimelineRange()
frame_events = GetFrameEventsInsideRange(d.renderer_process, timeline_range)

self.assertEquals(1, len(frame_events))
self.assertEquals(10, frame_events[0].queueing_duration)
Loading

0 comments on commit 1bbed7a

Please sign in to comment.