Skip to content

Commit 1c38591

Browse files
authored
Get rid of various unnecessary warnings in logs (#2981)
* Watch explicit event for channel actor termination We use an explicit event in the `Peer` when watching for child channel actors being terminated. This should get rid of the warnings in the logs about the `Terminated` event not being handled, or at least provide us more hints of which actors aren't properly being tracked. * Fix disconnect response in channel actors We weren't watching for the right event, which creates a lot of log lines saying that the `Disconnecting` event is unhandled. * Ignore closing negotiation if closing or closed If we receive an outdated closing message, we ignore it without creating a warning in the logs. * Ignore HTLC settlement commands while disconnected We ignore HTLC settlement commands while we're disconnected, they will be retried once the channel has been reestablished. We also ignore commands asking us to sign the latest state or update fees.
1 parent 8827a04 commit 1c38591

File tree

2 files changed

+72
-21
lines changed

2 files changed

+72
-21
lines changed

eclair-core/src/main/scala/fr/acinq/eclair/channel/fsm/Channel.scala

Lines changed: 44 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -2024,7 +2024,19 @@ class Channel(val nodeParams: NodeParams, val wallet: OnChainChannelFunder with
20242024

20252025
case Event(e: Error, d: DATA_CLOSING) => handleRemoteError(e, d)
20262026

2027-
case Event(INPUT_DISCONNECTED | INPUT_RECONNECTED(_, _, _), _) => stay() // we don't really care at this point
2027+
case Event(_: Shutdown, _) =>
2028+
log.debug("ignoring shutdown, closing transaction already published")
2029+
stay()
2030+
2031+
case Event(_: ClosingSigned, _) =>
2032+
log.debug("ignoring closing_signed, closing transaction already published")
2033+
stay()
2034+
2035+
case Event(_: AnnouncementSignatures, _) =>
2036+
log.debug("ignoring announcement_signatures, channel is closing")
2037+
stay()
2038+
2039+
case Event(INPUT_DISCONNECTED | _: INPUT_RECONNECTED, _) => stay() // we don't really care at this point
20282040
})
20292041

