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
5import random
6import unittest
7
8import telemetry.timeline.async_slice as tracing_async_slice
9import telemetry.timeline.bounds as timeline_bounds
10from telemetry.perf_tests_helper import FlattenList
11from telemetry.timeline import model
12from telemetry.util.statistics import DivideIfPossibleOrZero
13from telemetry.web_perf.metrics.rendering_stats import (
14    BEGIN_COMP_NAME,
15    BEGIN_SCROLL_UPDATE_COMP_NAME,
16    END_COMP_NAME,
17    FORWARD_SCROLL_UPDATE_COMP_NAME,
18    GESTURE_SCROLL_UPDATE_EVENT_NAME,
19    ORIGINAL_COMP_NAME,
20    SCROLL_UPDATE_EVENT_NAME,
21    UI_COMP_NAME)
22from telemetry.web_perf.metrics.rendering_stats import (
23    ComputeInputEventLatencies)
24from telemetry.web_perf.metrics.rendering_stats import GetInputLatencyEvents
25from telemetry.web_perf.metrics.rendering_stats import HasRenderingStats
26from telemetry.web_perf.metrics.rendering_stats import RenderingStats
27
28
29class MockTimer(object):
30  """A mock timer class which can generate random durations.
31
32  An instance of this class is used as a global timer to generate random
33  durations for stats and consistent timestamps for all mock trace events.
34  The unit of time is milliseconds.
35  """
36  def __init__(self):
37    self.milliseconds = 0
38
39  def Get(self):
40    return self.milliseconds
41
42  def Advance(self, low=0, high=1):
43    delta = random.uniform(low, high)
44    self.milliseconds += delta
45    return delta
46
47
48class ReferenceRenderingStats(object):
49  """ Stores expected data for comparison with actual RenderingStats """
50  def __init__(self):
51    self.frame_timestamps = []
52    self.frame_times = []
53    self.paint_times = []
54    self.painted_pixel_counts = []
55    self.record_times = []
56    self.recorded_pixel_counts = []
57    self.rasterize_times = []
58    self.rasterized_pixel_counts = []
59    self.approximated_pixel_percentages = []
60
61  def AppendNewRange(self):
62    self.frame_timestamps.append([])
63    self.frame_times.append([])
64    self.paint_times.append([])
65    self.painted_pixel_counts.append([])
66    self.record_times.append([])
67    self.recorded_pixel_counts.append([])
68    self.rasterize_times.append([])
69    self.rasterized_pixel_counts.append([])
70    self.approximated_pixel_percentages.append([])
71
72class ReferenceInputLatencyStats(object):
73  """ Stores expected data for comparison with actual input latency stats """
74  def __init__(self):
75    self.input_event_latency = []
76    self.input_event = []
77
78def AddMainThreadRenderingStats(mock_timer, thread, first_frame,
79                                ref_stats = None):
80  """ Adds a random main thread rendering stats event.
81
82  thread: The timeline model thread to which the event will be added.
83  first_frame: Is this the first frame within the bounds of an action?
84  ref_stats: A ReferenceRenderingStats object to record expected values.
85  """
86  # Create randonm data and timestap for main thread rendering stats.
87  data = { 'frame_count': 0,
88           'paint_time': 0.0,
89           'painted_pixel_count': 0,
90           'record_time': mock_timer.Advance(2, 4) / 1000.0,
91           'recorded_pixel_count': 3000*3000 }
92  timestamp = mock_timer.Get()
93
94  # Add a slice with the event data to the given thread.
95  thread.PushCompleteSlice(
96      'benchmark', 'BenchmarkInstrumentation::MainThreadRenderingStats',
97      timestamp, duration=0.0, thread_timestamp=None, thread_duration=None,
98      args={'data': data})
99
100  if not ref_stats:
101    return
102
103  # Add timestamp only if a frame was output
104  if data['frame_count'] == 1:
105    if not first_frame:
106      # Add frame_time if this is not the first frame in within the bounds of an
107      # action.
108      prev_timestamp = ref_stats.frame_timestamps[-1][-1]
109      ref_stats.frame_times[-1].append(round(timestamp - prev_timestamp, 2))
110    ref_stats.frame_timestamps[-1].append(timestamp)
111
112  ref_stats.paint_times[-1].append(data['paint_time'] * 1000.0)
113  ref_stats.painted_pixel_counts[-1].append(data['painted_pixel_count'])
114  ref_stats.record_times[-1].append(data['record_time'] * 1000.0)
115  ref_stats.recorded_pixel_counts[-1].append(data['recorded_pixel_count'])
116
117
118def AddImplThreadRenderingStats(mock_timer, thread, first_frame,
119                                ref_stats = None):
120  """ Adds a random impl thread rendering stats event.
121
122  thread: The timeline model thread to which the event will be added.
123  first_frame: Is this the first frame within the bounds of an action?
124  ref_stats: A ReferenceRenderingStats object to record expected values.
125  """
126  # Create randonm data and timestap for impl thread rendering stats.
127  data = { 'frame_count': 1,
128           'rasterize_time': mock_timer.Advance(5, 10) / 1000.0,
129           'rasterized_pixel_count': 1280*720,
130           'visible_content_area': random.uniform(0, 100),
131           'approximated_visible_content_area': random.uniform(0, 5)}
132  timestamp = mock_timer.Get()
133
134  # Add a slice with the event data to the given thread.
135  thread.PushCompleteSlice(
136      'benchmark', 'BenchmarkInstrumentation::ImplThreadRenderingStats',
137      timestamp, duration=0.0, thread_timestamp=None, thread_duration=None,
138      args={'data': data})
139
140  if not ref_stats:
141    return
142
143  # Add timestamp only if a frame was output
144  if data['frame_count'] == 1:
145    if not first_frame:
146      # Add frame_time if this is not the first frame in within the bounds of an
147      # action.
148      prev_timestamp = ref_stats.frame_timestamps[-1][-1]
149      ref_stats.frame_times[-1].append(round(timestamp - prev_timestamp, 2))
150    ref_stats.frame_timestamps[-1].append(timestamp)
151
152  ref_stats.rasterize_times[-1].append(data['rasterize_time'] * 1000.0)
153  ref_stats.rasterized_pixel_counts[-1].append(data['rasterized_pixel_count'])
154  ref_stats.approximated_pixel_percentages[-1].append(
155      round(DivideIfPossibleOrZero(data['approximated_visible_content_area'],
156                                   data['visible_content_area']) * 100.0, 3))
157
158
159def AddInputLatencyStats(mock_timer, start_thread, end_thread,
160                         ref_latency_stats = None):
161  """ Adds a random input latency stats event.
162
163  start_thread: The start thread on which the async slice is added.
164  end_thread: The end thread on which the async slice is ended.
165  ref_latency_stats: A ReferenceInputLatencyStats object for expected values.
166  """
167
168  mock_timer.Advance(2, 4)
169  original_comp_time = mock_timer.Get() * 1000.0
170  mock_timer.Advance(2, 4)
171  ui_comp_time = mock_timer.Get() * 1000.0
172  mock_timer.Advance(2, 4)
173  begin_comp_time = mock_timer.Get() * 1000.0
174  mock_timer.Advance(2, 4)
175  forward_comp_time = mock_timer.Get() * 1000.0
176  mock_timer.Advance(10, 20)
177  end_comp_time = mock_timer.Get() * 1000.0
178
179  data = { ORIGINAL_COMP_NAME: {'time': original_comp_time},
180           UI_COMP_NAME: {'time': ui_comp_time},
181           BEGIN_COMP_NAME: {'time': begin_comp_time},
182           END_COMP_NAME: {'time': end_comp_time} }
183
184  timestamp = mock_timer.Get()
185
186  async_slice = tracing_async_slice.AsyncSlice(
187      'benchmark', 'InputLatency', timestamp)
188
189  async_sub_slice = tracing_async_slice.AsyncSlice(
190      'benchmark', GESTURE_SCROLL_UPDATE_EVENT_NAME, timestamp)
191  async_sub_slice.args = {'data': data}
192  async_sub_slice.parent_slice = async_slice
193  async_sub_slice.start_thread = start_thread
194  async_sub_slice.end_thread = end_thread
195
196  async_slice.sub_slices.append(async_sub_slice)
197  async_slice.start_thread = start_thread
198  async_slice.end_thread = end_thread
199  start_thread.AddAsyncSlice(async_slice)
200
201  # Add scroll update latency info.
202  scroll_update_data = {
203      BEGIN_SCROLL_UPDATE_COMP_NAME: {'time': begin_comp_time},
204      FORWARD_SCROLL_UPDATE_COMP_NAME: {'time': forward_comp_time},
205      END_COMP_NAME: {'time': end_comp_time} }
206
207  scroll_async_slice = tracing_async_slice.AsyncSlice(
208      'benchmark', 'InputLatency', timestamp)
209
210  scroll_async_sub_slice = tracing_async_slice.AsyncSlice(
211      'benchmark', SCROLL_UPDATE_EVENT_NAME, timestamp)
212  scroll_async_sub_slice.args = {'data': scroll_update_data}
213  scroll_async_sub_slice.parent_slice = scroll_async_slice
214  scroll_async_sub_slice.start_thread = start_thread
215  scroll_async_sub_slice.end_thread = end_thread
216
217  scroll_async_slice.sub_slices.append(scroll_async_sub_slice)
218  scroll_async_slice.start_thread = start_thread
219  scroll_async_slice.end_thread = end_thread
220  start_thread.AddAsyncSlice(scroll_async_slice)
221
222  # Also add some dummy frame statistics so we can feed the resulting timeline
223  # to RenderingStats.
224  AddMainThreadRenderingStats(mock_timer, start_thread, False)
225  AddImplThreadRenderingStats(mock_timer, end_thread, False)
226
227  if not ref_latency_stats:
228    return
229
230  ref_latency_stats.input_event.append(async_sub_slice)
231  ref_latency_stats.input_event.append(scroll_async_sub_slice)
232  ref_latency_stats.input_event_latency.append((
233      GESTURE_SCROLL_UPDATE_EVENT_NAME,
234      (data[END_COMP_NAME]['time'] -
235       data[ORIGINAL_COMP_NAME]['time']) / 1000.0))
236  ref_latency_stats.input_event_latency.append((
237      SCROLL_UPDATE_EVENT_NAME,
238      (scroll_update_data[END_COMP_NAME]['time'] -
239       scroll_update_data[BEGIN_SCROLL_UPDATE_COMP_NAME]['time']) / 1000.0))
240
241
242class RenderingStatsUnitTest(unittest.TestCase):
243  def testHasRenderingStats(self):
244    timeline = model.TimelineModel()
245    timer = MockTimer()
246
247    # A process without rendering stats
248    process_without_stats = timeline.GetOrCreateProcess(pid = 1)
249    thread_without_stats = process_without_stats.GetOrCreateThread(tid = 11)
250    process_without_stats.FinalizeImport()
251    self.assertFalse(HasRenderingStats(thread_without_stats))
252
253    # A process with rendering stats, but no frames in them
254    process_without_frames = timeline.GetOrCreateProcess(pid = 2)
255    thread_without_frames = process_without_frames.GetOrCreateThread(tid = 21)
256    AddMainThreadRenderingStats(timer, thread_without_frames, True, None)
257    process_without_frames.FinalizeImport()
258    self.assertFalse(HasRenderingStats(thread_without_frames))
259
260    # A process with rendering stats and frames in them
261    process_with_frames = timeline.GetOrCreateProcess(pid = 3)
262    thread_with_frames = process_with_frames.GetOrCreateThread(tid = 31)
263    AddImplThreadRenderingStats(timer, thread_with_frames, True, None)
264    process_with_frames.FinalizeImport()
265    self.assertTrue(HasRenderingStats(thread_with_frames))
266
267  def testRangeWithoutFrames(self):
268    timer = MockTimer()
269    timeline = model.TimelineModel()
270
271    # Create a renderer process, with a main thread and impl thread.
272    renderer = timeline.GetOrCreateProcess(pid = 2)
273    renderer_main = renderer.GetOrCreateThread(tid = 21)
274    renderer_compositor = renderer.GetOrCreateThread(tid = 22)
275
276    # Create 10 main and impl rendering stats events for Action A.
277    timer.Advance(2, 4)
278    renderer_main.BeginSlice('webkit.console', 'ActionA', timer.Get(), '')
279    for i in xrange(0, 10):
280      first = (i == 0)
281      AddMainThreadRenderingStats(timer, renderer_main, first, None)
282      AddImplThreadRenderingStats(timer, renderer_compositor, first, None)
283    timer.Advance(2, 4)
284    renderer_main.EndSlice(timer.Get())
285
286    # Create 5 main and impl rendering stats events not within any action.
287    for i in xrange(0, 5):
288      first = (i == 0)
289      AddMainThreadRenderingStats(timer, renderer_main, first, None)
290      AddImplThreadRenderingStats(timer, renderer_compositor, first, None)
291
292    # Create Action B without any frames. This should trigger
293    # NotEnoughFramesError when the RenderingStats object is created.
294    timer.Advance(2, 4)
295    renderer_main.BeginSlice('webkit.console', 'ActionB', timer.Get(), '')
296    timer.Advance(2, 4)
297    renderer_main.EndSlice(timer.Get())
298
299    renderer.FinalizeImport()
300
301    timeline_markers = timeline.FindTimelineMarkers(['ActionA', 'ActionB'])
302    timeline_ranges = [ timeline_bounds.Bounds.CreateFromEvent(marker)
303                        for marker in timeline_markers ]
304
305    stats = RenderingStats(renderer, None, timeline_ranges)
306    self.assertEquals(0, len(stats.frame_timestamps[1]))
307
308
309  def testFromTimeline(self):
310    timeline = model.TimelineModel()
311
312    # Create a browser process and a renderer process, and a main thread and
313    # impl thread for each.
314    browser = timeline.GetOrCreateProcess(pid = 1)
315    browser_main = browser.GetOrCreateThread(tid = 11)
316    browser_compositor = browser.GetOrCreateThread(tid = 12)
317    renderer = timeline.GetOrCreateProcess(pid = 2)
318    renderer_main = renderer.GetOrCreateThread(tid = 21)
319    renderer_compositor = renderer.GetOrCreateThread(tid = 22)
320
321    timer = MockTimer()
322    renderer_ref_stats = ReferenceRenderingStats()
323    browser_ref_stats = ReferenceRenderingStats()
324
325    # Create 10 main and impl rendering stats events for Action A.
326    timer.Advance(2, 4)
327    renderer_main.BeginSlice('webkit.console', 'ActionA', timer.Get(), '')
328    renderer_ref_stats.AppendNewRange()
329    browser_ref_stats.AppendNewRange()
330    for i in xrange(0, 10):
331      first = (i == 0)
332      AddMainThreadRenderingStats(
333          timer, renderer_main, first, renderer_ref_stats)
334      AddImplThreadRenderingStats(
335          timer, renderer_compositor, first, renderer_ref_stats)
336      AddMainThreadRenderingStats(
337          timer, browser_main, first, browser_ref_stats)
338      AddImplThreadRenderingStats(
339          timer, browser_compositor, first, browser_ref_stats)
340    timer.Advance(2, 4)
341    renderer_main.EndSlice(timer.Get())
342
343    # Create 5 main and impl rendering stats events not within any action.
344    for i in xrange(0, 5):
345      first = (i == 0)
346      AddMainThreadRenderingStats(timer, renderer_main, first, None)
347      AddImplThreadRenderingStats(timer, renderer_compositor, first, None)
348      AddMainThreadRenderingStats(timer, browser_main, first, None)
349      AddImplThreadRenderingStats(timer, browser_compositor, first, None)
350
351    # Create 10 main and impl rendering stats events for Action B.
352    timer.Advance(2, 4)
353    renderer_main.BeginSlice('webkit.console', 'ActionB', timer.Get(), '')
354    renderer_ref_stats.AppendNewRange()
355    browser_ref_stats.AppendNewRange()
356    for i in xrange(0, 10):
357      first = (i == 0)
358      AddMainThreadRenderingStats(
359          timer, renderer_main, first, renderer_ref_stats)
360      AddImplThreadRenderingStats(
361          timer, renderer_compositor, first, renderer_ref_stats)
362      AddMainThreadRenderingStats(
363          timer, browser_main, first, browser_ref_stats)
364      AddImplThreadRenderingStats(
365          timer, browser_compositor, first, browser_ref_stats)
366    timer.Advance(2, 4)
367    renderer_main.EndSlice(timer.Get())
368
369    # Create 10 main and impl rendering stats events for Action A.
370    timer.Advance(2, 4)
371    renderer_main.BeginSlice('webkit.console', 'ActionA', timer.Get(), '')
372    renderer_ref_stats.AppendNewRange()
373    browser_ref_stats.AppendNewRange()
374    for i in xrange(0, 10):
375      first = (i == 0)
376      AddMainThreadRenderingStats(
377          timer, renderer_main, first, renderer_ref_stats)
378      AddImplThreadRenderingStats(
379          timer, renderer_compositor, first, renderer_ref_stats)
380      AddMainThreadRenderingStats(
381          timer, browser_main, first, browser_ref_stats)
382      AddImplThreadRenderingStats(
383          timer, browser_compositor, first, browser_ref_stats)
384    timer.Advance(2, 4)
385    renderer_main.EndSlice(timer.Get())
386
387    browser.FinalizeImport()
388    renderer.FinalizeImport()
389
390    timeline_markers = timeline.FindTimelineMarkers(
391        ['ActionA', 'ActionB', 'ActionA'])
392    timeline_ranges = [ timeline_bounds.Bounds.CreateFromEvent(marker)
393                        for marker in timeline_markers ]
394    stats = RenderingStats(renderer, browser, timeline_ranges)
395
396    # Compare rendering stats to reference.
397    self.assertEquals(stats.frame_timestamps,
398                      browser_ref_stats.frame_timestamps)
399    self.assertEquals(stats.frame_times, browser_ref_stats.frame_times)
400    self.assertEquals(stats.rasterize_times, renderer_ref_stats.rasterize_times)
401    self.assertEquals(stats.rasterized_pixel_counts,
402                      renderer_ref_stats.rasterized_pixel_counts)
403    self.assertEquals(stats.approximated_pixel_percentages,
404                      renderer_ref_stats.approximated_pixel_percentages)
405    self.assertEquals(stats.paint_times, renderer_ref_stats.paint_times)
406    self.assertEquals(stats.painted_pixel_counts,
407                      renderer_ref_stats.painted_pixel_counts)
408    self.assertEquals(stats.record_times, renderer_ref_stats.record_times)
409    self.assertEquals(stats.recorded_pixel_counts,
410                      renderer_ref_stats.recorded_pixel_counts)
411
412  def testInputLatencyFromTimeline(self):
413    timeline = model.TimelineModel()
414
415    # Create a browser process and a renderer process.
416    browser = timeline.GetOrCreateProcess(pid = 1)
417    browser_main = browser.GetOrCreateThread(tid = 11)
418    renderer = timeline.GetOrCreateProcess(pid = 2)
419    renderer_main = renderer.GetOrCreateThread(tid = 21)
420
421    timer = MockTimer()
422    ref_latency = ReferenceInputLatencyStats()
423
424    # Create 10 input latency stats events for Action A.
425    timer.Advance(2, 4)
426    renderer_main.BeginSlice('webkit.console', 'ActionA', timer.Get(), '')
427    for _ in xrange(0, 10):
428      AddInputLatencyStats(timer, browser_main, renderer_main, ref_latency)
429    timer.Advance(2, 4)
430    renderer_main.EndSlice(timer.Get())
431
432    # Create 5 input latency stats events not within any action.
433    timer.Advance(2, 4)
434    for _ in xrange(0, 5):
435      AddInputLatencyStats(timer, browser_main, renderer_main, None)
436
437    # Create 10 input latency stats events for Action B.
438    timer.Advance(2, 4)
439    renderer_main.BeginSlice('webkit.console', 'ActionB', timer.Get(), '')
440    for _ in xrange(0, 10):
441      AddInputLatencyStats(timer, browser_main, renderer_main, ref_latency)
442    timer.Advance(2, 4)
443    renderer_main.EndSlice(timer.Get())
444
445    # Create 10 input latency stats events for Action A.
446    timer.Advance(2, 4)
447    renderer_main.BeginSlice('webkit.console', 'ActionA', timer.Get(), '')
448    for _ in xrange(0, 10):
449      AddInputLatencyStats(timer, browser_main, renderer_main, ref_latency)
450    timer.Advance(2, 4)
451    renderer_main.EndSlice(timer.Get())
452
453    browser.FinalizeImport()
454    renderer.FinalizeImport()
455
456    input_events = []
457
458    timeline_markers = timeline.FindTimelineMarkers(
459        ['ActionA', 'ActionB', 'ActionA'])
460    timeline_ranges = [timeline_bounds.Bounds.CreateFromEvent(marker)
461                       for marker in timeline_markers]
462    for timeline_range in timeline_ranges:
463      if timeline_range.is_empty:
464        continue
465      input_events.extend(GetInputLatencyEvents(browser, timeline_range))
466
467    self.assertEquals(input_events, ref_latency.input_event)
468    input_event_latency_result = ComputeInputEventLatencies(input_events)
469    self.assertEquals(input_event_latency_result,
470                      ref_latency.input_event_latency)
471
472    stats = RenderingStats(renderer, browser, timeline_ranges)
473    self.assertEquals(FlattenList(stats.input_event_latency), [
474        latency for name, latency in ref_latency.input_event_latency
475        if name != SCROLL_UPDATE_EVENT_NAME])
476    self.assertEquals(FlattenList(stats.scroll_update_latency), [
477        latency for name, latency in ref_latency.input_event_latency
478        if name == SCROLL_UPDATE_EVENT_NAME])
479    self.assertEquals(FlattenList(stats.gesture_scroll_update_latency), [
480        latency for name, latency in ref_latency.input_event_latency
481        if name == GESTURE_SCROLL_UPDATE_EVENT_NAME])
482