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