search

get10101 / 10101

10101 (Ten-Ten-One): Self-custodial derivative trading at your fingertips.
https://10101.finance
MIT License
130 stars 23 forks source link

Force close channel: Cannot accept HTLC that would put our balance under counterparty-announced channel reserve value #1773

Closed holzeis closed 9 months ago

holzeis commented 11 months ago

A user channel got force closed after making a payment of 2k sats, while having an open position.

[I] TIME: 2023-12-20T23:50:47.045868Z Sending payment of 2,000 sats
[I] TIME: 2023-12-20T23:50:47.355523Z r: lightning::routing::router: Got route: path 0:
 node_id: 022ae8dbec1caa4dac93f07f2ebf5ad7a5dd08d375b79f11095e81b065c2155156, short_channel_id: 855653142975021056, fee_msat: 2001, cltv_expiry_delta: 42
 node_id: 03864ef025fde8fb587d989186ce6a4a186895ee44a926bfc370e2c366597a3f8f, short_channel_id: 896209728828014593, fee_msat: 1998, cltv_expiry_delta: 144
 node_id: 02d96eadea3d780104449aca5c93461ce67c1564e2e1d73225fa67dd3b997a6018, short_channel_id: 884888057714835456, fee_msat: 2000000, cltv_expiry_delta: 180
 blinded_tail: None

