# 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 class LoadTimesTimelineMetric(timeline_based_metric.TimelineBasedMetric): def __init__(self): super(LoadTimesTimelineMetric, self).__init__() self.report_main_thread_only = True def AddResults(self, model, renderer_thread, interaction_records, results): assert model assert len(interaction_records) == 1, ( 'LoadTimesTimelineMetric cannot compute metrics for more than 1 time ' 'range.') interaction_record = interaction_records[0] if self.report_main_thread_only: thread_filter = 'CrRendererMain' else: thread_filter = None events_by_name = collections.defaultdict(list) renderer_process = renderer_thread.parent for thread in renderer_process.threads.itervalues(): if thread_filter and not thread.name in thread_filter: continue thread_name = thread.name.replace('/','_') for e in thread.IterAllSlicesInRange(interaction_record.start, interaction_record.end): events_by_name[e.name].append(e) for event_name, event_group in events_by_name.iteritems(): times = [event.self_time for event in event_group] total = sum(times) biggest_jank = max(times) # Results objects cannot contain the '.' character, so remove that here. sanitized_event_name = event_name.replace('.', '_') full_name = thread_name + '|' + sanitized_event_name results.AddValue(scalar.ScalarValue( results.current_page, full_name, 'ms', total)) results.AddValue(scalar.ScalarValue( results.current_page, full_name + '_max', 'ms', biggest_jank)) results.AddValue(scalar.ScalarValue( results.current_page, full_name + '_avg', 'ms', total / len(times))) for counter_name, counter in renderer_process.counters.iteritems(): total = sum(counter.totals) # Results objects cannot contain the '.' character, so remove that here. sanitized_counter_name = counter_name.replace('.', '_') results.AddValue(scalar.ScalarValue( results.current_page, sanitized_counter_name, 'count', total)) results.AddValue(scalar.ScalarValue( results.current_page, sanitized_counter_name + '_avg', 'count', total / float(len(counter.totals)))) # We want to generate a consistant picture of our thread usage, despite # having several process configurations (in-proc-gpu/single-proc). # Since we can't isolate renderer threads in single-process mode, we # always sum renderer-process threads' times. We also sum all io-threads # for simplicity. TimelineThreadCategories = { "Chrome_InProcGpuThread": "GPU", "CrGpuMain" : "GPU", "AsyncTransferThread" : "GPU_transfer", "CrBrowserMain" : "browser", "Browser Compositor" : "browser", "CrRendererMain" : "renderer_main", "Compositor" : "renderer_compositor", "IOThread" : "IO", "CompositorTileWorker" : "raster", "DummyThreadName1" : "other", "DummyThreadName2" : "total_fast_path", "DummyThreadName3" : "total_all" } _MatchBySubString = ["IOThread", "CompositorTileWorker"] AllThreads = TimelineThreadCategories.values() NoThreads = [] FastPathThreads = ["GPU", "renderer_compositor", "browser", "IO"] 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, 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_" + interval_name def ThreadTasksResultName(thread_category, interval_name): return "tasks_per_" + interval_name + "_" + thread_category def ThreadMeanFrameTimeResultName(thread_category): return "mean_frame_time_" + thread_category def ThreadDetailResultName(thread_category, interval_name, detail): detail_sanitized = detail.replace('.','_') interval_sanitized = "" # Special-case per-frame detail names to preserve continuity. if interval_name == "frame": interval_sanitized = "" else: interval_sanitized = "_per_" + interval_name return ( "thread_" + thread_category + interval_sanitized + "|" + detail_sanitized) def ThreadCpuTimeUnits(interval_name): if interval_name == "second": return "%" return "ms" def ThreadCpuTimeValue(ms_cpu_time_per_interval, interval_name): # When measuring seconds of CPU time per second of system time, report a %. if interval_name == "second": return (ms_cpu_time_per_interval / 1000.0) * 100.0 return ms_cpu_time_per_interval 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 cpu_overhead = sum([CpuOverheadForEvent(x) for x in self.all_slices]) for x in self.toplevel_slices: # Only report thread-duration if we have it for all events. # # A thread_duration of 0 is valid, so this only returns 0 if it is None. if x.thread_duration == None: if not x.duration: continue else: return 0 else: cpu_duration += x.thread_duration return cpu_duration - cpu_overhead def SlicesInActions(self, slices): slices_in_actions = [] for event in slices: 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)) # 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, interval_name), ThreadCpuTimeUnits(interval_name), ThreadCpuTimeValue(cpu_per_interval, interval_name))) results.AddValue(scalar.ScalarValue( results.current_page, ThreadTasksResultName(self.name, interval_name), 'tasks', tasks_per_interval)) 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_per_interval = Rate(self_time, num_intervals) results.AddValue(scalar.ScalarValue( results.current_page, ThreadDetailResultName(self.name, interval_name, category), ThreadCpuTimeUnits(interval_name), ThreadCpuTimeValue(self_time_per_interval, interval_name))) all_measured_time = sum(all_self_times) idle_time = max(0, self.all_action_time - all_measured_time) idle_time_per_interval = Rate(idle_time, num_intervals) results.AddValue(scalar.ScalarValue( results.current_page, ThreadDetailResultName(self.name, interval_name, "idle"), ThreadCpuTimeUnits(interval_name), ThreadCpuTimeValue(idle_time_per_interval, interval_name))) 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 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 interaction's number of frames. frame_rate_thread = thread_category_results[FrameTraceThreadName] num_frames = frame_rate_thread.CountTracesWithName(FrameTraceName) # Calculate the interaction's duration. all_threads = thread_category_results['total_all'] num_seconds = all_threads.all_action_time / 1000.0 # 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) # Report mean frame time for the frame rate thread. We could report other # frame rates (eg. renderer_main) but this might get confusing. mean_frame_time = Rate(frame_rate_thread.all_action_time, num_frames) results.AddValue(scalar.ScalarValue( results.current_page, ThreadMeanFrameTimeResultName(FrameTraceThreadName), 'ms', mean_frame_time))