1#!/usr/bin/env python 2# -*- coding: utf-8 -*- 3# 4# Analyse lock events and compute statistics 5# 6# Author: Alex Bennée <alex.bennee@linaro.org> 7# 8 9import os 10import simpletrace 11import argparse 12import numpy as np 13 14class MutexAnalyser(simpletrace.Analyzer): 15 "A simpletrace Analyser for checking locks." 16 17 def __init__(self): 18 self.locks = 0 19 self.locked = 0 20 self.unlocks = 0 21 self.mutex_records = {} 22 23 def _get_mutex(self, mutex): 24 if not mutex in self.mutex_records: 25 self.mutex_records[mutex] = {"locks": 0, 26 "lock_time": 0, 27 "acquire_times": [], 28 "locked": 0, 29 "locked_time": 0, 30 "held_times": [], 31 "unlocked": 0} 32 33 return self.mutex_records[mutex] 34 35 def qemu_mutex_lock(self, timestamp, mutex, filename, line): 36 self.locks += 1 37 rec = self._get_mutex(mutex) 38 rec["locks"] += 1 39 rec["lock_time"] = timestamp[0] 40 rec["lock_loc"] = (filename, line) 41 42 def qemu_mutex_locked(self, timestamp, mutex, filename, line): 43 self.locked += 1 44 rec = self._get_mutex(mutex) 45 rec["locked"] += 1 46 rec["locked_time"] = timestamp[0] 47 acquire_time = rec["locked_time"] - rec["lock_time"] 48 rec["locked_loc"] = (filename, line) 49 rec["acquire_times"].append(acquire_time) 50 51 def qemu_mutex_unlock(self, timestamp, mutex, filename, line): 52 self.unlocks += 1 53 rec = self._get_mutex(mutex) 54 rec["unlocked"] += 1 55 held_time = timestamp[0] - rec["locked_time"] 56 rec["held_times"].append(held_time) 57 rec["unlock_loc"] = (filename, line) 58 59 60def get_args(): 61 "Grab options" 62 parser = argparse.ArgumentParser() 63 parser.add_argument("--output", "-o", type=str, help="Render plot to file") 64 parser.add_argument("events", type=str, help='trace file read from') 65 parser.add_argument("tracefile", type=str, help='trace file read from') 66 return parser.parse_args() 67 68if __name__ == '__main__': 69 args = get_args() 70 71 # Gather data from the trace 72 analyser = MutexAnalyser() 73 simpletrace.process(args.events, args.tracefile, analyser) 74 75 print ("Total locks: %d, locked: %d, unlocked: %d" % 76 (analyser.locks, analyser.locked, analyser.unlocks)) 77 78 # Now dump the individual lock stats 79 for key, val in sorted(analyser.mutex_records.iteritems(), 80 key=lambda (k,v): v["locks"]): 81 print ("Lock: %#x locks: %d, locked: %d, unlocked: %d" % 82 (key, val["locks"], val["locked"], val["unlocked"])) 83 84 acquire_times = np.array(val["acquire_times"]) 85 if len(acquire_times) > 0: 86 print (" Acquire Time: min:%d median:%d avg:%.2f max:%d" % 87 (acquire_times.min(), np.median(acquire_times), 88 acquire_times.mean(), acquire_times.max())) 89 90 held_times = np.array(val["held_times"]) 91 if len(held_times) > 0: 92 print (" Held Time: min:%d median:%d avg:%.2f max:%d" % 93 (held_times.min(), np.median(held_times), 94 held_times.mean(), held_times.max())) 95 96 # Check if any locks still held 97 if val["locks"] > val["locked"]: 98 print (" LOCK HELD (%s:%s)" % (val["locked_loc"])) 99 print (" BLOCKED (%s:%s)" % (val["lock_loc"])) 100