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