[D] TIME: 2023-12-20T23:50:47.358672Z r: lightning::ln::channel: Pushing new outbound HTLC with hash c67e3c500a657c2e394273b4b40ef12653b0bb6a124ed7bf93366b82c02f3cfe for 2003999 msat to peer 
[I] TIME: 2023-12-20T23:50:47.360711Z r: lightning::chain::channelmonitor: Applying update to monitor ff22f815bf06713bfe463a178b3add5dc0ae3698aed12cd88450157ddfd00ad1, bringing update_id from 25 to 26 with 1 change(s). 
[D] TIME: 2023-12-20T23:50:47.367697Z r: lightning::chain::chainmonitor: Persistence of ChannelMonitorUpdate for channel ff22f815bf06713bfe463a178b3add5dc0ae3698aed12cd88450157ddfd00ad1 completed 
[D] TIME: 2023-12-20T23:50:47.368948Z r: lightning::ln::channel: Restored monitor updating in channel ff22f815bf06713bfe463a178b3add5dc0ae3698aed12cd88450157ddfd00ad1 resulting in a commitment update and no RAA, with RAA first 
[I] TIME: 2023-12-20T23:50:47.369261Z r: lightning::ln::outbound_payment: Sending payment with id c67e3c500a657c2e394273b4b40ef12653b0bb6a124ed7bf93366b82c02f3cfe and hash c67e3c500a657c2e394273b4b40ef12653b0bb6a124ed7bf93366b82c02f3cfe returned Ok(()) 
[I] TIME: 2023-12-20T23:50:47.369365Z r: Initiated payment amount_msat: 2000000,payment_id: c67e3c500a657c2e394273b4b40ef12653b0bb6a124ed7bf93366b82c02f3cfe,peer_id: 02d96eadea3d780104449aca5c93461ce67c1564e2e1d73225fa67dd3b997a6018
[D] TIME: 2023-12-20T23:50:47.369423Z r: Inserting payment payment_hash: PaymentHash([198, 126, 60, 80, 10, 101, 124, 46, 57, 66, 115, 180, 180, 14, 241, 38, 83, 176, 187, 106, 18, 78, 215, 191, 147, 54, 107, 130, 192, 47, 60, 254])
[D] TIME: 2023-12-20T23:50:47.372909Z r: lightning::ln::peer_handler: Handling UpdateHTLCs event in peer_handler for node 022ae8dbec1caa4dac93f07f2ebf5ad7a5dd08d375b79f11095e81b065c2155156 with 1 adds, 0 fulfills, 0 fails for channel ff22f815bf06713bfe463a178b3add5dc0ae3698aed12cd88450157ddfd00ad1 
[D] TIME: 2023-12-20T23:50:47.398722Z r: lightning::ln::peer_handler: Got Err message from 022ae8dbec1caa4dac93f07f2ebf5ad7a5dd08d375b79f11095e81b065c2155156: Cannot accept HTLC that would put our balance under counterparty-announced channel reserve value 
[E] TIME: 2023-12-20T23:50:47.399066Z r: lightning::ln::channelmanager: Force-closing channel ff22f815bf06713bfe463a178b3add5dc0ae3698aed12cd88450157ddfd00ad1 
[D] TIME: 2023-12-20T23:50:47.399471Z r: lightning::ln::channelmanager: Channel balance for ff22f815bf06713bfe463a178b3add5dc0ae3698aed12cd88450157ddfd00ad1 before closure balance_msat=57708001, inbound_capacity_msat=4790000, outbound_capacity_msat=55708001 
[D] TIME: 2023-12-20T23:50:47.399733Z r: lightning::ln::channelmanager: Finishing force-closure of channel with 0 HTLCs to fail 
[I] TIME: 2023-12-20T23:50:47.399890Z r: lightning::chain::channelmonitor: Applying force close update to monitor ff22f815bf06713bfe463a178b3add5dc0ae3698aed12cd88450157ddfd00ad1 with 1 change(s). 
[D] TIME: 2023-12-20T23:50:47.400131Z r: lightning::chain::channelmonitor: Getting signed latest holder commitment transaction! 
[I] TIME: 2023-12-20T23:50:47.400244Z r: lightning::chain::channelmonitor: Broadcasting local commitment tx with txid 6d2de21811a88d8747a0c89465e69395d58ffa8ef6f41bb021e9e3a515bb98bc 
[I] TIME: 2023-12-20T23:50:47.400674Z r: Successfully triggered payment 
[I] TIME: 2023-12-20T23:50:47.400823Z r: Broadcasting transaction raw_tx: 020000000001014a17dce1019243a91a9e446e32417af2335830f8ebcb144a84d9a36d2de53c22000000000020121d800140e90000000000002200202cbbc4be00d80a6cbfc9779b7ad1a84cd5eb54e0a1e7a346b4c21d231bdb9a040400473044022036826e49849ade39bf1eb03abbbcce41a490585302ad8d76cadb82fbc0083cc902206241eab45ab8429625c24160c46289b15abb8366032a9128353d5f788fa0e7850147304402207625f48a13ed6032bae31ed2451bf80a96885c3cad59e7691026ad71cb6c8c1902204ba3eca161547e19873a31ea9bc3f482f83ae8381a892d9a8ec168a52737a36501475221024377f15a0e64bedfc2bcd8203c61e972d555f66cd7e0f8a6fec6aa706e3990a02103fe6724cb360a4b022856e2f0373b0b2e82d733b539e0dc803a2b41d522cd9a8d52ae27cf9b20,txid: 6d2de21811a88d8747a0c89465e69395d58ffa8ef6f41bb021e9e3a515bb98bc
[D] TIME: 2023-12-20T23:50:47.401512Z r: Upserting transaction transaction: Transaction { txid: 6d2de21811a88d8747a0c89465e69395d58ffa8ef6f41bb021e9e3a515bb98bc, fee: 0, created_at: 2023-12-20 23:50:47.40055206 +00:00:00, updated_at: 2023-12-20 23:50:47.40055206 +00:00:00, raw: "020000000001014a17dce1019243a91a9e446e32417af2335830f8ebcb144a84d9a36d2de53c22000000000020121d800140e90000000000002200202cbbc4be00d80a6cbfc9779b7ad1a84cd5eb54e0a1e7a346b4c21d231bdb9a040400473044022036826e49849ade39bf1eb03abbbcce41a490585302ad8d76cadb82fbc0083cc902206241eab45ab8429625c24160c46289b15abb8366032a9128353d5f788fa0e7850147304402207625f48a13ed6032bae31ed2451bf80a96885c3cad59e7691026ad71cb6c8c1902204ba3eca161547e19873a31ea9bc3f482f83ae8381a892d9a8ec168a52737a36501475221024377f15a0e64bedfc2bcd8203c61e972d555f66cd7e0f8a6fec6aa706e3990a02103fe6724cb360a4b022856e2f0373b0b2e82d733b539e0dc803a2b41d522cd9a8d52ae27cf9b20" }
holzeis commented 11 months ago

It also appears that the broadcasted transaction was invalid.

