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)