Skip to content

AssertionError in test_peer_anchor_push: actual_feerate < expected_feerate + 2 #8493

@whitslack

Description

@whitslack

While running the integration test suite at fcd92fe (v25.09rc2), I encountered an AssertionError in test_peer_anchor_push:

______________________________________________________ test_peer_anchor_push _______________________________________________________
[gw2] linux -- Python 3.13.5 /usr/bin/python3.13

node_factory = <pyln.testing.utils.NodeFactory object at 0x7fc48bbce830>
bitcoind = <pyln.testing.utils.BitcoinD object at 0x7fc48cd25040>
executor = <concurrent.futures.thread.ThreadPoolExecutor object at 0x7fc48bc09590>
chainparams = {'bip173_prefix': 'bcrt', 'chain_hash': '06226e46111a0b59caaf126043eb5bbf28c34f3a5e332a1fc7b2b73cf188910f', 'elements': False, 'example_addr': 'bcrt1qeyyk6sl5pr49ycpqyckvmttus5ttj25pd0zpvg', ...}

    @unittest.skipIf(TEST_NETWORK != 'regtest', 'elementsd anchors not supportd')
    def test_peer_anchor_push(node_factory, bitcoind, executor, chainparams):
        """Test that we use anchor on peer's commit to CPFP tx"""
        l1, l2, l3 = node_factory.line_graph(3, opts=[{},
                                                      {'min-emergency-msat': 546000,
                                                       'dev-warn-on-overgrind': None,
                                                       'broken_log': 'overgrind: short signature length'},
                                                      {'disconnect': ['-WIRE_UPDATE_FULFILL_HTLC'],
                                                       'dev-warn-on-overgrind': None,
                                                       'broken_log': 'overgrind: short signature length'}],
                                             wait_for_announce=True)
    
        # We splinter l2's funds so it's forced to use more than one UTXO to push.
        fundsats = int(Millisatoshi(only_one(l2.rpc.listfunds()['outputs'])['amount_msat']).to_satoshi())
        OUTPUT_SAT = 10000
        NUM_OUTPUTS = 10
        psbt = l2.rpc.fundpsbt("all", "1000perkw", 1000)['psbt']
        # Pay 5k sats in fees.
        psbt = l2.rpc.addpsbtoutput(fundsats - OUTPUT_SAT * NUM_OUTPUTS - 5000, psbt, destination=l3.rpc.newaddr()['bech32'])['psbt']
        for _ in range(NUM_OUTPUTS):
            psbt = l2.rpc.addpsbtoutput(OUTPUT_SAT, psbt)['psbt']
        l2.rpc.sendpsbt(l2.rpc.signpsbt(psbt)['signed_psbt'])
        bitcoind.generate_block(1, wait_for_mempool=1)
        sync_blockheight(bitcoind, [l1, l2])
    
        # Make sure all amounts are below OUTPUT_SAT sats!
        assert [x for x in l2.rpc.listfunds()['outputs'] if x['amount_msat'] > Millisatoshi(str(OUTPUT_SAT) + "sat")] == []
    
        # Get HTLC stuck, so l2 has reason to push commitment tx.
        amt = 100_000_000
        sticky_inv = l3.rpc.invoice(amt, 'sticky', 'sticky')
        route = l1.rpc.getroute(l3.info['id'], amt, 1)['route']
        l1.rpc.sendpay(route, sticky_inv['payment_hash'], payment_secret=sticky_inv['payment_secret'])
        l3.daemon.wait_for_log('dev_disconnect: -WIRE_UPDATE_FULFILL_HTLC')
    
        # Make sure HTLC expiry is what we expect!
        l2.daemon.wait_for_log('Adding HTLC 0 amount=100000000msat cltv=119 gave CHANNEL_ERR_ADD_OK')
    
        # l3 drops to chain, but make sure it doesn't CPFP its own anchor.
        wait_for(lambda: only_one(l3.rpc.listpeerchannels(l2.info['id'])['channels'])['htlcs'] != [])
        closetx = l3.rpc.dev_sign_last_tx(l2.info['id'])['tx']
        l3.stop()
        # We don't care about l1 any more, either
        l1.stop()
    
        # We put l3's tx in the mempool, but won't mine it.
        bitcoind.rpc.sendrawtransaction(closetx)
    
        # We aim for feerate ~3750, so this won't mine l3's unilateral close.
        # HTLC's going to time out at block 120 (we give one block grace)
        for block in range(110, 120):
            bitcoind.generate_block(1, needfeerate=5000)
            assert bitcoind.rpc.getblockcount() == block
            sync_blockheight(bitcoind, [l2])
        assert only_one(l2.rpc.listpeerchannels(l3.info['id'])['channels'])['state'] == 'CHANNELD_NORMAL'
    
        # Drops to chain
        bitcoind.generate_block(1, needfeerate=5000)
        wait_for(lambda: only_one(l2.rpc.listpeerchannels(l3.info['id'])['channels'])['state'] == 'AWAITING_UNILATERAL')
    
        # But, l3's tx already there, and identical feerate will not RBF.
        l2.daemon.wait_for_log("rejecting replacement")
        wait_for(lambda: len(bitcoind.rpc.getrawmempool()) == 2)
    
        # As blocks pass, we will use anchor to boost l3's tx.
        for block, feerate in zip(range(120, 124), (12000, 13000, 14000, 15000)):
            l2.daemon.wait_for_log(fr"Worth fee [0-9]*sat for remote commit tx to get 100000000msat at block 125 \(\+{125 - block}\) at feerate {feerate}perkw")
            l2.daemon.wait_for_log("sendrawtx exit 0")
            # Check feerate for entire package (commitment tx + anchor) is ~ correct
            details = bitcoind.rpc.getrawmempool(True).values()
            print(f"mempool = {details}")
            total_weight = sum([d['weight'] for d in details])
            total_fees = sum([float(d['fees']['base']) * 100_000_000 for d in details])
            total_feerate_perkw = total_fees / total_weight * 1000
