debug/testlib.py

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