Telemetry: Add mean-frame-time and tasks-per-frame

tools/perf/metrics/timeline.py

 # Copyright 2014 The Chromium Authors. All rights reserved.
 # Use of this source code is governed by a BSD-style license that can be
 # found in the LICENSE file.
 import collections
 
 from telemetry.web_perf.metrics import timeline_based_metric
 from telemetry.value import scalar
 
 
 class LoadTimesTimelineMetric(timeline_based_metric.TimelineBasedMetric):
@@ skipping 66 matching lines @@
   "Browser Compositor"    : "browser",
   "CrRendererMain"        : "renderer_main",
   "Compositor"            : "renderer_compositor",
   "IOThread"              : "IO",
   "CompositorRasterWorker": "raster",
   "DummyThreadName1"      : "other",
   "DummyThreadName2"      : "total_fast_path",
   "DummyThreadName3"      : "total_all"
 }
 
+# Normalizing cpu-time by different rates might get confusing, but we could
+# report different frame-rates by adding their associated trace here.

[ernstm, 2014/10/11 00:24:22]

Why add this if we don't use it? You could instead use FrameTraceThreadName and
FrameTraceName directly, no? If you want to keep it, I suggest changing variable
names, because having ThreadFrameTraceName, FrameTraceName and
FrameTraceThreadName is very confusing. This one could be called
FrameTraceMapping, becuase it maps FrameTraceThreadName to FrameTraceName.

[epenner, 2014/10/13 22:20:32]

Ahh, yeah my original goal was to remove those other ones and report multiple
frame-rates etc. but I decided not to do that. I've removed this mapping as we
can always add it in the future.

+ThreadFrameTraceName =  {
+  "renderer_compositor": "::SwapBuffers",
+}
+
 _MatchBySubString = ["IOThread", "CompositorRasterWorker"]
 
 AllThreads = TimelineThreadCategories.values()
 NoThreads = []
 FastPathThreads = ["GPU", "renderer_compositor", "browser", "IO"]
 
 ReportMainThreadOnly = ["renderer_main"]
 ReportFastPathResults = AllThreads
 ReportFastPathDetails = NoThreads
 ReportSilkResults = ["renderer_main", "total_all"]
 ReportSilkDetails = ["renderer_main"]
 
 # TODO(epenner): Thread names above are likely fairly stable but trace names
 # could change. We should formalize these traces to keep this robust.
 OverheadTraceCategory = "trace_event_overhead"
 OverheadTraceName = "overhead"
 FrameTraceName = "::SwapBuffers"
 FrameTraceThreadName = "renderer_compositor"
 
+def Rate(numerator, denominator):

[ernstm, 2014/10/11 00:24:22]

We have telmetry.util.statistics.DivideIfPossibleOrZero for this.

[epenner, 2014/10/13 22:20:32]

That doesn't cast to float. If you think I can change that to cast to float I'll
use it, otherwise I prefer keeping this.

[ernstm, 2014/10/14 17:06:11]

Please change DivideIfPossibleOrZero to cast to float. I only round one other
call site and that should definitely cast to float.

+  return (float(numerator) / denominator) if denominator else 0
 
 def ClockOverheadForEvent(event):
   if (event.category == OverheadTraceCategory and
       event.name == OverheadTraceName):
     return event.duration
   else:
     return 0
 
 def CpuOverheadForEvent(event):
   if (event.category == OverheadTraceCategory and
       event.thread_duration):
     return event.thread_duration
   else:
     return 0
 
 def ThreadCategoryName(thread_name):
   thread_category = "other"
   for substring, category in TimelineThreadCategories.iteritems():
     if substring in _MatchBySubString and substring in thread_name:
       thread_category = category
   if thread_name in TimelineThreadCategories:
     thread_category = TimelineThreadCategories[thread_name]
   return thread_category
 
-def ThreadTimeResultName(thread_category):
-  return "thread_" + thread_category + "_clock_time_per_frame"
+def ThreadCpuTimeResultName(thread_category):
+  # This name sucks but I don't want to change it and lose continuity

[ernstm, 2014/10/11 00:24:22]

Metrics can be migrated to new names on the dashboard, if that helps.

[epenner, 2014/10/13 22:20:32]

That sounds cool. Got some documentation on that? How about I do it in a
separate patch. It will change many pagesets/benchmarks so I want to do it
carefully.

[ernstm, 2014/10/14 17:06:11]

qyearsley can help with the data migration. It is a good idea to do it as a
separate patch.

[epenner, 2014/10/18 01:02:30]

Acknowledged.

+  return "thread_" + thread_category + "_cpu_time_per_frame"
 
-def ThreadCpuTimeResultName(thread_category):
-  return "thread_" + thread_category + "_cpu_time_per_frame"
+def ThreadTasksResultName(thread_category):
+  return "tasks_per_frame_" + thread_category
+
+def ThreadFpsResultName(thread_category):
+  return "fps_" + thread_category
 
 def ThreadDetailResultName(thread_category, detail):
   detail_sanitized = detail.replace('.','_')
   return "thread_" + thread_category + "|" + detail_sanitized
 
 
 class ResultsForThread(object):
   def __init__(self, model, record_ranges, name):
     self.model = model
     self.toplevel_slices = []
     self.all_slices = []
     self.name = name
     self.record_ranges = record_ranges
