Truncate hex strings in front logs (#1679)

Front-end logs can produce a huge amount of logs, with significant duplication. In order to reduce the log volume, we truncate `nodeId` and `channelId` in the MDC to only keep the first 8 hexadecimal characters. Also, override a few `toString` because some channel-queries-related case classes produce huge strings.
ACINQ · Feb 4, 2021 · d053188 · d053188
1 parent ac054a2
commit d053188
Show file tree

Hide file tree

Showing 5 changed files with 22 additions and 8 deletions.
diff --git a/eclair-core/src/main/scala/fr/acinq/eclair/crypto/TransportHandler.scala b/eclair-core/src/main/scala/fr/acinq/eclair/crypto/TransportHandler.scala
@@ -206,7 +206,7 @@ class TransportHandler[T: ClassTag](keyPair: KeyPair, rs: Option[ByteVector], co
 
       case Event(t: T, d: NormalData[T]) =>
         if (d.sendBuffer.normalPriority.size + d.sendBuffer.lowPriority.size >= MAX_BUFFERED) {
-          log.warning(s"send buffer overrun, closing connection")
+          log.warning("send buffer overrun, closing connection")
           connection ! PoisonPill
           stop(FSM.Normal)
         } else if (d.unackedSent.isDefined) {

diff --git a/eclair-core/src/main/scala/fr/acinq/eclair/wire/LightningMessageTypes.scala b/eclair-core/src/main/scala/fr/acinq/eclair/wire/LightningMessageTypes.scala
@@ -241,7 +241,10 @@ object EncodingType {
 }
 // @formatter:on
 
-case class EncodedShortChannelIds(encoding: EncodingType, array: List[ShortChannelId])
+case class EncodedShortChannelIds(encoding: EncodingType, array: List[ShortChannelId]) {
+  /** custom toString because it can get huge in logs */
+  override def toString: String = s"EncodedShortChannelIds($encoding,${array.headOption.getOrElse("")}->${array.lastOption.getOrElse("")} size=${array.size})"
+}
 
 case class QueryShortChannelIds(chainHash: ByteVector32,
                                 shortChannelIds: EncodedShortChannelIds,

diff --git a/eclair-core/src/main/scala/fr/acinq/eclair/wire/QueryShortChannelIdsTlv.scala b/eclair-core/src/main/scala/fr/acinq/eclair/wire/QueryShortChannelIdsTlv.scala
@@ -14,7 +14,10 @@ object QueryShortChannelIdsTlv {
     * @param encoding 0 means uncompressed, 1 means compressed with zlib
     * @param array array of query flags, each flags specifies the info we want for a given channel
     */
-  case class EncodedQueryFlags(encoding: EncodingType, array: List[Long]) extends QueryShortChannelIdsTlv
+  case class EncodedQueryFlags(encoding: EncodingType, array: List[Long]) extends QueryShortChannelIdsTlv {
+    /** custom toString because it can get huge in logs */
+    override def toString: String = s"EncodedQueryFlags($encoding, size=${array.size})"
+  }
 
   case object QueryFlagType {
     val INCLUDE_CHANNEL_ANNOUNCEMENT: Long = 1

diff --git a/eclair-core/src/main/scala/fr/acinq/eclair/wire/ReplyChannelRangeTlv.scala b/eclair-core/src/main/scala/fr/acinq/eclair/wire/ReplyChannelRangeTlv.scala
@@ -1,6 +1,6 @@
 package fr.acinq.eclair.wire
 
-import fr.acinq.eclair.{UInt64, wire}
+import fr.acinq.eclair.UInt64
 import fr.acinq.eclair.wire.CommonCodecs.{varint, varintoverflow}
 import scodec.Codec
 import scodec.codecs._
@@ -22,7 +22,10 @@ object ReplyChannelRangeTlv {
     * @param encoding same convention as for short channel ids
     * @param timestamps
     */
-  case class EncodedTimestamps(encoding: EncodingType, timestamps: List[Timestamps]) extends ReplyChannelRangeTlv
+  case class EncodedTimestamps(encoding: EncodingType, timestamps: List[Timestamps]) extends ReplyChannelRangeTlv {
+    /** custom toString because it can get huge in logs */
+    override def toString: String = s"EncodedTimestamps($encoding, size=${timestamps.size})"
+  }
 
   /**
     *
@@ -36,7 +39,10 @@ object ReplyChannelRangeTlv {
     *
     * @param checksums
     */
-  case class EncodedChecksums(checksums: List[Checksums]) extends ReplyChannelRangeTlv
+  case class EncodedChecksums(checksums: List[Checksums]) extends ReplyChannelRangeTlv {
+    /** custom toString because it can get huge in logs */
+    override def toString: String = s"EncodedChecksums(size=${checksums.size})"
+  }
 
   val timestampsCodec: Codec[Timestamps] = (
     ("timestamp1" | uint32) ::

diff --git a/eclair-front/modules/awseb/logback_eb.xml b/eclair-front/modules/awseb/logback_eb.xml
@@ -25,7 +25,8 @@
                     return formattedMessage.contains("connected to /10.") ||
                     (formattedMessage.contains("connection closed") &amp;&amp; !mdc.containsKey("nodeId")) ||
                     (formattedMessage.contains("transport died") &amp;&amp; !mdc.containsKey("nodeId")) ||
-                    (formattedMessage.contains("stopping") &amp;&amp; !mdc.containsKey("nodeId"));
+                    (formattedMessage.contains("stopping") &amp;&amp; !mdc.containsKey("nodeId")) ||
+                    (formattedMessage.contains("buffering send data"));
                 </expression>
             </evaluator>
             <OnMismatch>NEUTRAL</OnMismatch>
@@ -34,7 +35,8 @@
         <target>System.out</target>
         <withJansi>false</withJansi>
         <encoder>
-            <pattern>${HOSTNAME} %d %-5level %logger{24}%X{category}%X{nodeId}%X{channelId}%X{paymentHash}%.-11X{parentPaymentId}%.-11X{paymentId} - %msg%ex{12}%n</pattern>
+            <!-- the 'replace' conversion word strips the end of 64+ hexadecimal strings and keeps only the first 8 characters -->
+            <pattern>${HOSTNAME} %d %-5level %replace(%logger{24}%X{category}%X{nodeId}%X{channelId}%X{paymentHash}%.-11X{parentPaymentId}%.-11X{paymentId} - %msg){'(?&lt;=[a-f0-9]{8})[a-f0-9]{56,}', ''}%ex{12}%n</pattern>
         </encoder>
     </appender>