[I] TIME: 2023-12-21T18:38:48.591341Z r: lightning::chain::channelmonitor: Broadcasting local commitment tx with txid 6d2de21811a88d8747a0c89465e69395d58ffa8ef6f41bb021e9e3a515bb98bc 
[I] TIME: 2023-12-21T18:38:48.591387Z r: Broadcasting transaction raw_tx: 020000000001014a17dce1019243a91a9e446e32417af2335830f8ebcb144a84d9a36d2de53c22000000000020121d800140e90000000000002200202cbbc4be00d80a6cbfc9779b7ad1a84cd5eb54e0a1e7a346b4c21d231bdb9a040400473044022036826e49849ade39bf1eb03abbbcce41a490585302ad8d76cadb82fbc0083cc902206241eab45ab8429625c24160c46289b15abb8366032a9128353d5f788fa0e7850147304402207429bef4fde3ae58eef5f2ee42abb4681c5812b7b0bf432208d3b602744d7ce202202b4a5109995c9c4b38fc32e86c9bd0bb0f8eb96cb8fd991168c1e0198e97cbd101475221024377f15a0e64bedfc2bcd8203c61e972d555f66cd7e0f8a6fec6aa706e3990a02103fe6724cb360a4b022856e2f0373b0b2e82d733b539e0dc803a2b41d522cd9a8d52ae27cf9b20,txid: 6d2de21811a88d8747a0c89465e69395d58ffa8ef6f41bb021e9e3a515bb98bc
[I] TIME: 2023-12-21T18:38:48.591475Z r: Lightning node started with node ID 03cac634c37e8e0cb46d614adcc074d37a79da7880060eb7162c1ad35eae3a013c@0.0.0.0:39421 
[D] TIME: 2023-12-21T18:38:48.591506Z r: Response status code 200 OK 
[E] TIME: 2023-12-21T18:38:48.617441Z r: Error when broadcasting transaction: Failed to broadcast transaction 6d2de21811a88d8747a0c89465e69395d58ffa8ef6f41bb021e9e3a515bb98bc. Esplora client error: HttpResponse(400) txid: 6d2de21811a88d8747a0c89465e69395d58ffa8ef6f41bb021e9e3a515bb98bc

Don't know exactly whats invalid there (maybe it was also just instantly rejected because of too little fees), I presume there is only one output as the remaining balance of the coordinator was just dust respectively will go in full to the miner.

@luckysori wdyt?

bonomat commented 11 months ago

Don't know exactly whats invalid there (maybe it was also just instantly rejected because of too little fees), I presume there is only one output as the remaining balance of the coordinator was just dust respectively will go in full to the miner.

Unfortunately the transaction is invalid: it's witness stack is empty and the transaction it is spending from does not exist.

{
    "addresses": [
        "bc1q9jauf0sqmq9xe07fw7dh45dgfn27k48q58n6x345cgwjxx7mngzqpwuhgd"
    ],
    "block_height": -1,
    "block_index": -1,
    "confirmations": 0,
    "double_spend": false,
    "fees": 0,
    "hash": "6d2de21811a88d8747a0c89465e69395d58ffa8ef6f41bb021e9e3a515bb98bc",
    "inputs": [
        {
            "age": 0,
            "output_index": 0,
            "prev_hash": "223ce52d6da3d9844a14cbebf8305833f27a41326e449e1aa9439201e1dc174a",
            "script_type": "empty",
            "sequence": 2149388832
        }
    ],
    "lock_time": 547082023,
    "opt_in_rbf": true,
    "outputs": [
        {
            "addresses": [
                "bc1q9jauf0sqmq9xe07fw7dh45dgfn27k48q58n6x345cgwjxx7mngzqpwuhgd"
            ],
            "script": "00202cbbc4be00d80a6cbfc9779b7ad1a84cd5eb54e0a1e7a346b4c21d231bdb9a04",
            "script_type": "pay-to-witness-script-hash",
            "value": 59712
        }
    ],
    "preference": "low",
    "received": "2023-12-22T17:46:24.484969197Z",
    "relayed_by": "54.87.50.188",
    "size": 314,
    "total": 59712,
    "ver": 2,
    "vin_sz": 1,
    "vout_sz": 1,
    "vsize": 149
}
holzeis commented 11 months ago

Don't know exactly whats invalid there (maybe it was also just instantly rejected because of too little fees), I presume there is only one output as the remaining balance of the coordinator was just dust respectively will go in full to the miner.

Unfortunately the transaction is invalid: it's witness stack is empty and the transaction it is spending from does not exist.

The witness stack is empty because we don't log it. But I guess if the transaction it is spending from does not exist, it may mean that we might have failed to publish the split transaction 🤔.

holzeis commented 11 months ago

This issue is also the reason for another force closed channel. https://github.com/get10101/meta/issues/266

