debug/testlib.py

   1 import collections
   2 import os.path
   3 import random
   4 import re
   5 import shlex
   6 import subprocess
   7 import sys
   8 import tempfile
   9 import time
  10 import traceback
  11
  12 import pexpect
  13
  14 # Note that gdb comes with its own testsuite. I was unable to figure out how to
  15 # run that testsuite against the spike simulator.
  16
  17 def find_file(path):
  18     for directory in (os.getcwd(), os.path.dirname(__file__)):
  19         fullpath = os.path.join(directory, path)
  20         if os.path.exists(fullpath):
  21             return fullpath
  22     return None
  23
  24 def compile(args, xlen=32): # pylint: disable=redefined-builtin
  25     cc = os.path.expandvars("$RISCV/bin/riscv64-unknown-elf-gcc")
  26     cmd = [cc, "-g"]
  27     if xlen == 32:
  28         cmd.append("-march=rv32imac")
  29         cmd.append("-mabi=ilp32")
  30     else:
  31         cmd.append("-march=rv64imac")
  32         cmd.append("-mabi=lp64")
  33     for arg in args:
  34         found = find_file(arg)
  35         if found:
  36             cmd.append(found)
  37         else:
  38             cmd.append(arg)
  39     header("Compile")
  40     print "+", " ".join(cmd)
  41     process = subprocess.Popen(cmd, stdout=subprocess.PIPE,
  42                                stderr=subprocess.PIPE)
  43     stdout, stderr = process.communicate()
  44     if process.returncode:
  45         print stdout,
  46         print stderr,
  47         header("")
  48         raise Exception("Compile failed!")
  49
  50 def unused_port():
  51     # http://stackoverflow.com/questions/2838244/get-open-tcp-port-in-python/2838309#2838309
  52     import socket
  53     s = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
  54     s.bind(("", 0))
  55     port = s.getsockname()[1]
  56     s.close()
  57     return port
  58
  59 class Spike(object):
  60     logname = "spike-%d.log" % os.getpid()
  61
  62     def __init__(self, target, halted=False, timeout=None, with_jtag_gdb=True):
  63         """Launch spike. Return tuple of its process and the port it's running
  64         on."""
  65         self.process = None
  66
  67         if target.harts:
  68             harts = target.harts
  69         else:
  70             harts = [target]
  71
  72         if target.sim_cmd:
  73             cmd = shlex.split(target.sim_cmd)
  74         else:
  75             spike = os.path.expandvars("$RISCV/bin/spike")
  76             cmd = [spike]
  77
  78         cmd += ["-p%d" % len(harts)]
  79
  80         assert len(set(t.xlen for t in harts)) == 1, \
  81                 "All spike harts must have the same XLEN"
  82
  83         if harts[0].xlen == 32:
  84             cmd += ["--isa", "RV32G"]
  85         else:
  86             cmd += ["--isa", "RV64G"]
  87
  88         assert len(set(t.ram for t in harts)) == 1, \
  89                 "All spike harts must have the same RAM layout"
  90         assert len(set(t.ram_size for t in harts)) == 1, \
  91                 "All spike harts must have the same RAM layout"
  92         cmd += ["-m0x%x:0x%x" % (harts[0].ram, harts[0].ram_size)]
  93
  94         if timeout:
  95             cmd = ["timeout", str(timeout)] + cmd
  96
  97         if halted:
  98             cmd.append('-H')
  99         if with_jtag_gdb:
 100             cmd += ['--rbb-port', '0']
 101             os.environ['REMOTE_BITBANG_HOST'] = 'localhost'
 102         self.infinite_loop = harts[0].compile(
 103                 "programs/checksum.c", "programs/tiny-malloc.c",
 104                 "programs/infinite_loop.S", "-DDEFINE_MALLOC", "-DDEFINE_FREE")
 105         cmd.append(self.infinite_loop)
 106         logfile = open(self.logname, "w")
 107         logfile.write("+ %s\n" % " ".join(cmd))
 108         logfile.flush()
 109         self.process = subprocess.Popen(cmd, stdin=subprocess.PIPE,
 110                 stdout=logfile, stderr=logfile)
 111
 112         if with_jtag_gdb:
 113             self.port = None
 114             for _ in range(30):
 115                 m = re.search(r"Listening for remote bitbang connection on "
 116                         r"port (\d+).", open(self.logname).read())
 117                 if m:
 118                     self.port = int(m.group(1))
 119                     os.environ['REMOTE_BITBANG_PORT'] = m.group(1)
 120                     break
 121                 time.sleep(0.11)
 122             assert self.port, "Didn't get spike message about bitbang " \
 123                     "connection"
 124
 125     def __del__(self):
 126         if self.process:
 127             try:
 128                 self.process.kill()
 129                 self.process.wait()
 130             except OSError:
 131                 pass
 132
 133     def wait(self, *args, **kwargs):
 134         return self.process.wait(*args, **kwargs)
 135
 136 class VcsSim(object):
 137     logname = "simv.log"
 138
 139     def __init__(self, sim_cmd=None, debug=False):
 140         if sim_cmd:
 141             cmd = shlex.split(sim_cmd)
 142         else:
 143             cmd = ["simv"]
 144         cmd += ["+jtag_vpi_enable"]
 145         if debug:
 146             cmd[0] = cmd[0] + "-debug"
 147             cmd += ["+vcdplusfile=output/gdbserver.vpd"]
 148         logfile = open(self.logname, "w")
 149         logfile.write("+ %s\n" % " ".join(cmd))
 150         logfile.flush()
 151         listenfile = open(self.logname, "r")
 152         listenfile.seek(0, 2)
 153         self.process = subprocess.Popen(cmd, stdin=subprocess.PIPE,
 154                 stdout=logfile, stderr=logfile)
 155         done = False
 156         while not done:
 157             # Fail if VCS exits early
 158             exit_code = self.process.poll()
 159             if exit_code is not None:
 160                 raise RuntimeError('VCS simulator exited early with status %d'
 161                                    % exit_code)
 162
 163             line = listenfile.readline()
 164             if not line:
 165                 time.sleep(1)
 166             match = re.match(r"^Listening on port (\d+)$", line)
 167             if match:
 168                 done = True
 169                 self.port = int(match.group(1))
 170                 os.environ['JTAG_VPI_PORT'] = str(self.port)
 171
 172     def __del__(self):
 173         try:
 174             self.process.kill()
 175             self.process.wait()
 176         except OSError:
 177             pass
 178
 179 class Openocd(object):
 180     logfile = tempfile.NamedTemporaryFile(prefix='openocd', suffix='.log')
 181     logname = logfile.name
 182     print "OpenOCD Temporary Log File: %s" % logname
 183
 184     def __init__(self, server_cmd=None, config=None, debug=False, timeout=60):
 185         if server_cmd:
 186             cmd = shlex.split(server_cmd)
 187         else:
 188             openocd = os.path.expandvars("$RISCV/bin/openocd")
 189             cmd = [openocd]
 190             if debug:
 191                 cmd.append("-d")
 192
 193         # This command needs to come before any config scripts on the command
 194         # line, since they are executed in order.
 195         cmd += [
 196             # Tell OpenOCD to bind gdb to an unused, ephemeral port.
 197             "--command",
 198             "gdb_port 0",
 199             # Disable tcl and telnet servers, since they are unused and because
 200             # the port numbers will conflict if multiple OpenOCD processes are
 201             # running on the same server.
 202             "--command",
 203             "tcl_port disabled",
 204             "--command",
 205             "telnet_port disabled",
 206         ]
 207
 208         if config:
 209             f = find_file(config)
 210             if f is None:
 211                 print "Unable to read file " + config
 212                 exit(1)
 213
 214             cmd += ["-f", f]
 215         if debug:
 216             cmd.append("-d")
 217
 218         logfile = open(Openocd.logname, "w")
 219         logfile.write("+ %s\n" % " ".join(cmd))
 220         logfile.flush()
 221
 222         self.ports = []
 223         self.port = None
 224         self.process = self.start(cmd, logfile)
 225
 226     def start(self, cmd, logfile):
 227         process = subprocess.Popen(cmd, stdin=subprocess.PIPE,
 228                 stdout=logfile, stderr=logfile)
 229
 230         try:
 231             # Wait for OpenOCD to have made it through riscv_examine(). When
 232             # using OpenOCD to communicate with a simulator this may take a
 233             # long time, and gdb will time out when trying to connect if we
 234             # attempt too early.
 235             start = time.time()
 236             messaged = False
 237             while True:
 238                 log = open(Openocd.logname).read()
 239                 m = re.search(r"Listening on port (\d+) for gdb connections",
 240                         log)
 241                 if m:
 242                     if not self.ports:
 243                         self.port = int(m.group(1))
 244                     self.ports.append(int(m.group(1)))
 245
 246                 if "telnet server disabled" in log:
 247                     break
 248
 249                 if not process.poll() is None:
 250                     raise Exception(
 251                             "OpenOCD exited before completing riscv_examine()")
 252                 if not messaged and time.time() - start > 1:
 253                     messaged = True
 254                     print "Waiting for OpenOCD to start..."
 255                 if (time.time() - start) > timeout:
 256                     raise Exception("ERROR: Timed out waiting for OpenOCD to "
 257                             "listen for gdb")
 258             return process
 259         except Exception:
 260             header("OpenOCD log")
 261             sys.stdout.write(log)
 262             raise
 263
 264     def __del__(self):
 265         try:
 266             self.process.kill()
 267             self.process.wait()
 268         except (OSError, AttributeError):
 269             pass
 270
 271 class OpenocdCli(object):
 272     def __init__(self, port=4444):
 273         self.child = pexpect.spawn(
 274                 "sh -c 'telnet localhost %d | tee openocd-cli.log'" % port)
 275         self.child.expect("> ")
 276
 277     def command(self, cmd):
 278         self.child.sendline(cmd)
 279         self.child.expect(cmd)
 280         self.child.expect("\n")
 281         self.child.expect("> ")
 282         return self.child.before.strip("\t\r\n \0")
 283
 284     def reg(self, reg=''):
 285         output = self.command("reg %s" % reg)
 286         matches = re.findall(r"(\w+) \(/\d+\): (0x[0-9A-F]+)", output)
 287         values = {r: int(v, 0) for r, v in matches}
 288         if reg:
 289             return values[reg]
 290         return values
 291
 292     def load_image(self, image):
 293         output = self.command("load_image %s" % image)
 294         if 'invalid ELF file, only 32bits files are supported' in output:
 295             raise TestNotApplicable(output)
 296
 297 class CannotAccess(Exception):
 298     def __init__(self, address):
 299         Exception.__init__(self)
 300         self.address = address
 301
 302 Thread = collections.namedtuple('Thread', ('id', 'target_id', 'name',
 303     'frame'))
 304
 305 class Gdb(object):
 306     logfile = tempfile.NamedTemporaryFile(prefix="gdb", suffix=".log")
 307     logname = logfile.name
 308     print "GDB Temporary Log File: %s" % logname
 309
 310     def __init__(self,
 311             cmd=os.path.expandvars("$RISCV/bin/riscv64-unknown-elf-gdb")):
 312         self.child = pexpect.spawn(cmd)
 313         self.child.logfile = open(self.logname, "w")
 314         self.child.logfile.write("+ %s\n" % cmd)
 315         self.wait()
 316         self.command("set confirm off")
 317         self.command("set width 0")
 318         self.command("set height 0")
 319         # Force consistency.
 320         self.command("set print entry-values no")
 321
 322     def select_hart(self, hart):
 323         output = self.command("thread %d" % (hart.index + 1))
 324         assert "Unknown" not in output
 325
 326     def wait(self):
 327         """Wait for prompt."""
 328         self.child.expect(r"\(gdb\)")
 329
 330     def command(self, command, timeout=6000):
 331         self.child.sendline(command)
 332         self.child.expect("\n", timeout=timeout)
 333         self.child.expect(r"\(gdb\)", timeout=timeout)
 334         return self.child.before.strip()
 335
 336     def c(self, wait=True, timeout=-1, async=False):
 337         if async:
 338             async = "&"
 339         else:
 340             async = ""
 341         if wait:
 342             output = self.command("c%s" % async, timeout=timeout)
 343             assert "Continuing" in output
 344             return output
 345         else:
 346             self.child.sendline("c%s" % async)
 347             self.child.expect("Continuing")
 348
 349     def interrupt(self):
 350         self.child.send("\003")
 351         self.child.expect(r"\(gdb\)", timeout=6000)
 352         return self.child.before.strip()
 353
 354     def x(self, address, size='w'):
 355         output = self.command("x/%s %s" % (size, address))
 356         value = int(output.split(':')[1].strip(), 0)
 357         return value
 358
 359     def p_raw(self, obj):
 360         output = self.command("p %s" % obj)
 361         m = re.search("Cannot access memory at address (0x[0-9a-f]+)", output)
 362         if m:
 363             raise CannotAccess(int(m.group(1), 0))
 364         return output.split('=')[-1].strip()
 365
 366     def p(self, obj):
 367         output = self.command("p/x %s" % obj)
 368         m = re.search("Cannot access memory at address (0x[0-9a-f]+)", output)
 369         if m:
 370             raise CannotAccess(int(m.group(1), 0))
 371         value = int(output.split('=')[-1].strip(), 0)
 372         return value
 373
 374     def p_string(self, obj):
 375         output = self.command("p %s" % obj)
 376         value = shlex.split(output.split('=')[-1].strip())[1]
 377         return value
 378
 379     def stepi(self):
 380         output = self.command("stepi", timeout=60)
 381         return output
 382
 383     def load(self):
 384         output = self.command("load", timeout=6000)
 385         assert "failed" not in  output
 386         assert "Transfer rate" in output
 387
 388     def b(self, location):
 389         output = self.command("b %s" % location)
 390         assert "not defined" not in output
 391         assert "Breakpoint" in output
 392         return output
 393
 394     def hbreak(self, location):
 395         output = self.command("hbreak %s" % location)
 396         assert "not defined" not in output
 397         assert "Hardware assisted breakpoint" in output
 398         return output
 399
 400     def threads(self):
 401         output = self.command("info threads")
 402         threads = []
 403         for line in output.splitlines():
 404             m = re.match(
 405                     r"[\s\*]*(\d+)\s*Thread (\d+)\s*\(Name: ([^\)]+)\s*(.*)",
 406                     line)
 407             if m:
 408                 threads.append(Thread(*m.groups()))
 409         if not threads:
 410             threads.append(Thread('1', '1', 'Default', '???'))
 411         return threads
 412
 413     def thread(self, thread):
 414         return self.command("thread %s" % thread.id)
 415
 416 def run_all_tests(module, target, parsed):
 417     if not os.path.exists(parsed.logs):
 418         os.makedirs(parsed.logs)
 419
 420     overall_start = time.time()
 421
 422     global gdb_cmd  # pylint: disable=global-statement
 423     gdb_cmd = parsed.gdb
 424
 425     todo = []
 426     for hart in target.harts:
 427         if parsed.misaval:
 428             hart.misa = int(parsed.misaval, 16)
 429             print "Using $misa from command line: 0x%x" % hart.misa
 430         elif hart.misa:
 431             print "Using $misa from hart definition: 0x%x" % hart.misa
 432         else:
 433             todo.append(("ExamineTarget", ExamineTarget, hart))
 434
 435     for name in dir(module):
 436         definition = getattr(module, name)
 437         if type(definition) == type and hasattr(definition, 'test') and \
 438                 (not parsed.test or any(test in name for test in parsed.test)):
 439             todo.append((name, definition, None))
 440
 441     results, count = run_tests(parsed, target, todo)
 442
 443     header("ran %d tests in %.0fs" % (count, time.time() - overall_start),
 444             dash=':')
 445
 446     return print_results(results)
 447
 448 good_results = set(('pass', 'not_applicable'))
 449 def run_tests(parsed, target, todo):
 450     results = {}
 451     count = 0
 452
 453     for name, definition, hart in todo:
 454         log_name = os.path.join(parsed.logs, "%s-%s-%s.log" %
 455                 (time.strftime("%Y%m%d-%H%M%S"), type(target).__name__, name))
 456         log_fd = open(log_name, 'w')
 457         print "Running %s > %s ..." % (name, log_name),
 458         instance = definition(target, hart)
 459         sys.stdout.flush()
 460         log_fd.write("Test: %s\n" % name)
 461         log_fd.write("Target: %s\n" % type(target).__name__)
 462         start = time.time()
 463         real_stdout = sys.stdout
 464         sys.stdout = log_fd
 465         try:
 466             result = instance.run()
 467             log_fd.write("Result: %s\n" % result)
 468         finally:
 469             sys.stdout = real_stdout
 470             log_fd.write("Time elapsed: %.2fs\n" % (time.time() - start))
 471         print "%s in %.2fs" % (result, time.time() - start)
 472         if result not in good_results and parsed.print_failures:
 473             sys.stdout.write(open(log_name).read())
 474         sys.stdout.flush()
 475         results.setdefault(result, []).append((name, log_name))
 476         count += 1
 477         if result not in good_results and parsed.fail_fast:
 478             break
 479
 480     return results, count
 481
 482 def print_results(results):
 483     result = 0
 484     for key, value in results.iteritems():
 485         print "%d tests returned %s" % (len(value), key)
 486         if key not in good_results:
 487             result = 1
 488             for name, log_name in value:
 489                 print "   %s > %s" % (name, log_name)
 490
 491     return result
 492
 493 def add_test_run_options(parser):
 494     parser.add_argument("--logs", default="logs",
 495             help="Store logs in the specified directory.")
 496     parser.add_argument("--fail-fast", "-f", action="store_true",
 497             help="Exit as soon as any test fails.")
 498     parser.add_argument("--print-failures", action="store_true",
 499             help="When a test fails, print the log file to stdout.")
 500     parser.add_argument("test", nargs='*',
 501             help="Run only tests that are named here.")
 502     parser.add_argument("--gdb",
 503             help="The command to use to start gdb.")
 504     parser.add_argument("--misaval",
 505             help="Don't run ExamineTarget, just assume the misa value which is "
 506             "specified.")
 507
 508 def header(title, dash='-', length=78):
 509     if title:
 510         dashes = dash * (length - 4 - len(title))
 511         before = dashes[:len(dashes)/2]
 512         after = dashes[len(dashes)/2:]
 513         print "%s[ %s ]%s" % (before, title, after)
 514     else:
 515         print dash * length
 516
 517 def print_log(path):
 518     header(path)
 519     lines = open(path, "r").readlines()
 520     for l in lines:
 521         sys.stdout.write(l)
 522     print
 523
 524 class BaseTest(object):
 525     compiled = {}
 526
 527     def __init__(self, target, hart=None):
 528         self.target = target
 529         if hart:
 530             self.hart = hart
 531         else:
 532             self.hart = random.choice(target.harts)
 533         self.server = None
 534         self.target_process = None
 535         self.binary = None
 536         self.start = 0
 537         self.logs = []
 538
 539     def early_applicable(self):
 540         """Return a false value if the test has determined it cannot run
 541         without ever needing to talk to the target or server."""
 542         # pylint: disable=no-self-use
 543         return True
 544
 545     def setup(self):
 546         pass
 547
 548     def compile(self):
 549         compile_args = getattr(self, 'compile_args', None)
 550         if compile_args:
 551             if compile_args not in BaseTest.compiled:
 552                 # pylint: disable=star-args
 553                 BaseTest.compiled[compile_args] = \
 554                         self.hart.compile(*compile_args)
 555         self.binary = BaseTest.compiled.get(compile_args)
 556
 557     def classSetup(self):
 558         self.compile()
 559         self.target_process = self.target.create()
 560         if self.target_process:
 561             self.logs.append(self.target_process.logname)
 562         try:
 563             self.server = self.target.server()
 564             self.logs.append(self.server.logname)
 565         except Exception:
 566             for log in self.logs:
 567                 print_log(log)
 568             raise
 569
 570     def classTeardown(self):
 571         del self.server
 572         del self.target_process
 573
 574     def run(self):
 575         """
 576         If compile_args is set, compile a program and set self.binary.
 577
 578         Call setup().
 579
 580         Then call test() and return the result, displaying relevant information
 581         if an exception is raised.
 582         """
 583
 584         sys.stdout.flush()
 585
 586         if not self.early_applicable():
 587             return "not_applicable"
 588
 589         self.start = time.time()
 590
 591         try:
 592             self.classSetup()
 593             self.setup()
 594             result = self.test()    # pylint: disable=no-member
 595         except TestNotApplicable:
 596             result = "not_applicable"
 597         except Exception as e: # pylint: disable=broad-except
 598             if isinstance(e, TestFailed):
 599                 result = "fail"
 600             else:
 601                 result = "exception"
 602             if isinstance(e, TestFailed):
 603                 header("Message")
 604                 print e.message
 605             header("Traceback")
 606             traceback.print_exc(file=sys.stdout)
 607             return result
 608
 609         finally:
 610             for log in self.logs:
 611                 print_log(log)
 612             header("End of logs")
 613             self.classTeardown()
 614
 615         if not result:
 616             result = 'pass'
 617         return result
 618
 619 gdb_cmd = None
 620 class GdbTest(BaseTest):
 621     def __init__(self, target, hart=None):
 622         BaseTest.__init__(self, target, hart=hart)
 623         self.gdb = None
 624
 625     def classSetup(self):
 626         BaseTest.classSetup(self)
 627
 628         if gdb_cmd:
 629             self.gdb = Gdb(gdb_cmd)
 630         else:
 631             self.gdb = Gdb()
 632
 633         self.logs.append(self.gdb.logname)
 634
 635         if self.binary:
 636             self.gdb.command("file %s" % self.binary)
 637         if self.target:
 638             self.gdb.command("set arch riscv:rv%d" % self.hart.xlen)
 639             self.gdb.command("set remotetimeout %d" % self.target.timeout_sec)
 640         if self.server.port:
 641             self.gdb.command(
 642                     "target extended-remote localhost:%d" % self.server.port)
 643             self.gdb.select_hart(self.hart)
 644
 645         for cmd in self.target.gdb_setup:
 646             self.gdb.command(cmd)
 647
 648         # FIXME: OpenOCD doesn't handle PRIV now
 649         #self.gdb.p("$priv=3")
 650
 651     def classTeardown(self):
 652         del self.gdb
 653         BaseTest.classTeardown(self)
 654
 655 class GdbSingleHartTest(GdbTest):
 656     def classSetup(self):
 657         GdbTest.classSetup(self)
 658
 659         for hart in self.target.harts:
 660             # Park all harts that we're not using in a safe place.
 661             if hart != self.hart:
 662                 self.gdb.select_hart(hart)
 663                 self.gdb.p("$pc=loop_forever")
 664         self.gdb.select_hart(self.hart)
 665
 666 class ExamineTarget(GdbTest):
 667     def test(self):
 668         self.target.misa = self.gdb.p("$misa")
 669
 670         txt = "RV"
 671         if (self.target.misa >> 30) == 1:
 672             txt += "32"
 673         elif (self.target.misa >> 62) == 2:
 674             txt += "64"
 675         elif (self.target.misa >> 126) == 3:
 676             txt += "128"
 677         else:
 678             raise TestFailed("Couldn't determine XLEN from $misa (0x%x)" %
 679                     self.target.misa)
 680
 681         for i in range(26):
 682             if self.target.misa & (1<<i):
 683                 txt += chr(i + ord('A'))
 684         print txt,
 685
 686 class TestFailed(Exception):
 687     def __init__(self, message):
 688         Exception.__init__(self)
 689         self.message = message
 690
 691 class TestNotApplicable(Exception):
 692     def __init__(self, message):
 693         Exception.__init__(self)
 694         self.message = message
 695
 696 def assertEqual(a, b):
 697     if a != b:
 698         raise TestFailed("%r != %r" % (a, b))
 699
 700 def assertNotEqual(a, b):
 701     if a == b:
 702         raise TestFailed("%r == %r" % (a, b))
 703
 704 def assertIn(a, b):
 705     if a not in b:
 706         raise TestFailed("%r not in %r" % (a, b))
 707
 708 def assertNotIn(a, b):
 709     if a in b:
 710         raise TestFailed("%r in %r" % (a, b))
 711
 712 def assertGreater(a, b):
 713     if not a > b:
 714         raise TestFailed("%r not greater than %r" % (a, b))
 715
 716 def assertLess(a, b):
 717     if not a < b:
 718         raise TestFailed("%r not less than %r" % (a, b))
 719
 720 def assertTrue(a):
 721     if not a:
 722         raise TestFailed("%r is not True" % a)
 723
 724 def assertRegexpMatches(text, regexp):
 725     if not re.search(regexp, text):
 726         raise TestFailed("can't find %r in %r" % (regexp, text))