htlcswitch: pipeline settles to switch #3143

Crypt-iQ · 2019-05-30T16:40:01Z

This PR makes the outgoing link pipeline the settle to the
switch as soon as it receives it. Previously, it would wait for a
revocation before sending it, which caused increased latency on
payments as well as possibly never settling on the incoming link.
A duplicate settle is still sent to the switch, but it is handled
gracefully. A new AckEventTicker was added to the switch which
acknowledges any pending settle / fail entries in an outgoing
link's fwd pkgs in batch. This was needed in order to reduce the
number of db txn's which would have been incurred by acking whenever
we receive a duplicate settle without batching.

Fixes #3069

cfromknecht

@Crypt-iQ this looks great, only one minor comment. looking forward to benchmarking the performance improvement!

htlcswitch/link.go

Crypt-iQ · 2019-07-03T17:10:06Z

I have been running flakehunter unit tester on the failed test in travis and it hasn't failed... so I think it's unrelated. I have seen that error on my mac though (unrelated to this branch).

cfromknecht

@Crypt-iQ a couple other small comments, fixups can be squashed as well!

htlcswitch/switch.go

wpaulino

Not a blocker, but since there'll be duplicate settles we'll see some error logs that aren't necessary and might lead to users thinking there's an issue. Below are the trace logs for a completed payment:

2019-07-09 18:55:57.835 [DBG] HSWC: ChannelLink(668de44edf52c85c7ec6e54e604dcfe88d6a312cb08afb7d25bf49eb11ecedb4:0): sampled fee rate for 3 block conf: 12500 sat/kw
2019-07-09 18:56:02.893 [TRC] HSWC: Committing fresh circuits: ([]channeldb.CircuitKey) (len=1 cap=1) {
 (channeldb.CircuitKey) (Chan ID=0:0:0, HTLC ID=3)
}
2019-07-09 18:56:02.919 [TRC] HSWC: ChannelLink(401:1:0) received switch packet inkey=(Chan ID=0:0:0, HTLC ID=3), outkey=(Chan ID=401:1:0, HTLC ID=0)
2019-07-09 18:56:02.919 [TRC] HSWC: ChannelLink(401:1:0) Received downstream htlc: payment_hash=71b691fe313daa0a8ff7b18824f755240561a11512a18fe12c7c745dee7ed532, local_log_index=2, batch_size=1
2019-07-09 18:56:02.919 [DBG] HSWC: ChannelLink(401:1:0) Queueing keystone of ADD open circuit: (Chan ID=0:0:0, HTLC ID=3)->(Chan ID=401:1:0, HTLC ID=2)
2019-07-09 18:56:02.972 [TRC] HSWC: Opening finalized circuits: ([]htlcswitch.Keystone) (len=1 cap=1) {
 (htlcswitch.Keystone) (Chan ID=0:0:0, HTLC ID=3) --> (Chan ID=401:1:0, HTLC ID=2)
}
2019-07-09 18:56:03.008 [DBG] HSWC: ChannelLink(401:1:0) removing Add packet (Chan ID=0:0:0, HTLC ID=3) from mailbox
2019-07-09 18:56:03.008 [TRC] HSWC: Deleting resolved circuits: ([]channeldb.CircuitKey) <nil>
2019-07-09 18:56:03.067 [TRC] HSWC: ChannelLink(401:1:0) processing 0 remote adds for height 5
2019-07-09 18:56:03.211 [DBG] HSWC: Closed completed SETTLE circuit for 71b691fe313daa0a8ff7b18824f755240561a11512a18fe12c7c745dee7ed532: (0:0:0, 3) <-> (401:1:0, 2)
2019-07-09 18:56:03.211 [DBG] HSWC: Tearing down open circuit with SETTLE pkt, removing circuit=(Chan ID=0:0:0, HTLC ID=3) with keystone=(Chan ID=401:1:0, HTLC ID=2)
2019-07-09 18:56:03.218 [TRC] HSWC: Deleting resolved circuits: ([]channeldb.CircuitKey) (len=1 cap=1) {
 (channeldb.CircuitKey) (Chan ID=0:0:0, HTLC ID=3)
}
2019-07-09 18:56:03.257 [DBG] HSWC: Closed completed SETTLE circuit for 71b691fe313daa0a8ff7b18824f755240561a11512a18fe12c7c745dee7ed532: (0:0:0, 3) <-> (401:1:0, 2)
2019-07-09 18:56:03.364 [TRC] HSWC: Deleting resolved circuits: ([]channeldb.CircuitKey) <nil>
2019-07-09 18:56:03.440 [DBG] HSWC: ChannelLink(401:1:0): settle-fail-filter &{1 [0]}
2019-07-09 18:56:03.440 [TRC] HSWC: ChannelLink(401:1:0) processing 0 remote adds for height 6
2019-07-09 18:56:03.440 [ERR] HSWC: Unable to find target channel for HTLC settle/fail: channel ID = 401:1:0, HTLC ID = 2
2019-07-09 18:56:03.441 [ERR] HSWC: ChannelLink(401:1:0) unhandled error while forwarding htlc packet over htlcswitch: Unable to find target channel for HTLC settle/fail: channel ID = 401:1:0, HTLC ID = 2
2019-07-09 18:56:12.673 [DBG] HSWC: Sent 100 satoshis and received 0 satoshis in the last 10 seconds (0.200000 tx/sec)
2019-07-09 18:56:18.475 [DBG] HSWC: Acked 1 settle fails: ([]channeldb.SettleFailRef) (len=1 cap=1) {
 (channeldb.SettleFailRef) {
  Source: (lnwire.ShortChannelID) 401:1:0,
  Height: (uint64) 6,
  Index: (uint16) 0
 }
}

