diff --git a/scripts/analyse-locks-simpletrace.py b/scripts/analyse-locks-simpletrace.py new file mode 100755 index 0000000000..101e84dea5 --- /dev/null +++ b/scripts/analyse-locks-simpletrace.py @@ -0,0 +1,99 @@ +#!/usr/bin/env python +# -*- coding: utf-8 -*- +# +# Analyse lock events and compute statistics +# +# Author: Alex Bennée +# + +import os +import simpletrace +import argparse +import numpy as np + +class MutexAnalyser(simpletrace.Analyzer): + "A simpletrace Analyser for checking locks." + + def __init__(self): + self.locks = 0 + self.locked = 0 + self.unlocks = 0 + self.mutex_records = {} + + def _get_mutex(self, mutex): + if not mutex in self.mutex_records: + self.mutex_records[mutex] = {"locks": 0, + "lock_time": 0, + "acquire_times": [], + "locked": 0, + "locked_time": 0, + "held_times": [], + "unlocked": 0} + + return self.mutex_records[mutex] + + def qemu_mutex_lock(self, timestamp, mutex, filename, line): + self.locks += 1 + rec = self._get_mutex(mutex) + rec["locks"] += 1 + rec["lock_time"] = timestamp[0] + rec["lock_loc"] = (filename, line) + + def qemu_mutex_locked(self, timestamp, mutex, filename, line): + self.locked += 1 + rec = self._get_mutex(mutex) + rec["locked"] += 1 + rec["locked_time"] = timestamp[0] + acquire_time = rec["locked_time"] - rec["lock_time"] + rec["locked_loc"] = (filename, line) + rec["acquire_times"].append(acquire_time) + + def qemu_mutex_unlock(self, timestamp, mutex, filename, line): + self.unlocks += 1 + rec = self._get_mutex(mutex) + rec["unlocked"] += 1 + held_time = timestamp[0] - rec["locked_time"] + rec["held_times"].append(held_time) + rec["unlock_loc"] = (filename, line) + + +def get_args(): + "Grab options" + parser = argparse.ArgumentParser() + parser.add_argument("--output", "-o", type=str, help="Render plot to file") + parser.add_argument("events", type=str, help='trace file read from') + parser.add_argument("tracefile", type=str, help='trace file read from') + return parser.parse_args() + +if __name__ == '__main__': + args = get_args() + + # Gather data from the trace + analyser = MutexAnalyser() + simpletrace.process(args.events, args.tracefile, analyser) + + print ("Total locks: %d, locked: %d, unlocked: %d" % + (analyser.locks, analyser.locked, analyser.unlocks)) + + # Now dump the individual lock stats + for key, val in sorted(analyser.mutex_records.iteritems(), + key=lambda (k,v): v["locks"]): + print ("Lock: %#x locks: %d, locked: %d, unlocked: %d" % + (key, val["locks"], val["locked"], val["unlocked"])) + + acquire_times = np.array(val["acquire_times"]) + if len(acquire_times) > 0: + print (" Acquire Time: min:%d median:%d avg:%.2f max:%d" % + (acquire_times.min(), np.median(acquire_times), + acquire_times.mean(), acquire_times.max())) + + held_times = np.array(val["held_times"]) + if len(held_times) > 0: + print (" Held Time: min:%d median:%d avg:%.2f max:%d" % + (held_times.min(), np.median(held_times), + held_times.mean(), held_times.max())) + + # Check if any locks still held + if val["locks"] > val["locked"]: + print (" LOCK HELD (%s:%s)" % (val["locked_loc"])) + print (" BLOCKED (%s:%s)" % (val["lock_loc"]))