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