chore: introduce a pattern to help standardize log tag names

.changeset/nice-lions-tickle.md

@@ -0,0 +1,5 @@
+---
+"@farcaster/hubble": patch
+---
+
+chore: introduce a pattern to help standardize log tag names

apps/hubble/src/hubble.ts

@@ -51,6 +51,7 @@
   onChainEventToLog,
   SubmitMessageSuccessLogCache,
   usernameProofToLog,
+  Tags,
 } from "./utils/logger.js";
 import {
   addressInfoFromGossip,
@@ -1757,7 +1758,7 @@
       }
     }
 
-    log.info({ peerId }, "falling back to addressbook lookup for peer");
+    log.info(new Tags({ peerId: peerId.toString() }), "falling back to addressbook lookup for peer");
     const peerAddresses = await this.gossipNode.getPeerAddresses(peerId);
     if (!peerAddresses) {
       log.info({ function: "getRPCClientForPeer", peer }, `failed to find peer's address to request simple sync`);

apps/hubble/src/network/p2p/gossipNode.ts

@@ -25,7 +25,7 @@
 import { multiaddr, Multiaddr } from "@multiformats/multiaddr";
 import { err, ok, Result } from "neverthrow";
 import { TypedEmitter } from "tiny-typed-emitter";
-import { logger, messageTypeToName } from "../../utils/logger.js";
+import { logger, messageTypeToName, Tags } from "../../utils/logger.js";
 import { PeriodicPeerCheckScheduler } from "./periodicPeerCheck.js";
 import { GOSSIP_PROTOCOL_VERSION } from "./protocol.js";
 import { AddrInfo } from "@chainsafe/libp2p-gossipsub/types";
@@ -267,7 +267,7 @@
   async putPeerAddrToDB(peerIdStr: string, addr: string) {
     if (this._db) {
       await this._db.put(this.makePeerKey(peerIdStr), Buffer.from(addr));
-      log.info({ peerId: peerIdStr, addr }, "Added peer to DB");
+      log.info(new Tags({ addr, peerId: peerIdStr }), "Added peer to DB");
     }
   }
 
@@ -302,9 +302,9 @@
       const peerAddr = multiaddr(addr);
       const result = await this.connectAddress(peerAddr);
       if (result.isOk()) {
-        log.info({ peerIdStr, addr }, "Connected to peer from DB");
+        log.info(new Tags({ addr, peerId: peerIdStr }), "Connected to peer from DB");
       } else {
-        log.debug({ peerIdStr, addr, error: result.error }, "Failed to connect to peer from DB");
+        log.debug(new Tags({ addr, error: result.error, peerId: peerIdStr }), "Failed to connect to peer from DB");
       }
 
       // Sleep for a bit to avoid overwhelming the network
@@ -546,11 +546,11 @@
     this._nodeEvents?.addListener("connection:open", (detail: Connection) => {
       // console.log("Peer Connected", JSON.stringify(detail, null, 2));
       log.info(
-        {
-          peer: detail.remotePeer,
+        new Tags({
           addrs: detail.remoteAddr,
           type: detail.direction,
-        },
+          peerId: detail.remotePeer.toString(),
+        }),
         "P2P Connection established",
       );
       this.emit("peerConnect", detail);
@@ -561,12 +561,12 @@
       this.putPeerAddrToDB(detail.remotePeer.toString(), detail.remoteAddr.toString());
     });
     this._nodeEvents?.addListener("connection:close", (detail: Connection) => {
-      log.info({ peer: detail.remotePeer }, "P2P Connection disconnected");
+      log.info(new Tags({ peerId: detail.remotePeer.toString() }), "P2P Connection disconnected");
       this.emit("peerDisconnect", detail);
       this.updateStatsdPeerGauges();
     });
     this._nodeEvents?.addListener("peer:discovery", (detail) => {
-      log.info({ peer: detail }, "Discovered peer");
+      log.info(new Tags({ peerId: detail.remotePeer?.toString() }), "Discovered peer");
     });
     this._nodeEvents?.addListener("gossipsub:message", (detail: GossipsubMessage) => {
       log.debug({

apps/hubble/src/network/sync/syncHealthJob.ts

@@ -1,5 +1,5 @@
 import cron from "node-cron";
-import { logger } from "../../utils/logger.js";
+import { logger, Tags } from "../../utils/logger.js";
 import SyncEngine from "./syncEngine.js";
 import { RpcMetadataRetriever, SyncEngineMetadataRetriever, SyncHealthProbe } from "../../utils/syncHealth.js";
 import { HubInterface } from "hubble.js";
@@ -109,43 +109,15 @@
     let numAlreadyMerged = 0;
     for (const result of results) {
       if (result.isOk()) {
-        const hashString = bytesToHexString(result.value.hash);
-        const hash = hashString.isOk() ? hashString.value : "unable to show hash";
-
-        const typeValue = result.value.data?.type;
-        const type = typeValue ? UserDataType[typeValue] : "unknown type";
-
         log.info(
-          {
-            msgDetails: {
-              type,
-              fid: result.value.data?.fid,
-              timestamp: this.unixTimestampFromMessage(result.value),
-              hash,
-              peerId,
-            },
-            startTime,
-            stopTime,
-          },
+          new Tags({ peerId, message: result.value, startTime, stopTime }),
           "Successfully submitted message via SyncHealth",
         );
 
         numSuccesses += 1;
       } else {
-        const hashString = bytesToHexString(result.error.originalMessage.hash);
-        const hash = hashString.isOk() ? hashString.value : "unable to show hash";
-
-        const logTags = {
-          errMessage: result.error.hubError.message,
-          peerId,
-          startTime,
-          stopTime,
-          msgDetails: {
-            fid: result.error.originalMessage.data?.fid,
-            timestamp: this.unixTimestampFromMessage(result.error.originalMessage),
-            hash,
-          },
-        };
+        const logTags = new Tags({ errMessage: result.error.hubError.message, startTime, stopTime });
+
         if (result.error.hubError.errCode === "bad_request.duplicate") {
           // This message has already been merged into the DB, but for some reason is not in the Trie.
           // Just update the trie.
@@ -166,7 +138,7 @@
       const contactInfo = this._metadataRetriever._syncEngine.getContactInfoForPeerId(peer.identifier);
 
       if (!contactInfo) {
-        log.info({ peerId: peer.identifier }, "Couldn't get contact info for peer");
+        log.info(new Tags({ peerId: peer.identifier }), "Couldn't get contact info for peer");
         return undefined;
       }
 
@@ -205,7 +177,7 @@
       const rpcClient = await this.getRpcClient(peer);
 
       if (rpcClient === undefined) {
-        log.info({ peerId: peer.identifier }, "Couldn't get rpc client, skipping peer");
+        log.info(new Tags({ peerId: peer.identifier }), "Couldn't get rpc client, skipping peer");
         continue;
       }
 
@@ -225,11 +197,11 @@
         if (syncHealthMessageStats.isErr()) {
           const contactInfo = this.contactInfoForLogs(peer);
           log.info(
-            {
-              peerId: peer.identifier,
+            new Tags({
               err: syncHealthMessageStats.error,
               contactInfo,
-            },
+              peerId: peer.identifier,
+            }),
             `Error computing SyncHealth: ${syncHealthMessageStats.error}.`,
           );
           continue;

apps/hubble/src/utils/logger.ts

@@ -134,6 +134,46 @@
   }
 }
 
+export type TagFields = {
+  fid?: number;
+  timestamp?: number;
+  peerId?: string;
+  messageType?: MessageType;
+  message?: Message;
+  // biome-ignore lint/suspicious/noExplicitAny: justified use case
+  [key: string]: any;
+};
+
+// Always go through this class to construct log tags so that tag names are standardized.
+export class Tags {
+  private fields: TagFields;
+
+  constructor(fields: TagFields) {
+    this.fields = fields;
+  }
+
+  toString() {
+    const extraFields = Object.fromEntries(
+      Object.entries(this.fields).filter(([key, value]) => {
+        return !["fid", "timestamp", "peerId", "messageType", "message"].includes(key);
+      }),
+    );
+    JSON.stringify({
+      fid: this.fields.fid,
+      timestamp: this.fields.timestamp,
+      peerId: this.fields.peerId,
+      messageType: this.fields.messageType,
+      messageFields: {
+        timestamp: fromFarcasterTime(this.fields.message?.data?.timestamp || 0)._unsafeUnwrap(),
+        hash: this.fields.message ? bytesToHexString(this.fields.message.hash)._unsafeUnwrap() : undefined,
+        fid: this.fields.message?.data?.fid,
+        type: this.fields.message?.data?.type,
+      },
+      ...extraFields,
+    });
+  }
+}
+
 export const logger = new BufferedLogger().createProxy();
 export type Logger = pino.Logger;