Added test timing.

tools/test.py

 #!/usr/bin/env python
 #
 # Copyright 2008 the V8 project authors. All rights reserved.
 # Redistribution and use in source and binary forms, with or without
 # modification, are permitted provided that the following conditions are
 # met:
 #
 #     * Redistributions of source code must retain the above copyright
 #       notice, this list of conditions and the following disclaimer.
 #     * Redistributions in binary form must reproduce the above
@@ skipping 79 matching lines @@
     try:
       self.RunSingle()
       # Wait for the remaining threads
       for thread in threads:
         # Use a timeout so that signals (ctrl-c) will be processed.
         thread.join(timeout=10000000)
     except Exception, e:
       # If there's an exception we schedule an interruption for any
       # remaining threads.
       self.terminate = True
-      print e
-      return False
+      # ...and then reraise the exception to bail out
+      raise
     self.Done()
     return not self.failed
 
   def RunSingle(self):
     while not self.terminate:
       try:
         test = self.queue.get_nowait()
       except Empty:
         return
       case = test.case
       self.lock.acquire()
       self.AboutToRun(case)
       self.lock.release()
       try:
+        start = time.time()
         output = case.Run()
+        case.duration = (time.time() - start)
       except IOError, e:
         assert self.terminate
         return
       if self.terminate:
         return
       self.lock.acquire()
       if output.UnexpectedOutput():
         self.failed.append(output)
       else:
         self.succeeded += 1
@@ skipping 37 matching lines @@
     else:
       print
       print "==="
       print "=== %i tests failed" % len(self.failed)
       print "==="
 
 
 class VerboseProgressIndicator(SimpleProgressIndicator):
 
   def AboutToRun(self, case):
-    print '%s:' % case.GetLabel(),
+    print 'Starting %s...' % case.GetLabel()
     sys.stdout.flush()
 
   def HasRun(self, output):
     if output.UnexpectedOutput():
-      print "FAIL"
+      outcome = 'FAIL'
     else:
-      print "pass"
+      outcome = 'pass'
+    print 'Done running %s: %s' % (output.test.GetLabel(), outcome)
 
 
 class DotsProgressIndicator(SimpleProgressIndicator):
 
   def AboutToRun(self, case):
     pass
 
   def HasRun(self, output):
     total = self.succeeded + len(self.failed)
     if (total > 1) and (total % 50 == 1):
@@ skipping 108 matching lines @@
     self.stdout = stdout
     self.stderr = stderr
 
 
 class TestCase(object):
 
   def __init__(self, context, path):
     self.path = path
     self.context = context
     self.failed = None
+    self.duration = None
 
   def IsNegative(self):
     return False
 
+  def CompareTime(self, other):

[Dean McNamee, 2008/10/01 08:58:39]

Can't you just use cmp() or something?

+    diff = other.duration - self.duration
+    if diff == 0: return 0
+    elif diff < 0: return -1
+    else: return 1
+
   def DidFail(self, output):
     if self.failed is None:
       self.failed = self.IsFailureOutput(output)
     return self.failed
 
   def IsFailureOutput(self, output):
     return output.exit_code != 0
 
   def GetSource(self):
     return "(no source available)"
@@ skipping 690 matching lines @@
       default='none')
   result.add_option("--simulator", help="Run tests with architecture simulator",
       default='none')
   result.add_option("--special-command", default=None)
   result.add_option("--cat", help="Print the source of the tests",
       default=False, action="store_true")
   result.add_option("--warn-unused", help="Report unused rules",
       default=False, action="store_true")
   result.add_option("-j", help="The number of parallel tasks to run",
       default=1, type="int")
+  result.add_option("--time", help="Print timing information after running",
+      default=False, action="store_true")
   return result
 
 
 def ProcessOptions(options):
   global VERBOSE
   VERBOSE = options.verbose
   options.mode = options.mode.split(',')
   for mode in options.mode:
     if not mode in ['debug', 'release']:
       print "Unknown mode %s" % mode
@@ skipping 78 matching lines @@
 
 BUILT_IN_TESTS = ['mjsunit', 'cctest', 'message']
 
 
 def GetSuites(test_root):
   def IsSuite(path):
     return isdir(path) and exists(join(path, 'testcfg.py'))
   return [ f for f in os.listdir(test_root) if IsSuite(join(test_root, f)) ]
 
 
+def FormatTime(d):
+  millis = round(d * 1000) % 1000
+  return time.strftime("%M:%S.", time.gmtime(d)) + ("%03i" % millis)
+
+
 def Main():
   parser = BuildOptions()
   (options, args) = parser.parse_args()
   if not ProcessOptions(options):
     parser.print_help()
     return 1
 
   workspace = abspath(join(dirname(sys.argv[0]), '..'))
   suites = GetSuites(join(workspace, 'test'))
   repositories = [TestRepository(join(workspace, 'test', name)) for name in suites]
@@ skipping 66 matching lines @@
       print "--- end source: %s ---" % test.GetLabel()
     return 0
 
   if options.warn_unused:
     for rule in globally_unused_rules:
       print "Rule for '%s' was not used." % '/'.join([str(s) for s in rule.path])
 
   if options.report:
     PrintReport(all_cases)
 
+  result = None
   if len(all_cases) == 0:
     print "No tests to run."
     return 0
   else:
     try:
+      start = time.time()
       if RunTestCases(all_cases, options.progress, options.j):
-        return 0
+        result = 0
       else:
-        return 1
+        result = 1
+      duration = time.time() - start
     except KeyboardInterrupt:
       print "Interrupted"
       return 1
 
+  if options.time:
+    # Write the times to stderr to make it easy to separate from the
+    # test output.
+    print
+    sys.stderr.write("--- Total time: %s ---\n" % FormatTime(duration))
+    timed_tests = [ t.case for t in all_cases if not t.case.duration is None ]
+    timed_tests.sort(lambda a, b: a.CompareTime(b))
+    index = 1
+    for entry in timed_tests:
+      t = FormatTime(entry.duration)
+      sys.stderr.write("%3i (%s) %s\n" % (index, t, entry.GetLabel()))
+      index += 1
+
+  return result
+
 
 if __name__ == '__main__':
   sys.exit(Main())