>           check_feerate([l3, l2], total_feerate_perkw, feerate)

NUM_OUTPUTS = 10
OUTPUT_SAT = 10000
_          = 9
amt        = 100000000
bitcoind   = <pyln.testing.utils.BitcoinD object at 0x7fc48cd25040>
block      = 122
chainparams = {'bip173_prefix': 'bcrt',
 'chain_hash': '06226e46111a0b59caaf126043eb5bbf28c34f3a5e332a1fc7b2b73cf188910f',
 'elements': False,
 'example_addr': 'bcrt1qeyyk6sl5pr49ycpqyckvmttus5ttj25pd0zpvg',
 'feeoutput': False,
 'name': 'regtest',
 'p2sh_prefix': '2'}
closetx    = '020000000001018a9a631eb62265f256a96eb27eec48550846c24187e102b408fdf93648365dc5000000000096b64c80044a01000000000000220020525df7a97bd0506c9ec41ee4e5f095e6e5316db01846a0a687404628017e88494a010000000000002200206db2ec9041ba3ccb6309dcad26015f32637e6869be09d3c3d3a1cb1439296f0ba086010000000000220020f1589e7be2586c9c6b9cb1fe5772d6f11857e7830dc9249a7599be75f95796fa0aa60d0000000000220020b1b561b95c1bccd50fb21bd417a95cabbc3efc351b1353063fe5e9f185d21c8a04004730440220571a475adede813edfee03ffbe38f75b36e5115106553c0af8ad5b48133ccd7d02203b4c0b849de8595b938f143eec099b80200d966162eca6d0df8499c687bf66ed0147304402204ff37916512b181a2915259f569a8ec6e69acadc03ab50161a584b8c4656c19202204b67ce65310f427e3dd4ff4ed2cb380b07bcc505ce485ccc38e297fcad627bf40147522102d595ae92b3544c3250fb772f214ad8d4c51425033740a5bcc357190add6d7e7a2102d6063d022691b2490ab454dee73a57c6ff5d308352b461ece69f3c284f2c241252ae6e14d920'
details    = dict_values([{'vsize': 278, 'weight': 1112, 'time': 1755933329, 'height': 109, 'descendantcount': 2, 'descendantsize': 574, 'ancestorcount': 1, 'ancestorsize': 278, 'wtxid': '327a02300c7194ef5a9f20919560438c8e1c9db17284f47b53f03b4f0d3c583c', 'fees': {'base': Decimal('0.00004866'), 'modified': Decimal('0.00004866'), 'ancestor': Decimal('0.00004866'), 'descendant': Decimal('0.00032116')}, 'depends': [], 'spentby': ['f02d1b4eae7ed99d38910a8f30951f951ef4e11b2e0c127269522744399e5353'], 'bip125-replaceable': True, 'unbroadcast': True}, {'vsize': 296, 'weight': 1181, 'time': 1755933349, 'height': 122, 'descendantcount': 1, 'descendantsize': 296, 'ancestorcount': 2, 'ancestorsize': 574, 'wtxid': '2410bd327ac794cbbffcf5bd2f76a1e44884b946c751fd19c439bf0708436f9b', 'fees': {'base': Decimal('0.00027250'), 'modified': Decimal('0.00027250'), 'ancestor': Decimal('0.00032116'), 'descendant': Decimal('0.00027250')}, 'depends': ['828983827f1b3b719b1ce75b7ec7a56f7daa18e42be87545732d020fa0e14b11'], 'spentby': [], 'bip125-replaceable': True, 'unbroadcast': True}])
executor   = <concurrent.futures.thread.ThreadPoolExecutor object at 0x7fc48bc09590>
feerate    = 14000
fundsats   = 995073
l1         = <fixtures.LightningNode object at 0x7fc48b7e98b0>
l2         = <fixtures.LightningNode object at 0x7fc48b7e9a90>
l3         = <fixtures.LightningNode object at 0x7fc48b7e99a0>
node_factory = <pyln.testing.utils.NodeFactory object at 0x7fc48bbce830>
psbt       = 'cHNidP8BAP0rAgIAAAABippjHrYiZfJWqW6yfuxIVQhGwkGH4QK0CP35Nkg2XcUBAAAAAP3///8MIgIAAAAAAAAiUSCF1yAl54/Qi7YRGfCYerAEH1BWGtpuEwxkU0PbjETCr9mUDQAAAAAAFgAUOMEIVMEeEMs3hkYBQ8ljyFMN+JEQJwAAAAAAACJRIPV1GF9vgclCLHzpDRqf0hTz8d2kDClYQ1CZ5SXGIEziECcAAAAAAAAiUSCdaGRYkqV5BvCnD/dRIwGuKSYxJtkyZ2N0tiKCJgOW+xAnAAAAAAAAIlEgNwuuIwPosXeSo07gStqGprK4T9dqARQ7q9iZx+2eg3IQJwAAAAAAACJRILb7AGAtPLMFlF7yyD354T/LgnsfwYMAIxeSjQhpw6zIECcAAAAAAAAiUSD9q3wB+ucMCOCx+aysyhEKUxIeddxUol51QkFvNCrq9xAnAAAAAAAAIlEgZN4lqgfDNQuNZjka8Vyvu41XB4CQw/SIPMT23PrDqCIQJwAAAAAAACJRIMYGbyd7ajUIOc+HNU5sJBDW9x0wiW+Hr4+otnPlf8ggECcAAAAAAAAiUSC6wjwy4j1VA2Tgc8gyMw9Gp6a5QeOzb+AzSTKvRtIKbxAnAAAAAAAAIlEgUgIcYdojsu2j1QAMbYEtDJsIjCN+0qUQq9lNjD98Qh0QJwAAAAAAACJRICtd0GE7blNPVy289DEbZubMi7B+KFko3bb6V5Hkc3h0bAAAAAABAIkCAAAAAafxku1twWP9vNGxoZ9z77wtWmAUIwmhKaIQtJwUU+D4AQAAAAD9////AkBCDwAAAAAAIgAghphligHvsAHhzE32qLbzrbRh+j5nk4X9quQAvXOZazIBLw8AAAAAACJRIIoWwBiVzpD7ezO+3hzrbjkNE+RTg2szQTtdbGCAN2FqZgAAAAEBKwEvDwAAAAAAIlEgihbAGJXOkPt7M77eHOtuOQ0T5FODazNBO11sYIA3YWoAAAAAAAAAAAAAAAAA'
route      = [{'amount_msat': 100001001,
  'channel': '103x2x0',
  'delay': 15,
  'direction': 1,
  'id': '022d223620a359a47ff7f7ac447c85c46c923da53389221a0054c11c1e3ca31d59',
  'style': 'tlv'},
 {'amount_msat': 100000000,
  'channel': '103x1x0',
  'delay': 9,
  'direction': 0,
  'id': '035d2b1192dfba134e10e540875d366ebc8bc353d5aa766b80c090b39c3a5d885d',
  'style': 'tlv'}]
