search

lightningnetwork / lnd

Lightning Network Daemon ⚡️
MIT License
7.69k stars 2.08k forks source link

Resuming an intercepted HTLC through a recently opened zero-conf channel #6879

Open dangeross opened 2 years ago

dangeross commented 2 years ago

Background

I am building a service that receives an out-of-band channel request and, when a user hops an invoice through our node it holds the intercepted HTLC, creates a zero-conf channel, then resumes the HTLC to the user. But I’m having issues determining when is the best point to resume the HTLC for it to go through successfully. Locally testing it seems waiting 10 seconds after the ACTIVE_CHANNEL event works, but on mainnet the period is too short and errors with link fail: UNKNOWN_NEXT_PEER.

Is there a specific event after the PENDING_OPEN/OPEN/ACTIVE events where I know for sure the HTLC will go through? I am assuming once the channel is ACTIVE then it should in theory be ready for business.

Your environment

Steps to reproduce

Alice: Receiver of a new channel Bob: Payer of invoice

  1. Alice constructs an invoice with a route hop (chan_id is a random id) through the LSP node.
  2. Alice tells LSP the payment hash.
  3. Bob pays Alice's invoice.
  4. LSP intercepts the HTLC with the payment hash to Alice.
  5. LSP holds the HTLC and opens a zero-conf private channel to Alice (payment amount * 1.25 funded with PSBT flow).
  6. LND signals channel is PENDING_OPEN, OPEN then finally ACTIVE.
  7. LSP waits 10 seconds then resumes the intercepted HTLC.
  8. LND signals HTLC has a link fail: UNKNOWN_NEXT_PEER
  9. Bob's payment fails

Logs are included below. LND and LSP notate the LND node and LSP application.

