X-Git-Url: https://git.libre-soc.org/?a=blobdiff_plain;f=debug%2Ftestlib.py;h=6adc43ad6586ad8e11f14fb9e7d549e2d8f21cf0;hb=4dddbc79ada7f0a836cf538676c57c8df103ccf6;hp=385034b82a9103989059703c7d5a7e39b185b87a;hpb=49fc83aa23045abee5d396ef5a9d96b80c03178d;p=riscv-tests.git diff --git a/debug/testlib.py b/debug/testlib.py index 385034b..6adc43a 100644 --- a/debug/testlib.py +++ b/debug/testlib.py @@ -9,9 +9,13 @@ import sys import tempfile import time import traceback +import pipes import pexpect +print_log_names = False +real_stdout = sys.stdout + # Note that gdb comes with its own testsuite. I was unable to figure out how to # run that testsuite against the spike simulator. @@ -52,10 +56,13 @@ def compile(args, xlen=32): # pylint: disable=redefined-builtin raise Exception("Compile failed!") class Spike(object): - def __init__(self, target, halted=False, timeout=None, with_jtag_gdb=True): + def __init__(self, target, halted=False, timeout=None, with_jtag_gdb=True, + isa=None, progbufsize=None): """Launch spike. Return tuple of its process and the port it's running on.""" self.process = None + self.isa = isa + self.progbufsize = progbufsize if target.harts: harts = target.harts @@ -70,6 +77,8 @@ class Spike(object): self.logfile = tempfile.NamedTemporaryFile(prefix="spike-", suffix=".log") self.logname = self.logfile.name + if print_log_names: + real_stdout.write("Temporary spike log: %s\n" % self.logname) self.logfile.write("+ %s\n" % " ".join(cmd)) self.logfile.flush() self.process = subprocess.Popen(cmd, stdin=subprocess.PIPE, @@ -103,10 +112,17 @@ class Spike(object): assert len(set(t.xlen for t in harts)) == 1, \ "All spike harts must have the same XLEN" - if harts[0].xlen == 32: - cmd += ["--isa", "RV32G"] + if self.isa: + isa = self.isa else: - cmd += ["--isa", "RV64G"] + isa = "RV%dG" % harts[0].xlen + + cmd += ["--isa", isa] + cmd += ["--debug-auth"] + + if not self.progbufsize is None: + cmd += ["--progsize", str(self.progbufsize)] + cmd += ["--debug-sba", "32"] assert len(set(t.ram for t in harts)) == 1, \ "All spike harts must have the same RAM layout" @@ -137,9 +153,10 @@ class Spike(object): return self.process.wait(*args, **kwargs) class VcsSim(object): - logname = "simv.log" + logfile = tempfile.NamedTemporaryFile(prefix='simv', suffix='.log') + logname = logfile.name - def __init__(self, sim_cmd=None, debug=False): + def __init__(self, sim_cmd=None, debug=False, timeout=300): if sim_cmd: cmd = shlex.split(sim_cmd) else: @@ -148,14 +165,19 @@ class VcsSim(object): if debug: cmd[0] = cmd[0] + "-debug" cmd += ["+vcdplusfile=output/gdbserver.vpd"] + logfile = open(self.logname, "w") + if print_log_names: + real_stdout.write("Temporary VCS log: %s\n" % self.logname) logfile.write("+ %s\n" % " ".join(cmd)) logfile.flush() + listenfile = open(self.logname, "r") listenfile.seek(0, 2) self.process = subprocess.Popen(cmd, stdin=subprocess.PIPE, stdout=logfile, stderr=logfile) done = False + start = time.time() while not done: # Fail if VCS exits early exit_code = self.process.poll() @@ -172,6 +194,10 @@ class VcsSim(object): self.port = int(match.group(1)) os.environ['JTAG_VPI_PORT'] = str(self.port) + if (time.time() - start) > timeout: + raise Exception("Timed out waiting for VCS to listen for JTAG " + "vpi") + def __del__(self): try: self.process.kill() @@ -182,7 +208,6 @@ class VcsSim(object): class Openocd(object): logfile = tempfile.NamedTemporaryFile(prefix='openocd', suffix='.log') logname = logfile.name - print "OpenOCD Temporary Log File: %s" % logname def __init__(self, server_cmd=None, config=None, debug=False, timeout=60): self.timeout = timeout @@ -221,7 +246,13 @@ class Openocd(object): cmd.append("-d") logfile = open(Openocd.logname, "w") - logfile.write("+ %s\n" % " ".join(cmd)) + if print_log_names: + real_stdout.write("Temporary OpenOCD log: %s\n" % Openocd.logname) + env_entries = ("REMOTE_BITBANG_HOST", "REMOTE_BITBANG_PORT") + env_entries = [key for key in env_entries if key in os.environ] + logfile.write("+ %s%s\n" % ( + "".join("%s=%s " % (key, os.environ[key]) for key in env_entries), + " ".join(map(pipes.quote, cmd)))) logfile.flush() self.gdb_ports = [] @@ -268,7 +299,13 @@ class Openocd(object): def __del__(self): try: - self.process.kill() + self.process.terminate() + start = time.time() + while time.time() < start + 10000: + if self.process.poll(): + break + else: + self.process.kill() self.process.wait() except (OSError, AttributeError): pass @@ -304,6 +341,12 @@ class CannotAccess(Exception): Exception.__init__(self) self.address = address +class CouldNotFetch(Exception): + def __init__(self, regname, explanation): + Exception.__init__(self) + self.regname = regname + self.explanation = explanation + Thread = collections.namedtuple('Thread', ('id', 'description', 'target_id', 'name', 'frame')) @@ -311,13 +354,20 @@ class Gdb(object): """A single gdb class which can interact with one or more gdb instances.""" # pylint: disable=too-many-public-methods + # pylint: disable=too-many-instance-attributes def __init__(self, ports, cmd=os.path.expandvars("$RISCV/bin/riscv64-unknown-elf-gdb"), - binary=None): + timeout=60, binary=None): assert ports + self.ports = ports + self.cmd = cmd + self.timeout = timeout + self.binary = binary + self.stack = [] + self.harts = {} self.logfiles = [] self.children = [] @@ -325,14 +375,16 @@ class Gdb(object): logfile = tempfile.NamedTemporaryFile(prefix="gdb@%d-" % port, suffix=".log") self.logfiles.append(logfile) + if print_log_names: + real_stdout.write("Temporary gdb log: %s\n" % logfile.name) child = pexpect.spawn(cmd) child.logfile = logfile child.logfile.write("+ %s\n" % cmd) self.children.append(child) self.active_child = self.children[0] - self.harts = {} - for port, child in zip(ports, self.children): + def connect(self): + for port, child in zip(self.ports, self.children): self.select_child(child) self.wait() self.command("set confirm off") @@ -340,9 +392,10 @@ class Gdb(object): self.command("set height 0") # Force consistency. self.command("set print entry-values no") + self.command("set remotetimeout %d" % self.timeout) self.command("target extended-remote localhost:%d" % port) - if binary: - self.command("file %s" % binary) + if self.binary: + self.command("file %s" % self.binary) threads = self.threads() for t in threads: hartid = None @@ -355,12 +408,18 @@ class Gdb(object): hartid = max(self.harts) + 1 else: hartid = 0 - self.harts[hartid] = (child, t) + # solo: True iff this is the only thread on this child + self.harts[hartid] = {'child': child, + 'thread': t, + 'solo': len(threads) == 1} def __del__(self): for child in self.children: del child + def one_hart_per_gdb(self): + return all(h['solo'] for h in self.harts.itervalues()) + def lognames(self): return [logfile.name for logfile in self.logfiles] @@ -368,10 +427,11 @@ class Gdb(object): self.active_child = child def select_hart(self, hart): - child, thread = self.harts[hart.id] - self.select_child(child) - output = self.command("thread %s" % thread.id) - assert "Unknown" not in output + h = self.harts[hart.id] + self.select_child(h['child']) + if not h['solo']: + output = self.command("thread %s" % h['thread'].id, ops=5) + assert "Unknown" not in output def push_state(self): self.stack.append({ @@ -386,8 +446,11 @@ class Gdb(object): """Wait for prompt.""" self.active_child.expect(r"\(gdb\)") - def command(self, command, timeout=6000): - """timeout is in seconds""" + def command(self, command, ops=1): + """ops is the estimated number of operations gdb will have to perform + to perform this command. It is used to compute a timeout based on + self.timeout.""" + timeout = ops * self.timeout self.active_child.sendline(command) self.active_child.expect("\n", timeout=timeout) self.active_child.expect(r"\(gdb\)", timeout=timeout) @@ -400,7 +463,7 @@ class Gdb(object): self.select_child(child) self.command(command) - def c(self, wait=True, timeout=-1, async=False): + def c(self, wait=True, async=False): """ Dumb c command. In RTOS mode, gdb will resume all harts. @@ -411,30 +474,46 @@ class Gdb(object): async = "&" else: async = "" + ops = 10 if wait: - output = self.command("c%s" % async, timeout=timeout) + output = self.command("c%s" % async, ops=ops) assert "Continuing" in output return output else: self.active_child.sendline("c%s" % async) - self.active_child.expect("Continuing") + self.active_child.expect("Continuing", timeout=ops * self.timeout) - def c_all(self): - """Resume every hart.""" + def c_all(self, wait=True): + """ + Resume every hart. + + This function works fine when using multiple gdb sessions, but the + caller must be careful when using it nonetheless. gdb's behavior is to + not set breakpoints until just before the hart is resumed, and then + clears them as soon as the hart halts. That means that you can't set + one software breakpoint, and expect multiple harts to hit it. It's + possible that the first hart completes set/run/halt/clear before the + second hart even gets to resume, so it will never hit the breakpoint. + """ with PrivateState(self): for child in self.children: child.sendline("c") child.expect("Continuing") - # Now wait for them all to halt - for child in self.children: - child.expect(r"\(gdb\)") + if wait: + for child in self.children: + child.expect(r"\(gdb\)") def interrupt(self): self.active_child.send("\003") self.active_child.expect(r"\(gdb\)", timeout=6000) return self.active_child.before.strip() + def interrupt_all(self): + for child in self.children: + self.select_child(child) + self.interrupt() + def x(self, address, size='w'): output = self.command("x/%s %s" % (size, address)) value = int(output.split(':')[1].strip(), 0) @@ -462,6 +541,9 @@ class Gdb(object): m = re.search("Cannot access memory at address (0x[0-9a-f]+)", output) if m: raise CannotAccess(int(m.group(1), 0)) + m = re.search(r"Could not fetch register \"(\w+)\"; (.*)$", output) + if m: + raise CouldNotFetch(m.group(1), m.group(2)) rhs = output.split('=')[-1] return self.parse_string(rhs) @@ -470,29 +552,43 @@ class Gdb(object): value = shlex.split(output.split('=')[-1].strip())[1] return value + def info_registers(self, group): + output = self.command("info registers %s" % group) + result = {} + for line in output.splitlines(): + if "Could not fetch" in line: + name, value = line.split(None, 1) + else: + name, hex_value, _ = line.split(None, 2) + value = int(hex_value, 0) + result[name] = value + return result + def stepi(self): - output = self.command("stepi", timeout=60) + output = self.command("stepi", ops=10) return output def load(self): - output = self.command("load", timeout=6000) + output = self.command("load", ops=1000) assert "failed" not in output assert "Transfer rate" in output + output = self.command("compare-sections", ops=1000) + assert "MIS" not in output def b(self, location): - output = self.command("b %s" % location) + output = self.command("b %s" % location, ops=5) assert "not defined" not in output assert "Breakpoint" in output return output def hbreak(self, location): - output = self.command("hbreak %s" % location) + output = self.command("hbreak %s" % location, ops=5) assert "not defined" not in output assert "Hardware assisted breakpoint" in output return output def threads(self): - output = self.command("info threads") + output = self.command("info threads", ops=100) threads = [] for line in output.splitlines(): m = re.match( @@ -523,8 +619,12 @@ class PrivateState(object): self.gdb.pop_state() def run_all_tests(module, target, parsed): - if not os.path.exists(parsed.logs): + try: os.makedirs(parsed.logs) + except OSError: + # There's a race where multiple instances of the test program might + # decide to create the logs directory at the same time. + pass overall_start = time.time() @@ -532,18 +632,20 @@ def run_all_tests(module, target, parsed): gdb_cmd = parsed.gdb todo = [] + examine_added = False for hart in target.harts: if parsed.misaval: hart.misa = int(parsed.misaval, 16) print "Using $misa from command line: 0x%x" % hart.misa elif hart.misa: print "Using $misa from hart definition: 0x%x" % hart.misa - else: - todo.append(("ExamineTarget", ExamineTarget, hart)) + elif not examine_added: + todo.append(("ExamineTarget", ExamineTarget, None)) + examine_added = True for name in dir(module): definition = getattr(module, name) - if type(definition) == type and hasattr(definition, 'test') and \ + if isinstance(definition, type) and hasattr(definition, 'test') and \ (not parsed.test or any(test in name for test in parsed.test)): todo.append((name, definition, None)) @@ -569,14 +671,19 @@ def run_tests(parsed, target, todo): log_fd.write("Test: %s\n" % name) log_fd.write("Target: %s\n" % type(target).__name__) start = time.time() + global real_stdout # pylint: disable=global-statement real_stdout = sys.stdout sys.stdout = log_fd try: - result = instance.run(real_stdout) + result = instance.run() log_fd.write("Result: %s\n" % result) + log_fd.write("Logfile: %s\n" % log_name) + log_fd.write("Reproduce: %s %s %s\n" % (sys.argv[0], parsed.target, + name)) finally: sys.stdout = real_stdout log_fd.write("Time elapsed: %.2fs\n" % (time.time() - start)) + log_fd.flush() print "[%s] %s in %.2fs" % (name, result, time.time() - start) if result not in good_results and parsed.print_failures: sys.stdout.write(open(log_name).read()) @@ -606,6 +713,9 @@ def add_test_run_options(parser): help="Exit as soon as any test fails.") parser.add_argument("--print-failures", action="store_true", help="When a test fails, print the log file to stdout.") + parser.add_argument("--print-log-names", "--pln", action="store_true", + help="Print names of temporary log files as soon as they are " + "created.") parser.add_argument("test", nargs='*', help="Run only tests that are named here.") parser.add_argument("--gdb", @@ -623,12 +733,15 @@ def header(title, dash='-', length=78): else: print dash * length -def print_log(path): - header(path) - for l in open(path, "r"): +def print_log_handle(name, handle): + header(name) + for l in handle: sys.stdout.write(l) print +def print_log(path): + print_log_handle(path, open(path, "r")) + class BaseTest(object): compiled = {} @@ -658,7 +771,6 @@ class BaseTest(object): compile_args = getattr(self, 'compile_args', None) if compile_args: if compile_args not in BaseTest.compiled: - # pylint: disable=star-args BaseTest.compiled[compile_args] = \ self.target.compile(self.hart, *compile_args) self.binary = BaseTest.compiled.get(compile_args) @@ -683,7 +795,7 @@ class BaseTest(object): def postMortem(self): pass - def run(self, real_stdout): + def run(self): """ If compile_args is set, compile a program and set self.binary. @@ -702,8 +814,6 @@ class BaseTest(object): try: self.classSetup() - real_stdout.write("[%s] Temporary logs: %s\n" % ( - type(self).__name__, ", ".join(self.logs))) self.setup() result = self.test() # pylint: disable=no-member except TestNotApplicable: @@ -727,10 +837,15 @@ class BaseTest(object): return result finally: + # Get handles to logs before the files are deleted. + logs = [] for log in self.logs: - print_log(log) - header("End of logs") + logs.append((log, open(log, "r"))) + self.classTeardown() + for name, handle in logs: + print_log_handle(name, handle) + header("End of logs") if not result: result = 'pass' @@ -746,16 +861,17 @@ class GdbTest(BaseTest): BaseTest.classSetup(self) if gdb_cmd: - self.gdb = Gdb(self.server.gdb_ports, gdb_cmd, binary=self.binary) + self.gdb = Gdb(self.server.gdb_ports, gdb_cmd, + timeout=self.target.timeout_sec, binary=self.binary) else: - self.gdb = Gdb(self.server.gdb_ports, binary=self.binary) + self.gdb = Gdb(self.server.gdb_ports, + timeout=self.target.timeout_sec, binary=self.binary) self.logs += self.gdb.lognames() + self.gdb.connect() - if self.target: - self.gdb.global_command("set arch riscv:rv%d" % self.hart.xlen) - self.gdb.global_command("set remotetimeout %d" % - self.target.timeout_sec) + self.gdb.global_command("set remotetimeout %d" % + self.target.timeout_sec) for cmd in self.target.gdb_setup: self.gdb.command(cmd) @@ -769,42 +885,59 @@ class GdbTest(BaseTest): if not self.gdb: return self.gdb.interrupt() - self.gdb.command("info registers all", timeout=10) + self.gdb.command("disassemble", ops=20) + self.gdb.command("info registers all", ops=100) + self.gdb.command("flush regs") + self.gdb.command("info threads", ops=100) def classTeardown(self): del self.gdb BaseTest.classTeardown(self) -class GdbSingleHartTest(GdbTest): - def classSetup(self): - GdbTest.classSetup(self) - + def parkOtherHarts(self): + """Park harts besides the currently selected one in loop_forever().""" for hart in self.target.harts: # Park all harts that we're not using in a safe place. if hart != self.hart: self.gdb.select_hart(hart) self.gdb.p("$pc=loop_forever") + self.gdb.select_hart(self.hart) +class GdbSingleHartTest(GdbTest): + def classSetup(self): + GdbTest.classSetup(self) + self.parkOtherHarts() + class ExamineTarget(GdbTest): def test(self): - self.hart.misa = self.gdb.p("$misa") - - txt = "RV" - if (self.hart.misa >> 30) == 1: - txt += "32" - elif (self.hart.misa >> 62) == 2: - txt += "64" - elif (self.hart.misa >> 126) == 3: - txt += "128" - else: - raise TestFailed("Couldn't determine XLEN from $misa (0x%x)" % - self.hart.misa) + for hart in self.target.harts: + self.gdb.select_hart(hart) + + hart.misa = self.gdb.p("$misa") + + txt = "RV" + misa_xlen = 0 + if ((hart.misa & 0xFFFFFFFF) >> 30) == 1: + misa_xlen = 32 + elif ((hart.misa & 0xFFFFFFFFFFFFFFFF) >> 62) == 2: + misa_xlen = 64 + elif ((hart.misa & 0xFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF) >> 126) == 3: + misa_xlen = 128 + else: + raise TestFailed("Couldn't determine XLEN from $misa (0x%x)" % + self.hart.misa) + + if misa_xlen != hart.xlen: + raise TestFailed("MISA reported XLEN of %d but we were "\ + "expecting XLEN of %d\n" % (misa_xlen, hart.xlen)) + + txt += ("%d" % misa_xlen) - for i in range(26): - if self.hart.misa & (1<