#!/usr/bin/env python3 # -*- coding: utf-8 -*- # # Analyse lock events and compute statistics # # Author: Alex Bennée # 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: k_v[1]["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"]))