test/functional/test_runner.py

   1 #!/usr/bin/env python3
   2 # Copyright (c) 2014-2016 The Bitcoin Core developers
   3 # Distributed under the MIT software license, see the accompanying
   4 # file COPYING or http://www.opensource.org/licenses/mit-license.php.
   5 """Run regression test suite.
   6
   7 This module calls down into individual test cases via subprocess. It will
   8 forward all unrecognized arguments onto the individual test scripts.
   9
  10 Functional tests are disabled on Windows by default. Use --force to run them anyway.
  11
  12 For a description of arguments recognized by test scripts, see
  13 `test/functional/test_framework/test_framework.py:BitcoinTestFramework.main`.
  14
  15 """
  16
  17 import argparse
  18 import configparser
  19 import datetime
  20 import os
  21 import time
  22 import shutil
  23 import signal
  24 import sys
  25 import subprocess
  26 import tempfile
  27 import re
  28 import logging
  29
  30 # Formatting. Default colors to empty strings.
  31 BOLD, BLUE, RED, GREY = ("", ""), ("", ""), ("", ""), ("", "")
  32 try:
  33     # Make sure python thinks it can write unicode to its stdout
  34     "\u2713".encode("utf_8").decode(sys.stdout.encoding)
  35     TICK = "✓ "
  36     CROSS = "✖ "
  37     CIRCLE = "○ "
  38 except UnicodeDecodeError:
  39     TICK = "P "
  40     CROSS = "x "
  41     CIRCLE = "o "
  42
  43 if os.name == 'posix':
  44     # primitive formatting on supported
  45     # terminal via ANSI escape sequences:
  46     BOLD = ('\033[0m', '\033[1m')
  47     BLUE = ('\033[0m', '\033[0;34m')
  48     RED = ('\033[0m', '\033[0;31m')
  49     GREY = ('\033[0m', '\033[1;30m')
  50
  51 TEST_EXIT_PASSED = 0
  52 TEST_EXIT_SKIPPED = 77
  53
  54 BASE_SCRIPTS= [
  55     # Scripts that are run by the travis build process.
  56     # Longest test should go first, to favor running tests in parallel
  57     'wallet-hd.py',
  58     'walletbackup.py',
  59     # vv Tests less than 5m vv
  60     'p2p-fullblocktest.py',
  61     'fundrawtransaction.py',
  62     'p2p-compactblocks.py',
  63     'segwit.py',
  64     # vv Tests less than 2m vv
  65     'wallet.py',
  66     'wallet-accounts.py',
  67     'p2p-segwit.py',
  68     'wallet-dump.py',
  69     'listtransactions.py',
  70     # vv Tests less than 60s vv
  71     'sendheaders.py',
  72     'zapwallettxes.py',
  73     'importmulti.py',
  74     'mempool_limit.py',
  75     'merkle_blocks.py',
  76     'receivedby.py',
  77     'abandonconflict.py',
  78     'bip68-112-113-p2p.py',
  79     'rawtransactions.py',
  80     'reindex.py',
  81     # vv Tests less than 30s vv
  82     'zmq_test.py',
  83     'mempool_resurrect_test.py',
  84     'txn_doublespend.py --mineblock',
  85     'txn_clone.py',
  86     'getchaintips.py',
  87     'rest.py',
  88     'mempool_spendcoinbase.py',
  89     'mempool_reorg.py',
  90     'mempool_persist.py',
  91     'multiwallet.py',
  92     'httpbasics.py',
  93     'multi_rpc.py',
  94     'proxy_test.py',
  95     'signrawtransactions.py',
  96     'disconnect_ban.py',
  97     'decodescript.py',
  98     'blockchain.py',
  99     'disablewallet.py',
 100     'net.py',
 101     'keypool.py',
 102     'p2p-mempool.py',
 103     'prioritise_transaction.py',
 104     'invalidblockrequest.py',
 105     'invalidtxrequest.py',
 106     'p2p-versionbits-warning.py',
 107     'preciousblock.py',
 108     'importprunedfunds.py',
 109     'signmessages.py',
 110     'nulldummy.py',
 111     'import-rescan.py',
 112     'mining.py',
 113     'bumpfee.py',
 114     'rpcnamedargs.py',
 115     'listsinceblock.py',
 116     'p2p-leaktests.py',
 117     'wallet-encryption.py',
 118     'bipdersig-p2p.py',
 119     'bip65-cltv-p2p.py',
 120     'uptime.py',
 121 ]
 122
 123 EXTENDED_SCRIPTS = [
 124     # These tests are not run by the travis build process.
 125     # Longest test should go first, to favor running tests in parallel
 126     'pruning.py',
 127     # vv Tests less than 20m vv
 128     'smartfees.py',
 129     # vv Tests less than 5m vv
 130     'maxuploadtarget.py',
 131     'mempool_packages.py',
 132     'dbcrash.py',
 133     # vv Tests less than 2m vv
 134     'bip68-sequence.py',
 135     'getblocktemplate_longpoll.py',
 136     'p2p-timeouts.py',
 137     # vv Tests less than 60s vv
 138     'bip9-softforks.py',
 139     'p2p-feefilter.py',
 140     'rpcbind_test.py',
 141     # vv Tests less than 30s vv
 142     'assumevalid.py',
 143     'example_test.py',
 144     'txn_doublespend.py',
 145     'txn_clone.py --mineblock',
 146     'forknotify.py',
 147     'invalidateblock.py',
 148     'p2p-acceptblock.py',
 149     'replace-by-fee.py',
 150 ]
 151
 152 # Place EXTENDED_SCRIPTS first since it has the 3 longest running tests
 153 ALL_SCRIPTS = EXTENDED_SCRIPTS + BASE_SCRIPTS
 154
 155 NON_SCRIPTS = [
 156     # These are python files that live in the functional tests directory, but are not test scripts.
 157     "combine_logs.py",
 158     "create_cache.py",
 159     "test_runner.py",
 160 ]
 161
 162 def main():
 163     # Parse arguments and pass through unrecognised args
 164     parser = argparse.ArgumentParser(add_help=False,
 165                                      usage='%(prog)s [test_runner.py options] [script options] [scripts]',
 166                                      description=__doc__,
 167                                      epilog='''
 168     Help text and arguments for individual test script:''',
 169                                      formatter_class=argparse.RawTextHelpFormatter)
 170     parser.add_argument('--coverage', action='store_true', help='generate a basic coverage report for the RPC interface')
 171     parser.add_argument('--exclude', '-x', help='specify a comma-seperated-list of scripts to exclude.')
 172     parser.add_argument('--extended', action='store_true', help='run the extended test suite in addition to the basic tests')
 173     parser.add_argument('--force', '-f', action='store_true', help='run tests even on platforms where they are disabled by default (e.g. windows).')
 174     parser.add_argument('--help', '-h', '-?', action='store_true', help='print help text and exit')
 175     parser.add_argument('--jobs', '-j', type=int, default=4, help='how many test scripts to run in parallel. Default=4.')
 176     parser.add_argument('--keepcache', '-k', action='store_true', help='the default behavior is to flush the cache directory on startup. --keepcache retains the cache from the previous testrun.')
 177     parser.add_argument('--quiet', '-q', action='store_true', help='only print results summary and failure logs')
 178     parser.add_argument('--tmpdirprefix', '-t', default=tempfile.gettempdir(), help="Root directory for datadirs")
 179     args, unknown_args = parser.parse_known_args()
 180
 181     # args to be passed on always start with two dashes; tests are the remaining unknown args
 182     tests = [arg for arg in unknown_args if arg[:2] != "--"]
 183     passon_args = [arg for arg in unknown_args if arg[:2] == "--"]
 184
 185     # Read config generated by configure.
 186     config = configparser.ConfigParser()
 187     configfile = os.path.abspath(os.path.dirname(__file__)) + "/../config.ini"
 188     config.read_file(open(configfile))
 189
 190     passon_args.append("--configfile=%s" % configfile)
 191
 192     # Set up logging
 193     logging_level = logging.INFO if args.quiet else logging.DEBUG
 194     logging.basicConfig(format='%(message)s', level=logging_level)
 195
 196     # Create base test directory
 197     tmpdir = "%s/bitcoin_test_runner_%s" % (args.tmpdirprefix, datetime.datetime.now().strftime("%Y%m%d_%H%M%S"))
 198     os.makedirs(tmpdir)
 199
 200     logging.debug("Temporary test directory at %s" % tmpdir)
 201
 202     enable_wallet = config["components"].getboolean("ENABLE_WALLET")
 203     enable_utils = config["components"].getboolean("ENABLE_UTILS")
 204     enable_bitcoind = config["components"].getboolean("ENABLE_BITCOIND")
 205
 206     if config["environment"]["EXEEXT"] == ".exe" and not args.force:
 207         # https://github.com/bitcoin/bitcoin/commit/d52802551752140cf41f0d9a225a43e84404d3e9
 208         # https://github.com/bitcoin/bitcoin/pull/5677#issuecomment-136646964
 209         print("Tests currently disabled on Windows by default. Use --force option to enable")
 210         sys.exit(0)
 211
 212     if not (enable_wallet and enable_utils and enable_bitcoind):
 213         print("No functional tests to run. Wallet, utils, and bitcoind must all be enabled")
 214         print("Rerun `configure` with -enable-wallet, -with-utils and -with-daemon and rerun make")
 215         sys.exit(0)
 216
 217     # Build list of tests
 218     if tests:
 219         # Individual tests have been specified. Run specified tests that exist
 220         # in the ALL_SCRIPTS list. Accept the name with or without .py extension.
 221         tests = [re.sub("\.py$", "", t) + ".py" for t in tests]
 222         test_list = []
 223         for t in tests:
 224             if t in ALL_SCRIPTS:
 225                 test_list.append(t)
 226             else:
 227                 print("{}WARNING!{} Test '{}' not found in full test list.".format(BOLD[1], BOLD[0], t))
 228     else:
 229         # No individual tests have been specified.
 230         # Run all base tests, and optionally run extended tests.
 231         test_list = BASE_SCRIPTS
 232         if args.extended:
 233             # place the EXTENDED_SCRIPTS first since the three longest ones
 234             # are there and the list is shorter
 235             test_list = EXTENDED_SCRIPTS + test_list
 236
 237     # Remove the test cases that the user has explicitly asked to exclude.
 238     if args.exclude:
 239         tests_excl = [re.sub("\.py$", "", t) + ".py" for t in args.exclude.split(',')]
 240         for exclude_test in tests_excl:
 241             if exclude_test in test_list:
 242                 test_list.remove(exclude_test)
 243             else:
 244                 print("{}WARNING!{} Test '{}' not found in current test list.".format(BOLD[1], BOLD[0], exclude_test))
 245
 246     if not test_list:
 247         print("No valid test scripts specified. Check that your test is in one "
 248               "of the test lists in test_runner.py, or run test_runner.py with no arguments to run all tests")
 249         sys.exit(0)
 250
 251     if args.help:
 252         # Print help for test_runner.py, then print help of the first script (with args removed) and exit.
 253         parser.print_help()
 254         subprocess.check_call([(config["environment"]["SRCDIR"] + '/test/functional/' + test_list[0].split()[0])] + ['-h'])
 255         sys.exit(0)
 256
 257     check_script_list(config["environment"]["SRCDIR"])
 258
 259     if not args.keepcache:
 260         shutil.rmtree("%s/test/cache" % config["environment"]["BUILDDIR"], ignore_errors=True)
 261
 262     run_tests(test_list, config["environment"]["SRCDIR"], config["environment"]["BUILDDIR"], config["environment"]["EXEEXT"], tmpdir, args.jobs, args.coverage, passon_args)
 263
 264 def run_tests(test_list, src_dir, build_dir, exeext, tmpdir, jobs=1, enable_coverage=False, args=[]):
 265     # Warn if bitcoind is already running (unix only)
 266     try:
 267         if subprocess.check_output(["pidof", "bitcoind"]) is not None:
 268             print("%sWARNING!%s There is already a bitcoind process running on this system. Tests may fail unexpectedly due to resource contention!" % (BOLD[1], BOLD[0]))
 269     except (OSError, subprocess.SubprocessError):
 270         pass
 271
 272     # Warn if there is a cache directory
 273     cache_dir = "%s/test/cache" % build_dir
 274     if os.path.isdir(cache_dir):
 275         print("%sWARNING!%s There is a cache directory here: %s. If tests fail unexpectedly, try deleting the cache directory." % (BOLD[1], BOLD[0], cache_dir))
 276
 277     #Set env vars
 278     if "BITCOIND" not in os.environ:
 279         os.environ["BITCOIND"] = build_dir + '/src/bitcoind' + exeext
 280
 281     tests_dir = src_dir + '/test/functional/'
 282
 283     flags = ["--srcdir={}/src".format(build_dir)] + args
 284     flags.append("--cachedir=%s" % cache_dir)
 285
 286     if enable_coverage:
 287         coverage = RPCCoverage()
 288         flags.append(coverage.flag)
 289         logging.debug("Initializing coverage directory at %s" % coverage.dir)
 290     else:
 291         coverage = None
 292
 293     if len(test_list) > 1 and jobs > 1:
 294         # Populate cache
 295         subprocess.check_output([tests_dir + 'create_cache.py'] + flags + ["--tmpdir=%s/cache" % tmpdir])
 296
 297     #Run Tests
 298     job_queue = TestHandler(jobs, tests_dir, tmpdir, test_list, flags)
 299     time0 = time.time()
 300     test_results = []
 301
 302     max_len_name = len(max(test_list, key=len))
 303
 304     for _ in range(len(test_list)):
 305         test_result, stdout, stderr = job_queue.get_next()
 306         test_results.append(test_result)
 307
 308         if test_result.status == "Passed":
 309             logging.debug("\n%s%s%s passed, Duration: %s s" % (BOLD[1], test_result.name, BOLD[0], test_result.time))
 310         elif test_result.status == "Skipped":
 311             logging.debug("\n%s%s%s skipped" % (BOLD[1], test_result.name, BOLD[0]))
 312         else:
 313             print("\n%s%s%s failed, Duration: %s s\n" % (BOLD[1], test_result.name, BOLD[0], test_result.time))
 314             print(BOLD[1] + 'stdout:\n' + BOLD[0] + stdout + '\n')
 315             print(BOLD[1] + 'stderr:\n' + BOLD[0] + stderr + '\n')
 316
 317     print_results(test_results, max_len_name, (int(time.time() - time0)))
 318
 319     if coverage:
 320         coverage.report_rpc_coverage()
 321
 322         logging.debug("Cleaning up coverage data")
 323         coverage.cleanup()
 324
 325     # Clear up the temp directory if all subdirectories are gone
 326     if not os.listdir(tmpdir):
 327         os.rmdir(tmpdir)
 328
 329     all_passed = all(map(lambda test_result: test_result.was_successful, test_results))
 330
 331     sys.exit(not all_passed)
 332
 333 def print_results(test_results, max_len_name, runtime):
 334     results = "\n" + BOLD[1] + "%s | %s | %s\n\n" % ("TEST".ljust(max_len_name), "STATUS   ", "DURATION") + BOLD[0]
 335
 336     test_results.sort(key=lambda result: result.name.lower())
 337     all_passed = True
 338     time_sum = 0
 339
 340     for test_result in test_results:
 341         all_passed = all_passed and test_result.was_successful
 342         time_sum += test_result.time
 343         test_result.padding = max_len_name
 344         results += str(test_result)
 345
 346     status = TICK + "Passed" if all_passed else CROSS + "Failed"
 347     results += BOLD[1] + "\n%s | %s | %s s (accumulated) \n" % ("ALL".ljust(max_len_name), status.ljust(9), time_sum) + BOLD[0]
 348     results += "Runtime: %s s\n" % (runtime)
 349     print(results)
 350
 351 class TestHandler:
 352     """
 353     Trigger the testscrips passed in via the list.
 354     """
 355
 356     def __init__(self, num_tests_parallel, tests_dir, tmpdir, test_list=None, flags=None):
 357         assert(num_tests_parallel >= 1)
 358         self.num_jobs = num_tests_parallel
 359         self.tests_dir = tests_dir
 360         self.tmpdir = tmpdir
 361         self.test_list = test_list
 362         self.flags = flags
 363         self.num_running = 0
 364         # In case there is a graveyard of zombie bitcoinds, we can apply a
 365         # pseudorandom offset to hopefully jump over them.
 366         # (625 is PORT_RANGE/MAX_NODES)
 367         self.portseed_offset = int(time.time() * 1000) % 625
 368         self.jobs = []
 369
 370     def get_next(self):
 371         while self.num_running < self.num_jobs and self.test_list:
 372             # Add tests
 373             self.num_running += 1
 374             t = self.test_list.pop(0)
 375             portseed = len(self.test_list) + self.portseed_offset
 376             portseed_arg = ["--portseed={}".format(portseed)]
 377             log_stdout = tempfile.SpooledTemporaryFile(max_size=2**16)
 378             log_stderr = tempfile.SpooledTemporaryFile(max_size=2**16)
 379             test_argv = t.split()
 380             tmpdir = ["--tmpdir=%s/%s_%s" % (self.tmpdir, re.sub(".py$", "", test_argv[0]), portseed)]
 381             self.jobs.append((t,
 382                               time.time(),
 383                               subprocess.Popen([self.tests_dir + test_argv[0]] + test_argv[1:] + self.flags + portseed_arg + tmpdir,
 384                                                universal_newlines=True,
 385                                                stdout=log_stdout,
 386                                                stderr=log_stderr),
 387                               log_stdout,
 388                               log_stderr))
 389         if not self.jobs:
 390             raise IndexError('pop from empty list')
 391         while True:
 392             # Return first proc that finishes
 393             time.sleep(.5)
 394             for j in self.jobs:
 395                 (name, time0, proc, log_out, log_err) = j
 396                 if os.getenv('TRAVIS') == 'true' and int(time.time() - time0) > 20 * 60:
 397                     # In travis, timeout individual tests after 20 minutes (to stop tests hanging and not
 398                     # providing useful output.
 399                     proc.send_signal(signal.SIGINT)
 400                 if proc.poll() is not None:
 401                     log_out.seek(0), log_err.seek(0)
 402                     [stdout, stderr] = [l.read().decode('utf-8') for l in (log_out, log_err)]
 403                     log_out.close(), log_err.close()
 404                     if proc.returncode == TEST_EXIT_PASSED and stderr == "":
 405                         status = "Passed"
 406                     elif proc.returncode == TEST_EXIT_SKIPPED:
 407                         status = "Skipped"
 408                     else:
 409                         status = "Failed"
 410                     self.num_running -= 1
 411                     self.jobs.remove(j)
 412
 413                     return TestResult(name, status, int(time.time() - time0)), stdout, stderr
 414             print('.', end='', flush=True)
 415
 416 class TestResult():
 417     def __init__(self, name, status, time):
 418         self.name = name
 419         self.status = status
 420         self.time = time
 421         self.padding = 0
 422
 423     def __repr__(self):
 424         if self.status == "Passed":
 425             color = BLUE
 426             glyph = TICK
 427         elif self.status == "Failed":
 428             color = RED
 429             glyph = CROSS
 430         elif self.status == "Skipped":
 431             color = GREY
 432             glyph = CIRCLE
 433
 434         return color[1] + "%s | %s%s | %s s\n" % (self.name.ljust(self.padding), glyph, self.status.ljust(7), self.time) + color[0]
 435
 436     @property
 437     def was_successful(self):
 438         return self.status != "Failed"
 439
 440
 441 def check_script_list(src_dir):
 442     """Check scripts directory.
 443
 444     Check that there are no scripts in the functional tests directory which are
 445     not being run by pull-tester.py."""
 446     script_dir = src_dir + '/test/functional/'
 447     python_files = set([t for t in os.listdir(script_dir) if t[-3:] == ".py"])
 448     missed_tests = list(python_files - set(map(lambda x: x.split()[0], ALL_SCRIPTS + NON_SCRIPTS)))
 449     if len(missed_tests) != 0:
 450         print("%sWARNING!%s The following scripts are not being run: %s. Check the test lists in test_runner.py." % (BOLD[1], BOLD[0], str(missed_tests)))
 451         if os.getenv('TRAVIS') == 'true':
 452             # On travis this warning is an error to prevent merging incomplete commits into master
 453             sys.exit(1)
 454
 455 class RPCCoverage(object):
 456     """
 457     Coverage reporting utilities for test_runner.
 458
 459     Coverage calculation works by having each test script subprocess write
 460     coverage files into a particular directory. These files contain the RPC
 461     commands invoked during testing, as well as a complete listing of RPC
 462     commands per `bitcoin-cli help` (`rpc_interface.txt`).
 463
 464     After all tests complete, the commands run are combined and diff'd against
 465     the complete list to calculate uncovered RPC commands.
 466
 467     See also: test/functional/test_framework/coverage.py
 468
 469     """
 470     def __init__(self):
 471         self.dir = tempfile.mkdtemp(prefix="coverage")
 472         self.flag = '--coveragedir=%s' % self.dir
 473
 474     def report_rpc_coverage(self):
 475         """
 476         Print out RPC commands that were unexercised by tests.
 477
 478         """
 479         uncovered = self._get_uncovered_rpc_commands()
 480
 481         if uncovered:
 482             print("Uncovered RPC commands:")
 483             print("".join(("  - %s\n" % i) for i in sorted(uncovered)))
 484         else:
 485             print("All RPC commands covered.")
 486
 487     def cleanup(self):
 488         return shutil.rmtree(self.dir)
 489
 490     def _get_uncovered_rpc_commands(self):
 491         """
 492         Return a set of currently untested RPC commands.
 493
 494         """
 495         # This is shared from `test/functional/test-framework/coverage.py`
 496         reference_filename = 'rpc_interface.txt'
 497         coverage_file_prefix = 'coverage.'
 498
 499         coverage_ref_filename = os.path.join(self.dir, reference_filename)
 500         coverage_filenames = set()
 501         all_cmds = set()
 502         covered_cmds = set()
 503
 504         if not os.path.isfile(coverage_ref_filename):
 505             raise RuntimeError("No coverage reference found")
 506
 507         with open(coverage_ref_filename, 'r') as f:
 508             all_cmds.update([i.strip() for i in f.readlines()])
 509
 510         for root, dirs, files in os.walk(self.dir):
 511             for filename in files:
 512                 if filename.startswith(coverage_file_prefix):
 513                     coverage_filenames.add(os.path.join(root, filename))
 514
 515         for filename in coverage_filenames:
 516             with open(filename, 'r') as f:
 517                 covered_cmds.update([i.strip() for i in f.readlines()])
 518
 519         return all_cmds - covered_cmds
 520
 521
 522 if __name__ == '__main__':
 523     main()