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 |