Add metrics for cache and DB hits in event processing

vulcanize · Sep 30, 2022 · 0524514 · 0524514
1 parent 5986c62
commit 0524514
Show file tree

Hide file tree

Showing 3 changed files with 33 additions and 3 deletions.
diff --git a/packages/util/src/database.ts b/packages/util/src/database.ts
@@ -24,7 +24,7 @@ import { SelectionNode } from 'graphql';
 
 import { BlockProgressInterface, ContractInterface, EventInterface, SyncStatusInterface } from './types';
 import { MAX_REORG_DEPTH, UNKNOWN_EVENT_NAME } from './constants';
-import { blockProgressCount, eventCount } from './metrics';
+import { blockProgressCount, eventCount, eventProcessingLoadEntityDBQueryDuration, eventProcessingLoadEntityCacheHitCount, eventProcessingLoadEntityCount } from './metrics';
 
 const OPERATOR_MAP = {
   equals: '=',
@@ -529,6 +529,8 @@ export class Database {
   }
 
   async getModelEntity<Entity> (repo: Repository<Entity>, whereOptions: any): Promise<Entity | undefined> {
+    eventProcessingLoadEntityCount.inc();
+
     const findOptions = {
       where: whereOptions,
       order: {
@@ -550,6 +552,7 @@ export class Database {
             ?.get(findOptions.where.id);
 
           if (entity) {
+            eventProcessingLoadEntityCacheHitCount.inc();
             return _.cloneDeep(entity) as Entity;
           }
 
@@ -568,11 +571,14 @@ export class Database {
             ?.get(findOptions.where.id);
 
           if (entity) {
+            eventProcessingLoadEntityCacheHitCount.inc();
             return _.cloneDeep(entity) as Entity;
           }
 
           // Get latest pruned entity from DB if not found in cache.
+          const endTimer = eventProcessingLoadEntityDBQueryDuration.startTimer();
           const dbEntity = await this._getLatestPrunedEntity(repo, findOptions.where.id, canonicalBlockNumber);
+          endTimer();
 
           if (dbEntity) {
             // Update latest pruned entity in cache.
@@ -583,7 +589,11 @@ export class Database {
         }
       }
 
-      return this.getPrevEntityVersion(repo.queryRunner!, repo, findOptions);
+      const endTimer = eventProcessingLoadEntityDBQueryDuration.startTimer();
+      const dbEntity = await this.getPrevEntityVersion(repo.queryRunner!, repo, findOptions);
+      endTimer();
+
+      return dbEntity;
     }
 
     return repo.findOne(findOptions);

diff --git a/packages/util/src/job-runner.ts b/packages/util/src/job-runner.ts
@@ -12,7 +12,7 @@ import { JobQueue } from './job-queue';
 import { EventInterface, IndexerInterface, SyncStatusInterface } from './types';
 import { wait } from './misc';
 import { createPruningJob } from './common';
-import { lastBlockNumEvents, lastBlockProcessDuration, lastProcessedBlockNumber } from './metrics';
+import { eventProcessingLoadEntityCacheHitCount, eventProcessingLoadEntityCount, lastBlockNumEvents, lastBlockProcessDuration, lastProcessedBlockNumber } from './metrics';
 
 const log = debug('vulcanize:job-runner');
 
@@ -341,6 +341,8 @@ export class JobRunner {
           dbEvent.eventInfo = JSON.stringify(eventInfo);
         }
 
+        eventProcessingLoadEntityCount.set(0);
+        eventProcessingLoadEntityCacheHitCount.set(0);
         await this._indexer.processEvent(dbEvent);
       }
 
@@ -365,6 +367,9 @@ export class JobRunner {
         const watchedContract = this._indexer.isWatchedContract(dbEvent.contract);
 
         if (watchedContract) {
+          eventProcessingLoadEntityCount.set(0);
+          eventProcessingLoadEntityCacheHitCount.set(0);
+
           // Events of contract added in same block might be processed multiple times.
           // This is because there is no check for lastProcessedEventIndex against these events.
           await this._indexer.processEvent(dbEvent);

diff --git a/packages/util/src/metrics.ts b/packages/util/src/metrics.ts
@@ -49,6 +49,21 @@ export const eventCount = new promClient.Gauge({
   help: 'Total entries in event table'
 });
 
+export const eventProcessingLoadEntityCount = new promClient.Gauge({
+  name: 'event_processing_load_entity_total',
+  help: 'Total load entities in a single event processing'
+});
+
+export const eventProcessingLoadEntityCacheHitCount = new promClient.Gauge({
+  name: 'event_processing_load_entity_cache_hit_total',
+  help: 'Total load entities hitting cache in a single event processing'
+});
+
+export const eventProcessingLoadEntityDBQueryDuration = new promClient.Histogram({
+  name: 'event_processing_load_entity_db_query_seconds',
+  help: 'Duration of DB query made in event processing'
+});
+
 // Export metrics on a server
 const app: Application = express();