lndmanage icon indicating copy to clipboard operation
lndmanage copied to clipboard

channel disappears although tx has > 100 confirmations, possibly because peer disconnected before tx was confirmed

Open xmrk-btc opened this issue 2 years ago • 3 comments

See https://github.com/lightningnetwork/lnd/issues/6717 for more info. Opening issue here because it seems lndmanage openchannels sent funds to the address even though lnd logged unable to open channel to NodeKey...

xmrk-btc avatar Jul 13 '22 17:07 xmrk-btc

Hey, could you provide logs? Look into ~/.lndmanage/lndmanage.log. We can also communicate via email [email protected].

bitromortac avatar Jul 14 '22 13:07 bitromortac

Sure, here it is , didn't know lndmanage had its own logs. The lnd logs are in the linked lnd issue.


[2022-07-09 16:24:26 DEBUG] Using selector: EpollSelector
[2022-07-09 16:24:26 DEBUG] Node interface starting.
[2022-07-09 16:24:27 DEBUG] Connecting async rpcs.
[2022-07-09 16:24:27 DEBUG] Using AsyncIOEngine.POLLER as I/O engine
[2022-07-09 16:24:27 INFO] Cached graph is too old. Fetching new one.
[2022-07-09 16:24:46 DEBUG] Network.set_graph_and_edges 18.2389 s
[2022-07-09 16:24:51 DEBUG] Network.load_graph 23.8341 s
[2022-07-09 16:24:51 DEBUG] Network.load_liquidity_hints 0.0004 s
[2022-07-09 16:24:54 INFO] >>> Checking node pubkeys and address information.
[2022-07-09 16:24:54 INFO] >>> Connecting to channel peer candidates.
[2022-07-09 16:24:54 INFO]     trying to connect to 021cc722c97eaaeb7649e2a88301b2b0826060f3ebbd008bcd2d23ba2798dcc850@zul6k2zgi5tprvrk3kx3qo6lfch5ohir3ogg2henzvk3zq3znqkossyd.onion:9735
[2022-07-09 16:24:54 INFO]     > already connected
[2022-07-09 16:24:54 INFO] >>> Available UTXOs:
[2022-07-09 16:24:54 DEBUG]     d26aa7514db96f5ef90413d8cdadf11c1811a5fc7e0904d401197f33a24a7d12:0 9872936 sat
[2022-07-09 16:24:54 DEBUG]     Transaction size calculation for 1 (p2wkh) + 0 (np2wkh) inputs, 1channels, change False: 153 vbytes
[2022-07-09 16:24:54 INFO] >>> Used UTXOs:
[2022-07-09 16:24:54 INFO]     d26aa7514db96f5ef90413d8cdadf11c1811a5fc7e0904d401197f33a24a7d12:0 9872936 sat
[2022-07-09 16:24:54 INFO] >>> Channels will be public.
[2022-07-09 16:24:54 INFO]     Channel capacities: [9870476] sat (9870476 sat total).
[2022-07-09 16:24:54 INFO]     Fees: 2460 sat (16 sat/vbyte).
[2022-07-09 16:24:54 INFO]     Change: 0 sat.
[2022-07-09 16:24:54 INFO] >>> Asking peers for channel opening.
[2022-07-09 16:28:56 DEBUG]    > peer 021cc722c9...: got address: bc1q6chtu402x9yhj4upkussry4vy5vxhcu8rhncsarmdg0cajh3ndvsw57kvr
[2022-07-09 16:28:56 INFO] >>> Funding PSBT.
[2022-07-09 16:28:56 DEBUG]     given inputs: [UTXO(txid='d26aa7514db96f5ef90413d8cdadf11c1811a5fc7e0904d401197f33a24a7d12', output_index=0, amount_sat=9872936, transaction_type=<AddressType.WITNESS_PUBKEY_HASH
: 0>)]
[2022-07-09 16:28:56 DEBUG]     inputs (psbt): 1
[2022-07-09 16:28:56 DEBUG]     outputs (psbt): 1
[2022-07-09 16:28:56 DEBUG]     amounts (psbt): [9870476]
[2022-07-09 16:28:56 INFO] >>> WARNING: this is a relatively new feature, so please check the generated PSBT by the following command:
[2022-07-09 16:28:56 INFO] bitcoin-cli decodepsbt "cHNidP8BAF4CAAAAARJ9SqIzfxkB1AQJfvylERgc8a3N2BME+V5vuU1Rp2rSAAAAAAAAAAAAAYyclgAAAAAAIgAg1i6+VeoxSXlXgbchAZKsJRhr44cd54h0e2ofjsrxm1kAAAAAAAEA7AIAAAAAAQG8tvNRy39
zyQfwWFXaPcLCLWupt6xjVIfd8B59sxYCAgEAAAAAsQQAAAEoppYAAAAAABYAFLeKaqyyQc6J2uqITJW2+dU/4eVOA0cwRAIgeuLZ1nF0u1Ou5RqOALpX7lHjKAV6xsRzH90g4Clp9sQCIBMRT5mL5cnNm3scNMyxFexzEsj2PNYUCuBYrGoraY0bAQBNYyEDygsVzi/1jOyGyHc26
kETAJGxTNE7y2snUt29NP+Jj7tnArEEsnUhA0Pcgdn7Vb2P1dXf0m/xzxt+cqWBhksmgYROa9JcDfAnaKziVgsAAQEfKKaWAAAAAAAWABS3imqsskHOidrqiEyVtvnVP+HlTgEDBAEAAAAiBgMPR4Flxt2YfbazgdYDujepOCSygJJJ5BpFQrg7kNRjQxgAAAAAVAAAgAAAAIAAAAC
AAAAAAAwKAAAAAA=="
[2022-07-09 16:28:56 INFO] >>> You have 8 minutes from now to decide.

