diff --git a/tests/test_closing.py b/tests/test_closing.py index 1a79bbb55..05622ee04 100644 --- a/tests/test_closing.py +++ b/tests/test_closing.py @@ -1,11 +1,118 @@ from fixtures import * # noqa: F401,F403 +from lightning import RpcError +from utils import only_one, sync_blockheight, wait_for, DEVELOPER, TIMEOUT, VALGRIND -import os -with open('config.vars') as configfile: - config = dict([(line.rstrip().split('=', 1)) for line in configfile]) +import queue +import pytest +import re +import threading +import unittest -DEVELOPER = os.getenv("DEVELOPER", config['DEVELOPER']) == "1" + +@unittest.skipIf(not DEVELOPER, "Too slow without --dev-bitcoind-poll") +def test_closing(node_factory, bitcoind): + l1, l2 = node_factory.line_graph(2) + chan = l1.get_channel_scid(l2) + + l1.pay(l2, 200000000) + + assert bitcoind.rpc.getmempoolinfo()['size'] == 0 + + billboard = only_one(l1.rpc.listpeers(l2.info['id'])['peers'][0]['channels'])['status'] + assert billboard == ['CHANNELD_NORMAL:Funding transaction locked.'] + billboard = only_one(l2.rpc.listpeers(l1.info['id'])['peers'][0]['channels'])['status'] + assert billboard == ['CHANNELD_NORMAL:Funding transaction locked.'] + + bitcoind.rpc.generate(5) + + # Only wait for the channels to activate with DEVELOPER=1, + # otherwise it's going to take too long because of the missing + # --dev-broadcast-interval + if DEVELOPER: + wait_for(lambda: len(l1.getactivechannels()) == 2) + wait_for(lambda: len(l2.getactivechannels()) == 2) + billboard = only_one(l1.rpc.listpeers(l2.info['id'])['peers'][0]['channels'])['status'] + # This may either be from a local_update or an announce, so just + # check for the substring + assert 'CHANNELD_NORMAL:Funding transaction locked.' in billboard[0] + + # This should return with an error, then close. + with pytest.raises(RpcError, match=r'Channel close negotiation not finished'): + l1.rpc.close(chan, False, 0) + + l1.daemon.wait_for_log(' to CHANNELD_SHUTTING_DOWN') + l2.daemon.wait_for_log(' to CHANNELD_SHUTTING_DOWN') + + l1.daemon.wait_for_log(' to CLOSINGD_SIGEXCHANGE') + l2.daemon.wait_for_log(' to CLOSINGD_SIGEXCHANGE') + + # And should put closing into mempool. + l1.daemon.wait_for_log('sendrawtx exit 0') + l2.daemon.wait_for_log('sendrawtx exit 0') + + # Both nodes should have disabled the channel in their view + wait_for(lambda: len(l1.getactivechannels()) == 0) + wait_for(lambda: len(l2.getactivechannels()) == 0) + + assert bitcoind.rpc.getmempoolinfo()['size'] == 1 + + # Now grab the close transaction + closetxid = only_one(bitcoind.rpc.getrawmempool(False)) + + billboard = only_one(l1.rpc.listpeers(l2.info['id'])['peers'][0]['channels'])['status'] + assert billboard == ['CLOSINGD_SIGEXCHANGE:We agreed on a closing fee of 5430 satoshi'] + bitcoind.rpc.generate(1) + + l1.daemon.wait_for_log(r'Owning output .* txid %s' % closetxid) + l2.daemon.wait_for_log(r'Owning output .* txid %s' % closetxid) + + # Make sure both nodes have grabbed their close tx funds + assert closetxid in set([o['txid'] for o in l1.rpc.listfunds()['outputs']]) + assert closetxid in set([o['txid'] for o in l2.rpc.listfunds()['outputs']]) + + wait_for(lambda: only_one(l1.rpc.listpeers(l2.info['id'])['peers'][0]['channels'])['status'] == [ + 'CLOSINGD_SIGEXCHANGE:We agreed on a closing fee of 5430 satoshi', + 'ONCHAIN:Tracking mutual close transaction', + 'ONCHAIN:All outputs resolved: waiting 99 more blocks before forgetting channel' + ]) + + bitcoind.rpc.generate(9) + wait_for(lambda: only_one(l1.rpc.listpeers(l2.info['id'])['peers'][0]['channels'])['status'] == [ + 'CLOSINGD_SIGEXCHANGE:We agreed on a closing fee of 5430 satoshi', + 'ONCHAIN:Tracking mutual close transaction', + 'ONCHAIN:All outputs resolved: waiting 90 more blocks before forgetting channel' + ]) + + # Make sure both have forgotten about it + bitcoind.rpc.generate(90) + wait_for(lambda: len(l1.rpc.listchannels()['channels']) == 0) + wait_for(lambda: len(l2.rpc.listchannels()['channels']) == 0) + + +def test_closing_while_disconnected(node_factory, bitcoind): + l1, l2 = node_factory.line_graph(2, opts={'may_reconnect': True}) + chan = l1.get_channel_scid(l2) + + l1.pay(l2, 200000000) + l2.stop() + + # The close should still be triggered afterwards. + with pytest.raises(RpcError, match=r'Channel close negotiation not finished'): + l1.rpc.close(chan, False, 0) + l1.daemon.wait_for_log(' to CHANNELD_SHUTTING_DOWN') + + l2.start() + l1.daemon.wait_for_log(' to CLOSINGD_SIGEXCHANGE') + l2.daemon.wait_for_log(' to CLOSINGD_SIGEXCHANGE') + + # And should put closing into mempool. + l1.daemon.wait_for_log('sendrawtx exit 0') + l2.daemon.wait_for_log('sendrawtx exit 0') + + bitcoind.rpc.generate(101) + wait_for(lambda: len(l1.rpc.listchannels()['channels']) == 0) + wait_for(lambda: len(l2.rpc.listchannels()['channels']) == 0) def test_closing_id(node_factory): @@ -29,3 +136,1063 @@ def test_closing_id(node_factory): l2.rpc.close(pid) l1.daemon.wait_for_log("Forgetting remote peer .*") l2.daemon.wait_for_log("Forgetting remote peer .*") + + +@unittest.skipIf(not DEVELOPER, "needs dev-rescan-outputs") +def test_closing_torture(node_factory, executor, bitcoind): + l1, l2 = node_factory.get_nodes(2) + amount = 10**6 + + # The range below of 15 is unsatisfactory. + # Before the fix was applied, 15 would often pass. + # However, increasing the number of tries would + # take longer in VALGRIND mode, triggering a CI + # failure since the test does not print any + # output. + for i in range(15): + # Reduce probability that spurious sendrawtx error will occur + l1.rpc.dev_rescan_outputs() + + # Create a channel. + l1.rpc.connect(l2.info['id'], 'localhost', l2.port) + l1.fund_channel(l2, amount) + scid = l1.get_channel_scid(l2) + + # Get it confirmed. + l1.bitcoin.generate_block(6) + + # Wait for it to go to CHANNELD_NORMAL + l1.wait_channel_active(scid) + l2.wait_channel_active(scid) + + # Start closers: can take a long time under valgrind! + c1 = executor.submit(l1.rpc.close, l2.info['id'], False, 60) + c2 = executor.submit(l2.rpc.close, l1.info['id'], False, 60) + # Wait for close to finish + c1.result(TIMEOUT) + c2.result(TIMEOUT) + + wait_for(lambda: len(bitcoind.rpc.getrawmempool(False)) == 1) + + # Get close confirmed + l1.bitcoin.generate_block(100) + wait_for(lambda: len(l1.rpc.listpeers()['peers']) == 0) + wait_for(lambda: len(l2.rpc.listpeers()['peers']) == 0) + + +@unittest.skipIf(not DEVELOPER, "needs dev-override-feerates") +def test_closing_different_fees(node_factory, bitcoind, executor): + l1 = node_factory.get_node() + + # Default feerate = 15000/7500/1000 + # It will start at the second number, accepting anything above the first. + feerates = [[20000, 15000, 7400], [8000, 1001, 100]] + amounts = [0, 545999, 546000] + num_peers = len(feerates) * len(amounts) + + addr = l1.rpc.newaddr()['address'] + bitcoind.rpc.sendtoaddress(addr, 1) + numfunds = len(l1.rpc.listfunds()['outputs']) + bitcoind.generate_block(1) + wait_for(lambda: len(l1.rpc.listfunds()['outputs']) > numfunds) + + # Create them in a batch, for speed! + peers = [] + for feerate in feerates: + for amount in amounts: + p = node_factory.get_node(options={ + 'dev-override-fee-rates': '{}/{}/{}'.format(feerate[0], + feerate[1], + feerate[2]) + }) + p.feerate = feerate + p.amount = amount + l1.rpc.connect(p.info['id'], 'localhost', p.port) + peers.append(p) + + for p in peers: + p.channel = l1.rpc.fundchannel(p.info['id'], 10**6)['channel_id'] + # Technically, this is async to fundchannel returning. + l1.daemon.wait_for_log('sendrawtx exit 0') + + bitcoind.generate_block(6) + + # Now wait for them all to hit normal state, do payments + l1.daemon.wait_for_logs(['update for channel .* now ACTIVE'] * num_peers + + ['to CHANNELD_NORMAL'] * num_peers) + for p in peers: + if p.amount != 0: + l1.pay(p, 100000000) + + # Now close all channels + # All closes occur in parallel, and on Travis, + # ALL those lightningd are running on a single core, + # so increase the timeout so that this test will pass + # when valgrind is enabled. + # (close timeout defaults to 30 as of this writing) + closes = [executor.submit(l1.rpc.close, p.channel, False, 90) for p in peers] + + for c in closes: + c.result(90) + + # close does *not* wait for the sendrawtransaction, so do that! + # Note that since they disagree on the ideal fee, they may conflict + # (first one in will win), so we cannot look at logs, we need to + # wait for mempool. + wait_for(lambda: bitcoind.rpc.getmempoolinfo()['size'] == num_peers) + + bitcoind.generate_block(1) + for p in peers: + p.daemon.wait_for_log(' to ONCHAIN') + wait_for(lambda: only_one(p.rpc.listpeers(l1.info['id'])['peers'][0]['channels'])['status'][1] == 'ONCHAIN:Tracking mutual close transaction') + l1.daemon.wait_for_logs([' to ONCHAIN'] * num_peers) + + +@unittest.skipIf(not DEVELOPER, "needs DEVELOPER=1") +def test_closing_negotiation_reconnect(node_factory, bitcoind): + disconnects = ['-WIRE_CLOSING_SIGNED', + '@WIRE_CLOSING_SIGNED', + '+WIRE_CLOSING_SIGNED'] + l1 = node_factory.get_node(disconnect=disconnects, may_reconnect=True) + l2 = node_factory.get_node(may_reconnect=True) + l1.rpc.connect(l2.info['id'], 'localhost', l2.port) + + chan = l1.fund_channel(l2, 10**6) + l1.pay(l2, 200000000) + + assert bitcoind.rpc.getmempoolinfo()['size'] == 0 + + # This should return with an error, then close. + with pytest.raises(RpcError, match=r'Channel close negotiation not finished'): + l1.rpc.close(chan, False, 0) + + l1.daemon.wait_for_log(' to CHANNELD_SHUTTING_DOWN') + l2.daemon.wait_for_log(' to CHANNELD_SHUTTING_DOWN') + + l1.daemon.wait_for_log(' to CLOSINGD_SIGEXCHANGE') + l2.daemon.wait_for_log(' to CLOSINGD_SIGEXCHANGE') + + # And should put closing into mempool (happens async, so + # CLOSINGD_COMPLETE may come first). + l1.daemon.wait_for_logs(['sendrawtx exit 0', ' to CLOSINGD_COMPLETE']) + l2.daemon.wait_for_logs(['sendrawtx exit 0', ' to CLOSINGD_COMPLETE']) + assert bitcoind.rpc.getmempoolinfo()['size'] == 1 + + +@unittest.skipIf(not DEVELOPER, "needs DEVELOPER=1") +def test_penalty_inhtlc(node_factory, bitcoind, executor): + """Test penalty transaction with an incoming HTLC""" + # We suppress each one after first commit; HTLC gets added not fulfilled. + l1 = node_factory.get_node(disconnect=['=WIRE_COMMITMENT_SIGNED-nocommit'], may_fail=True) + l2 = node_factory.get_node(disconnect=['=WIRE_COMMITMENT_SIGNED-nocommit']) + + l1.rpc.connect(l2.info['id'], 'localhost', l2.port) + l1.fund_channel(l2, 10**6) + + # Now, this will get stuck due to l1 commit being disabled.. + t = executor.submit(l1.pay, l2, 100000000) + + assert len(l1.getactivechannels()) == 2 + assert len(l2.getactivechannels()) == 2 + + # They should both have commitments blocked now. + l1.daemon.wait_for_log('=WIRE_COMMITMENT_SIGNED-nocommit') + l2.daemon.wait_for_log('=WIRE_COMMITMENT_SIGNED-nocommit') + + # Make sure l1 got l2's commitment to the HTLC, and sent to master. + l1.daemon.wait_for_log('UPDATE WIRE_CHANNEL_GOT_COMMITSIG') + + # Take our snapshot. + tx = l1.rpc.dev_sign_last_tx(l2.info['id'])['tx'] + + # Let them continue + l1.rpc.dev_reenable_commit(l2.info['id']) + l2.rpc.dev_reenable_commit(l1.info['id']) + + # Should fulfill. + l1.daemon.wait_for_log('peer_in WIRE_UPDATE_FULFILL_HTLC') + l1.daemon.wait_for_log('peer_out WIRE_REVOKE_AND_ACK') + + l2.daemon.wait_for_log('peer_out WIRE_UPDATE_FULFILL_HTLC') + l1.daemon.wait_for_log('peer_in WIRE_REVOKE_AND_ACK') + + # Payment should now complete. + t.result(timeout=10) + + # Now we really mess things up! + bitcoind.rpc.sendrawtransaction(tx) + bitcoind.generate_block(1) + + l2.daemon.wait_for_log(' to ONCHAIN') + # FIXME: l1 should try to stumble along! + wait_for(lambda: len(l2.getactivechannels()) == 0) + + # l2 should spend all of the outputs (except to-us). + # Could happen in any order, depending on commitment tx. + l2.daemon.wait_for_logs([ + 'Propose handling THEIR_REVOKED_UNILATERAL/DELAYED_OUTPUT_TO_THEM by OUR_PENALTY_TX .* after 0 blocks', + 'sendrawtx exit 0', + 'Propose handling THEIR_REVOKED_UNILATERAL/THEIR_HTLC by OUR_PENALTY_TX .* after 0 blocks', + 'sendrawtx exit 0' + ]) + + # FIXME: test HTLC tx race! + + # 100 blocks later, all resolved. + bitcoind.generate_block(100) + + l2.daemon.wait_for_log('onchaind complete, forgetting peer') + + outputs = l2.rpc.listfunds()['outputs'] + assert [o['status'] for o in outputs] == ['confirmed'] * 2 + # Allow some lossage for fees. + assert sum(o['value'] for o in outputs) < 10**6 + assert sum(o['value'] for o in outputs) > 10**6 - 15000 + + +@unittest.skipIf(not DEVELOPER, "needs DEVELOPER=1") +def test_penalty_outhtlc(node_factory, bitcoind, executor): + """Test penalty transaction with an outgoing HTLC""" + # First we need to get funds to l2, so suppress after second. + l1 = node_factory.get_node(disconnect=['=WIRE_COMMITMENT_SIGNED*3-nocommit'], may_fail=True) + l2 = node_factory.get_node(disconnect=['=WIRE_COMMITMENT_SIGNED*3-nocommit']) + + l1.rpc.connect(l2.info['id'], 'localhost', l2.port) + l1.fund_channel(l2, 10**6) + + # Move some across to l2. + l1.pay(l2, 200000000) + + assert not l1.daemon.is_in_log('=WIRE_COMMITMENT_SIGNED') + assert not l2.daemon.is_in_log('=WIRE_COMMITMENT_SIGNED') + + # Now, this will get stuck due to l1 commit being disabled.. + t = executor.submit(l2.pay, l1, 100000000) + + # Make sure we get signature from them. + l1.daemon.wait_for_log('peer_in WIRE_UPDATE_ADD_HTLC') + l1.daemon.wait_for_log('peer_in WIRE_COMMITMENT_SIGNED') + + # They should both have commitments blocked now. + l1.daemon.wait_for_log('dev_disconnect: =WIRE_COMMITMENT_SIGNED') + l2.daemon.wait_for_log('dev_disconnect: =WIRE_COMMITMENT_SIGNED') + + # Make sure both sides got revoke_and_ack for that commitment. + l1.daemon.wait_for_log('peer_in WIRE_REVOKE_AND_ACK') + l2.daemon.wait_for_log('peer_in WIRE_REVOKE_AND_ACK') + + # Take our snapshot. + tx = l1.rpc.dev_sign_last_tx(l2.info['id'])['tx'] + + # Let them continue + l1.rpc.dev_reenable_commit(l2.info['id']) + l2.rpc.dev_reenable_commit(l1.info['id']) + + # Thread should complete. + t.result(timeout=10) + + # Make sure both sides got revoke_and_ack for final. + l1.daemon.wait_for_log('peer_in WIRE_REVOKE_AND_ACK') + l2.daemon.wait_for_log('peer_in WIRE_REVOKE_AND_ACK') + + # Now we really mess things up! + bitcoind.rpc.sendrawtransaction(tx) + bitcoind.generate_block(1) + + l2.daemon.wait_for_log(' to ONCHAIN') + # FIXME: l1 should try to stumble along! + + # l2 should spend all of the outputs (except to-us). + # Could happen in any order, depending on commitment tx. + l2.daemon.wait_for_logs([ + 'Ignoring output.*: THEIR_REVOKED_UNILATERAL/OUTPUT_TO_US', + 'Propose handling THEIR_REVOKED_UNILATERAL/DELAYED_OUTPUT_TO_THEM by OUR_PENALTY_TX .* after 0 blocks', + 'sendrawtx exit 0', + 'Propose handling THEIR_REVOKED_UNILATERAL/OUR_HTLC by OUR_PENALTY_TX .* after 0 blocks', + 'sendrawtx exit 0' + ]) + + # FIXME: test HTLC tx race! + + # 100 blocks later, all resolved. + bitcoind.generate_block(100) + + wait_for(lambda: len(l2.rpc.listpeers()['peers']) == 0) + + outputs = l2.rpc.listfunds()['outputs'] + assert [o['status'] for o in outputs] == ['confirmed'] * 3 + # Allow some lossage for fees. + assert sum(o['value'] for o in outputs) < 10**6 + assert sum(o['value'] for o in outputs) > 10**6 - 15000 + + +@unittest.skipIf(not DEVELOPER, "needs DEVELOPER=1") +def test_onchain_first_commit(node_factory, bitcoind): + """Onchain handling where funder immediately drops to chain""" + + # HTLC 1->2, 1 fails just after funding. + disconnects = ['+WIRE_FUNDING_LOCKED', 'permfail'] + l1 = node_factory.get_node(disconnect=disconnects) + # Make locktime different, as we once had them reversed! + l2 = node_factory.get_node(options={'watchtime-blocks': 10}) + l1.fundwallet(10**7) + + l1.rpc.connect(l2.info['id'], 'localhost', l2.port) + + l1.rpc.fundchannel(l2.info['id'], 10**6) + l1.daemon.wait_for_log('sendrawtx exit 0') + + l1.bitcoin.generate_block(1) + + # l1 will drop to chain. + l1.daemon.wait_for_log('permfail') + l1.daemon.wait_for_log('sendrawtx exit 0') + l1.bitcoin.generate_block(1) + l1.daemon.wait_for_log(' to ONCHAIN') + l2.daemon.wait_for_log(' to ONCHAIN') + + # 10 later, l1 should collect its to-self payment. + bitcoind.generate_block(10) + l1.daemon.wait_for_logs([ + 'Broadcasting OUR_DELAYED_RETURN_TO_WALLET .* to resolve OUR_UNILATERAL/DELAYED_OUTPUT_TO_US', + 'sendrawtx exit 0' + ]) + + # 94 later, l2 is done. + bitcoind.generate_block(94) + l2.daemon.wait_for_log('onchaind complete, forgetting peer') + + # Now, 100 blocks and l1 should be done. + bitcoind.generate_block(6) + l1.daemon.wait_for_log('onchaind complete, forgetting peer') + + +@unittest.skipIf(not DEVELOPER, "needs DEVELOPER=1") +def test_onchain_unwatch(node_factory, bitcoind): + """Onchaind should not watch random spends""" + l1, l2 = node_factory.line_graph(2) + + l1.pay(l2, 200000000) + + l1.rpc.dev_fail(l2.info['id']) + l1.daemon.wait_for_log('Failing due to dev-fail command') + l1.daemon.wait_for_log('sendrawtx exit 0') + + l1.bitcoin.generate_block(1) + l1.daemon.wait_for_log(' to ONCHAIN') + l2.daemon.wait_for_log(' to ONCHAIN') + + # 10 later, l1 should collect its to-self payment. + bitcoind.generate_block(10) + l1.daemon.wait_for_log('Broadcasting OUR_DELAYED_RETURN_TO_WALLET .* to resolve ' + 'OUR_UNILATERAL/DELAYED_OUTPUT_TO_US') + l1.daemon.wait_for_log('sendrawtx exit 0') + + # First time it sees it, onchaind cares. + bitcoind.generate_block(1) + l1.daemon.wait_for_log('Resolved OUR_UNILATERAL/DELAYED_OUTPUT_TO_US by our proposal ' + 'OUR_DELAYED_RETURN_TO_WALLET') + + # Now test unrelated onchain churn. + # Daemon gets told about wallet; says it doesn't care. + l1.rpc.withdraw(l1.rpc.newaddr()['address'], 'all') + bitcoind.generate_block(1) + l1.daemon.wait_for_log("but we don't care") + + # And lightningd should respect that! + assert not l1.daemon.is_in_log("Can't unwatch txid") + + # So these should not generate further messages + for i in range(5): + l1.rpc.withdraw(l1.rpc.newaddr()['address'], 'all') + bitcoind.generate_block(1) + # Make sure it digests the block + sync_blockheight(bitcoind, [l1]) + + # We won't see this again. + assert not l1.daemon.is_in_log("but we don't care", + start=l1.daemon.logsearch_start) + + # Note: for this test we leave onchaind running, so we can detect + # any leaks! + + +@unittest.skipIf(not DEVELOPER, "needs DEVELOPER=1") +def test_onchaind_replay(node_factory, bitcoind): + disconnects = ['+WIRE_REVOKE_AND_ACK', 'permfail'] + options = {'watchtime-blocks': 201, 'cltv-delta': 101} + l1 = node_factory.get_node(options=options, disconnect=disconnects) + l2 = node_factory.get_node(options=options) + + l1.rpc.connect(l2.info['id'], 'localhost', l2.port) + l1.fund_channel(l2, 10**6) + + rhash = l2.rpc.invoice(10**8, 'onchaind_replay', 'desc')['payment_hash'] + routestep = { + 'msatoshi': 10**8 - 1, + 'id': l2.info['id'], + 'delay': 101, + 'channel': '1:1:1' + } + l1.rpc.sendpay([routestep], rhash) + l1.daemon.wait_for_log('sendrawtx exit 0') + bitcoind.rpc.generate(1) + + # Wait for nodes to notice the failure, this seach needle is after the + # DB commit so we're sure the tx entries in onchaindtxs have been added + l1.daemon.wait_for_log("Deleting channel .* due to the funding outpoint being spent") + l2.daemon.wait_for_log("Deleting channel .* due to the funding outpoint being spent") + + # We should at least have the init tx now + assert len(l1.db_query("SELECT * FROM channeltxs;")) > 0 + assert len(l2.db_query("SELECT * FROM channeltxs;")) > 0 + + # Generate some blocks so we restart the onchaind from DB (we rescan + # last_height - 100) + bitcoind.rpc.generate(100) + sync_blockheight(bitcoind, [l1, l2]) + + # l1 should still have a running onchaind + assert len(l1.db_query("SELECT * FROM channeltxs;")) > 0 + + l2.rpc.stop() + l1.restart() + + # Can't wait for it, it's after the "Server started" wait in restart() + assert l1.daemon.is_in_log(r'Restarting onchaind for channel') + + # l1 should still notice that the funding was spent and that we should react to it + l1.daemon.wait_for_log("Propose handling OUR_UNILATERAL/DELAYED_OUTPUT_TO_US by OUR_DELAYED_RETURN_TO_WALLET") + sync_blockheight(bitcoind, [l1]) + bitcoind.rpc.generate(10) + sync_blockheight(bitcoind, [l1]) + + +@unittest.skipIf(not DEVELOPER, "needs DEVELOPER=1") +def test_onchain_dust_out(node_factory, bitcoind, executor): + """Onchain handling of outgoing dust htlcs (they should fail)""" + # HTLC 1->2, 1 fails after it's irrevocably committed + disconnects = ['@WIRE_REVOKE_AND_ACK', 'permfail'] + l1 = node_factory.get_node(disconnect=disconnects) + l2 = node_factory.get_node() + + l1.rpc.connect(l2.info['id'], 'localhost', l2.port) + l1.fund_channel(l2, 10**6) + + # Must be dust! + rhash = l2.rpc.invoice(1, 'onchain_dust_out', 'desc')['payment_hash'] + routestep = { + 'msatoshi': 1, + 'id': l2.info['id'], + 'delay': 5, + 'channel': '1:1:1' + } + + l1.rpc.sendpay([routestep], rhash) + payfuture = executor.submit(l1.rpc.waitsendpay, rhash) + + # l1 will drop to chain. + l1.daemon.wait_for_log('permfail') + l1.daemon.wait_for_log('sendrawtx exit 0') + l1.bitcoin.generate_block(1) + l1.daemon.wait_for_log(' to ONCHAIN') + l2.daemon.wait_for_log(' to ONCHAIN') + + # We use 3 blocks for "reasonable depth" + bitcoind.generate_block(3) + + # It should fail. + with pytest.raises(RpcError): + payfuture.result(5) + + l1.daemon.wait_for_log('WIRE_PERMANENT_CHANNEL_FAILURE: missing in commitment tx') + + # Retry payment, this should fail (and, as a side-effect, tickle a + # bug). + with pytest.raises(RpcError, match=r'WIRE_UNKNOWN_NEXT_PEER'): + l1.rpc.sendpay([routestep], rhash) + + # 6 later, l1 should collect its to-self payment. + bitcoind.generate_block(6) + l1.daemon.wait_for_log('Broadcasting OUR_DELAYED_RETURN_TO_WALLET .* to resolve OUR_UNILATERAL/DELAYED_OUTPUT_TO_US') + l1.daemon.wait_for_log('sendrawtx exit 0') + + # 94 later, l2 is done. + bitcoind.generate_block(94) + l2.daemon.wait_for_log('onchaind complete, forgetting peer') + + # Restart l1, it should not crash! + l1.restart() + + # Now, 100 blocks and l1 should be done. + bitcoind.generate_block(6) + l1.daemon.wait_for_log('onchaind complete, forgetting peer') + + # Payment failed, BTW + assert only_one(l2.rpc.listinvoices('onchain_dust_out')['invoices'])['status'] == 'unpaid' + + +@unittest.skipIf(not DEVELOPER, "needs DEVELOPER=1") +def test_onchain_timeout(node_factory, bitcoind, executor): + """Onchain handling of outgoing failed htlcs""" + # HTLC 1->2, 1 fails just after it's irrevocably committed + disconnects = ['+WIRE_REVOKE_AND_ACK', 'permfail'] + l1 = node_factory.get_node(disconnect=disconnects) + l2 = node_factory.get_node() + l2 = node_factory.get_node() + + l1.rpc.connect(l2.info['id'], 'localhost', l2.port) + + l1.rpc.connect(l2.info['id'], 'localhost', l2.port) + l1.fund_channel(l2, 10**6) + + rhash = l2.rpc.invoice(10**8, 'onchain_timeout', 'desc')['payment_hash'] + # We underpay, so it fails. + routestep = { + 'msatoshi': 10**8 - 1, + 'id': l2.info['id'], + 'delay': 5, + 'channel': '1:1:1' + } + + l1.rpc.sendpay([routestep], rhash) + payfuture = executor.submit(l1.rpc.waitsendpay, rhash) + + # l1 will drop to chain. + l1.daemon.wait_for_log('permfail') + l1.daemon.wait_for_log('sendrawtx exit 0') + l1.bitcoin.generate_block(1) + l1.daemon.wait_for_log(' to ONCHAIN') + l2.daemon.wait_for_log(' to ONCHAIN') + + # Wait for timeout. + l1.daemon.wait_for_logs(['Propose handling OUR_UNILATERAL/DELAYED_OUTPUT_TO_US by OUR_DELAYED_RETURN_TO_WALLET .* after 5 blocks', + 'Propose handling OUR_UNILATERAL/OUR_HTLC by OUR_HTLC_TIMEOUT_TX .* after 6 blocks']) + bitcoind.generate_block(4) + + l1.daemon.wait_for_log('sendrawtx exit 0') + + bitcoind.generate_block(1) + l1.daemon.wait_for_log('sendrawtx exit 0') + + # We use 3 blocks for "reasonable depth" + bitcoind.generate_block(3) + + # It should fail. + with pytest.raises(RpcError): + payfuture.result(5) + + l1.daemon.wait_for_log('WIRE_PERMANENT_CHANNEL_FAILURE: timed out') + + # 2 later, l1 spends HTLC (5 blocks total). + bitcoind.generate_block(2) + l1.daemon.wait_for_log('Broadcasting OUR_DELAYED_RETURN_TO_WALLET .* to resolve OUR_HTLC_TIMEOUT_TX/DELAYED_OUTPUT_TO_US') + l1.daemon.wait_for_log('sendrawtx exit 0') + + # 89 later, l2 is done. + bitcoind.generate_block(89) + l2.daemon.wait_for_log('onchaind complete, forgetting peer') + + # Now, 100 blocks and l1 should be done. + bitcoind.generate_block(10) + sync_blockheight(bitcoind, [l1]) + assert not l1.daemon.is_in_log('onchaind complete, forgetting peer') + bitcoind.generate_block(1) + l1.daemon.wait_for_log('onchaind complete, forgetting peer') + + # Payment failed, BTW + assert only_one(l2.rpc.listinvoices('onchain_timeout')['invoices'])['status'] == 'unpaid' + + +@unittest.skipIf(not DEVELOPER, "needs DEVELOPER=1") +def test_onchain_middleman(node_factory, bitcoind): + # HTLC 1->2->3, 1->2 goes down after 2 gets preimage from 3. + disconnects = ['-WIRE_UPDATE_FULFILL_HTLC', 'permfail'] + l1 = node_factory.get_node() + l2 = node_factory.get_node(disconnect=disconnects) + l3 = node_factory.get_node() + + # l2 connects to both, so l1 can't reconnect and thus l2 drops to chain + l2.rpc.connect(l1.info['id'], 'localhost', l1.port) + l2.rpc.connect(l3.info['id'], 'localhost', l3.port) + l2.fund_channel(l1, 10**6) + c23 = l2.fund_channel(l3, 10**6) + + # Make sure routes finalized. + bitcoind.generate_block(5) + l1.wait_channel_active(c23) + + # Give l1 some money to play with. + l2.pay(l1, 2 * 10**8) + + # Must be bigger than dust! + rhash = l3.rpc.invoice(10**8, 'middleman', 'desc')['payment_hash'] + + route = l1.rpc.getroute(l3.info['id'], 10**8, 1)["route"] + assert len(route) == 2 + + q = queue.Queue() + + def try_pay(): + try: + l1.rpc.sendpay(route, rhash) + l1.rpc.waitsendpay(rhash) + q.put(None) + except Exception as err: + q.put(err) + + t = threading.Thread(target=try_pay) + t.daemon = True + t.start() + + # l2 will drop to chain. + l2.daemon.wait_for_log('sendrawtx exit 0') + l1.bitcoin.generate_block(1) + l2.daemon.wait_for_log(' to ONCHAIN') + l1.daemon.wait_for_log(' to ONCHAIN') + l2.daemon.wait_for_log('OUR_UNILATERAL/THEIR_HTLC') + + # l2 should fulfill HTLC onchain, and spend to-us (any order) + l2.daemon.wait_for_log('Propose handling OUR_UNILATERAL/THEIR_HTLC by OUR_HTLC_SUCCESS_TX .* after 0 blocks') + l2.daemon.wait_for_log('sendrawtx exit 0') + + # Payment should succeed. + l1.bitcoin.generate_block(1) + l1.daemon.wait_for_log('THEIR_UNILATERAL/OUR_HTLC gave us preimage') + err = q.get(timeout=10) + if err: + print("Got err from sendpay thread") + raise err + t.join(timeout=1) + assert not t.isAlive() + + # Three more, l2 can spend to-us. + bitcoind.generate_block(3) + l2.daemon.wait_for_logs([ + 'Broadcasting OUR_DELAYED_RETURN_TO_WALLET .* to resolve OUR_UNILATERAL/DELAYED_OUTPUT_TO_US', + 'sendrawtx exit 0' + ]) + + # One more block, HTLC tx is now spendable. + l1.bitcoin.generate_block(1) + l2.daemon.wait_for_logs([ + 'Broadcasting OUR_DELAYED_RETURN_TO_WALLET .* to resolve OUR_HTLC_SUCCESS_TX/DELAYED_OUTPUT_TO_US', + 'sendrawtx exit 0' + ]) + + # 100 blocks after last spend, l2 should be done. + l1.bitcoin.generate_block(100) + l2.daemon.wait_for_log('onchaind complete, forgetting peer') + + +@unittest.skipIf(not DEVELOPER, "needs DEVELOPER=1") +def test_onchain_feechange(node_factory, bitcoind, executor): + """Onchain handling when we restart with different fees""" + # HTLC 1->2, 2 fails just after they're both irrevocably committed + # We need 2 to drop to chain, because then 1's HTLC timeout tx + # is generated on-the-fly, and is thus feerate sensitive. + disconnects = ['-WIRE_UPDATE_FAIL_HTLC', 'permfail'] + l1 = node_factory.get_node(may_reconnect=True) + l2 = node_factory.get_node(disconnect=disconnects, + may_reconnect=True) + + l1.rpc.connect(l2.info['id'], 'localhost', l2.port) + l1.fund_channel(l2, 10**6) + + rhash = l2.rpc.invoice(10**8, 'onchain_timeout', 'desc')['payment_hash'] + # We underpay, so it fails. + routestep = { + 'msatoshi': 10**8 - 1, + 'id': l2.info['id'], + 'delay': 5, + 'channel': '1:1:1' + } + + executor.submit(l1.rpc.sendpay, [routestep], rhash) + + # l2 will drop to chain. + l2.daemon.wait_for_log('permfail') + l2.daemon.wait_for_log('sendrawtx exit 0') + bitcoind.generate_block(1) + l1.daemon.wait_for_log(' to ONCHAIN') + l2.daemon.wait_for_log(' to ONCHAIN') + + # Wait for timeout. + l1.daemon.wait_for_log('Propose handling THEIR_UNILATERAL/OUR_HTLC by OUR_HTLC_TIMEOUT_TO_US .* after 6 blocks') + bitcoind.generate_block(6) + + l1.daemon.wait_for_log('sendrawtx exit 0') + + # Make sure that gets included. + + bitcoind.generate_block(1) + # Now we restart with different feerates. + l1.stop() + + l1.daemon.cmd_line.append('--override-fee-rates=20000/9000/2000') + l1.start() + + # We recognize different proposal as ours. + l1.daemon.wait_for_log('Resolved THEIR_UNILATERAL/OUR_HTLC by our proposal OUR_HTLC_TIMEOUT_TO_US') + + # We use 3 blocks for "reasonable depth", so add two more + bitcoind.generate_block(2) + + # Note that the very similar test_onchain_timeout looks for a + # different string: that's because it sees the JSONRPC response, + # and due to the l1 restart, there is none here. + l1.daemon.wait_for_log('WIRE_PERMANENT_CHANNEL_FAILURE') + + # 90 later, l2 is done + bitcoind.generate_block(89) + sync_blockheight(bitcoind, [l2]) + assert not l2.daemon.is_in_log('onchaind complete, forgetting peer') + bitcoind.generate_block(1) + l2.daemon.wait_for_log('onchaind complete, forgetting peer') + + # Now, 7 blocks and l1 should be done. + bitcoind.generate_block(6) + sync_blockheight(bitcoind, [l1]) + assert not l1.daemon.is_in_log('onchaind complete, forgetting peer') + bitcoind.generate_block(1) + l1.daemon.wait_for_log('onchaind complete, forgetting peer') + + # Payment failed, BTW + assert only_one(l2.rpc.listinvoices('onchain_timeout')['invoices'])['status'] == 'unpaid' + + +@unittest.skipIf(not DEVELOPER, "needs DEVELOPER=1 for dev-set-fees") +def test_onchain_all_dust(node_factory, bitcoind, executor): + """Onchain handling when we reduce output to all dust""" + # HTLC 1->2, 2 fails just after they're both irrevocably committed + # We need 2 to drop to chain, because then 1's HTLC timeout tx + # is generated on-the-fly, and is thus feerate sensitive. + disconnects = ['-WIRE_UPDATE_FAIL_HTLC', 'permfail'] + l1 = node_factory.get_node(options={'dev-no-reconnect': None}) + l2 = node_factory.get_node(disconnect=disconnects) + + l1.rpc.connect(l2.info['id'], 'localhost', l2.port) + l1.fund_channel(l2, 10**6) + + rhash = l2.rpc.invoice(10**8, 'onchain_timeout', 'desc')['payment_hash'] + # We underpay, so it fails. + routestep = { + 'msatoshi': 10**7 - 1, + 'id': l2.info['id'], + 'delay': 5, + 'channel': '1:1:1' + } + + executor.submit(l1.rpc.sendpay, [routestep], rhash) + + # l2 will drop to chain. + l2.daemon.wait_for_log('permfail') + l2.daemon.wait_for_log('sendrawtx exit 0') + + # Make l1's fees really high. + l1.rpc.dev_setfees('100000', '100000', '100000') + + bitcoind.generate_block(1) + l1.daemon.wait_for_log(' to ONCHAIN') + l2.daemon.wait_for_log(' to ONCHAIN') + + # Wait for timeout. + l1.daemon.wait_for_log('Propose handling THEIR_UNILATERAL/OUR_HTLC by IGNORING_TINY_PAYMENT .* after 6 blocks') + bitcoind.generate_block(5) + + l1.daemon.wait_for_logs(['Broadcasting IGNORING_TINY_PAYMENT .* to resolve THEIR_UNILATERAL/OUR_HTLC', + 'sendrawtx exit 0', + 'Ignoring output 0 of .*: THEIR_UNILATERAL/OUR_HTLC']) + + # 100 deep and l2 forgets. + bitcoind.generate_block(93) + sync_blockheight(bitcoind, [l1, l2]) + assert not l2.daemon.is_in_log('onchaind complete, forgetting peer') + assert not l1.daemon.is_in_log('onchaind complete, forgetting peer') + bitcoind.generate_block(1) + l2.daemon.wait_for_log('onchaind complete, forgetting peer') + + # l1 does not wait for ignored payment. + l1.daemon.wait_for_log('onchaind complete, forgetting peer') + + +@unittest.skipIf(not DEVELOPER, "needs DEVELOPER=1 for dev_fail") +def test_onchain_different_fees(node_factory, bitcoind, executor): + """Onchain handling when we've had a range of fees""" + l1, l2 = node_factory.line_graph(2, fundchannel=True, fundamount=10**7) + + l2.rpc.dev_ignore_htlcs(id=l1.info['id'], ignore=True) + p1 = executor.submit(l1.pay, l2, 1000000000) + l1.daemon.wait_for_log('htlc 0: RCVD_ADD_ACK_COMMIT->SENT_ADD_ACK_REVOCATION') + + l1.rpc.dev_setfees('14000') + p2 = executor.submit(l1.pay, l2, 900000000) + l1.daemon.wait_for_log('htlc 1: RCVD_ADD_ACK_COMMIT->SENT_ADD_ACK_REVOCATION') + + l1.rpc.dev_setfees('5000') + p3 = executor.submit(l1.pay, l2, 800000000) + l1.daemon.wait_for_log('htlc 2: RCVD_ADD_ACK_COMMIT->SENT_ADD_ACK_REVOCATION') + + # Drop to chain + l1.rpc.dev_fail(l2.info['id']) + l1.daemon.wait_for_log('sendrawtx exit 0') + + bitcoind.generate_block(1) + l1.daemon.wait_for_log(' to ONCHAIN') + l2.daemon.wait_for_log(' to ONCHAIN') + + # Both sides should have correct feerate + assert l1.db_query('SELECT min_possible_feerate, max_possible_feerate FROM channels;') == [{ + 'min_possible_feerate': 5000, + 'max_possible_feerate': 14000 + }] + assert l2.db_query('SELECT min_possible_feerate, max_possible_feerate FROM channels;') == [{ + 'min_possible_feerate': 5000, + 'max_possible_feerate': 14000 + }] + + bitcoind.generate_block(5) + # Three HTLCs, and one for the to-us output. + l1.daemon.wait_for_logs(['sendrawtx exit 0'] * 4) + + # We use 3 blocks for "reasonable depth" + bitcoind.generate_block(3) + + with pytest.raises(Exception): + p1.result(10) + with pytest.raises(Exception): + p2.result(10) + with pytest.raises(Exception): + p3.result(10) + + # Two more for HTLC timeout tx to be spent. + bitcoind.generate_block(2) + l1.daemon.wait_for_logs(['sendrawtx exit 0'] * 3) + + # Now, 100 blocks it should be done. + bitcoind.generate_block(100) + wait_for(lambda: l1.rpc.listpeers()['peers'] == []) + wait_for(lambda: l2.rpc.listpeers()['peers'] == []) + + +@unittest.skipIf(not DEVELOPER, "needs DEVELOPER=1") +def test_permfail_new_commit(node_factory, bitcoind, executor): + # Test case where we have two possible commits: it will use new one. + disconnects = ['-WIRE_REVOKE_AND_ACK', 'permfail'] + l1 = node_factory.get_node(options={'dev-no-reconnect': None}) + l2 = node_factory.get_node(disconnect=disconnects) + + l1.rpc.connect(l2.info['id'], 'localhost', l2.port) + l1.fund_channel(l2, 10**6) + + # This will fail at l2's end. + t = executor.submit(l1.pay, l2, 200000000) + + l2.daemon.wait_for_log('dev_disconnect permfail') + l2.daemon.wait_for_log('sendrawtx exit 0') + bitcoind.generate_block(1) + l1.daemon.wait_for_log('Their unilateral tx, new commit point') + l1.daemon.wait_for_log(' to ONCHAIN') + l2.daemon.wait_for_log(' to ONCHAIN') + l2.daemon.wait_for_log('Propose handling OUR_UNILATERAL/THEIR_HTLC by THEIR_HTLC_TIMEOUT_TO_THEM \\(IGNORING\\) after 6 blocks') + l1.daemon.wait_for_log('Propose handling THEIR_UNILATERAL/OUR_HTLC by OUR_HTLC_TIMEOUT_TO_US (.*) after 6 blocks') + + # OK, time out HTLC. + bitcoind.generate_block(5) + l1.daemon.wait_for_log('sendrawtx exit 0') + bitcoind.generate_block(1) + l1.daemon.wait_for_log('Resolved THEIR_UNILATERAL/OUR_HTLC by our proposal OUR_HTLC_TIMEOUT_TO_US') + l2.daemon.wait_for_log('Ignoring output.*: OUR_UNILATERAL/THEIR_HTLC') + + t.cancel() + + # Now, 100 blocks it should be done. + bitcoind.generate_block(100) + wait_for(lambda: l1.rpc.listpeers()['peers'] == []) + wait_for(lambda: l2.rpc.listpeers()['peers'] == []) + + +@unittest.skipIf(not DEVELOPER, "needs DEVELOPER=1") +def test_permfail_htlc_in(node_factory, bitcoind, executor): + # Test case where we fail with unsettled incoming HTLC. + disconnects = ['-WIRE_UPDATE_FULFILL_HTLC', 'permfail'] + l1 = node_factory.get_node(options={'dev-no-reconnect': None}) + l2 = node_factory.get_node(disconnect=disconnects) + + l1.rpc.connect(l2.info['id'], 'localhost', l2.port) + l1.fund_channel(l2, 10**6) + + # This will fail at l2's end. + t = executor.submit(l1.pay, l2, 200000000) + + l2.daemon.wait_for_log('dev_disconnect permfail') + l2.daemon.wait_for_log('sendrawtx exit 0') + bitcoind.generate_block(1) + l1.daemon.wait_for_log('Their unilateral tx, old commit point') + l1.daemon.wait_for_log(' to ONCHAIN') + l2.daemon.wait_for_log(' to ONCHAIN') + l2.daemon.wait_for_log('Propose handling OUR_UNILATERAL/THEIR_HTLC by THEIR_HTLC_TIMEOUT_TO_THEM \\(IGNORING\\) after 6 blocks') + l1.daemon.wait_for_log('Propose handling THEIR_UNILATERAL/OUR_HTLC by OUR_HTLC_TIMEOUT_TO_US (.*) after 6 blocks') + # l2 then gets preimage, uses it instead of ignoring + l2.daemon.wait_for_log('Propose handling OUR_UNILATERAL/THEIR_HTLC by OUR_HTLC_SUCCESS_TX .* after 0 blocks') + l2.daemon.wait_for_log('sendrawtx exit 0') + bitcoind.generate_block(1) + + # OK, l1 sees l2 fulfill htlc. + l1.daemon.wait_for_log('THEIR_UNILATERAL/OUR_HTLC gave us preimage') + l2.daemon.wait_for_log('Propose handling OUR_HTLC_SUCCESS_TX/DELAYED_OUTPUT_TO_US by OUR_DELAYED_RETURN_TO_WALLET .* after 5 blocks') + bitcoind.generate_block(6) + + l2.daemon.wait_for_log('sendrawtx exit 0') + + t.cancel() + + # Now, 100 blocks it should be done. + bitcoind.generate_block(95) + l1.daemon.wait_for_log('onchaind complete, forgetting peer') + assert not l2.daemon.is_in_log('onchaind complete, forgetting peer') + bitcoind.generate_block(5) + l2.daemon.wait_for_log('onchaind complete, forgetting peer') + + +@unittest.skipIf(not DEVELOPER, "needs DEVELOPER=1") +def test_permfail_htlc_out(node_factory, bitcoind, executor): + # Test case where we fail with unsettled outgoing HTLC. + disconnects = ['+WIRE_REVOKE_AND_ACK', 'permfail'] + l1 = node_factory.get_node(options={'dev-no-reconnect': None}) + l2 = node_factory.get_node(disconnect=disconnects) + + l1.rpc.connect(l2.info['id'], 'localhost', l2.port) + l2.fund_channel(l1, 10**6) + + # This will fail at l2's end. + t = executor.submit(l2.pay, l1, 200000000) + + l2.daemon.wait_for_log('dev_disconnect permfail') + l2.daemon.wait_for_log('sendrawtx exit 0') + bitcoind.generate_block(1) + l1.daemon.wait_for_log('Their unilateral tx, old commit point') + l1.daemon.wait_for_log(' to ONCHAIN') + l2.daemon.wait_for_log(' to ONCHAIN') + l2.daemon.wait_for_logs([ + 'Propose handling OUR_UNILATERAL/OUR_HTLC by OUR_HTLC_TIMEOUT_TX \\(.*\\) after 6 blocks', + 'Propose handling OUR_UNILATERAL/DELAYED_OUTPUT_TO_US by OUR_DELAYED_RETURN_TO_WALLET .* after 5 blocks' + ]) + + l1.daemon.wait_for_log('Propose handling THEIR_UNILATERAL/THEIR_HTLC by THEIR_HTLC_TIMEOUT_TO_THEM \\(IGNORING\\) after 6 blocks') + # l1 then gets preimage, uses it instead of ignoring + l1.daemon.wait_for_log('Propose handling THEIR_UNILATERAL/THEIR_HTLC by THEIR_HTLC_FULFILL_TO_US .* after 0 blocks') + l1.daemon.wait_for_log('sendrawtx exit 0') + + # l2 sees l1 fulfill tx. + bitcoind.generate_block(1) + + l2.daemon.wait_for_log('OUR_UNILATERAL/OUR_HTLC gave us preimage') + t.cancel() + + # l2 can send OUR_DELAYED_RETURN_TO_WALLET after 3 more blocks. + bitcoind.generate_block(3) + l2.daemon.wait_for_log('Broadcasting OUR_DELAYED_RETURN_TO_WALLET .* to resolve OUR_UNILATERAL/DELAYED_OUTPUT_TO_US') + l2.daemon.wait_for_log('sendrawtx exit 0') + + # Now, 100 blocks they should be done. + bitcoind.generate_block(95) + sync_blockheight(bitcoind, [l1, l2]) + assert not l1.daemon.is_in_log('onchaind complete, forgetting peer') + assert not l2.daemon.is_in_log('onchaind complete, forgetting peer') + bitcoind.generate_block(1) + l1.daemon.wait_for_log('onchaind complete, forgetting peer') + sync_blockheight(bitcoind, [l2]) + assert not l2.daemon.is_in_log('onchaind complete, forgetting peer') + bitcoind.generate_block(3) + sync_blockheight(bitcoind, [l2]) + assert not l2.daemon.is_in_log('onchaind complete, forgetting peer') + bitcoind.generate_block(1) + wait_for(lambda: l2.rpc.listpeers()['peers'] == []) + + +@unittest.skipIf(not DEVELOPER, "needs DEVELOPER=1") +def test_permfail(node_factory, bitcoind): + l1, l2 = node_factory.line_graph(2) + + # The funding change should be confirmed and our only output + assert [o['status'] for o in l1.rpc.listfunds()['outputs']] == ['confirmed'] + l1.pay(l2, 200000000) + + # Make sure l2 has received sig with 0 htlcs! + l2.daemon.wait_for_log('Received commit_sig with 0 htlc sigs') + + # Make sure l1 has final revocation. + l1.daemon.wait_for_log('Sending commit_sig with 0 htlc sigs') + l1.daemon.wait_for_log('peer_in WIRE_REVOKE_AND_ACK') + + # We fail l2, so l1 will reconnect to it. + l2.rpc.dev_fail(l1.info['id']) + l2.daemon.wait_for_log('Failing due to dev-fail command') + l2.daemon.wait_for_log('sendrawtx exit 0') + + assert l1.bitcoin.rpc.getmempoolinfo()['size'] == 1 + + # Now grab the close transaction + closetxid = only_one(l1.bitcoin.rpc.getrawmempool(False)) + + # l2 will send out tx (l1 considers it a transient error) + bitcoind.generate_block(1) + + l1.daemon.wait_for_log('Their unilateral tx, old commit point') + l1.daemon.wait_for_log(' to ONCHAIN') + l2.daemon.wait_for_log(' to ONCHAIN') + l2.daemon.wait_for_log('Propose handling OUR_UNILATERAL/DELAYED_OUTPUT_TO_US by OUR_DELAYED_RETURN_TO_WALLET (.*) after 5 blocks') + + wait_for(lambda: only_one(l1.rpc.listpeers(l2.info['id'])['peers'][0]['channels'])['status'] == + ['ONCHAIN:Tracking their unilateral close', + 'ONCHAIN:All outputs resolved: waiting 99 more blocks before forgetting channel']) + + def check_billboard(): + billboard = only_one(l2.rpc.listpeers(l1.info['id'])['peers'][0]['channels'])['status'] + return ( + len(billboard) == 2 and + billboard[0] == 'ONCHAIN:Tracking our own unilateral close' and + re.fullmatch('ONCHAIN:.* outputs unresolved: in 4 blocks will spend DELAYED_OUTPUT_TO_US \(.*:0\) using OUR_DELAYED_RETURN_TO_WALLET', billboard[1]) + ) + wait_for(check_billboard) + + # Now, mine 4 blocks so it sends out the spending tx. + bitcoind.generate_block(4) + + # It should send the to-wallet tx. + l2.daemon.wait_for_log('Broadcasting OUR_DELAYED_RETURN_TO_WALLET') + l2.daemon.wait_for_log('sendrawtx exit 0') + + # 100 after l1 sees tx, it should be done. + bitcoind.generate_block(95) + wait_for(lambda: l1.rpc.listpeers()['peers'] == []) + + wait_for(lambda: only_one(l2.rpc.listpeers(l1.info['id'])['peers'][0]['channels'])['status'] == [ + 'ONCHAIN:Tracking our own unilateral close', + 'ONCHAIN:All outputs resolved: waiting 5 more blocks before forgetting channel' + ]) + + # Now, 100 blocks l2 should be done. + bitcoind.generate_block(5) + wait_for(lambda: l2.rpc.listpeers()['peers'] == []) + + # Only l1 has a direct output since all of l2's outputs are respent (it + # failed). Also the output should now be listed as confirmed since we + # generated some more blocks. + assert (closetxid, "confirmed") in set([(o['txid'], o['status']) for o in l1.rpc.listfunds()['outputs']]) + + addr = l1.bitcoin.rpc.getnewaddress() + l1.rpc.withdraw(addr, "all") + + +@unittest.skipIf(not DEVELOPER, "needs DEVELOPER=1") +def test_shutdown(node_factory): + # Fail, in that it will exit before cleanup. + l1 = node_factory.get_node(may_fail=True) + if not VALGRIND: + leaks = l1.rpc.dev_memleak()['leaks'] + if len(leaks): + raise Exception("Node {} has memory leaks: {}" + .format(l1.daemon.lightning_dir, leaks)) + l1.rpc.stop() diff --git a/tests/test_lightningd.py b/tests/test_lightningd.py index 9d1d2cd62..c1dcc6bcc 100644 --- a/tests/test_lightningd.py +++ b/tests/test_lightningd.py @@ -263,17 +263,6 @@ class LightningDTests(BaseLightningDTests): def fake_bitcoind_unfail(self, l1): os.remove(os.path.join(l1.daemon.lightning_dir, "bitcoin-cli-fail")) - @unittest.skipIf(not DEVELOPER, "needs DEVELOPER=1") - def test_shutdown(self): - # Fail, in that it will exit before cleanup. - l1 = self.node_factory.get_node(may_fail=True) - if not VALGRIND: - leaks = l1.rpc.dev_memleak()['leaks'] - if len(leaks): - raise Exception("Node {} has memory leaks: {}" - .format(l1.daemon.lightning_dir, leaks)) - l1.rpc.stop() - def test_features(self): l1, l2 = self.connect() @@ -410,103 +399,6 @@ class LightningDTests(BaseLightningDTests): l2.daemon.wait_for_log('to_self_delay 100 larger than 99') - @unittest.skipIf(not DEVELOPER, "Too slow without --dev-bitcoind-poll") - def test_closing(self): - l1, l2 = self.connect() - - chan = self.fund_channel(l1, l2, 10**6) - self.pay(l1, l2, 200000000) - - assert l1.bitcoin.rpc.getmempoolinfo()['size'] == 0 - - billboard = only_one(l1.rpc.listpeers(l2.info['id'])['peers'][0]['channels'])['status'] - assert billboard == ['CHANNELD_NORMAL:Funding transaction locked.'] - billboard = only_one(l2.rpc.listpeers(l1.info['id'])['peers'][0]['channels'])['status'] - assert billboard == ['CHANNELD_NORMAL:Funding transaction locked.'] - - l1.bitcoin.rpc.generate(5) - - # Only wait for the channels to activate with DEVELOPER=1, - # otherwise it's going to take too long because of the missing - # --dev-broadcast-interval - if DEVELOPER: - wait_for(lambda: len(l1.getactivechannels()) == 2) - wait_for(lambda: len(l2.getactivechannels()) == 2) - billboard = only_one(l1.rpc.listpeers(l2.info['id'])['peers'][0]['channels'])['status'] - # This may either be from a local_update or an announce, so just - # check for the substring - assert 'CHANNELD_NORMAL:Funding transaction locked.' in billboard[0] - - # This should return with an error, then close. - self.assertRaisesRegex(RpcError, - "Channel close negotiation not finished", - l1.rpc.close, chan, False, 0) - l1.daemon.wait_for_log(' to CHANNELD_SHUTTING_DOWN') - l2.daemon.wait_for_log(' to CHANNELD_SHUTTING_DOWN') - - l1.daemon.wait_for_log(' to CLOSINGD_SIGEXCHANGE') - l2.daemon.wait_for_log(' to CLOSINGD_SIGEXCHANGE') - - # And should put closing into mempool. - l1.daemon.wait_for_log('sendrawtx exit 0') - l2.daemon.wait_for_log('sendrawtx exit 0') - - # Both nodes should have disabled the channel in their view - wait_for(lambda: len(l1.getactivechannels()) == 0) - wait_for(lambda: len(l2.getactivechannels()) == 0) - - assert l1.bitcoin.rpc.getmempoolinfo()['size'] == 1 - - # Now grab the close transaction - closetxid = only_one(l1.bitcoin.rpc.getrawmempool(False)) - - billboard = only_one(l1.rpc.listpeers(l2.info['id'])['peers'][0]['channels'])['status'] - assert billboard == ['CLOSINGD_SIGEXCHANGE:We agreed on a closing fee of 5430 satoshi'] - l1.bitcoin.rpc.generate(1) - - l1.daemon.wait_for_log(r'Owning output .* txid %s' % closetxid) - l2.daemon.wait_for_log(r'Owning output .* txid %s' % closetxid) - - # Make sure both nodes have grabbed their close tx funds - assert closetxid in set([o['txid'] for o in l1.rpc.listfunds()['outputs']]) - assert closetxid in set([o['txid'] for o in l2.rpc.listfunds()['outputs']]) - - wait_for(lambda: only_one(l1.rpc.listpeers(l2.info['id'])['peers'][0]['channels'])['status'] == ['CLOSINGD_SIGEXCHANGE:We agreed on a closing fee of 5430 satoshi', 'ONCHAIN:Tracking mutual close transaction', 'ONCHAIN:All outputs resolved: waiting 99 more blocks before forgetting channel']) - - l1.bitcoin.rpc.generate(9) - wait_for(lambda: only_one(l1.rpc.listpeers(l2.info['id'])['peers'][0]['channels'])['status'] == ['CLOSINGD_SIGEXCHANGE:We agreed on a closing fee of 5430 satoshi', 'ONCHAIN:Tracking mutual close transaction', 'ONCHAIN:All outputs resolved: waiting 90 more blocks before forgetting channel']) - - # Make sure both have forgotten about it - l1.bitcoin.rpc.generate(90) - wait_forget_channels(l1) - wait_forget_channels(l2) - - def test_closing_while_disconnected(self): - l1, l2 = self.connect(may_reconnect=True) - - chan = self.fund_channel(l1, l2, 10**6) - self.pay(l1, l2, 200000000) - - l2.stop() - - # The close should still be triggered afterwards. - self.assertRaisesRegex(RpcError, - "Channel close negotiation not finished", - l1.rpc.close, chan, False, 0) - l1.daemon.wait_for_log(' to CHANNELD_SHUTTING_DOWN') - - l2.start() - l1.daemon.wait_for_log(' to CLOSINGD_SIGEXCHANGE') - l2.daemon.wait_for_log(' to CLOSINGD_SIGEXCHANGE') - - # And should put closing into mempool. - l1.daemon.wait_for_log('sendrawtx exit 0') - l2.daemon.wait_for_log('sendrawtx exit 0') - - bitcoind.rpc.generate(101) - wait_forget_channels(l1) - wait_forget_channels(l2) - def test_db_upgrade(self): l1 = self.node_factory.get_node() l1.stop() @@ -551,977 +443,6 @@ class LightningDTests(BaseLightningDTests): bitcoind.generate_block(5) sync_blockheight([l1]) - @unittest.skipIf(not DEVELOPER, "needs dev-rescan-outputs") - def test_closing_torture(self): - l1 = self.node_factory.get_node() - l2 = self.node_factory.get_node() - - amount = 10**6 - self.give_funds(l1, amount + 10**7) - - # The range below of 15 is unsatisfactory. - # Before the fix was applied, 15 would often pass. - # However, increasing the number of tries would - # take longer in VALGRIND mode, triggering a CI - # failure since the test does not print any - # output. - for i in range(15): - # Reduce probability that spurious sendrawtx error will occur - l1.rpc.dev_rescan_outputs() - - # Create a channel. - l1.rpc.connect(l2.info['id'], 'localhost', l2.port) - l1.rpc.fundchannel(l2.info['id'], amount) - l1.daemon.wait_for_log('sendrawtx exit 0') - # Get it confirmed. - l1.bitcoin.generate_block(6) - # Wait for it to go to CHANNELD_NORMAL - l1.daemon.wait_for_logs(['to CHANNELD_NORMAL']) - l2.daemon.wait_for_logs(['to CHANNELD_NORMAL']) - - # Start closers: can take a long time under valgrind! - c1 = self.executor.submit(l1.rpc.close, l2.info['id'], False, 60) - c2 = self.executor.submit(l2.rpc.close, l1.info['id'], False, 60) - # Wait for close to finish - c1.result(utils.TIMEOUT) - c2.result(utils.TIMEOUT) - l1.daemon.wait_for_log('sendrawtx exit 0') - # Get close confirmed - l1.bitcoin.generate_block(100) - - @flaky - @unittest.skipIf(not DEVELOPER, "needs dev-override-feerates") - def test_closing_different_fees(self): - l1 = self.node_factory.get_node() - - # Default feerate = 15000/7500/1000 - # It will start at the second number, accepting anything above the first. - feerates = [[20000, 15000, 7400], [8000, 1001, 100]] - amounts = [0, 545999, 546000] - num_peers = len(feerates) * len(amounts) - self.give_funds(l1, (10**6) * num_peers + 10000 * num_peers) - - # Create them in a batch, for speed! - peers = [] - for feerate in feerates: - for amount in amounts: - p = self.node_factory.get_node(options={ - 'dev-override-fee-rates': '{}/{}/{}'.format(feerate[0], - feerate[1], - feerate[2]) - }) - p.feerate = feerate - p.amount = amount - l1.rpc.connect(p.info['id'], 'localhost', p.port) - peers.append(p) - - for p in peers: - p.channel = l1.rpc.fundchannel(p.info['id'], 10**6)['channel_id'] - # Technically, this is async to fundchannel returning. - l1.daemon.wait_for_log('sendrawtx exit 0') - - bitcoind.generate_block(6) - - # Now wait for them all to hit normal state, do payments - l1.daemon.wait_for_logs(['update for channel .* now ACTIVE'] * num_peers + - ['to CHANNELD_NORMAL'] * num_peers) - for p in peers: - if p.amount != 0: - self.pay(l1, p, 100000000) - - # Now close all channels - # All closes occur in parallel, and on Travis, - # ALL those lightningd are running on a single core, - # so increase the timeout so that this test will pass - # when valgrind is enabled. - # (close timeout defaults to 30 as of this writing) - closes = [self.executor.submit(l1.rpc.close, p.channel, False, 90) for p in peers] - - for c in closes: - c.result(90) - - # close does *not* wait for the sendrawtransaction, so do that! - # Note that since they disagree on the ideal fee, they may conflict - # (first one in will win), so we cannot look at logs, we need to - # wait for mempool. - wait_for(lambda: bitcoind.rpc.getmempoolinfo()['size'] == num_peers) - - bitcoind.generate_block(1) - for p in peers: - p.daemon.wait_for_log(' to ONCHAIN') - wait_for(lambda: only_one(p.rpc.listpeers(l1.info['id'])['peers'][0]['channels'])['status'][1] == 'ONCHAIN:Tracking mutual close transaction') - l1.daemon.wait_for_logs([' to ONCHAIN'] * num_peers) - - @unittest.skipIf(not DEVELOPER, "needs DEVELOPER=1") - def test_permfail(self): - l1, l2 = self.connect() - - self.fund_channel(l1, l2, 10**6) - - # The funding change should be confirmed and our only output - assert [o['status'] for o in l1.rpc.listfunds()['outputs']] == ['confirmed'] - self.pay(l1, l2, 200000000) - - # Make sure l2 has received sig with 0 htlcs! - l2.daemon.wait_for_log('Received commit_sig with 0 htlc sigs') - - # Make sure l1 has final revocation. - l1.daemon.wait_for_log('Sending commit_sig with 0 htlc sigs') - l1.daemon.wait_for_log('peer_in WIRE_REVOKE_AND_ACK') - - # We fail l2, so l1 will reconnect to it. - l2.rpc.dev_fail(l1.info['id']) - l2.daemon.wait_for_log('Failing due to dev-fail command') - l2.daemon.wait_for_log('sendrawtx exit 0') - - assert l1.bitcoin.rpc.getmempoolinfo()['size'] == 1 - - # Now grab the close transaction - closetxid = only_one(l1.bitcoin.rpc.getrawmempool(False)) - - # l2 will send out tx (l1 considers it a transient error) - bitcoind.generate_block(1) - - l1.daemon.wait_for_log('Their unilateral tx, old commit point') - l1.daemon.wait_for_log(' to ONCHAIN') - l2.daemon.wait_for_log(' to ONCHAIN') - l2.daemon.wait_for_log('Propose handling OUR_UNILATERAL/DELAYED_OUTPUT_TO_US by OUR_DELAYED_RETURN_TO_WALLET (.*) after 5 blocks') - - wait_for(lambda: only_one(l1.rpc.listpeers(l2.info['id'])['peers'][0]['channels'])['status'] == - ['ONCHAIN:Tracking their unilateral close', - 'ONCHAIN:All outputs resolved: waiting 99 more blocks before forgetting channel']) - - def check_billboard(): - billboard = only_one(l2.rpc.listpeers(l1.info['id'])['peers'][0]['channels'])['status'] - return ( - len(billboard) == 2 and - billboard[0] == 'ONCHAIN:Tracking our own unilateral close' and - re.fullmatch('ONCHAIN:.* outputs unresolved: in 4 blocks will spend DELAYED_OUTPUT_TO_US \(.*:0\) using OUR_DELAYED_RETURN_TO_WALLET', billboard[1]) - ) - wait_for(check_billboard) - - # Now, mine 4 blocks so it sends out the spending tx. - bitcoind.generate_block(4) - - # It should send the to-wallet tx. - l2.daemon.wait_for_log('Broadcasting OUR_DELAYED_RETURN_TO_WALLET') - l2.daemon.wait_for_log('sendrawtx exit 0') - - # 100 after l1 sees tx, it should be done. - bitcoind.generate_block(95) - wait_forget_channels(l1) - - wait_for(lambda: only_one(l2.rpc.listpeers(l1.info['id'])['peers'][0]['channels'])['status'] == ['ONCHAIN:Tracking our own unilateral close', 'ONCHAIN:All outputs resolved: waiting 5 more blocks before forgetting channel']) - - # Now, 100 blocks l2 should be done. - bitcoind.generate_block(5) - wait_forget_channels(l2) - - # Only l1 has a direct output since all of l2's outputs are respent (it - # failed). Also the output should now be listed as confirmed since we - # generated some more blocks. - assert (closetxid, "confirmed") in set([(o['txid'], o['status']) for o in l1.rpc.listfunds()['outputs']]) - - addr = l1.bitcoin.rpc.getnewaddress() - l1.rpc.withdraw(addr, "all") - - @unittest.skipIf(not DEVELOPER, "needs DEVELOPER=1") - def test_onchain_first_commit(self): - """Onchain handling where funder immediately drops to chain""" - - # HTLC 1->2, 1 fails just after funding. - disconnects = ['+WIRE_FUNDING_LOCKED', 'permfail'] - l1 = self.node_factory.get_node(disconnect=disconnects) - # Make locktime different, as we once had them reversed! - l2 = self.node_factory.get_node(options={'watchtime-blocks': 10}) - - l1.rpc.connect(l2.info['id'], 'localhost', l2.port) - - self.give_funds(l1, 10**6 + 1000000) - - l1.rpc.fundchannel(l2.info['id'], 10**6) - l1.daemon.wait_for_log('sendrawtx exit 0') - - l1.bitcoin.generate_block(1) - - # l1 will drop to chain. - l1.daemon.wait_for_log('permfail') - l1.daemon.wait_for_log('sendrawtx exit 0') - l1.bitcoin.generate_block(1) - l1.daemon.wait_for_log(' to ONCHAIN') - l2.daemon.wait_for_log(' to ONCHAIN') - - # 10 later, l1 should collect its to-self payment. - bitcoind.generate_block(10) - l1.daemon.wait_for_log('Broadcasting OUR_DELAYED_RETURN_TO_WALLET .* to resolve OUR_UNILATERAL/DELAYED_OUTPUT_TO_US') - l1.daemon.wait_for_log('sendrawtx exit 0') - - # 94 later, l2 is done. - bitcoind.generate_block(94) - l2.daemon.wait_for_log('onchaind complete, forgetting peer') - - # Now, 100 blocks and l1 should be done. - bitcoind.generate_block(6) - l1.daemon.wait_for_log('onchaind complete, forgetting peer') - - @unittest.skipIf(not DEVELOPER, "needs DEVELOPER=1") - def test_onchain_unwatch(self): - """Onchaind should not watch random spends""" - l1, l2 = self.connect() - - self.fund_channel(l1, l2, 10**6) - self.pay(l1, l2, 200000000) - - l1.rpc.dev_fail(l2.info['id']) - l1.daemon.wait_for_log('Failing due to dev-fail command') - l1.daemon.wait_for_log('sendrawtx exit 0') - - l1.bitcoin.generate_block(1) - l1.daemon.wait_for_log(' to ONCHAIN') - l2.daemon.wait_for_log(' to ONCHAIN') - - # 10 later, l1 should collect its to-self payment. - bitcoind.generate_block(10) - l1.daemon.wait_for_log('Broadcasting OUR_DELAYED_RETURN_TO_WALLET .* to resolve ' - 'OUR_UNILATERAL/DELAYED_OUTPUT_TO_US') - l1.daemon.wait_for_log('sendrawtx exit 0') - - # First time it sees it, onchaind cares. - bitcoind.generate_block(1) - l1.daemon.wait_for_log('Resolved OUR_UNILATERAL/DELAYED_OUTPUT_TO_US by our proposal ' - 'OUR_DELAYED_RETURN_TO_WALLET') - - # Now test unrelated onchain churn. - # Daemon gets told about wallet; says it doesn't care. - l1.rpc.withdraw(l1.rpc.newaddr()['address'], 'all') - bitcoind.generate_block(1) - l1.daemon.wait_for_log("but we don't care") - - # And lightningd should respect that! - assert not l1.daemon.is_in_log("Can't unwatch txid") - - # So these should not generate further messages - for i in range(5): - l1.rpc.withdraw(l1.rpc.newaddr()['address'], 'all') - bitcoind.generate_block(1) - # Make sure it digests the block - sync_blockheight([l1]) - - # We won't see this again. - assert not l1.daemon.is_in_log("but we don't care", - start=l1.daemon.logsearch_start) - - # Note: for this test we leave onchaind running, so we can detect - # any leaks! - - @unittest.skipIf(not DEVELOPER, "needs DEVELOPER=1") - def test_onchaind_replay(self): - disconnects = ['+WIRE_REVOKE_AND_ACK', 'permfail'] - options = {'watchtime-blocks': 201, 'cltv-delta': 101} - l1 = self.node_factory.get_node(options=options, disconnect=disconnects) - l2 = self.node_factory.get_node(options=options) - - l1.rpc.connect(l2.info['id'], 'localhost', l2.port) - self.fund_channel(l1, l2, 10**6) - - rhash = l2.rpc.invoice(10**8, 'onchaind_replay', 'desc')['payment_hash'] - routestep = { - 'msatoshi': 10**8 - 1, - 'id': l2.info['id'], - 'delay': 101, - 'channel': '1:1:1' - } - l1.rpc.sendpay(to_json([routestep]), rhash) - l1.daemon.wait_for_log('sendrawtx exit 0') - bitcoind.rpc.generate(1) - - # Wait for nodes to notice the failure, this seach needle is after the - # DB commit so we're sure the tx entries in onchaindtxs have been added - l1.daemon.wait_for_log("Deleting channel .* due to the funding outpoint being spent") - l2.daemon.wait_for_log("Deleting channel .* due to the funding outpoint being spent") - - # We should at least have the init tx now - assert len(l1.db_query("SELECT * FROM channeltxs;")) > 0 - assert len(l2.db_query("SELECT * FROM channeltxs;")) > 0 - - # Generate some blocks so we restart the onchaind from DB (we rescan - # last_height - 100) - bitcoind.rpc.generate(100) - sync_blockheight([l1, l2]) - - # l1 should still have a running onchaind - assert len(l1.db_query("SELECT * FROM channeltxs;")) > 0 - - l2.rpc.stop() - l1.restart() - - # Can't wait for it, it's after the "Server started" wait in restart() - assert l1.daemon.is_in_log(r'Restarting onchaind for channel') - - # l1 should still notice that the funding was spent and that we should react to it - l1.daemon.wait_for_log("Propose handling OUR_UNILATERAL/DELAYED_OUTPUT_TO_US by OUR_DELAYED_RETURN_TO_WALLET") - sync_blockheight([l1]) - bitcoind.rpc.generate(10) - sync_blockheight([l1]) - - @unittest.skipIf(not DEVELOPER, "needs DEVELOPER=1") - def test_onchain_dust_out(self): - """Onchain handling of outgoing dust htlcs (they should fail)""" - # HTLC 1->2, 1 fails after it's irrevocably committed - disconnects = ['@WIRE_REVOKE_AND_ACK', 'permfail'] - l1 = self.node_factory.get_node(disconnect=disconnects) - l2 = self.node_factory.get_node() - - l1.rpc.connect(l2.info['id'], 'localhost', l2.port) - self.fund_channel(l1, l2, 10**6) - - # Must be dust! - rhash = l2.rpc.invoice(1, 'onchain_dust_out', 'desc')['payment_hash'] - routestep = { - 'msatoshi': 1, - 'id': l2.info['id'], - 'delay': 5, - 'channel': '1:1:1' - } - - l1.rpc.sendpay(to_json([routestep]), rhash) - payfuture = self.executor.submit(l1.rpc.waitsendpay, rhash) - - # l1 will drop to chain. - l1.daemon.wait_for_log('permfail') - l1.daemon.wait_for_log('sendrawtx exit 0') - l1.bitcoin.generate_block(1) - l1.daemon.wait_for_log(' to ONCHAIN') - l2.daemon.wait_for_log(' to ONCHAIN') - - # We use 3 blocks for "reasonable depth" - bitcoind.generate_block(3) - - # It should fail. - self.assertRaises(RpcError, payfuture.result, 5) - - l1.daemon.wait_for_log('WIRE_PERMANENT_CHANNEL_FAILURE: missing in commitment tx') - - # Retry payment, this should fail (and, as a side-effect, tickle a - # bug). - self.assertRaisesRegex(RpcError, 'WIRE_UNKNOWN_NEXT_PEER', - l1.rpc.sendpay, to_json([routestep]), rhash) - - # 6 later, l1 should collect its to-self payment. - bitcoind.generate_block(6) - l1.daemon.wait_for_log('Broadcasting OUR_DELAYED_RETURN_TO_WALLET .* to resolve OUR_UNILATERAL/DELAYED_OUTPUT_TO_US') - l1.daemon.wait_for_log('sendrawtx exit 0') - - # 94 later, l2 is done. - bitcoind.generate_block(94) - l2.daemon.wait_for_log('onchaind complete, forgetting peer') - - # Restart l1, it should not crash! - l1.restart() - - # Now, 100 blocks and l1 should be done. - bitcoind.generate_block(6) - l1.daemon.wait_for_log('onchaind complete, forgetting peer') - - # Payment failed, BTW - assert only_one(l2.rpc.listinvoices('onchain_dust_out')['invoices'])['status'] == 'unpaid' - - @unittest.skipIf(not DEVELOPER, "needs DEVELOPER=1") - def test_onchain_timeout(self): - """Onchain handling of outgoing failed htlcs""" - # HTLC 1->2, 1 fails just after it's irrevocably committed - disconnects = ['+WIRE_REVOKE_AND_ACK', 'permfail'] - l1 = self.node_factory.get_node(disconnect=disconnects) - l2 = self.node_factory.get_node() - - l1.rpc.connect(l2.info['id'], 'localhost', l2.port) - l2 = self.node_factory.get_node() - - l1.rpc.connect(l2.info['id'], 'localhost', l2.port) - self.fund_channel(l1, l2, 10**6) - - rhash = l2.rpc.invoice(10**8, 'onchain_timeout', 'desc')['payment_hash'] - # We underpay, so it fails. - routestep = { - 'msatoshi': 10**8 - 1, - 'id': l2.info['id'], - 'delay': 5, - 'channel': '1:1:1' - } - - l1.rpc.sendpay(to_json([routestep]), rhash) - payfuture = self.executor.submit(l1.rpc.waitsendpay, rhash) - - # l1 will drop to chain. - l1.daemon.wait_for_log('permfail') - l1.daemon.wait_for_log('sendrawtx exit 0') - l1.bitcoin.generate_block(1) - l1.daemon.wait_for_log(' to ONCHAIN') - l2.daemon.wait_for_log(' to ONCHAIN') - - # Wait for timeout. - l1.daemon.wait_for_logs(['Propose handling OUR_UNILATERAL/DELAYED_OUTPUT_TO_US by OUR_DELAYED_RETURN_TO_WALLET .* after 5 blocks', - 'Propose handling OUR_UNILATERAL/OUR_HTLC by OUR_HTLC_TIMEOUT_TX .* after 6 blocks']) - bitcoind.generate_block(4) - - l1.daemon.wait_for_log('sendrawtx exit 0') - - bitcoind.generate_block(1) - l1.daemon.wait_for_log('sendrawtx exit 0') - - # We use 3 blocks for "reasonable depth" - bitcoind.generate_block(3) - - # It should fail. - self.assertRaises(RpcError, payfuture.result, 5) - - l1.daemon.wait_for_log('WIRE_PERMANENT_CHANNEL_FAILURE: timed out') - - # 2 later, l1 spends HTLC (5 blocks total). - bitcoind.generate_block(2) - l1.daemon.wait_for_log('Broadcasting OUR_DELAYED_RETURN_TO_WALLET .* to resolve OUR_HTLC_TIMEOUT_TX/DELAYED_OUTPUT_TO_US') - l1.daemon.wait_for_log('sendrawtx exit 0') - - # 89 later, l2 is done. - bitcoind.generate_block(89) - l2.daemon.wait_for_log('onchaind complete, forgetting peer') - - # Now, 100 blocks and l1 should be done. - bitcoind.generate_block(10) - sync_blockheight([l1]) - assert not l1.daemon.is_in_log('onchaind complete, forgetting peer') - bitcoind.generate_block(1) - l1.daemon.wait_for_log('onchaind complete, forgetting peer') - - # Payment failed, BTW - assert only_one(l2.rpc.listinvoices('onchain_timeout')['invoices'])['status'] == 'unpaid' - - @unittest.skipIf(not DEVELOPER, "needs DEVELOPER=1") - def test_onchain_middleman(self): - # HTLC 1->2->3, 1->2 goes down after 2 gets preimage from 3. - disconnects = ['-WIRE_UPDATE_FULFILL_HTLC', 'permfail'] - l1 = self.node_factory.get_node() - l2 = self.node_factory.get_node(disconnect=disconnects) - l3 = self.node_factory.get_node() - - # l2 connects to both, so l1 can't reconnect and thus l2 drops to chain - l2.rpc.connect(l1.info['id'], 'localhost', l1.port) - l2.rpc.connect(l3.info['id'], 'localhost', l3.port) - self.fund_channel(l2, l1, 10**6) - c23 = self.fund_channel(l2, l3, 10**6) - - # Make sure routes finalized. - self.wait_for_routes(l1, [c23]) - - # Give l1 some money to play with. - self.pay(l2, l1, 2 * 10**8) - - # Must be bigger than dust! - rhash = l3.rpc.invoice(10**8, 'middleman', 'desc')['payment_hash'] - - route = l1.rpc.getroute(l3.info['id'], 10**8, 1)["route"] - assert len(route) == 2 - - q = queue.Queue() - - def try_pay(): - try: - l1.rpc.sendpay(to_json(route), rhash) - l1.rpc.waitsendpay(rhash) - q.put(None) - except Exception as err: - q.put(err) - - t = threading.Thread(target=try_pay) - t.daemon = True - t.start() - - # l2 will drop to chain. - l2.daemon.wait_for_log('sendrawtx exit 0') - l1.bitcoin.generate_block(1) - l2.daemon.wait_for_log(' to ONCHAIN') - l1.daemon.wait_for_log(' to ONCHAIN') - l2.daemon.wait_for_log('OUR_UNILATERAL/THEIR_HTLC') - - # l2 should fulfill HTLC onchain, and spend to-us (any order) - l2.daemon.wait_for_log('Propose handling OUR_UNILATERAL/THEIR_HTLC by OUR_HTLC_SUCCESS_TX .* after 0 blocks') - l2.daemon.wait_for_log('sendrawtx exit 0') - - # Payment should succeed. - l1.bitcoin.generate_block(1) - l1.daemon.wait_for_log('THEIR_UNILATERAL/OUR_HTLC gave us preimage') - err = q.get(timeout=10) - if err: - print("Got err from sendpay thread") - raise err - t.join(timeout=1) - assert not t.isAlive() - - # Three more, l2 can spend to-us. - bitcoind.generate_block(3) - l2.daemon.wait_for_log('Broadcasting OUR_DELAYED_RETURN_TO_WALLET .* to resolve OUR_UNILATERAL/DELAYED_OUTPUT_TO_US') - l2.daemon.wait_for_log('sendrawtx exit 0') - - # One more block, HTLC tx is now spendable. - l1.bitcoin.generate_block(1) - l2.daemon.wait_for_log('Broadcasting OUR_DELAYED_RETURN_TO_WALLET .* to resolve OUR_HTLC_SUCCESS_TX/DELAYED_OUTPUT_TO_US') - l2.daemon.wait_for_log('sendrawtx exit 0') - - # 100 blocks after last spend, l2 should be done. - l1.bitcoin.generate_block(100) - l2.daemon.wait_for_log('onchaind complete, forgetting peer') - - @unittest.skipIf(not DEVELOPER, "needs DEVELOPER=1") - def test_penalty_inhtlc(self): - """Test penalty transaction with an incoming HTLC""" - # We suppress each one after first commit; HTLC gets added not fulfilled. - l1 = self.node_factory.get_node(disconnect=['=WIRE_COMMITMENT_SIGNED-nocommit'], may_fail=True) - l2 = self.node_factory.get_node(disconnect=['=WIRE_COMMITMENT_SIGNED-nocommit']) - - l1.rpc.connect(l2.info['id'], 'localhost', l2.port) - self.fund_channel(l1, l2, 10**6) - - # Now, this will get stuck due to l1 commit being disabled.. - t = self.pay(l1, l2, 100000000, async=True) - - assert len(l1.getactivechannels()) == 2 - assert len(l2.getactivechannels()) == 2 - - # They should both have commitments blocked now. - l1.daemon.wait_for_log('=WIRE_COMMITMENT_SIGNED-nocommit') - l2.daemon.wait_for_log('=WIRE_COMMITMENT_SIGNED-nocommit') - - # Make sure l1 got l2's commitment to the HTLC, and sent to master. - l1.daemon.wait_for_log('UPDATE WIRE_CHANNEL_GOT_COMMITSIG') - - # Take our snapshot. - tx = l1.rpc.dev_sign_last_tx(l2.info['id'])['tx'] - - # Let them continue - l1.rpc.dev_reenable_commit(l2.info['id']) - l2.rpc.dev_reenable_commit(l1.info['id']) - - # Should fulfill. - l1.daemon.wait_for_log('peer_in WIRE_UPDATE_FULFILL_HTLC') - l1.daemon.wait_for_log('peer_out WIRE_REVOKE_AND_ACK') - - l2.daemon.wait_for_log('peer_out WIRE_UPDATE_FULFILL_HTLC') - l1.daemon.wait_for_log('peer_in WIRE_REVOKE_AND_ACK') - - # Payment should now complete. - t.result(timeout=10) - - # Now we really mess things up! - bitcoind.rpc.sendrawtransaction(tx) - bitcoind.generate_block(1) - - l2.daemon.wait_for_log(' to ONCHAIN') - # FIXME: l1 should try to stumble along! - wait_for(lambda: len(l2.getactivechannels()) == 0) - - # l2 should spend all of the outputs (except to-us). - # Could happen in any order, depending on commitment tx. - l2.daemon.wait_for_logs(['Propose handling THEIR_REVOKED_UNILATERAL/DELAYED_OUTPUT_TO_THEM by OUR_PENALTY_TX .* after 0 blocks', - 'sendrawtx exit 0', - 'Propose handling THEIR_REVOKED_UNILATERAL/THEIR_HTLC by OUR_PENALTY_TX .* after 0 blocks', - 'sendrawtx exit 0']) - - # FIXME: test HTLC tx race! - - # 100 blocks later, all resolved. - bitcoind.generate_block(100) - - l2.daemon.wait_for_log('onchaind complete, forgetting peer') - - outputs = l2.rpc.listfunds()['outputs'] - assert [o['status'] for o in outputs] == ['confirmed'] * 2 - # Allow some lossage for fees. - assert sum(o['value'] for o in outputs) < 10**6 - assert sum(o['value'] for o in outputs) > 10**6 - 15000 - - @unittest.skipIf(not DEVELOPER, "needs DEVELOPER=1") - def test_penalty_outhtlc(self): - """Test penalty transaction with an outgoing HTLC""" - # First we need to get funds to l2, so suppress after second. - l1 = self.node_factory.get_node(disconnect=['=WIRE_COMMITMENT_SIGNED*3-nocommit'], may_fail=True) - l2 = self.node_factory.get_node(disconnect=['=WIRE_COMMITMENT_SIGNED*3-nocommit']) - - l1.rpc.connect(l2.info['id'], 'localhost', l2.port) - self.fund_channel(l1, l2, 10**6) - - # Move some across to l2. - self.pay(l1, l2, 200000000) - - assert not l1.daemon.is_in_log('=WIRE_COMMITMENT_SIGNED') - assert not l2.daemon.is_in_log('=WIRE_COMMITMENT_SIGNED') - - # Now, this will get stuck due to l1 commit being disabled.. - t = self.pay(l2, l1, 100000000, async=True) - # Make sure we get signature from them. - l1.daemon.wait_for_log('peer_in WIRE_UPDATE_ADD_HTLC') - l1.daemon.wait_for_log('peer_in WIRE_COMMITMENT_SIGNED') - - # They should both have commitments blocked now. - l1.daemon.wait_for_log('dev_disconnect: =WIRE_COMMITMENT_SIGNED') - l2.daemon.wait_for_log('dev_disconnect: =WIRE_COMMITMENT_SIGNED') - - # Make sure both sides got revoke_and_ack for that commitment. - l1.daemon.wait_for_log('peer_in WIRE_REVOKE_AND_ACK') - l2.daemon.wait_for_log('peer_in WIRE_REVOKE_AND_ACK') - - # Take our snapshot. - tx = l1.rpc.dev_sign_last_tx(l2.info['id'])['tx'] - - # Let them continue - l1.rpc.dev_reenable_commit(l2.info['id']) - l2.rpc.dev_reenable_commit(l1.info['id']) - - # Thread should complete. - t.result(timeout=10) - - # Make sure both sides got revoke_and_ack for final. - l1.daemon.wait_for_log('peer_in WIRE_REVOKE_AND_ACK') - l2.daemon.wait_for_log('peer_in WIRE_REVOKE_AND_ACK') - - # Now we really mess things up! - bitcoind.rpc.sendrawtransaction(tx) - bitcoind.generate_block(1) - - l2.daemon.wait_for_log(' to ONCHAIN') - # FIXME: l1 should try to stumble along! - - # l2 should spend all of the outputs (except to-us). - # Could happen in any order, depending on commitment tx. - l2.daemon.wait_for_logs(['Ignoring output.*: THEIR_REVOKED_UNILATERAL/OUTPUT_TO_US', - 'Propose handling THEIR_REVOKED_UNILATERAL/DELAYED_OUTPUT_TO_THEM by OUR_PENALTY_TX .* after 0 blocks', - 'sendrawtx exit 0', - 'Propose handling THEIR_REVOKED_UNILATERAL/OUR_HTLC by OUR_PENALTY_TX .* after 0 blocks', - 'sendrawtx exit 0']) - - # FIXME: test HTLC tx race! - - # 100 blocks later, all resolved. - bitcoind.generate_block(100) - - wait_forget_channels(l2) - - outputs = l2.rpc.listfunds()['outputs'] - assert [o['status'] for o in outputs] == ['confirmed'] * 3 - # Allow some lossage for fees. - assert sum(o['value'] for o in outputs) < 10**6 - assert sum(o['value'] for o in outputs) > 10**6 - 15000 - - @unittest.skipIf(not DEVELOPER, "needs DEVELOPER=1") - def test_onchain_feechange(self): - """Onchain handling when we restart with different fees""" - # HTLC 1->2, 2 fails just after they're both irrevocably committed - # We need 2 to drop to chain, because then 1's HTLC timeout tx - # is generated on-the-fly, and is thus feerate sensitive. - disconnects = ['-WIRE_UPDATE_FAIL_HTLC', 'permfail'] - l1 = self.node_factory.get_node(may_reconnect=True) - l2 = self.node_factory.get_node(disconnect=disconnects, - may_reconnect=True) - - l1.rpc.connect(l2.info['id'], 'localhost', l2.port) - self.fund_channel(l1, l2, 10**6) - - rhash = l2.rpc.invoice(10**8, 'onchain_timeout', 'desc')['payment_hash'] - # We underpay, so it fails. - routestep = { - 'msatoshi': 10**8 - 1, - 'id': l2.info['id'], - 'delay': 5, - 'channel': '1:1:1' - } - - self.executor.submit(l1.rpc.sendpay, to_json([routestep]), rhash) - - # l2 will drop to chain. - l2.daemon.wait_for_log('permfail') - l2.daemon.wait_for_log('sendrawtx exit 0') - bitcoind.generate_block(1) - l1.daemon.wait_for_log(' to ONCHAIN') - l2.daemon.wait_for_log(' to ONCHAIN') - - # Wait for timeout. - l1.daemon.wait_for_log('Propose handling THEIR_UNILATERAL/OUR_HTLC by OUR_HTLC_TIMEOUT_TO_US .* after 6 blocks') - bitcoind.generate_block(6) - - l1.daemon.wait_for_log('sendrawtx exit 0') - - # Make sure that gets included. - - bitcoind.generate_block(1) - # Now we restart with different feerates. - l1.stop() - - l1.daemon.cmd_line.append('--override-fee-rates=20000/9000/2000') - l1.start() - - # We recognize different proposal as ours. - l1.daemon.wait_for_log('Resolved THEIR_UNILATERAL/OUR_HTLC by our proposal OUR_HTLC_TIMEOUT_TO_US') - - # We use 3 blocks for "reasonable depth", so add two more - bitcoind.generate_block(2) - - # Note that the very similar test_onchain_timeout looks for a - # different string: that's because it sees the JSONRPC response, - # and due to the l1 restart, there is none here. - l1.daemon.wait_for_log('WIRE_PERMANENT_CHANNEL_FAILURE') - - # 90 later, l2 is done - bitcoind.generate_block(89) - sync_blockheight([l2]) - assert not l2.daemon.is_in_log('onchaind complete, forgetting peer') - bitcoind.generate_block(1) - l2.daemon.wait_for_log('onchaind complete, forgetting peer') - - # Now, 7 blocks and l1 should be done. - bitcoind.generate_block(6) - sync_blockheight([l1]) - assert not l1.daemon.is_in_log('onchaind complete, forgetting peer') - bitcoind.generate_block(1) - l1.daemon.wait_for_log('onchaind complete, forgetting peer') - - # Payment failed, BTW - assert only_one(l2.rpc.listinvoices('onchain_timeout')['invoices'])['status'] == 'unpaid' - - @unittest.skipIf(not DEVELOPER, "needs DEVELOPER=1 for dev-set-fees") - def test_onchain_all_dust(self): - """Onchain handling when we reduce output to all dust""" - # HTLC 1->2, 2 fails just after they're both irrevocably committed - # We need 2 to drop to chain, because then 1's HTLC timeout tx - # is generated on-the-fly, and is thus feerate sensitive. - disconnects = ['-WIRE_UPDATE_FAIL_HTLC', 'permfail'] - l1 = self.node_factory.get_node(options={'dev-no-reconnect': None}) - l2 = self.node_factory.get_node(disconnect=disconnects) - - l1.rpc.connect(l2.info['id'], 'localhost', l2.port) - self.fund_channel(l1, l2, 10**6) - - rhash = l2.rpc.invoice(10**8, 'onchain_timeout', 'desc')['payment_hash'] - # We underpay, so it fails. - routestep = { - 'msatoshi': 10**7 - 1, - 'id': l2.info['id'], - 'delay': 5, - 'channel': '1:1:1' - } - - self.executor.submit(l1.rpc.sendpay, to_json([routestep]), rhash) - - # l2 will drop to chain. - l2.daemon.wait_for_log('permfail') - l2.daemon.wait_for_log('sendrawtx exit 0') - - # Make l1's fees really high. - l1.rpc.dev_setfees('100000', '100000', '100000') - - bitcoind.generate_block(1) - l1.daemon.wait_for_log(' to ONCHAIN') - l2.daemon.wait_for_log(' to ONCHAIN') - - # Wait for timeout. - l1.daemon.wait_for_log('Propose handling THEIR_UNILATERAL/OUR_HTLC by IGNORING_TINY_PAYMENT .* after 6 blocks') - bitcoind.generate_block(5) - - l1.daemon.wait_for_logs(['Broadcasting IGNORING_TINY_PAYMENT .* to resolve THEIR_UNILATERAL/OUR_HTLC', - 'sendrawtx exit 0', - 'Ignoring output 0 of .*: THEIR_UNILATERAL/OUR_HTLC']) - - # 100 deep and l2 forgets. - bitcoind.generate_block(93) - sync_blockheight([l1, l2]) - assert not l2.daemon.is_in_log('onchaind complete, forgetting peer') - assert not l1.daemon.is_in_log('onchaind complete, forgetting peer') - bitcoind.generate_block(1) - l2.daemon.wait_for_log('onchaind complete, forgetting peer') - - # l1 does not wait for ignored payment. - l1.daemon.wait_for_log('onchaind complete, forgetting peer') - - @unittest.skipIf(not DEVELOPER, "needs DEVELOPER=1 for dev_fail") - def test_onchain_different_fees(self): - """Onchain handling when we've had a range of fees""" - - l1, l2 = self.connect() - self.fund_channel(l1, l2, 10**7) - - l2.rpc.dev_ignore_htlcs(id=l1.info['id'], ignore=True) - p1 = self.pay(l1, l2, 1000000000, async=True) - l1.daemon.wait_for_log('htlc 0: RCVD_ADD_ACK_COMMIT->SENT_ADD_ACK_REVOCATION') - - l1.rpc.dev_setfees('14000') - p2 = self.pay(l1, l2, 900000000, async=True) - l1.daemon.wait_for_log('htlc 1: RCVD_ADD_ACK_COMMIT->SENT_ADD_ACK_REVOCATION') - - l1.rpc.dev_setfees('5000') - p3 = self.pay(l1, l2, 800000000, async=True) - l1.daemon.wait_for_log('htlc 2: RCVD_ADD_ACK_COMMIT->SENT_ADD_ACK_REVOCATION') - - # Drop to chain - l1.rpc.dev_fail(l2.info['id']) - l1.daemon.wait_for_log('sendrawtx exit 0') - - bitcoind.generate_block(1) - l1.daemon.wait_for_log(' to ONCHAIN') - l2.daemon.wait_for_log(' to ONCHAIN') - - # Both sides should have correct feerate - assert l1.db_query('SELECT min_possible_feerate, max_possible_feerate FROM channels;') == [{'min_possible_feerate': 5000, 'max_possible_feerate': 14000}] - assert l2.db_query('SELECT min_possible_feerate, max_possible_feerate FROM channels;') == [{'min_possible_feerate': 5000, 'max_possible_feerate': 14000}] - - bitcoind.generate_block(5) - # Three HTLCs, and one for the to-us output. - l1.daemon.wait_for_logs(['sendrawtx exit 0'] * 4) - - # We use 3 blocks for "reasonable depth" - bitcoind.generate_block(3) - - self.assertRaises(TimeoutError, p1.result, 10) - self.assertRaises(TimeoutError, p2.result, 10) - self.assertRaises(TimeoutError, p3.result, 10) - - # Two more for HTLC timeout tx to be spent. - bitcoind.generate_block(2) - l1.daemon.wait_for_logs(['sendrawtx exit 0'] * 3) - - # Now, 100 blocks it should be done. - bitcoind.generate_block(100) - wait_forget_channels(l1) - wait_forget_channels(l2) - - @unittest.skipIf(not DEVELOPER, "needs DEVELOPER=1") - def test_permfail_new_commit(self): - # Test case where we have two possible commits: it will use new one. - disconnects = ['-WIRE_REVOKE_AND_ACK', 'permfail'] - l1 = self.node_factory.get_node(options={'dev-no-reconnect': None}) - l2 = self.node_factory.get_node(disconnect=disconnects) - - l1.rpc.connect(l2.info['id'], 'localhost', l2.port) - self.fund_channel(l1, l2, 10**6) - - # This will fail at l2's end. - t = self.pay(l1, l2, 200000000, async=True) - - l2.daemon.wait_for_log('dev_disconnect permfail') - l2.daemon.wait_for_log('sendrawtx exit 0') - bitcoind.generate_block(1) - l1.daemon.wait_for_log('Their unilateral tx, new commit point') - l1.daemon.wait_for_log(' to ONCHAIN') - l2.daemon.wait_for_log(' to ONCHAIN') - l2.daemon.wait_for_log('Propose handling OUR_UNILATERAL/THEIR_HTLC by THEIR_HTLC_TIMEOUT_TO_THEM \\(IGNORING\\) after 6 blocks') - l1.daemon.wait_for_log('Propose handling THEIR_UNILATERAL/OUR_HTLC by OUR_HTLC_TIMEOUT_TO_US (.*) after 6 blocks') - - # OK, time out HTLC. - bitcoind.generate_block(5) - l1.daemon.wait_for_log('sendrawtx exit 0') - bitcoind.generate_block(1) - l1.daemon.wait_for_log('Resolved THEIR_UNILATERAL/OUR_HTLC by our proposal OUR_HTLC_TIMEOUT_TO_US') - l2.daemon.wait_for_log('Ignoring output.*: OUR_UNILATERAL/THEIR_HTLC') - - t.cancel() - - # Now, 100 blocks it should be done. - bitcoind.generate_block(100) - wait_forget_channels(l1) - wait_forget_channels(l2) - - @unittest.skipIf(not DEVELOPER, "needs DEVELOPER=1") - def test_permfail_htlc_in(self): - # Test case where we fail with unsettled incoming HTLC. - disconnects = ['-WIRE_UPDATE_FULFILL_HTLC', 'permfail'] - l1 = self.node_factory.get_node(options={'dev-no-reconnect': None}) - l2 = self.node_factory.get_node(disconnect=disconnects) - - l1.rpc.connect(l2.info['id'], 'localhost', l2.port) - self.fund_channel(l1, l2, 10**6) - - # This will fail at l2's end. - t = self.pay(l1, l2, 200000000, async=True) - - l2.daemon.wait_for_log('dev_disconnect permfail') - l2.daemon.wait_for_log('sendrawtx exit 0') - bitcoind.generate_block(1) - l1.daemon.wait_for_log('Their unilateral tx, old commit point') - l1.daemon.wait_for_log(' to ONCHAIN') - l2.daemon.wait_for_log(' to ONCHAIN') - l2.daemon.wait_for_log('Propose handling OUR_UNILATERAL/THEIR_HTLC by THEIR_HTLC_TIMEOUT_TO_THEM \\(IGNORING\\) after 6 blocks') - l1.daemon.wait_for_log('Propose handling THEIR_UNILATERAL/OUR_HTLC by OUR_HTLC_TIMEOUT_TO_US (.*) after 6 blocks') - # l2 then gets preimage, uses it instead of ignoring - l2.daemon.wait_for_log('Propose handling OUR_UNILATERAL/THEIR_HTLC by OUR_HTLC_SUCCESS_TX .* after 0 blocks') - l2.daemon.wait_for_log('sendrawtx exit 0') - bitcoind.generate_block(1) - - # OK, l1 sees l2 fulfill htlc. - l1.daemon.wait_for_log('THEIR_UNILATERAL/OUR_HTLC gave us preimage') - l2.daemon.wait_for_log('Propose handling OUR_HTLC_SUCCESS_TX/DELAYED_OUTPUT_TO_US by OUR_DELAYED_RETURN_TO_WALLET .* after 5 blocks') - bitcoind.generate_block(6) - - l2.daemon.wait_for_log('sendrawtx exit 0') - - t.cancel() - - # Now, 100 blocks it should be done. - bitcoind.generate_block(95) - l1.daemon.wait_for_log('onchaind complete, forgetting peer') - assert not l2.daemon.is_in_log('onchaind complete, forgetting peer') - bitcoind.generate_block(5) - l2.daemon.wait_for_log('onchaind complete, forgetting peer') - - @unittest.skipIf(not DEVELOPER, "needs DEVELOPER=1") - def test_permfail_htlc_out(self): - # Test case where we fail with unsettled outgoing HTLC. - disconnects = ['+WIRE_REVOKE_AND_ACK', 'permfail'] - l1 = self.node_factory.get_node(options={'dev-no-reconnect': None}) - l2 = self.node_factory.get_node(disconnect=disconnects) - - l1.rpc.connect(l2.info['id'], 'localhost', l2.port) - self.fund_channel(l2, l1, 10**6) - - # This will fail at l2's end. - t = self.pay(l2, l1, 200000000, async=True) - - l2.daemon.wait_for_log('dev_disconnect permfail') - l2.daemon.wait_for_log('sendrawtx exit 0') - bitcoind.generate_block(1) - l1.daemon.wait_for_log('Their unilateral tx, old commit point') - l1.daemon.wait_for_log(' to ONCHAIN') - l2.daemon.wait_for_log(' to ONCHAIN') - l2.daemon.wait_for_logs(['Propose handling OUR_UNILATERAL/OUR_HTLC by OUR_HTLC_TIMEOUT_TX \\(.*\\) after 6 blocks', - 'Propose handling OUR_UNILATERAL/DELAYED_OUTPUT_TO_US by OUR_DELAYED_RETURN_TO_WALLET .* after 5 blocks']) - - l1.daemon.wait_for_log('Propose handling THEIR_UNILATERAL/THEIR_HTLC by THEIR_HTLC_TIMEOUT_TO_THEM \\(IGNORING\\) after 6 blocks') - # l1 then gets preimage, uses it instead of ignoring - l1.daemon.wait_for_log('Propose handling THEIR_UNILATERAL/THEIR_HTLC by THEIR_HTLC_FULFILL_TO_US .* after 0 blocks') - l1.daemon.wait_for_log('sendrawtx exit 0') - - # l2 sees l1 fulfill tx. - bitcoind.generate_block(1) - - l2.daemon.wait_for_log('OUR_UNILATERAL/OUR_HTLC gave us preimage') - t.cancel() - - # l2 can send OUR_DELAYED_RETURN_TO_WALLET after 3 more blocks. - bitcoind.generate_block(3) - l2.daemon.wait_for_log('Broadcasting OUR_DELAYED_RETURN_TO_WALLET .* to resolve OUR_UNILATERAL/DELAYED_OUTPUT_TO_US') - l2.daemon.wait_for_log('sendrawtx exit 0') - - # Now, 100 blocks they should be done. - bitcoind.generate_block(95) - sync_blockheight([l1, l2]) - assert not l1.daemon.is_in_log('onchaind complete, forgetting peer') - assert not l2.daemon.is_in_log('onchaind complete, forgetting peer') - bitcoind.generate_block(1) - l1.daemon.wait_for_log('onchaind complete, forgetting peer') - sync_blockheight([l2]) - assert not l2.daemon.is_in_log('onchaind complete, forgetting peer') - bitcoind.generate_block(3) - sync_blockheight([l2]) - assert not l2.daemon.is_in_log('onchaind complete, forgetting peer') - bitcoind.generate_block(1) - wait_forget_channels(l2) - def ping_tests(self, l1, l2): # 0-byte pong gives just type + length field. ret = l1.rpc.dev_ping(l2.info['id'], 0, 0) @@ -2310,36 +1231,6 @@ class LightningDTests(BaseLightningDTests): wait_forget_channels(l1) wait_forget_channels(l2) - @unittest.skipIf(not DEVELOPER, "needs DEVELOPER=1") - def test_closing_negotiation_reconnect(self): - disconnects = ['-WIRE_CLOSING_SIGNED', - '@WIRE_CLOSING_SIGNED', - '+WIRE_CLOSING_SIGNED'] - l1 = self.node_factory.get_node(disconnect=disconnects, may_reconnect=True) - l2 = self.node_factory.get_node(may_reconnect=True) - l1.rpc.connect(l2.info['id'], 'localhost', l2.port) - - chan = self.fund_channel(l1, l2, 10**6) - self.pay(l1, l2, 200000000) - - assert l1.bitcoin.rpc.getmempoolinfo()['size'] == 0 - - # This should return with an error, then close. - self.assertRaisesRegex(RpcError, - "Channel close negotiation not finished", - l1.rpc.close, chan, False, 0) - l1.daemon.wait_for_log(' to CHANNELD_SHUTTING_DOWN') - l2.daemon.wait_for_log(' to CHANNELD_SHUTTING_DOWN') - - l1.daemon.wait_for_log(' to CLOSINGD_SIGEXCHANGE') - l2.daemon.wait_for_log(' to CLOSINGD_SIGEXCHANGE') - - # And should put closing into mempool (happens async, so - # CLOSINGD_COMPLETE may come first). - l1.daemon.wait_for_logs(['sendrawtx exit 0', ' to CLOSINGD_COMPLETE']) - l2.daemon.wait_for_logs(['sendrawtx exit 0', ' to CLOSINGD_COMPLETE']) - assert l1.bitcoin.rpc.getmempoolinfo()['size'] == 1 - @unittest.skipIf(not DEVELOPER, "needs DEVELOPER=1") def test_bech32_funding(self): # Don't get any funds from previous runs. diff --git a/tests/utils.py b/tests/utils.py index fe495a8d2..051aadd3c 100644 --- a/tests/utils.py +++ b/tests/utils.py @@ -1,9 +1,11 @@ import logging import os +import random import re import shutil import sqlite3 import stat +import string import subprocess import threading import time @@ -64,6 +66,12 @@ def only_one(arr): return arr[0] +def sync_blockheight(bitcoind, nodes): + height = bitcoind.rpc.getblockchaininfo()['blocks'] + for n in nodes: + wait_for(lambda: n.rpc.getinfo()['blockheight'] == height) + + class TailableProc(object): """A monitorable process that we can start, stop and tail. @@ -548,6 +556,33 @@ class LightningNode(object): ['Received channel_update for channel {}\\(1\\)'.format(c) for c in channel_ids]) + def pay(self, dst, amt, label=None): + if not label: + label = ''.join(random.choice(string.ascii_letters + string.digits) for _ in range(20)) + + rhash = dst.rpc.invoice(amt, label, label)['payment_hash'] + invoices = dst.rpc.listinvoices(label)['invoices'] + assert len(invoices) == 1 and invoices[0]['status'] == 'unpaid' + + routestep = { + 'msatoshi': amt, + 'id': dst.info['id'], + 'delay': 5, + 'channel': '1:1:1' + } + + def wait_pay(): + # Up to 10 seconds for payment to succeed. + start_time = time.time() + while dst.rpc.listinvoices(label)['invoices'][0]['status'] != 'paid': + if time.time() > start_time + 10: + raise TimeoutError('Payment timed out') + time.sleep(0.1) + # sendpay is async now + self.rpc.sendpay([routestep], rhash) + # wait for sendpay to comply + self.rpc.waitsendpay(rhash) + class NodeFactory(object): """A factory to setup and start `lightningd` daemons.