[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]
[Qemu-devel] [RFC PATCH 24/26] scripts/analyse-locks-simpletrace.py: scr
From: |
Pavel Dovgalyuk |
Subject: |
[Qemu-devel] [RFC PATCH 24/26] scripts/analyse-locks-simpletrace.py: script to analyse lock times |
Date: |
Tue, 31 Oct 2017 14:08:51 +0300 |
User-agent: |
StGit/0.17.1-dirty |
From: Alex Bennée <address@hidden>
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 <address@hidden>
---
scripts/analyse-locks-simpletrace.py | 99 ++++++++++++++++++++++++++++++++++
1 file changed, 99 insertions(+)
create mode 100755 scripts/analyse-locks-simpletrace.py
diff --git a/scripts/analyse-locks-simpletrace.py
b/scripts/analyse-locks-simpletrace.py
new file mode 100755
index 0000000..b72c951
--- /dev/null
+++ b/scripts/analyse-locks-simpletrace.py
@@ -0,0 +1,99 @@
+#!/usr/bin/env python
+# -*- coding: utf-8 -*-
+#
+# Analyse lock events and
+#
+# Author: Alex Bennée <address@hidden>
+#
+
+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"]))
- [Qemu-devel] [RFC PATCH 14/26] replay/replay.c: bump REPLAY_VERSION again, (continued)
- [Qemu-devel] [RFC PATCH 14/26] replay/replay.c: bump REPLAY_VERSION again, Pavel Dovgalyuk, 2017/10/31
- [Qemu-devel] [RFC PATCH 15/26] replay/replay-internal.c: track holding of replay_lock, Pavel Dovgalyuk, 2017/10/31
- [Qemu-devel] [RFC PATCH 17/26] replay: push replay_mutex_lock up the call tree, Pavel Dovgalyuk, 2017/10/31
- [Qemu-devel] [RFC PATCH 16/26] replay: make locking visible outside replay code, Pavel Dovgalyuk, 2017/10/31
- [Qemu-devel] [RFC PATCH 18/26] cpu-exec: don't overwrite exception_index, Pavel Dovgalyuk, 2017/10/31
- [Qemu-devel] [RFC PATCH 19/26] cpu-exec: reset exit flag before calling cpu_exec_nocache, Pavel Dovgalyuk, 2017/10/31
- [Qemu-devel] [RFC PATCH 20/26] replay: don't destroy mutex at exit, Pavel Dovgalyuk, 2017/10/31
- [Qemu-devel] [RFC PATCH 21/26] replay: check return values of fwrite, Pavel Dovgalyuk, 2017/10/31
- [Qemu-devel] [RFC PATCH 22/26] scripts/qemu-gdb: add simple tcg lock status helper, Pavel Dovgalyuk, 2017/10/31
- [Qemu-devel] [RFC PATCH 23/26] util/qemu-thread-*: add qemu_lock, locked and unlock trace events, Pavel Dovgalyuk, 2017/10/31
- [Qemu-devel] [RFC PATCH 24/26] scripts/analyse-locks-simpletrace.py: script to analyse lock times,
Pavel Dovgalyuk <=
- [Qemu-devel] [RFC PATCH 26/26] scripts/qemu-gdb/timers.py: new helper to dump timer state, Pavel Dovgalyuk, 2017/10/31
- [Qemu-devel] [RFC PATCH 25/26] scripts/replay-dump.py: replay log dumper, Pavel Dovgalyuk, 2017/10/31
- Re: [Qemu-devel] [RFC PATCH 00/26] replay additions, no-reply, 2017/10/31
- [Qemu-devel] [RFC PATCH 00/26] replay additions, Pavel Dovgalyuk, 2017/10/31
- [Qemu-devel] [RFC PATCH 01/26] block: implement bdrv_snapshot_goto for blkreplay, Pavel Dovgalyuk, 2017/10/31
- [Qemu-devel] [RFC PATCH 02/26] blkreplay: create temporary overlay for underlaying devices, Pavel Dovgalyuk, 2017/10/31
- [Qemu-devel] [RFC PATCH 03/26] replay: disable default snapshot for record/replay, Pavel Dovgalyuk, 2017/10/31
- [Qemu-devel] [RFC PATCH 04/26] replay: fix processing async events, Pavel Dovgalyuk, 2017/10/31
- [Qemu-devel] [RFC PATCH 05/26] replay: fixed replay_enable_events, Pavel Dovgalyuk, 2017/10/31
- [Qemu-devel] [RFC PATCH 06/26] replay: fix save/load vm for non-empty queue, Pavel Dovgalyuk, 2017/10/31