def testStartFinishOneSliceOneThread(self):
events = [
# Time is intentionally out of order.
{'name': 'a', 'args': {}, 'pid': 52, 'ts': 560, 'cat': 'cat',
'tid': 53,
'ph': 'F', 'id': 72},
{'name': 'a', 'pid': 52, 'ts': 524, 'cat': 'cat',
'tid': 53,
'ph': 'S', 'id': 72, 'args': {'foo': 'bar'}}
]
m = timeline_model.TimelineModel(event_data=events)
self.assertEqual(2, len(m.GetAllEvents()))
processes = m.GetAllProcesses()
t = processes[0].threads[53]
slices = t.async_slices
self.assertEqual(1, len(slices))
self.assertEqual('a', slices[0].name)
self.assertEqual('cat', slices[0].category)
self.assertEqual(72, slices[0].id)
self.assertEqual('bar', slices[0].args['foo'])
self.assertEqual(0, slices[0].start)
self.assertAlmostEqual((60 - 24) / 1000.0, slices[0].duration)
self.assertEqual(t, slices[0].start_thread)
self.assertEqual(t, slices[0].end_thread)
def setUp(self):
model = model_module.TimelineModel()
renderer_thread = model.GetOrCreateProcess(1).GetOrCreateThread(2)
renderer_thread.name = 'CrRendererMain'
# [ X ]
# [ Y ]
renderer_thread.BeginSlice('cat1', 'x.y', 10, 0)
renderer_thread.EndSlice(20, 20)
renderer_thread.async_slices.append(
async_slice.AsyncSlice('cat',
'Interaction.LogicalName1/is_smooth',
timestamp=0,
duration=20,
start_thread=renderer_thread,
end_thread=renderer_thread))
renderer_thread.async_slices.append(
async_slice.AsyncSlice(
'cat',
'Interaction.LogicalName2/is_loading_resources',
timestamp=25,
duration=5,
start_thread=renderer_thread,
end_thread=renderer_thread))
model.FinalizeImport()
self.model = model
self.renderer_thread = renderer_thread
def testAutoclosingWithEventsOutsideBounds(self):
events = [
# Slice that begins before min and ends after max of the other threads.
{'name': 'a', 'args': {}, 'pid': 1, 'ts': 0, 'cat': 'foo',
'tid': 1, 'ph': 'B'},
{'name': 'b', 'args': {}, 'pid': 1, 'ts': 3, 'cat': 'foo',
'tid': 1, 'ph': 'B'},
# Slice that does finish to give an 'end time' to establish a basis
{'name': 'c', 'args': {}, 'pid': 1, 'ts': 1, 'cat': 'bar',
'tid': 2, 'ph': 'B'},
{'name': 'c', 'args': {}, 'pid': 1, 'ts': 2, 'cat': 'bar',
'tid': 2, 'ph': 'E'}
]
m = timeline_model.TimelineModel(event_data=events,
shift_world_to_zero=False)
p = m.GetAllProcesses()[0]
t = p.threads[1]
self.assertEqual(2, len(t.all_slices))
slice_event = FindEventNamed(t.all_slices, 'a')
self.assertEqual('a', slice_event.name)
self.assertEqual('foo', slice_event.category)
self.assertAlmostEqual(0, slice_event.start)
self.assertAlmostEqual(0.003, slice_event.duration)
t2 = p.threads[2]
slice2 = FindEventNamed(t2.all_slices, 'c')
self.assertEqual('c', slice2.name)
self.assertEqual('bar', slice2.category)
self.assertAlmostEqual(0.001, slice2.start)
self.assertAlmostEqual(0.001, slice2.duration)
self.assertAlmostEqual(0.000, m.bounds.min)
self.assertAlmostEqual(0.003, m.bounds.max)
def testOverheadIsRemoved(self):
model = model_module.TimelineModel()
renderer_main = model.GetOrCreateProcess(1).GetOrCreateThread(2)
renderer_main.name = 'CrRendererMain'
# Create one frame swap.
cc_main = model.GetOrCreateProcess(1).GetOrCreateThread(3)
cc_main.name = 'Compositor'
cc_main.BeginSlice('cc_cat', timeline.FrameTraceName, 10, 10)
cc_main.EndSlice(11, 11)
# [ X ]
# [Overhead]
overhead_category = timeline.OverheadTraceCategory
overhead_name = timeline.OverheadTraceName
renderer_main.BeginSlice('cat1', 'X', 10, 0)
renderer_main.BeginSlice(overhead_category, overhead_name, 15, 5)
renderer_main.EndSlice(16, 6)
renderer_main.EndSlice(30, 10)
model.FinalizeImport()
# Include everything in an action-range.
metric = timeline.ThreadTimesTimelineMetric()
metric._action_ranges = [self.GetActionRange(10, 30)]
metric.details_to_report = timeline.ReportMainThreadOnly
results = self.GetResultsForModel(metric, model)
# Test a couple specific results.
assert_results = {
timeline.ThreadCpuTimeResultName('renderer_main'): 9.0,
}
for name, value in assert_results.iteritems():
results.AssertHasPageSpecificScalarValue(name, 'ms', value)
def testMultiCounter(self):
events = [
{'name': 'ctr', 'args': {'value1': 0, 'value2': 7}, 'pid': 1, 'ts': 0,
'cat': 'foo', 'tid': 1, 'ph': 'C'},
{'name': 'ctr', 'args': {'value1': 10, 'value2': 4}, 'pid': 1, 'ts': 10,
'cat': 'foo', 'tid': 1, 'ph': 'C'},
{'name': 'ctr', 'args': {'value1': 0, 'value2': 1 }, 'pid': 1, 'ts': 20,
'cat': 'foo', 'tid': 1, 'ph': 'C'}
]
m = timeline_model.TimelineModel(event_data=events)
p = m.GetAllProcesses()[0]
ctr = p.counters['foo.ctr']
self.assertEqual('ctr', ctr.name)
self.assertEqual('ctr', ctr.name)
self.assertEqual('foo', ctr.category)
self.assertEqual(3, ctr.num_samples)
self.assertEqual(2, ctr.num_series)
self.assertEqual(sorted(['value1', 'value2']), sorted(ctr.series_names))
self.assertEqual(sorted([0, 0.01, 0.02]), sorted(ctr.timestamps))
self.assertEqual(sorted([0, 7, 10, 4, 0, 1]), sorted(ctr.samples))
# We can't check ctr.totals here because it can change depending on
# the order in which the series names are added.
self.assertEqual(14, ctr.max_total)
def testNestedParsing(self):
events = [
{'name': 'a', 'args': {}, 'pid': 1, 'ts': 1, 'tts': 2, 'cat': 'foo',
'tid': 1, 'ph': 'B'},
{'name': 'b', 'args': {}, 'pid': 1, 'ts': 3, 'tts': 3, 'cat': 'bar',
'tid': 1, 'ph': 'B'},
{'name': 'b', 'args': {}, 'pid': 1, 'ts': 5, 'tts': 4, 'cat': 'bar',
'tid': 1, 'ph': 'E'},
{'name': 'a', 'args': {}, 'pid': 1, 'ts': 7, 'tts': 5, 'cat': 'foo',
'tid': 1, 'ph': 'E'}
]
m = timeline_model.TimelineModel(event_data=events,
shift_world_to_zero=False)
t = m.GetAllProcesses()[0].threads[1]
slice_a = FindEventNamed(t.all_slices, 'a')
slice_b = FindEventNamed(t.all_slices, 'b')
self.assertEqual('a', slice_a.name)
self.assertEqual('foo', slice_a.category)
self.assertAlmostEqual(0.001, slice_a.start)
self.assertAlmostEqual(0.006, slice_a.duration)
self.assertAlmostEqual(0.002, slice_a.thread_start)
self.assertAlmostEqual(0.003, slice_a.thread_duration)
self.assertEqual('b', slice_b.name)
self.assertEqual('bar', slice_b.category)
self.assertAlmostEqual(0.003, slice_b.start)
self.assertAlmostEqual(0.002, slice_b.duration)
self.assertAlmostEqual(0.003, slice_b.thread_start)
self.assertAlmostEqual(0.001, slice_b.thread_duration)
def testNestedAutoclosing(self):
events = [
# Tasks that don't finish.
{'name': 'a1', 'args': {}, 'pid': 1, 'ts': 1, 'cat': 'foo',
'tid': 1, 'ph': 'B'},
{'name': 'a2', 'args': {}, 'pid': 1, 'ts': 1.5, 'cat': 'foo',
'tid': 1, 'ph': 'B'},
# Slice that does finish to give an 'end time' to make autoclosing work.
{'name': 'b', 'args': {}, 'pid': 1, 'ts': 1, 'cat': 'foo',
'tid': 2, 'ph': 'B'},
{'name': 'b', 'args': {}, 'pid': 1, 'ts': 2, 'cat': 'foo',
'tid': 2, 'ph': 'E'}
]
m = timeline_model.TimelineModel(event_data=events,
shift_world_to_zero=False)
t1 = m.GetAllProcesses()[0].threads[1]
t2 = m.GetAllProcesses()[0].threads[2]
slice_a1 = FindEventNamed(t1.all_slices, 'a1')
slice_a2 = FindEventNamed(t1.all_slices, 'a2')
FindEventNamed(t2.all_slices, 'b')
self.assertAlmostEqual(0.002, slice_a1.end)
self.assertAlmostEqual(0.002, slice_a2.end)
def testImport(self):
m = model.TimelineModel([_SAMPLE_MESSAGE], shift_world_to_zero=False)
self.assertEquals(1, len(m.processes))
self.assertEquals(1, len(m.processes.values()[0].threads))
renderer_thread = m.GetAllThreads()[0]
self.assertEquals(1, len(renderer_thread.toplevel_slices))
self.assertEquals('Program', renderer_thread.toplevel_slices[0].name)
def testAsyncStepsInOneThread(self):
events = [
# Time is intentionally out of order.
{'name': 'a', 'args': {'z': 3}, 'pid': 52, 'ts': 560, 'cat': 'foo',
'tid': 53, 'ph': 'F', 'id': 72},
{'name': 'a', 'args': {'step': 's1', 'y': 2}, 'pid': 52, 'ts': 548,
'cat': 'foo', 'tid': 53, 'ph': 'T', 'id': 72},
{'name': 'a', 'args': {'x': 1}, 'pid': 52, 'ts': 524, 'cat': 'foo',
'tid': 53, 'ph': 'S', 'id': 72}
]
m = timeline_model.TimelineModel(event_data=events)
t = m.GetAllProcesses()[0].threads[53]
self.assertEqual(1, len(t.async_slices))
parent_slice = t.async_slices[0]
self.assertEqual('a', parent_slice.name)
self.assertEqual('foo', parent_slice.category)
self.assertEqual(0, parent_slice.start)
self.assertEqual(2, len(parent_slice.sub_slices))
sub_slice = parent_slice.sub_slices[0]
self.assertEqual('a', sub_slice.name)
self.assertEqual('foo', sub_slice.category)
self.assertAlmostEqual(0, sub_slice.start)
self.assertAlmostEqual((548 - 524) / 1000.0, sub_slice.duration)
self.assertEqual(1, sub_slice.args['x'])
sub_slice = parent_slice.sub_slices[1]
self.assertEqual('a:s1', sub_slice.name)
self.assertEqual('foo', sub_slice.category)
self.assertAlmostEqual((548 - 524) / 1000.0, sub_slice.start)
self.assertAlmostEqual((560 - 548) / 1000.0, sub_slice.duration)
self.assertEqual(2, sub_slice.args['y'])
self.assertEqual(3, sub_slice.args['z'])
def testBasicSingleThreadNonnestedParsing(self):
events = [
{'name': 'a', 'args': {}, 'pid': 52, 'ts': 520, 'cat': 'foo',
'tid': 53, 'ph': 'B'},
{'name': 'a', 'args': {}, 'pid': 52, 'ts': 560, 'cat': 'foo',
'tid': 53, 'ph': 'E'},
{'name': 'b', 'args': {}, 'pid': 52, 'ts': 629, 'cat': 'bar',
'tid': 53, 'ph': 'B'},
{'name': 'b', 'args': {}, 'pid': 52, 'ts': 631, 'cat': 'bar',
'tid': 53, 'ph': 'E'}
]
m = timeline_model.TimelineModel(event_data=events)
processes = m.GetAllProcesses()
self.assertEqual(1, len(processes))
p = processes[0]
self.assertEqual(52, p.pid)
self.assertEqual(1, len(p.threads))
t = p.threads[53]
self.assertEqual(2, len(t.all_slices))
self.assertEqual(53, t.tid)
slice_event = t.all_slices[0]
self.assertEqual('a', slice_event.name)
self.assertEqual('foo', slice_event.category)
self.assertAlmostEqual(0, slice_event.start)
self.assertAlmostEqual((560 - 520) / 1000.0, slice_event.duration)
self.assertEqual(0, len(slice_event.sub_slices))
slice_event = t.all_slices[1]
self.assertEqual('b', slice_event.name)
self.assertEqual('bar', slice_event.category)
self.assertAlmostEqual((629 - 520) / 1000.0, slice_event.start)
self.assertAlmostEqual((631 - 629) / 1000.0, slice_event.duration)
self.assertEqual(0, len(slice_event.sub_slices))
def MeasurePage(self, page, tab, results):
timeline_data = tab.browser.StopTracing()
timeline_model = model.TimelineModel(timeline_data)
self._power_metric.Stop(page, tab)
self._power_metric.AddResults(tab, results)
def _IsDone():
return tab.EvaluateJavaScript('isDone')
decode_image_events = \
timeline_model.GetAllEventsOfName('Decode Image')
# If it is a real image page, then store only the last-minIterations
# decode tasks.
if (hasattr(
page,
'image_decoding_measurement_limit_results_to_min_iterations')
and
page.image_decoding_measurement_limit_results_to_min_iterations
):
assert _IsDone()
min_iterations = tab.EvaluateJavaScript('minIterations')
decode_image_events = decode_image_events[-min_iterations:]
durations = [d.duration for d in decode_image_events]
if not durations:
return
image_decoding_avg = sum(durations) / len(durations)
results.Add('ImageDecoding_avg', 'ms', image_decoding_avg)
results.Add('ImageLoading_avg', 'ms',
tab.EvaluateJavaScript('averageLoadingTimeMs()'))
def Stop(self):
if not self._is_recording:
raise TabBackendException('Stop() called but not started')
self._is_recording = False
self._timeline_model = model.TimelineModel(event_data=self._raw_events,
shift_world_to_zero=False)
req = {'method': 'Timeline.stop'}
self._SendSyncRequest(req)
self._inspector_backend.UnregisterDomain('Timeline')
def Stop(self):
"""Stops recording and makes a TimelineModel with the event data."""
assert self._is_recording, 'Stop should be called after Start.'
request = {'method': 'Timeline.stop'}
result = self._SendSyncRequest(request)
raw_events = result['events']
self._timeline_model = model.TimelineModel(event_data=raw_events,
shift_world_to_zero=False)
self._inspector_backend.UnregisterDomain('Timeline')
self._is_recording = False
def testImportStringWithTrailingNewLine(self):
events = [
{'name': 'a', 'args': {}, 'pid': 52, 'ts': 524, 'cat': 'foo',
'tid': 53, 'ph': 'B'},
{'name': 'a', 'args': {}, 'pid': 52, 'ts': 560, 'cat': 'foo',
'tid': 53, 'ph': 'E'}
]
m = timeline_model.TimelineModel(event_data=json.dumps(events) + '\n')
self.assertEqual(1, len(m.GetAllProcesses()))
def testImportObjectInsteadOfArray(self):
events = { 'traceEvents': [
{'name': 'a', 'args': {}, 'pid': 52, 'ts': 524, 'cat': 'foo',
'tid': 53, 'ph': 'B'},
{'name': 'a', 'args': {}, 'pid': 52, 'ts': 560, 'cat': 'foo',
'tid': 53, 'ph': 'E'}
] }
m = timeline_model.TimelineModel(event_data=events)
self.assertEqual(1, len(m.GetAllProcesses()))
def testMultiplePidParsing(self):
events = [
{'name': 'a', 'args': {}, 'pid': 1, 'ts': 2, 'tts': 1, 'cat': 'foo',
'tid': 1, 'ph': 'B'},
{'name': 'a', 'args': {}, 'pid': 1, 'ts': 4, 'tts': 2, 'cat': 'foo',
'tid': 1, 'ph': 'E'},
{'name': 'b', 'args': {}, 'pid': 2, 'ts': 6, 'tts': 3, 'cat': 'bar',
'tid': 2, 'ph': 'B'},
{'name': 'b', 'args': {}, 'pid': 2, 'ts': 8, 'tts': 4, 'cat': 'bar',
'tid': 2, 'ph': 'E'}
]
m = timeline_model.TimelineModel(event_data=events)
processes = m.GetAllProcesses()
self.assertEqual(2, len(processes))
p = processes[0]
self.assertEqual(1, p.pid)
self.assertEqual(1, len(p.threads))
# Check process 1 thread 1.
t = p.threads[1]
self.assertEqual(1, len(t.all_slices))
self.assertEqual(1, t.tid)
slice_event = t.all_slices[0]
self.assertEqual('a', slice_event.name)
self.assertEqual('foo', slice_event.category)
self.assertAlmostEqual(0, slice_event.start)
self.assertAlmostEqual((4 - 2) / 1000.0, slice_event.duration)
self.assertAlmostEqual(1 / 1000.0, slice_event.thread_start)
self.assertAlmostEqual((2 - 1) / 1000.0, slice_event.thread_duration)
# Check process 2 thread 2.
# TODO: will this be in deterministic order?
p = processes[1]
self.assertEqual(2, p.pid)
self.assertEqual(1, len(p.threads))
t = p.threads[2]
self.assertEqual(1, len(t.all_slices))
self.assertEqual(2, t.tid)
slice_event = t.all_slices[0]
self.assertEqual('b', slice_event.name)
self.assertEqual('bar', slice_event.category)
self.assertAlmostEqual((6 - 2) / 1000.0, slice_event.start)
self.assertAlmostEqual((8 - 6) / 1000.0, slice_event.duration)
self.assertAlmostEqual(3 / 1000.0, slice_event.thread_start)
self.assertAlmostEqual((4 - 3) / 1000.0, slice_event.thread_duration)
# Check getAllThreads.
self.assertEqual([processes[0].threads[1],
processes[1].threads[2]],
m.GetAllThreads())
def testSliceHierarchy(self):
''' The slice hierarchy should look something like this:
[ a ]
[ b ] [ d ]
[ c ] [ e ]
'''
events = [
{'name': 'a', 'args': {}, 'pid': 52, 'ts': 100, 'cat': 'foo',
'tid': 53, 'ph': 'B'},
{'name': 'a', 'args': {}, 'pid': 52, 'ts': 200, 'cat': 'foo',
'tid': 53, 'ph': 'E'},
{'name': 'b', 'args': {}, 'pid': 52, 'ts': 125, 'cat': 'foo',
'tid': 53, 'ph': 'B'},
{'name': 'b', 'args': {}, 'pid': 52, 'ts': 165, 'cat': 'foo',
'tid': 53, 'ph': 'E'},
{'name': 'c', 'args': {}, 'pid': 52, 'ts': 125, 'cat': 'foo',
'tid': 53, 'ph': 'B'},
{'name': 'c', 'args': {}, 'pid': 52, 'ts': 135, 'cat': 'foo',
'tid': 53, 'ph': 'E'},
{'name': 'd', 'args': {}, 'pid': 52, 'ts': 175, 'cat': 'foo',
'tid': 53, 'ph': 'B'},
{'name': 'd', 'args': {}, 'pid': 52, 'ts': 190, 'cat': 'foo',
'tid': 53, 'ph': 'E'},
{'name': 'e', 'args': {}, 'pid': 52, 'ts': 155, 'cat': 'foo',
'tid': 53, 'ph': 'B'},
{'name': 'e', 'args': {}, 'pid': 52, 'ts': 165, 'cat': 'foo',
'tid': 53, 'ph': 'E'}
]
m = timeline_model.TimelineModel(event_data=events,
shift_world_to_zero=False)
processes = m.GetAllProcesses()
self.assertEqual(1, len(processes))
p = processes[0]
self.assertEqual(1, len(p.threads))
t = p.threads[53]
slice_a = t.all_slices[0]
self.assertEqual(4, len(slice_a.GetAllSubSlices()))
self.assertEqual('a', slice_a.name)
self.assertEqual(100 / 1000.0, slice_a.start)
self.assertEqual(200 / 1000.0, slice_a.end)
self.assertEqual(2, len(slice_a.sub_slices))
slice_b = slice_a.sub_slices[0]
self.assertEqual('b', slice_b.name)
self.assertEqual(2, len(slice_b.sub_slices))
self.assertEqual('c', slice_b.sub_slices[0].name)
self.assertEqual('e', slice_b.sub_slices[1].name)
slice_d = slice_a.sub_slices[1]
self.assertEqual('d', slice_d.name)
self.assertEqual(0, len(slice_d.sub_slices))
def ValidatePage(self, page, tab, results):
timeline_data = tab.browser.StopTracing()
timeline_model = model.TimelineModel(timeline_data)
for process in timeline_model.GetAllProcesses():
if 'gpu.GpuMemoryUsage' in process.counters:
counter = process.GetCounter('gpu', 'GpuMemoryUsage')
mb_used = counter.samples[-1] / 1048576
if mb_used + WIGGLE_ROOM_MB < SINGLE_TAB_LIMIT_MB:
raise page_test.Failure(self._FormatException('low', mb_used))
if mb_used - WIGGLE_ROOM_MB > MEMORY_LIMIT_MB:
raise page_test.Failure(self._FormatException('high', mb_used))
