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