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