Chromium Code Reviews| OLD | NEW |
|---|---|
| 1 # Copyright 2015 The Chromium Authors. All rights reserved. | 1 # Copyright 2015 The Chromium Authors. All rights reserved. |
| 2 # Use of this source code is governed by a BSD-style license that can be | 2 # Use of this source code is governed by a BSD-style license that can be |
| 3 # found in the LICENSE file. | 3 # found in the LICENSE file. |
| 4 | 4 |
| 5 from telemetry.page import page_test | 5 from telemetry.page import page_test |
| 6 from telemetry.timeline.model import TimelineModel | |
| 7 from telemetry.timeline import tracing_category_filter | 6 from telemetry.timeline import tracing_category_filter |
| 8 from telemetry.timeline import tracing_options | 7 from telemetry.web_perf import timeline_based_measurement |
| 9 from telemetry.util import statistics | 8 from metrics import v8_gc_times_metric |
| 10 from telemetry.value import scalar | 9 |
| 10 | |
| 11 class _CustomResultsWrapper(timeline_based_measurement.ResultsWrapperInterface): | |
|
eakuefner
2015/10/15 15:58:35
Please don't use a results wrapper. This has been
| |
| 12 def __init__(self): | |
| 13 super(_CustomResultsWrapper, self).__init__() | |
| 14 self._pages_to_tir_labels = {} | |
| 15 | |
| 16 def _AssertNewValueHasSameInteractionLabel(self, new_value): | |
| 17 tir_label = self._pages_to_tir_labels.get(new_value.page) | |
| 18 if tir_label: | |
| 19 assert tir_label == self._tir_label, ( | |
| 20 'V8GCTimes measurement do not support multiple interaction record ' | |
| 21 'labels per page yet. See crbug.com/453109 for more information.') | |
| 22 else: | |
| 23 self._pages_to_tir_labels[new_value.page] = self._tir_label | |
| 24 | |
| 25 def AddValue(self, value): | |
| 26 self._AssertNewValueHasSameInteractionLabel(value) | |
| 27 self._results.AddValue(value) | |
| 11 | 28 |
| 12 | 29 |
| 13 class V8GCTimes(page_test.PageTest): | 30 class V8GCTimes(page_test.PageTest): |
| 14 | |
| 15 _TIME_OUT_IN_SECONDS = 60 | |
| 16 _CATEGORIES = ['blink.console', | 31 _CATEGORIES = ['blink.console', |
| 17 'renderer.scheduler', | 32 'renderer.scheduler', |
| 18 'v8', | 33 'v8', |
| 19 'webkit.console'] | 34 'webkit.console'] |
| 20 _RENDERER_MAIN_THREAD = 'CrRendererMain' | 35 def __init__(self, needs_browser_restart_after_each_page=False): |
| 21 _IDLE_TASK_PARENT = 'SingleThreadIdleTaskRunner::RunTask' | 36 super(V8GCTimes, self).__init__(needs_browser_restart_after_each_page) |
| 22 | 37 self._tbm = None |
| 23 def __init__(self): | |
| 24 super(V8GCTimes, self).__init__() | |
| 25 | 38 |
| 26 def WillNavigateToPage(self, page, tab): | 39 def WillNavigateToPage(self, page, tab): |
| 27 category_filter = tracing_category_filter.TracingCategoryFilter() | 40 category_filter = tracing_category_filter.TracingCategoryFilter() |
| 28 | 41 |
| 29 for category in self._CATEGORIES: | 42 for category in self._CATEGORIES: |
| 30 category_filter.AddIncludedCategory(category) | 43 category_filter.AddIncludedCategory(category) |
| 31 | 44 |
| 32 options = tracing_options.TracingOptions() | 45 options = timeline_based_measurement.Options(category_filter) |
| 33 options.enable_chrome_trace = True | 46 options.SetTimelineBasedMetrics([v8_gc_times_metric.V8GCTimesMetric()]) |
| 47 self._tbm = timeline_based_measurement.TimelineBasedMeasurement( | |
| 48 options, _CustomResultsWrapper()) | |
| 49 self._tbm.WillRunStory(tab.browser.platform) | |
| 34 | 50 |
| 35 tab.browser.platform.tracing_controller.Start( | 51 def ValidateAndMeasurePage(self, _, tab, results): |
| 36 options, category_filter, self._TIME_OUT_IN_SECONDS) | 52 self._tbm.Measure(tab.browser.platform, results) |
| 37 | |
| 38 def ValidateAndMeasurePage(self, page, tab, results): | |
| 39 trace_data = tab.browser.platform.tracing_controller.Stop() | |
| 40 timeline_model = TimelineModel(trace_data) | |
| 41 renderer_process = timeline_model.GetRendererProcessFromTabId(tab.id) | |
| 42 self._AddV8MetricsToResults(renderer_process, results) | |
| 43 | 53 |
| 44 def DidRunPage(self, platform): | 54 def DidRunPage(self, platform): |
| 45 if platform.tracing_controller.is_tracing_running: | 55 if self._tbm: |
| 46 platform.tracing_controller.Stop() | 56 self._tbm.DidRunStory(platform) |
| 47 | |
| 48 def _AddV8MetricsToResults(self, process, results): | |
| 49 if process is None: | |
| 50 return | |
| 51 | |
| 52 for thread in process.threads.values(): | |
| 53 if thread.name != self._RENDERER_MAIN_THREAD: | |
| 54 continue | |
| 55 | |
| 56 self._AddV8EventStatsToResults(thread, results) | |
| 57 self._AddCpuTimeStatsToResults(thread, results) | |
| 58 | |
| 59 def _AddV8EventStatsToResults(self, thread, results): | |
| 60 v8_event_stats = [ | |
| 61 V8EventStat('V8.GCIncrementalMarking', | |
| 62 'v8_gc_incremental_marking', | |
| 63 'incremental marking steps'), | |
| 64 V8EventStat('V8.GCScavenger', | |
| 65 'v8_gc_scavenger', | |
| 66 'scavenges'), | |
| 67 V8EventStat('V8.GCCompactor', | |
| 68 'v8_gc_mark_compactor', | |
| 69 'mark-sweep-compactor')] | |
| 70 # Find all V8 GC events in the trace. | |
| 71 for event in thread.IterAllSlices(): | |
| 72 event_stat = _FindV8EventStatForEvent(v8_event_stats, event.name) | |
| 73 if not event_stat: | |
| 74 continue | |
| 75 | |
| 76 event_stat.thread_duration += event.thread_duration | |
| 77 event_stat.max_thread_duration = max(event_stat.max_thread_duration, | |
| 78 event.thread_duration) | |
| 79 event_stat.count += 1 | |
| 80 | |
| 81 parent_idle_task = _ParentIdleTask(event) | |
| 82 if parent_idle_task: | |
| 83 allotted_idle_time = parent_idle_task.args['allotted_time_ms'] | |
| 84 idle_task_wall_overrun = 0 | |
| 85 if event.duration > allotted_idle_time: | |
| 86 idle_task_wall_overrun = event.duration - allotted_idle_time | |
| 87 # Don't count time over the deadline as being inside idle time. | |
| 88 # Since the deadline should be relative to wall clock we compare | |
| 89 # allotted_time_ms with wall duration instead of thread duration, and | |
| 90 # then assume the thread duration was inside idle for the same | |
| 91 # percentage of time. | |
| 92 inside_idle = event.thread_duration * statistics.DivideIfPossibleOrZero( | |
| 93 event.duration - idle_task_wall_overrun, event.duration) | |
| 94 event_stat.thread_duration_inside_idle += inside_idle | |
| 95 event_stat.idle_task_overrun_duration += idle_task_wall_overrun | |
| 96 | |
| 97 for v8_event_stat in v8_event_stats: | |
| 98 results.AddValue(scalar.ScalarValue( | |
| 99 results.current_page, v8_event_stat.result_name, 'ms', | |
| 100 v8_event_stat.thread_duration, | |
| 101 description=('Total thread duration spent in %s' % | |
| 102 v8_event_stat.result_description))) | |
| 103 results.AddValue(scalar.ScalarValue( | |
| 104 results.current_page, '%s_max' % v8_event_stat.result_name, 'ms', | |
| 105 v8_event_stat.max_thread_duration, | |
| 106 description=('Max thread duration spent in %s' % | |
| 107 v8_event_stat.result_description))) | |
| 108 results.AddValue(scalar.ScalarValue( | |
| 109 results.current_page, '%s_count' % v8_event_stat.result_name, 'count', | |
| 110 v8_event_stat.count, | |
| 111 description=('Number of %s' % | |
| 112 v8_event_stat.result_description))) | |
| 113 average_thread_duration = statistics.DivideIfPossibleOrZero( | |
| 114 v8_event_stat.thread_duration, v8_event_stat.count) | |
| 115 results.AddValue(scalar.ScalarValue( | |
| 116 results.current_page, '%s_average' % v8_event_stat.result_name, 'ms', | |
| 117 average_thread_duration, | |
| 118 description=('Average thread duration spent in %s' % | |
| 119 v8_event_stat.result_description))) | |
| 120 results.AddValue(scalar.ScalarValue(results.current_page, | |
| 121 '%s_outside_idle' % v8_event_stat.result_name, 'ms', | |
| 122 v8_event_stat.thread_duration_outside_idle, | |
| 123 description=( | |
| 124 'Total thread duration spent in %s outside of idle tasks' % | |
| 125 v8_event_stat.result_description))) | |
| 126 results.AddValue(scalar.ScalarValue(results.current_page, | |
| 127 '%s_idle_deadline_overrun' % v8_event_stat.result_name, 'ms', | |
| 128 v8_event_stat.idle_task_overrun_duration, | |
| 129 description=('Total idle task deadline overrun for %s idle tasks' | |
| 130 % v8_event_stat.result_description))) | |
| 131 results.AddValue(scalar.ScalarValue(results.current_page, | |
| 132 '%s_percentage_idle' % v8_event_stat.result_name, 'idle%', | |
| 133 v8_event_stat.percentage_thread_duration_during_idle, | |
| 134 description=('Percentage of %s spent in idle time' % | |
| 135 v8_event_stat.result_description))) | |
| 136 | |
| 137 # Add total metrics. | |
| 138 gc_total = sum(x.thread_duration for x in v8_event_stats) | |
| 139 gc_total_outside_idle = sum( | |
| 140 x.thread_duration_outside_idle for x in v8_event_stats) | |
| 141 gc_total_idle_deadline_overrun = sum( | |
| 142 x.idle_task_overrun_duration for x in v8_event_stats) | |
| 143 gc_total_percentage_idle = statistics.DivideIfPossibleOrZero( | |
| 144 100 * (gc_total - gc_total_outside_idle), gc_total) | |
| 145 | |
| 146 results.AddValue(scalar.ScalarValue(results.current_page, | |
| 147 'v8_gc_total', 'ms', gc_total, | |
| 148 description='Total thread duration of all garbage collection events')) | |
| 149 results.AddValue(scalar.ScalarValue(results.current_page, | |
| 150 'v8_gc_total_outside_idle', 'ms', gc_total_outside_idle, | |
| 151 description=( | |
| 152 'Total thread duration of all garbage collection events outside of ' | |
| 153 'idle tasks'))) | |
| 154 results.AddValue(scalar.ScalarValue(results.current_page, | |
| 155 'v8_gc_total_idle_deadline_overrun', 'ms', | |
| 156 gc_total_idle_deadline_overrun, | |
| 157 description=( | |
| 158 'Total idle task deadline overrun for all idle tasks garbage ' | |
| 159 'collection events'))) | |
| 160 results.AddValue(scalar.ScalarValue(results.current_page, | |
| 161 'v8_gc_total_percentage_idle', 'idle%', gc_total_percentage_idle, | |
| 162 description=( | |
| 163 'Percentage of the thread duration of all garbage collection ' | |
| 164 'events spent inside of idle tasks'))) | |
| 165 | |
| 166 def _AddCpuTimeStatsToResults(self, thread, results): | |
| 167 if thread.toplevel_slices: | |
| 168 start_time = min(s.start for s in thread.toplevel_slices) | |
| 169 end_time = max(s.end for s in thread.toplevel_slices) | |
| 170 duration = end_time - start_time | |
| 171 cpu_time = sum(s.thread_duration for s in thread.toplevel_slices) | |
| 172 else: | |
| 173 duration = cpu_time = 0 | |
| 174 | |
| 175 results.AddValue(scalar.ScalarValue( | |
| 176 results.current_page, 'duration', 'ms', duration)) | |
| 177 results.AddValue(scalar.ScalarValue( | |
| 178 results.current_page, 'cpu_time', 'ms', cpu_time)) | |
| 179 | |
| 180 | |
| 181 def _FindV8EventStatForEvent(v8_event_stats_list, event_name): | |
| 182 for v8_event_stat in v8_event_stats_list: | |
| 183 if v8_event_stat.src_event_name == event_name: | |
| 184 return v8_event_stat | |
| 185 return None | |
| 186 | |
| 187 | |
| 188 def _ParentIdleTask(event): | |
| 189 parent = event.parent_slice | |
| 190 while parent: | |
| 191 # pylint: disable=protected-access | |
| 192 if parent.name == V8GCTimes._IDLE_TASK_PARENT: | |
| 193 return parent | |
| 194 parent = parent.parent_slice | |
| 195 return None | |
| 196 | |
| 197 | |
| 198 class V8EventStat(object): | |
| 199 | |
| 200 def __init__(self, src_event_name, result_name, result_description): | |
| 201 self.src_event_name = src_event_name | |
| 202 self.result_name = result_name | |
| 203 self.result_description = result_description | |
| 204 self.thread_duration = 0.0 | |
| 205 self.thread_duration_inside_idle = 0.0 | |
| 206 self.idle_task_overrun_duration = 0.0 | |
| 207 self.max_thread_duration = 0.0 | |
| 208 self.count = 0 | |
| 209 | |
| 210 @property | |
| 211 def thread_duration_outside_idle(self): | |
| 212 return self.thread_duration - self.thread_duration_inside_idle | |
| 213 | |
| 214 @property | |
| 215 def percentage_thread_duration_during_idle(self): | |
| 216 return statistics.DivideIfPossibleOrZero( | |
| 217 100 * self.thread_duration_inside_idle, self.thread_duration) | |
| OLD | NEW |