mirror of
https://gitlab.com/qemu-project/qemu
synced 2024-09-06 01:43:39 +00:00
scripts/analyse-locks-simpletrace.py: script to analyse lock times
This script allows analysis of mutex acquisition and hold times based on a trace file. Given a trace control file of: qemu_mutex_lock qemu_mutex_locked qemu_mutex_unlock And running with: $QEMU $QEMU_ARGS -trace events=./lock-trace You can analyse the results with: ./scripts/analyse-locks-simpletrace.py trace-events-all ./trace-21812 Signed-off-by: Alex Bennée <alex.bennee@linaro.org> Signed-off-by: Paolo Bonzini <pbonzini@redhat.com>
This commit is contained in:
parent
6c27a0ded9
commit
b5976c2e46
99
scripts/analyse-locks-simpletrace.py
Executable file
99
scripts/analyse-locks-simpletrace.py
Executable file
|
@ -0,0 +1,99 @@
|
|||
#!/usr/bin/env python
|
||||
# -*- coding: utf-8 -*-
|
||||
#
|
||||
# Analyse lock events and compute statistics
|
||||
#
|
||||
# Author: Alex Bennée <alex.bennee@linaro.org>
|
||||
#
|
||||
|
||||
import os
|
||||
import simpletrace
|
||||
import argparse
|
||||
import numpy as np
|
||||
|
||||
class MutexAnalyser(simpletrace.Analyzer):
|
||||
"A simpletrace Analyser for checking locks."
|
||||
|
||||
def __init__(self):
|
||||
self.locks = 0
|
||||
self.locked = 0
|
||||
self.unlocks = 0
|
||||
self.mutex_records = {}
|
||||
|
||||
def _get_mutex(self, mutex):
|
||||
if not mutex in self.mutex_records:
|
||||
self.mutex_records[mutex] = {"locks": 0,
|
||||
"lock_time": 0,
|
||||
"acquire_times": [],
|
||||
"locked": 0,
|
||||
"locked_time": 0,
|
||||
"held_times": [],
|
||||
"unlocked": 0}
|
||||
|
||||
return self.mutex_records[mutex]
|
||||
|
||||
def qemu_mutex_lock(self, timestamp, mutex, filename, line):
|
||||
self.locks += 1
|
||||
rec = self._get_mutex(mutex)
|
||||
rec["locks"] += 1
|
||||
rec["lock_time"] = timestamp[0]
|
||||
rec["lock_loc"] = (filename, line)
|
||||
|
||||
def qemu_mutex_locked(self, timestamp, mutex, filename, line):
|
||||
self.locked += 1
|
||||
rec = self._get_mutex(mutex)
|
||||
rec["locked"] += 1
|
||||
rec["locked_time"] = timestamp[0]
|
||||
acquire_time = rec["locked_time"] - rec["lock_time"]
|
||||
rec["locked_loc"] = (filename, line)
|
||||
rec["acquire_times"].append(acquire_time)
|
||||
|
||||
def qemu_mutex_unlock(self, timestamp, mutex, filename, line):
|
||||
self.unlocks += 1
|
||||
rec = self._get_mutex(mutex)
|
||||
rec["unlocked"] += 1
|
||||
held_time = timestamp[0] - rec["locked_time"]
|
||||
rec["held_times"].append(held_time)
|
||||
rec["unlock_loc"] = (filename, line)
|
||||
|
||||
|
||||
def get_args():
|
||||
"Grab options"
|
||||
parser = argparse.ArgumentParser()
|
||||
parser.add_argument("--output", "-o", type=str, help="Render plot to file")
|
||||
parser.add_argument("events", type=str, help='trace file read from')
|
||||
parser.add_argument("tracefile", type=str, help='trace file read from')
|
||||
return parser.parse_args()
|
||||
|
||||
if __name__ == '__main__':
|
||||
args = get_args()
|
||||
|
||||
# Gather data from the trace
|
||||
analyser = MutexAnalyser()
|
||||
simpletrace.process(args.events, args.tracefile, analyser)
|
||||
|
||||
print ("Total locks: %d, locked: %d, unlocked: %d" %
|
||||
(analyser.locks, analyser.locked, analyser.unlocks))
|
||||
|
||||
# Now dump the individual lock stats
|
||||
for key, val in sorted(analyser.mutex_records.iteritems(),
|
||||
key=lambda (k,v): v["locks"]):
|
||||
print ("Lock: %#x locks: %d, locked: %d, unlocked: %d" %
|
||||
(key, val["locks"], val["locked"], val["unlocked"]))
|
||||
|
||||
acquire_times = np.array(val["acquire_times"])
|
||||
if len(acquire_times) > 0:
|
||||
print (" Acquire Time: min:%d median:%d avg:%.2f max:%d" %
|
||||
(acquire_times.min(), np.median(acquire_times),
|
||||
acquire_times.mean(), acquire_times.max()))
|
||||
|
||||
held_times = np.array(val["held_times"])
|
||||
if len(held_times) > 0:
|
||||
print (" Held Time: min:%d median:%d avg:%.2f max:%d" %
|
||||
(held_times.min(), np.median(held_times),
|
||||
held_times.mean(), held_times.max()))
|
||||
|
||||
# Check if any locks still held
|
||||
if val["locks"] > val["locked"]:
|
||||
print (" LOCK HELD (%s:%s)" % (val["locked_loc"]))
|
||||
print (" BLOCKED (%s:%s)" % (val["lock_loc"]))
|
Loading…
Reference in a new issue