search

ACINQ / phoenixd

https://phoenix.acinq.co/server
Apache License 2.0
117 stars 15 forks source link

Disconnect occurs during OpenDualFundedChannel, fee credit is lost and new channel opens fail [JVM, Windows, Testnet] #103

Closed remyers closed 3 months ago

remyers commented 3 months ago

This issue occurs with --chain=testnet on a Windows 11 system using the final 0.3.3 JVM release.

I can reproduce this issue by sending 20,000 sats to my node's bolt-12 address twice. The first time I get a fee credit for 20,000 sats, the second time an OpenDualFundedChannel flow begins but aborts after sending AcceptDualFundedChannel.

It seems like when phoenixd aborts while doing an OpenDualFundedChannel fee credits are lost. If I don't do any more payments, phoenixd will continue to try to open channels that also fail.

Either the ACINQ testnet node is out of funding liquidity, or there's a bug in the OpenDualFundedChannel flow. Even if it's just a liquidity issue, we need to handle that edge case better and not zero out fee credits until the new channel is successfully opened.

I can send a zip file with my .phoenix directory if that would help.

2024-08-26 08:22:17 Info: (fr.acinq.lightning.io.Peer) received CurrentFeeCredit(amount=20000 sat)
    remoteNodeId: 03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134
    connectionId: 1724660537497
2024-08-26 08:22:17 Info: (fr.acinq.lightning.io.Peer) current fee credit: 20000 sat
    remoteNodeId: 03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134
    connectionId: 1724660537497
2024-08-26 08:22:17 Info: (fr.acinq.lightning.io.Peer) received OpenDualFundedChannel(chainHash=43497fd7f826957108f4a30fd9cec3aeba79972084e90ead01ea330900000000, temporaryChannelId=16102a5e130749b69b57b464d1b3673e4b835e13a78d9388b52503759257b232, fundingFeerate=1250 sat/kw, commitmentFeerate=2500 sat/kw, fundingAmount=15172 sat, dustLimit=546 sat, maxHtlcValueInFlightMsat=2100000000000000000, htlcMinimum=1 msat, toSelfDelay=CltvExpiryDelta(720), maxAcceptedHtlcs=30, lockTime=2874800, fundingPubkey=03d61b49cf6a9c8d09bb768c20365adbabd3b8bacd744e75cb60fc231249c1f055, revocationBasepoint=02ee3deac65589cc45d09ae8bfdcaecc0395581cc0229ccb257f1c41eeed11b4af, paymentBasepoint=03f9463e442f9649823bd3abc71e1ed38db38a4e27bc0af00ef41e0f39277db53e, delayedPaymentBasepoint=03271dd137e46dd4a941630cbbbca122e1d2165fd7bddfe12ce21247bcc9baba96, htlcBasepoint=03b96adc1ea4414b102a5deca8e9cbe17ff20f2d76c64121b5056ac0f93669f97a, firstPerCommitmentPoint=024045502844879e04d0e918b32d30128b295c5ec581f5f4aec54f9f9e425191d6, secondPerCommitmentPoint=02a178eaa179065a955ec81015f6c481e4be11acf1031ad101e8765d5b912d8380, channelFlags=0, tlvStream=TlvStream(records=[ChannelTypeTlv(channelType=anchor_outputs_zero_reserve), fr.acinq.lightning.wire.ChannelTlv$RequireConfirmedInputsTlv@35f829fa, OriginTlv(origin=PayToOpenOrigin(paymentHash=a562b1a23660c520eb9ae07d940931adc048e0b279f9d3af574d6ef267e506ed, serviceFee=0 msat, miningFee=0 sat, amount=22000 msat)), PushAmountTlv(amount=22000 msat)], unknown=[]))
    remoteNodeId: 03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134
    connectionId: 1724660537497
    temporaryChannelId: 16102a5e130749b69b57b464d1b3673e4b835e13a78d9388b52503759257b232
2024-08-26 08:22:18 Info: (fr.acinq.lightning.channel.states.ChannelState) WaitForInit -> WaitForOpenChannel
    remoteNodeId: 03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134
    state: WaitForInit
2024-08-26 08:22:18 Info: (fr.acinq.lightning.io.Peer) on-chain fees: Feerates(minimum=1 sat/byte, slow=2 sat/byte, medium=675 sat/byte, fast=846 sat/byte, fastest=1086 sat/byte)
    remoteNodeId: 03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134
2024-08-26 08:22:18 Info: (fr.acinq.lightning.channel.states.ChannelState) WaitForOpenChannel -> WaitForFundingCreated
    remoteNodeId: 03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134
    state: WaitForOpenChannel
    temporaryChannelId: 16102a5e130749b69b57b464d1b3673e4b835e13a78d9388b52503759257b232
