fix: stop indexer-agent logs emitting duplicate JSON keys (#1239)

The indexer-agent tags every log line with the service name, but a few lines reuse that same label to also carry a subgraph name, so the label appears twice and log tooling silently keeps only one copy. This gives the subgraph name its own label and adds a lint rule that blocks the whole class of duplicate-key mistakes going forward.

Author: MoonBoi9001

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({ ... }).',
+      },
+    ],
+  },
 }

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,
         })
 

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: {

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({ ... }).',
+      },
+    ],
+  },
 }

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({ ... }).',
+      },
+    ],
+  },
 }

packages/indexer-common/src/graph-node.ts

@@ -536,16 +536,16 @@ export class GraphNode {
 
   async create(name: string): Promise<void> {
     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<void> {
     try {
       this.logger.info(`Deploy subgraph deployment`, {
-        name,
+        subgraphName: name,
         deployment: deployment.display,
       })
       const response = await this.admin.request('subgraph_deploy', {
@@ -566,15 +566,15 @@ export class GraphNode {
 
       this.logger.trace(`Response from 'subgraph_deploy' call`, {
         deployment: deployment.display,
-        name,
+        subgraphName: name,
         response,
       })
 
       if (response.error) {
         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<void> {
     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)

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<string | null> {
-    // 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) {

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,

packages/indexer-common/src/utils.ts

@@ -46,7 +46,7 @@ export async function monitorEthBalance(
   metrics: Metrics,
   networkIdentifier: string,
 ): Promise<void> {
-  logger = logger.child({ component: 'ETHBalanceMonitor' })
+  logger = logger.child({ subComponent: 'ETHBalanceMonitor' })
 
   logger.info('Monitor operator ETH balance (refreshes every 120s)')