From patchwork Tue Mar 13 22:47:15 2018 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 8bit X-Patchwork-Submitter: Paolo Bonzini X-Patchwork-Id: 131539 Delivered-To: patch@linaro.org Received: by 10.46.84.17 with SMTP id i17csp177219ljb; Tue, 13 Mar 2018 16:36:40 -0700 (PDT) X-Google-Smtp-Source: AG47ELutAkw8RhPpA4sOjIDUZPjbUtAeFpKHXnGkCkisKGiiDVJ/NBKEp8V+k5/X76AqANSFMLQf X-Received: by 10.55.239.26 with SMTP id j26mr3795848qkk.315.1520984200334; Tue, 13 Mar 2018 16:36:40 -0700 (PDT) ARC-Seal: i=1; a=rsa-sha256; t=1520984200; cv=none; d=google.com; s=arc-20160816; b=SKAxVgp9yJQ8OkrHCf09QsNmoevIeUh8cwa2H14yR4BaWro9R8F5b3rZMN8eI0epe2 3Hl0SUfuifF4sIGSa4ooBqOaE6yJoND01zA9kblwsQ2+GVcnF2zTsEUzb7eCswcdAUPS xfrR4TfB4mQ8J6RGHAza6E5DC3pgx3sSsJHaM0kmvYjBOmZBk5IOBaq8VCCgRBPtIn2d 5vXQUM/4OeoIOftaF4e8PaLmJRkDaHA3+RVCYaKnUnTETobRXah10DayN7ARVgwF6VKS gCDgjyeUjj3qYR4yuq3bdR4VqQEQ52ZkSnVhD21iRHmJW1t8oF1HLH06PYRrnFZgGAYZ U+rg== ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=google.com; s=arc-20160816; h=sender:errors-to:cc:list-subscribe:list-help:list-post:list-archive :list-unsubscribe:list-id:precedence:subject :content-transfer-encoding:mime-version:references:in-reply-to :message-id:date:to:from:dkim-signature:arc-authentication-results; bh=4Vlrd7SbMe43nB+/halXfcomflyEBlE8n2JZ+Snr2Jg=; b=ZkeN5okgAhYs6BEyus6hgBquIVT2FOgaFGDGoMdG4vCmtamelLe6h9gSuZLCxaJaQt VvebOMC5II4dfIHxNWY9sFOPGW4fK/N2C3APFP3oWNm6YtYyp2eSC+9d2spviRZEhCWD RtotcJdm8RzQbyAyu4a0gUuKWS0XHmkMX4YUG7EdXyxm1sDXnSmYb+Slcbjddxl+SyIH C/F98GuJBXsZv8EYTfiZIrrGzrDfC7gg9D6FCh6p1+jyx5wRx7Bgs2B8ezsoYsSmWYm8 OPgXcdyV5wELLgXKypR5Kq6b4/MXmi+wh/gH3YmCgfiHJPzakvpc/K3q8Gbxjr6uOrTA xbPg== ARC-Authentication-Results: i=1; mx.google.com; dkim=fail header.i=@gmail.com header.s=20161025 header.b=i8+7cD65; spf=pass (google.com: domain of qemu-devel-bounces+patch=linaro.org@nongnu.org designates 2001:4830:134:3::11 as permitted sender) smtp.mailfrom=qemu-devel-bounces+patch=linaro.org@nongnu.org; dmarc=fail (p=NONE sp=NONE dis=NONE) header.from=redhat.com Return-Path: Received: from lists.gnu.org (lists.gnu.org. [2001:4830:134:3::11]) by mx.google.com with ESMTPS id p57si1447856qtf.335.2018.03.13.16.36.40 for (version=TLS1 cipher=AES128-SHA bits=128/128); Tue, 13 Mar 2018 16:36:40 -0700 (PDT) Received-SPF: pass (google.com: domain of qemu-devel-bounces+patch=linaro.org@nongnu.org designates 2001:4830:134:3::11 as permitted sender) client-ip=2001:4830:134:3::11; Authentication-Results: mx.google.com; dkim=fail header.i=@gmail.com header.s=20161025 header.b=i8+7cD65; spf=pass (google.com: domain of qemu-devel-bounces+patch=linaro.org@nongnu.org designates 2001:4830:134:3::11 as permitted sender) smtp.mailfrom=qemu-devel-bounces+patch=linaro.org@nongnu.org; dmarc=fail (p=NONE sp=NONE dis=NONE) header.from=redhat.com Received: from localhost ([::1]:43550 helo=lists.gnu.org) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1evtTD-0005yS-OC for patch@linaro.org; Tue, 13 Mar 2018 19:36:39 -0400 Received: from eggs.gnu.org ([2001:4830:134:3::10]:58809) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1evsir-0006Up-90 for qemu-devel@nongnu.org; Tue, 13 Mar 2018 18:48:47 -0400 Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71) (envelope-from ) id 1evsip-0004Eu-CR for qemu-devel@nongnu.org; Tue, 13 Mar 2018 18:48:45 -0400 Received: from mail-wr0-x234.google.com ([2a00:1450:400c:c0c::234]:35976) by eggs.gnu.org with esmtps (TLS1.0:RSA_AES_128_CBC_SHA1:16) (Exim 4.71) (envelope-from ) id 1evsip-0004EG-1P for qemu-devel@nongnu.org; Tue, 13 Mar 2018 18:48:43 -0400 Received: by mail-wr0-x234.google.com with SMTP id d10so2573276wrf.3 for ; Tue, 13 Mar 2018 15:48:42 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20161025; h=sender:from:to:cc:subject:date:message-id:in-reply-to:references :mime-version:content-transfer-encoding; bh=4Vlrd7SbMe43nB+/halXfcomflyEBlE8n2JZ+Snr2Jg=; b=i8+7cD65lAhNKWvXqTodXfJWwQu0QoQFhqHxsPTVegK02NlB7n5wyYexd5qZ/FtBRx QiFo+VTIu1kTXyEt3T0eWBdcy0Iop0H9/8hKYl6fwlSE8tHfSNEOqBHUtuvkFvOOlRdY RcuPxwLL3OppLKfo03spP6TfHpxakOEnF8JWndYCEuBzftoet4FHcreXkjZ9klmbE1iv Uq2kcNuhpApgu7ZRzyhiCAioYcMmhOlZJH6njIJ3JW1LNRKXP650gcCuWwOHxcFWJeBH vCxjGsOk/iutXNm5Es3TyfuG5ihtY9nQLloiMjdNlU5t4I5PVxXWQNpGW/JibRsN/sJ7 T/fw== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:sender:from:to:cc:subject:date:message-id :in-reply-to:references:mime-version:content-transfer-encoding; bh=4Vlrd7SbMe43nB+/halXfcomflyEBlE8n2JZ+Snr2Jg=; b=qc0V0UjCp4VqLXwE4S6kVsFs8O03NfMFA9iJuNWbyRpQxYZEzvoIBmWF7ev72KvFTl 07oEVbr8Ltux8Y51ROzOQrFSirm83i1/wmVVRhhyCEjbiIlcsCdChYtiLZHPlKADez4P f4p4QRl0bnvNYwvEG8EJeVDD0pTdze0tykwVAQ6SokkLv+Prroyke7Qlr6ztDIAN2uz3 I4D6henD3klf65Q/gM0YOBfX6p2qdqv2YOl4Wy83V2uHVRiB6//EzBZIarz3vgstpQql krzDEWQpjw4Y7bV11naLUTwWi1DW+m5Vd0gL4D7Q/uUOx06uPuSB+9T0sV8GYutoIJ6Q t6+Q== X-Gm-Message-State: AElRT7EYLfQjvbog3p6PEV3JAMWjpyGXzfuAhZFJ/BzROR86HfkX2dbs qtm2SWllZlfq5NxGyiZraBeOrk5c X-Received: by 10.223.176.237 with SMTP id j42mr1939890wra.25.1520981321487; Tue, 13 Mar 2018 15:48:41 -0700 (PDT) Received: from donizetti.lan (94-36-191-219.adsl-ull.clienti.tiscali.it. [94.36.191.219]) by smtp.gmail.com with ESMTPSA id x107sm1557951wrb.97.2018.03.13.15.48.40 (version=TLS1_2 cipher=ECDHE-RSA-CHACHA20-POLY1305 bits=256/256); Tue, 13 Mar 2018 15:48:40 -0700 (PDT) From: Paolo Bonzini To: qemu-devel@nongnu.org Date: Tue, 13 Mar 2018 23:47:15 +0100 Message-Id: <20180313224719.4954-66-pbonzini@redhat.com> X-Mailer: git-send-email 2.14.3 In-Reply-To: <20180313224719.4954-1-pbonzini@redhat.com> References: <20180313224719.4954-1-pbonzini@redhat.com> MIME-Version: 1.0 X-detected-operating-system: by eggs.gnu.org: Genre and OS details not recognized. X-Received-From: 2a00:1450:400c:c0c::234 Subject: [Qemu-devel] [PULL 65/69] scripts/replay-dump.py: replay log dumper X-BeenThere: qemu-devel@nongnu.org X-Mailman-Version: 2.1.21 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Cc: =?utf-8?q?Alex_Benn=C3=A9e?= Errors-To: qemu-devel-bounces+patch=linaro.org@nongnu.org Sender: "Qemu-devel" From: Alex Bennée This script is a debugging tool for looking through the contents of a replay log file. It is incomplete but should fail gracefully at events it doesn't understand. It currently understands two different log formats as the audio record/replay support was merged during since MTTCG. It was written to help debug what has caused the BQL changes to break replay support. Signed-off-by: Alex Bennée Message-Id: <20180227095310.1060.14500.stgit@pasha-VirtualBox> Signed-off-by: Paolo Bonzini --- scripts/replay-dump.py | 308 +++++++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 308 insertions(+) create mode 100755 scripts/replay-dump.py -- 2.14.3 diff --git a/scripts/replay-dump.py b/scripts/replay-dump.py new file mode 100755 index 0000000000..e274086277 --- /dev/null +++ b/scripts/replay-dump.py @@ -0,0 +1,308 @@ +#!/usr/bin/env python +# -*- coding: utf-8 -*- +# +# Dump the contents of a recorded execution stream +# +# Copyright (c) 2017 Alex Bennée +# +# This library is free software; you can redistribute it and/or +# modify it under the terms of the GNU Lesser General Public +# License as published by the Free Software Foundation; either +# version 2 of the License, or (at your option) any later version. +# +# This library is distributed in the hope that it will be useful, +# but WITHOUT ANY WARRANTY; without even the implied warranty of +# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU +# Lesser General Public License for more details. +# +# You should have received a copy of the GNU Lesser General Public +# License along with this library; if not, see . + +import argparse +import struct +from collections import namedtuple + +# This mirrors some of the global replay state which some of the +# stream loading refers to. Some decoders may read the next event so +# we need handle that case. Calling reuse_event will ensure the next +# event is read from the cache rather than advancing the file. + +class ReplayState(object): + def __init__(self): + self.event = -1 + self.event_count = 0 + self.already_read = False + self.current_checkpoint = 0 + self.checkpoint = 0 + + def set_event(self, ev): + self.event = ev + self.event_count += 1 + + def get_event(self): + self.already_read = False + return self.event + + def reuse_event(self, ev): + self.event = ev + self.already_read = True + + def set_checkpoint(self): + self.checkpoint = self.event - self.checkpoint_start + + def get_checkpoint(self): + return self.checkpoint + +replay_state = ReplayState() + +# Simple read functions that mirror replay-internal.c +# The file-stream is big-endian and manually written out a byte at a time. + +def read_byte(fin): + "Read a single byte" + return struct.unpack('>B', fin.read(1))[0] + +def read_event(fin): + "Read a single byte event, but save some state" + if replay_state.already_read: + return replay_state.get_event() + else: + replay_state.set_event(read_byte(fin)) + return replay_state.event + +def read_word(fin): + "Read a 16 bit word" + return struct.unpack('>H', fin.read(2))[0] + +def read_dword(fin): + "Read a 32 bit word" + return struct.unpack('>I', fin.read(4))[0] + +def read_qword(fin): + "Read a 64 bit word" + return struct.unpack('>Q', fin.read(8))[0] + +# Generic decoder structure +Decoder = namedtuple("Decoder", "eid name fn") + +def call_decode(table, index, dumpfile): + "Search decode table for next step" + decoder = next((d for d in table if d.eid == index), None) + if not decoder: + print "Could not decode index: %d" % (index) + print "Entry is: %s" % (decoder) + print "Decode Table is:\n%s" % (table) + return False + else: + return decoder.fn(decoder.eid, decoder.name, dumpfile) + +# Print event +def print_event(eid, name, string=None, event_count=None): + "Print event with count" + if not event_count: + event_count = replay_state.event_count + + if string: + print "%d:%s(%d) %s" % (event_count, name, eid, string) + else: + print "%d:%s(%d)" % (event_count, name, eid) + + +# Decoders for each event type + +def decode_unimp(eid, name, _unused_dumpfile): + "Unimplimented decoder, will trigger exit" + print "%s not handled - will now stop" % (name) + return False + +# Checkpoint decoder +def swallow_async_qword(eid, name, dumpfile): + "Swallow a qword of data without looking at it" + step_id = read_qword(dumpfile) + print " %s(%d) @ %d" % (name, eid, step_id) + return True + +async_decode_table = [ Decoder(0, "REPLAY_ASYNC_EVENT_BH", swallow_async_qword), + Decoder(1, "REPLAY_ASYNC_INPUT", decode_unimp), + Decoder(2, "REPLAY_ASYNC_INPUT_SYNC", decode_unimp), + Decoder(3, "REPLAY_ASYNC_CHAR_READ", decode_unimp), + Decoder(4, "REPLAY_ASYNC_EVENT_BLOCK", decode_unimp), + Decoder(5, "REPLAY_ASYNC_EVENT_NET", decode_unimp), +] +# See replay_read_events/replay_read_event +def decode_async(eid, name, dumpfile): + """Decode an ASYNC event""" + + print_event(eid, name) + + async_event_kind = read_byte(dumpfile) + async_event_checkpoint = read_byte(dumpfile) + + if async_event_checkpoint != replay_state.current_checkpoint: + print " mismatch between checkpoint %d and async data %d" % ( + replay_state.current_checkpoint, async_event_checkpoint) + return True + + return call_decode(async_decode_table, async_event_kind, dumpfile) + + +def decode_instruction(eid, name, dumpfile): + ins_diff = read_dword(dumpfile) + print_event(eid, name, "0x%x" % (ins_diff)) + return True + +def decode_audio_out(eid, name, dumpfile): + audio_data = read_dword(dumpfile) + print_event(eid, name, "%d" % (audio_data)) + return True + +def decode_checkpoint(eid, name, dumpfile): + """Decode a checkpoint. + + Checkpoints contain a series of async events with their own specific data. + """ + replay_state.set_checkpoint() + # save event count as we peek ahead + event_number = replay_state.event_count + next_event = read_event(dumpfile) + + # if the next event is EVENT_ASYNC there are a bunch of + # async events to read, otherwise we are done + if next_event != 3: + print_event(eid, name, "no additional data", event_number) + else: + print_event(eid, name, "more data follows", event_number) + + replay_state.reuse_event(next_event) + return True + +def decode_checkpoint_init(eid, name, dumpfile): + print_event(eid, name) + return True + +def decode_interrupt(eid, name, dumpfile): + print_event(eid, name) + return True + +def decode_clock(eid, name, dumpfile): + clock_data = read_qword(dumpfile) + print_event(eid, name, "0x%x" % (clock_data)) + return True + + +# pre-MTTCG merge +v5_event_table = [Decoder(0, "EVENT_INSTRUCTION", decode_instruction), + Decoder(1, "EVENT_INTERRUPT", decode_interrupt), + Decoder(2, "EVENT_EXCEPTION", decode_unimp), + Decoder(3, "EVENT_ASYNC", decode_async), + Decoder(4, "EVENT_SHUTDOWN", decode_unimp), + Decoder(5, "EVENT_CHAR_WRITE", decode_unimp), + Decoder(6, "EVENT_CHAR_READ_ALL", decode_unimp), + Decoder(7, "EVENT_CHAR_READ_ALL_ERROR", decode_unimp), + Decoder(8, "EVENT_CLOCK_HOST", decode_clock), + Decoder(9, "EVENT_CLOCK_VIRTUAL_RT", decode_clock), + Decoder(10, "EVENT_CP_CLOCK_WARP_START", decode_checkpoint), + Decoder(11, "EVENT_CP_CLOCK_WARP_ACCOUNT", decode_checkpoint), + Decoder(12, "EVENT_CP_RESET_REQUESTED", decode_checkpoint), + Decoder(13, "EVENT_CP_SUSPEND_REQUESTED", decode_checkpoint), + Decoder(14, "EVENT_CP_CLOCK_VIRTUAL", decode_checkpoint), + Decoder(15, "EVENT_CP_CLOCK_HOST", decode_checkpoint), + Decoder(16, "EVENT_CP_CLOCK_VIRTUAL_RT", decode_checkpoint), + Decoder(17, "EVENT_CP_INIT", decode_checkpoint_init), + Decoder(18, "EVENT_CP_RESET", decode_checkpoint), +] + +# post-MTTCG merge, AUDIO support added +v6_event_table = [Decoder(0, "EVENT_INSTRUCTION", decode_instruction), + Decoder(1, "EVENT_INTERRUPT", decode_interrupt), + Decoder(2, "EVENT_EXCEPTION", decode_unimp), + Decoder(3, "EVENT_ASYNC", decode_async), + Decoder(4, "EVENT_SHUTDOWN", decode_unimp), + Decoder(5, "EVENT_CHAR_WRITE", decode_unimp), + Decoder(6, "EVENT_CHAR_READ_ALL", decode_unimp), + Decoder(7, "EVENT_CHAR_READ_ALL_ERROR", decode_unimp), + Decoder(8, "EVENT_AUDIO_OUT", decode_audio_out), + Decoder(9, "EVENT_AUDIO_IN", decode_unimp), + Decoder(10, "EVENT_CLOCK_HOST", decode_clock), + Decoder(11, "EVENT_CLOCK_VIRTUAL_RT", decode_clock), + Decoder(12, "EVENT_CP_CLOCK_WARP_START", decode_checkpoint), + Decoder(13, "EVENT_CP_CLOCK_WARP_ACCOUNT", decode_checkpoint), + Decoder(14, "EVENT_CP_RESET_REQUESTED", decode_checkpoint), + Decoder(15, "EVENT_CP_SUSPEND_REQUESTED", decode_checkpoint), + Decoder(16, "EVENT_CP_CLOCK_VIRTUAL", decode_checkpoint), + Decoder(17, "EVENT_CP_CLOCK_HOST", decode_checkpoint), + Decoder(18, "EVENT_CP_CLOCK_VIRTUAL_RT", decode_checkpoint), + Decoder(19, "EVENT_CP_INIT", decode_checkpoint_init), + Decoder(20, "EVENT_CP_RESET", decode_checkpoint), +] + +# Shutdown cause added +v7_event_table = [Decoder(0, "EVENT_INSTRUCTION", decode_instruction), + Decoder(1, "EVENT_INTERRUPT", decode_interrupt), + Decoder(2, "EVENT_EXCEPTION", decode_unimp), + Decoder(3, "EVENT_ASYNC", decode_async), + Decoder(4, "EVENT_SHUTDOWN", decode_unimp), + Decoder(5, "EVENT_SHUTDOWN_HOST_ERR", decode_unimp), + Decoder(6, "EVENT_SHUTDOWN_HOST_QMP", decode_unimp), + Decoder(7, "EVENT_SHUTDOWN_HOST_SIGNAL", decode_unimp), + Decoder(8, "EVENT_SHUTDOWN_HOST_UI", decode_unimp), + Decoder(9, "EVENT_SHUTDOWN_GUEST_SHUTDOWN", decode_unimp), + Decoder(10, "EVENT_SHUTDOWN_GUEST_RESET", decode_unimp), + Decoder(11, "EVENT_SHUTDOWN_GUEST_PANIC", decode_unimp), + Decoder(12, "EVENT_SHUTDOWN___MAX", decode_unimp), + Decoder(13, "EVENT_CHAR_WRITE", decode_unimp), + Decoder(14, "EVENT_CHAR_READ_ALL", decode_unimp), + Decoder(15, "EVENT_CHAR_READ_ALL_ERROR", decode_unimp), + Decoder(16, "EVENT_AUDIO_OUT", decode_audio_out), + Decoder(17, "EVENT_AUDIO_IN", decode_unimp), + Decoder(18, "EVENT_CLOCK_HOST", decode_clock), + Decoder(19, "EVENT_CLOCK_VIRTUAL_RT", decode_clock), + Decoder(20, "EVENT_CP_CLOCK_WARP_START", decode_checkpoint), + Decoder(21, "EVENT_CP_CLOCK_WARP_ACCOUNT", decode_checkpoint), + Decoder(22, "EVENT_CP_RESET_REQUESTED", decode_checkpoint), + Decoder(23, "EVENT_CP_SUSPEND_REQUESTED", decode_checkpoint), + Decoder(24, "EVENT_CP_CLOCK_VIRTUAL", decode_checkpoint), + Decoder(25, "EVENT_CP_CLOCK_HOST", decode_checkpoint), + Decoder(26, "EVENT_CP_CLOCK_VIRTUAL_RT", decode_checkpoint), + Decoder(27, "EVENT_CP_INIT", decode_checkpoint_init), + Decoder(28, "EVENT_CP_RESET", decode_checkpoint), +] + +def parse_arguments(): + "Grab arguments for script" + parser = argparse.ArgumentParser() + parser.add_argument("-f", "--file", help='record/replay dump to read from', + required=True) + return parser.parse_args() + +def decode_file(filename): + "Decode a record/replay dump" + dumpfile = open(filename, "rb") + + # read and throwaway the header + version = read_dword(dumpfile) + junk = read_qword(dumpfile) + + print "HEADER: version 0x%x" % (version) + + if version == 0xe02007: + event_decode_table = v7_event_table + replay_state.checkpoint_start = 12 + elif version == 0xe02006: + event_decode_table = v6_event_table + replay_state.checkpoint_start = 12 + else: + event_decode_table = v5_event_table + replay_state.checkpoint_start = 10 + + try: + decode_ok = True + while decode_ok: + event = read_event(dumpfile) + decode_ok = call_decode(event_decode_table, event, dumpfile) + finally: + dumpfile.close() + +if __name__ == "__main__": + args = parse_arguments() + decode_file(args.file)