[I] TIME: 2023-12-16T09:17:29.564026Z Sending payment of 4,000 sats
[T] TIME: 2023-12-16T09:17:29.573959Z r: lightning::routing::router: Searching for a route from payer 02e30a37a724f877630ed17e6da5a4d87655b5461959f4d7a8f53998742b9f5110 to payee node id 021294fff596e497ad2902cd5f19673e9020953d90625d68c22e91b51a45c032d3 with MPP and 1 first hops overriding the network graph with a fee limit of 18446744073709551615 msat 
[T] TIME: 2023-12-16T09:17:29.574252Z r: lightning::routing::router: Building path from payee node id 021294fff596e497ad2902cd5f19673e9020953d90625d68c22e91b51a45c032d3 to payer 02e30a37a724f877630ed17e6da5a4d87655b5461959f4d7a8f53998742b9f5110 for value 4000000 msat. 
[T] TIME: 2023-12-16T09:17:29.575631Z r: lightning::routing::router: Starting main path collection loop with 49 nodes pre-filled from first/last hops. 
[T] TIME: 2023-12-16T09:17:29.778056Z r: lightning::routing::router: Found a path back to us from the target with 3 hops contributing up to 4000000 msat: 
 [
    PathBuildingHop {
        node_id: NodeId(022ae8dbec1caa4dac93f07f2ebf5ad7a5dd08d375b79f11095e81b065c2155156),
        short_channel_id: Some(
            896385650821890049,
        ),
        total_fee_msat: 6002,
        next_hops_fee_msat: 6002,
        hop_use_fee_msat: 0,
        total_fee_msat - (next_hops_fee_msat + hop_use_fee_msat): 0,
        path_penalty_msat: 4078,
        path_htlc_minimum_msat: 1001,
        cltv_expiry_delta: 0,
    },
    PathBuildingHop {
        node_id: NodeId(02f1a8c87607f415c8f22c00593002775941dea48869ce23096af27b0cfdcc0b69),
        short_channel_id: Some(
            896220724049608705,
        ),
        total_fee_msat: 6002,
        next_hops_fee_msat: 2000,
        hop_use_fee_msat: 4002,
        total_fee_msat - (next_hops_fee_msat + hop_use_fee_msat): 0,
        path_penalty_msat: 3548,
        path_htlc_minimum_msat: 1001,
        cltv_expiry_delta: 42,
    },
    PathBuildingHop {
        node_id: NodeId(021294fff596e497ad2902cd5f19673e9020953d90625d68c22e91b51a45c032d3),
        short_channel_id: Some(
            831361632601374720,
        ),
        total_fee_msat: 2000,
        next_hops_fee_msat: 0,
        hop_use_fee_msat: 0,
        total_fee_msat - (next_hops_fee_msat + hop_use_fee_msat): 2000,
        path_penalty_msat: 1774,
        path_htlc_minimum_msat: 1000,
        cltv_expiry_delta: 144,
    },
] 
[T] TIME: 2023-12-16T09:17:29.778370Z r: lightning::routing::router: Disabling route candidate SCID 896220724049608705 for future path building iterations to avoid duplicates. 
[T] TIME: 2023-12-16T09:17:29.778470Z r: lightning::routing::router: Collected our payment amount on the first pass, but running again to collect extra paths with a potentially higher value to meet htlc_minimum_msat limit. 
[T] TIME: 2023-12-16T09:17:29.778641Z r: lightning::routing::router: Starting main path collection loop with 49 nodes pre-filled from first/last hops. 
[T] TIME: 2023-12-16T09:17:30.030624Z r: lightning::routing::router: Found a path back to us from the target with 4 hops contributing up to 980985 msat: 
 [
    PathBuildingHop {
        node_id: NodeId(022ae8dbec1caa4dac93f07f2ebf5ad7a5dd08d375b79f11095e81b065c2155156),
        short_channel_id: Some(
            896385650821890049,
        ),
        total_fee_msat: 13013,
        next_hops_fee_msat: 13013,
        hop_use_fee_msat: 0,
        total_fee_msat - (next_hops_fee_msat + hop_use_fee_msat): 0,
        path_penalty_msat: 6192,
        path_htlc_minimum_msat: 2002,
        cltv_expiry_delta: 0,
    },
    PathBuildingHop {
        node_id: NodeId(03c157946cc1cd376b929e36006e645fae490b1b1d4156b40db804e01b4bda48cd),
        short_channel_id: Some(
            902281232132145155,
        ),
        total_fee_msat: 13013,
        next_hops_fee_msat: 1012,
        hop_use_fee_msat: 12001,
        total_fee_msat - (next_hops_fee_msat + hop_use_fee_msat): 0,
        path_penalty_msat: 5685,
        path_htlc_minimum_msat: 2002,
        cltv_expiry_delta: 42,
    },
    PathBuildingHop {
        node_id: NodeId(031015a7839468a3c266d662d5bb21ea4cea24226936e2864a7ca4f2c3939836e0),
        short_channel_id: Some(
            894923300219191297,
        ),
        total_fee_msat: 1012,
        next_hops_fee_msat: 1012,
        hop_use_fee_msat: 0,
        total_fee_msat - (next_hops_fee_msat + hop_use_fee_msat): 0,
        path_penalty_msat: 3790,
        path_htlc_minimum_msat: 2000,
        cltv_expiry_delta: 144,
    },
    PathBuildingHop {
        node_id: NodeId(021294fff596e497ad2902cd5f19673e9020953d90625d68c22e91b51a45c032d3),
        short_channel_id: Some(
            895631385755058176,
        ),
        total_fee_msat: 1012,
        next_hops_fee_msat: 0,
        hop_use_fee_msat: 0,
        total_fee_msat - (next_hops_fee_msat + hop_use_fee_msat): 1012,
        path_penalty_msat: 1895,
        path_htlc_minimum_msat: 2000,
        cltv_expiry_delta: 40,
    },
] 
[T] TIME: 2023-12-16T09:17:30.030856Z r: lightning::routing::router: Disabling route candidate SCID 894923300219191297 for future path building iterations to avoid duplicates. 
[T] TIME: 2023-12-16T09:17:30.031019Z r: lightning::routing::router: Starting main path collection loop with 49 nodes pre-filled from first/last hops. 
[T] TIME: 2023-12-16T09:17:30.285109Z r: lightning::routing::router: Ignoring first hop with SCID 896385650821890049 due to insufficient value contribution. 
[T] TIME: 2023-12-16T09:17:30.296976Z r: lightning::routing::router: Starting main path collection loop with 49 nodes pre-filled from first/last hops. 
[T] TIME: 2023-12-16T09:17:30.549617Z r: lightning::routing::router: Ignoring first hop with SCID 896385650821890049 due to insufficient value contribution. 
[T] TIME: 2023-12-16T09:17:30.563176Z r: lightning::routing::router: Have now collected 4980985 msat (seeking 12000000 msat) in paths. Last path loop did not find a new path. 
[T] TIME: 2023-12-16T09:17:30.563458Z r: lightning::routing::router: Ignored 1128 candidate hops due to insufficient value contribution, 0 due to path length limit, 623 due to CLTV delta limit, 0 due to previous payment failure, 1271 due to htlc_minimum_msat limit, 383 to avoid overpaying, 0 due to maximum total fee limit. Total: 3405 ignored candidates. 
[I] TIME: 2023-12-16T09:17:30.563558Z r: lightning::routing::router: Got route: path 0:
 node_id: 022ae8dbec1caa4dac93f07f2ebf5ad7a5dd08d375b79f11095e81b065c2155156, short_channel_id: 896385650821890049, fee_msat: 4002, cltv_expiry_delta: 42
 node_id: 02f1a8c87607f415c8f22c00593002775941dea48869ce23096af27b0cfdcc0b69, short_channel_id: 896220724049608705, fee_msat: 2000, cltv_expiry_delta: 144
 node_id: 021294fff596e497ad2902cd5f19673e9020953d90625d68c22e91b51a45c032d3, short_channel_id: 831361632601374720, fee_msat: 4000000, cltv_expiry_delta: 18
 blinded_tail: None