[2022-07-09 16:28:56 INFO] 
>>> Do you want to open the channel(s) (y/n)?
[2022-07-09 16:31:01 INFO] >>> Verifying PSBT.
[2022-07-09 16:31:02 INFO] >>> Signing PSBT.
[2022-07-09 16:31:02 INFO]     Signed transaction:
    02000000000101127d4aa2337f1901d404097efca511181cf1adcdd81304f95e6fb94d51a76ad2000000000000000000018c9c960000000000220020d62ebe55ea3149795781b7210192ac25186be3871de788747b6a1f8ecaf19b590247304402204108c15be67552ad6acb12651c472e3e03c9c839fad0e348d438b072e29df6bb022031755c5509b31b99bf515df02e198804ecbe6f2b1fae004e1ddb1383c2de44080121030f478165c6dd987db6b381d603ba37a93824b2809249e41a4542b83b90d4634300000000
[2022-07-09 16:31:02 INFO]     Signed psbt:
    cHNidP8BAF4CAAAAARJ9SqIzfxkB1AQJfvylERgc8a3N2BME+V5vuU1Rp2rSAAAAAAAAAAAAAYyclgAAAAAAIgAg1i6+VeoxSXlXgbchAZKsJRhr44cd54h0e2ofjsrxm1kAAAAAAAEA7AIAAAAAAQG8tvNRy39zyQfwWFXaPcLCLWupt6xjVIfd8B59sxYCAgEAAAAAsQQAAAEoppYAAAAAABYAFLeKaqyyQc6J2uqITJW2+dU/4eVOA0cwRAIgeuLZ1nF0u1Ou5RqOALpX7lHjKAV6xsRzH90g4Clp9sQCIBMRT5mL5cnNm3scNMyxFexzEsj2PNYUCuBYrGoraY0bAQBNYyEDygsVzi/1jOyGyHc26kETAJGxTNE7y2snUt29NP+Jj7tnArEEsnUhA0Pcgdn7Vb2P1dXf0m/xzxt+cqWBhksmgYROa9JcDfAnaKziVgsAAQEfKKaWAAAAAAAWABS3imqsskHOidrqiEyVtvnVP+HlTgEIawJHMEQCIEEIwVvmdVKtassSZRxHLj4Dycg5+tDjSNQ4sHLinfa7AiAxdVxVCbMbmb9RXfAuGYgE7L5vKx+uAE4d2xODwt5ECAEhAw9HgWXG3Zh9trOB1gO6N6k4JLKAkknkGkVCuDuQ1GNDAAA=
