245 lines
7.5 KiB
Python
245 lines
7.5 KiB
Python
|
# Copyright 2021 The ChromiumOS Authors
|
||
|
|
# 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:])
|