LND: 2022-08-31 20:45:08.752 [DBG] HSWC: Interceptor connected
LND: 2022-08-31 20:45:08.769 [INF] INVC: New invoice subscription client: id=3
LND: 2022-08-31 20:45:09.553 [DBG] HSWC: ChannelLink(c957c171ce969e2aee5fe3205f91c6c82a5e749b70133a72947b0496a785c170:0): forwarding 1 packets to switch: replay=false
LSP: 2022/08/31 20:45:09 HTLC Intercept
LSP: 2022/08/31 20:45:09 IncomingAmountMsat: 50000000
LSP: 2022/08/31 20:45:09 IncomingCircuitKey.ChanId: 819214228179320832
LSP: 2022/08/31 20:45:09 IncomingCircuitKey.HtlcId: 1213
LSP: 2022/08/31 20:45:09 IncomingExpiry: 752100
LSP: 2022/08/31 20:45:09 OnionBlob: 00035c851ce5f61f589efe9e3a8114f4ba6f9d33a9b72c8884990b2663f33419eb404319094cbdb6f03d2d69024b9dbf81ccdf4176fe2188ddd6927244c6e55e5f56be222e5b9b7b0ac9d59eee638069e3e94e320525fc>
LSP: 2022/08/31 20:45:09 OutgoingAmountMsat: 50000000
LSP: 2022/08/31 20:45:09 OutgoingExpiry: 752100
LSP: 2022/08/31 20:45:09 OutgoingRequestedChanId: 2590498713548019166
LSP: 2022/08/31 20:45:09 PaymentHash: 5e63e43c608b2c5a5b80f608b793421366a3f5066d1a21a5d0ed3d994853b40c
LSP: 2022/08/31 20:45:09 PSBT thread locked
LSP: 2022/08/31 20:45:09 Psbt Fund open channel request
LND: 2022-08-31 20:45:09.639 [DBG] RPCS: [openchannel] request to NodeKey(03ec54855663fec338e007e05734821189850f375c720a093bfce7cc611e03a220) allocation(us=62500, them=0)
LND: 2022-08-31 20:45:09.646 [DBG] RPCS: [openchannel]: using fee of 2264 sat/kw for funding tx
LND: 2022-08-31 20:45:09.647 [INF] FNDG: Initiating fundingRequest(local_amt=0.000625 BTC (subtract_fees=false), push_amt=0 mSAT, chain_hash=000000000019d6689c085ae165831e934ff763ae46a2a6c172b3f1b60a8ce26f, pee>
LND: 2022-08-31 20:45:10.224 [INF] FNDG: Target commit tx sat/kw for pendingID(9a6c5e94f18cdd59db0577acd6e036a72740dd046a2897ac23f34cdadc22d5de): 2667
LND: 2022-08-31 20:45:10.225 [INF] FNDG: Dust limit for pendingID(9a6c5e94f18cdd59db0577acd6e036a72740dd046a2897ac23f34cdadc22d5de): 0.00000354 BTC
LND: 2022-08-31 20:45:10.225 [INF] FNDG: Starting funding workflow with 24.134.172.181:42308 for pending_id(9a6c5e94f18cdd59db0577acd6e036a72740dd046a2897ac23f34cdadc22d5de), committype=anchors-zero-fee-second->
LND: 2022-08-31 20:45:10.530 [INF] FNDG: Recv'd fundingResponse for pending_id(9a6c5e94f18cdd59db0577acd6e036a72740dd046a2897ac23f34cdadc22d5de)
LND: 2022-08-31 20:45:10.531 [INF] FNDG: pendingChan(9a6c5e94f18cdd59db0577acd6e036a72740dd046a2897ac23f34cdadc22d5de): remote party proposes num_confs=0, csv_delay=144
LSP: 2022/08/31 20:45:10 PSBT thread unlocked
LSP: 2022/08/31 20:45:10 PSBT Fund timeout (2022-08-31 20:45:10.545595324 +0000 UTC m=+125.495887113) set for 2022-08-31 20:45:40.533967 +0000 UTC: 29.988372393s
LSP: 2022/08/31 20:45:40 PSBT thread locked
LND: 2022-08-31 20:45:41.265 [DBG] RPCS: Verifying PSBT for pending_id=9a6c5e94f18cdd59db0577acd6e036a72740dd046a2897ac23f34cdadc22d5de
LND: 2022-08-31 20:45:41.352 [DBG] RPCS: Finalizing PSBT for pending_id=9a6c5e94f18cdd59db0577acd6e036a72740dd046a2897ac23f34cdadc22d5de
LND: 2022-08-31 20:45:41.355 [INF] FNDG: Generated ChannelPoint(fb64e290ebb29944f2fe257685886e3a9ae881469c3b3741e65c0e6a700167d8:0) for pending_id(9a6c5e94f18cdd59db0577acd6e036a72740dd046a2897ac23f34cdadc22d5d>
LND: 2022-08-31 20:45:41.425 [INF] LNWL: Inserting unconfirmed transaction fb64e290ebb29944f2fe257685886e3a9ae881469c3b3741e65c0e6a700167d8
LND: 2022-08-31 20:45:41.618 [INF] CNCT: Creating new ChannelArbitrator for ChannelPoint(fb64e290ebb29944f2fe257685886e3a9ae881469c3b3741e65c0e6a700167d8:0)
LND: 2022-08-31 20:45:41.619 [DBG] CNCT: New ChainEventSubscription(id=0) for ChannelPoint(fb64e290ebb29944f2fe257685886e3a9ae881469c3b3741e65c0e6a700167d8:0)
LND: 2022-08-31 20:45:41.654 [DBG] CNCT: Starting ChannelArbitrator(fb64e290ebb29944f2fe257685886e3a9ae881469c3b3741e65c0e6a700167d8:0), htlc_set=(map[contractcourt.HtlcSetKey]contractcourt.htlcSet) (len=2) {
LND:  (contractcourt.HtlcSetKey) LocalHtlcSet: (contractcourt.htlcSet) {
LND:   incomingHTLCs: (map[uint64]channeldb.HTLC) {
LND:   },
LND:   outgoingHTLCs: (map[uint64]channeldb.HTLC) {
LND:   }
LND:  },
LND:  (contractcourt.HtlcSetKey) RemoteHtlcSet: (contractcourt.htlcSet) {
LND:   incomingHTLCs: (map[uint64]channeldb.HTLC) {
LND:   },
LND:   outgoingHTLCs: (map[uint64]channeldb.HTLC) {
LND:   }
LND:  }
LND: }
LND: , state=StateDefault
LND: 2022-08-31 20:45:41.660 [INF] CNCT: ChannelArbitrator(fb64e290ebb29944f2fe257685886e3a9ae881469c3b3741e65c0e6a700167d8:0): starting state=StateDefault, trigger=chainTrigger, triggerHeight=752057
LND: 2022-08-31 20:45:41.660 [DBG] CNCT: ChannelArbitrator(fb64e290ebb29944f2fe257685886e3a9ae881469c3b3741e65c0e6a700167d8:0): attempting state step with trigger=chainTrigger from state=StateDefault
LND: 2022-08-31 20:45:41.660 [DBG] CNCT: ChannelArbitrator(fb64e290ebb29944f2fe257685886e3a9ae881469c3b3741e65c0e6a700167d8:0): new block (height=752057) examining active HTLC's
LND: 2022-08-31 20:45:41.660 [DBG] CNCT: ChannelArbitrator(fb64e290ebb29944f2fe257685886e3a9ae881469c3b3741e65c0e6a700167d8:0): checking commit chain actions at height=752057, in_htlc_count=0, out_htlc_count=0
LND: 2022-08-31 20:45:41.660 [DBG] CNCT: ChannelArbitrator(fb64e290ebb29944f2fe257685886e3a9ae881469c3b3741e65c0e6a700167d8:0): no actions for chain trigger, terminating
LND: 2022-08-31 20:45:41.660 [DBG] CNCT: ChannelArbitrator(fb64e290ebb29944f2fe257685886e3a9ae881469c3b3741e65c0e6a700167d8:0): terminating at state=StateDefault
LND: 2022-08-31 20:45:41.660 [DBG] CNCT: Starting chain watcher for ChannelPoint(fb64e290ebb29944f2fe257685886e3a9ae881469c3b3741e65c0e6a700167d8:0)
LND: 2022-08-31 20:45:41.668 [INF] NTFN: New spend subscription: spend_id=16, outpoint=fb64e290ebb29944f2fe257685886e3a9ae881469c3b3741e65c0e6a700167d8:0, script=0 0eb94fbed669e7cbb6f0ee83fc872c2ae719a695bd17ac>
LND: 2022-08-31 20:45:41.668 [INF] NTFN: Dispatching historical spend rescan for outpoint=fb64e290ebb29944f2fe257685886e3a9ae881469c3b3741e65c0e6a700167d8:0, script=0 0eb94fbed669e7cbb6f0ee83fc872c2ae719a695bd1>
LND: 2022-08-31 20:45:41.675 [INF] FNDG: Finalizing pending_id(9a6c5e94f18cdd59db0577acd6e036a72740dd046a2897ac23f34cdadc22d5de) over ChannelPoint(fb64e290ebb29944f2fe257685886e3a9ae881469c3b3741e65c0e6a700167d>
LND: 2022-08-31 20:45:41.675 [INF] CNCT: Close observer for ChannelPoint(fb64e290ebb29944f2fe257685886e3a9ae881469c3b3741e65c0e6a700167d8:0) active
LSP: 2022/08/31 20:45:41 Channel Event: PENDING_OPEN_CHANNEL
LSP: 2022/08/31 20:45:41 Txid: fb64e290ebb29944f2fe257685886e3a9ae881469c3b3741e65c0e6a700167d8
LSP: 2022/08/31 20:45:41 OutputIndex: 0
LND: 2022-08-31 20:45:41.678 [INF] NTFN: Historical spend dispatch finished for request outpoint=fb64e290ebb29944f2fe257685886e3a9ae881469c3b3741e65c0e6a700167d8:0, script=0 0eb94fbed669e7cbb6f0ee83fc872c2ae719>
LSP: 2022/08/31 20:45:41 Transaction: fb64e290ebb29944f2fe257685886e3a9ae881469c3b3741e65c0e6a700167d8
LSP: 2022/08/31 20:45:41 BlockHash:
LSP: 2022/08/31 20:45:41 BlockHeight: 0
LSP: 2022/08/31 20:45:41 Confirmations: 0
LSP: 2022/08/31 20:45:41 Amount: -62806
LSP: 2022/08/31 20:45:41 TotalFees: 306
LSP: 2022/08/31 20:45:41 PublishTransaction:
LSP: 2022/08/31 20:45:42 PSBT thread unlocked
LND: 2022-08-31 20:45:42.186 [DBG] NTFN: Updated spend hint to height=752057 for unconfirmed spend request outpoint=fb64e290ebb29944f2fe257685886e3a9ae881469c3b3741e65c0e6a700167d8:0, script=0 0eb94fbed669e7cbb>
LND: 2022-08-31 20:45:42.221 [INF] CHBU: Updating on-disk multi SCB backup: num_old_chans=12, num_new_chans=13
LND: 2022-08-31 20:45:42.584 [INF] RPCS: channel: fb64e290ebb29944f2fe257685886e3a9ae881469c3b3741e65c0e6a700167d8:0 not found by channel event store
LSP: 2022/08/31 20:45:42 Channel Event: OPEN_CHANNEL
LSP: 2022/08/31 20:45:42 Txid: fb64e290ebb29944f2fe257685886e3a9ae881469c3b3741e65c0e6a700167d8
LSP: 2022/08/31 20:45:42 OutputIndex: 0
LND: 2022-08-31 20:45:42.655 [INF] FNDG: Peer(03ec54855663fec338e007e05734821189850f375c720a093bfce7cc611e03a220) is online, sending FundingLocked for ChannelID(d86701706a0e5ce641373b9c4681e89a3a6e88857625fef24>
LND: 2022-08-31 20:45:42.918 [WRN] CHBU: Replacing disk backup for ChannelPoint(023d57fd072796bfdf1e049f7dbc025e06c59cbea05971e751a369be37257782:0) w/ newer version
LND: 2022-08-31 20:45:42.918 [WRN] CHBU: Replacing disk backup for ChannelPoint(5cd8693e35224ce6182f53452f68e1c6d8ac52c475e8ee037d9622f100e2192d:0) w/ newer version
LND: 2022-08-31 20:45:42.918 [WRN] CHBU: Replacing disk backup for ChannelPoint(c957c171ce969e2aee5fe3205f91c6c82a5e749b70133a72947b0496a785c170:0) w/ newer version
LND: 2022-08-31 20:45:42.918 [WRN] CHBU: Replacing disk backup for ChannelPoint(f4782bd639767a9768f2d16d127ebea915010bef5482fc32991244be35f4a2cc:1) w/ newer version
LND: 2022-08-31 20:45:42.918 [WRN] CHBU: Replacing disk backup for ChannelPoint(d1717468aaa8c87ab4089dd0bfb9d666320ff176abc743f50b300c92f93606e5:0) w/ newer version
LND: 2022-08-31 20:45:42.918 [WRN] CHBU: Replacing disk backup for ChannelPoint(bbf8e5a897aa9aa8b050a4d83ca11d0589c141cf09a368f1ae8ced63fe33b845:0) w/ newer version
LND: 2022-08-31 20:45:42.918 [WRN] CHBU: Replacing disk backup for ChannelPoint(859c4b59cd9390f51c2387e43534b0a3eddb1898c7b2201267680348dd733b58:1) w/ newer version
LND: 2022-08-31 20:45:42.918 [WRN] CHBU: Replacing disk backup for ChannelPoint(999d890c956b9ca4282f288511eb183fa14be18c9b9de14873dcdf54b7839a39:1) w/ newer version
LND: 2022-08-31 20:45:42.918 [WRN] CHBU: Replacing disk backup for ChannelPoint(a085e37dde93cc2af07218f7b9bcfb4ae0624dd4943c65de812fe8f4f32c9f23:1) w/ newer version
LND: 2022-08-31 20:45:42.918 [WRN] CHBU: Replacing disk backup for ChannelPoint(ba61b13b176d428a3959678ac3cf60fa62f2702f9535d9f385c7f3e67f68dbd2:1) w/ newer version
LND: 2022-08-31 20:45:42.918 [WRN] CHBU: Replacing disk backup for ChannelPoint(fd3563f1dd10bf8dddcafb309d2fa178d17f0242c855af308752a318969243d0:1) w/ newer version
LND: 2022-08-31 20:45:42.918 [WRN] CHBU: Replacing disk backup for ChannelPoint(206db1e2c09ecea70eaa0854438c8453683ad9d78dc519e2ba52fe059a4ad83f:0) w/ newer version
LND: 2022-08-31 20:45:43.419 [INF] CHBU: Updating backup file at /home/ubuntu/.lnd/data/chain/bitcoin/mainnet/channel.backup
LND: 2022-08-31 20:45:43.421 [INF] CHBU: Swapping old multi backup file from /home/ubuntu/.lnd/data/chain/bitcoin/mainnet/temp-dont-use.backup to /home/ubuntu/.lnd/data/chain/bitcoin/mainnet/channel.backup
LND: 2022-08-31 20:45:43.422 [INF] CHBU: Updating on-disk multi SCB backup: num_old_chans=13, num_new_chans=13
LND: 2022-08-31 20:45:43.656 [INF] PEER: Peer(03ec54855663fec338e007e05734821189850f375c720a093bfce7cc611e03a220): New channel active ChannelPoint(fb64e290ebb29944f2fe257685886e3a9ae881469c3b3741e65c0e6a700167d>
LND: 2022-08-31 20:45:43.656 [DBG] CNCT: New ChainEventSubscription(id=1) for ChannelPoint(fb64e290ebb29944f2fe257685886e3a9ae881469c3b3741e65c0e6a700167d8:0)
LND: 2022-08-31 20:45:43.656 [INF] HSWC: ChannelLink(fb64e290ebb29944f2fe257685886e3a9ae881469c3b3741e65c0e6a700167d8:0): starting
LND: 2022-08-31 20:45:43.675 [INF] HSWC: Trimming open circuits for chan_id=16000000:0:0, start_htlc_id=0
LND: 2022-08-31 20:45:43.676 [INF] HSWC: Adding live link chan_id=d86701706a0e5ce641373b9c4681e89a3a6e88857625fef24499b2eb90e264fb, short_chan_id=16000000:0:0
LND: 2022-08-31 20:45:43.676 [INF] CNCT: Attempting to update ContractSignals for ChannelPoint(fb64e290ebb29944f2fe257685886e3a9ae881469c3b3741e65c0e6a700167d8:0)
LND: 2022-08-31 20:45:43.676 [INF] HSWC: ChannelLink(fb64e290ebb29944f2fe257685886e3a9ae881469c3b3741e65c0e6a700167d8:0): HTLC manager started, bandwidth=57759000 mSAT
LSP: 2022/08/31 20:45:43 Channel Event: ACTIVE_CHANNEL
LSP: 2022/08/31 20:45:43 Txid: fb64e290ebb29944f2fe257685886e3a9ae881469c3b3741e65c0e6a700167d8
LSP: 2022/08/31 20:45:43 OutputIndex: 0
LSP: 2022/08/31 20:45:43 Wait 10 seconds before resuming HTLCs: 2
LND: 2022-08-31 20:45:43.691 [DBG] HSWC: ChannelLink(fb64e290ebb29944f2fe257685886e3a9ae881469c3b3741e65c0e6a700167d8:0): loaded 0 fwd pks
LND: 2022-08-31 20:45:44.624 [INF] NTFN: New confirmation subscription: conf_id=2, txid=fb64e290ebb29944f2fe257685886e3a9ae881469c3b3741e65c0e6a700167d8, num_confs=6 height_hint=752057
LND: 2022-08-31 20:45:44.624 [DBG] NTFN: Dispatching historical confirmation rescan for txid=fb64e290ebb29944f2fe257685886e3a9ae881469c3b3741e65c0e6a700167d8
LND: 2022-08-31 20:45:44.624 [INF] FNDG: Waiting for funding tx (fb64e290ebb29944f2fe257685886e3a9ae881469c3b3741e65c0e6a700167d8) to reach 6 confirmations
LND: 2022-08-31 20:45:44.629 [DBG] NTFN: Confirmation details for txid=fb64e290ebb29944f2fe257685886e3a9ae881469c3b3741e65c0e6a700167d8 not found during historical dispatch, waiting to dispatch at tip
LND: 2022-08-31 20:45:46.304 [WRN] CHBU: Replacing disk backup for ChannelPoint(bbf8e5a897aa9aa8b050a4d83ca11d0589c141cf09a368f1ae8ced63fe33b845:0) w/ newer version
LND: 2022-08-31 20:45:46.305 [WRN] CHBU: Replacing disk backup for ChannelPoint(859c4b59cd9390f51c2387e43534b0a3eddb1898c7b2201267680348dd733b58:1) w/ newer version
LND: 2022-08-31 20:45:46.305 [WRN] CHBU: Replacing disk backup for ChannelPoint(023d57fd072796bfdf1e049f7dbc025e06c59cbea05971e751a369be37257782:0) w/ newer version
LND: 2022-08-31 20:45:46.305 [WRN] CHBU: Replacing disk backup for ChannelPoint(5cd8693e35224ce6182f53452f68e1c6d8ac52c475e8ee037d9622f100e2192d:0) w/ newer version
LND: 2022-08-31 20:45:46.305 [WRN] CHBU: Replacing disk backup for ChannelPoint(c957c171ce969e2aee5fe3205f91c6c82a5e749b70133a72947b0496a785c170:0) w/ newer version
LND: 2022-08-31 20:45:46.305 [WRN] CHBU: Replacing disk backup for ChannelPoint(f4782bd639767a9768f2d16d127ebea915010bef5482fc32991244be35f4a2cc:1) w/ newer version
LND: 2022-08-31 20:45:46.305 [WRN] CHBU: Replacing disk backup for ChannelPoint(d1717468aaa8c87ab4089dd0bfb9d666320ff176abc743f50b300c92f93606e5:0) w/ newer version
LND: 2022-08-31 20:45:46.305 [WRN] CHBU: Replacing disk backup for ChannelPoint(fd3563f1dd10bf8dddcafb309d2fa178d17f0242c855af308752a318969243d0:1) w/ newer version
LND: 2022-08-31 20:45:46.305 [WRN] CHBU: Replacing disk backup for ChannelPoint(206db1e2c09ecea70eaa0854438c8453683ad9d78dc519e2ba52fe059a4ad83f:0) w/ newer version
LND: 2022-08-31 20:45:46.305 [WRN] CHBU: Replacing disk backup for ChannelPoint(999d890c956b9ca4282f288511eb183fa14be18c9b9de14873dcdf54b7839a39:1) w/ newer version
LND: 2022-08-31 20:45:46.305 [WRN] CHBU: Replacing disk backup for ChannelPoint(a085e37dde93cc2af07218f7b9bcfb4ae0624dd4943c65de812fe8f4f32c9f23:1) w/ newer version
LND: 2022-08-31 20:45:46.305 [WRN] CHBU: Replacing disk backup for ChannelPoint(fb64e290ebb29944f2fe257685886e3a9ae881469c3b3741e65c0e6a700167d8:0) w/ newer version
LND: 2022-08-31 20:45:46.305 [WRN] CHBU: Replacing disk backup for ChannelPoint(ba61b13b176d428a3959678ac3cf60fa62f2702f9535d9f385c7f3e67f68dbd2:1) w/ newer version
LND: 2022-08-31 20:45:47.426 [INF] CHBU: Updating backup file at /home/ubuntu/.lnd/data/chain/bitcoin/mainnet/channel.backup
LND: 2022-08-31 20:45:47.429 [INF] CHBU: Swapping old multi backup file from /home/ubuntu/.lnd/data/chain/bitcoin/mainnet/temp-dont-use.backup to /home/ubuntu/.lnd/data/chain/bitcoin/mainnet/channel.backup
LSP: 2022/08/31 20:45:47 Channel Backup
LND: 2022-08-31 20:45:48.428 [DBG] RPCS: [walletbalance] Total balance=0.59861969 BTC (confirmed=0.27223745 BTC, unconfirmed=0.32638224 BTC)
LSP: 2022/08/31 20:45:48 TotalBalance: 59861969
LSP: 2022/08/31 20:45:48 ConfirmedBalance: 27223745
LSP: 2022/08/31 20:45:48 UnconfirmedBalance: 32638224
LSP: 2022/08/31 20:45:48 LockedBalance: 32701030
LSP: 2022/08/31 20:45:48 Channel Backup
LND: 2022-08-31 20:45:50.391 [INF] DISC: GossipSyncer(02fae89cbe71577b9cc93c59c9505f28a7e1a5666dd8c13d71826370ef1f5db7c9): requesting new chans from height=0 and 752057 blocks after
LND: 2022-08-31 20:45:53.706 [DBG] HSWC: unable to find link with destination 2356044:14343202:54750
LND: 2022-08-31 20:45:53.706 [ERR] HSWC: UnknownNextPeer
LND: 2022-08-31 20:45:53.706 [DBG] HSWC: ChannelLink(c957c171ce969e2aee5fe3205f91c6c82a5e749b70133a72947b0496a785c170:0): queueing removal of FAIL closed circuit: (Chan ID=745071:2451:0, HTLC ID=1213)->(Chan ID>
LND: 2022-08-31 20:45:53.706 [ERR] HSWC: Unhandled error while reforwarding htlc settle/fail over htlcswitch: UnknownNextPeer
LSP: 2022/08/31 20:45:53 HTLC Event: FORWARD
LSP: 2022/08/31 20:45:53 Link Fail HTLC Event
LSP: 2022/08/31 20:45:53 WireFailure: UNKNOWN_NEXT_PEER
LSP: 2022/08/31 20:45:53 FailureDetail: NO_DETAIL
LSP: 2022/08/31 20:45:53 FailureString: UnknownNextPeer
LND: 2022-08-31 20:45:53.772 [DBG] HSWC: ChannelLink(c957c171ce969e2aee5fe3205f91c6c82a5e749b70133a72947b0496a785c170:0): removing Fail/Settle packet (Chan ID=745071:2451:0, HTLC ID=1213) from mailbox
LND: 2022-08-31 20:45:56.116 [INF] PEER: Peer(02fae89cbe71577b9cc93c59c9505f28a7e1a5666dd8c13d71826370ef1f5db7c9): unable to read message from peer: read tcp 10.0.13.57:9735->91.149.225.172:40124: i/o timeout
LND: 2022-08-31 20:45:56.116 [INF] PEER: Peer(02fae89cbe71577b9cc93c59c9505f28a7e1a5666dd8c13d71826370ef1f5db7c9): disconnecting 02fae89cbe71577b9cc93c59c9505f28a7e1a5666dd8c13d71826370ef1f5db7c9@91.149.225.172>
LND: 2022-08-31 20:45:56.116 [INF] NTFN: Cancelling epoch notification, epoch_id=46
LND: 2022-08-31 20:45:56.317 [INF] DISC: Removing GossipSyncer for peer=02fae89cbe71577b9cc93c59c9505f28a7e1a5666dd8c13d71826370ef1f5db7c9
LND: 2022-08-31 20:45:56.317 [INF] HSWC: ChannelLink(999d890c956b9ca4282f288511eb183fa14be18c9b9de14873dcdf54b7839a39:1): stopping
LND: 2022-08-31 20:45:56.317 [INF] HSWC: ChannelLink(999d890c956b9ca4282f288511eb183fa14be18c9b9de14873dcdf54b7839a39:1): exited
LND: 2022-08-31 20:45:56.317 [INF] HSWC: Removing channel link with ChannelID(399a83b754dfdc7348e19d9b8ce14ba13f18eb1185282f28a49c6b950c899d98)
LSP: 2022/08/31 20:45:56 Channel Event: INACTIVE_CHANNEL
LND: 2022-08-31 20:45:58.889 [INF] SRVR: New inbound connection from 185.220.101.168:9922
LND: 2022-08-31 20:45:58.889 [INF] SRVR: Finalizing connection to 02fae89cbe71577b9cc93c59c9505f28a7e1a5666dd8c13d71826370ef1f5db7c9@185.220.101.168:9922, inbound=true
LND: 2022-08-31 20:45:58.973 [INF] PEER: Peer(02fae89cbe71577b9cc93c59c9505f28a7e1a5666dd8c13d71826370ef1f5db7c9): loading ChannelPoint(999d890c956b9ca4282f288511eb183fa14be18c9b9de14873dcdf54b7839a39:1)
LND: 2022-08-31 20:45:58.997 [DBG] CNCT: New ChainEventSubscription(id=4) for ChannelPoint(999d890c956b9ca4282f288511eb183fa14be18c9b9de14873dcdf54b7839a39:1)
LND: 2022-08-31 20:45:58.997 [INF] HSWC: ChannelLink(999d890c956b9ca4282f288511eb183fa14be18c9b9de14873dcdf54b7839a39:1): starting
LND: 2022-08-31 20:45:59.009 [INF] HSWC: Trimming open circuits for chan_id=748003:316:1, start_htlc_id=672
LND: 2022-08-31 20:45:59.009 [INF] HSWC: Adding live link chan_id=399a83b754dfdc7348e19d9b8ce14ba13f18eb1185282f28a49c6b950c899d98, short_chan_id=748003:316:1
LND: 2022-08-31 20:45:59.009 [INF] NTFN: New block epoch subscription
LND: 2022-08-31 20:45:59.009 [INF] CNCT: Attempting to update ContractSignals for ChannelPoint(999d890c956b9ca4282f288511eb183fa14be18c9b9de14873dcdf54b7839a39:1)
LND: 2022-08-31 20:45:59.009 [INF] HSWC: ChannelLink(999d890c956b9ca4282f288511eb183fa14be18c9b9de14873dcdf54b7839a39:1): HTLC manager started, bandwidth=3118347265 mSAT
LND: 2022-08-31 20:45:59.009 [INF] HSWC: ChannelLink(999d890c956b9ca4282f288511eb183fa14be18c9b9de14873dcdf54b7839a39:1): attempting to re-synchronize
LND: 2022-08-31 20:45:59.009 [INF] PEER: Peer(02fae89cbe71577b9cc93c59c9505f28a7e1a5666dd8c13d71826370ef1f5db7c9): Negotiated chan series queries
LND: 2022-08-31 20:45:59.009 [INF] DISC: Creating new GossipSyncer for peer=02fae89cbe71577b9cc93c59c9505f28a7e1a5666dd8c13d71826370ef1f5db7c9
LND: 2022-08-31 20:45:59.044 [DBG] HSWC: Sent 0 satoshis and received 0 satoshis in the last 10 seconds (0.100000 tx/sec)
LND: 2022-08-31 20:45:59.343 [INF] HSWC: ChannelLink(999d890c956b9ca4282f288511eb183fa14be18c9b9de14873dcdf54b7839a39:1): received re-establishment message from remote side
LSP: 2022/08/31 20:45:59 Channel Event: ACTIVE_CHANNEL
LSP: 2022/08/31 20:45:59 Txid: 999d890c956b9ca4282f288511eb183fa14be18c9b9de14873dcdf54b7839a39
LSP: 2022/08/31 20:45:59 OutputIndex: 1
LND: 2022-08-31 20:45:59.362 [DBG] HSWC: ChannelLink(999d890c956b9ca4282f288511eb183fa14be18c9b9de14873dcdf54b7839a39:1): loaded 0 fwd pks
LND: 2022-08-31 20:46:07.989 [INF] CRTR: Processed channels=2 updates=324 nodes=25 in last 1m58.728044245s
LND: 2022-08-31 20:46:36.650 [INF] DISC: Broadcasting 389 new announcements in 18 sub batches
LND: 2022-08-31 20:47:08.465 [INF] CRTR: Processed channels=0 updates=127 nodes=5 in last 1m0.475844331s
LND: 2022-08-31 20:48:06.650 [INF] DISC: Broadcasting 251 new announcements in 18 sub batches
LND: 2022-08-31 20:48:07.989 [INF] CRTR: Processed channels=0 updates=161 nodes=1 in last 59.52351865s
LND: 2022-08-31 20:49:07.989 [INF] CRTR: Processed channels=0 updates=161 nodes=7 in last 59.999810653s
LND: 2022-08-31 20:49:36.650 [INF] DISC: Broadcasting 247 new announcements in 18 sub batches
LND: 2022-08-31 20:50:07.989 [INF] CRTR: Processed channels=0 updates=147 nodes=14 in last 1m0.000272214s
LND: 2022-08-31 20:50:57.963 [DBG] HSWC: ChannelLink(5cd8693e35224ce6182f53452f68e1c6d8ac52c475e8ee037d9622f100e2192d:0): sampled fee rate for 3 block conf: 2667 sat/kw
LND: 2022-08-31 20:51:06.650 [INF] DISC: Broadcasting 239 new announcements in 18 sub batches
LND: 2022-08-31 20:51:07.990 [INF] CRTR: Processed channels=0 updates=151 nodes=6 in last 1m0.000323333s
LND: 2022-08-31 20:52:07.989 [INF] CRTR: Processed channels=0 updates=148 nodes=11 in last 59.999201726s
LND: 2022-08-31 20:52:13.646 [DBG] HSWC: ChannelLink(f4782bd639767a9768f2d16d127ebea915010bef5482fc32991244be35f4a2cc:1): sampled fee rate for 3 block conf: 2667 sat/kw
LND: 2022-08-31 20:52:18.344 [DBG] HSWC: ChannelLink(859c4b59cd9390f51c2387e43534b0a3eddb1898c7b2201267680348dd733b58:1): forwarding 1 packets to switch: replay=false

Expected behaviour

Once the newly opened channel is active, signalled with the ACTIVE_CHANNEL event then the channel should be ready to resume HTLCs.

Actual behaviour

After the opened channel is active, even after waiting up to 10 seconds, the HTLC results in a link error UNKNOWN_NEXT_PEER once the HTLC is resumed.

dstadulis commented 2 years ago

a service that receives an out-of-band channel request and, when a user hops an invoice through our node it holds the intercepted HTLC, creates a zero-conf channel, then resumes the HTLC to the user

A compelling flow! Hope this design is developed.

sputn1ck commented 2 years ago

I don't know if there is a log / event you could look for, but a way to check if the channel is ready could be to retry a probe payment with the routerrpc.SendPayment api e.g.

 &routerrpc.SendPaymentRequest{
    PaymentHash = // some random payment hash
    TimoutSeconds = // some sane time to wait for
    Amt = // whatever amount you need
    Dest = // pubkey of peer
    OutgoingChanIds = // chanid of new channel
}

If this succeeds, resuming the htlc might work.

Crypt-iQ commented 2 years ago

I don't think anything needs to change here, the database state of the channel has went from "pending open" to "open". Your peer hasn't sent you a FundingLocked message, meaning you haven't added the ChannelUpdate to your graph. It may just take longer for your peer to send this message on mainnet rather than regtest.

dangeross commented 2 years ago

If I subscribe to SubscribeChannelGraph could I receive an update when the FundingLocked message is received and channel update added to the graph?

dangeross commented 2 years ago

Quick update, I've updated to listen for the first GraphTopologyUpdate related to the opened channel, then trigger resuming the HTLCs after a delay. But I'm still getting the same error: UNKNOWN_NEXT_PEER

LSP: 2022/09/06 19:40:36 HTLC Intercept
LSP: 2022/09/06 19:40:36 IncomingAmountMsat: 25000000
LSP: 2022/09/06 19:40:36 IncomingCircuitKey.ChanId: 822325845953937409
LSP: 2022/09/06 19:40:36 IncomingCircuitKey.HtlcId: 2560
LSP: 2022/09/06 19:40:36 IncomingExpiry: 752970
LSP: 2022/09/06 19:40:36 OnionBlob: 00027ba1b7f8f9f20b513b16aeef0c546d7079b4c474af3a5c9c4a205e9dbc81a50dd7d2181816ec357f792a07368fd41f9ecd060ff41df35fb0e8a22b508478b07d8ecead16676a1e9b394df0cc1f61>
LSP: 2022/09/06 19:40:36 OutgoingAmountMsat: 25000000
LSP: 2022/09/06 19:40:36 OutgoingExpiry: 752970
LSP: 2022/09/06 19:40:36 OutgoingRequestedChanId: 15766966598639671997
LSP: 2022/09/06 19:40:36 PaymentHash: f9f6bfc71eec2a6d27ca48b1900a954769a6831728a30329c3c21d2a9c8178a1
LSP: 2022/09/06 19:40:36 PSBT thread locked
LSP: 2022/09/06 19:40:36 Psbt Fund open channel request
LND: 2022-09-06 19:40:36.150 [DBG] RPCS: [openchannel] request to NodeKey(03ec54855663fec338e007e05734821189850f375c720a093bfce7cc611e03a220) allocation(us=31250, them=0)
LND: 2022-09-06 19:40:36.156 [DBG] RPCS: [openchannel]: using fee of 2428 sat/kw for funding tx
LND: 2022-09-06 19:40:36.157 [INF] FNDG: Initiating fundingRequest(local_amt=0.0003125 BTC (subtract_fees=false), push_amt=0 mSAT, chain_hash=000000000019d6689c085ae165831e934ff763ae46a2a6c172b3f1>
LND: 2022-09-06 19:40:36.184 [DBG] HSWC: ChannelLink(f4782bd639767a9768f2d16d127ebea915010bef5482fc32991244be35f4a2cc:1): removing Add packet (Chan ID=745570:750:1, HTLC ID=12908) from mailbox
LND: 2022-09-06 19:40:48.267 [DBG] HSWC: Sent 50000 satoshis and received 100 satoshis in the last 10 seconds (0.400000 tx/sec)
LND: 2022-09-06 19:40:48.807 [INF] FNDG: Target commit tx sat/kw for pendingID(78d4553b510740736189efc27479f87f2801ca06bf601793dacf8495a15ddabd): 3424
LND: 2022-09-06 19:40:48.807 [INF] FNDG: Dust limit for pendingID(78d4553b510740736189efc27479f87f2801ca06bf601793dacf8495a15ddabd): 0.00000354 BTC
LND: 2022-09-06 19:40:48.808 [INF] FNDG: Starting funding workflow with 24.134.172.181:52092 for pending_id(78d4553b510740736189efc27479f87f2801ca06bf601793dacf8495a15ddabd), committype=anchors-ze>
LND: 2022-09-06 19:40:49.569 [DBG] HSWC: Sent 0 satoshis and received 0 satoshis in the last 10 seconds (0.100000 tx/sec)
LND: 2022-09-06 19:40:49.855 [INF] FNDG: Recv'd fundingResponse for pending_id(78d4553b510740736189efc27479f87f2801ca06bf601793dacf8495a15ddabd)
LND: 2022-09-06 19:40:49.856 [INF] FNDG: pendingChan(78d4553b510740736189efc27479f87f2801ca06bf601793dacf8495a15ddabd): remote party proposes num_confs=0, csv_delay=144
LSP: 2022/09/06 19:40:49 PSBT thread unlocked
LSP: 2022/09/06 19:40:49 PSBT Fund timeout (2022-09-06 19:40:49.871895439 +0000 UTC m=+575.155568414) set for 2022-09-06 19:41:19.857106 +0000 UTC: 29.985210985s
LSP: 2022/09/06 19:40:49 Payment timeout set for 30 seconds: f9f6bfc71eec2a6d27ca48b1900a954769a6831728a30329c3c21d2a9c8178a1
LSP: 2022/09/06 19:40:49 Payment timeout ended (OPENING_CHANNEL): f9f6bfc71eec2a6d27ca48b1900a954769a6831728a30329c3c21d2a9c8178a1
LSP: 2022/09/06 19:41:19 PSBT thread locked
LND: 2022-09-06 19:41:20.873 [DBG] RPCS: Verifying PSBT for pending_id=78d4553b510740736189efc27479f87f2801ca06bf601793dacf8495a15ddabd
LND: 2022-09-06 19:41:21.122 [DBG] RPCS: Finalizing PSBT for pending_id=78d4553b510740736189efc27479f87f2801ca06bf601793dacf8495a15ddabd
LND: 2022-09-06 19:41:21.125 [INF] FNDG: Generated ChannelPoint(5d66eb4fcb989e8a13d078aebda7df3fc9a71b69380f1e308967cabd062385a0:0) for pending_id(78d4553b510740736189efc27479f87f2801ca06bf601793d>
LND: 2022-09-06 19:41:21.228 [INF] LNWL: Inserting unconfirmed transaction 5d66eb4fcb989e8a13d078aebda7df3fc9a71b69380f1e308967cabd062385a0
LND: 2022-09-06 19:41:21.512 [INF] CNCT: Creating new ChannelArbitrator for ChannelPoint(5d66eb4fcb989e8a13d078aebda7df3fc9a71b69380f1e308967cabd062385a0:0)
LND: 2022-09-06 19:41:21.518 [DBG] CNCT: New ChainEventSubscription(id=0) for ChannelPoint(5d66eb4fcb989e8a13d078aebda7df3fc9a71b69380f1e308967cabd062385a0:0)
LND: 2022-09-06 19:41:21.832 [INF] CNCT: ChannelArbitrator(5d66eb4fcb989e8a13d078aebda7df3fc9a71b69380f1e308967cabd062385a0:0): starting state=StateDefault, trigger=chainTrigger, triggerHeight=752>
LND: 2022-09-06 19:41:21.832 [DBG] CNCT: ChannelArbitrator(5d66eb4fcb989e8a13d078aebda7df3fc9a71b69380f1e308967cabd062385a0:0): attempting state step with trigger=chainTrigger from state=StateDefa>
LND: 2022-09-06 19:41:21.832 [DBG] CNCT: ChannelArbitrator(5d66eb4fcb989e8a13d078aebda7df3fc9a71b69380f1e308967cabd062385a0:0): new block (height=752927) examining active HTLC's
LND: 2022-09-06 19:41:21.832 [DBG] CNCT: ChannelArbitrator(5d66eb4fcb989e8a13d078aebda7df3fc9a71b69380f1e308967cabd062385a0:0): checking commit chain actions at height=752927, in_htlc_count=0, out>
LND: 2022-09-06 19:41:21.832 [DBG] CNCT: ChannelArbitrator(5d66eb4fcb989e8a13d078aebda7df3fc9a71b69380f1e308967cabd062385a0:0): no actions for chain trigger, terminating
LND: 2022-09-06 19:41:21.832 [DBG] CNCT: ChannelArbitrator(5d66eb4fcb989e8a13d078aebda7df3fc9a71b69380f1e308967cabd062385a0:0): terminating at state=StateDefault
LND: 2022-09-06 19:41:21.832 [DBG] CNCT: Starting chain watcher for ChannelPoint(5d66eb4fcb989e8a13d078aebda7df3fc9a71b69380f1e308967cabd062385a0:0)
LND: 2022-09-06 19:41:21.843 [INF] NTFN: New spend subscription: spend_id=22, outpoint=5d66eb4fcb989e8a13d078aebda7df3fc9a71b69380f1e308967cabd062385a0:0, script=0 22e359a770a8044504cf8870974c91e4>
LND: 2022-09-06 19:41:21.843 [INF] NTFN: Dispatching historical spend rescan for outpoint=5d66eb4fcb989e8a13d078aebda7df3fc9a71b69380f1e308967cabd062385a0:0, script=0 22e359a770a8044504cf8870974c9>
LND: 2022-09-06 19:41:21.852 [INF] FNDG: Finalizing pending_id(78d4553b510740736189efc27479f87f2801ca06bf601793dacf8495a15ddabd) over ChannelPoint(5d66eb4fcb989e8a13d078aebda7df3fc9a71b69380f1e308>
LND: 2022-09-06 19:41:21.852 [INF] CNCT: Close observer for ChannelPoint(5d66eb4fcb989e8a13d078aebda7df3fc9a71b69380f1e308967cabd062385a0:0) active
LSP: 2022/09/06 19:41:21 Channel Event: PENDING_OPEN_CHANNEL
LND: 2022-09-06 19:41:21.854 [INF] NTFN: Historical spend dispatch finished for request outpoint=5d66eb4fcb989e8a13d078aebda7df3fc9a71b69380f1e308967cabd062385a0:0, script=0 22e359a770a8044504cf88>
LSP: 2022/09/06 19:41:22 Transaction: 5d66eb4fcb989e8a13d078aebda7df3fc9a71b69380f1e308967cabd062385a0
LSP: 2022/09/06 19:41:22 BlockHash:
LSP: 2022/09/06 19:41:22 BlockHeight: 0
LSP: 2022/09/06 19:41:22 Confirmations: 0
LSP: 2022/09/06 19:41:22 Amount: -31556
LSP: 2022/09/06 19:41:22 TotalFees: 306
LSP: 2022/09/06 19:41:22 PublishTransaction:
LSP: 2022/09/06 19:41:22 PSBT thread unlocked
LND: 2022-09-06 19:41:22.441 [DBG] NTFN: Updated spend hint to height=752927 for unconfirmed spend request outpoint=5d66eb4fcb989e8a13d078aebda7df3fc9a71b69380f1e308967cabd062385a0:0, script=0 22e>
LND: 2022-09-06 19:41:22.509 [INF] CHBU: Updating on-disk multi SCB backup: num_old_chans=12, num_new_chans=13
LSP: 2022/09/06 19:41:23 Channel Event: OPEN_CHANNEL
LSP: 2022/09/06 19:41:23 Txid: 5d66eb4fcb989e8a13d078aebda7df3fc9a71b69380f1e308967cabd062385a0
LSP: 2022/09/06 19:41:23 OutputIndex: 0
LND: 2022-09-06 19:41:23.803 [INF] FNDG: Peer(03ec54855663fec338e007e05734821189850f375c720a093bfce7cc611e03a220) is online, sending FundingLocked for ChannelID(a0852306bdca6789301e0f38691ba7c93fd>
LND: 2022-09-06 19:41:24.452 [WRN] DISC: ignoring remote ChannelAnnouncement for own channel 
LND: 2022-09-06 19:41:24.799 [INF] PEER: Peer(03ec54855663fec338e007e05734821189850f375c720a093bfce7cc611e03a220): New channel active ChannelPoint(5d66eb4fcb989e8a13d078aebda7df3fc9a71b69380f1e308>
LND: 2022-09-06 19:41:24.799 [DBG] CNCT: New ChainEventSubscription(id=1) for ChannelPoint(5d66eb4fcb989e8a13d078aebda7df3fc9a71b69380f1e308967cabd062385a0:0)
LND: 2022-09-06 19:41:24.799 [INF] HSWC: ChannelLink(5d66eb4fcb989e8a13d078aebda7df3fc9a71b69380f1e308967cabd062385a0:0): starting
LND: 2022-09-06 19:41:24.822 [INF] HSWC: Trimming open circuits for chan_id=16000000:0:1, start_htlc_id=0
LND: 2022-09-06 19:41:24.822 [INF] HSWC: Adding live link chan_id=a0852306bdca6789301e0f38691ba7c93fdfa7bdae78d0138a9e98cb4feb665d, short_chan_id=16000000:0:1
LND: 2022-09-06 19:41:24.823 [INF] CNCT: Attempting to update ContractSignals for ChannelPoint(5d66eb4fcb989e8a13d078aebda7df3fc9a71b69380f1e308967cabd062385a0:0)
LND: 2022-09-06 19:41:24.823 [INF] HSWC: ChannelLink(5d66eb4fcb989e8a13d078aebda7df3fc9a71b69380f1e308967cabd062385a0:0): HTLC manager started, bandwidth=25799000 mSAT
LSP: 2022/09/06 19:41:24 Channel Event: ACTIVE_CHANNEL
LND: 2022-09-06 19:41:24.840 [DBG] HSWC: ChannelLink(5d66eb4fcb989e8a13d078aebda7df3fc9a71b69380f1e308967cabd062385a0:0): loaded 0 fwd pks

LSP: 2022/09/06 19:42:59 Graph Update
LSP: 2022/09/06 19:42:59 ChanID: 16000000:0:1
LSP: 2022/09/06 19:42:59 Txid: 5d66eb4fcb989e8a13d078aebda7df3fc9a71b69380f1e308967cabd062385a0
LSP: 2022/09/06 19:42:59 OutputIndex: 0
LSP: 2022/09/06 19:42:59 AdvertisingNode: 03ec54855663fec338e007e05734821189850f375c720a093bfce7cc611e03a220
LSP: 2022/09/06 19:42:59 ConnectingNode: 029e6289970aa5e57fe92bb8ae0cefa7ff388bb21a0f8277bc3a45fc5c10e98c4b
LSP: 2022/09/06 19:42:59 Disabled: false
LSP: 2022/09/06 19:42:59 Wait 5 seconds before resuming HTLCs: 4

LND: 2022-09-06 19:43:04.859 [DBG] HSWC: unable to find link with destination 14339972:9806173:55997
LND: 2022-09-06 19:43:04.859 [ERR] HSWC: UnknownNextPeer
LND: 2022-09-06 19:43:04.859 [ERR] HSWC: Unhandled error while reforwarding htlc settle/fail over htlcswitch: UnknownNextPeer
LND: 2022-09-06 19:43:04.859 [DBG] HSWC: ChannelLink(859c4b59cd9390f51c2387e43534b0a3eddb1898c7b2201267680348dd733b58:1): queueing removal of FAIL closed circuit: (Chan ID=747901:437:1, HTLC ID=25>
LSP: 2022/09/06 19:43:04 HTLC Event: FORWARD
LSP: 2022/09/06 19:43:04 Link Fail HTLC Event
LSP: 2022/09/06 19:43:04 WireFailure: UNKNOWN_NEXT_PEER
LSP: 2022/09/06 19:43:04 FailureDetail: NO_DETAIL
LSP: 2022/09/06 19:43:04 FailureString: UnknownNextPeer
LND: 2022-09-06 19:43:33.192 [INF] NTFN: New confirmation subscription: conf_id=4, txid=5d66eb4fcb989e8a13d078aebda7df3fc9a71b69380f1e308967cabd062385a0, num_confs=6 height_hint=752927
LND: 2022-09-06 19:43:33.193 [DBG] NTFN: Dispatching historical confirmation rescan for txid=5d66eb4fcb989e8a13d078aebda7df3fc9a71b69380f1e308967cabd062385a0
LND: 2022-09-06 19:43:33.193 [INF] FNDG: Waiting for funding tx (5d66eb4fcb989e8a13d078aebda7df3fc9a71b69380f1e308967cabd062385a0) to reach 6 confirmations
LND: 2022-09-06 19:43:33.197 [DBG] NTFN: Confirmation details for txid=5d66eb4fcb989e8a13d078aebda7df3fc9a71b69380f1e308967cabd062385a0 not found during historical dispatch, waiting to dispatch at>

Restart


LND: 2022-09-06 20:25:29.601 [INF] DISC: Creating new GossipSyncer for peer=03ec54855663fec338e007e05734821189850f375c720a093bfce7cc611e03a220
LND: 2022-09-06 20:25:29.601 [INF] HSWC: ChannelLink(5d66eb4fcb989e8a13d078aebda7df3fc9a71b69380f1e308967cabd062385a0:0): resending FundingLocked message to peer
LND: 2022-09-06 20:25:29.602 [INF] DISC: GossipSyncer(03ec54855663fec338e007e05734821189850f375c720a093bfce7cc611e03a220): filtering chan range: start_height=0, num_blocks=752927
LND: 2022-09-06 20:25:29.602 [INF] HSWC: ChannelLink(5d66eb4fcb989e8a13d078aebda7df3fc9a71b69380f1e308967cabd062385a0:0): received re-establishment message from remote side```
Crypt-iQ commented 2 years ago

How are you creating the alias SCID (short channel id) as Alice? Currently LND doesn't let you set the alias, so your forwards on mainnet shouldn't work - the one that you use in the invoice MUST be the LSP's alias. ACTIVE_CHANNEL is the correct event to be listening for. I'm curious how you are able to get this to work on regtest given that the same constraints with the alias apply.

dangeross commented 2 years ago

I'm curious why regtest works also.

The LSP generates a random 32 byte chan_id and returns it as part of the out-of-band channel request. Then Alice adds the chan_id and LSP pubkey to the route hints of the invoice.

I assumed the route hints are not absolute and LND could pick an alternative channel if necessary because of non-strict forwarding. As written in the HtlcInterceptor ForwardHtlcInterceptorRequest RPC response:

outgoing_requested_chan_id - The requested outgoing channel id for this forwarded htlc. Because of non-strict forwarding, this isn't necessarily the channel over which the packet will be forwarded eventually. A different channel to the same peer may be selected as well.

Can you think of an alternative way to achieve this if I'm implementing it incorrectly?

Crypt-iQ commented 2 years ago

32-byte channel ids don't go in the invoice, the 8-byte short channel id goes there. Non-strict forwarding only works if the short channel id in the invoice maps to an actual channel - it can't be randomly generated in the way you've done, there's no way for the LSP LND node to know what to do with this random channel. I can't think of a way your flow works since:

dangeross commented 2 years ago

Ok, thanks for your feedback. If you think there is no way to open a channel this way during a HTLC interception, then the issue can be closed.

Crypt-iQ commented 2 years ago

It may be possible in a future API, but not now. So it's not really an issue but more of a feature request