From 25b0a2d7aae2e42f495633a663e9bae268db1bd8 Mon Sep 17 00:00:00 2001 From: t-bast Date: Fri, 1 Oct 2021 15:17:17 +0200 Subject: [PATCH] Add log file for important notifications Add a new log file for important notifications that require an action from the node operator. Using a separate log file makes it easier than grepping specific messages from the standard logs, and lets us use a different style of messaging, where we provide more information about what steps to take to resolve the issue. --- docs/release-notes/eclair-vnext.md | 5 +++++ .../src/main/scala/fr/acinq/eclair/Logs.scala | 6 ++++-- .../main/scala/fr/acinq/eclair/Setup.scala | 1 + .../acinq/eclair/balance/BalanceActor.scala | 6 +++++- .../fr/acinq/eclair/channel/Channel.scala | 5 ++++- .../main/scala/fr/acinq/eclair/io/Peer.scala | 1 + .../src/test/resources/logback-test.xml | 19 +++++++++++++++---- eclair-front/src/main/resources/logback.xml | 19 +++++++++++++++++++ eclair-node/src/main/resources/logback.xml | 19 +++++++++++++++++++ .../src/main/scala/fr/acinq/eclair/Boot.scala | 8 ++------ .../src/test/resources/logback-test.xml | 13 ++++++++++++- 11 files changed, 87 insertions(+), 15 deletions(-) diff --git a/docs/release-notes/eclair-vnext.md b/docs/release-notes/eclair-vnext.md index e129106981..9f5d123b68 100644 --- a/docs/release-notes/eclair-vnext.md +++ b/docs/release-notes/eclair-vnext.md @@ -116,6 +116,11 @@ We still support receiving non-segwit remote scripts, but will force-close if th See the [spec discussions](https://github.com/lightningnetwork/lightning-rfc/pull/894) for more details. +### Separate log for important notifications + +Eclair added a new log file (`notifications.log`) for important notifications that require an action from the node operator. +Node operators should watch this file very regularly. + ### Sample GUI removed We previously included code for a sample GUI: `eclair-node-gui`. diff --git a/eclair-core/src/main/scala/fr/acinq/eclair/Logs.scala b/eclair-core/src/main/scala/fr/acinq/eclair/Logs.scala index 5f83f372c4..e9f4e13ef8 100644 --- a/eclair-core/src/main/scala/fr/acinq/eclair/Logs.scala +++ b/eclair-core/src/main/scala/fr/acinq/eclair/Logs.scala @@ -28,11 +28,15 @@ import fr.acinq.eclair.io.{Peer, PeerConnection} import fr.acinq.eclair.router.Router._ import fr.acinq.eclair.router._ import fr.acinq.eclair.wire.protocol._ +import grizzled.slf4j.Logger import java.util.UUID object Logs { + /** This logger should be used to log important notifications for the node operator. */ + val notifications = Logger("notifications") + /** * @param parentPaymentId_opt depending on the context, this may be: * - for a send : the parent payment id @@ -77,7 +81,6 @@ object Logs { } } - // @formatter: off sealed trait LogCategory { def category: String } @@ -138,7 +141,6 @@ object Logs { } } - // @formatter: on } // we use a dedicated class so that the logging can be independently adjusted diff --git a/eclair-core/src/main/scala/fr/acinq/eclair/Setup.scala b/eclair-core/src/main/scala/fr/acinq/eclair/Setup.scala index d25a194ace..8c14a9c6ce 100644 --- a/eclair-core/src/main/scala/fr/acinq/eclair/Setup.scala +++ b/eclair-core/src/main/scala/fr/acinq/eclair/Setup.scala @@ -79,6 +79,7 @@ class Setup(val datadir: File, implicit val ec = ExecutionContext.Implicits.global implicit val sttpBackend = OkHttpFutureBackend() + Logs.notifications.info(s"eclair is starting (version=${Kit.getVersion} commit=${Kit.getCommit})") logger.info(s"hello!") logger.info(s"version=${Kit.getVersion} commit=${Kit.getCommit}") logger.info(s"datadir=${datadir.getCanonicalPath}") diff --git a/eclair-core/src/main/scala/fr/acinq/eclair/balance/BalanceActor.scala b/eclair-core/src/main/scala/fr/acinq/eclair/balance/BalanceActor.scala index 923d04a6ef..e65373fb64 100644 --- a/eclair-core/src/main/scala/fr/acinq/eclair/balance/BalanceActor.scala +++ b/eclair-core/src/main/scala/fr/acinq/eclair/balance/BalanceActor.scala @@ -2,7 +2,8 @@ package fr.acinq.eclair.balance import akka.actor.typed.scaladsl.{ActorContext, Behaviors} import akka.actor.typed.{ActorRef, Behavior} -import fr.acinq.bitcoin.ByteVector32 +import fr.acinq.bitcoin.{ByteVector32, MilliBtcDouble} +import fr.acinq.eclair.Logs import fr.acinq.eclair.balance.BalanceActor._ import fr.acinq.eclair.balance.CheckBalance.GlobalBalance import fr.acinq.eclair.balance.Monitoring.{Metrics, Tags} @@ -83,6 +84,9 @@ private class BalanceActor(context: ActorContext[Command], case Success(result) => log.info("current balance: total={} onchain.confirmed={} onchain.unconfirmed={} offchain={}", result.total.toDouble, result.onChain.confirmed.toDouble, result.onChain.unconfirmed.toDouble, result.offChain.total.toDouble) log.debug("current balance details : {}", result) + if (result.onChain.confirmed < 1.millibtc) { + Logs.notifications.warn(s"on-chain confirmed balance is low (${result.onChain.confirmed.toMilliBtc}), eclair may not be able to guarantee funds safety in case channels force-close: you should add some utxos to your bitcoin wallet") + } Metrics.GlobalBalance.withoutTags().update(result.total.toMilliBtc.toDouble) Metrics.GlobalBalanceDetailed.withTag(Tags.BalanceType, Tags.BalanceTypes.OnchainConfirmed).update(result.onChain.confirmed.toMilliBtc.toDouble) Metrics.GlobalBalanceDetailed.withTag(Tags.BalanceType, Tags.BalanceTypes.OnchainUnconfirmed).update(result.onChain.unconfirmed.toMilliBtc.toDouble) 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 f5e0c0711b..148c8bba80 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 @@ -2485,6 +2485,7 @@ class Channel(val nodeParams: NodeParams, val wallet: OnChainChannelFunder, remo case None => // the published tx was neither their current commitment nor a revoked one log.error(s"couldn't identify txid=${tx.txid}, something very bad is going on!!!") + Logs.notifications.error(s"funding tx ${d.commitments.commitInput.outPoint.txid} of channel ${d.channelId} was spent by an unknown transaction, indicating that your DB has lost data or your node has been breached: please contact the dev team.") goto(ERR_INFORMATION_LEAK) } } @@ -2508,7 +2509,8 @@ class Channel(val nodeParams: NodeParams, val wallet: OnChainChannelFunder, remo private def handleInformationLeak(tx: Transaction, d: HasCommitments) = { // this is never supposed to happen !! - log.error(s"our funding tx ${d.commitments.commitInput.outPoint.txid} was spent by txid=${tx.txid} !!") + log.error(s"our funding tx ${d.commitments.commitInput.outPoint.txid} was spent by txid=${tx.txid}!!") + Logs.notifications.error(s"funding tx ${d.commitments.commitInput.outPoint.txid} of channel ${d.channelId} was spent by an unknown transaction, indicating that your DB has lost data or your node has been breached: please contact the dev team.") val exc = FundingTxSpent(d.channelId, tx) val error = Error(d.channelId, exc.getMessage) @@ -2604,6 +2606,7 @@ class Channel(val nodeParams: NodeParams, val wallet: OnChainChannelFunder, remo } catch { case t: SQLException => log.error(t, "fatal database error\n") + Logs.notifications.error("eclair is shutting down because of a fatal database error", t) sys.exit(-2) case t: Throwable => handleLocalError(t, event.stateData, None) } 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 69bda6a352..e6e782ced2 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 @@ -114,6 +114,7 @@ class Peer(val nodeParams: NodeParams, remoteNodeId: PublicKey, wallet: OnChainA case Event(err@Error(channelId, reason, _), d: ConnectedData) if channelId == CHANNELID_ZERO => log.error(s"connection-level error, failing all channels! reason=${new String(reason.toArray)}") + Logs.notifications.info(s"$remoteNodeId sent us a connection-level error, closing all channels (reason=${new String(reason.toArray)})") d.channels.values.toSet[ActorRef].foreach(_ forward err) // we deduplicate with toSet because there might be two entries per channel (tmp id and final id) d.peerConnection ! PeerConnection.Kill(KillReason.AllChannelsFail) stay() diff --git a/eclair-core/src/test/resources/logback-test.xml b/eclair-core/src/test/resources/logback-test.xml index 61d69722c5..02005a0eea 100644 --- a/eclair-core/src/test/resources/logback-test.xml +++ b/eclair-core/src/test/resources/logback-test.xml @@ -24,29 +24,40 @@ + + System.out + + %d %highlight(%-5level)- %msg%ex{12}%n + + + - + - + - + + + + - + + diff --git a/eclair-front/src/main/resources/logback.xml b/eclair-front/src/main/resources/logback.xml index 395f1dad75..18aaba8def 100644 --- a/eclair-front/src/main/resources/logback.xml +++ b/eclair-front/src/main/resources/logback.xml @@ -39,6 +39,20 @@ + + ${eclair.datadir:-${user.home}/.eclair}/notifications.log + + + ${eclair.datadir:-${user.home}/.eclair}/notifications.%d{yyyy-MM-dd}.log + + 30 + 1GB + + + %d %highlight(%-5level)- %msg%ex{24}%n + + + @@ -52,6 +66,11 @@ + + + + + diff --git a/eclair-node/src/main/resources/logback.xml b/eclair-node/src/main/resources/logback.xml index f3f71bdc5c..29d0eb12b2 100644 --- a/eclair-node/src/main/resources/logback.xml +++ b/eclair-node/src/main/resources/logback.xml @@ -39,6 +39,20 @@ + + ${eclair.datadir:-${user.home}/.eclair}/notifications.log + + + ${eclair.datadir:-${user.home}/.eclair}/notifications.%d{yyyy-MM-dd}.log + + 30 + 1GB + + + %d %highlight(%-5level)- %msg%ex{24}%n + + + @@ -52,6 +66,11 @@ + + + + + diff --git a/eclair-node/src/main/scala/fr/acinq/eclair/Boot.scala b/eclair-node/src/main/scala/fr/acinq/eclair/Boot.scala index 2e63b178cf..c60535bb2c 100644 --- a/eclair-node/src/main/scala/fr/acinq/eclair/Boot.scala +++ b/eclair-node/src/main/scala/fr/acinq/eclair/Boot.scala @@ -16,8 +16,6 @@ package fr.acinq.eclair -import java.io.File - import akka.actor.ActorSystem import akka.http.scaladsl.Http import akka.stream.BindFailedException @@ -25,6 +23,7 @@ import fr.acinq.eclair.api.Service import grizzled.slf4j.Logging import kamon.Kamon +import java.io.File import scala.concurrent.ExecutionContext import scala.util.{Failure, Success} @@ -61,10 +60,6 @@ object Boot extends App with Logging { /** * Starts the http APIs service if enabled in the configuration - * - * @param kit - * @param system - * @param ec */ def startApiServiceIfEnabled(kit: Kit, providers: Seq[RouteProvider] = Nil)(implicit system: ActorSystem, ec: ExecutionContext) = { val config = system.settings.config.getConfig("eclair") @@ -91,6 +86,7 @@ object Boot extends App with Logging { val errorMsg = if (t.getMessage != null) t.getMessage else t.getClass.getSimpleName System.err.println(s"fatal error: $errorMsg") logger.error(s"fatal error: $errorMsg", t) + Logs.notifications.error("could not start eclair:", t) System.exit(1) } } diff --git a/eclair-node/src/test/resources/logback-test.xml b/eclair-node/src/test/resources/logback-test.xml index 25719eb7b7..3a851bd91d 100644 --- a/eclair-node/src/test/resources/logback-test.xml +++ b/eclair-node/src/test/resources/logback-test.xml @@ -24,8 +24,19 @@ + + System.out + + %d %highlight(%-5level)- %msg%ex{12}%n + + + + + + + - + \ No newline at end of file