test/functional/test_framework/test_framework.py

   1 #!/usr/bin/env python3
   2 # Copyright (c) 2014-2017 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 """Base class for RPC testing."""
   6
   7 from enum import Enum
   8 import logging
   9 import optparse
  10 import os
  11 import pdb
  12 import shutil
  13 import sys
  14 import tempfile
  15 import time
  16
  17 from .authproxy import JSONRPCException
  18 from . import coverage
  19 from .test_node import TestNode
  20 from .util import (
  21     MAX_NODES,
  22     PortSeed,
  23     assert_equal,
  24     check_json_precision,
  25     connect_nodes_bi,
  26     disconnect_nodes,
  27     initialize_datadir,
  28     log_filename,
  29     p2p_port,
  30     set_node_times,
  31     sync_blocks,
  32     sync_mempools,
  33 )
  34
  35 class TestStatus(Enum):
  36     PASSED = 1
  37     FAILED = 2
  38     SKIPPED = 3
  39
  40 TEST_EXIT_PASSED = 0
  41 TEST_EXIT_FAILED = 1
  42 TEST_EXIT_SKIPPED = 77
  43
  44 class BitcoinTestFramework():
  45     """Base class for a bitcoin test script.
  46
  47     Individual bitcoin test scripts should subclass this class and override the set_test_params() and run_test() methods.
  48
  49     Individual tests can also override the following methods to customize the test setup:
  50
  51     - add_options()
  52     - setup_chain()
  53     - setup_network()
  54     - setup_nodes()
  55
  56     The __init__() and main() methods should not be overridden.
  57
  58     This class also contains various public and private helper methods."""
  59
  60     def __init__(self):
  61         """Sets test framework defaults. Do not override this method. Instead, override the set_test_params() method"""
  62         self.setup_clean_chain = False
  63         self.nodes = []
  64         self.mocktime = 0
  65         self.set_test_params()
  66
  67         assert hasattr(self, "num_nodes"), "Test must set self.num_nodes in set_test_params()"
  68
  69     def main(self):
  70         """Main function. This should not be overridden by the subclass test scripts."""
  71
  72         parser = optparse.OptionParser(usage="%prog [options]")
  73         parser.add_option("--nocleanup", dest="nocleanup", default=False, action="store_true",
  74                           help="Leave bitcoinds and test.* datadir on exit or error")
  75         parser.add_option("--noshutdown", dest="noshutdown", default=False, action="store_true",
  76                           help="Don't stop bitcoinds after the test execution")
  77         parser.add_option("--srcdir", dest="srcdir", default=os.path.normpath(os.path.dirname(os.path.realpath(__file__)) + "/../../../src"),
  78                           help="Source directory containing bitcoind/bitcoin-cli (default: %default)")
  79         parser.add_option("--cachedir", dest="cachedir", default=os.path.normpath(os.path.dirname(os.path.realpath(__file__)) + "/../../cache"),
  80                           help="Directory for caching pregenerated datadirs")
  81         parser.add_option("--tmpdir", dest="tmpdir", help="Root directory for datadirs")
  82         parser.add_option("-l", "--loglevel", dest="loglevel", default="INFO",
  83                           help="log events at this level and higher to the console. Can be set to DEBUG, INFO, WARNING, ERROR or CRITICAL. Passing --loglevel DEBUG will output all logs to console. Note that logs at all levels are always written to the test_framework.log file in the temporary test directory.")
  84         parser.add_option("--tracerpc", dest="trace_rpc", default=False, action="store_true",
  85                           help="Print out all RPC calls as they are made")
  86         parser.add_option("--portseed", dest="port_seed", default=os.getpid(), type='int',
  87                           help="The seed to use for assigning port numbers (default: current process id)")
  88         parser.add_option("--coveragedir", dest="coveragedir",
  89                           help="Write tested RPC commands into this directory")
  90         parser.add_option("--configfile", dest="configfile",
  91                           help="Location of the test framework config file")
  92         parser.add_option("--pdbonfailure", dest="pdbonfailure", default=False, action="store_true",
  93                           help="Attach a python debugger if test fails")
  94         self.add_options(parser)
  95         (self.options, self.args) = parser.parse_args()
  96
  97         PortSeed.n = self.options.port_seed
  98
  99         os.environ['PATH'] = self.options.srcdir + ":" + self.options.srcdir + "/qt:" + os.environ['PATH']
 100
 101         check_json_precision()
 102
 103         self.options.cachedir = os.path.abspath(self.options.cachedir)
 104
 105         # Set up temp directory and start logging
 106         if self.options.tmpdir:
 107             self.options.tmpdir = os.path.abspath(self.options.tmpdir)
 108             os.makedirs(self.options.tmpdir, exist_ok=False)
 109         else:
 110             self.options.tmpdir = tempfile.mkdtemp(prefix="test")
 111         self._start_logging()
 112
 113         success = TestStatus.FAILED
 114
 115         try:
 116             self.setup_chain()
 117             self.setup_network()
 118             self.run_test()
 119             success = TestStatus.PASSED
 120         except JSONRPCException as e:
 121             self.log.exception("JSONRPC error")
 122         except SkipTest as e:
 123             self.log.warning("Test Skipped: %s" % e.message)
 124             success = TestStatus.SKIPPED
 125         except AssertionError as e:
 126             self.log.exception("Assertion failed")
 127         except KeyError as e:
 128             self.log.exception("Key error")
 129         except Exception as e:
 130             self.log.exception("Unexpected exception caught during testing")
 131         except KeyboardInterrupt as e:
 132             self.log.warning("Exiting after keyboard interrupt")
 133
 134         if success == TestStatus.FAILED and self.options.pdbonfailure:
 135             print("Testcase failed. Attaching python debugger. Enter ? for help")
 136             pdb.set_trace()
 137
 138         if not self.options.noshutdown:
 139             self.log.info("Stopping nodes")
 140             if self.nodes:
 141                 self.stop_nodes()
 142         else:
 143             self.log.info("Note: bitcoinds were not stopped and may still be running")
 144
 145         if not self.options.nocleanup and not self.options.noshutdown and success != TestStatus.FAILED:
 146             self.log.info("Cleaning up")
 147             shutil.rmtree(self.options.tmpdir)
 148         else:
 149             self.log.warning("Not cleaning up dir %s" % self.options.tmpdir)
 150
 151         if success == TestStatus.PASSED:
 152             self.log.info("Tests successful")
 153             exit_code = TEST_EXIT_PASSED
 154         elif success == TestStatus.SKIPPED:
 155             self.log.info("Test skipped")
 156             exit_code = TEST_EXIT_SKIPPED
 157         else:
 158             self.log.error("Test failed. Test logging available at %s/test_framework.log", self.options.tmpdir)
 159             self.log.error("Hint: Call {} '{}' to consolidate all logs".format(os.path.normpath(os.path.dirname(os.path.realpath(__file__)) + "/../combine_logs.py"), self.options.tmpdir))
 160             exit_code = TEST_EXIT_FAILED
 161         logging.shutdown()
 162         sys.exit(exit_code)
 163
 164     # Methods to override in subclass test scripts.
 165     def set_test_params(self):
 166         """Tests must this method to change default values for number of nodes, topology, etc"""
 167         raise NotImplementedError
 168
 169     def add_options(self, parser):
 170         """Override this method to add command-line options to the test"""
 171         pass
 172
 173     def setup_chain(self):
 174         """Override this method to customize blockchain setup"""
 175         self.log.info("Initializing test directory " + self.options.tmpdir)
 176         if self.setup_clean_chain:
 177             self._initialize_chain_clean()
 178         else:
 179             self._initialize_chain()
 180
 181     def setup_network(self):
 182         """Override this method to customize test network topology"""
 183         self.setup_nodes()
 184
 185         # Connect the nodes as a "chain".  This allows us
 186         # to split the network between nodes 1 and 2 to get
 187         # two halves that can work on competing chains.
 188         for i in range(self.num_nodes - 1):
 189             connect_nodes_bi(self.nodes, i, i + 1)
 190         self.sync_all()
 191
 192     def setup_nodes(self):
 193         """Override this method to customize test node setup"""
 194         extra_args = None
 195         if hasattr(self, "extra_args"):
 196             extra_args = self.extra_args
 197         self.add_nodes(self.num_nodes, extra_args)
 198         self.start_nodes()
 199
 200     def run_test(self):
 201         """Tests must override this method to define test logic"""
 202         raise NotImplementedError
 203
 204     # Public helper methods. These can be accessed by the subclass test scripts.
 205
 206     def add_nodes(self, num_nodes, extra_args=None, rpchost=None, timewait=None, binary=None):
 207         """Instantiate TestNode objects"""
 208
 209         if extra_args is None:
 210             extra_args = [[]] * num_nodes
 211         if binary is None:
 212             binary = [None] * num_nodes
 213         assert_equal(len(extra_args), num_nodes)
 214         assert_equal(len(binary), num_nodes)
 215         for i in range(num_nodes):
 216             self.nodes.append(TestNode(i, self.options.tmpdir, extra_args[i], rpchost, timewait=timewait, binary=binary[i], stderr=None, mocktime=self.mocktime, coverage_dir=self.options.coveragedir))
 217
 218     def start_node(self, i, extra_args=None, stderr=None):
 219         """Start a bitcoind"""
 220
 221         node = self.nodes[i]
 222
 223         node.start(extra_args, stderr)
 224         node.wait_for_rpc_connection()
 225
 226         if self.options.coveragedir is not None:
 227             coverage.write_all_rpc_commands(self.options.coveragedir, node.rpc)
 228
 229     def start_nodes(self, extra_args=None):
 230         """Start multiple bitcoinds"""
 231
 232         if extra_args is None:
 233             extra_args = [None] * self.num_nodes
 234         assert_equal(len(extra_args), self.num_nodes)
 235         try:
 236             for i, node in enumerate(self.nodes):
 237                 node.start(extra_args[i])
 238             for node in self.nodes:
 239                 node.wait_for_rpc_connection()
 240         except:
 241             # If one node failed to start, stop the others
 242             self.stop_nodes()
 243             raise
 244
 245         if self.options.coveragedir is not None:
 246             for node in self.nodes:
 247                 coverage.write_all_rpc_commands(self.options.coveragedir, node.rpc)
 248
 249     def stop_node(self, i):
 250         """Stop a bitcoind test node"""
 251         self.nodes[i].stop_node()
 252         self.nodes[i].wait_until_stopped()
 253
 254     def stop_nodes(self):
 255         """Stop multiple bitcoind test nodes"""
 256         for node in self.nodes:
 257             # Issue RPC to stop nodes
 258             node.stop_node()
 259
 260         for node in self.nodes:
 261             # Wait for nodes to stop
 262             node.wait_until_stopped()
 263
 264     def restart_node(self, i, extra_args=None):
 265         """Stop and start a test node"""
 266         self.stop_node(i)
 267         self.start_node(i, extra_args)
 268
 269     def assert_start_raises_init_error(self, i, extra_args=None, expected_msg=None):
 270         with tempfile.SpooledTemporaryFile(max_size=2**16) as log_stderr:
 271             try:
 272                 self.start_node(i, extra_args, stderr=log_stderr)
 273                 self.stop_node(i)
 274             except Exception as e:
 275                 assert 'bitcoind exited' in str(e)  # node must have shutdown
 276                 self.nodes[i].running = False
 277                 self.nodes[i].process = None
 278                 if expected_msg is not None:
 279                     log_stderr.seek(0)
 280                     stderr = log_stderr.read().decode('utf-8')
 281                     if expected_msg not in stderr:
 282                         raise AssertionError("Expected error \"" + expected_msg + "\" not found in:\n" + stderr)
 283             else:
 284                 if expected_msg is None:
 285                     assert_msg = "bitcoind should have exited with an error"
 286                 else:
 287                     assert_msg = "bitcoind should have exited with expected error " + expected_msg
 288                 raise AssertionError(assert_msg)
 289
 290     def wait_for_node_exit(self, i, timeout):
 291         self.nodes[i].process.wait(timeout)
 292
 293     def split_network(self):
 294         """
 295         Split the network of four nodes into nodes 0/1 and 2/3.
 296         """
 297         disconnect_nodes(self.nodes[1], 2)
 298         disconnect_nodes(self.nodes[2], 1)
 299         self.sync_all([self.nodes[:2], self.nodes[2:]])
 300
 301     def join_network(self):
 302         """
 303         Join the (previously split) network halves together.
 304         """
 305         connect_nodes_bi(self.nodes, 1, 2)
 306         self.sync_all()
 307
 308     def sync_all(self, node_groups=None):
 309         if not node_groups:
 310             node_groups = [self.nodes]
 311
 312         for group in node_groups:
 313             sync_blocks(group)
 314             sync_mempools(group)
 315
 316     def enable_mocktime(self):
 317         """Enable mocktime for the script.
 318
 319         mocktime may be needed for scripts that use the cached version of the
 320         blockchain.  If the cached version of the blockchain is used without
 321         mocktime then the mempools will not sync due to IBD.
 322
 323         For backwared compatibility of the python scripts with previous
 324         versions of the cache, this helper function sets mocktime to Jan 1,
 325         2014 + (201 * 10 * 60)"""
 326         self.mocktime = 1388534400 + (201 * 10 * 60)
 327
 328     def disable_mocktime(self):
 329         self.mocktime = 0
 330
 331     # Private helper methods. These should not be accessed by the subclass test scripts.
 332
 333     def _start_logging(self):
 334         # Add logger and logging handlers
 335         self.log = logging.getLogger('TestFramework')
 336         self.log.setLevel(logging.DEBUG)
 337         # Create file handler to log all messages
 338         fh = logging.FileHandler(self.options.tmpdir + '/test_framework.log')
 339         fh.setLevel(logging.DEBUG)
 340         # Create console handler to log messages to stderr. By default this logs only error messages, but can be configured with --loglevel.
 341         ch = logging.StreamHandler(sys.stdout)
 342         # User can provide log level as a number or string (eg DEBUG). loglevel was caught as a string, so try to convert it to an int
 343         ll = int(self.options.loglevel) if self.options.loglevel.isdigit() else self.options.loglevel.upper()
 344         ch.setLevel(ll)
 345         # Format logs the same as bitcoind's debug.log with microprecision (so log files can be concatenated and sorted)
 346         formatter = logging.Formatter(fmt='%(asctime)s.%(msecs)03d000 %(name)s (%(levelname)s): %(message)s', datefmt='%Y-%m-%d %H:%M:%S')
 347         formatter.converter = time.gmtime
 348         fh.setFormatter(formatter)
 349         ch.setFormatter(formatter)
 350         # add the handlers to the logger
 351         self.log.addHandler(fh)
 352         self.log.addHandler(ch)
 353
 354         if self.options.trace_rpc:
 355             rpc_logger = logging.getLogger("BitcoinRPC")
 356             rpc_logger.setLevel(logging.DEBUG)
 357             rpc_handler = logging.StreamHandler(sys.stdout)
 358             rpc_handler.setLevel(logging.DEBUG)
 359             rpc_logger.addHandler(rpc_handler)
 360
 361     def _initialize_chain(self):
 362         """Initialize a pre-mined blockchain for use by the test.
 363
 364         Create a cache of a 200-block-long chain (with wallet) for MAX_NODES
 365         Afterward, create num_nodes copies from the cache."""
 366
 367         assert self.num_nodes <= MAX_NODES
 368         create_cache = False
 369         for i in range(MAX_NODES):
 370             if not os.path.isdir(os.path.join(self.options.cachedir, 'node' + str(i))):
 371                 create_cache = True
 372                 break
 373
 374         if create_cache:
 375             self.log.debug("Creating data directories from cached datadir")
 376
 377             # find and delete old cache directories if any exist
 378             for i in range(MAX_NODES):
 379                 if os.path.isdir(os.path.join(self.options.cachedir, "node" + str(i))):
 380                     shutil.rmtree(os.path.join(self.options.cachedir, "node" + str(i)))
 381
 382             # Create cache directories, run bitcoinds:
 383             for i in range(MAX_NODES):
 384                 datadir = initialize_datadir(self.options.cachedir, i)
 385                 args = [os.getenv("BITCOIND", "bitcoind"), "-server", "-keypool=1", "-datadir=" + datadir, "-discover=0"]
 386                 if i > 0:
 387                     args.append("-connect=127.0.0.1:" + str(p2p_port(0)))
 388                 self.nodes.append(TestNode(i, self.options.cachedir, extra_args=[], rpchost=None, timewait=None, binary=None, stderr=None, mocktime=self.mocktime, coverage_dir=None))
 389                 self.nodes[i].args = args
 390                 self.start_node(i)
 391
 392             # Wait for RPC connections to be ready
 393             for node in self.nodes:
 394                 node.wait_for_rpc_connection()
 395
 396             # Create a 200-block-long chain; each of the 4 first nodes
 397             # gets 25 mature blocks and 25 immature.
 398             # Note: To preserve compatibility with older versions of
 399             # initialize_chain, only 4 nodes will generate coins.
 400             #
 401             # blocks are created with timestamps 10 minutes apart
 402             # starting from 2010 minutes in the past
 403             self.enable_mocktime()
 404             block_time = self.mocktime - (201 * 10 * 60)
 405             for i in range(2):
 406                 for peer in range(4):
 407                     for j in range(25):
 408                         set_node_times(self.nodes, block_time)
 409                         self.nodes[peer].generate(1)
 410                         block_time += 10 * 60
 411                     # Must sync before next peer starts generating blocks
 412                     sync_blocks(self.nodes)
 413
 414             # Shut them down, and clean up cache directories:
 415             self.stop_nodes()
 416             self.nodes = []
 417             self.disable_mocktime()
 418             for i in range(MAX_NODES):
 419                 os.remove(log_filename(self.options.cachedir, i, "debug.log"))
 420                 os.remove(log_filename(self.options.cachedir, i, "wallets/db.log"))
 421                 os.remove(log_filename(self.options.cachedir, i, "peers.dat"))
 422                 os.remove(log_filename(self.options.cachedir, i, "fee_estimates.dat"))
 423
 424         for i in range(self.num_nodes):
 425             from_dir = os.path.join(self.options.cachedir, "node" + str(i))
 426             to_dir = os.path.join(self.options.tmpdir, "node" + str(i))
 427             shutil.copytree(from_dir, to_dir)
 428             initialize_datadir(self.options.tmpdir, i)  # Overwrite port/rpcport in bitcoin.conf
 429
 430     def _initialize_chain_clean(self):
 431         """Initialize empty blockchain for use by the test.
 432
 433         Create an empty blockchain and num_nodes wallets.
 434         Useful if a test case wants complete control over initialization."""
 435         for i in range(self.num_nodes):
 436             initialize_datadir(self.options.tmpdir, i)
 437
 438 class ComparisonTestFramework(BitcoinTestFramework):
 439     """Test framework for doing p2p comparison testing
 440
 441     Sets up some bitcoind binaries:
 442     - 1 binary: test binary
 443     - 2 binaries: 1 test binary, 1 ref binary
 444     - n>2 binaries: 1 test binary, n-1 ref binaries"""
 445
 446     def set_test_params(self):
 447         self.num_nodes = 2
 448         self.setup_clean_chain = True
 449
 450     def add_options(self, parser):
 451         parser.add_option("--testbinary", dest="testbinary",
 452                           default=os.getenv("BITCOIND", "bitcoind"),
 453                           help="bitcoind binary to test")
 454         parser.add_option("--refbinary", dest="refbinary",
 455                           default=os.getenv("BITCOIND", "bitcoind"),
 456                           help="bitcoind binary to use for reference nodes (if any)")
 457
 458     def setup_network(self):
 459         extra_args = [['-whitelist=127.0.0.1']] * self.num_nodes
 460         if hasattr(self, "extra_args"):
 461             extra_args = self.extra_args
 462         self.add_nodes(self.num_nodes, extra_args,
 463                        binary=[self.options.testbinary] +
 464                        [self.options.refbinary] * (self.num_nodes - 1))
 465         self.start_nodes()
 466
 467 class SkipTest(Exception):
 468     """This exception is raised to skip a test"""
 469     def __init__(self, message):
 470         self.message = message