def _CreateAsyncSlices(self):
if len(self._all_async_events) == 0:
return
self._all_async_events.sort(key=lambda x: x['event']['ts'])
async_event_states_by_name_then_id = {}
all_async_events = self._all_async_events
for async_event_state in all_async_events:
event = async_event_state['event']
name = event.get('name', None)
if name is None:
self._model.import_errors.append(
'Async events (ph: b, e, S, T or F) require an name parameter.')
continue
event_id = event.get('id')
if event_id is None:
self._model.import_errors.append(
'Async events (ph: b, e, S, T or F) require an id parameter.')
continue
# TODO(simonjam): Add a synchronous tick on the appropriate thread.
if event['ph'] == 'S' or event['ph'] == 'b':
if not name in async_event_states_by_name_then_id:
async_event_states_by_name_then_id[name] = {}
if event_id in async_event_states_by_name_then_id[name]:
self._model.import_errors.append(
'At %d, a slice of the same id %s was already open.' % (
event['ts'], event_id))
continue
async_event_states_by_name_then_id[name][event_id] = []
async_event_states_by_name_then_id[name][event_id].append(
async_event_state)
else:
if name not in async_event_states_by_name_then_id:
self._model.import_errors.append(
'At %d, no slice named %s was open.' % (event['ts'], name,))
continue
if event_id not in async_event_states_by_name_then_id[name]:
self._model.import_errors.append(
'At %d, no slice named %s with id=%s was open.' % (
event['ts'], name, event_id))
continue
events = async_event_states_by_name_then_id[name][event_id]
events.append(async_event_state)
if event['ph'] == 'F' or event['ph'] == 'e':
# Create a slice from start to end.
async_slice = tracing_async_slice.AsyncSlice(
events[0]['event']['cat'],
name,
events[0]['event']['ts'] / 1000.0)
async_slice.duration = ((event['ts'] / 1000.0)
- (events[0]['event']['ts'] / 1000.0))
async_slice.start_thread = events[0]['thread']
async_slice.end_thread = async_event_state['thread']
if async_slice.start_thread == async_slice.end_thread:
if 'tts' in event and 'tts' in events[0]['event']:
async_slice.thread_start = events[0]['event']['tts'] / 1000.0
async_slice.thread_duration = ((event['tts'] / 1000.0)
- (events[0]['event']['tts'] / 1000.0))
async_slice.id = event_id
async_slice.args = events[0]['event']['args']
# Create sub_slices for each step.
for j in xrange(1, len(events)):
sub_name = name
if events[j - 1]['event']['ph'] == 'T':
sub_name = name + ':' + events[j - 1]['event']['args']['step']
sub_slice = tracing_async_slice.AsyncSlice(
events[0]['event']['cat'],
sub_name,
events[j - 1]['event']['ts'] / 1000.0)
sub_slice.parent_slice = async_slice
sub_slice.duration = ((events[j]['event']['ts'] / 1000.0)
- (events[j - 1]['event']['ts'] / 1000.0))
sub_slice.start_thread = events[j - 1]['thread']
sub_slice.end_thread = events[j]['thread']
if sub_slice.start_thread == sub_slice.end_thread:
if 'tts' in events[j]['event'] and \
'tts' in events[j - 1]['event']:
sub_slice.thread_duration = \
((events[j]['event']['tts'] / 1000.0)
- (events[j - 1]['event']['tts'] / 1000.0))
sub_slice.id = event_id
sub_slice.args = events[j - 1]['event']['args']
async_slice.AddSubSlice(sub_slice)
# The args for the finish event go in the last sub_slice.
last_slice = async_slice.sub_slices[-1]
for arg_name, arg_value in event['args'].iteritems():
last_slice.args[arg_name] = arg_value
# Add |async_slice| to the start-thread's async_slices.
async_slice.start_thread.AddAsyncSlice(async_slice)
del async_event_states_by_name_then_id[name][event_id]
def AddInputLatencyStats(mock_timer,
start_thread,
end_thread,
ref_latency_stats=None):
""" Adds a random input latency stats event.
start_thread: The start thread on which the async slice is added.
end_thread: The end thread on which the async slice is ended.
ref_latency_stats: A ReferenceInputLatencyStats object for expected values.
"""
original_comp_time = mock_timer.AdvanceAndGet(2, 4) * 1000.0
ui_comp_time = mock_timer.AdvanceAndGet(2, 4) * 1000.0
begin_comp_time = mock_timer.AdvanceAndGet(2, 4) * 1000.0
forward_comp_time = mock_timer.AdvanceAndGet(2, 4) * 1000.0
end_comp_time = mock_timer.AdvanceAndGet(10, 20) * 1000.0
data = {
rendering_stats.ORIGINAL_COMP_NAME: {
'time': original_comp_time
},
rendering_stats.UI_COMP_NAME: {
'time': ui_comp_time
},
rendering_stats.BEGIN_COMP_NAME: {
'time': begin_comp_time
},
rendering_stats.END_COMP_NAME: {
'time': end_comp_time
}
}
timestamp = mock_timer.AdvanceAndGet(2, 4)
tracing_async_slice = async_slice.AsyncSlice('benchmark', 'InputLatency',
timestamp)
async_sub_slice = async_slice.AsyncSlice(
'benchmark', rendering_stats.GESTURE_SCROLL_UPDATE_EVENT_NAME,
timestamp)
async_sub_slice.args = {'data': data}
async_sub_slice.parent_slice = tracing_async_slice
async_sub_slice.start_thread = start_thread
async_sub_slice.end_thread = end_thread
tracing_async_slice.sub_slices.append(async_sub_slice)
tracing_async_slice.start_thread = start_thread
tracing_async_slice.end_thread = end_thread
start_thread.AddAsyncSlice(tracing_async_slice)
# Add scroll update latency info.
scroll_update_data = {
rendering_stats.BEGIN_SCROLL_UPDATE_COMP_NAME: {
'time': begin_comp_time
},
rendering_stats.FORWARD_SCROLL_UPDATE_COMP_NAME: {
'time': forward_comp_time
},
rendering_stats.END_COMP_NAME: {
'time': end_comp_time
}
}
scroll_async_slice = async_slice.AsyncSlice('benchmark', 'InputLatency',
timestamp)
scroll_async_sub_slice = async_slice.AsyncSlice(
'benchmark', rendering_stats.SCROLL_UPDATE_EVENT_NAME, timestamp)
scroll_async_sub_slice.args = {'data': scroll_update_data}
scroll_async_sub_slice.parent_slice = scroll_async_slice
scroll_async_sub_slice.start_thread = start_thread
scroll_async_sub_slice.end_thread = end_thread
scroll_async_slice.sub_slices.append(scroll_async_sub_slice)
scroll_async_slice.start_thread = start_thread
scroll_async_slice.end_thread = end_thread
start_thread.AddAsyncSlice(scroll_async_slice)
# Also add some dummy frame statistics so we can feed the resulting timeline
# to RenderingStats.
AddImplThreadRenderingStats(mock_timer, end_thread, False)
if not ref_latency_stats:
return
ref_latency_stats.input_event.append(async_sub_slice)
ref_latency_stats.input_event.append(scroll_async_sub_slice)
ref_latency_stats.input_event_latency.append(
(rendering_stats.GESTURE_SCROLL_UPDATE_EVENT_NAME,
(data[rendering_stats.END_COMP_NAME]['time'] -
data[rendering_stats.ORIGINAL_COMP_NAME]['time']) / 1000.0))
scroll_update_time = (
scroll_update_data[rendering_stats.END_COMP_NAME]['time'] -
scroll_update_data[
rendering_stats.BEGIN_SCROLL_UPDATE_COMP_NAME]['time'])
ref_latency_stats.input_event_latency.append(
(rendering_stats.SCROLL_UPDATE_EVENT_NAME,
scroll_update_time / 1000.0))
def AddInputLatencyStats(mock_timer,
start_thread,
end_thread,
ref_latency_stats=None):
""" Adds a random input latency stats event.
start_thread: The start thread on which the async slice is added.
end_thread: The end thread on which the async slice is ended.
ref_latency_stats: A ReferenceInputLatencyStats object for expected values.
"""
mock_timer.Advance(2, 4)
original_comp_time = mock_timer.Get() * 1000.0
mock_timer.Advance(2, 4)
ui_comp_time = mock_timer.Get() * 1000.0
mock_timer.Advance(2, 4)
begin_comp_time = mock_timer.Get() * 1000.0
mock_timer.Advance(2, 4)
forward_comp_time = mock_timer.Get() * 1000.0
mock_timer.Advance(10, 20)
end_comp_time = mock_timer.Get() * 1000.0
data = {
ORIGINAL_COMP_NAME: {
'time': original_comp_time
},
UI_COMP_NAME: {
'time': ui_comp_time
},
BEGIN_COMP_NAME: {
'time': begin_comp_time
},
END_COMP_NAME: {
'time': end_comp_time
}
}
timestamp = mock_timer.Get()
async_slice = tracing_async_slice.AsyncSlice('benchmark', 'InputLatency',
timestamp)
async_sub_slice = tracing_async_slice.AsyncSlice(
'benchmark', GESTURE_SCROLL_UPDATE_EVENT_NAME, timestamp)
async_sub_slice.args = {'data': data}
async_sub_slice.parent_slice = async_slice
async_sub_slice.start_thread = start_thread
async_sub_slice.end_thread = end_thread
async_slice.sub_slices.append(async_sub_slice)
async_slice.start_thread = start_thread
async_slice.end_thread = end_thread
start_thread.AddAsyncSlice(async_slice)
# Add scroll update latency info.
scroll_update_data = {
BEGIN_SCROLL_UPDATE_COMP_NAME: {
'time': begin_comp_time
},
FORWARD_SCROLL_UPDATE_COMP_NAME: {
'time': forward_comp_time
},
END_COMP_NAME: {
'time': end_comp_time
}
}
scroll_async_slice = tracing_async_slice.AsyncSlice(
'benchmark', 'InputLatency', timestamp)
scroll_async_sub_slice = tracing_async_slice.AsyncSlice(
'benchmark', SCROLL_UPDATE_EVENT_NAME, timestamp)
scroll_async_sub_slice.args = {'data': scroll_update_data}
scroll_async_sub_slice.parent_slice = scroll_async_slice
scroll_async_sub_slice.start_thread = start_thread
scroll_async_sub_slice.end_thread = end_thread
scroll_async_slice.sub_slices.append(scroll_async_sub_slice)
scroll_async_slice.start_thread = start_thread
scroll_async_slice.end_thread = end_thread
start_thread.AddAsyncSlice(scroll_async_slice)
if not ref_latency_stats:
return
ref_latency_stats.input_event.append(async_sub_slice)
ref_latency_stats.input_event.append(scroll_async_sub_slice)
ref_latency_stats.input_event_latency.append(
(GESTURE_SCROLL_UPDATE_EVENT_NAME,
(data[END_COMP_NAME]['time'] - data[ORIGINAL_COMP_NAME]['time']) /
1000.0))
ref_latency_stats.input_event_latency.append(
(SCROLL_UPDATE_EVENT_NAME,
(scroll_update_data[END_COMP_NAME]['time'] -
scroll_update_data[BEGIN_SCROLL_UPDATE_COMP_NAME]['time']) / 1000.0))
def testGetAdjustedInteractionIfContainGesture(self):
model = model_module.TimelineModel()
renderer_main = model.GetOrCreateProcess(1).GetOrCreateThread(2)
renderer_main.name = 'CrRendererMain'
# [ X ] [ Y ]
# [ sub_async_slice_X ]
# [ record_1]
# [ record_6]
# [ record_2 ] [ record_3 ]
# [ record_4 ]
# [ record_5 ]
#
# Note: X and Y are async slice with name
# SyntheticGestureController::running
async_slice_X = async_slice.AsyncSlice(
'X',
'SyntheticGestureController::running',
10,
duration=20,
start_thread=renderer_main,
end_thread=renderer_main)
sub_async_slice_X = async_slice.AsyncSlice(
'X',
'SyntheticGestureController::running',
10,
duration=20,
start_thread=renderer_main,
end_thread=renderer_main)
sub_async_slice_X.parent_slice = async_slice_X
async_slice_X.AddSubSlice(sub_async_slice_X)
async_slice_Y = async_slice.AsyncSlice(
'X',
'SyntheticGestureController::running',
60,
duration=20,
start_thread=renderer_main,
end_thread=renderer_main)
renderer_main.AddAsyncSlice(async_slice_X)
renderer_main.AddAsyncSlice(async_slice_Y)
model.FinalizeImport(shift_world_to_zero=False)
record_1 = tir_module.TimelineInteractionRecord(
'Gesture_included', 15, 25)
record_2 = tir_module.TimelineInteractionRecord(
'Gesture_overlapped_left', 5, 25)
record_3 = tir_module.TimelineInteractionRecord(
'Gesture_overlapped_right', 25, 35)
record_4 = tir_module.TimelineInteractionRecord(
'Gesture_containing', 5, 35)
record_5 = tir_module.TimelineInteractionRecord(
'Gesture_non_overlapped', 35, 45)
record_6 = tir_module.TimelineInteractionRecord(
'Action_included', 15, 25)
adjusted_record_1 = sg_util.GetAdjustedInteractionIfContainGesture(
model, record_1)
self.assertEquals(adjusted_record_1.start, 10)
self.assertEquals(adjusted_record_1.end, 30)
self.assertTrue(adjusted_record_1 is not record_1)
adjusted_record_2 = sg_util.GetAdjustedInteractionIfContainGesture(
model, record_2)
self.assertEquals(adjusted_record_2.start, 10)
self.assertEquals(adjusted_record_2.end, 30)
adjusted_record_3 = sg_util.GetAdjustedInteractionIfContainGesture(
model, record_3)
self.assertEquals(adjusted_record_3.start, 10)
self.assertEquals(adjusted_record_3.end, 30)
adjusted_record_4 = sg_util.GetAdjustedInteractionIfContainGesture(
model, record_4)
self.assertEquals(adjusted_record_4.start, 10)
self.assertEquals(adjusted_record_4.end, 30)
adjusted_record_5 = sg_util.GetAdjustedInteractionIfContainGesture(
model, record_5)
self.assertEquals(adjusted_record_5.start, 35)
self.assertEquals(adjusted_record_5.end, 45)
self.assertTrue(adjusted_record_5 is not record_5)
adjusted_record_6 = sg_util.GetAdjustedInteractionIfContainGesture(
model, record_6)
self.assertEquals(adjusted_record_6.start, 15)
self.assertEquals(adjusted_record_6.end, 25)
self.assertTrue(adjusted_record_6 is not record_6)
def _AddAsyncSlice(self, renderer_thread, category, name, start, end):
s = async_slice.AsyncSlice(
category, name,
timestamp=start, duration=end - start, start_thread=renderer_thread,
end_thread=renderer_thread)
renderer_thread.AddAsyncSlice(s)
def AddInteraction(self, thread, marker='', ts=0, duration=5):
assert thread in (self._renderer_thread, self._foo_thread)
thread.async_slices.append(async_slice.AsyncSlice(
'category', marker, timestamp=ts, duration=duration,
start_thread=self._renderer_thread, end_thread=self._renderer_thread,
thread_start=ts, thread_duration=duration))
def CreateSimpleRecordWithName(self, event_name):
s = async_slice.AsyncSlice(
'cat', event_name,
timestamp=0, duration=200, thread_start=20, thread_duration=100)
return tir_module.TimelineInteractionRecord.FromAsyncEvent(s)
