Intermittent test failures in fundrawtransaction.py #6391

laanwj commented at 4:37 PM on July 7, 2015: member

Some travis runs abort with:

Running testscript fundrawtransaction.py...
Initializing test directory /tmp/testDgVGV6
start_node: bitcoind started, calling bitcoin-cli -rpcwait getblockcount
start_node: calling bitcoin-cli -rpcwait getblockcount returned
start_node: bitcoind started, calling bitcoin-cli -rpcwait getblockcount
start_node: calling bitcoin-cli -rpcwait getblockcount returned
start_node: bitcoind started, calling bitcoin-cli -rpcwait getblockcount
start_node: calling bitcoin-cli -rpcwait getblockcount returned
Mining blocks...
Assertion failed: 50.00000000 != 1.5
File "/home/travis/build/bitcoin/bitcoin/bitcoin-x86_64-unknown-linux-gnu/qa/rpc-tests/test_framework/test_framework.py", line 118, in main
self.run_test()
File "/home/travis/build/bitcoin/bitcoin/bitcoin-x86_64-unknown-linux-gnu/qa/rpc-tests/fundrawtransaction.py", line 59, in run_test
assert_equal(fee + totalOut, 1.5) #the 1.5BTC coin must be taken
File "/home/travis/build/bitcoin/bitcoin/bitcoin-x86_64-unknown-linux-gnu/qa/rpc-tests/test_framework/util.py", line 342, in assert_equal
raise AssertionError("%s != %s"%(str(thing1),str(thing2)))
Stopping nodes
Cleaning up
Failed

laanwj added the label Tests on Jul 7, 2015

jonasschnelli commented at 6:56 PM on July 7, 2015: contributor

Hmm.... this means, that fundrawtransaction or our coin selection doesn't work properly.

fundrawtransaction.py:

At L35 we send a 1.5BTC coin to node[2]
At L39 we mine the tx from 1. and sync the nodes
At L50 we fund(rawtransaction) a new tx on node[2] with one output of 1.0 BTC.
Because we have sent a 1.5BTC to node[2] (mined and synced), it should prefer this 1.5BTC coin instead of taking a 50BTC coin.

The assertion fails because the test showed that the 50BTC coin has been preferred.

I can't reproduce this on my systems. Has anyone found out a way to reproduce that?

laanwj commented at 1:10 PM on July 8, 2015: member

Another one, in a different test. It must be some race condition or timeout.

Running testscript txn_clone.py...
Initializing test directory /tmp/testtoOq_3
start_node: bitcoind started, calling bitcoin-cli -rpcwait getblockcount
start_node: calling bitcoin-cli -rpcwait getblockcount returned
start_node: bitcoind started, calling bitcoin-cli -rpcwait getblockcount
start_node: calling bitcoin-cli -rpcwait getblockcount returned
start_node: bitcoind started, calling bitcoin-cli -rpcwait getblockcount
start_node: calling bitcoin-cli -rpcwait getblockcount returned
start_node: bitcoind started, calling bitcoin-cli -rpcwait getblockcount
start_node: calling bitcoin-cli -rpcwait getblockcount returned
Assertion failed: 1 != 0
File "/home/travis/build/bitcoin/bitcoin/bitcoin-i686-pc-linux-gnu/qa/rpc-tests/test_framework/test_framework.py", line 118, in main
self.run_test()
File "/home/travis/build/bitcoin/bitcoin/bitcoin-i686-pc-linux-gnu/qa/rpc-tests/txn_clone.py", line 139, in run_test
assert_equal(tx2["confirmations"], 0)
File "/home/travis/build/bitcoin/bitcoin/bitcoin-i686-pc-linux-gnu/qa/rpc-tests/test_framework/util.py", line 342, in assert_equal
raise AssertionError("%s != %s"%(str(thing1),str(thing2)))
Stopping nodes
Cleaning up
Failed

laanwj commented at 1:30 PM on July 8, 2015: member

It is not easy to reproduce, happens very rarely. It may be something about syncing between nodes not working properly.

sdaftuar commented at 2:06 PM on July 9, 2015: member

I can reproduce this reliably by doing a sync_all() in between node2 generating 1 block at line 32, and node0 generating 101 blocks at line 33:

def run_test(self):
        print "Mining blocks..."
        feeTolerance = Decimal(0.00000002) #if the fee's positive delta is higher than this value tests will fail, neg. delta always fail the tests

        self.nodes[2].generate(1)
>>>     self.sync_all()
        self.nodes[0].generate(101)
        self.sync_all()

morcos commented at 7:17 PM on July 9, 2015: member

@jonasschnelli , @sdaftuar is right that that sync needs to be in there otherwise node 2 often doesn't even have its own 50BTC coin, because it has be reorged away by node 0's chain. The sync ensures that node 0 builds off of node 2.

As to why that causes failure, I haven't been paying attention to the changes introduced with fundrawtransaction, but I don't understand where your assumptions are coming from as to which coins should have been preferred. It seems like several of the asserts fail. SelectCoinsMinConf has a kind of messy randomized algorithm for selecting coins.

laanwj commented at 4:55 PM on July 10, 2015: member

The one in txn_clone should be solved by #6414

sdaftuar commented at 5:14 PM on July 10, 2015: member

@TheBlueMatt I noticed you opened #6415, which includes updates to this test -- any ideas here?

jonasschnelli commented at 5:56 PM on July 10, 2015: contributor

@morcos: Okay. I see now the reorg issue with a missing sync. #6415 would not fix this. Will open a PR.

laanwj closed this on Jul 13, 2015

MarcoFalke locked this on Sep 8, 2021