Support total and per-second task/threadtime timeline metrics

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.util.statistics import DivideIfPossibleOrZero
 from telemetry.value import scalar
 from telemetry.web_perf.metrics import timeline_based_metric
 
 
@@ skipping 83 matching lines @@
 ReportMainThreadOnly = ["renderer_main"]
 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"
 
+IntervalNames = ["frame", "second"]
+
 def Rate(numerator, denominator):
   return DivideIfPossibleOrZero(numerator, denominator)
 
 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 ThreadCpuTimeResultName(thread_category):
+def ThreadCpuTimeResultName(thread_category, interval_name):
   # This isn't a good name, but I don't want to change it and lose continuity.
-  return "thread_" + thread_category + "_cpu_time_per_frame"
+  return "thread_" + thread_category + "_cpu_time_per_" + interval_name
 
-def ThreadTasksResultName(thread_category):
-  return "tasks_per_frame_" + thread_category
+def ThreadTasksResultName(thread_category, interval_name):
+  return "tasks_per_" + interval_name + "_" + thread_category
 
-def ThreadMeanFrameTimeResultName(thread_category):
-  return "mean_frame_time_" + thread_category
+def ThreadMeanTimeResultName(thread_category, interval_name):
+  return "mean_" + interval_name + "_time_" + thread_category
 
-def ThreadDetailResultName(thread_category, detail):
+def ThreadDetailResultName(thread_category, interval_name, detail):
   detail_sanitized = detail.replace('.','_')
-  return "thread_" + thread_category + "|" + detail_sanitized
+  # Special-case per-frame detail names to preserve continuity.
+  interval_sanitized = (
+      "" if interval_name == "frame" else "_per_" + interval_name)
+  return (
+      "thread_" + thread_category + interval_sanitized + "|" + 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 = \
@@ skipping 28 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 mean frame (if there is a trace specified to find it).
-  def AddResults(self, num_frames, results):
-    cpu_per_frame = Rate(self.cpu_time, num_frames)
-    tasks_per_frame = Rate(len(self.toplevel_slices), num_frames)
+  # Reports cpu-time per interval and tasks per interval.
+  def AddResults(self, num_intervals, interval_name, results):
+    cpu_per_interval = Rate(self.cpu_time, num_intervals)
+    tasks_per_interval = Rate(len(self.toplevel_slices), num_intervals)
     results.AddValue(scalar.ScalarValue(
-        results.current_page, ThreadCpuTimeResultName(self.name),
-        'ms', cpu_per_frame))
+        results.current_page,
+        ThreadCpuTimeResultName(self.name, interval_name),
+        'ms', cpu_per_interval))
     results.AddValue(scalar.ScalarValue(
-        results.current_page, ThreadTasksResultName(self.name),
-        'tasks', tasks_per_frame))
+        results.current_page,
+        ThreadTasksResultName(self.name, interval_name),
+        'tasks', tasks_per_interval))
     # Report mean frame time if this is the thread we are using for normalizing
     # other results. We could report other frame rates (eg. renderer_main) but
     # this might get confusing.
     if self.name == FrameTraceThreadName:
       num_frames = self.CountTracesWithName(FrameTraceName)
       mean_frame_time = Rate(self.all_action_time, num_frames)
       results.AddValue(scalar.ScalarValue(
-          results.current_page, ThreadMeanFrameTimeResultName(self.name),
+          results.current_page,
+          ThreadMeanTimeResultName(self.name, interval_name),
           'ms', mean_frame_time))
 
-  def AddDetailedResults(self, num_frames, results):
+  def AddDetailedResults(self, num_intervals, interval_name, 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
+      self_time_result = (
+          (float(self_time) / num_intervals) if num_intervals else 0)
       results.AddValue(scalar.ScalarValue(
-          results.current_page, ThreadDetailResultName(self.name, category),
+          results.current_page,
+          ThreadDetailResultName(self.name, interval_name, category),
           'ms', self_time_result))
     all_measured_time = sum(all_self_times)
     idle_time = max(0, self.all_action_time - all_measured_time)
-    idle_time_result = (float(idle_time) / num_frames) if num_frames else 0
+    idle_time_result = (
+        (float(idle_time) / num_intervals) if num_intervals else 0)
     results.AddValue(scalar.ScalarValue(
-        results.current_page, ThreadDetailResultName(self.name, "idle"),
+        results.current_page,
+        ThreadDetailResultName(self.name, interval_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
 
+  def ComputeSliceTimeRange(self):
+    if not self.all_slices:
+      return 0
+
+    start = min(s.start for s in self.all_slices)
+    end = max(s.end for s in self.all_slices)
+    return max(0, end - start)
+
+
 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 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)
+          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.
+    # Calculate the interaction's number of frames.
     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)
+    # Calculate the interaction's duration.
+    all_threads = thread_category_results['total_all']
+    num_seconds = all_threads.ComputeSliceTimeRange() / 1000.0

[nednguyen, 2015/05/01 19:15:10]

Don't you want to use num_seconds = sum all the time of the interaction records
instead of the total time of all thread's slices?

If I recall correctly, these metrics are supposed to be for interaction records
on each thread, not for the whole threads.

[jdduke (slow), 2015/05/01 21:08:47]

I see now, so we can just reuse ResultsForThread.all_action_time?

+
+    # Report the desired results and details for each interval type.
+    intervals = [("frame", num_frames), ("second", num_seconds)]
+    for (interval_name, num_intervals) in intervals:
+      for thread_results in thread_category_results.values():
+        if thread_results.name in self.results_to_report:
+          thread_results.AddResults(num_intervals, interval_name, 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_intervals, interval_name, results)