2024-08-26 08:22:18 Info: (fr.acinq.lightning.io.Peer) switching channel id from 16102a5e130749b69b57b464d1b3673e4b835e13a78d9388b52503759257b232 to fc91f5c8fc969aeaab2e7368e578a6d4e38c5529ec2acefc2cf42bbc120d05ea
    remoteNodeId: 03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134
    channelId: fc91f5c8fc969aeaab2e7368e578a6d4e38c5529ec2acefc2cf42bbc120d05ea
2024-08-26 08:22:18 Info: (fr.acinq.lightning.io.Peer) sending AcceptDualFundedChannel(temporaryChannelId=16102a5e130749b69b57b464d1b3673e4b835e13a78d9388b52503759257b232, fundingAmount=0 sat, dustLimit=546 sat, maxHtlcValueInFlightMsat=20000000000, htlcMinimum=1000 msat, minimumDepth=0, toSelfDelay=CltvExpiryDelta(2016), maxAcceptedHtlcs=6, fundingPubkey=02560f2d10ea9ed4a31a28d45e6fabc45c95c0003be9b343504920daa0697ca138, revocationBasepoint=03ee2fac3dbdcc15fc7e29c51fed18a290b62234cf53167f0038269617f270137f, paymentBasepoint=02e763f89ac5138523d20a03a11404b0e9ef10489abe1ea99cc42c55489b7153ba, delayedPaymentBasepoint=03ea8e0d80edd3ed2a1872a4519f6c16fce9ba58ad9117595759d7297b4cb47e20, htlcBasepoint=03f2425aa96577542cbb4bde21778d8a8c9077d0c53cf5bb03d14ddbcca6d7df8f, firstPerCommitmentPoint=038e4c32cedd81627f8feefcf8232d5819e4a39ee4c8af54f7c5bfeeb38762b9e9, secondPerCommitmentPoint=031ca321e791674f0224070e89815abd9e51bcf0c502abda2a09c1251e5727aca7, tlvStream=TlvStream(records=[ChannelTypeTlv(channelType=anchor_outputs_zero_reserve)], unknown=[]))
    remoteNodeId: 03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134
    connectionId: 1724660537497
2024-08-26 08:22:18 Info: (fr.acinq.lightning.io.Peer) received TxAbort(channelId=fc91f5c8fc969aeaab2e7368e578a6d4e38c5529ec2acefc2cf42bbc120d05ea, data=6368616e6e656c2066756e64696e67206572726f72, tlvs=TlvStream(records=[], unknown=[]))
    remoteNodeId: 03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134
    connectionId: 1724660537497
    channelId: fc91f5c8fc969aeaab2e7368e578a6d4e38c5529ec2acefc2cf42bbc120d05ea
2024-08-26 08:22:18 Warn: (fr.acinq.lightning.channel.states.ChannelState) our peer aborted the dual funding flow: ascii='channel funding error' bin=6368616e6e656c2066756e64696e67206572726f72
    remoteNodeId: 03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134
    state: WaitForFundingCreated
    channelId: fc91f5c8fc969aeaab2e7368e578a6d4e38c5529ec2acefc2cf42bbc120d05ea
2024-08-26 08:22:18 Info: (fr.acinq.lightning.channel.states.ChannelState) WaitForFundingCreated -> Aborted
    remoteNodeId: 03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134
    state: WaitForFundingCreated
    channelId: fc91f5c8fc969aeaab2e7368e578a6d4e38c5529ec2acefc2cf42bbc120d05ea
2024-08-26 08:22:18 Info: (fr.acinq.lightning.io.Peer) sending TxAbort(channelId=fc91f5c8fc969aeaab2e7368e578a6d4e38c5529ec2acefc2cf42bbc120d05ea, data=6475616c2066756e64696e672061626f727465643a207265717565737465642062792070656572, tlvs=TlvStream(records=[], unknown=[]))
    remoteNodeId: 03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134
    connectionId: 1724660537497
2024-08-26 08:22:47 Info: (fr.acinq.lightning.io.Peer) checking for timed out htlcs for channels: 
    remoteNodeId: 03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134
2024-08-26 08:23:18 Warn: (fr.acinq.lightning.io.Peer) TCP receive: Connection closed
    remoteNodeId: 03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134
    connectionId: 1724660537497
2024-08-26 08:23:18 Warn: (fr.acinq.lightning.io.Peer) closing TCP socket: Connection closed
    remoteNodeId: 03933884aaf1d6b108397e5efe5c86bcf2d8ca8d2f700eda99db9214fc2712b134
remyers commented 3 months ago

The full log and output from listincomingpayments and listchannels: logs-and-payments.zip

t-bast commented 3 months ago

This should be fixed with the updated fee-credit protocol: https://github.com/ACINQ/lightning-kmp/pull/660 I don't think we should work in fixing this for the current fee-credit protocol since we want to replace it soon.

remyers commented 3 months ago

Will close this and test again with the new fee-credit protocol when it's ready.