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