tools/perf/measurements/v8_gc_times_unittest.py

   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
   3 # found in the LICENSE file.
   4
   5 from telemetry import decorators
   6 from telemetry.internal.results import page_test_results
   7 from telemetry.page import page as page_module
   8 from telemetry.testing import options_for_unittests
   9 from telemetry.testing import page_test_test_case
  10 from telemetry.timeline import model as model_module
  11 from telemetry.util import wpr_modes
  12
  13 from measurements import v8_gc_times
  14
  15
  16 class V8GCTimesTestPageHelper(object):
  17
  18   def __init__(self, page_set):
  19     self._page_set = page_set
  20     self._model = model_module.TimelineModel()
  21     self._renderer_process = self._model.GetOrCreateProcess(1)
  22     self._renderer_thread = self._renderer_process.GetOrCreateThread(2)
  23     self._renderer_thread.name = 'CrRendererMain'
  24
  25   def AddEvent(self, category, name, thread_start, thread_duration,
  26                args=None, wall_start=None, wall_duration=None):
  27     wall_start = wall_start or thread_start
  28     wall_duration = wall_duration or thread_duration
  29     self._renderer_thread.BeginSlice(category, name, wall_start, thread_start,
  30                                      args=args)
  31     self._renderer_thread.EndSlice(wall_start + wall_duration,
  32                                    thread_start + thread_duration)
  33
  34   class MockV8GCTimesPage(page_module.Page):
  35
  36     def __init__(self, page_set):
  37       super(V8GCTimesTestPageHelper.MockV8GCTimesPage, self).__init__(
  38           'file://blank.html', page_set, page_set.base_dir)
  39
  40   def MeasureFakePage(self):
  41     # Create a fake page and add it to the page set.
  42     results = page_test_results.PageTestResults()
  43     page = V8GCTimesTestPageHelper.MockV8GCTimesPage(self._page_set)
  44     self._page_set.AddStory(page)
  45
  46     # Pretend we're about to run the tests to silence lower level asserts.
  47     results.WillRunPage(page)
  48
  49     v8_gc_times_metric = v8_gc_times.V8GCTimes()
  50     # pylint: disable=protected-access
  51     v8_gc_times_metric._renderer_process = self._renderer_process
  52
  53     # Finalize the timeline import.
  54     self._model.FinalizeImport()
  55
  56     # Measure the V8GCTimes metric and return the results
  57     # pylint: disable=protected-access
  58     v8_gc_times_metric._AddV8MetricsToResults(self._renderer_process, results)
  59     results.DidRunPage(page)
  60     return results
  61
  62
  63 class V8GCTimesTests(page_test_test_case.PageTestTestCase):
  64
  65   def setUp(self):
  66     self._options = options_for_unittests.GetCopy()
  67     self._options.browser_options.wpr_mode = wpr_modes.WPR_OFF
  68
  69   def testWithNoTraceEvents(self):
  70     test_page_helper = V8GCTimesTestPageHelper(
  71         self.CreateEmptyPageSet())
  72
  73     results = test_page_helper.MeasureFakePage()
  74     self._AssertResultsEqual(_GetEmptyResults(), _ActualValues(results))
  75
  76   def testWithNoGarbageCollectionEvents(self):
  77     test_page_helper = V8GCTimesTestPageHelper(
  78         self.CreateEmptyPageSet())
  79
  80     test_page_helper.AddEvent('toplevel', 'PostMessage',
  81         thread_start=0, thread_duration=14, wall_start=5, wall_duration=35)
  82
  83     results = test_page_helper.MeasureFakePage()
  84     expected = _GetEmptyResults()
  85     expected['duration'] = ('ms', 35)
  86     expected['cpu_time'] = ('ms', 14)
  87
  88     self._AssertResultsEqual(expected, _ActualValues(results))
  89
  90   def testWithGarbageCollectionEvents(self):
  91     test_page_helper = V8GCTimesTestPageHelper(
  92         self.CreateEmptyPageSet())
  93
  94     test_page_helper.AddEvent('toplevel', 'PostMessage',
  95         thread_start=0, thread_duration=57, wall_start=5, wall_duration=68)
  96     test_page_helper.AddEvent('v8', 'V8.GCScavenger', 5, 4)
  97     test_page_helper.AddEvent('v8', 'V8.GCScavenger', 15, 3)
  98     test_page_helper.AddEvent('v8', 'V8.GCIncrementalMarking', 23, 4)
  99     test_page_helper.AddEvent('v8', 'V8.GCIncrementalMarking', 34, 2)
 100     test_page_helper.AddEvent('v8', 'V8.GCCompactor', 42, 4)
 101     test_page_helper.AddEvent('v8', 'V8.GCCompactor', 52, 5)
 102
 103     results = test_page_helper.MeasureFakePage()
 104     expected = _GetEmptyResults()
 105     expected['duration'] = ('ms', 68)
 106     expected['cpu_time'] = ('ms', 57)
 107     expected['v8_gc_incremental_marking'] = ('ms', 6.0)
 108     expected['v8_gc_incremental_marking_outside_idle'] = ('ms', 6.0)
 109     expected['v8_gc_scavenger'] = ('ms', 7.0)
 110     expected['v8_gc_scavenger_outside_idle'] = ('ms', 7.0)
 111     expected['v8_gc_mark_compactor'] = ('ms', 9.0)
 112     expected['v8_gc_mark_compactor_outside_idle'] = ('ms', 9.0)
 113     expected['v8_gc_total'] = ('ms', 22.0)
 114     expected['v8_gc_total_outside_idle'] = ('ms', 22.0)
 115
 116     self._AssertResultsEqual(expected, _ActualValues(results))
 117
 118   def testWithIdleTaskGarbageCollectionEvents(self):
 119     test_page_helper = V8GCTimesTestPageHelper(
 120         self.CreateEmptyPageSet())
 121
 122     test_page_helper.AddEvent('toplevel', 'PostMessage',
 123         thread_start=0, thread_duration=57, wall_start=5, wall_duration=68)
 124
 125     test_page_helper.AddEvent('v8', 'V8.GCScavenger', 5, 4)
 126     test_page_helper.AddEvent('renderer.scheduler',
 127         'SingleThreadIdleTaskRunner::RunTask', 15, 4, {'allotted_time_ms': 12})
 128     test_page_helper.AddEvent('v8', 'V8.GCScavenger', 15, 3)
 129
 130     test_page_helper.AddEvent('v8', 'V8.GCIncrementalMarking', 23, 4)
 131     test_page_helper.AddEvent('renderer.scheduler',
 132         'SingleThreadIdleTaskRunner::RunTask', 34, 3, {'allotted_time_ms': 12})
 133     test_page_helper.AddEvent('v8', 'V8.GCIncrementalMarking', 34, 2)
 134
 135     test_page_helper.AddEvent('v8', 'V8.GCCompactor', 42, 4)
 136     test_page_helper.AddEvent('renderer.scheduler',
 137         'SingleThreadIdleTaskRunner::RunTask', 52, 6, {'allotted_time_ms': 12})
 138     test_page_helper.AddEvent('v8', 'V8.GCCompactor', 52, 5)
 139
 140     results = test_page_helper.MeasureFakePage()
 141     expected = _GetEmptyResults()
 142     expected['duration'] = ('ms', 68)
 143     expected['cpu_time'] = ('ms', 57)
 144     expected['v8_gc_incremental_marking'] = ('ms', 6.0)
 145     expected['v8_gc_incremental_marking_outside_idle'] = ('ms', 4.0)
 146     expected['v8_gc_incremental_marking_percentage_idle'] = \
 147         ('idle%', 100 * 2 / 6.0)
 148     expected['v8_gc_scavenger'] = ('ms', 7.0)
 149     expected['v8_gc_scavenger_outside_idle'] = ('ms', 4.0)
 150     expected['v8_gc_scavenger_percentage_idle'] = ('idle%', 100 * 3 / 7.0)
 151     expected['v8_gc_mark_compactor'] = ('ms', 9.0)
 152     expected['v8_gc_mark_compactor_outside_idle'] = ('ms', 4.0)
 153     expected['v8_gc_mark_compactor_percentage_idle'] = ('idle%', 100 * 5 / 9.0)
 154     expected['v8_gc_total'] = ('ms', 22.0)
 155     expected['v8_gc_total_outside_idle'] = ('ms', 12.0)
 156     expected['v8_gc_total_percentage_idle'] = ('idle%', 100 * 10 / 22.0)
 157
 158     self._AssertResultsEqual(expected, _ActualValues(results))
 159
 160   def testWithIdleTaskOverruns(self):
 161     test_page_helper = V8GCTimesTestPageHelper(
 162         self.CreateEmptyPageSet())
 163
 164     test_page_helper.AddEvent('toplevel', 'PostMessage',
 165         thread_start=0, thread_duration=80, wall_start=5, wall_duration=92)
 166
 167     test_page_helper.AddEvent('renderer.scheduler',
 168         'SingleThreadIdleTaskRunner::RunTask', 15, 15, {'allotted_time_ms': 8})
 169     test_page_helper.AddEvent('v8', 'V8.GCScavenger', 15, 14)
 170
 171     test_page_helper.AddEvent('renderer.scheduler',
 172         'SingleThreadIdleTaskRunner::RunTask', 34, 15, {'allotted_time_ms': 6})
 173     test_page_helper.AddEvent('v8', 'V8.GCIncrementalMarking', 34, 14)
 174
 175     test_page_helper.AddEvent('renderer.scheduler',
 176         'SingleThreadIdleTaskRunner::RunTask', 52, 23, {'allotted_time_ms': 9})
 177     test_page_helper.AddEvent('v8', 'V8.GCCompactor', 52, 22)
 178
 179     results = test_page_helper.MeasureFakePage()
 180     expected = _GetEmptyResults()
 181     expected['duration'] = ('ms', 92)
 182     expected['cpu_time'] = ('ms', 80)
 183     expected['v8_gc_incremental_marking'] = ('ms', 14.0)
 184     expected['v8_gc_incremental_marking_outside_idle'] = ('ms', 8.0)
 185     expected['v8_gc_incremental_marking_idle_deadline_overrun'] = ('ms', 8.0)
 186     expected['v8_gc_incremental_marking_percentage_idle'] = \
 187         ('idle%', 100 * 6 / 14.0)
 188     expected['v8_gc_scavenger'] = ('ms', 14.0)
 189     expected['v8_gc_scavenger_outside_idle'] = ('ms', 6.0)
 190     expected['v8_gc_scavenger_idle_deadline_overrun'] = ('ms', 6.0)
 191     expected['v8_gc_scavenger_percentage_idle'] = ('idle%', 100 * 8 / 14.0)
 192     expected['v8_gc_mark_compactor'] = ('ms', 22.0)
 193     expected['v8_gc_mark_compactor_outside_idle'] = ('ms', 13.0)
 194     expected['v8_gc_mark_compactor_idle_deadline_overrun'] = ('ms', 13.0)
 195     expected['v8_gc_mark_compactor_percentage_idle'] = ('idle%', 100 * 9 / 22.0)
 196     expected['v8_gc_total'] = ('ms', 50.0)
 197     expected['v8_gc_total_outside_idle'] = ('ms', 27.0)
 198     expected['v8_gc_total_idle_deadline_overrun'] = ('ms', 27.0)
 199     expected['v8_gc_total_percentage_idle'] = ('idle%', 100 * 23 / 50.0)
 200
 201     self._AssertResultsEqual(expected, _ActualValues(results))
 202
 203   def testWithIdleTaskWallDurationOverruns(self):
 204     test_page_helper = V8GCTimesTestPageHelper(
 205         self.CreateEmptyPageSet())
 206
 207     test_page_helper.AddEvent('toplevel', 'PostMessage',
 208         thread_start=0, thread_duration=80, wall_start=5, wall_duration=92)
 209
 210     test_page_helper.AddEvent('renderer.scheduler',
 211         'SingleThreadIdleTaskRunner::RunTask', 15, 15, {'allotted_time_ms': 8})
 212     test_page_helper.AddEvent('v8', 'V8.GCScavenger',
 213         thread_start=15, thread_duration=4, wall_start=15, wall_duration=14)
 214
 215     results = test_page_helper.MeasureFakePage()
 216     expected = _GetEmptyResults()
 217     expected['duration'] = ('ms', 92)
 218     expected['cpu_time'] = ('ms', 80)
 219     expected['v8_gc_scavenger'] = ('ms', 4.0)
 220     expected_outside_idle = 4.0 - (4.0 * 8 / 14)
 221     expected['v8_gc_scavenger_outside_idle'] = ('ms', expected_outside_idle)
 222     expected['v8_gc_scavenger_idle_deadline_overrun'] = ('ms', 6.0)
 223     expected['v8_gc_scavenger_percentage_idle'] = \
 224         ('idle%', 100 * (4.0 - expected_outside_idle) / 4.0)
 225     expected['v8_gc_total'] = expected['v8_gc_scavenger']
 226     expected['v8_gc_total_outside_idle'] = \
 227         expected['v8_gc_scavenger_outside_idle']
 228     expected['v8_gc_total_idle_deadline_overrun'] = \
 229         expected['v8_gc_scavenger_idle_deadline_overrun']
 230     expected['v8_gc_total_percentage_idle'] = \
 231         expected['v8_gc_scavenger_percentage_idle']
 232
 233     self._AssertResultsEqual(expected, _ActualValues(results))
 234
 235   def _AssertResultsEqual(self, expected, actual):
 236     for key in expected.iterkeys():
 237       self.assertIn(key, actual.keys())
 238       self.assertEqual(expected[key], actual[key],
 239           'Result for [' + key + '] - expected ' + str(expected[key]) +
 240           ' but got ' + str(actual[key]))
 241
 242   @decorators.Disabled('win')  # crbug.com/416502
 243   def testCleanUpTrace(self):
 244     self.TestTracingCleanedUp(v8_gc_times.V8GCTimes, self._options)
 245
 246
 247 def _ActualValues(results):
 248   return dict(list(
 249       (v.name, (v.units, v.value))
 250       for v in results.all_page_specific_values
 251       ))
 252
 253
 254 def _GetEmptyResults():
 255   return {'cpu_time': ('ms', 0.0),
 256           'duration': ('ms', 0.0),
 257           'v8_gc_incremental_marking': ('ms', 0.0),
 258           'v8_gc_incremental_marking_idle_deadline_overrun': ('ms', 0.0),
 259           'v8_gc_incremental_marking_outside_idle': ('ms', 0.0),
 260           'v8_gc_incremental_marking_percentage_idle': ('idle%', 0.0),
 261           'v8_gc_mark_compactor': ('ms', 0.0),
 262           'v8_gc_mark_compactor_idle_deadline_overrun': ('ms', 0.0),
 263           'v8_gc_mark_compactor_outside_idle': ('ms', 0.0),
 264           'v8_gc_mark_compactor_percentage_idle': ('idle%', 0.0),
 265           'v8_gc_scavenger': ('ms', 0.0),
 266           'v8_gc_scavenger_idle_deadline_overrun': ('ms', 0.0),
 267           'v8_gc_scavenger_outside_idle': ('ms', 0.0),
 268           'v8_gc_scavenger_percentage_idle': ('idle%', 0.0),
 269           'v8_gc_total': ('ms', 0.0),
 270           'v8_gc_total_idle_deadline_overrun': ('ms', 0.0),
 271           'v8_gc_total_outside_idle': ('ms', 0.0)}