[2022-07-09 16:31:02 INFO]     Final transaction size: 203 bytes
[2022-07-09 16:31:02 INFO] >>> Publishing transaction.
[2022-07-09 16:31:03 DEBUG] Disconnecting rpcs.
[2022-07-09 16:24:27 DEBUG] Using AsyncIOEngine.POLLER as I/O engine
[2022-07-09 16:24:27 INFO] Cached graph is too old. Fetching new one.
[2022-07-09 16:24:46 DEBUG] Network.set_graph_and_edges 18.2389 s
[2022-07-09 16:24:51 DEBUG] Network.load_graph 23.8341 s
[2022-07-09 16:24:51 DEBUG] Network.load_liquidity_hints 0.0004 s
[2022-07-09 16:24:54 INFO] >>> Checking node pubkeys and address information.
[2022-07-09 16:24:54 INFO] >>> Connecting to channel peer candidates.
[2022-07-09 16:24:54 INFO]     trying to connect to 021cc722c97eaaeb7649e2a88301b2b0826060f3ebbd008bcd2d23ba2798dcc850@zul6k2zgi5tprvrk3kx3qo6lfch5ohir3ogg2henzvk3zq3znqkossyd.onion:9735
[2022-07-09 16:24:54 INFO]     > already connected
[2022-07-09 16:24:54 INFO] >>> Available UTXOs:
[2022-07-09 16:24:54 DEBUG]     d26aa7514db96f5ef90413d8cdadf11c1811a5fc7e0904d401197f33a24a7d12:0 9872936 sat
[2022-07-09 16:24:54 DEBUG]     Transaction size calculation for 1 (p2wkh) + 0 (np2wkh) inputs, 1channels, change False: 153 vbytes
[2022-07-09 16:24:54 INFO] >>> Used UTXOs:
[2022-07-09 16:24:54 INFO]     d26aa7514db96f5ef90413d8cdadf11c1811a5fc7e0904d401197f33a24a7d12:0 9872936 sat
[2022-07-09 16:24:54 INFO] >>> Channels will be public.
[2022-07-09 16:24:54 INFO]     Channel capacities: [9870476] sat (9870476 sat total).
[2022-07-09 16:24:54 INFO]     Fees: 2460 sat (16 sat/vbyte).
[2022-07-09 16:24:54 INFO]     Change: 0 sat.
[2022-07-09 16:24:54 INFO] >>> Asking peers for channel opening.
[2022-07-09 16:28:56 DEBUG]    > peer 021cc722c9...: got address: bc1q6chtu402x9yhj4upkussry4vy5vxhcu8rhncsarmdg0cajh3ndvsw57kvr
[2022-07-09 16:28:56 INFO] >>> Funding PSBT.
[2022-07-09 16:28:56 DEBUG]     given inputs: [UTXO(txid='d26aa7514db96f5ef90413d8cdadf11c1811a5fc7e0904d401197f33a24a7d12', output_index=0, amount_sat=9872936, transaction_type=<AddressType.WITNESS_PUBKEY_HASH
: 0>)]
[2022-07-09 16:28:56 DEBUG]     inputs (psbt): 1
[2022-07-09 16:28:56 DEBUG]     outputs (psbt): 1
[2022-07-09 16:28:56 DEBUG]     amounts (psbt): [9870476]
[2022-07-09 16:28:56 INFO] >>> WARNING: this is a relatively new feature, so please check the generated PSBT by the following command:
[2022-07-09 16:28:56 INFO] bitcoin-cli decodepsbt "cHNidP8BAF4CAAAAARJ9SqIzfxkB1AQJfvylERgc8a3N2BME+V5vuU1Rp2rSAAAAAAAAAAAAAYyclgAAAAAAIgAg1i6+VeoxSXlXgbchAZKsJRhr44cd54h0e2ofjsrxm1kAAAAAAAEA7AIAAAAAAQG8tvNRy39
zyQfwWFXaPcLCLWupt6xjVIfd8B59sxYCAgEAAAAAsQQAAAEoppYAAAAAABYAFLeKaqyyQc6J2uqITJW2+dU/4eVOA0cwRAIgeuLZ1nF0u1Ou5RqOALpX7lHjKAV6xsRzH90g4Clp9sQCIBMRT5mL5cnNm3scNMyxFexzEsj2PNYUCuBYrGoraY0bAQBNYyEDygsVzi/1jOyGyHc26
kETAJGxTNE7y2snUt29NP+Jj7tnArEEsnUhA0Pcgdn7Vb2P1dXf0m/xzxt+cqWBhksmgYROa9JcDfAnaKziVgsAAQEfKKaWAAAAAAAWABS3imqsskHOidrqiEyVtvnVP+HlTgEDBAEAAAAiBgMPR4Flxt2YfbazgdYDujepOCSygJJJ5BpFQrg7kNRjQxgAAAAAVAAAgAAAAIAAAAC
AAAAAAAwKAAAAAA=="
[2022-07-09 16:28:56 INFO] >>> You have 8 minutes from now to decide.

