diff --git a/Makefile b/Makefile index 0b80b4dd0..71c6d9579 100644 --- a/Makefile +++ b/Makefile @@ -234,10 +234,7 @@ $(HELPER_OBJS) $(CORE_OBJS) $(CORE_TX_OBJS) $(CORE_PROTOBUF_OBJS) $(BITCOIN_OBJS test-protocol: test/test_protocol set -e; TMP=`mktemp`; for f in test/commits/*.script; do if ! $(VALGRIND) test/test_protocol < $$f > $$TMP; then echo "test/test_protocol < $$f FAILED" >&2; exit 1; fi; diff -u $$TMP $$f.expected; done; rm $$TMP -# FIXME: check doesn't depend on lightningd-blackbox-tests, since they -# can't run in parallel with daemon blackbox tests. check: test-protocol - $(MAKE) lightningd-blackbox-tests $(MAKE) pytest pytest: daemon/lightningd daemon/lightning-cli lightningd-all diff --git a/lightningd/pay.c b/lightningd/pay.c index 8d8577fbe..760744d32 100644 --- a/lightningd/pay.c +++ b/lightningd/pay.c @@ -59,8 +59,11 @@ void payment_succeeded(struct lightningd *ld, struct htlc_end *dst, const struct preimage *rval) { /* FIXME: dev_htlc will do this! */ - if (!dst->pay_command) + if (!dst->pay_command) { + log_debug(ld->log, "Payment succeeded on HTLC %"PRIu64, + dst->htlc_id); return; + } assert(!dst->pay_command->rval); dst->pay_command->rval = tal_dup(dst->pay_command, diff --git a/lightningd/test/Makefile b/lightningd/test/Makefile index ea71bca5a..50a4386b6 100644 --- a/lightningd/test/Makefile +++ b/lightningd/test/Makefile @@ -14,25 +14,5 @@ $(LIGHTNINGD_TEST_OBJS): $(LIGHTNINGD_HEADERS) $(LIGHTNINGD_SRC) $(LIGHTNINGD_LI lightningd/tests: $(LIGHTNINGD_TEST_PROGRAMS:%=unittest/%) -# So far, only basic test. -lightningd-test-0-basic: lightningd-test-setup-0 - -lightningd-test-0-%: - NO_VALGRIND=$(NO_VALGRIND) VG_TRACE_CHILDREN="--trace-children=yes" VARIANT=0 lightningd/test/test-$* - -# We shutdown first in case something is left over. -lightningd-test-setup-%: lightningd-all daemon/lightning-cli - VARIANT=$* daemon/test/scripts/shutdown.sh 2>/dev/null || true - VARIANT=$* daemon/test/scripts/setup.sh - -lightningd-test-shutdown-0: lightningd-test-0-basic - VARIANT=0 daemon/test/scripts/shutdown.sh -lightningd-test-shutdown-1: lightningd-test-1-basic\ --restart - VARIANT=1 daemon/test/scripts/shutdown.sh -lightningd-test-shutdown-2: lightningd-test-2-basic\ --reconnect - VARIANT=2 daemon/test/scripts/shutdown.sh - -lightningd-blackbox-tests: lightningd-test-shutdown-0 #lightningd-test-shutdown-1 lightningd-test-shutdown-2 - check-source-bolt: $(LIGHTNINGD_TEST_SRC:%=bolt-check/%) check-whitespace: $(LIGHTNINGD_TEST_SRC:%=check-whitespace/%) diff --git a/lightningd/test/test-basic b/lightningd/test/test-basic deleted file mode 100755 index e2e57fd42..000000000 --- a/lightningd/test/test-basic +++ /dev/null @@ -1,123 +0,0 @@ -#! /bin/sh -e - -# Wherever we are, we want to be in daemon/test dir. -cd `git rev-parse --show-toplevel`/daemon/test - -. scripts/vars.sh -. scripts/helpers.sh - -parse_cmdline 2 "$@" -setup_lightning 2 - -start_lightningd 2 lightningd/lightningd - -if lcli1 connect localhost $PORT2 $ID1; then - echo Connected OK with wrong ID? >&2 - exit 1 -fi - -lcli1 connect localhost $PORT2 $ID2 - -# Should now be exchanging gossip -lcli1 getpeers | $FGREP '"condition" : "Exchanging gossip"' - -# It should have gone through these steps -lcli1 getpeers info | $FGREP "Starting handshake as initiator" -lcli1 getpeers info | $FGREP "Beginning gossip" -lcli1 getpeers info | $FGREP "Exchanging gossip" - -# Both should still be owned by gossip -lcli1 getpeers | $FGREP '"owner" : "lightningd_gossip"' -lcli2 getpeers | $FGREP '"owner" : "lightningd_gossip"' - -# Add some funds. -NEWADDR=`lcli1 newaddr | get_field address` -FUND_INPUT_TXID=`$CLI sendtoaddress $NEWADDR 0.10000002` -FUND_INPUT_TX=`$CLI getrawtransaction $FUND_INPUT_TXID` - -lcli1 addfunds $FUND_INPUT_TX | $FGREP '"satoshis" : 10000002' - -# Now fund a channel. -lcli1 fundchannel $ID2 1000000 - -# Now wait for it to reach depth -lcli1 getpeers info | $FGREP "Waiting for our funding tx" -[ `lcli1 getpeers | get_field msatoshi_to_us` = 1000000000 ] -[ `lcli1 getpeers | get_field msatoshi_to_them` = 0 ] -[ `lcli2 getpeers | get_field msatoshi_to_them` = 1000000000 ] -[ `lcli2 getpeers | get_field msatoshi_to_us` = 0 ] - -$CLI generate 10 -check "lcli1 getpeers info | $FGREP 'Funding tx reached depth'" -check "lcli2 getpeers info | $FGREP 'Funding tx reached depth'" - -check "lcli1 getpeers | tr -s '\012\011\" ' ' ' | $FGREP 'condition : Normal operation'" -check "lcli2 getpeers | tr -s '\012\011\" ' ' ' | $FGREP 'condition : Normal operation'" - -SECRET=1de08917a61cb2b62ed5937d38577f6a7bfe59c176781c6d8128018e8b5ccdfd -RHASH=`lcli1 dev-rhash $SECRET | sed 's/.*"\([0-9a-f]*\)".*/\1/'` - -# This is actually dust -lcli1 dev-newhtlc $ID2 100000 $(( $(blockheight) + 10 )) $RHASH -check "lcli1 getlog debug | $FGREP 'Sending commit_sig with 0 htlc sigs'" - -check "lcli2 getlog debug | $FGREP 'their htlc 0 locked'" -check "lcli2 getpeers info | $FGREP 'failed htlc 0 code 0x400f'" -check "lcli1 getpeers info | $FGREP 'htlc 0 failed with code 0x400f'" - -# This one isn't dust. -RHASH=`lcli2 invoice 100000000 testpayment1 | get_field rhash` -[ `lcli2 listinvoice testpayment1 | get_field complete` = false ] - -lcli1 dev-newhtlc $ID2 100000000 $(( $(blockheight) + 10 )) $RHASH -check "lcli1 getlog debug | $FGREP 'Sending commit_sig with 1 htlc sigs'" - -check "lcli2 getlog debug | $FGREP 'Resolving invoice '\'testpayment1\'' with HTLC 1'" -[ `lcli2 listinvoice testpayment1 | get_field complete` = true ] - -check "lcli1 getpeers | get_field msatoshi_to_us | $FGREP -w 900000000" -[ `lcli1 getpeers | get_field msatoshi_to_us` = 900000000 ] -[ `lcli1 getpeers | get_field msatoshi_to_them` = 100000000 ] -[ `lcli2 getpeers | get_field msatoshi_to_them` = 900000000 ] -[ `lcli2 getpeers | get_field msatoshi_to_us` = 100000000 ] - -RHASH=`lcli2 invoice 200000000 testpayment2 | get_field rhash` -[ `lcli2 listinvoice testpayment2 | get_field complete` = false ] - -# Not enough delay. -if lcli1 sendpay '[ { "msatoshi" : 200000000, "id" : "'$ID2'", "delay" : 3 } ]' $RHASH; then - echo Infufficient delay succeeded? >&2 -fi - -# Insufficient funds. -if lcli1 sendpay '[ { "msatoshi" : 199999999, "id" : "'$ID2'", "delay" : 5 } ]' $RHASH; then - echo Infufficient funds succeeded? >&2 -fi - -# Bad ID. -if lcli1 sendpay '[ { "msatoshi" : 200000000,, "id" : "'$ID2'", "delay" : 5 } ]' 00000000000000000000000000000000; then - echo Bad ID succeeded? >&2 -fi - -# This works -lcli1 sendpay '[ { "msatoshi" : 200000000, "id" : "'$ID2'", "delay" : 5 } ]' $RHASH -[ `lcli2 listinvoice testpayment2 | get_field complete` = true ] - -# This will "succeed", but won't actually send anything (duplicate) -if lcli1 getlog debug | $FGREP 'json_sendpay: found previous... succeeded'; then - echo Already had found previous? >&2 - exit 1 -fi -lcli1 sendpay '[ { "msatoshi" : 200000000, "id" : "'$ID2'", "delay" : 5 } ]' $RHASH -lcli1 getlog debug | $FGREP 'json_sendpay: found previous... succeeded' - -# FIXME: test paying via another node, should fail to pay twice. - -# Overpay. -RHASH=`lcli2 invoice 200000000 testpayment3 | get_field rhash` -lcli1 sendpay '[ { "msatoshi" : 200000001, "id" : "'$ID2'", "delay" : 5 } ]' $RHASH - -lcli1 stop -lcli2 stop - -all_ok diff --git a/tests/test_lightningd.py b/tests/test_lightningd.py index 3b631eeee..63089c953 100644 --- a/tests/test_lightningd.py +++ b/tests/test_lightningd.py @@ -3,6 +3,8 @@ from concurrent import futures from hashlib import sha256 from lightning import LightningRpc, LegacyLightningRpc +import copy +import json import logging import os import sys @@ -19,6 +21,8 @@ if os.getenv("TEST_DEBUG", None) != None: logging.basicConfig(level=logging.DEBUG, stream=sys.stdout) logging.info("Tests running in '%s'", TEST_DIR) +def to_json(arg): + return json.loads(json.dumps(arg)) def setupBitcoind(): global bitcoind @@ -138,12 +142,112 @@ class LightningDTests(BaseLightningDTests): def test_connect(self): l1,l2 = self.connect() - p1 = l1.rpc.getpeer(l2.info['id']) - p2 = l2.rpc.getpeer(l1.info['id']) + p1 = l1.rpc.getpeer(l2.info['id'], 'info') + p2 = l2.rpc.getpeer(l1.info['id'], 'info') assert p1['condition'] == 'Exchanging gossip' assert p2['condition'] == 'Exchanging gossip' + # It should have gone through these steps + assert 'condition: Starting handshake as initiator' in p1['log'] + assert 'condition: Beginning gossip' in p1['log'] + assert 'condition: Exchanging gossip' in p1['log'] + + # Both should still be owned by gossip + assert p1['owner'] == 'lightningd_gossip' + assert p2['owner'] == 'lightningd_gossip' + + def test_htlc(self): + l1,l2 = self.connect() + + self.fund_channel(l1, l2, 10**6) + l1.daemon.wait_for_log('condition: Funding tx reached depth 6') + l2.daemon.wait_for_log('condition: Funding tx reached depth 6') + + secret = '1de08917a61cb2b62ed5937d38577f6a7bfe59c176781c6d8128018e8b5ccdfd' + rhash = l1.rpc.dev_rhash(secret)['rhash'] + + # This is actually dust, and uncalled for. + l1.rpc.dev_newhtlc(l2.info['id'], 100000, l1.bitcoin.rpc.getblockcount() + 10, rhash) + l1.daemon.wait_for_log('Sending commit_sig with 0 htlc sigs') + l2.daemon.wait_for_log('their htlc 0 locked') + l2.daemon.wait_for_log('failed htlc 0 code 0x400f') + l1.daemon.wait_for_log('htlc 0 failed with code 0x400f') + + # Set up invoice (non-dust, just to test), and pay it. + # This one isn't dust. + rhash = l2.rpc.invoice(100000000, 'testpayment1')['rhash'] + assert l2.rpc.listinvoice('testpayment1')[0]['complete'] == False + + l1.rpc.dev_newhtlc(l2.info['id'], 100000000, l1.bitcoin.rpc.getblockcount() + 10, rhash) + l1.daemon.wait_for_log('Sending commit_sig with 1 htlc sigs') + l2.daemon.wait_for_log('their htlc 1 locked') + l2.daemon.wait_for_log("Resolving invoice 'testpayment1' with HTLC 1") + assert l2.rpc.listinvoice('testpayment1')[0]['complete'] == True + l1.daemon.wait_for_log('Payment succeeded on HTLC 1') + + # Balances should have changed. + p1 = l1.rpc.getpeer(l2.info['id']) + p2 = l2.rpc.getpeer(l1.info['id']) + assert p1['msatoshi_to_us'] == 900000000 + assert p1['msatoshi_to_them'] == 100000000 + assert p2['msatoshi_to_us'] == 100000000 + assert p2['msatoshi_to_them'] == 900000000 + + def test_sendpay(self): + l1,l2 = self.connect() + + self.fund_channel(l1, l2, 10**6) + + amt = 200000000 + rhash = l2.rpc.invoice(amt, 'testpayment2')['rhash'] + assert l2.rpc.listinvoice('testpayment2')[0]['complete'] == False + + routestep = { 'msatoshi' : amt, 'id' : l2.info['id'], 'delay' : 5} + + # Insufficient funds. + rs = copy.deepcopy(routestep) + rs['msatoshi'] = rs['msatoshi'] - 1 + self.assertRaises(ValueError, l1.rpc.sendpay, to_json([rs]), rhash) + assert l2.rpc.listinvoice('testpayment2')[0]['complete'] == False + + # Gross overpayment (more than factor of 2) + rs = copy.deepcopy(routestep) + rs['msatoshi'] = rs['msatoshi'] * 2 + 1 + self.assertRaises(ValueError, l1.rpc.sendpay, to_json([rs]), rhash) + assert l2.rpc.listinvoice('testpayment2')[0]['complete'] == False + + # Insufficient delay. + rs = copy.deepcopy(routestep) + rs['delay'] = rs['delay'] - 2 + self.assertRaises(ValueError, l1.rpc.sendpay, to_json([rs]), rhash) + assert l2.rpc.listinvoice('testpayment2')[0]['complete'] == False + + # Bad ID. + rs = copy.deepcopy(routestep) + rs['id'] = '00000000000000000000000000000000' + self.assertRaises(ValueError, l1.rpc.sendpay, to_json([rs]), rhash) + assert l2.rpc.listinvoice('testpayment2')[0]['complete'] == False + + # This works. + l1.rpc.sendpay(to_json([routestep]), rhash) + assert l2.rpc.listinvoice('testpayment2')[0]['complete'] == True + + # Repeat will "succeed", but won't actually send anything (duplicate) + assert not l1.daemon.is_in_log('... succeeded') + l1.rpc.sendpay(to_json([routestep]), rhash) + l1.daemon.wait_for_log('... succeeded') + assert l2.rpc.listinvoice('testpayment2')[0]['complete'] == True + + # Overpaying by "only" a factor of 2 succeeds. + rhash = l2.rpc.invoice(amt, 'testpayment3')['rhash'] + assert l2.rpc.listinvoice('testpayment3')[0]['complete'] == False + routestep = { 'msatoshi' : amt * 2, 'id' : l2.info['id'], 'delay' : 5} + l1.rpc.sendpay(to_json([routestep]), rhash) + assert l2.rpc.listinvoice('testpayment3')[0]['complete'] == True + + # FIXME: test paying via another node, should fail to pay twice. + def test_gossip_jsonrpc(self): l1,l2 = self.connect() diff --git a/tests/utils.py b/tests/utils.py index 2d05a6a2e..6eb55f268 100644 --- a/tests/utils.py +++ b/tests/utils.py @@ -74,7 +74,19 @@ class TailableProc(object): logging.debug("%s: %s", self.prefix, line.decode().rstrip()) self.logs_cond.notifyAll() self.running = False - + + def is_in_log(self, regex): + """Look for `regex` in the logs.""" + + ex = re.compile(regex) + for l in self.logs: + if ex.search(l): + logging.debug("Found '%s' in logs", regex) + return True + + logging.debug("Did not find '%s' in logs", regex) + return False + def wait_for_log(self, regex, offset=1000, timeout=60): """Look for `regex` in the logs.