qemu/scripts/analyse-locks-simpletrace.py
<<
>>
Prefs
   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 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: k_v[1]["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