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