summary refs log tree commit diff stats
path: root/scripts/analyse-locks-simpletrace.py
diff options
context:
space:
mode:
authorPeter Maydell <peter.maydell@linaro.org>2018-01-16 15:45:15 +0000
committerPeter Maydell <peter.maydell@linaro.org>2018-01-16 15:45:15 +0000
commitc1d5b9add7b04661bedef9a3379a8b82547b53db (patch)
tree7c064b14e4a3645aedbd7d7f0009b9ee71ad9952 /scripts/analyse-locks-simpletrace.py
parentaae39d24a387a273deab3eb930dbf730aa379e22 (diff)
parentb5976c2e46e86b36b01d8ac380a182e22209a7cd (diff)
downloadfocaccia-qemu-c1d5b9add7b04661bedef9a3379a8b82547b53db.tar.gz
focaccia-qemu-c1d5b9add7b04661bedef9a3379a8b82547b53db.zip
Merge remote-tracking branch 'remotes/bonzini/tags/for-upstream' into staging
* QemuMutex tracing improvements (Alex)
* ram_addr_t optimization (David)
* SCSI fixes (Fam, Stefan, me)
* do {} while (0) fixes (Eric)
* KVM fix for PMU (Jan)
* memory leak fixes from ASAN (Marc-André)
* migration fix for HPET, icount, loadvm (Maria, Pavel)
* hflags fixes (me, Tao)
* block/iscsi uninitialized variable (Peter L.)
* full support for GMainContexts in character devices (Peter Xu)
* more boot-serial-test (Thomas)
* Memory leak fix (Zhecheng)

# gpg: Signature made Tue 16 Jan 2018 14:15:45 GMT
# gpg:                using RSA key 0xBFFBD25F78C7AE83
# gpg: Good signature from "Paolo Bonzini <bonzini@gnu.org>"
# gpg:                 aka "Paolo Bonzini <pbonzini@redhat.com>"
# Primary key fingerprint: 46F5 9FBD 57D6 12E7 BFD4  E2F7 7E15 100C CD36 69B1
#      Subkey fingerprint: F133 3857 4B66 2389 866C  7682 BFFB D25F 78C7 AE83

* remotes/bonzini/tags/for-upstream: (51 commits)
  scripts/analyse-locks-simpletrace.py: script to analyse lock times
  util/qemu-thread-*: add qemu_lock, locked and unlock trace events
  cpu: flush TB cache when loading VMState
  block/iscsi: fix initialization of iTask in iscsi_co_get_block_status
  find_ram_offset: Align ram_addr_t allocation on long boundaries
  find_ram_offset: Add comments and tracing
  cpu_physical_memory_sync_dirty_bitmap: Another alignment fix
  checkpatch: Enforce proper do/while (0) style
  maint: Fix macros with broken 'do/while(0); ' usage
  tests: Avoid 'do/while(false); ' in vhost-user-bridge
  chardev: Clean up previous patch indentation
  chardev: Use goto/label instead of do/break/while(0)
  mips: Tweak location of ';' in macros
  net: Drop unusual use of do { } while (0);
  irq: fix memory leak
  cpus: unify qemu_*_wait_io_event
  icount: fixed saving/restoring of icount warp timers
  scripts/qemu-gdb/timers.py: new helper to dump timer state
  scripts/qemu-gdb: add simple tcg lock status helper
  target-i386: update hflags on Hypervisor.framework
  ...

Signed-off-by: Peter Maydell <peter.maydell@linaro.org>
Diffstat (limited to 'scripts/analyse-locks-simpletrace.py')
-rwxr-xr-xscripts/analyse-locks-simpletrace.py99
1 files changed, 99 insertions, 0 deletions
diff --git a/scripts/analyse-locks-simpletrace.py b/scripts/analyse-locks-simpletrace.py
new file mode 100755
index 0000000000..101e84dea5
--- /dev/null
+++ b/scripts/analyse-locks-simpletrace.py
@@ -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"]))