[T] TIME: 2023-12-16T09:17:30.565631Z r: lightning::ln::channelmanager: Attempting to send payment with payment hash 48d1a94f327d02fa23bf872dc8362f811252de5e59b2816f1961f3f7a6279b38 along path with next hop 896385650821890049 
[D] TIME: 2023-12-16T09:17:30.570272Z r: lightning::ln::channel: Pushing new outbound HTLC with hash 48d1a94f327d02fa23bf872dc8362f811252de5e59b2816f1961f3f7a6279b38 for 4006002 msat to peer 
[T] TIME: 2023-12-16T09:17:30.570509Z r: lightning::ln::channel: Updating HTLC state for a newly-sent commitment_signed... 
[T] TIME: 2023-12-16T09:17:30.571756Z r: lightning::ln::channel: Building commitment transaction number 281474976710643 (really 12 xor 175745500781987) for channel 503569597755e6d0689e78beeb269b2b73ebb4b939204da893263979f5c577e6 for remote, generated by us with fee 81014... 
[T] TIME: 2023-12-16T09:17:30.571927Z r: lightning::ln::channel:    ...including outbound LocalAnnounced dust HTLC 0 (hash 48d1a94f327d02fa23bf872dc8362f811252de5e59b2816f1961f3f7a6279b38) with value 4006002 
[T] TIME: 2023-12-16T09:17:30.571990Z r: lightning::ln::channel:    ...including to_local output with value 152197 
[T] TIME: 2023-12-16T09:17:30.573115Z r: lightning::chain::chainmonitor: Updating ChannelMonitor for channel 503569597755e6d0689e78beeb269b2b73ebb4b939204da893263979f5c577e6 
[I] TIME: 2023-12-16T09:17:30.573307Z r: lightning::chain::channelmonitor: Applying update to monitor 503569597755e6d0689e78beeb269b2b73ebb4b939204da893263979f5c577e6, bringing update_id from 28 to 29 with 1 change(s). 
[T] TIME: 2023-12-16T09:17:30.573391Z r: lightning::chain::channelmonitor: Updating ChannelMonitor with latest counterparty commitment transaction info 
[T] TIME: 2023-12-16T09:17:30.573661Z r: lightning::chain::channelmonitor: Tracking new counterparty commitment transaction with txid 460c67a8ffa9c9f882f40267dc19f9e8e4961784225ebaf584e0a53cd22ec586 at commitment number 281474976710643 with 1 HTLC outputs 
[D] TIME: 2023-12-16T09:17:30.582372Z r: lightning::chain::chainmonitor: Persistence of ChannelMonitorUpdate for channel 503569597755e6d0689e78beeb269b2b73ebb4b939204da893263979f5c577e6 completed 
[T] TIME: 2023-12-16T09:17:30.583066Z r: lightning::ln::channel: Creating an announcement_signatures message for channel 503569597755e6d0689e78beeb269b2b73ebb4b939204da893263979f5c577e6 
[T] TIME: 2023-12-16T09:17:30.583341Z r: lightning::ln::channel: Ignore : Channel is not available for public announcements 
[T] TIME: 2023-12-16T09:17:30.583536Z r: lightning::ln::channel: Regenerated latest commitment update in channel 503569597755e6d0689e78beeb269b2b73ebb4b939204da893263979f5c577e6 with 1 update_adds, 0 update_fulfills, 0 update_fails, and 0 update_fail_malformeds 
[T] TIME: 2023-12-16T09:17:30.584108Z r: lightning::ln::channel: Building commitment transaction number 281474976710643 (really 12 xor 175745500781987) for channel 503569597755e6d0689e78beeb269b2b73ebb4b939204da893263979f5c577e6 for remote, generated by us with fee 81014... 
[T] TIME: 2023-12-16T09:17:30.584328Z r: lightning::ln::channel:    ...including outbound LocalAnnounced dust HTLC 0 (hash 48d1a94f327d02fa23bf872dc8362f811252de5e59b2816f1961f3f7a6279b38) with value 4006002 
[T] TIME: 2023-12-16T09:17:30.584511Z r: lightning::ln::channel:    ...including to_local output with value 152197 
[T] TIME: 2023-12-16T09:17:30.584672Z r: lightning::ln::channel: Signed remote commitment tx 02000000012dcc569825cd54fc34b988b4dab5f69e4b0084ba6267b48a6183b8a545481a470000000000f0d69f8001855202000000000016001487da9290b1ea234e93f72b73e09166b2f44162a1af1d2520 (txid 460c67a8ffa9c9f882f40267dc19f9e8e4961784225ebaf584e0a53cd22ec586) with redeemscript 47522102ae73e2d2d5463b4f6496de97bbe984ce5e8b9b2b1cfafc7d0c00957ea85621092103e31415ba823511c6fbb39ee7e9219c2247bd83451dbec59264645e928c4ff10552ae with value 183372 -> 30d60e9e4e45617edee0a9f84191920a99c000fc3e8bfb7f8e6b0e21f9bd17f63c37d7493779333bdcc0d4bebec02a160ff3a8089df59b32740f9cca2a98592c in channel 503569597755e6d0689e78beeb269b2b73ebb4b939204da893263979f5c577e6 
[D] TIME: 2023-12-16T09:17:30.584953Z r: lightning::ln::channel: Restored monitor updating in channel 503569597755e6d0689e78beeb269b2b73ebb4b939204da893263979f5c577e6 resulting in a commitment update and no RAA, with RAA first 
[T] TIME: 2023-12-16T09:17:30.585373Z r: lightning::ln::channelmanager: Handling channel resumption for channel 503569597755e6d0689e78beeb269b2b73ebb4b939204da893263979f5c577e6 with no RAA, a commitment update, 0 pending forwards, not broadcasting funding, without channel ready, without announcement 
[I] TIME: 2023-12-16T09:17:30.585592Z r: lightning::ln::outbound_payment: Sending payment with id 48d1a94f327d02fa23bf872dc8362f811252de5e59b2816f1961f3f7a6279b38 and hash 48d1a94f327d02fa23bf872dc8362f811252de5e59b2816f1961f3f7a6279b38 returned Ok(()) 
[T] TIME: 2023-12-16T09:17:30.585768Z r: lightning_background_processor: Persisting ChannelManager... 
[I] TIME: 2023-12-16T09:17:30.586231Z r: Initiated payment amount_msat: 4000000,payment_id: 48d1a94f327d02fa23bf872dc8362f811252de5e59b2816f1961f3f7a6279b38,peer_id: 021294fff596e497ad2902cd5f19673e9020953d90625d68c22e91b51a45c032d3
[D] TIME: 2023-12-16T09:17:30.586439Z r: Inserting payment payment_hash: PaymentHash([72, 209, 169, 79, 50, 125, 2, 250, 35, 191, 135, 45, 200, 54, 47, 129, 18, 82, 222, 94, 89, 178, 129, 111, 25, 97, 243, 247, 166, 39, 155, 56])
[I] TIME: 2023-12-16T09:17:30.588749Z r: Successfully triggered payment 
[T] TIME: 2023-12-16T09:17:30.591645Z r: lightning_background_processor: Done persisting ChannelManager. 
[D] TIME: 2023-12-16T09:17:30.592227Z r: lightning::ln::peer_handler: Handling UpdateHTLCs event in peer_handler for node 022ae8dbec1caa4dac93f07f2ebf5ad7a5dd08d375b79f11095e81b065c2155156 with 1 adds, 0 fulfills, 0 fails for channel 503569597755e6d0689e78beeb269b2b73ebb4b939204da893263979f5c577e6 
[D] TIME: 2023-12-16T09:17:30.838940Z r: lightning::ln::peer_handler: Got Err message from 022ae8dbec1caa4dac93f07f2ebf5ad7a5dd08d375b79f11095e81b065c2155156: Cannot accept HTLC that would put our balance under counterparty-announced channel reserve value 
[E] TIME: 2023-12-16T09:17:30.839315Z r: lightning::ln::channelmanager: Force-closing channel 503569597755e6d0689e78beeb269b2b73ebb4b939204da893263979f5c577e6 
[D] TIME: 2023-12-16T09:17:30.839542Z r: Response status code 200 OK 
[D] TIME: 2023-12-16T09:17:30.839683Z r: lightning::ln::channelmanager: Channel balance for 503569597755e6d0689e78beeb269b2b73ebb4b939204da893263979f5c577e6 before closure balance_msat=152197998, inbound_capacity_msat=4568000, outbound_capacity_msat=129597998 
[D] TIME: 2023-12-16T09:17:30.839800Z r: Successfully uploaded backup of ln/monitors/e777c5f579392693a84d2039b9b4eb732b9b26ebbe789e68d0e6557759693550_1. 
[D] TIME: 2023-12-16T09:17:30.839905Z r: lightning::ln::channelmanager: Finishing force-closure of channel with 0 HTLCs to fail 
[T] TIME: 2023-12-16T09:17:30.840132Z r: lightning::chain::chainmonitor: Updating ChannelMonitor for channel 503569597755e6d0689e78beeb269b2b73ebb4b939204da893263979f5c577e6 
[I] TIME: 2023-12-16T09:17:30.840260Z r: lightning::chain::channelmonitor: Applying force close update to monitor 503569597755e6d0689e78beeb269b2b73ebb4b939204da893263979f5c577e6 with 1 change(s). 
[T] TIME: 2023-12-16T09:17:30.840389Z r: lightning::chain::channelmonitor: Updating ChannelMonitor: channel force closed, should broadcast: true 
[D] TIME: 2023-12-16T09:17:30.840495Z r: Response status code 200 OK 
[D] TIME: 2023-12-16T09:17:30.840597Z r: Successfully uploaded backup of ln/manager. 
[D] TIME: 2023-12-16T09:17:30.840705Z r: lightning::chain::channelmonitor: Getting signed latest holder commitment transaction! 
[I] TIME: 2023-12-16T09:17:30.841180Z r: lightning::chain::channelmonitor: Broadcasting local commitment tx with txid a045101fcffb36a2dbbe75419172e7f860dcb0e990ca7fa3c694029175aceabc 
[I] TIME: 2023-12-16T09:17:30.841492Z r: Broadcasting transaction raw_tx: 020000000001012dcc569825cd54fc34b988b4dab5f69e4b0084ba6267b48a6183b8a545481a470000000000f0d69f80012c620200000000002200208cf1b2beb7f52fa9c3079decc7f0a4b02122de8d2de60eb08950661caa1abe39040047304402206f40e1fa12bc5b01161594b6246bf15139fd7edeed91aadaf2a3555d6fd3f47b02200895a6c8f759410597d9920f4988f0ca2f76e29125563bc8c3a46282be94373a0147304402207f524ffc8b1ed851fc7b59fe0f7da42d029514b435607f58a81d67b9f28d5c8902201116341a2040f33371ef60a58ca18d72ba39e5ea6e982b499757c760a27cd5ad0147522102ae73e2d2d5463b4f6496de97bbe984ce5e8b9b2b1cfafc7d0c00957ea85621092103e31415ba823511c6fbb39ee7e9219c2247bd83451dbec59264645e928c4ff10552aea81d2520,txid: a045101fcffb36a2dbbe75419172e7f860dcb0e990ca7fa3c694029175aceabc
[D] TIME: 2023-12-16T09:17:30.841842Z r: Upserting transaction transaction: Transaction { txid: a045101fcffb36a2dbbe75419172e7f860dcb0e990ca7fa3c694029175aceabc, fee: 0, created_at: 2023-12-16 9:17:30.841354897 +00:00:00, updated_at: 2023-12-16 9:17:30.841354897 +00:00:00, raw: "020000000001012dcc569825cd54fc34b988b4dab5f69e4b0084ba6267b48a6183b8a545481a470000000000f0d69f80012c620200000000002200208cf1b2beb7f52fa9c3079decc7f0a4b02122de8d2de60eb08950661caa1abe39040047304402206f40e1fa12bc5b01161594b6246bf15139fd7edeed91aadaf2a3555d6fd3f47b02200895a6c8f759410597d9920f4988f0ca2f76e29125563bc8c3a46282be94373a0147304402207f524ffc8b1ed851fc7b59fe0f7da42d029514b435607f58a81d67b9f28d5c8902201116341a2040f33371ef60a58ca18d72ba39e5ea6e982b499757c760a27cd5ad0147522102ae73e2d2d5463b4f6496de97bbe984ce5e8b9b2b1cfafc7d0c00957ea85621092103e31415ba823511c6fbb39ee7e9219c2247bd83451dbec59264645e928c4ff10552aea81d2520" }
[E] TIME: 2023-12-16T09:17:30.933697Z r: Error when broadcasting transaction: Failed to broadcast transaction a045101fcffb36a2dbbe75419172e7f860dcb0e990ca7fa3c694029175aceabc. Esplora client error: HttpResponse(400) txid: a045101fcffb36a2dbbe75419172e7f860dcb0e990ca7fa3c694029175aceabc
bonomat commented 11 months ago