sticky_inv = {'bolt11': 'lnbcrt1m1p52j65ssp5hykpkwyv56gw748epc3zz45kc5gevkg5ueckld5pwsg93wdjnjkspp5k6q7r4ey9cjsf0dtuvgjl8dhvxlfee9554vxjzzq7hcpgs44hs3qdq2wd6xjcmt0yxqyjw5qcqp9rzjqgkjyd3q5dv6gllh77kygly9c3kfy0d9xwyjyxsq2nq3c83u5vw4jqqqvuqqqqgqqqqqqqqpqqqqqzsqqc9qxpqysgqnlvs9cxzd6j90kg8kj7sh3yy22wga0swzfvqmqzjw2hmruky592h29jfcyjw5wzv8fwwza03hhm5wx98tuqn0fjlypuquwl3nf3f03qqp7rwl3',
 'created_index': 1,
 'expires_at': 1756538128,
 'payment_hash': 'b681e1d7242e2504bdabe3112f9db761be9ce4b4a558690840f5f01442b5bc22',
 'payment_secret': 'b92c1b388ca690ef54f90e22215696c511965914e6716fb681741058b9b29cad'}
total_feerate_perkw = 14006.105538595726
total_fees = 32116.0
total_weight = 2293

tests/test_closing.py:4064: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