[2022-07-09 16:28:56 INFO] 
>>> Do you want to open the channel(s) (y/n)?
[2022-07-09 16:31:01 INFO] >>> Verifying PSBT.
[2022-07-09 16:31:02 INFO] >>> Signing PSBT.
[2022-07-09 16:31:02 INFO]     Signed transaction:
    02000000000101127d4aa2337f1901d404097efca511181cf1adcdd81304f95e6fb94d51a76ad2000000000000000000018c9c960000000000220020d62ebe55ea3149795781b7210192ac25186be3871de788747b6a1f8ecaf19b590247304402204108c15be67552ad6acb12651c472e3e03c9c839fad0e348d438b072e29df6bb022031755c5509b31b99bf515df02e198804ecbe6f2b1fae004e1ddb1383c2de44080121030f478165c6dd987db6b381d603ba37a93824b2809249e41a4542b83b90d4634300000000
[2022-07-09 16:31:02 INFO]     Signed psbt:
    cHNidP8BAF4CAAAAARJ9SqIzfxkB1AQJfvylERgc8a3N2BME+V5vuU1Rp2rSAAAAAAAAAAAAAYyclgAAAAAAIgAg1i6+VeoxSXlXgbchAZKsJRhr44cd54h0e2ofjsrxm1kAAAAAAAEA7AIAAAAAAQG8tvNRy39zyQfwWFXaPcLCLWupt6xjVIfd8B59sxYCAgEAAAAAsQQAAAEoppYAAAAAABYAFLeKaqyyQc6J2uqITJW2+dU/4eVOA0cwRAIgeuLZ1nF0u1Ou5RqOALpX7lHjKAV6xsRzH90g4Clp9sQCIBMRT5mL5cnNm3scNMyxFexzEsj2PNYUCuBYrGoraY0bAQBNYyEDygsVzi/1jOyGyHc26kETAJGxTNE7y2snUt29NP+Jj7tnArEEsnUhA0Pcgdn7Vb2P1dXf0m/xzxt+cqWBhksmgYROa9JcDfAnaKziVgsAAQEfKKaWAAAAAAAWABS3imqsskHOidrqiEyVtvnVP+HlTgEIawJHMEQCIEEIwVvmdVKtassSZRxHLj4Dycg5+tDjSNQ4sHLinfa7AiAxdVxVCbMbmb9RXfAuGYgE7L5vKx+uAE4d2xODwt5ECAEhAw9HgWXG3Zh9trOB1gO6N6k4JLKAkknkGkVCuDuQ1GNDAAA=
[2022-07-09 16:31:02 INFO]     Final transaction size: 203 bytes
[2022-07-09 16:31:02 INFO] >>> Publishing transaction.
[2022-07-09 16:31:03 DEBUG] Disconnecting rpcs.

But note that lnd fails to open the channel at 16:38:28, when lndmanage already ended. (Not sure what it means, not going to speculate.)

xmrk-btc avatar Jul 14 '22 18:07 xmrk-btc

Thank you, the issue seems to be that the peer disconnected during the funding flow and that was not caught. I am replacing the internal channel funding of lndmanage with a wrapper around the batchopen api of lnd in #137.

bitromortac avatar Jul 14 '22 18:07 bitromortac

Fixed by #137.

bitromortac avatar Mar 09 '23 08:03 bitromortac