+    self.all_action_time = \
+        sum([record_range.bounds for record_range in self.record_ranges])
 
   @property
   def clock_time(self):
     clock_duration = sum([x.duration for x in self.toplevel_slices])
     clock_overhead = sum([ClockOverheadForEvent(x) for x in self.all_slices])
     return clock_duration - clock_overhead
 
   @property
   def cpu_time(self):
     cpu_duration = 0
@@ skipping 17 matching lines @@
       for record_range in self.record_ranges:
         if record_range.ContainsInterval(event.start, event.end):
           slices_in_actions.append(event)
           break
     return slices_in_actions
 
   def AppendThreadSlices(self, thread):
     self.all_slices.extend(self.SlicesInActions(thread.all_slices))
     self.toplevel_slices.extend(self.SlicesInActions(thread.toplevel_slices))
 
+  # Currently we report cpu-time per frame, tasks per frame, and possibly
+  # the frame rate (if there is a trace specified to find it).
   def AddResults(self, num_frames, results):
-    cpu_per_frame = (float(self.cpu_time) / num_frames) if num_frames else 0
+    cpu_per_frame = Rate(self.cpu_time, num_frames)
+    tasks_per_frame = Rate(len(self.toplevel_slices), num_frames)
     results.AddValue(scalar.ScalarValue(
         results.current_page, ThreadCpuTimeResultName(self.name),
         'ms', cpu_per_frame))
+    results.AddValue(scalar.ScalarValue(
+        results.current_page, ThreadTasksResultName(self.name),
+        'tasks', tasks_per_frame))
+    if self.name in ThreadFrameTraceName:
+      num_frames = self.CountTracesWithName(ThreadFrameTraceName[self.name])
+      frame_rate = Rate(num_frames, self.all_action_time) * 1000
+      results.AddValue(scalar.ScalarValue(
+          results.current_page, ThreadFpsResultName(self.name),
+          'fps', frame_rate))
 
   def AddDetailedResults(self, num_frames, results):
     slices_by_category = collections.defaultdict(list)
     for s in self.all_slices:
       slices_by_category[s.category].append(s)
     all_self_times = []
     for category, slices_in_category in slices_by_category.iteritems():
       self_time = sum([x.self_time for x in slices_in_category])
       all_self_times.append(self_time)
       self_time_result = (float(self_time) / num_frames) if num_frames else 0
       results.AddValue(scalar.ScalarValue(
           results.current_page, ThreadDetailResultName(self.name, category),
           'ms', self_time_result))
     all_measured_time = sum(all_self_times)
-    all_action_time = \
-        sum([record_range.bounds for record_range in self.record_ranges])
-    idle_time = max(0, all_action_time - all_measured_time)
+    idle_time = max(0, self.all_action_time - all_measured_time)
     idle_time_result = (float(idle_time) / num_frames) if num_frames else 0
     results.AddValue(scalar.ScalarValue(
         results.current_page, ThreadDetailResultName(self.name, "idle"),
         'ms', idle_time_result))
 
+  def CountTracesWithName(self, substring):
+    count = 0
+    for event in self.all_slices:
+      if substring in event.name:
+        count += 1
+    return count
 
 class ThreadTimesTimelineMetric(timeline_based_metric.TimelineBasedMetric):
   def __init__(self):
     super(ThreadTimesTimelineMetric, self).__init__()
     # Minimal traces, for minimum noise in CPU-time measurements.
     self.results_to_report = AllThreads
     self.details_to_report = NoThreads
 
-  def CountSlices(self, slices, substring):
-    count = 0
-    for event in slices:
-      if substring in event.name:
-        count += 1
-    return count
-
   def AddResults(self, model, _, interaction_records, results):
     # Set up each thread category for consistant results.
     thread_category_results = {}
     for name in TimelineThreadCategories.values():
       thread_category_results[name] = ResultsForThread(
         model, [r.GetBounds() for r in interaction_records], name)
 
     # Group the slices by their thread category.
     for thread in model.GetAllThreads():
       thread_category = ThreadCategoryName(thread.name)
       thread_category_results[thread_category].AppendThreadSlices(thread)
 
     # Group all threads.
     for thread in model.GetAllThreads():
       thread_category_results['total_all'].AppendThreadSlices(thread)
 
     # Also group fast-path threads.
     for thread in model.GetAllThreads():
       if ThreadCategoryName(thread.name) in FastPathThreads:
         thread_category_results['total_fast_path'].AppendThreadSlices(thread)
 
-    # Calculate the number of frames.
-    frame_slices = thread_category_results[FrameTraceThreadName].all_slices
-    num_frames = self.CountSlices(frame_slices, FrameTraceName)
+    # Calculate the number of frames / frame-rate.
+    frame_rate_thread = thread_category_results[FrameTraceThreadName]
+    num_frames = frame_rate_thread.CountTracesWithName(FrameTraceName)
 
     # Report the desired results and details.
     for thread_results in thread_category_results.values():
       if thread_results.name in self.results_to_report:
         thread_results.AddResults(num_frames, results)
       # TOOD(nduca): When generic results objects are done, this special case
       # can be replaced with a generic UI feature.
       if thread_results.name in self.details_to_report:
         thread_results.AddDetailedResults(num_frames, results)