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