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