20302042
when(CLOSED)(handleExceptions {
@@ -2045,10 +2057,22 @@ class Channel(val nodeParams: NodeParams, val wallet: OnChainChannelFunder with
20452057
stay()
20462058

20472059
case Event(w: WatchTriggered, _) =>
2048-
log.warning("ignoring watch event, channel is closed (event={})", w)
2060+
log.debug("ignoring watch event, channel is closed (event={})", w)
2061+
stay()
2062+
2063+
case Event(_: Shutdown, _) =>
2064+
log.debug("ignoring shutdown, channel is closed")
2065+
stay()
2066+
2067+
case Event(_: ClosingSigned, _) =>
2068+
log.debug("ignoring closing_signed, channel is closed")
20492069
stay()
20502070

2051-
case Event(INPUT_DISCONNECTED, _) => stay() // we are disconnected, but it doesn't matter anymore
2071+
case Event(_: AnnouncementSignatures, _) =>
2072+
log.debug("ignoring announcement_signatures, channel is closed")
2073+
stay()
2074+
2075+
case Event(INPUT_DISCONNECTED | _: INPUT_RECONNECTED, _) => stay() // we are disconnected, but it doesn't matter anymore
20522076
})
20532077

20542078
when(OFFLINE)(handleExceptions {
@@ -2118,6 +2142,14 @@ class Channel(val nodeParams: NodeParams, val wallet: OnChainChannelFunder with
21182142

21192143
case Event(c: CMD_ADD_HTLC, d: DATA_NORMAL) => handleAddDisconnected(c, d)
21202144

2145+
case Event(e: HtlcSettlementCommand, _) =>
2146+
log.debug("cannot settle htlc_id={}, channel is offline", e.id)
2147+
stay()
2148+
2149+
case Event(_: CMD_SIGN, _) => stay()
2150+
2151+
case Event(_: CMD_UPDATE_FEE, _) => stay()
2152+
21212153
case Event(c: CMD_UPDATE_RELAY_FEE, d: DATA_NORMAL) => handleUpdateRelayFeeDisconnected(c, d)
21222154

21232155
case Event(getTxResponse: GetTxWithMetaResponse, d: DATA_WAIT_FOR_FUNDING_CONFIRMED) if getTxResponse.txid == d.commitments.latest.fundingTxId => handleGetFundingTx(getTxResponse, d.waitingSince, d.fundingTx_opt)
@@ -2325,6 +2357,14 @@ class Channel(val nodeParams: NodeParams, val wallet: OnChainChannelFunder with
23252357

23262358
case Event(c: CMD_ADD_HTLC, d: DATA_NORMAL) => handleAddDisconnected(c, d)
23272359

2360+
case Event(e: HtlcSettlementCommand, _) =>
2361+
log.debug("cannot settle htlc_id={}, channel is syncing", e.id)
2362+
stay()
2363+
2364+
case Event(_: CMD_SIGN, _) => stay()
2365+
2366+
case Event(_: CMD_UPDATE_FEE, _) => stay()
2367+
23282368
case Event(c: CMD_UPDATE_RELAY_FEE, d: DATA_NORMAL) => handleUpdateRelayFeeDisconnected(c, d)
23292369

23302370
case Event(channelReestablish: ChannelReestablish, d: DATA_SHUTDOWN) =>
@@ -2469,7 +2509,7 @@ class Channel(val nodeParams: NodeParams, val wallet: OnChainChannelFunder with
24692509
case Event(_: BroadcastChannelUpdate, _) => stay()
24702510

24712511
// we receive this when we tell the peer to disconnect
2472-
case Event("disconnecting", _) => stay()
2512+
case Event(_: Peer.DisconnectResponse, _) => stay()
24732513

24742514
// funding tx was confirmed in time, let's just ignore this
24752515
case Event(BITCOIN_FUNDING_TIMEOUT, _: PersistentChannelData) => stay()

eclair-core/src/main/scala/fr/acinq/eclair/io/Peer.scala

Lines changed: 28 additions & 17 deletions
Original file line numberDiff line numberDiff line change
@@ -18,7 +18,7 @@ package fr.acinq.eclair.io
1818

1919
import akka.actor.typed.scaladsl.Behaviors
2020
import akka.actor.typed.scaladsl.adapter.{ClassicActorContextOps, ClassicActorRefOps}
21-
import akka.actor.{Actor, ActorContext, ActorRef, ExtendedActorSystem, FSM, OneForOneStrategy, PossiblyHarmful, Props, Status, SupervisorStrategy, Terminated, typed}
21+
import akka.actor.{Actor, ActorContext, ActorRef, ExtendedActorSystem, FSM, OneForOneStrategy, PossiblyHarmful, Props, Status, SupervisorStrategy, typed}
2222
import akka.event.Logging.MDC
2323
import akka.event.{BusLogging, DiagnosticLoggingAdapter}
2424
import akka.util.Timeout
@@ -103,11 +103,15 @@ class Peer(val nodeParams: NodeParams,
103103
case Event(connectionReady: PeerConnection.ConnectionReady, d: DisconnectedData) =>
104104
gotoConnected(connectionReady, d.channels.map { case (k: ChannelId, v) => (k, v) }, d.activeChannels, d.peerStorage)
105105

106-
case Event(Terminated(actor), d: DisconnectedData) if d.channels.values.toSet.contains(actor) =>
107-
// we have at most 2 ids: a TemporaryChannelId and a FinalChannelId
108-
val channelIds = d.channels.filter(_._2 == actor).keys
109-
log.info(s"channel closed: channelId=${channelIds.mkString("/")}")
110-
val channels1 = d.channels -- channelIds
106+
case Event(ChannelTerminated(actor), d: DisconnectedData) =>
107+
val channels1 = if (d.channels.values.toSet.contains(actor)) {
108+
// we have at most 2 ids: a TemporaryChannelId and a FinalChannelId
109+
val channelIds = d.channels.filter(_._2 == actor).keys
110+
log.info(s"channel closed: channelId=${channelIds.mkString("/")}")
111+
d.channels -- channelIds
112+
} else {
113+
d.channels
114+
}
111115
if (channels1.isEmpty && canForgetPendingOnTheFlyFunding()) {
112116
log.info("that was the last open channel")
113117
context.system.eventStream.publish(LastChannelClosed(self, remoteNodeId))
@@ -495,17 +499,21 @@ class Peer(val nodeParams: NodeParams,
495499
goto(DISCONNECTED) using DisconnectedData(d.channels.collect { case (k: FinalChannelId, v) => (k, v) }, d.activeChannels, d.peerStorage)
496500
}
497501

498-
case Event(Terminated(actor), d: ConnectedData) if d.channels.values.toSet.contains(actor) =>
499-
// we have at most 2 ids: a TemporaryChannelId and a FinalChannelId
500-
val channelIds = d.channels.filter(_._2 == actor).keys
501-
log.info(s"channel closed: channelId=${channelIds.mkString("/")}")
502-
val channels1 = d.channels -- channelIds
503-
if (channels1.isEmpty) {
504-
log.info("that was the last open channel, closing the connection")
505-
context.system.eventStream.publish(LastChannelClosed(self, remoteNodeId))
506-
d.peerConnection ! PeerConnection.Kill(KillReason.NoRemainingChannel)
502+
case Event(ChannelTerminated(actor), d: ConnectedData) =>
503+
if (d.channels.values.toSet.contains(actor)) {
504+
// we have at most 2 ids: a TemporaryChannelId and a FinalChannelId
505+
val channelIds = d.channels.filter(_._2 == actor).keys
506+
log.info(s"channel closed: channelId=${channelIds.mkString("/")}")
507+
val channels1 = d.channels -- channelIds
508+
if (channels1.isEmpty) {
509+
log.info("that was the last open channel, closing the connection")
510+
context.system.eventStream.publish(LastChannelClosed(self, remoteNodeId))
511+
d.peerConnection ! PeerConnection.Kill(KillReason.NoRemainingChannel)
512+
}
513+
stay() using d.copy(channels = channels1)
514+
} else {
515+
stay()
507516
}
508-
stay() using d.copy(channels = channels1)
509517

510518
case Event(connectionReady: PeerConnection.ConnectionReady, d: ConnectedData) =>
511519
log.debug(s"got new connection, killing current one and switching")
@@ -843,7 +851,7 @@ class Peer(val nodeParams: NodeParams,
843851

844852
private def spawnChannel(): ActorRef = {
845853
val channel = channelFactory.spawn(context, remoteNodeId)
846-
context watch channel
854+
context.watchWith(channel, ChannelTerminated(channel.ref))
847855
channel
848856
}
849857

@@ -1088,6 +1096,9 @@ object Peer {
10881096
*/
10891097
case class ConnectionDown(peerConnection: ActorRef) extends RemoteTypes
10901098

1099+
/** A child channel actor has been terminated. */
1100+
case class ChannelTerminated(channel: ActorRef) extends RemoteTypes
1101+
10911102
case class RelayOnionMessage(messageId: ByteVector32, msg: OnionMessage, replyTo_opt: Option[typed.ActorRef[Status]])
10921103

10931104
case class RelayUnknownMessage(unknownMessage: UnknownMessage)

0 commit comments

Comments
 (0)