Skip to content

Commit 5080bbb

Browse files
authored
chore: introduce a pattern to help standardize log tag names (#2371)
It's hard to filter logs by tag if we name the same tag different things in different places. Introduce a pattern for constructing logs that pushes us toward standardizing log tag names. ## Merge Checklist _Choose all relevant options below by adding an `x` now or at any time before submitting for review_ - [x] PR title adheres to the [conventional commits](https://www.conventionalcommits.org/en/v1.0.0/) standard - [x] PR has a [changeset](https://github.com/farcasterxyz/hub-monorepo/blob/main/CONTRIBUTING.md#35-adding-changesets) - [x] PR has been tagged with a change label(s) (i.e. documentation, feature, bugfix, or chore) - [ ] PR includes [documentation](https://github.com/farcasterxyz/hub-monorepo/blob/main/CONTRIBUTING.md#32-writing-docs) if necessary. <!-- start pr-codex --> --- ## PR-Codex overview This PR focuses on standardizing log tag names by introducing a `Tags` class, which is used throughout the codebase to create consistent log entries. ### Detailed summary - Introduced `Tags` class in `apps/hubble/src/utils/logger.ts` for standardized log tags. - Updated logging in `apps/hubble/src/hubble.ts`, `apps/hubble/src/network/p2p/gossipNode.ts`, and `apps/hubble/src/network/sync/syncHealthJob.ts` to use `Tags`. - Added `TagFields` type definition for better structure of log fields. > ✨ Ask PR-Codex anything about this PR by commenting with `/codex {your question}` <!-- end pr-codex -->
1 parent 8c13640 commit 5080bbb

File tree

5 files changed

+65
-47
lines changed

5 files changed

+65
-47
lines changed

.changeset/nice-lions-tickle.md

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,5 @@
1+
---
2+
"@farcaster/hubble": patch
3+
---
4+
5+
chore: introduce a pattern to help standardize log tag names

apps/hubble/src/hubble.ts

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -51,6 +51,7 @@ import {
5151
onChainEventToLog,
5252
SubmitMessageSuccessLogCache,
5353
usernameProofToLog,
54+
Tags,
5455
} from "./utils/logger.js";
5556
import {
5657
addressInfoFromGossip,
@@ -1757,7 +1758,7 @@ export class Hub implements HubInterface {
17571758
}
17581759
}
17591760

1760-
log.info({ peerId }, "falling back to addressbook lookup for peer");
1761+
log.info(new Tags({ peerId: peerId.toString() }), "falling back to addressbook lookup for peer");
17611762
const peerAddresses = await this.gossipNode.getPeerAddresses(peerId);
17621763
if (!peerAddresses) {
17631764
log.info({ function: "getRPCClientForPeer", peer }, `failed to find peer's address to request simple sync`);

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

Lines changed: 9 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -25,7 +25,7 @@ import { peerIdFromBytes, peerIdFromString } from "@libp2p/peer-id";
2525
import { multiaddr, Multiaddr } from "@multiformats/multiaddr";
2626
import { err, ok, Result } from "neverthrow";
2727
import { TypedEmitter } from "tiny-typed-emitter";
28-
import { logger, messageTypeToName } from "../../utils/logger.js";
28+
import { logger, messageTypeToName, Tags } from "../../utils/logger.js";
2929
import { PeriodicPeerCheckScheduler } from "./periodicPeerCheck.js";
3030
import { GOSSIP_PROTOCOL_VERSION } from "./protocol.js";
3131
import { AddrInfo } from "@chainsafe/libp2p-gossipsub/types";
@@ -267,7 +267,7 @@ export class GossipNode extends TypedEmitter<NodeEvents> {
267267
async putPeerAddrToDB(peerIdStr: string, addr: string) {
268268
if (this._db) {
269269
await this._db.put(this.makePeerKey(peerIdStr), Buffer.from(addr));
270-
log.info({ peerId: peerIdStr, addr }, "Added peer to DB");
270+
log.info(new Tags({ addr, peerId: peerIdStr }), "Added peer to DB");
271271
}
272272
}
273273

@@ -302,9 +302,9 @@ export class GossipNode extends TypedEmitter<NodeEvents> {
302302
const peerAddr = multiaddr(addr);
303303
const result = await this.connectAddress(peerAddr);
304304
if (result.isOk()) {
305-
log.info({ peerIdStr, addr }, "Connected to peer from DB");
305+
log.info(new Tags({ addr, peerId: peerIdStr }), "Connected to peer from DB");
306306
} else {
307-
log.debug({ peerIdStr, addr, error: result.error }, "Failed to connect to peer from DB");
307+
log.debug(new Tags({ addr, error: result.error, peerId: peerIdStr }), "Failed to connect to peer from DB");
308308
}
309309

310310
// Sleep for a bit to avoid overwhelming the network
@@ -546,11 +546,11 @@ export class GossipNode extends TypedEmitter<NodeEvents> {
546546
this._nodeEvents?.addListener("connection:open", (detail: Connection) => {
547547
// console.log("Peer Connected", JSON.stringify(detail, null, 2));
548548
log.info(
549-
{
550-
peer: detail.remotePeer,
549+
new Tags({
551550
addrs: detail.remoteAddr,
552551
type: detail.direction,
553-
},
552+
peerId: detail.remotePeer.toString(),
553+
}),
554554
"P2P Connection established",
555555
);
556556
this.emit("peerConnect", detail);
@@ -561,12 +561,12 @@ export class GossipNode extends TypedEmitter<NodeEvents> {
561561
this.putPeerAddrToDB(detail.remotePeer.toString(), detail.remoteAddr.toString());
562562
});
563563
this._nodeEvents?.addListener("connection:close", (detail: Connection) => {
564-
log.info({ peer: detail.remotePeer }, "P2P Connection disconnected");
564+
log.info(new Tags({ peerId: detail.remotePeer.toString() }), "P2P Connection disconnected");
565565
this.emit("peerDisconnect", detail);
566566
this.updateStatsdPeerGauges();
567567
});
568568
this._nodeEvents?.addListener("peer:discovery", (detail) => {
569-
log.info({ peer: detail }, "Discovered peer");
569+
log.info(new Tags({ peerId: detail.remotePeer?.toString() }), "Discovered peer");
570570
});
571571
this._nodeEvents?.addListener("gossipsub:message", (detail: GossipsubMessage) => {
572572
log.debug({

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

Lines changed: 9 additions & 37 deletions
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,5 @@
11
import cron from "node-cron";
2-
import { logger } from "../../utils/logger.js";
2+
import { logger, Tags } from "../../utils/logger.js";
33
import SyncEngine from "./syncEngine.js";
44
import { RpcMetadataRetriever, SyncEngineMetadataRetriever, SyncHealthProbe } from "../../utils/syncHealth.js";
55
import { HubInterface } from "hubble.js";
@@ -109,43 +109,15 @@ export class MeasureSyncHealthJobScheduler {
109109
let numAlreadyMerged = 0;
110110
for (const result of results) {
111111
if (result.isOk()) {
112-
const hashString = bytesToHexString(result.value.hash);
113-
const hash = hashString.isOk() ? hashString.value : "unable to show hash";
114-
115-
const typeValue = result.value.data?.type;
116-
const type = typeValue ? UserDataType[typeValue] : "unknown type";
117-
118112
log.info(
119-
{
120-
msgDetails: {
121-
type,
122-
fid: result.value.data?.fid,
123-
timestamp: this.unixTimestampFromMessage(result.value),
124-
hash,
125-
peerId,
126-
},
127-
startTime,
128-
stopTime,
129-
},
113+
new Tags({ peerId, message: result.value, startTime, stopTime }),
130114
"Successfully submitted message via SyncHealth",
131115
);
132116

133117
numSuccesses += 1;
134118
} else {
135-
const hashString = bytesToHexString(result.error.originalMessage.hash);
136-
const hash = hashString.isOk() ? hashString.value : "unable to show hash";
137-
138-
const logTags = {
139-
errMessage: result.error.hubError.message,
140-
peerId,
141-
startTime,
142-
stopTime,
143-
msgDetails: {
144-
fid: result.error.originalMessage.data?.fid,
145-
timestamp: this.unixTimestampFromMessage(result.error.originalMessage),
146-
hash,
147-
},
148-
};
119+
const logTags = new Tags({ errMessage: result.error.hubError.message, startTime, stopTime });
120+
149121
if (result.error.hubError.errCode === "bad_request.duplicate") {
150122
// This message has already been merged into the DB, but for some reason is not in the Trie.
151123
// Just update the trie.
@@ -166,7 +138,7 @@ export class MeasureSyncHealthJobScheduler {
166138
const contactInfo = this._metadataRetriever._syncEngine.getContactInfoForPeerId(peer.identifier);
167139

168140
if (!contactInfo) {
169-
log.info({ peerId: peer.identifier }, "Couldn't get contact info for peer");
141+
log.info(new Tags({ peerId: peer.identifier }), "Couldn't get contact info for peer");
170142
return undefined;
171143
}
172144

@@ -205,7 +177,7 @@ export class MeasureSyncHealthJobScheduler {
205177
const rpcClient = await this.getRpcClient(peer);
206178

207179
if (rpcClient === undefined) {
208-
log.info({ peerId: peer.identifier }, "Couldn't get rpc client, skipping peer");
180+
log.info(new Tags({ peerId: peer.identifier }), "Couldn't get rpc client, skipping peer");
209181
continue;
210182
}
211183

@@ -225,11 +197,11 @@ export class MeasureSyncHealthJobScheduler {
225197
if (syncHealthMessageStats.isErr()) {
226198
const contactInfo = this.contactInfoForLogs(peer);
227199
log.info(
228-
{
229-
peerId: peer.identifier,
200+
new Tags({
230201
err: syncHealthMessageStats.error,
231202
contactInfo,
232-
},
203+
peerId: peer.identifier,
204+
}),
233205
`Error computing SyncHealth: ${syncHealthMessageStats.error}.`,
234206
);
235207
continue;

apps/hubble/src/utils/logger.ts

Lines changed: 40 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -134,6 +134,46 @@ class BufferedLogger {
134134
}
135135
}
136136

137+
export type TagFields = {
138+
fid?: number;
139+
timestamp?: number;
140+
peerId?: string;
141+
messageType?: MessageType;
142+
message?: Message;
143+
// biome-ignore lint/suspicious/noExplicitAny: justified use case
144+
[key: string]: any;
145+
};
146+
147+
// Always go through this class to construct log tags so that tag names are standardized.
148+
export class Tags {
149+
private fields: TagFields;
150+
151+
constructor(fields: TagFields) {
152+
this.fields = fields;
153+
}
154+
155+
toString() {
156+
const extraFields = Object.fromEntries(
157+
Object.entries(this.fields).filter(([key, value]) => {
158+
return !["fid", "timestamp", "peerId", "messageType", "message"].includes(key);
159+
}),
160+
);
161+
JSON.stringify({
162+
fid: this.fields.fid,
163+
timestamp: this.fields.timestamp,
164+
peerId: this.fields.peerId,
165+
messageType: this.fields.messageType,
166+
messageFields: {
167+
timestamp: fromFarcasterTime(this.fields.message?.data?.timestamp || 0)._unsafeUnwrap(),
168+
hash: this.fields.message ? bytesToHexString(this.fields.message.hash)._unsafeUnwrap() : undefined,
169+
fid: this.fields.message?.data?.fid,
170+
type: this.fields.message?.data?.type,
171+
},
172+
...extraFields,
173+
});
174+
}
175+
}
176+
137177
export const logger = new BufferedLogger().createProxy();
138178
export type Logger = pino.Logger;
139179

0 commit comments

Comments
 (0)