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