htlcswitch/switch.go

wpaulino · 2019-07-10T01:01:42Z

server.go

@@ -430,6 +430,8 @@ func newServer(listenAddrs []net.Addr, chanDB *channeldb.DB, cc *chainControl,
 			htlcswitch.DefaultFwdEventInterval),
 		LogEventTicker: ticker.New(
 			htlcswitch.DefaultLogInterval),
+		AckEventTicker: ticker.New(


Style nit: wrapping should be (if it doesn't fit in 80 chars):

ticker.New( htlcswitch.DefaultAckInterval, )

wpaulino · 2019-07-10T01:04:59Z

htlcswitch/link_test.go

+	// because the settles are pipelined to the switch and otherwise
+	// the bandwidth won't be updated by the time Alice receives a
+	// response here.
+	time.Sleep(2 * time.Second)


We could use a mock ticker to send a force tick and avoid the sleep.

I'm a little confused about how this would work. We can feed ticks to the AckEventTicker, but that won't help since we need to actually wait for the revocation from Bob (the duplicate settle doesn't matter here) and there doesn't seem to be a straightforward way to be notified upon receiving a revocation. We could loop and timeout after some timeout interval, but that's not so clean either...

It seems TestChannelLinkSingleHopPayment fails for a similar reason and can be updated with this.

Ah sorry, you're right. I see why the sleep is indeed needed, seems fine to me as is for now.

Hm, the TestChannelLinkSingleHopPayment no longer fails on my machine with flake-unit, so maybe it's just my Mac.

Nevermind, it flakes!

Can use lntest.WaitPredicate instead?

Get an import cycle then, but we could just copy the function?

Crypt-iQ · 2019-07-10T17:46:50Z

@wpaulino I wasn't entirely sure what to do about the extra error logs - I could remove it if the packet has a destRef field? What was once erroneous behavior is the norm so I think that'd make sense. What do you think?

wpaulino · 2019-07-11T20:57:03Z

@wpaulino I wasn't entirely sure what to do about the extra error logs - I could remove it if the packet has a destRef field? What was once erroneous behavior is the norm so I think that'd make sense. What do you think?

Sounds good to me. I think @cfromknecht had some thoughts on possibly refactoring that portion of code to improve clarity of the new behavior, though I'd say it's not a blocker for this PR.

Crypt-iQ · 2019-07-11T21:47:19Z

@wpaulino I wasn't entirely sure what to do about the extra error logs - I could remove it if the packet has a destRef field? What was once erroneous behavior is the norm so I think that'd make sense. What do you think?

Sounds good to me. I think @cfromknecht had some thoughts on possibly refactoring that portion of code to improve clarity of the new behavior, though I'd say it's not a blocker for this PR.

If we don't log the error, we should still return the error and it will still get reported in the link though. So idk if the change is worth it?

htlcswitch/switch.go

Roasbeef

This diff turned out to be much smaller than I had originally anticipated, me gusta!

Roasbeef · 2019-07-17T01:08:38Z

htlcswitch/switch.go

+
+	// DefaultAckInterval is the duration between attempts to ack any settle
+	// fails in a forwarding package.
+	DefaultAckInterval = 15 * time.Second


I would this we want this value to be much lower, like in the ms? The two above are for non-critical operations like logging.

this isn't too critical, it just needs to happen at some point so we stop resending the htlc internally. if it doesn't happen before shutdown it will be done when on the next connection

lntest/itest/lnd_test.go

cfromknecht

LGTM! Nice work on this optimization @Crypt-iQ !! 💯

Roasbeef · 2019-07-18T18:30:56Z

Needs a rebase @Crypt-iQ.

This commit makes the outgoing link pipeline the settle to the switch as soon as it receives it. Previously, it would wait for a revocation before sending it, which caused increased latency on payments as well as possibly never settling on the incoming link. A duplicate settle is still sent to the switch, but it is handled gracefully. A new AckEventTicker was added to the switch which acknowledges any pending settle / fail entries in an outgoing link's fwd pkgs in batch. This was needed in order to reduce the number of db txn's which would have been incurred by acking whenever we receive a duplicate settle without batching.

Crypt-iQ · 2019-07-18T21:21:34Z

Rebased and squashed fixups @Roasbeef

Roasbeef

LGTM ⛩

cfromknecht · 2019-07-20T01:13:11Z

@Crypt-iQ Cheers to lower latency for anyone routing through LND!! 🍾🎉🔥

joostjager · 2019-10-31T15:02:56Z

Created issue for unjustified error: #3656

Not ideal that there is always an error added to the log during the very basic operation of a successful payment.

Crypt-iQ changed the title ~~[WIP] htlcswitch: pipeline settles to switch~~ htlcswitch: pipeline settles to switch May 31, 2019

Roasbeef added htlcswitch incomplete WIP PR, not fully finalized, but light review possible optimization P3 might get fixed, nice to have labels Jun 18, 2019

wpaulino added this to the 0.7.1 milestone Jul 2, 2019

wpaulino added the v0.7.1 label Jul 2, 2019

cfromknecht reviewed Jul 3, 2019

View reviewed changes

htlcswitch/link.go Outdated Show resolved Hide resolved

cfromknecht reviewed Jul 9, 2019

View reviewed changes

htlcswitch/switch.go Outdated Show resolved Hide resolved

htlcswitch/switch.go Show resolved Hide resolved

Roasbeef requested a review from wpaulino July 9, 2019 23:27

wpaulino reviewed Jul 10, 2019

View reviewed changes

Crypt-iQ force-pushed the pipelining_settle_0525 branch from 09f980e to 9f065dc Compare July 11, 2019 03:36

Crypt-iQ requested a review from Roasbeef as a code owner July 11, 2019 03:36

cfromknecht reviewed Jul 11, 2019

View reviewed changes

htlcswitch/switch.go Outdated Show resolved Hide resolved

htlcswitch/switch.go Show resolved Hide resolved

Roasbeef requested changes Jul 17, 2019

View reviewed changes

Crypt-iQ force-pushed the pipelining_settle_0525 branch 3 times, most recently from 6f1c1c3 to 029956e Compare July 17, 2019 11:05

cfromknecht approved these changes Jul 17, 2019

View reviewed changes

Crypt-iQ force-pushed the pipelining_settle_0525 branch from 029956e to 00814dc Compare July 18, 2019 21:20

Roasbeef approved these changes Jul 19, 2019

View reviewed changes

cfromknecht merged commit 807012f into lightningnetwork:master Jul 20, 2019

Crypt-iQ deleted the pipelining_settle_0525 branch July 20, 2019 01:55

kincaidoneil mentioned this pull request Jul 29, 2019

Troubleshoot LND latency issues interledgerjs/settlement-lightning#37

Open

4 tasks

joostjager mentioned this pull request Oct 31, 2019

Unfounded [ERR] HSWC: Unable to find target channel for HTLC settle/fail #3656

Closed

Crypt-iQ mentioned this pull request Mar 22, 2020

htlcswitch: log fixes #4107

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

htlcswitch: pipeline settles to switch #3143

htlcswitch: pipeline settles to switch #3143

Crypt-iQ commented May 30, 2019 •

edited

Loading

cfromknecht left a comment

Crypt-iQ commented Jul 3, 2019

cfromknecht left a comment

wpaulino left a comment

wpaulino Jul 10, 2019

wpaulino Jul 10, 2019

Crypt-iQ Jul 11, 2019

Crypt-iQ Jul 11, 2019

wpaulino Jul 11, 2019

Crypt-iQ Jul 11, 2019

Crypt-iQ Jul 12, 2019

halseth Jul 18, 2019

Crypt-iQ Jul 18, 2019

Crypt-iQ commented Jul 10, 2019

wpaulino commented Jul 11, 2019

Crypt-iQ commented Jul 11, 2019

Roasbeef left a comment

Roasbeef Jul 17, 2019

cfromknecht Jul 17, 2019

cfromknecht left a comment

Roasbeef commented Jul 18, 2019

Crypt-iQ commented Jul 18, 2019

Roasbeef left a comment

cfromknecht commented Jul 20, 2019

joostjager commented Oct 31, 2019 •

edited

Loading

htlcswitch: pipeline settles to switch #3143

htlcswitch: pipeline settles to switch #3143

Conversation

Crypt-iQ commented May 30, 2019 • edited Loading

cfromknecht left a comment

Choose a reason for hiding this comment

Crypt-iQ commented Jul 3, 2019

cfromknecht left a comment

Choose a reason for hiding this comment

wpaulino left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Crypt-iQ commented Jul 10, 2019

wpaulino commented Jul 11, 2019

Crypt-iQ commented Jul 11, 2019

Roasbeef left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

cfromknecht left a comment

Choose a reason for hiding this comment

Roasbeef commented Jul 18, 2019

Crypt-iQ commented Jul 18, 2019

Roasbeef left a comment

Choose a reason for hiding this comment

cfromknecht commented Jul 20, 2019

joostjager commented Oct 31, 2019 • edited Loading

Crypt-iQ commented May 30, 2019 •

edited

Loading

joostjager commented Oct 31, 2019 •

edited

Loading