From 3c26d41975012cb6490ab7fdee01bb9519f5e2e9 Mon Sep 17 00:00:00 2001 From: MoonBoi9001 Date: Tue, 23 Jun 2026 11:03:15 +1200 Subject: [PATCH 1/3] fix(logging): rename colliding subgraph name field in agent logs The agent's root logger stamps every line with name=IndexerAgent, yet some log calls also put the subgraph's own name under that same name key, so one JSON line carried name twice. Strict parsers keep only the last value and drop the first; the per-call field is now subgraphName. Co-Authored-By: Claude Opus 4.8 Claude-Session: https://claude.ai/code/session_01KJmMVG736T3xefovirWryK --- packages/indexer-agent/src/agent.ts | 2 +- packages/indexer-common/src/graph-node.ts | 38 +++++++++++------------ 2 files changed, 19 insertions(+), 21 deletions(-) diff --git a/packages/indexer-agent/src/agent.ts b/packages/indexer-agent/src/agent.ts index bd7be1323..1238d4e1a 100644 --- a/packages/indexer-agent/src/agent.ts +++ b/packages/indexer-agent/src/agent.ts @@ -954,7 +954,7 @@ export class Agent { const name = `indexer-agent/${deployment.ipfsHash.slice(-10)}` logger.info(`Index subgraph deployment`, { - name, + subgraphName: name, deployment: deployment.display, }) diff --git a/packages/indexer-common/src/graph-node.ts b/packages/indexer-common/src/graph-node.ts index 836985514..b238a40cf 100644 --- a/packages/indexer-common/src/graph-node.ts +++ b/packages/indexer-common/src/graph-node.ts @@ -536,16 +536,16 @@ export class GraphNode { async create(name: string): Promise { try { - this.logger.info(`Create subgraph name`, { name }) + this.logger.info(`Create subgraph name`, { subgraphName: name }) const response = await this.admin.request('subgraph_create', { name }) if (response.error) { throw response.error } - this.logger.info(`Successfully created subgraph name`, { name }) + this.logger.info(`Successfully created subgraph name`, { subgraphName: name }) } catch (error) { if (error.message.includes('already exists')) { this.logger.debug(`Subgraph name already exists, will deploy to existing name`, { - name, + subgraphName: name, }) return } @@ -556,7 +556,7 @@ export class GraphNode { async deploy(name: string, deployment: SubgraphDeploymentID): Promise { try { this.logger.info(`Deploy subgraph deployment`, { - name, + subgraphName: name, deployment: deployment.display, }) const response = await this.admin.request('subgraph_deploy', { @@ -566,7 +566,7 @@ export class GraphNode { this.logger.trace(`Response from 'subgraph_deploy' call`, { deployment: deployment.display, - name, + subgraphName: name, response, }) @@ -574,7 +574,7 @@ export class GraphNode { throw response.error } this.logger.info(`Successfully deployed subgraph deployment`, { - name, + subgraphName: name, deployment: deployment.display, }) } catch (error) { @@ -587,7 +587,7 @@ export class GraphNode { const err = indexerError(errorCode, error) this.logger.error(INDEXER_ERROR_MESSAGES[errorCode], { - name, + subgraphName: name, deployment: deployment.display, err, }) @@ -678,7 +678,7 @@ export class GraphNode { currentAssignments?: SubgraphDeploymentAssignment[], ): Promise { this.logger.debug('Ensure subgraph deployment is syncing', { - name, + subgraphName: name, deployment: deployment.ipfsHash, }) try { @@ -693,12 +693,12 @@ export class GraphNode { if (matchingAssignment?.paused == false) { this.logger.debug('Subgraph deployment already syncing, ensure() is a no-op', { - name, + subgraphName: name, deployment: deployment.ipfsHash, }) } else if (matchingAssignment?.paused == true) { this.logger.debug('Subgraph deployment paused, resuming', { - name, + subgraphName: name, deployment: deployment.ipfsHash, }) await this.resume(deployment) @@ -714,7 +714,7 @@ export class GraphNode { this.logger.debug( 'Subgraph deployment not found, creating subgraph name and deploying...', { - name, + subgraphName: name, deployment: deployment.ipfsHash, }, ) @@ -725,7 +725,7 @@ export class GraphNode { if (!(error instanceof IndexerError)) { const errorCode = IndexerErrorCode.IE020 this.logger.error(INDEXER_ERROR_MESSAGES[errorCode], { - name, + subgraphName: name, deployment: deployment.display, error: indexerError(errorCode, error), }) @@ -753,7 +753,7 @@ export class GraphNode { // Safety check - should not happen if called correctly from ensure() if (!this.manifestResolver) { this.logger.error('Auto-graft called but manifest resolver not initialized', { - name, + subgraphName: name, deployment: deployment.display, }) return @@ -763,7 +763,7 @@ export class GraphNode { const dependencies = await this.manifestResolver.resolveWithDependencies(deployment) if (dependencies.dependencies.length == 0) { this.logger.debug('No subgraph dependencies found', { - name, + subgraphName: name, deployment: deployment.display, }) } else { @@ -788,7 +788,7 @@ export class GraphNode { if (dependencyAssignment) { this.logger.info("Dependency subgraph found, checking if it's healthy", { - name, + subgraphName: name, deployment: dependency.base.display, block_required: dependency.block, }) @@ -940,11 +940,9 @@ export class GraphNode { throw new Error(`Chain not found in indexing status for deployment`) } - // NOTES: - // - latestBlock is the latest block that has been indexed - // - earliestBlock and chainHeadBlock are the earliest and latest blocks on the chain, respectively - // if the deployment is paused and latestBlock is null or lower than we need, unpause it, - // otherwise, if it's paused, we can't unpause it, so just wait + // Unpause a paused deployment only when its indexed head (latestBlock) is null + // or below the block we need; once paused past that point it can't be resumed, + // so wait instead. if ( deployed[0].paused && (!chain.latestBlock || chain.latestBlock.number < blockHeight) From a5b0b4880b10f648405cd50dc78f0a6dabd86cc0 Mon Sep 17 00:00:00 2001 From: MoonBoi9001 Date: Tue, 23 Jun 2026 13:47:38 +1200 Subject: [PATCH 2/3] fix(logging): forbid pino reserved keys as per-call log fields Add an eslint rule across the agent, common and cli packages banning pino's reserved keys (name, level, time, pid, hostname, msg, v) as per-call log fields, which silently emit a duplicate JSON key. It caught two more real collisions (a `name` and a `msg`), fixed here too. Co-Authored-By: Claude Opus 4.8 Claude-Session: https://claude.ai/code/session_01KJmMVG736T3xefovirWryK --- packages/indexer-agent/.eslintrc.js | 15 ++++++++++++++- packages/indexer-agent/src/db/cli/umzug.ts | 2 +- packages/indexer-cli/.eslintrc.js | 15 ++++++++++++++- packages/indexer-common/.eslintrc.js | 15 ++++++++++++++- .../src/indexer-management/monitor.ts | 15 ++++++--------- 5 files changed, 49 insertions(+), 13 deletions(-) diff --git a/packages/indexer-agent/.eslintrc.js b/packages/indexer-agent/.eslintrc.js index 60edb6c8b..d74df7526 100644 --- a/packages/indexer-agent/.eslintrc.js +++ b/packages/indexer-agent/.eslintrc.js @@ -2,5 +2,18 @@ module.exports = { root: true, parser: '@typescript-eslint/parser', plugins: ['@typescript-eslint'], - extends: ['eslint:recommended', 'plugin:@typescript-eslint/recommended', 'prettier'] + extends: ['eslint:recommended', 'plugin:@typescript-eslint/recommended', 'prettier'], + rules: { + // Pino emits a per-call field whose key matches a logger binding as a SECOND JSON + // key; strict parsers keep only the last. Forbid pino reserved keys as per-call fields. + 'no-restricted-syntax': [ + 'error', + { + selector: + "CallExpression[callee.property.name=/^(trace|debug|info|warn|error|fatal)$/] > ObjectExpression > Property[key.name=/^(name|level|time|pid|hostname|msg|v)$/]", + message: + 'Do not pass a pino reserved key (name, level, time, pid, hostname, msg, v) as a per-call log field: it collides with the logger bindings and emits a duplicate JSON key that strict parsers silently drop. Use a distinct key (e.g. subgraphName) or set bindings via logger.child({ ... }).', + }, + ], + }, } diff --git a/packages/indexer-agent/src/db/cli/umzug.ts b/packages/indexer-agent/src/db/cli/umzug.ts index 71654a44f..c117fa6f0 100644 --- a/packages/indexer-agent/src/db/cli/umzug.ts +++ b/packages/indexer-agent/src/db/cli/umzug.ts @@ -50,7 +50,7 @@ const sequelize = new Sequelize({ logging: false, }) -logger.debug('Successfully connected to DB', { name: database }) +logger.debug('Successfully connected to DB', { database }) export const migrator = new Umzug({ migrations: { diff --git a/packages/indexer-cli/.eslintrc.js b/packages/indexer-cli/.eslintrc.js index 437698c81..9189b3077 100644 --- a/packages/indexer-cli/.eslintrc.js +++ b/packages/indexer-cli/.eslintrc.js @@ -2,5 +2,18 @@ module.exports = { root: false, parser: '@typescript-eslint/parser', plugins: ['@typescript-eslint'], - extends: ['eslint:recommended', 'plugin:@typescript-eslint/recommended', 'prettier'] + extends: ['eslint:recommended', 'plugin:@typescript-eslint/recommended', 'prettier'], + rules: { + // Pino emits a per-call field whose key matches a logger binding as a SECOND JSON + // key; strict parsers keep only the last. Forbid pino reserved keys as per-call fields. + 'no-restricted-syntax': [ + 'error', + { + selector: + "CallExpression[callee.property.name=/^(trace|debug|info|warn|error|fatal)$/] > ObjectExpression > Property[key.name=/^(name|level|time|pid|hostname|msg|v)$/]", + message: + 'Do not pass a pino reserved key (name, level, time, pid, hostname, msg, v) as a per-call log field: it collides with the logger bindings and emits a duplicate JSON key that strict parsers silently drop. Use a distinct key (e.g. subgraphName) or set bindings via logger.child({ ... }).', + }, + ], + }, } diff --git a/packages/indexer-common/.eslintrc.js b/packages/indexer-common/.eslintrc.js index 437698c81..9189b3077 100644 --- a/packages/indexer-common/.eslintrc.js +++ b/packages/indexer-common/.eslintrc.js @@ -2,5 +2,18 @@ module.exports = { root: false, parser: '@typescript-eslint/parser', plugins: ['@typescript-eslint'], - extends: ['eslint:recommended', 'plugin:@typescript-eslint/recommended', 'prettier'] + extends: ['eslint:recommended', 'plugin:@typescript-eslint/recommended', 'prettier'], + rules: { + // Pino emits a per-call field whose key matches a logger binding as a SECOND JSON + // key; strict parsers keep only the last. Forbid pino reserved keys as per-call fields. + 'no-restricted-syntax': [ + 'error', + { + selector: + "CallExpression[callee.property.name=/^(trace|debug|info|warn|error|fatal)$/] > ObjectExpression > Property[key.name=/^(name|level|time|pid|hostname|msg|v)$/]", + message: + 'Do not pass a pino reserved key (name, level, time, pid, hostname, msg, v) as a per-call log field: it collides with the logger bindings and emits a duplicate JSON key that strict parsers silently drop. Use a distinct key (e.g. subgraphName) or set bindings via logger.child({ ... }).', + }, + ], + }, } diff --git a/packages/indexer-common/src/indexer-management/monitor.ts b/packages/indexer-common/src/indexer-management/monitor.ts index c4771d89e..1bc8159c0 100644 --- a/packages/indexer-common/src/indexer-management/monitor.ts +++ b/packages/indexer-common/src/indexer-management/monitor.ts @@ -164,10 +164,8 @@ export class NetworkMonitor { * @returns network `alias` if the network is supported, `null` otherwise */ async allocationNetworkAlias(allocation: Allocation): Promise { - // TODO: - // resolveChainId will throw an Error when we can't resolve the chainId in - // the future, let's get this from the epoch subgraph (perhaps at startup) - // and then resolve it here. + // TODO: resolveChainId will throw when we can't resolve the chainId; in the future + // get this from the epoch subgraph (perhaps at startup) and resolve it here. try { const { network: allocationNetworkAlias } = await this.graphNode.subgraphFeatures( allocation.subgraphDeployment.id, @@ -947,7 +945,7 @@ Please submit an issue at https://github.com/graphprotocol/block-oracle/issues/n } else { this.logger.error(`Failed to query latest epoch number`, { err, - msg: err.message, + errorMessage: err.message, networkID, networkAlias, }) @@ -1388,10 +1386,9 @@ Please submit an issue at https://github.com/graphprotocol/block-oracle/issues/n return [hexlify(new Uint8Array(32).fill(0)), 0] } - // poi = undefined, force=true -- submit even if poi is 0x0 - // poi = defined, force=true -- no generatedPOI needed, just submit the POI supplied (with some sanitation?) - // poi = undefined, force=false -- submit with generated POI if one available - // poi = defined, force=false -- submit user defined POI only if generated POI matches + // force=true: poi undefined -> submit even if 0x0; poi defined -> submit the supplied POI + // force=false: poi undefined -> submit a generated POI if available; poi defined -> submit the + // user POI only if it matches the generated POI switch (force) { case true: switch (!!poi) { From eb00431405cfd7b092d2156f774079c9c3afcdd1 Mon Sep 17 00:00:00 2001 From: MoonBoi9001 Date: Tue, 23 Jun 2026 17:26:57 +1200 Subject: [PATCH 3/3] fix(logging): stop child loggers emitting duplicate component keys The ETH-balance monitor, freshness checkers, and network monitor each re-set `component` on a child logger that already inherited it, emitting two `component` keys (invalid JSON). Use a distinct `subComponent` key instead, and drop a duplicate `protocolNetwork`. Co-Authored-By: Claude Opus 4.8 --- packages/indexer-common/src/network.ts | 9 ++++----- packages/indexer-common/src/utils.ts | 2 +- 2 files changed, 5 insertions(+), 6 deletions(-) diff --git a/packages/indexer-common/src/network.ts b/packages/indexer-common/src/network.ts index 3aa87f90a..1eb900dec 100644 --- a/packages/indexer-common/src/network.ts +++ b/packages/indexer-common/src/network.ts @@ -125,7 +125,7 @@ export class Network { networkProvider, specification.subgraphs.maxBlockDistance, specification.subgraphs.freshnessSleepMilliseconds, - logger.child({ component: 'FreshnessChecker' }), + logger.child({ subComponent: 'FreshnessChecker' }), Infinity, ) @@ -162,7 +162,7 @@ export class Network { networkProvider, specification.subgraphs.maxBlockDistance, specification.subgraphs.freshnessSleepMilliseconds, - logger.child({ component: 'FreshnessChecker' }), + logger.child({ subComponent: 'FreshnessChecker' }), Infinity, ) indexingPaymentsSubgraph = await SubgraphClient.create({ @@ -214,7 +214,7 @@ export class Network { networkProvider, specification.subgraphs.maxBlockDistance, specification.subgraphs.freshnessSleepMilliseconds, - logger.child({ component: 'FreshnessChecker' }), + logger.child({ subComponent: 'FreshnessChecker' }), Infinity, ) @@ -243,8 +243,7 @@ export class Network { contracts, specification.indexerOptions, logger.child({ - component: 'NetworkMonitor', - protocolNetwork: specification.networkIdentifier, + subComponent: 'NetworkMonitor', }), graphNode, networkSubgraph, diff --git a/packages/indexer-common/src/utils.ts b/packages/indexer-common/src/utils.ts index e66b678ef..08b91b2c6 100644 --- a/packages/indexer-common/src/utils.ts +++ b/packages/indexer-common/src/utils.ts @@ -46,7 +46,7 @@ export async function monitorEthBalance( metrics: Metrics, networkIdentifier: string, ): Promise { - logger = logger.child({ component: 'ETHBalanceMonitor' }) + logger = logger.child({ subComponent: 'ETHBalanceMonitor' }) logger.info('Monitor operator ETH balance (refreshes every 120s)')