test/functional/pruning.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 """Test the pruning code.
   6
   7 WARNING:
   8 This test uses 4GB of disk space.
   9 This test takes 30 mins or more (up to 2 hours)
  10 """
  11
  12 from test_framework.test_framework import BitcoinTestFramework
  13 from test_framework.util import *
  14 import time
  15 import os
  16
  17 MIN_BLOCKS_TO_KEEP = 288
  18
  19 # Rescans start at the earliest block up to 2 hours before a key timestamp, so
  20 # the manual prune RPC avoids pruning blocks in the same window to be
  21 # compatible with pruning based on key creation time.
  22 TIMESTAMP_WINDOW = 2 * 60 * 60
  23
  24
  25 def calc_usage(blockdir):
  26     return sum(os.path.getsize(blockdir+f) for f in os.listdir(blockdir) if os.path.isfile(blockdir+f)) / (1024. * 1024.)
  27
  28 class PruneTest(BitcoinTestFramework):
  29     def set_test_params(self):
  30         self.setup_clean_chain = True
  31         self.num_nodes = 6
  32
  33         # Create nodes 0 and 1 to mine.
  34         # Create node 2 to test pruning.
  35         self.full_node_default_args = ["-maxreceivebuffer=20000","-blockmaxsize=999000", "-checkblocks=5", "-limitdescendantcount=100", "-limitdescendantsize=5000", "-limitancestorcount=100", "-limitancestorsize=5000" ]
  36         # Create nodes 3 and 4 to test manual pruning (they will be re-started with manual pruning later)
  37         # Create nodes 5 to test wallet in prune mode, but do not connect
  38         self.extra_args = [self.full_node_default_args,
  39                            self.full_node_default_args,
  40                            ["-maxreceivebuffer=20000", "-prune=550"],
  41                            ["-maxreceivebuffer=20000", "-blockmaxsize=999000"],
  42                            ["-maxreceivebuffer=20000", "-blockmaxsize=999000"],
  43                            ["-prune=550"]]
  44
  45     def setup_network(self):
  46         self.setup_nodes()
  47
  48         self.prunedir = self.options.tmpdir + "/node2/regtest/blocks/"
  49
  50         connect_nodes(self.nodes[0], 1)
  51         connect_nodes(self.nodes[1], 2)
  52         connect_nodes(self.nodes[2], 0)
  53         connect_nodes(self.nodes[0], 3)
  54         connect_nodes(self.nodes[0], 4)
  55         sync_blocks(self.nodes[0:5])
  56
  57     def setup_nodes(self):
  58         self.add_nodes(self.num_nodes, self.extra_args, timewait=900)
  59         self.start_nodes()
  60
  61     def create_big_chain(self):
  62         # Start by creating some coinbases we can spend later
  63         self.nodes[1].generate(200)
  64         sync_blocks(self.nodes[0:2])
  65         self.nodes[0].generate(150)
  66         # Then mine enough full blocks to create more than 550MiB of data
  67         for i in range(645):
  68             mine_large_block(self.nodes[0], self.utxo_cache_0)
  69
  70         sync_blocks(self.nodes[0:5])
  71
  72     def test_height_min(self):
  73         if not os.path.isfile(self.prunedir+"blk00000.dat"):
  74             raise AssertionError("blk00000.dat is missing, pruning too early")
  75         self.log.info("Success")
  76         self.log.info("Though we're already using more than 550MiB, current usage: %d" % calc_usage(self.prunedir))
  77         self.log.info("Mining 25 more blocks should cause the first block file to be pruned")
  78         # Pruning doesn't run until we're allocating another chunk, 20 full blocks past the height cutoff will ensure this
  79         for i in range(25):
  80             mine_large_block(self.nodes[0], self.utxo_cache_0)
  81
  82         waitstart = time.time()
  83         while os.path.isfile(self.prunedir+"blk00000.dat"):
  84             time.sleep(0.1)
  85             if time.time() - waitstart > 30:
  86                 raise AssertionError("blk00000.dat not pruned when it should be")
  87
  88         self.log.info("Success")
  89         usage = calc_usage(self.prunedir)
  90         self.log.info("Usage should be below target: %d" % usage)
  91         if (usage > 550):
  92             raise AssertionError("Pruning target not being met")
  93
  94     def create_chain_with_staleblocks(self):
  95         # Create stale blocks in manageable sized chunks
  96         self.log.info("Mine 24 (stale) blocks on Node 1, followed by 25 (main chain) block reorg from Node 0, for 12 rounds")
  97
  98         for j in range(12):
  99             # Disconnect node 0 so it can mine a longer reorg chain without knowing about node 1's soon-to-be-stale chain
 100             # Node 2 stays connected, so it hears about the stale blocks and then reorg's when node0 reconnects
 101             # Stopping node 0 also clears its mempool, so it doesn't have node1's transactions to accidentally mine
 102             self.stop_node(0)
 103             self.start_node(0, extra_args=self.full_node_default_args)
 104             # Mine 24 blocks in node 1
 105             for i in range(24):
 106                 if j == 0:
 107                     mine_large_block(self.nodes[1], self.utxo_cache_1)
 108                 else:
 109                     # Add node1's wallet transactions back to the mempool, to
 110                     # avoid the mined blocks from being too small.
 111                     self.nodes[1].resendwallettransactions()
 112                     self.nodes[1].generate(1) #tx's already in mempool from previous disconnects
 113
 114             # Reorg back with 25 block chain from node 0
 115             for i in range(25):
 116                 mine_large_block(self.nodes[0], self.utxo_cache_0)
 117
 118             # Create connections in the order so both nodes can see the reorg at the same time
 119             connect_nodes(self.nodes[1], 0)
 120             connect_nodes(self.nodes[2], 0)
 121             sync_blocks(self.nodes[0:3])
 122
 123         self.log.info("Usage can be over target because of high stale rate: %d" % calc_usage(self.prunedir))
 124
 125     def reorg_test(self):
 126         # Node 1 will mine a 300 block chain starting 287 blocks back from Node 0 and Node 2's tip
 127         # This will cause Node 2 to do a reorg requiring 288 blocks of undo data to the reorg_test chain
 128         # Reboot node 1 to clear its mempool (hopefully make the invalidate faster)
 129         # Lower the block max size so we don't keep mining all our big mempool transactions (from disconnected blocks)
 130         self.stop_node(1)
 131         self.start_node(1, extra_args=["-maxreceivebuffer=20000","-blockmaxsize=5000", "-checkblocks=5", "-disablesafemode"])
 132
 133         height = self.nodes[1].getblockcount()
 134         self.log.info("Current block height: %d" % height)
 135
 136         invalidheight = height-287
 137         badhash = self.nodes[1].getblockhash(invalidheight)
 138         self.log.info("Invalidating block %s at height %d" % (badhash,invalidheight))
 139         self.nodes[1].invalidateblock(badhash)
 140
 141         # We've now switched to our previously mined-24 block fork on node 1, but that's not what we want
 142         # So invalidate that fork as well, until we're on the same chain as node 0/2 (but at an ancestor 288 blocks ago)
 143         mainchainhash = self.nodes[0].getblockhash(invalidheight - 1)
 144         curhash = self.nodes[1].getblockhash(invalidheight - 1)
 145         while curhash != mainchainhash:
 146             self.nodes[1].invalidateblock(curhash)
 147             curhash = self.nodes[1].getblockhash(invalidheight - 1)
 148
 149         assert(self.nodes[1].getblockcount() == invalidheight - 1)
 150         self.log.info("New best height: %d" % self.nodes[1].getblockcount())
 151
 152         # Reboot node1 to clear those giant tx's from mempool
 153         self.stop_node(1)
 154         self.start_node(1, extra_args=["-maxreceivebuffer=20000","-blockmaxsize=5000", "-checkblocks=5", "-disablesafemode"])
 155
 156         self.log.info("Generating new longer chain of 300 more blocks")
 157         self.nodes[1].generate(300)
 158
 159         self.log.info("Reconnect nodes")
 160         connect_nodes(self.nodes[0], 1)
 161         connect_nodes(self.nodes[2], 1)
 162         sync_blocks(self.nodes[0:3], timeout=120)
 163
 164         self.log.info("Verify height on node 2: %d" % self.nodes[2].getblockcount())
 165         self.log.info("Usage possibly still high bc of stale blocks in block files: %d" % calc_usage(self.prunedir))
 166
 167         self.log.info("Mine 220 more blocks so we have requisite history (some blocks will be big and cause pruning of previous chain)")
 168
 169         # Get node0's wallet transactions back in its mempool, to avoid the
 170         # mined blocks from being too small.
 171         self.nodes[0].resendwallettransactions()
 172
 173         for i in range(22):
 174             # This can be slow, so do this in multiple RPC calls to avoid
 175             # RPC timeouts.
 176             self.nodes[0].generate(10) #node 0 has many large tx's in its mempool from the disconnects
 177         sync_blocks(self.nodes[0:3], timeout=300)
 178
 179         usage = calc_usage(self.prunedir)
 180         self.log.info("Usage should be below target: %d" % usage)
 181         if (usage > 550):
 182             raise AssertionError("Pruning target not being met")
 183
 184         return invalidheight,badhash
 185
 186     def reorg_back(self):
 187         # Verify that a block on the old main chain fork has been pruned away
 188         assert_raises_rpc_error(-1, "Block not available (pruned data)", self.nodes[2].getblock, self.forkhash)
 189         self.log.info("Will need to redownload block %d" % self.forkheight)
 190
 191         # Verify that we have enough history to reorg back to the fork point
 192         # Although this is more than 288 blocks, because this chain was written more recently
 193         # and only its other 299 small and 220 large block are in the block files after it,
 194         # its expected to still be retained
 195         self.nodes[2].getblock(self.nodes[2].getblockhash(self.forkheight))
 196
 197         first_reorg_height = self.nodes[2].getblockcount()
 198         curchainhash = self.nodes[2].getblockhash(self.mainchainheight)
 199         self.nodes[2].invalidateblock(curchainhash)
 200         goalbestheight = self.mainchainheight
 201         goalbesthash = self.mainchainhash2
 202
 203         # As of 0.10 the current block download logic is not able to reorg to the original chain created in
 204         # create_chain_with_stale_blocks because it doesn't know of any peer that's on that chain from which to
 205         # redownload its missing blocks.
 206         # Invalidate the reorg_test chain in node 0 as well, it can successfully switch to the original chain
 207         # because it has all the block data.
 208         # However it must mine enough blocks to have a more work chain than the reorg_test chain in order
 209         # to trigger node 2's block download logic.
 210         # At this point node 2 is within 288 blocks of the fork point so it will preserve its ability to reorg
 211         if self.nodes[2].getblockcount() < self.mainchainheight:
 212             blocks_to_mine = first_reorg_height + 1 - self.mainchainheight
 213             self.log.info("Rewind node 0 to prev main chain to mine longer chain to trigger redownload. Blocks needed: %d" % blocks_to_mine)
 214             self.nodes[0].invalidateblock(curchainhash)
 215             assert(self.nodes[0].getblockcount() == self.mainchainheight)
 216             assert(self.nodes[0].getbestblockhash() == self.mainchainhash2)
 217             goalbesthash = self.nodes[0].generate(blocks_to_mine)[-1]
 218             goalbestheight = first_reorg_height + 1
 219
 220         self.log.info("Verify node 2 reorged back to the main chain, some blocks of which it had to redownload")
 221         waitstart = time.time()
 222         while self.nodes[2].getblockcount() < goalbestheight:
 223             time.sleep(0.1)
 224             if time.time() - waitstart > 900:
 225                 raise AssertionError("Node 2 didn't reorg to proper height")
 226         assert(self.nodes[2].getbestblockhash() == goalbesthash)
 227         # Verify we can now have the data for a block previously pruned
 228         assert(self.nodes[2].getblock(self.forkhash)["height"] == self.forkheight)
 229
 230     def manual_test(self, node_number, use_timestamp):
 231         # at this point, node has 995 blocks and has not yet run in prune mode
 232         self.start_node(node_number)
 233         node = self.nodes[node_number]
 234         assert_equal(node.getblockcount(), 995)
 235         assert_raises_rpc_error(-1, "not in prune mode", node.pruneblockchain, 500)
 236
 237         # now re-start in manual pruning mode
 238         self.stop_node(node_number)
 239         self.start_node(node_number, extra_args=["-prune=1"])
 240         node = self.nodes[node_number]
 241         assert_equal(node.getblockcount(), 995)
 242
 243         def height(index):
 244             if use_timestamp:
 245                 return node.getblockheader(node.getblockhash(index))["time"] + TIMESTAMP_WINDOW
 246             else:
 247                 return index
 248
 249         def prune(index, expected_ret=None):
 250             ret = node.pruneblockchain(height(index))
 251             # Check the return value. When use_timestamp is True, just check
 252             # that the return value is less than or equal to the expected
 253             # value, because when more than one block is generated per second,
 254             # a timestamp will not be granular enough to uniquely identify an
 255             # individual block.
 256             if expected_ret is None:
 257                 expected_ret = index
 258             if use_timestamp:
 259                 assert_greater_than(ret, 0)
 260                 assert_greater_than(expected_ret + 1, ret)
 261             else:
 262                 assert_equal(ret, expected_ret)
 263
 264         def has_block(index):
 265             return os.path.isfile(self.options.tmpdir + "/node{}/regtest/blocks/blk{:05}.dat".format(node_number, index))
 266
 267         # should not prune because chain tip of node 3 (995) < PruneAfterHeight (1000)
 268         assert_raises_rpc_error(-1, "Blockchain is too short for pruning", node.pruneblockchain, height(500))
 269
 270         # mine 6 blocks so we are at height 1001 (i.e., above PruneAfterHeight)
 271         node.generate(6)
 272         assert_equal(node.getblockchaininfo()["blocks"], 1001)
 273
 274         # negative heights should raise an exception
 275         assert_raises_rpc_error(-8, "Negative", node.pruneblockchain, -10)
 276
 277         # height=100 too low to prune first block file so this is a no-op
 278         prune(100)
 279         if not has_block(0):
 280             raise AssertionError("blk00000.dat is missing when should still be there")
 281
 282         # Does nothing
 283         node.pruneblockchain(height(0))
 284         if not has_block(0):
 285             raise AssertionError("blk00000.dat is missing when should still be there")
 286
 287         # height=500 should prune first file
 288         prune(500)
 289         if has_block(0):
 290             raise AssertionError("blk00000.dat is still there, should be pruned by now")
 291         if not has_block(1):
 292             raise AssertionError("blk00001.dat is missing when should still be there")
 293
 294         # height=650 should prune second file
 295         prune(650)
 296         if has_block(1):
 297             raise AssertionError("blk00001.dat is still there, should be pruned by now")
 298
 299         # height=1000 should not prune anything more, because tip-288 is in blk00002.dat.
 300         prune(1000, 1001 - MIN_BLOCKS_TO_KEEP)
 301         if not has_block(2):
 302             raise AssertionError("blk00002.dat is still there, should be pruned by now")
 303
 304         # advance the tip so blk00002.dat and blk00003.dat can be pruned (the last 288 blocks should now be in blk00004.dat)
 305         node.generate(288)
 306         prune(1000)
 307         if has_block(2):
 308             raise AssertionError("blk00002.dat is still there, should be pruned by now")
 309         if has_block(3):
 310             raise AssertionError("blk00003.dat is still there, should be pruned by now")
 311
 312         # stop node, start back up with auto-prune at 550MB, make sure still runs
 313         self.stop_node(node_number)
 314         self.start_node(node_number, extra_args=["-prune=550"])
 315
 316         self.log.info("Success")
 317
 318     def wallet_test(self):
 319         # check that the pruning node's wallet is still in good shape
 320         self.log.info("Stop and start pruning node to trigger wallet rescan")
 321         self.stop_node(2)
 322         self.start_node(2, extra_args=["-prune=550"])
 323         self.log.info("Success")
 324
 325         # check that wallet loads successfully when restarting a pruned node after IBD.
 326         # this was reported to fail in #7494.
 327         self.log.info("Syncing node 5 to test wallet")
 328         connect_nodes(self.nodes[0], 5)
 329         nds = [self.nodes[0], self.nodes[5]]
 330         sync_blocks(nds, wait=5, timeout=300)
 331         self.stop_node(5) #stop and start to trigger rescan
 332         self.start_node(5, extra_args=["-prune=550"])
 333         self.log.info("Success")
 334
 335     def run_test(self):
 336         self.log.info("Warning! This test requires 4GB of disk space and takes over 30 mins (up to 2 hours)")
 337         self.log.info("Mining a big blockchain of 995 blocks")
 338
 339         # Determine default relay fee
 340         self.relayfee = self.nodes[0].getnetworkinfo()["relayfee"]
 341
 342         # Cache for utxos, as the listunspent may take a long time later in the test
 343         self.utxo_cache_0 = []
 344         self.utxo_cache_1 = []
 345
 346         self.create_big_chain()
 347         # Chain diagram key:
 348         # *   blocks on main chain
 349         # +,&,$,@ blocks on other forks
 350         # X   invalidated block
 351         # N1  Node 1
 352         #
 353         # Start by mining a simple chain that all nodes have
 354         # N0=N1=N2 **...*(995)
 355
 356         # stop manual-pruning node with 995 blocks
 357         self.stop_node(3)
 358         self.stop_node(4)
 359
 360         self.log.info("Check that we haven't started pruning yet because we're below PruneAfterHeight")
 361         self.test_height_min()
 362         # Extend this chain past the PruneAfterHeight
 363         # N0=N1=N2 **...*(1020)
 364
 365         self.log.info("Check that we'll exceed disk space target if we have a very high stale block rate")
 366         self.create_chain_with_staleblocks()
 367         # Disconnect N0
 368         # And mine a 24 block chain on N1 and a separate 25 block chain on N0
 369         # N1=N2 **...*+...+(1044)
 370         # N0    **...**...**(1045)
 371         #
 372         # reconnect nodes causing reorg on N1 and N2
 373         # N1=N2 **...*(1020) *...**(1045)
 374         #                   \
 375         #                    +...+(1044)
 376         #
 377         # repeat this process until you have 12 stale forks hanging off the
 378         # main chain on N1 and N2
 379         # N0    *************************...***************************(1320)
 380         #
 381         # N1=N2 **...*(1020) *...**(1045) *..         ..**(1295) *...**(1320)
 382         #                   \            \                      \
 383         #                    +...+(1044)  &..                    $...$(1319)
 384
 385         # Save some current chain state for later use
 386         self.mainchainheight = self.nodes[2].getblockcount()   #1320
 387         self.mainchainhash2 = self.nodes[2].getblockhash(self.mainchainheight)
 388
 389         self.log.info("Check that we can survive a 288 block reorg still")
 390         (self.forkheight,self.forkhash) = self.reorg_test() #(1033, )
 391         # Now create a 288 block reorg by mining a longer chain on N1
 392         # First disconnect N1
 393         # Then invalidate 1033 on main chain and 1032 on fork so height is 1032 on main chain
 394         # N1   **...*(1020) **...**(1032)X..
 395         #                  \
 396         #                   ++...+(1031)X..
 397         #
 398         # Now mine 300 more blocks on N1
 399         # N1    **...*(1020) **...**(1032) @@...@(1332)
 400         #                 \               \
 401         #                  \               X...
 402         #                   \                 \
 403         #                    ++...+(1031)X..   ..
 404         #
 405         # Reconnect nodes and mine 220 more blocks on N1
 406         # N1    **...*(1020) **...**(1032) @@...@@@(1552)
 407         #                 \               \
 408         #                  \               X...
 409         #                   \                 \
 410         #                    ++...+(1031)X..   ..
 411         #
 412         # N2    **...*(1020) **...**(1032) @@...@@@(1552)
 413         #                 \               \
 414         #                  \               *...**(1320)
 415         #                   \                 \
 416         #                    ++...++(1044)     ..
 417         #
 418         # N0    ********************(1032) @@...@@@(1552)
 419         #                                 \
 420         #                                  *...**(1320)
 421
 422         self.log.info("Test that we can rerequest a block we previously pruned if needed for a reorg")
 423         self.reorg_back()
 424         # Verify that N2 still has block 1033 on current chain (@), but not on main chain (*)
 425         # Invalidate 1033 on current chain (@) on N2 and we should be able to reorg to
 426         # original main chain (*), but will require redownload of some blocks
 427         # In order to have a peer we think we can download from, must also perform this invalidation
 428         # on N0 and mine a new longest chain to trigger.
 429         # Final result:
 430         # N0    ********************(1032) **...****(1553)
 431         #                                 \
 432         #                                  X@...@@@(1552)
 433         #
 434         # N2    **...*(1020) **...**(1032) **...****(1553)
 435         #                 \               \
 436         #                  \               X@...@@@(1552)
 437         #                   \
 438         #                    +..
 439         #
 440         # N1 doesn't change because 1033 on main chain (*) is invalid
 441
 442         self.log.info("Test manual pruning with block indices")
 443         self.manual_test(3, use_timestamp=False)
 444
 445         self.log.info("Test manual pruning with timestamps")
 446         self.manual_test(4, use_timestamp=True)
 447
 448         self.log.info("Test wallet re-scan")
 449         self.wallet_test()
 450
 451         self.log.info("Done")
 452
 453 if __name__ == '__main__':
 454     PruneTest().main()