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 import telemetry.timeline.async_slice as tracing_async_slice
   9 import telemetry.timeline.bounds as timeline_bounds
  10 from telemetry.perf_tests_helper import FlattenList
  11 from telemetry.timeline import model
  12 from telemetry.util.statistics import DivideIfPossibleOrZero
  13 from 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)
  22 from telemetry.web_perf.metrics.rendering_stats import (
  23     ComputeInputEventLatencies)
  24 from telemetry.web_perf.metrics.rendering_stats import GetInputLatencyEvents
  25 from telemetry.web_perf.metrics.rendering_stats import HasRenderingStats
  26 from telemetry.web_perf.metrics.rendering_stats import RenderingStats
  27
  28
  29 class 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
  48 class 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
  72 class 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
  78 def 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
 118 def 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
 159 def 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
 242 class 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])