From 836fe45aa5e84fb801044e3bbcc97472da89e7f8 Mon Sep 17 00:00:00 2001 From: Nabarun Gogoi Date: Thu, 6 Jun 2024 13:57:33 +0530 Subject: [PATCH] Add metrics for GQL query duration (#516) * Record GQL query durations by operation name * Use try finally for timer metric * Export watcher repo URL in metrics * Remove unnecessary prefix from repo link * Update repository label name --------- Co-authored-by: Prathamesh Musale --- .../src/templates/package-template.handlebars | 2 +- .../templates/resolvers-template.handlebars | 130 +++++++++++------- packages/util/src/gql-metrics.ts | 7 + packages/util/src/metrics.ts | 8 +- 4 files changed, 95 insertions(+), 52 deletions(-) diff --git a/packages/codegen/src/templates/package-template.handlebars b/packages/codegen/src/templates/package-template.handlebars index 1815fcfc..961879a3 100644 --- a/packages/codegen/src/templates/package-template.handlebars +++ b/packages/codegen/src/templates/package-template.handlebars @@ -31,7 +31,7 @@ }, "repository": { "type": "git", - "url": "git+https://github.com/cerc-io/watcher-ts.git" + "url": "https://github.com/cerc-io/watcher-ts.git" }, "author": "", "license": "AGPL-3.0", diff --git a/packages/codegen/src/templates/resolvers-template.handlebars b/packages/codegen/src/templates/resolvers-template.handlebars index f8808b54..ea3c7d00 100644 --- a/packages/codegen/src/templates/resolvers-template.handlebars +++ b/packages/codegen/src/templates/resolvers-template.handlebars @@ -12,6 +12,7 @@ import { {{/if}} gqlTotalQueryCount, gqlQueryCount, + gqlQueryDuration, getResultState, IndexerInterface, GraphQLBigInt, @@ -36,6 +37,20 @@ import { {{query.entityName}} } from './entity/{{query.entityName}}'; const log = debug('vulcanize:resolver'); +const executeAndRecordMetrics = async (gqlLabel: string, operation: () => Promise) => { + gqlTotalQueryCount.inc(1); + gqlQueryCount.labels(gqlLabel).inc(1); + const endTimer = gqlQueryDuration.labels(gqlLabel).startTimer(); + + try { + const result = await operation(); + + return result; + } finally { + endTimer(); + } +}; + export const createResolvers = async (indexerArg: IndexerInterface, eventWatcher: EventWatcher): Promise => { const indexer = indexerArg as Indexer; @@ -84,14 +99,15 @@ export const createResolvers = async (indexerArg: IndexerInterface, eventWatcher ): Promise => { log('{{this.name}}', blockHash, contractAddress {{~#each this.params}}, {{this.name~}} {{/each}}); - gqlTotalQueryCount.inc(1); - gqlQueryCount.labels('{{this.name}}').inc(1); - + // Set cache-control hints // setGQLCacheHints(info, {}, gqlCacheConfig); - return indexer.{{this.name}}(blockHash, contractAddress - {{~#each this.params}}, {{this.name~}} {{/each}}); + return executeAndRecordMetrics( + '{{this.name}}', + async () => indexer.{{this.name}}(blockHash, contractAddress + {{~#each this.params}}, {{this.name~}} {{/each}}) + ); }, {{/each}} @@ -104,13 +120,14 @@ export const createResolvers = async (indexerArg: IndexerInterface, eventWatcher info: GraphQLResolveInfo ) => { log('{{this.queryName}}', id, JSON.stringify(block, jsonBigIntStringReplacer)); - gqlTotalQueryCount.inc(1); - gqlQueryCount.labels('{{this.queryName}}').inc(1); // Set cache-control hints // setGQLCacheHints(info, block, gqlCacheConfig); - return indexer.getSubgraphEntity({{this.entityName}}, id, block, info); + return executeAndRecordMetrics( + '{{this.queryName}}', + async () => indexer.getSubgraphEntity({{this.entityName}}, id, block, info) + ); }, {{this.pluralQueryName}}: async ( @@ -120,73 +137,86 @@ export const createResolvers = async (indexerArg: IndexerInterface, eventWatcher info: GraphQLResolveInfo ) => { log('{{this.pluralQueryName}}', JSON.stringify(block, jsonBigIntStringReplacer), JSON.stringify(where, jsonBigIntStringReplacer), first, skip, orderBy, orderDirection); - gqlTotalQueryCount.inc(1); - gqlQueryCount.labels('{{this.pluralQueryName}}').inc(1); // Set cache-control hints // setGQLCacheHints(info, block, gqlCacheConfig); - return indexer.getSubgraphEntities( - {{this.entityName}}, - block, - where, - { limit: first, skip, orderBy, orderDirection }, - info + return executeAndRecordMetrics( + '{{this.pluralQueryName}}', + async () => indexer.getSubgraphEntities( + {{this.entityName}}, + block, + where, + { limit: first, skip, orderBy, orderDirection }, + info + ) ); }, {{/each}} events: async (_: any, { blockHash, contractAddress, name }: { blockHash: string, contractAddress: string, name?: string }) => { log('events', blockHash, contractAddress, name); - gqlTotalQueryCount.inc(1); - gqlQueryCount.labels('events').inc(1); - const block = await indexer.getBlockProgress(blockHash); - if (!block || !block.isComplete) { - throw new Error(`Block hash ${blockHash} number ${block?.blockNumber} not processed yet`); - } + return executeAndRecordMetrics( + 'events', + async () => { + const block = await indexer.getBlockProgress(blockHash); + if (!block || !block.isComplete) { + throw new Error(`Block hash ${blockHash} number ${block?.blockNumber} not processed yet`); + } - const events = await indexer.getEventsByFilter(blockHash, contractAddress, name); - return events.map(event => indexer.getResultEvent(event)); + const events = await indexer.getEventsByFilter(blockHash, contractAddress, name); + return events.map(event => indexer.getResultEvent(event)); + } + ); }, eventsInRange: async (_: any, { fromBlockNumber, toBlockNumber }: { fromBlockNumber: number, toBlockNumber: number }) => { log('eventsInRange', fromBlockNumber, toBlockNumber); - gqlTotalQueryCount.inc(1); - gqlQueryCount.labels('eventsInRange').inc(1); - const syncStatus = await indexer.getSyncStatus(); + return executeAndRecordMetrics( + 'eventsInRange', + async () => { + const syncStatus = await indexer.getSyncStatus(); - if (!syncStatus) { - throw new Error('No blocks processed yet'); - } + if (!syncStatus) { + throw new Error('No blocks processed yet'); + } - if ((fromBlockNumber < syncStatus.initialIndexedBlockNumber) || (toBlockNumber > syncStatus.latestProcessedBlockNumber)) { - throw new Error(`Block range should be between ${syncStatus.initialIndexedBlockNumber} and ${syncStatus.latestProcessedBlockNumber}`); - } + if ((fromBlockNumber < syncStatus.initialIndexedBlockNumber) || (toBlockNumber > syncStatus.latestProcessedBlockNumber)) { + throw new Error(`Block range should be between ${syncStatus.initialIndexedBlockNumber} and ${syncStatus.latestProcessedBlockNumber}`); + } - const events = await indexer.getEventsInRange(fromBlockNumber, toBlockNumber); - return events.map(event => indexer.getResultEvent(event)); + const events = await indexer.getEventsInRange(fromBlockNumber, toBlockNumber); + return events.map(event => indexer.getResultEvent(event)); + } + ); }, getStateByCID: async (_: any, { cid }: { cid: string }) => { log('getStateByCID', cid); - gqlTotalQueryCount.inc(1); - gqlQueryCount.labels('getStateByCID').inc(1); - const state = await indexer.getStateByCID(cid); + return executeAndRecordMetrics( + 'getStateByCID', + async () => { + const state = await indexer.getStateByCID(cid); - return state && state.block.isComplete ? getResultState(state) : undefined; + return state && state.block.isComplete ? getResultState(state) : undefined; + } + ); }, getState: async (_: any, { blockHash, contractAddress, kind }: { blockHash: string, contractAddress: string, kind: string }) => { log('getState', blockHash, contractAddress, kind); - gqlTotalQueryCount.inc(1); - gqlQueryCount.labels('getState').inc(1); - const state = await indexer.getPrevState(blockHash, contractAddress, kind); + return executeAndRecordMetrics( + 'getState', + async () => { + const state = await indexer.getPrevState(blockHash, contractAddress, kind); - return state && state.block.isComplete ? getResultState(state) : undefined; + return state && state.block.isComplete ? getResultState(state) : undefined; + } + ); }, {{#if (subgraphPath)}} @@ -195,19 +225,21 @@ export const createResolvers = async (indexerArg: IndexerInterface, eventWatcher { block = {} }: { block: BlockHeight } ) => { log('_meta'); - gqlTotalQueryCount.inc(1); - gqlQueryCount.labels('_meta').inc(1); - return indexer.getMetaData(block); + return executeAndRecordMetrics( + '_meta', + async () => indexer.getMetaData(block) + ); }, {{/if}} getSyncStatus: async () => { log('getSyncStatus'); - gqlTotalQueryCount.inc(1); - gqlQueryCount.labels('getSyncStatus').inc(1); - return indexer.getSyncStatus(); + return executeAndRecordMetrics( + 'getSyncStatus', + async () => indexer.getSyncStatus() + ); } } }; diff --git a/packages/util/src/gql-metrics.ts b/packages/util/src/gql-metrics.ts index eec55254..ddfa370b 100644 --- a/packages/util/src/gql-metrics.ts +++ b/packages/util/src/gql-metrics.ts @@ -27,6 +27,13 @@ export const gqlQueryCount = new client.Counter({ registers: [gqlRegistry] }); +export const gqlQueryDuration = new client.Gauge({ + name: 'gql_query_duration_seconds', + help: 'Duration of GQL queries', + labelNames: ['name'] as const, + registers: [gqlRegistry] +}); + // Export metrics on a server const app: Application = express(); diff --git a/packages/util/src/metrics.ts b/packages/util/src/metrics.ts index a1684a4c..4f9a2a9c 100644 --- a/packages/util/src/metrics.ts +++ b/packages/util/src/metrics.ts @@ -288,8 +288,12 @@ const registerWatcherInfoMetrics = async (): Promise => { const watcherInfoMetric = new client.Gauge({ name: 'watcher_info', help: 'Watcher info (static)', - labelNames: ['version', 'commitHash'] + labelNames: ['repository', 'version', 'commitHash'] }); - watcherInfoMetric.set({ version: pkgJson.version, commitHash: pkgJson.commitHash }, 1); + watcherInfoMetric.set({ + repository: pkgJson.repository && pkgJson.repository.url.replace(/^git\+/, ''), + version: pkgJson.version, + commitHash: pkgJson.commitHash + }, 1); };