| OLD | NEW |
| (Empty) |
| 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 import logging | |
| 6 import StringIO | |
| 7 import unittest | |
| 8 | |
| 9 from telemetry.results import page_test_results | |
| 10 from telemetry.timeline import model as model_module | |
| 11 from telemetry.timeline import async_slice | |
| 12 from telemetry.web_perf import timeline_interaction_record as tir_module | |
| 13 from telemetry.web_perf.metrics import fast_metric | |
| 14 | |
| 15 | |
| 16 class RendererThreadHelper(object): | |
| 17 def __init__(self, wall_start, wall_duration, thread_start, thread_duration): | |
| 18 self._model = model_module.TimelineModel() | |
| 19 renderer_process = self._model.GetOrCreateProcess(1) | |
| 20 self._renderer_thread = renderer_process.GetOrCreateThread(2) | |
| 21 self._renderer_thread.name = 'CrRendererMain' | |
| 22 self._renderer_thread.BeginSlice('cat1', 'x.y', wall_start, thread_start) | |
| 23 self._renderer_thread.EndSlice(wall_start + wall_duration, | |
| 24 thread_start + thread_duration) | |
| 25 self._async_slices = [] | |
| 26 | |
| 27 def AddInteraction(self, logical_name='LogicalName', **kwargs): | |
| 28 # Rename kwargs for AsyncSlice. | |
| 29 kwargs['timestamp'] = kwargs.pop('wall_start') | |
| 30 kwargs['duration'] = kwargs.pop('wall_duration') | |
| 31 | |
| 32 self._async_slices.append(async_slice.AsyncSlice( | |
| 33 'cat', 'Interaction.%s/is_fast' % logical_name, | |
| 34 start_thread=self._renderer_thread, end_thread=self._renderer_thread, | |
| 35 **kwargs)) | |
| 36 | |
| 37 def AddEvent(self, category, name, wall_start, wall_duration, thread_start, | |
| 38 thread_duration): | |
| 39 self._renderer_thread.BeginSlice(category, name, wall_start, thread_start) | |
| 40 self._renderer_thread.EndSlice(wall_start + wall_duration, | |
| 41 thread_start + thread_duration) | |
| 42 | |
| 43 def MeasureFakePage(self, metric): | |
| 44 self._renderer_thread.async_slices.extend(self._async_slices) | |
| 45 self._model.FinalizeImport() | |
| 46 interaction_records = [ | |
| 47 tir_module.TimelineInteractionRecord.FromAsyncEvent(s) | |
| 48 for s in self._async_slices] | |
| 49 results = page_test_results.PageTestResults() | |
| 50 fake_page = None | |
| 51 results.WillRunPage(fake_page) | |
| 52 metric.AddResults(self._model, self._renderer_thread, interaction_records, | |
| 53 results) | |
| 54 results.DidRunPage(fake_page) | |
| 55 return results | |
| 56 | |
| 57 | |
| 58 class FastMetricTests(unittest.TestCase): | |
| 59 | |
| 60 def setUp(self): | |
| 61 self.log_output = StringIO.StringIO() | |
| 62 self.stream_handler = logging.StreamHandler(self.log_output) | |
| 63 logging.getLogger().addHandler(self.stream_handler) | |
| 64 | |
| 65 def tearDown(self): | |
| 66 logging.getLogger().removeHandler(self.stream_handler) | |
| 67 self.log_output.close() | |
| 68 | |
| 69 def LogOutput(self): | |
| 70 return self.log_output.getvalue() | |
| 71 | |
| 72 def ActualValues(self, results): | |
| 73 return sorted( | |
| 74 (v.name, v.units, v.value) | |
| 75 for v in results.all_page_specific_values | |
| 76 ) | |
| 77 | |
| 78 def testAddResultsWithThreadTime(self): | |
| 79 # Wall time diagram: | |
| 80 # 1 2 3 4 | |
| 81 # 01234567890123456789012345678901234567890123456789 | |
| 82 # [ x.y ] | |
| 83 # [ Interaction.LogicalName/is_fast ] | |
| 84 renderer_thread_helper = RendererThreadHelper( | |
| 85 wall_start=5, wall_duration=35, thread_start=0, thread_duration=54) | |
| 86 renderer_thread_helper.AddInteraction( | |
| 87 wall_start=32, wall_duration=37, thread_start=51, thread_duration=33) | |
| 88 | |
| 89 metric = fast_metric.FastMetric() | |
| 90 results = renderer_thread_helper.MeasureFakePage(metric) | |
| 91 | |
| 92 expected_values = [ | |
| 93 ('fast-cpu_time', 'ms', 3), # 54 - 51; thread overlap | |
| 94 ('fast-duration', 'ms', 37), # total interaction wall duration | |
| 95 ('fast-idle_time', 'ms', 29), # (32 + 37) - (5 + 35); interaction wall | |
| 96 # time outside of renderer wall time. | |
| 97 ('fast-incremental_marking', 'ms', 0.0), | |
| 98 ('fast-incremental_marking_outside_idle', 'ms', 0.0), | |
| 99 ('fast-mark_compactor', 'ms', 0.0), | |
| 100 ('fast-mark_compactor_outside_idle', 'ms', 0.0), | |
| 101 ('fast-scavenger', 'ms', 0.0), | |
| 102 ('fast-scavenger_outside_idle', 'ms', 0.0), | |
| 103 ('fast-total_garbage_collection', 'ms', 0.0), | |
| 104 ('fast-total_garbage_collection_outside_idle', 'ms', 0.0) | |
| 105 ] | |
| 106 self.assertEqual(expected_values, self.ActualValues(results)) | |
| 107 | |
| 108 def testAddResultsWithoutThreadTime(self): | |
| 109 # Wall time diagram: | |
| 110 # 1 2 3 4 | |
| 111 # 01234567890123456789012345678901234567890123456789 | |
| 112 # [ x.y ] | |
| 113 # [ Interaction.LogicalName/is_fast ] | |
| 114 renderer_thread_helper = RendererThreadHelper( | |
| 115 wall_start=5, wall_duration=35, thread_start=0, thread_duration=54) | |
| 116 renderer_thread_helper.AddInteraction( | |
| 117 wall_start=32, wall_duration=37) # no thread_start, no thread_duration | |
| 118 | |
| 119 metric = fast_metric.FastMetric() | |
| 120 results = renderer_thread_helper.MeasureFakePage(metric) | |
| 121 | |
| 122 expected_values = [ | |
| 123 # cpu_time is skipped because there is no thread time. | |
| 124 ('fast-duration', 'ms', 37), # total interaction wall duration | |
| 125 ('fast-idle_time', 'ms', 29), # (32 + 37) - (5 + 35); interaction wall | |
| 126 # time outside of renderer wall time. | |
| 127 ('fast-incremental_marking', 'ms', 0.0), | |
| 128 ('fast-incremental_marking_outside_idle', 'ms', 0.0), | |
| 129 ('fast-mark_compactor', 'ms', 0.0), | |
| 130 ('fast-mark_compactor_outside_idle', 'ms', 0.0), | |
| 131 ('fast-scavenger', 'ms', 0.0), | |
| 132 ('fast-scavenger_outside_idle', 'ms', 0.0), | |
| 133 ('fast-total_garbage_collection', 'ms', 0.0), | |
| 134 ('fast-total_garbage_collection_outside_idle', 'ms', 0.0) | |
| 135 ] | |
| 136 self.assertEqual(expected_values, self.ActualValues(results)) | |
| 137 self.assertIn('Main thread cpu_time cannot be computed for records', | |
| 138 self.LogOutput()) | |
| 139 | |
| 140 def testAddResultsWithMultipleInteractions(self): | |
| 141 # Wall time diagram: | |
| 142 # 1 2 3 4 | |
| 143 # 01234567890123456789012345678901234567890123456789 | |
| 144 # [ x.y ] | |
| 145 # [ Interaction.Foo/is_fast ] [ Interaction.Bar/is_fast ] | |
| 146 renderer_thread_helper = RendererThreadHelper( | |
| 147 wall_start=2, wall_duration=45, thread_start=0, thread_duration=101) | |
| 148 renderer_thread_helper.AddInteraction( | |
| 149 logical_name='Foo', | |
| 150 wall_start=6, wall_duration=27, thread_start=51, thread_duration=33) | |
| 151 renderer_thread_helper.AddInteraction( | |
| 152 logical_name='Bar', | |
| 153 wall_start=38, wall_duration=27, thread_start=90, thread_duration=33) | |
| 154 | |
| 155 metric = fast_metric.FastMetric() | |
| 156 results = renderer_thread_helper.MeasureFakePage(metric) | |
| 157 | |
| 158 expected_values = [ | |
| 159 ('fast-cpu_time', 'ms', 44), # thread overlap | |
| 160 ('fast-duration', 'ms', 54), # 27 + 27; total interaction wall duration | |
| 161 ('fast-idle_time', 'ms', 18), # (38 + 27) - (2 + 45); interaction wall | |
| 162 # time outside of renderer wall time. | |
| 163 ('fast-incremental_marking', 'ms', 0.0), | |
| 164 ('fast-incremental_marking_outside_idle', 'ms', 0.0), | |
| 165 ('fast-mark_compactor', 'ms', 0.0), | |
| 166 ('fast-mark_compactor_outside_idle', 'ms', 0.0), | |
| 167 ('fast-scavenger', 'ms', 0.0), | |
| 168 ('fast-scavenger_outside_idle', 'ms', 0.0), | |
| 169 ('fast-total_garbage_collection', 'ms', 0.0), | |
| 170 ('fast-total_garbage_collection_outside_idle', 'ms', 0.0) | |
| 171 ] | |
| 172 self.assertEqual(expected_values, self.ActualValues(results)) | |
| 173 | |
| 174 def testAddResultsWithGarbeCollectionEvents(self): | |
| 175 # Thread time diagram: | |
| 176 # 1 2 3 4 5 | |
| 177 # 012345678901234567890123456789012345678901234567890123456789 | |
| 178 # [ x.y ] | |
| 179 # [ Interaction.Foo/is_fast ] | |
| 180 # [ Idle ] [Idle] [Idle] | |
| 181 # [ S ] [S] [ I ] [I] [MC ] [MC] | |
| 182 renderer_thread_helper = RendererThreadHelper( | |
| 183 wall_start=1, wall_duration=57, thread_start=1, thread_duration=57) | |
| 184 renderer_thread_helper.AddInteraction( | |
| 185 logical_name='Foo', | |
| 186 wall_start=3, wall_duration=58, thread_start=3, thread_duration=58) | |
| 187 renderer_thread_helper.AddEvent('v8', 'V8.GCIdleNotification', 3, 7, 3, 7) | |
| 188 renderer_thread_helper.AddEvent('v8', 'V8.GCIdleNotification', 22, 5, 22, 5) | |
| 189 renderer_thread_helper.AddEvent('v8', 'V8.GCIdleNotification', 41, 5, 41, 5) | |
| 190 renderer_thread_helper.AddEvent('v8', 'V8.GCScavenger', 5, 4, 5, 4) | |
| 191 renderer_thread_helper.AddEvent('v8', 'V8.GCScavenger', 15, 2, 15, 2) | |
| 192 renderer_thread_helper.AddEvent('v8', 'V8.GCIncrementalMarking', 23, 4, 23, | |
| 193 4) | |
| 194 renderer_thread_helper.AddEvent('v8', 'V8.GCIncrementalMarking', 34, 2, 34, | |
| 195 2) | |
| 196 renderer_thread_helper.AddEvent('v8', 'V8.GCCompactor', 42, 4, 42, 4) | |
| 197 renderer_thread_helper.AddEvent('v8', 'V8.GCCompactor', 52, 3, 52, 3) | |
| 198 | |
| 199 metric = fast_metric.FastMetric() | |
| 200 results = renderer_thread_helper.MeasureFakePage(metric) | |
| 201 | |
| 202 expected_values = [ | |
| 203 ('fast-cpu_time', 'ms', 55), # thread overlap | |
| 204 ('fast-duration', 'ms', 58), # total interaction wall duration | |
| 205 ('fast-idle_time', 'ms', 3), # (3 + 58) - (1 + 57); interaction wall | |
| 206 # time outside of renderer wall time. | |
| 207 ('fast-incremental_marking', 'ms', 6.0), | |
| 208 ('fast-incremental_marking_outside_idle', 'ms', 2.0), | |
| 209 ('fast-mark_compactor', 'ms', 7.0), | |
| 210 ('fast-mark_compactor_outside_idle', 'ms', 3.0), | |
| 211 ('fast-scavenger', 'ms', 6.0), | |
| 212 ('fast-scavenger_outside_idle', 'ms', 2.0), | |
| 213 ('fast-total_garbage_collection', 'ms', 19.0), | |
| 214 ('fast-total_garbage_collection_outside_idle', 'ms', 7.0) | |
| 215 ] | |
| 216 self.assertEqual(expected_values, self.ActualValues(results)) | |
| OLD | NEW |