src/tools/telemetry/telemetry/web_perf/metrics/rendering_stats_unittest.py

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