nodes = [<fixtures.LightningNode object at 0x7fc48b7e99a0>, <fixtures.LightningNode object at 0x7fc48b7e9a90>]
actual_feerate = 14006.105538595726, expected_feerate = 14000

    def check_feerate(nodes, actual_feerate, expected_feerate):
        # Feerate can't be lower.
        assert actual_feerate > expected_feerate - 2
        if actual_feerate >= expected_feerate + 2:
            if any([did_short_sig(n) for n in nodes]):
                return
        # Use assert as it shows the actual values on failure
>       assert actual_feerate < expected_feerate + 2
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
E       AssertionError

actual_feerate = 14006.105538595726
expected_feerate = 14000
nodes      = [<fixtures.LightningNode object at 0x7fc48b7e99a0>,
 <fixtures.LightningNode object at 0x7fc48b7e9a90>]

tests/utils.py:684: AssertionError

It appears as though some piece of code somewhere had calculated the transaction fee as though the total weight of the transaction would be 2294, but then the the total weight ended up being 1 sipa less, and that difference caused the actual feerate to increase from 14000 sat/kw to ~14006.1 sat/kw, which exceeded the tolerance of check_feerate.

My wild guess is that a signature ended up being encoded using one fewer byte than would be typical, due to an unusually low-magnitude integer value. There's always a chance that this can happen (and in theory the encoded signature could even be multiple bytes shorter than typical in even more unlikely cases), so the test should be prepared to allow for it. Low probability does not mean zero probability. Test cases that exhibit probabilistic pass/fail behavior are a nuisance.

Metadata

Metadata

Assignees

Labels

No labels
No labels

Type

No type

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions