Skip to content

Commit cce272f

Browse files
rustyrussellrustyrussell
committed
onchaind: fix confusing message about delayed txs.
We say "in N blocks" but we actually mean "N blocks after this tx" which is actually N-1 or less. Change wording and tighten tests which misunderstood this. Also, the 'assert not l1.daemon.is_in_log('onchaind complete, forgetting peer')' are unlikely to work until the daemon has actually seen the block, so add sync_blockheight before all of those. These changes reveal some sloppy testing, which we fix. Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
1 parent 049f536 commit cce272f

File tree

2 files changed

+39
-33
lines changed

2 files changed

+39
-33
lines changed

‎onchaind/onchain.c

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -341,7 +341,7 @@ static void propose_resolution(struct tracked_output *out,
341341
unsigned int depth_required,
342342
enum tx_type tx_type)
343343
{
344-
status_trace("Propose handling %s/%s by %s (%s) in %u blocks",
344+
status_trace("Propose handling %s/%s by %s (%s) after %u blocks",
345345
tx_type_name(out->tx_type),
346346
output_type_name(out->output_type),
347347
tx_type_name(tx_type),

‎tests/test_lightningd.py

Lines changed: 38 additions & 32 deletions
Original file line numberDiff line numberDiff line change
@@ -1225,7 +1225,7 @@ def test_permfail(self):
12251225
l1.daemon.wait_for_log('Their unilateral tx, old commit point')
12261226
l1.daemon.wait_for_log(' to ONCHAIN')
12271227
l2.daemon.wait_for_log(' to ONCHAIN')
1228-
l2.daemon.wait_for_log('Propose handling OUR_UNILATERAL/DELAYED_OUTPUT_TO_US by OUR_DELAYED_RETURN_TO_WALLET (.*) in 5 blocks')
1228+
l2.daemon.wait_for_log('Propose handling OUR_UNILATERAL/DELAYED_OUTPUT_TO_US by OUR_DELAYED_RETURN_TO_WALLET (.*) after 5 blocks')
12291229

12301230
wait_for(lambda: l1.rpc.listpeers(l2.info['id'])['peers'][0]['channels'][0]['status'] ==
12311231
['CHANNELD_NORMAL:Received error from peer: channel ALL: Internal error: Failing due to dev-fail command',
@@ -1430,11 +1430,13 @@ def test_onchain_timeout(self):
14301430
l2.daemon.wait_for_log(' to ONCHAIN')
14311431

14321432
# Wait for timeout.
1433-
l1.daemon.wait_for_log('Propose handling OUR_UNILATERAL/DELAYED_OUTPUT_TO_US by OUR_DELAYED_RETURN_TO_WALLET .* in 5 blocks')
1434-
bitcoind.generate_block(5)
1433+
l1.daemon.wait_for_logs(['Propose handling OUR_UNILATERAL/DELAYED_OUTPUT_TO_US by OUR_DELAYED_RETURN_TO_WALLET .* after 5 blocks',
1434+
'Propose handling OUR_UNILATERAL/OUR_HTLC by OUR_HTLC_TIMEOUT_TX .* after 6 blocks'])
1435+
bitcoind.generate_block(4)
14351436

1436-
# (l1 will also collect its to-self payment.)
14371437
l1.daemon.wait_for_log('sendrawtx exit 0')
1438+
1439+
bitcoind.generate_block(1)
14381440
l1.daemon.wait_for_log('sendrawtx exit 0')
14391441

14401442
# We use 3 blocks for "reasonable depth"
@@ -1456,6 +1458,7 @@ def test_onchain_timeout(self):
14561458

14571459
# Now, 100 blocks and l1 should be done.
14581460
bitcoind.generate_block(10)
1461+
sync_blockheight([l1])
14591462
assert not l1.daemon.is_in_log('onchaind complete, forgetting peer')
14601463
bitcoind.generate_block(1)
14611464
l1.daemon.wait_for_log('onchaind complete, forgetting peer')
@@ -1510,7 +1513,7 @@ def try_pay():
15101513
l2.daemon.wait_for_log('OUR_UNILATERAL/THEIR_HTLC')
15111514

15121515
# l2 should fulfill HTLC onchain, and spend to-us (any order)
1513-
l2.daemon.wait_for_log('Propose handling OUR_UNILATERAL/THEIR_HTLC by OUR_HTLC_SUCCESS_TX .* in 0 blocks')
1516+
l2.daemon.wait_for_log('Propose handling OUR_UNILATERAL/THEIR_HTLC by OUR_HTLC_SUCCESS_TX .* after 0 blocks')
15141517
l2.daemon.wait_for_log('sendrawtx exit 0')
15151518

15161519
# Payment should succeed.
@@ -1587,9 +1590,9 @@ def test_penalty_inhtlc(self):
15871590

15881591
# l2 should spend all of the outputs (except to-us).
15891592
# Could happen in any order, depending on commitment tx.
1590-
l2.daemon.wait_for_logs(['Propose handling THEIR_REVOKED_UNILATERAL/DELAYED_OUTPUT_TO_THEM by OUR_PENALTY_TX .* in 0 blocks',
1593+
l2.daemon.wait_for_logs(['Propose handling THEIR_REVOKED_UNILATERAL/DELAYED_OUTPUT_TO_THEM by OUR_PENALTY_TX .* after 0 blocks',
15911594
'sendrawtx exit 0',
1592-
'Propose handling THEIR_REVOKED_UNILATERAL/THEIR_HTLC by OUR_PENALTY_TX .* in 0 blocks',
1595+
'Propose handling THEIR_REVOKED_UNILATERAL/THEIR_HTLC by OUR_PENALTY_TX .* after 0 blocks',
15931596
'sendrawtx exit 0'])
15941597

15951598
# FIXME: test HTLC tx race!
@@ -1650,9 +1653,9 @@ def test_penalty_outhtlc(self):
16501653
# l2 should spend all of the outputs (except to-us).
16511654
# Could happen in any order, depending on commitment tx.
16521655
l2.daemon.wait_for_logs(['Ignoring output.*: THEIR_REVOKED_UNILATERAL/OUTPUT_TO_US',
1653-
'Propose handling THEIR_REVOKED_UNILATERAL/DELAYED_OUTPUT_TO_THEM by OUR_PENALTY_TX .* in 0 blocks',
1656+
'Propose handling THEIR_REVOKED_UNILATERAL/DELAYED_OUTPUT_TO_THEM by OUR_PENALTY_TX .* after 0 blocks',
16541657
'sendrawtx exit 0',
1655-
'Propose handling THEIR_REVOKED_UNILATERAL/OUR_HTLC by OUR_PENALTY_TX .* in 0 blocks',
1658+
'Propose handling THEIR_REVOKED_UNILATERAL/OUR_HTLC by OUR_PENALTY_TX .* after 0 blocks',
16561659
'sendrawtx exit 0'])
16571660

16581661
# FIXME: test HTLC tx race!
@@ -1695,7 +1698,7 @@ def test_onchain_feechange(self):
16951698
l2.daemon.wait_for_log(' to ONCHAIN')
16961699

16971700
# Wait for timeout.
1698-
l1.daemon.wait_for_log('Propose handling THEIR_UNILATERAL/OUR_HTLC by OUR_HTLC_TIMEOUT_TO_US .* in 6 blocks')
1701+
l1.daemon.wait_for_log('Propose handling THEIR_UNILATERAL/OUR_HTLC by OUR_HTLC_TIMEOUT_TO_US .* after 6 blocks')
16991702
bitcoind.generate_block(6)
17001703

17011704
l1.daemon.wait_for_log('sendrawtx exit 0')
@@ -1773,7 +1776,7 @@ def test_onchain_all_dust(self):
17731776
l2.daemon.wait_for_log(' to ONCHAIN')
17741777

17751778
# Wait for timeout.
1776-
l1.daemon.wait_for_log('Propose handling THEIR_UNILATERAL/OUR_HTLC by DONATING_TO_MINERS .* in 6 blocks')
1779+
l1.daemon.wait_for_log('Propose handling THEIR_UNILATERAL/OUR_HTLC by DONATING_TO_MINERS .* after 6 blocks')
17771780
bitcoind.generate_block(6)
17781781

17791782
l1.daemon.wait_for_log('sendrawtx exit 0')
@@ -1814,8 +1817,8 @@ def test_permfail_new_commit(self):
18141817
l1.daemon.wait_for_log('Their unilateral tx, new commit point')
18151818
l1.daemon.wait_for_log(' to ONCHAIN')
18161819
l2.daemon.wait_for_log(' to ONCHAIN')
1817-
l2.daemon.wait_for_log('Propose handling OUR_UNILATERAL/THEIR_HTLC by THEIR_HTLC_TIMEOUT_TO_THEM \\(IGNORING\\) in 6 blocks')
1818-
l1.daemon.wait_for_log('Propose handling THEIR_UNILATERAL/OUR_HTLC by OUR_HTLC_TIMEOUT_TO_US (.*) in 6 blocks')
1820+
l2.daemon.wait_for_log('Propose handling OUR_UNILATERAL/THEIR_HTLC by THEIR_HTLC_TIMEOUT_TO_THEM \\(IGNORING\\) after 6 blocks')
1821+
l1.daemon.wait_for_log('Propose handling THEIR_UNILATERAL/OUR_HTLC by OUR_HTLC_TIMEOUT_TO_US (.*) after 6 blocks')
18191822

18201823
# OK, time out HTLC.
18211824
bitcoind.generate_block(5)
@@ -1850,16 +1853,16 @@ def test_permfail_htlc_in(self):
18501853
l1.daemon.wait_for_log('Their unilateral tx, old commit point')
18511854
l1.daemon.wait_for_log(' to ONCHAIN')
18521855
l2.daemon.wait_for_log(' to ONCHAIN')
1853-
l2.daemon.wait_for_log('Propose handling OUR_UNILATERAL/THEIR_HTLC by THEIR_HTLC_TIMEOUT_TO_THEM \\(IGNORING\\) in 6 blocks')
1854-
l1.daemon.wait_for_log('Propose handling THEIR_UNILATERAL/OUR_HTLC by OUR_HTLC_TIMEOUT_TO_US (.*) in 6 blocks')
1856+
l2.daemon.wait_for_log('Propose handling OUR_UNILATERAL/THEIR_HTLC by THEIR_HTLC_TIMEOUT_TO_THEM \\(IGNORING\\) after 6 blocks')
1857+
l1.daemon.wait_for_log('Propose handling THEIR_UNILATERAL/OUR_HTLC by OUR_HTLC_TIMEOUT_TO_US (.*) after 6 blocks')
18551858
# l2 then gets preimage, uses it instead of ignoring
1856-
l2.daemon.wait_for_log('Propose handling OUR_UNILATERAL/THEIR_HTLC by OUR_HTLC_SUCCESS_TX .* in 0 blocks')
1859+
l2.daemon.wait_for_log('Propose handling OUR_UNILATERAL/THEIR_HTLC by OUR_HTLC_SUCCESS_TX .* after 0 blocks')
18571860
l2.daemon.wait_for_log('sendrawtx exit 0')
18581861
bitcoind.generate_block(1)
18591862

18601863
# OK, l1 sees l2 fulfill htlc.
18611864
l1.daemon.wait_for_log('THEIR_UNILATERAL/OUR_HTLC gave us preimage')
1862-
l2.daemon.wait_for_log('Propose handling OUR_HTLC_SUCCESS_TX/DELAYED_OUTPUT_TO_US by OUR_DELAYED_RETURN_TO_WALLET .* in 5 blocks')
1865+
l2.daemon.wait_for_log('Propose handling OUR_HTLC_SUCCESS_TX/DELAYED_OUTPUT_TO_US by OUR_DELAYED_RETURN_TO_WALLET .* after 5 blocks')
18631866
bitcoind.generate_block(6)
18641867

18651868
l2.daemon.wait_for_log('sendrawtx exit 0')
@@ -1892,12 +1895,12 @@ def test_permfail_htlc_out(self):
18921895
l1.daemon.wait_for_log('Their unilateral tx, old commit point')
18931896
l1.daemon.wait_for_log(' to ONCHAIN')
18941897
l2.daemon.wait_for_log(' to ONCHAIN')
1895-
l2.daemon.wait_for_logs(['Propose handling OUR_UNILATERAL/OUR_HTLC by OUR_HTLC_TIMEOUT_TX \\(.*\\) in 6 blocks',
1896-
'Propose handling OUR_UNILATERAL/DELAYED_OUTPUT_TO_US by OUR_DELAYED_RETURN_TO_WALLET .* in 5 blocks'])
1898+
l2.daemon.wait_for_logs(['Propose handling OUR_UNILATERAL/OUR_HTLC by OUR_HTLC_TIMEOUT_TX \\(.*\\) after 6 blocks',
1899+
'Propose handling OUR_UNILATERAL/DELAYED_OUTPUT_TO_US by OUR_DELAYED_RETURN_TO_WALLET .* after 5 blocks'])
18971900

1898-
l1.daemon.wait_for_log('Propose handling THEIR_UNILATERAL/THEIR_HTLC by THEIR_HTLC_TIMEOUT_TO_THEM \\(IGNORING\\) in 6 blocks')
1901+
l1.daemon.wait_for_log('Propose handling THEIR_UNILATERAL/THEIR_HTLC by THEIR_HTLC_TIMEOUT_TO_THEM \\(IGNORING\\) after 6 blocks')
18991902
# l1 then gets preimage, uses it instead of ignoring
1900-
l1.daemon.wait_for_log('Propose handling THEIR_UNILATERAL/THEIR_HTLC by THEIR_HTLC_FULFILL_TO_US .* in 0 blocks')
1903+
l1.daemon.wait_for_log('Propose handling THEIR_UNILATERAL/THEIR_HTLC by THEIR_HTLC_FULFILL_TO_US .* after 0 blocks')
19011904
l1.daemon.wait_for_log('sendrawtx exit 0')
19021905

19031906
# l2 sees l1 fulfill tx.
@@ -1906,19 +1909,22 @@ def test_permfail_htlc_out(self):
19061909
l2.daemon.wait_for_log('OUR_UNILATERAL/OUR_HTLC gave us preimage')
19071910
t.cancel()
19081911

1909-
# l2 can send OUR_DELAYED_RETURN_TO_WALLET after 4 more blocks.
1910-
bitcoind.generate_block(4)
1912+
# l2 can send OUR_DELAYED_RETURN_TO_WALLET after 3 more blocks.
1913+
bitcoind.generate_block(3)
19111914
l2.daemon.wait_for_log('Broadcasting OUR_DELAYED_RETURN_TO_WALLET .* to resolve OUR_UNILATERAL/DELAYED_OUTPUT_TO_US')
19121915
l2.daemon.wait_for_log('sendrawtx exit 0')
19131916

19141917
# Now, 100 blocks they should be done.
1915-
bitcoind.generate_block(94)
1918+
bitcoind.generate_block(95)
1919+
sync_blockheight([l1, l2])
19161920
assert not l1.daemon.is_in_log('onchaind complete, forgetting peer')
19171921
assert not l2.daemon.is_in_log('onchaind complete, forgetting peer')
19181922
bitcoind.generate_block(1)
19191923
l1.daemon.wait_for_log('onchaind complete, forgetting peer')
1924+
sync_blockheight([l2])
19201925
assert not l2.daemon.is_in_log('onchaind complete, forgetting peer')
1921-
bitcoind.generate_block(5)
1926+
bitcoind.generate_block(3)
1927+
sync_blockheight([l2])
19221928
assert not l2.daemon.is_in_log('onchaind complete, forgetting peer')
19231929
bitcoind.generate_block(1)
19241930
wait_forget_channels(l2)
@@ -2469,14 +2475,14 @@ def test_htlc_out_timeout(self):
24692475
l2.daemon.wait_for_log(' to ONCHAIN')
24702476

24712477
# L1 will timeout HTLC immediately
2472-
l1.daemon.wait_for_logs(['Propose handling OUR_UNILATERAL/OUR_HTLC by OUR_HTLC_TIMEOUT_TX .* in 0 blocks',
2473-
'Propose handling OUR_UNILATERAL/DELAYED_OUTPUT_TO_US by OUR_DELAYED_RETURN_TO_WALLET .* in 5 blocks'])
2478+
l1.daemon.wait_for_logs(['Propose handling OUR_UNILATERAL/OUR_HTLC by OUR_HTLC_TIMEOUT_TX .* after 0 blocks',
2479+
'Propose handling OUR_UNILATERAL/DELAYED_OUTPUT_TO_US by OUR_DELAYED_RETURN_TO_WALLET .* after 5 blocks'])
24742480

24752481
l1.daemon.wait_for_log('sendrawtx exit 0')
24762482
bitcoind.generate_block(1)
24772483

2478-
l1.daemon.wait_for_log('Propose handling OUR_HTLC_TIMEOUT_TX/DELAYED_OUTPUT_TO_US by OUR_DELAYED_RETURN_TO_WALLET .* in 5 blocks')
2479-
bitcoind.generate_block(5)
2484+
l1.daemon.wait_for_log('Propose handling OUR_HTLC_TIMEOUT_TX/DELAYED_OUTPUT_TO_US by OUR_DELAYED_RETURN_TO_WALLET .* after 5 blocks')
2485+
bitcoind.generate_block(4)
24802486
# It should now claim both the to-local and htlc-timeout-tx outputs.
24812487
l1.daemon.wait_for_logs(['Broadcasting OUR_DELAYED_RETURN_TO_WALLET',
24822488
'Broadcasting OUR_DELAYED_RETURN_TO_WALLET',
@@ -2524,11 +2530,11 @@ def test_htlc_in_timeout(self):
25242530
l1.daemon.wait_for_log(' to ONCHAIN')
25252531

25262532
# L2 will collect HTLC
2527-
l2.daemon.wait_for_log('Propose handling OUR_UNILATERAL/THEIR_HTLC by OUR_HTLC_SUCCESS_TX .* in 0 blocks')
2533+
l2.daemon.wait_for_log('Propose handling OUR_UNILATERAL/THEIR_HTLC by OUR_HTLC_SUCCESS_TX .* after 0 blocks')
25282534
l2.daemon.wait_for_log('sendrawtx exit 0')
25292535
bitcoind.generate_block(1)
2530-
l2.daemon.wait_for_log('Propose handling OUR_HTLC_SUCCESS_TX/DELAYED_OUTPUT_TO_US by OUR_DELAYED_RETURN_TO_WALLET .* in 5 blocks')
2531-
bitcoind.generate_block(5)
2536+
l2.daemon.wait_for_log('Propose handling OUR_HTLC_SUCCESS_TX/DELAYED_OUTPUT_TO_US by OUR_DELAYED_RETURN_TO_WALLET .* after 5 blocks')
2537+
bitcoind.generate_block(4)
25322538
l2.daemon.wait_for_log('Broadcasting OUR_DELAYED_RETURN_TO_WALLET')
25332539
l2.daemon.wait_for_log('sendrawtx exit 0')
25342540

0 commit comments

Comments
 (0)