From 1a00bd44fea14c3cc2873dff1ad52fad1ea7e468 Mon Sep 17 00:00:00 2001 From: t-bast Date: Tue, 6 Jul 2021 11:35:35 +0200 Subject: [PATCH] Use warning messages for connection issues https://github.com/lightningnetwork/lightning-rfc/pull/834 recommends sending warning messages instead of connection-level errors in some cases, which avoids unnecessary channel closure. --- .../fr/acinq/eclair/channel/Channel.scala | 6 ++-- .../main/scala/fr/acinq/eclair/io/Peer.scala | 7 ++--- .../fr/acinq/eclair/io/PeerConnection.scala | 29 ++++++++++++------- .../acinq/eclair/io/PeerConnectionSpec.scala | 18 ++++++++---- 4 files changed, 36 insertions(+), 24 deletions(-) diff --git a/eclair-core/src/main/scala/fr/acinq/eclair/channel/Channel.scala b/eclair-core/src/main/scala/fr/acinq/eclair/channel/Channel.scala index 7756577489..a4194774f2 100644 --- a/eclair-core/src/main/scala/fr/acinq/eclair/channel/Channel.scala +++ b/eclair-core/src/main/scala/fr/acinq/eclair/channel/Channel.scala @@ -1701,16 +1701,18 @@ class Channel(val nodeParams: NodeParams, val wallet: EclairWallet, remoteNodeId // a channel_reestablish when reconnecting a channel that recently got confirmed, and instead send a funding_locked // first and then go silent. This is due to a race condition on their side, so we trigger a reconnection, hoping that // we will eventually receive their channel_reestablish. - case Event(_: FundingLocked, _) => + case Event(_: FundingLocked, d) => log.warning("received funding_locked before channel_reestablish (known lnd bug): disconnecting...") + send(Warning(d.channelId, "spec violation: you sent funding_locked before channel_reestablish")) peer ! Peer.Disconnect(remoteNodeId) stay // This handler is a workaround for an issue in lnd similar to the one above: they sometimes send announcement_signatures // before channel_reestablish, which is a minor spec violation. It doesn't halt the channel, we can simply postpone // that message. - case Event(remoteAnnSigs: AnnouncementSignatures, _) => + case Event(remoteAnnSigs: AnnouncementSignatures, d) => log.warning("received announcement_signatures before channel_reestablish (known lnd bug): delaying...") + send(Warning(d.channelId, "spec violation: you sent announcement_signatures before channel_reestablish")) context.system.scheduler.scheduleOnce(5 seconds, self, remoteAnnSigs) stay diff --git a/eclair-core/src/main/scala/fr/acinq/eclair/io/Peer.scala b/eclair-core/src/main/scala/fr/acinq/eclair/io/Peer.scala index 30a336572c..8f32281ede 100644 --- a/eclair-core/src/main/scala/fr/acinq/eclair/io/Peer.scala +++ b/eclair-core/src/main/scala/fr/acinq/eclair/io/Peer.scala @@ -106,7 +106,7 @@ class Peer(val nodeParams: NodeParams, remoteNodeId: PublicKey, wallet: EclairWa stay case Event(warning: Warning, _: ConnectedData) => - log.warning("peer sent warning: {}", warning.channelId, warning.toAscii) + log.warning("peer sent warning: {}", warning.toAscii) // NB: we don't forward warnings to the channel actors, they shouldn't take any automatic action. // It's up to the node operator to decide what to do to address the warning. stay @@ -318,7 +318,7 @@ class Peer(val nodeParams: NodeParams, remoteNodeId: PublicKey, wallet: EclairWa } def replyUnknownChannel(peerConnection: ActorRef, unknownChannelId: ByteVector32): Unit = { - val msg = Error(unknownChannelId, UNKNOWN_CHANNEL_MESSAGE) + val msg = Warning(unknownChannelId, "unknown channel") logMessage(msg, "OUT") peerConnection ! msg } @@ -361,10 +361,7 @@ class Peer(val nodeParams: NodeParams, remoteNodeId: PublicKey, wallet: EclairWa object Peer { - // @formatter:off val CHANNELID_ZERO: ByteVector32 = ByteVector32.Zeroes - val UNKNOWN_CHANNEL_MESSAGE: ByteVector = ByteVector.view("unknown channel".getBytes()) - // @formatter:on trait ChannelFactory { def spawn(context: ActorContext, remoteNodeId: PublicKey, origin_opt: Option[ActorRef]): ActorRef diff --git a/eclair-core/src/main/scala/fr/acinq/eclair/io/PeerConnection.scala b/eclair-core/src/main/scala/fr/acinq/eclair/io/PeerConnection.scala index 8bcdd3742a..e0fead89a8 100644 --- a/eclair-core/src/main/scala/fr/acinq/eclair/io/PeerConnection.scala +++ b/eclair-core/src/main/scala/fr/acinq/eclair/io/PeerConnection.scala @@ -24,7 +24,6 @@ import fr.acinq.eclair.Logs.LogCategory import fr.acinq.eclair.crypto.Noise.KeyPair import fr.acinq.eclair.crypto.TransportHandler import fr.acinq.eclair.io.Monitoring.{Metrics, Tags} -import fr.acinq.eclair.io.Peer.CHANNELID_ZERO import fr.acinq.eclair.remote.EclairInternalsSerializer.RemoteTypes import fr.acinq.eclair.router.Router._ import fr.acinq.eclair.wire.protocol @@ -195,18 +194,24 @@ class PeerConnection(keyPair: KeyPair, conf: PeerConnection.Conf, switchboard: A d.transport ! Pong(ByteVector.fill(pongLength)(0.toByte)) } else { log.warning(s"ignoring invalid ping with pongLength=${ping.pongLength}") + d.transport ! Warning(s"invalid pong length (${ping.pongLength})") } stay case Event(pong@Pong(data), d: ConnectedData) => d.transport ! TransportHandler.ReadAck(pong) d.expectedPong_opt match { - case Some(ExpectedPong(ping, timestamp)) if ping.pongLength == data.length => - // we use the pong size to correlate between pings and pongs - val latency = System.currentTimeMillis - timestamp - log.debug(s"received pong with latency=$latency") - cancelTimer(PingTimeout.toString()) - // we don't need to call scheduleNextPing here, the next ping was already scheduled when we received that pong + case Some(ExpectedPong(ping, timestamp)) => + if (ping.pongLength == data.length) { + // we use the pong size to correlate between pings and pongs + val latency = System.currentTimeMillis - timestamp + log.debug(s"received pong with latency=$latency") + cancelTimer(PingTimeout.toString()) + // we don't need to call scheduleNextPing here, the next ping was already scheduled when we received that pong + } else { + log.warning(s"ignoring invalid pong with length=${data.length}") + d.transport ! Warning(s"invalid pong length (${data.length})") + } case None => log.debug(s"received unexpected pong with size=${data.length}") } @@ -264,6 +269,7 @@ class PeerConnection(keyPair: KeyPair, conf: PeerConnection.Conf, switchboard: A d.transport ! TransportHandler.ReadAck(msg) if (msg.chainHash != d.chainHash) { log.warning("received gossip_timestamp_range message for chain {}, we're on {}", msg.chainHash, d.chainHash) + d.transport ! Warning(s"invalid gossip_timestamp_range chain (${msg.chainHash})") stay } else { log.info(s"setting up gossipTimestampFilter=$msg") @@ -306,16 +312,16 @@ class PeerConnection(keyPair: KeyPair, conf: PeerConnection.Conf, switchboard: A case _ => "unknown" } log.error(s"peer sent us a routing message with invalid sig: r=$r bin=$bin") - // for now we just return an error, maybe ban the peer in the future? + // for now we just send a warning, maybe ban the peer in the future? // TODO: this doesn't actually disconnect the peer, once we introduce peer banning we should actively disconnect - d.transport ! Error(CHANNELID_ZERO, ByteVector.view(s"bad announcement sig! bin=$bin".getBytes())) + d.transport ! Warning(s"invalid announcement sig (bin=$bin)") d.behavior case GossipDecision.InvalidAnnouncement(c) => // they seem to be sending us fake announcements? log.error(s"couldn't find funding tx with valid scripts for shortChannelId=${c.shortChannelId}") - // for now we just return an error, maybe ban the peer in the future? + // for now we just send a warning, maybe ban the peer in the future? // TODO: this doesn't actually disconnect the peer, once we introduce peer banning we should actively disconnect - d.transport ! Error(CHANNELID_ZERO, ByteVector.view(s"couldn't verify channel! shortChannelId=${c.shortChannelId}".getBytes())) + d.transport ! Warning(s"invalid announcement, couldn't verify channel (shortChannelId=${c.shortChannelId})") d.behavior case GossipDecision.ChannelClosed(_) => if (d.behavior.ignoreNetworkAnnouncement) { @@ -325,6 +331,7 @@ class PeerConnection(keyPair: KeyPair, conf: PeerConnection.Conf, switchboard: A d.behavior.copy(fundingTxAlreadySpentCount = d.behavior.fundingTxAlreadySpentCount + 1) } else { log.warning(s"peer sent us too many channel announcements with funding tx already spent (count=${d.behavior.fundingTxAlreadySpentCount + 1}), ignoring network announcements for $IGNORE_NETWORK_ANNOUNCEMENTS_PERIOD") + d.transport ! Warning("too many channel announcements with funding tx already spent, please check your bitcoin node") setTimer(ResumeAnnouncements.toString, ResumeAnnouncements, IGNORE_NETWORK_ANNOUNCEMENTS_PERIOD, repeat = false) d.behavior.copy(fundingTxAlreadySpentCount = d.behavior.fundingTxAlreadySpentCount + 1, ignoreNetworkAnnouncement = true) } diff --git a/eclair-core/src/test/scala/fr/acinq/eclair/io/PeerConnectionSpec.scala b/eclair-core/src/test/scala/fr/acinq/eclair/io/PeerConnectionSpec.scala index f118691201..afe397d005 100644 --- a/eclair-core/src/test/scala/fr/acinq/eclair/io/PeerConnectionSpec.scala +++ b/eclair-core/src/test/scala/fr/acinq/eclair/io/PeerConnectionSpec.scala @@ -231,6 +231,7 @@ class PeerConnectionSpec extends TestKitBaseClass with FixtureAnyFunSuiteLike wi val ping = Ping(Int.MaxValue, randomBytes(127)) transport.send(peerConnection, ping) transport.expectMsg(TransportHandler.ReadAck(ping)) + assert(transport.expectMsgType[Warning].channelId === Peer.CHANNELID_ZERO) transport.expectNoMsg() } @@ -332,8 +333,13 @@ class PeerConnectionSpec extends TestKitBaseClass with FixtureAnyFunSuiteLike wi router.send(peerConnection, GossipDecision.ChannelClosed(c)) } // peer will temporary ignore announcements coming from bob + var warningSent = false for (ann <- channels ++ updates) { transport.send(peerConnection, ann) + if (!warningSent) { + transport.expectMsgType[Warning] + warningSent = true + } transport.expectMsg(TransportHandler.ReadAck(ann)) } router.expectNoMsg(1 second) @@ -354,16 +360,16 @@ class PeerConnectionSpec extends TestKitBaseClass with FixtureAnyFunSuiteLike wi // now let's assume that the router isn't happy with those channels because the announcement is invalid router.send(peerConnection, GossipDecision.InvalidAnnouncement(channels(0))) // peer will return a connection-wide error, including the hex-encoded representation of the bad message - val error1 = transport.expectMsgType[Error] - assert(error1.channelId === Peer.CHANNELID_ZERO) - assert(new String(error1.data.toArray).startsWith("couldn't verify channel! shortChannelId=")) + val warn1 = transport.expectMsgType[Warning] + assert(warn1.channelId === Peer.CHANNELID_ZERO) + assert(new String(warn1.data.toArray).startsWith("invalid announcement, couldn't verify channel")) // let's assume that one of the sigs were invalid router.send(peerConnection, GossipDecision.InvalidSignature(channels(0))) // peer will return a connection-wide error, including the hex-encoded representation of the bad message - val error2 = transport.expectMsgType[Error] - assert(error2.channelId === Peer.CHANNELID_ZERO) - assert(new String(error2.data.toArray).startsWith("bad announcement sig! bin=0100")) + val warn2 = transport.expectMsgType[Warning] + assert(warn2.channelId === Peer.CHANNELID_ZERO) + assert(new String(warn2.data.toArray).startsWith("invalid announcement sig")) } }