diff options
author | Peter Maydell <peter.maydell@linaro.org> | 2018-01-16 15:45:15 +0000 |
---|---|---|
committer | Peter Maydell <peter.maydell@linaro.org> | 2018-01-16 15:45:15 +0000 |
commit | c1d5b9add7b04661bedef9a3379a8b82547b53db (patch) | |
tree | 7c064b14e4a3645aedbd7d7f0009b9ee71ad9952 /scripts/analyse-locks-simpletrace.py | |
parent | aae39d24a387a273deab3eb930dbf730aa379e22 (diff) | |
parent | b5976c2e46e86b36b01d8ac380a182e22209a7cd (diff) |
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-x | scripts/analyse-locks-simpletrace.py | 99 |
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"])) |