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