app/test/autotest_runner.py

   1 #!/usr/bin/python
   2
   3 #   BSD LICENSE
   4 #
   5 #   Copyright(c) 2010-2014 Intel Corporation. All rights reserved.
   6 #   All rights reserved.
   7 #
   8 #   Redistribution and use in source and binary forms, with or without
   9 #   modification, are permitted provided that the following conditions
  10 #   are met:
  11 #
  12 #     * Redistributions of source code must retain the above copyright
  13 #       notice, this list of conditions and the following disclaimer.
  14 #     * Redistributions in binary form must reproduce the above copyright
  15 #       notice, this list of conditions and the following disclaimer in
  16 #       the documentation and/or other materials provided with the
  17 #       distribution.
  18 #     * Neither the name of Intel Corporation nor the names of its
  19 #       contributors may be used to endorse or promote products derived
  20 #       from this software without specific prior written permission.
  21 #
  22 #   THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
  23 #   "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
  24 #   LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR
  25 #   A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT
  26 #   OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
  27 #   SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
  28 #   LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE,
  29 #   DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY
  30 #   THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
  31 #   (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
  32 #   OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
  33
  34 # The main logic behind running autotests in parallel
  35
  36 import StringIO
  37 import csv
  38 import multiprocessing
  39 import pexpect
  40 import re
  41 import subprocess
  42 import sys
  43 import time
  44
  45 # wait for prompt
  46
  47
  48 def wait_prompt(child):
  49     try:
  50         child.sendline()
  51         result = child.expect(["RTE>>", pexpect.TIMEOUT, pexpect.EOF],
  52                               timeout=120)
  53     except:
  54         return False
  55     if result == 0:
  56         return True
  57     else:
  58         return False
  59
  60 # run a test group
  61 # each result tuple in results list consists of:
  62 #   result value (0 or -1)
  63 #   result string
  64 #   test name
  65 #   total test run time (double)
  66 #   raw test log
  67 #   test report (if not available, should be None)
  68 #
  69 # this function needs to be outside AutotestRunner class
  70 # because otherwise Pool won't work (or rather it will require
  71 # quite a bit of effort to make it work).
  72
  73
  74 def run_test_group(cmdline, test_group):
  75     results = []
  76     child = None
  77     start_time = time.time()
  78     startuplog = None
  79
  80     # run test app
  81     try:
  82         # prepare logging of init
  83         startuplog = StringIO.StringIO()
  84
  85         print >>startuplog, "\n%s %s\n" % ("=" * 20, test_group["Prefix"])
  86         print >>startuplog, "\ncmdline=%s" % cmdline
  87
  88         child = pexpect.spawn(cmdline, logfile=startuplog)
  89
  90         # wait for target to boot
  91         if not wait_prompt(child):
  92             child.close()
  93
  94             results.append((-1,
  95                             "Fail [No prompt]",
  96                             "Start %s" % test_group["Prefix"],
  97                             time.time() - start_time,
  98                             startuplog.getvalue(),
  99                             None))
 100
 101             # mark all tests as failed
 102             for test in test_group["Tests"]:
 103                 results.append((-1, "Fail [No prompt]", test["Name"],
 104                                 time.time() - start_time, "", None))
 105             # exit test
 106             return results
 107
 108     except:
 109         results.append((-1,
 110                         "Fail [Can't run]",
 111                         "Start %s" % test_group["Prefix"],
 112                         time.time() - start_time,
 113                         startuplog.getvalue(),
 114                         None))
 115
 116         # mark all tests as failed
 117         for t in test_group["Tests"]:
 118             results.append((-1, "Fail [Can't run]", t["Name"],
 119                             time.time() - start_time, "", None))
 120         # exit test
 121         return results
 122
 123     # startup was successful
 124     results.append((0, "Success", "Start %s" % test_group["Prefix"],
 125                     time.time() - start_time, startuplog.getvalue(), None))
 126
 127     # parse the binary for available test commands
 128     binary = cmdline.split()[0]
 129     stripped = 'not stripped' not in subprocess.check_output(['file', binary])
 130     if not stripped:
 131         symbols = subprocess.check_output(['nm', binary]).decode('utf-8')
 132         avail_cmds = re.findall('test_register_(\w+)', symbols)
 133
 134     # run all tests in test group
 135     for test in test_group["Tests"]:
 136
 137         # create log buffer for each test
 138         # in multiprocessing environment, the logging would be
 139         # interleaved and will create a mess, hence the buffering
 140         logfile = StringIO.StringIO()
 141         child.logfile = logfile
 142
 143         result = ()
 144
 145         # make a note when the test started
 146         start_time = time.time()
 147
 148         try:
 149             # print test name to log buffer
 150             print >>logfile, "\n%s %s\n" % ("-" * 20, test["Name"])
 151
 152             # run test function associated with the test
 153             if stripped or test["Command"] in avail_cmds:
 154                 result = test["Func"](child, test["Command"])
 155             else:
 156                 result = (0, "Skipped [Not Available]")
 157
 158             # make a note when the test was finished
 159             end_time = time.time()
 160
 161             # append test data to the result tuple
 162             result += (test["Name"], end_time - start_time,
 163                        logfile.getvalue())
 164
 165             # call report function, if any defined, and supply it with
 166             # target and complete log for test run
 167             if test["Report"]:
 168                 report = test["Report"](self.target, log)
 169
 170                 # append report to results tuple
 171                 result += (report,)
 172             else:
 173                 # report is None
 174                 result += (None,)
 175         except:
 176             # make a note when the test crashed
 177             end_time = time.time()
 178
 179             # mark test as failed
 180             result = (-1, "Fail [Crash]", test["Name"],
 181                       end_time - start_time, logfile.getvalue(), None)
 182         finally:
 183             # append the results to the results list
 184             results.append(result)
 185
 186     # regardless of whether test has crashed, try quitting it
 187     try:
 188         child.sendline("quit")
 189         child.close()
 190     # if the test crashed, just do nothing instead
 191     except:
 192         # nop
 193         pass
 194
 195     # return test results
 196     return results
 197
 198
 199 # class representing an instance of autotests run
 200 class AutotestRunner:
 201     cmdline = ""
 202     parallel_test_groups = []
 203     non_parallel_test_groups = []
 204     logfile = None
 205     csvwriter = None
 206     target = ""
 207     start = None
 208     n_tests = 0
 209     fails = 0
 210     log_buffers = []
 211     blacklist = []
 212     whitelist = []
 213
 214     def __init__(self, cmdline, target, blacklist, whitelist):
 215         self.cmdline = cmdline
 216         self.target = target
 217         self.blacklist = blacklist
 218         self.whitelist = whitelist
 219
 220         # log file filename
 221         logfile = "%s.log" % target
 222         csvfile = "%s.csv" % target
 223
 224         self.logfile = open(logfile, "w")
 225         csvfile = open(csvfile, "w")
 226         self.csvwriter = csv.writer(csvfile)
 227
 228         # prepare results table
 229         self.csvwriter.writerow(["test_name", "test_result", "result_str"])
 230
 231     # set up cmdline string
 232     def __get_cmdline(self, test):
 233         cmdline = self.cmdline
 234
 235         # append memory limitations for each test
 236         # otherwise tests won't run in parallel
 237         if "i686" not in self.target:
 238             cmdline += " --socket-mem=%s" % test["Memory"]
 239         else:
 240             # affinitize startup so that tests don't fail on i686
 241             cmdline = "taskset 1 " + cmdline
 242             cmdline += " -m " + str(sum(map(int, test["Memory"].split(","))))
 243
 244         # set group prefix for autotest group
 245         # otherwise they won't run in parallel
 246         cmdline += " --file-prefix=%s" % test["Prefix"]
 247
 248         return cmdline
 249
 250     def add_parallel_test_group(self, test_group):
 251         self.parallel_test_groups.append(test_group)
 252
 253     def add_non_parallel_test_group(self, test_group):
 254         self.non_parallel_test_groups.append(test_group)
 255
 256     def __process_results(self, results):
 257         # this iterates over individual test results
 258         for i, result in enumerate(results):
 259
 260             # increase total number of tests that were run
 261             # do not include "start" test
 262             if i > 0:
 263                 self.n_tests += 1
 264
 265             # unpack result tuple
 266             test_result, result_str, test_name, \
 267                 test_time, log, report = result
 268
 269             # get total run time
 270             cur_time = time.time()
 271             total_time = int(cur_time - self.start)
 272
 273             # print results, test run time and total time since start
 274             print ("%s:" % test_name).ljust(30),
 275             print result_str.ljust(29),
 276             print "[%02dm %02ds]" % (test_time / 60, test_time % 60),
 277
 278             # don't print out total time every line, it's the same anyway
 279             if i == len(results) - 1:
 280                 print "[%02dm %02ds]" % (total_time / 60, total_time % 60)
 281             else:
 282                 print ""
 283
 284             # if test failed and it wasn't a "start" test
 285             if test_result < 0 and not i == 0:
 286                 self.fails += 1
 287
 288             # collect logs
 289             self.log_buffers.append(log)
 290
 291             # create report if it exists
 292             if report:
 293                 try:
 294                     f = open("%s_%s_report.rst" %
 295                              (self.target, test_name), "w")
 296                 except IOError:
 297                     print "Report for %s could not be created!" % test_name
 298                 else:
 299                     with f:
 300                         f.write(report)
 301
 302             # write test result to CSV file
 303             if i != 0:
 304                 self.csvwriter.writerow([test_name, test_result, result_str])
 305
 306     # this function iterates over test groups and removes each
 307     # test that is not in whitelist/blacklist
 308     def __filter_groups(self, test_groups):
 309         groups_to_remove = []
 310
 311         # filter out tests from parallel test groups
 312         for i, test_group in enumerate(test_groups):
 313
 314             # iterate over a copy so that we could safely delete individual
 315             # tests
 316             for test in test_group["Tests"][:]:
 317                 test_id = test["Command"]
 318
 319                 # dump tests are specified in full e.g. "Dump_mempool"
 320                 if "_autotest" in test_id:
 321                     test_id = test_id[:-len("_autotest")]
 322
 323                 # filter out blacklisted/whitelisted tests
 324                 if self.blacklist and test_id in self.blacklist:
 325                     test_group["Tests"].remove(test)
 326                     continue
 327                 if self.whitelist and test_id not in self.whitelist:
 328                     test_group["Tests"].remove(test)
 329                     continue
 330
 331             # modify or remove original group
 332             if len(test_group["Tests"]) > 0:
 333                 test_groups[i] = test_group
 334             else:
 335                 # remember which groups should be deleted
 336                 # put the numbers backwards so that we start
 337                 # deleting from the end, not from the beginning
 338                 groups_to_remove.insert(0, i)
 339
 340         # remove test groups that need to be removed
 341         for i in groups_to_remove:
 342             del test_groups[i]
 343
 344         return test_groups
 345
 346     # iterate over test groups and run tests associated with them
 347     def run_all_tests(self):
 348         # filter groups
 349         self.parallel_test_groups = \
 350             self.__filter_groups(self.parallel_test_groups)
 351         self.non_parallel_test_groups = \
 352             self.__filter_groups(self.non_parallel_test_groups)
 353
 354         # create a pool of worker threads
 355         pool = multiprocessing.Pool(processes=1)
 356
 357         results = []
 358
 359         # whatever happens, try to save as much logs as possible
 360         try:
 361
 362             # create table header
 363             print ""
 364             print "Test name".ljust(30),
 365             print "Test result".ljust(29),
 366             print "Test".center(9),
 367             print "Total".center(9)
 368             print "=" * 80
 369
 370             # make a note of tests start time
 371             self.start = time.time()
 372
 373             # assign worker threads to run test groups
 374             for test_group in self.parallel_test_groups:
 375                 result = pool.apply_async(run_test_group,
 376                                           [self.__get_cmdline(test_group),
 377                                            test_group])
 378                 results.append(result)
 379
 380             # iterate while we have group execution results to get
 381             while len(results) > 0:
 382
 383                 # iterate over a copy to be able to safely delete results
 384                 # this iterates over a list of group results
 385                 for group_result in results[:]:
 386
 387                     # if the thread hasn't finished yet, continue
 388                     if not group_result.ready():
 389                         continue
 390
 391                     res = group_result.get()
 392
 393                     self.__process_results(res)
 394
 395                     # remove result from results list once we're done with it
 396                     results.remove(group_result)
 397
 398             # run non_parallel tests. they are run one by one, synchronously
 399             for test_group in self.non_parallel_test_groups:
 400                 group_result = run_test_group(
 401                     self.__get_cmdline(test_group), test_group)
 402
 403                 self.__process_results(group_result)
 404
 405             # get total run time
 406             cur_time = time.time()
 407             total_time = int(cur_time - self.start)
 408
 409             # print out summary
 410             print "=" * 80
 411             print "Total run time: %02dm %02ds" % (total_time / 60,
 412                                                    total_time % 60)
 413             if self.fails != 0:
 414                 print "Number of failed tests: %s" % str(self.fails)
 415
 416             # write summary to logfile
 417             self.logfile.write("Summary\n")
 418             self.logfile.write("Target: ".ljust(15) + "%s\n" % self.target)
 419             self.logfile.write("Tests: ".ljust(15) + "%i\n" % self.n_tests)
 420             self.logfile.write("Failed tests: ".ljust(
 421                 15) + "%i\n" % self.fails)
 422         except:
 423             print "Exception occurred"
 424             print sys.exc_info()
 425             self.fails = 1
 426
 427         # drop logs from all executions to a logfile
 428         for buf in self.log_buffers:
 429             self.logfile.write(buf.replace("\r", ""))
 430
 431         return self.fails