| # Copyright 2021 The Chromium OS Authors. All rights reserved. |
| # Use of this source code is governed by a BSD-style license that can be |
| # found in the LICENSE file. |
| |
| """Utility class for analyzing sommelier buffer statistics.""" |
| |
| import argparse |
| from collections import defaultdict |
| import sys |
| |
| class Action(object): |
| """Hold data about sommelier buffer operations.""" |
| |
| __slots__ = ('type', 'bid', 'time') |
| def __init__(self, action_type, bid, time): |
| self.type = action_type |
| self.bid = bid |
| self.time = time |
| |
| |
| class Stats: |
| """For processing text files of sommelier data and printing their stats.""" |
| |
| def __init__(self): |
| self.surfaces = defaultdict(list) |
| self.bid_sid = {} |
| self.sid_bid = {} |
| |
| def read(self, filename): |
| """Read in a sommelier-timing output file for later processing. |
| |
| Sample file: |
| Event, Type, Surface_ID, Buffer_ID, Time # header line 1 |
| 0 surface_attach 12 23 1612345678.987654321 # line 2 |
| 1 surface_commit 12 -1 1612345678.987654325 # lines 3, 4, ... |
| |
| Run sommelier with the timing-filename option to generate an event log: |
| sommelier -X --glamor --trace-system \ |
| --timing-filename=out.txt glxgears & |
| |
| Args: |
| filename (string): The path to the buffer time data. |
| """ |
| |
| with open(filename, 'r') as f: |
| # Skip the header line. |
| f.readline() |
| for line in f: |
| try: |
| [_, action_type, sid, bid, timestamp] = line.split() |
| except ValueError: |
| continue |
| sid = int(sid) |
| bid = int(bid) |
| # use dictionary history to fill missing ids |
| if sid != -1 and bid != -1: |
| self.sid_bid[sid] = bid |
| self.bid_sid[bid] = sid |
| elif sid in self.sid_bid: |
| bid = self.sid_bid[sid] |
| elif bid in self.bid_sid: |
| sid = self.bid_sid[bid] |
| # convert string time into floating point time |
| time = float(timestamp) |
| |
| self.surfaces[sid].append(Action(action_type, bid, time)) |
| |
| def add(self, durr, tot, err): |
| """Kahan sum function to reduce floating point error. |
| |
| Args: |
| durr (float): The elapsed time between two actions. |
| tot (float): The summed total of elapsed times. |
| err (float): The accumulated error. |
| |
| Returns: |
| tot (int): the new summed total of elapsed times. |
| err (int): the new accumulated error. |
| """ |
| y = durr - err |
| t = tot + y |
| err = (t - tot) - y |
| tot = t |
| return tot, err |
| |
| def add_acr(self, sid, time, acr, idx): |
| """Update the sum/total, error, and count of each action type. |
| |
| Args: |
| sid (int): the id of the surface to display stats for. |
| time (float): the time the current action to place. |
| acr (dict): A dicitionary containing numerical info on accumulated stats. |
| idx (dict): A dictionary containing the last index of an action |
| """ |
| for action, pos in idx.items(): |
| if pos is not None: |
| prev_time = self.surfaces[sid][pos].time |
| x = action[0] # use first letter of action type in key names |
| tot, err = self.add(time - prev_time, acr[x], acr[x + 'err']) |
| acr[x] = tot |
| acr[x + 'err'] = err |
| acr[x + '_count'] += 1 |
| |
| def print_stats(self, sid): |
| """Print the average times between calls to a surface. |
| |
| Args: |
| sid (int): the id of the surface to display stats for. |
| """ |
| |
| # to_attach - a dict used in calculating summed difference from any other |
| # call (a, c, r) to an "attach" call. |
| # a - attach, c - commit, r - release |
| # aerr - accumulated numerical error from summing differences. |
| # a_count - count of attach-attach differences so far. |
| to_attach = { |
| 'a': 0, 'aerr': 0, 'a_count': 0, |
| 'c': 0, 'cerr': 0, 'c_count': 0, |
| 'r': 0, 'rerr': 0, 'r_count': 0, |
| } |
| to_commit = { |
| 'a': 0, 'aerr': 0, 'a_count': 0, |
| 'c': 0, 'cerr': 0, 'c_count': 0, |
| 'r': 0, 'rerr': 0, 'r_count': 0, |
| } |
| to_release = { |
| 'a': 0, 'aerr': 0, 'a_count': 0, |
| 'c': 0, 'cerr': 0, 'c_count': 0, |
| 'r': 0, 'rerr': 0, 'r_count': 0, |
| } |
| |
| # idx stores the last index of an attach, commit, and release call. |
| idx = {'attach': None, 'commit': None, 'release': None} |
| # For every action, calculate summed difference based on its type. |
| # e.g. for a commit action, calculate time between it and the previous |
| # attach, commit, and release call using to_commit. |
| for i, action in enumerate(self.surfaces[sid]): |
| time = action.time |
| |
| if action.type == 'attach': |
| self.add_acr(sid, time, to_attach, idx) |
| idx['attach'] = i |
| elif action.type == 'commit': |
| self.add_acr(sid, time, to_commit, idx) |
| idx['commit'] = i |
| elif action.type == 'release': |
| self.add_acr(sid, time, to_release, idx) |
| idx['release'] = i |
| |
| print('attach-attach avg: ', |
| to_attach['a'] * 1000 / to_attach['a_count'], ' ms') |
| print('commit-attach avg: ', |
| to_attach['c'] * 1000 / to_attach['c_count'], ' ms') |
| print('release-attach avg: ', |
| to_attach['r'] * 1000 / to_attach['r_count'], ' ms') |
| print() |
| print('commit-commit avg: ', |
| to_commit['c'] * 1000 / to_commit['c_count'], ' ms') |
| print('attach-commit avg: ', |
| to_commit['a'] * 1000 / to_commit['a_count'], ' ms') |
| print('release-commit avg: ', |
| to_commit['r'] * 1000 / to_commit['r_count'], ' ms') |
| print() |
| print('release-release avg: ', |
| to_release['r'] * 1000 / to_release['r_count'], ' ms') |
| print('attach-release avg: ', |
| to_release['a'] * 1000 / to_release['a_count'], ' ms') |
| print('commit-release avg: ', |
| to_release['c'] * 1000 / to_release['c_count'], ' ms') |
| |
| |
| def main(args): |
| parser = argparse.ArgumentParser( |
| description='Compute average of interprocess times') |
| parser.add_argument('file', |
| type=str, |
| help='the timing log file to process') |
| parser.add_argument('--surface_id', |
| type=int, |
| help='the id of the surface to compute averages on') |
| args = parser.parse_args() |
| log = args.file |
| sid = args.surface_id |
| stats = Stats() |
| stats.read(log) |
| # Print buffer stats for the sid with the most number of actions. |
| if not sid: |
| sid = next(iter(stats.surfaces.keys())) |
| for key in stats.surfaces: |
| if len(stats.surfaces[key]) > len(stats.surfaces[sid]): |
| sid = key |
| stats.print_stats(sid) |
| |
| if __name__ == '__main__': |
| main(sys.argv[1:]) |