The witness stack is empty because we don't log it.

It should be included in the serialized transaction here: https://github.com/get10101/10101/blob/e1c56f766a02f09923390d58372811630f8956c8/crates/ln-dlc-node/src/ldk_node_wallet.rs#L279

bonomat commented 11 months ago

But I guess if the transaction it is spending from does not exist, it may mean that we might have failed to publish the split transaction 🤔.

Imho we tried to publish a wrong transaction which was never signed. Maybe this is a lightning commitment transaction which spends from an outdated split transaction?

bonomat commented 11 months ago

Did we ask LDK if this is expected by design? I.e. if we would not accept an HTLC we force-close the channel? Sounds a bit harsh to me. 

[D] TIME: 2023-12-16T09:17:30.838940Z r: lightning::ln::peer_handler: Got Err message from 022ae8dbec1caa4dac93f07f2ebf5ad7a5dd08d375b79f11095e81b065c2155156: Cannot accept HTLC that would put our balance under counterparty-announced channel reserve value 
[E] TIME: 2023-12-16T09:17:30.839315Z r: lightning::ln::channelmanager: Force-closing channel 503569597755e6d0689e78beeb269b2b73ebb4b939204da893263979f5c577e6 
[
TheBlueMatt commented 10 months ago

I'd answered this privately, but, no, generally you should never see this. We do need to force-close the channel, but its really an indication there's a bug on the HTLC-sender's side.

I didn't dig too much into the 10101 code, but is it possible update_channel_funding_txo got called, reducing the channel's amount, then the LSP closed on the next update because the channel was already below the limit? Alternatively, is it possible the LSP and the client had slightly different amounts in the latest channel state?