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