tools/perf/measurements/task_execution_time.py

   1 # Copyright 2014 The Chromium Authors. All rights reserved.
   2 # Use of this source code is governed by a BSD-style license that can be
   3 # found in the LICENSE file.
   4
   5 from collections import namedtuple
   6 from telemetry.core.platform import tracing_category_filter
   7 from telemetry.core.platform import tracing_options
   8 from telemetry.page import page_test
   9 from telemetry.timeline.model import TimelineModel
  10 from telemetry.util import statistics
  11 from telemetry.value import scalar
  12
  13 # Set up named tuple to use as dictionary key.
  14 TaskKey = namedtuple('TaskKey', 'name section')
  15
  16
  17 class TaskExecutionTime(page_test.PageTest):
  18
  19   IDLE_SECTION_TRIGGER = 'SingleThreadIdleTaskRunner::RunTask'
  20   IDLE_SECTION = 'IDLE'
  21
  22   _TIME_OUT_IN_SECONDS = 60
  23   _NUMBER_OF_RESULTS_TO_DISPLAY = 10
  24   _BROWSER_THREADS = ['Chrome_ChildIOThread',
  25                       'Chrome_IOThread']
  26   _RENDERER_THREADS = ['Chrome_ChildIOThread',
  27                        'Chrome_IOThread',
  28                        'CrRendererMain']
  29   _CATEGORIES = ['benchmark',
  30                  'blink',
  31                  'blink.console',
  32                  'blink_gc',
  33                  'cc',
  34                  'gpu',
  35                  'ipc',
  36                  'renderer.scheduler',
  37                  'toplevel',
  38                  'v8',
  39                  'webkit.console']
  40
  41   def __init__(self):
  42     super(TaskExecutionTime, self).__init__('RunPageInteractions')
  43     self._renderer_process = None
  44     self._browser_process = None
  45     self._results = None
  46
  47   def WillNavigateToPage(self, page, tab):
  48     category_filter = tracing_category_filter.TracingCategoryFilter()
  49
  50     for category in self._CATEGORIES:
  51       category_filter.AddIncludedCategory(category)
  52
  53     options = tracing_options.TracingOptions()
  54     options.enable_chrome_trace = True
  55
  56     tab.browser.platform.tracing_controller.Start(
  57         options, category_filter, self._TIME_OUT_IN_SECONDS)
  58
  59   def DidRunActions(self, page, tab):
  60     trace_data = tab.browser.platform.tracing_controller.Stop()
  61     timeline_model = TimelineModel(trace_data)
  62
  63     self._renderer_process = timeline_model.GetRendererProcessFromTabId(tab.id)
  64     self._browser_process = timeline_model.browser_process
  65
  66   def ValidateAndMeasurePage(self, page, tab, results):
  67     self._results = results
  68
  69     for thread in self._BROWSER_THREADS:
  70       self._AddTasksFromThreadToResults(self._browser_process, thread)
  71
  72     for thread in self._RENDERER_THREADS:
  73       self._AddTasksFromThreadToResults(self._renderer_process, thread)
  74
  75   def _AddTasksFromThreadToResults(self, process, thread_name):
  76     if process is None:
  77       return
  78
  79     tasks = TaskExecutionTime._GetTasksForThread(process, thread_name)
  80
  81     # Pull out all the unique sections used by the returned tasks.
  82     sections = set([key.section for key in tasks.iterkeys()])
  83
  84     # Remove sections we don't care about (currently just Idle tasks).
  85     if TaskExecutionTime.IDLE_SECTION in sections:
  86       sections.remove(TaskExecutionTime.IDLE_SECTION)
  87
  88     # Create top N list for each section. Note: This nested loop (n-squared)
  89     # solution will become inefficient as the number of sections grows.
  90     # Consider a refactor to pre-split the tasks into section buckets if this
  91     # happens and performance becomes an isssue.
  92     for section in sections:
  93       task_list = [tasks[key] for key in tasks if key.section == section]
  94       self._AddSlowestTasksToResults(task_list)
  95
  96   def _AddSlowestTasksToResults(self, tasks):
  97     sorted_tasks = sorted(
  98         tasks,
  99         key=lambda slice: slice.median_self_duration,
 100         reverse=True)
 101
 102     for task in sorted_tasks[:self.GetExpectedResultCount()]:
 103       self._results.AddValue(scalar.ScalarValue(
 104           self._results.current_page,
 105           task.name,
 106           'ms',
 107           task.median_self_duration,
 108           description='Slowest tasks'))
 109
 110   @staticmethod
 111   def _GetTasksForThread(process, target_thread):
 112     task_durations = {}
 113
 114     for thread in process.threads.values():
 115       if thread.name != target_thread:
 116         continue
 117       for task_slice in thread.IterAllSlices():
 118         _ProcessTasksForThread(
 119             task_durations,
 120             process.name + ':' + thread.name,
 121             task_slice)
 122
 123     return task_durations
 124
 125   @staticmethod
 126   def GetExpectedResultCount():
 127     return TaskExecutionTime._NUMBER_OF_RESULTS_TO_DISPLAY
 128
 129
 130 def _ProcessTasksForThread(
 131     task_durations,
 132     thread_name,
 133     task_slice,
 134     section=None):
 135   if task_slice.self_thread_time is None:
 136     # Early out if this slice is a TRACE_EVENT_INSTANT, as it has no duration.
 137     return
 138
 139   # Note: By setting a different section below we split off this task into
 140   # a different sorting bucket. Too add extra granularity (e.g. tasks executed
 141   # during page loading) add logic to set a different section name here. The
 142   # section name is set before the slice's data is recorded so the triggering
 143   # event will be included in its own section (i.e. the idle trigger will be
 144   # recorded as an idle event).
 145
 146   if task_slice.name == TaskExecutionTime.IDLE_SECTION_TRIGGER:
 147     section = TaskExecutionTime.IDLE_SECTION
 148
 149   # Add the thread name and section (e.g. 'Idle') to the test name
 150   # so it is human-readable.
 151   reported_name = thread_name + ':'
 152   if section:
 153     reported_name += section + ':'
 154
 155   if 'src_func' in task_slice.args:
 156     # Data contains the name of the timed function, use it as the name.
 157     reported_name += task_slice.args['src_func']
 158   elif 'line' in task_slice.args:
 159     # Data contains IPC class and line numbers, use these as the name.
 160     reported_name += 'IPC_Class_' + str(task_slice.args['class'])
 161     reported_name += ':Line_' + str(task_slice.args['line'])
 162   else:
 163     # Fallback to use the name of the task slice.
 164     reported_name += task_slice.name.lower()
 165
 166   # Replace any '.'s with '_'s as V8 uses them and it confuses the dashboard.
 167   reported_name = reported_name.replace('.', '_')
 168
 169   # Use the name and section as the key to bind identical entries. The section
 170   # is tracked separately so results can be easily split up across section
 171   # boundaries (e.g. Idle Vs Not-idle) for top-10 generation even if the name
 172   # of the task is identical.
 173   dictionary_key = TaskKey(reported_name, section)
 174   self_duration = task_slice.self_thread_time
 175
 176   if dictionary_key in task_durations:
 177     # Task_durations already contains an entry for this (e.g. from an earlier
 178     # slice), add the new duration so we can calculate a median value later on.
 179     task_durations[dictionary_key].Update(self_duration)
 180   else:
 181     # This is a new task so create a new entry for it.
 182     task_durations[dictionary_key] = SliceNameAndDurations(
 183         reported_name,
 184         self_duration)
 185
 186   # Process sub slices recursively, passing the current section down.
 187   for sub_slice in task_slice.sub_slices:
 188     _ProcessTasksForThread(
 189         task_durations,
 190         thread_name,
 191         sub_slice,
 192         section)
 193
 194
 195 class SliceNameAndDurations:
 196
 197   def __init__(self, name, self_duration):
 198     self.name = name
 199     self.self_durations = [self_duration]
 200
 201   def Update(self, self_duration):
 202     self.self_durations.append(self_duration)
 203
 204   @property
 205   def median_self_duration(self):
 206     return statistics.Median(self.self_durations)