From e63608be79a7269e80021e24fa8f27fc7de074c2 Mon Sep 17 00:00:00 2001 From: Blair Currey <12960453+BlairCurrey@users.noreply.github.com> Date: Mon, 26 Aug 2024 10:34:14 -0400 Subject: [PATCH] feat(backend): ww performance create quote metrics (#2896) * feat(backend): add create quote service metrics * feat: add getQuote traces --- .../provisioning/dashboards/example.json | 622 +++++++++++++++--- packages/backend/src/fee/service.ts | 1 + packages/backend/src/index.ts | 7 +- .../src/open_payments/quote/service.ts | 84 ++- .../backend/src/payment-method/ilp/service.ts | 64 +- .../scripts/create-outgoing-payments.js | 4 +- 6 files changed, 670 insertions(+), 112 deletions(-) diff --git a/localenv/telemetry/grafana/provisioning/dashboards/example.json b/localenv/telemetry/grafana/provisioning/dashboards/example.json index 513c1b1448..e15844a4e7 100644 --- a/localenv/telemetry/grafana/provisioning/dashboards/example.json +++ b/localenv/telemetry/grafana/provisioning/dashboards/example.json @@ -18,6 +18,7 @@ "editable": true, "fiscalYearStartMonth": 0, "graphTooltip": 0, + "id": 1, "links": [], "panels": [ { @@ -85,6 +86,327 @@ "x": 0, "y": 0 }, + "id": 7, + "options": { + "legend": { + "calcs": [], + "displayMode": "list", + "placement": "bottom", + "showLegend": true + }, + "tooltip": { + "mode": "single", + "sort": "none" + } + }, + "targets": [ + { + "datasource": { + "type": "prometheus", + "uid": "PBFA97CFB590B2093" + }, + "editorMode": "code", + "expr": "rate(quote_service_create_time_ms_sum[$__rate_interval])/rate(quote_service_create_time_ms_count[$__rate_interval])", + "instant": false, + "legendFormat": "{{description}}", + "range": true, + "refId": "A" + }, + { + "datasource": { + "type": "prometheus", + "uid": "PBFA97CFB590B2093" + }, + "editorMode": "code", + "expr": "rate(quote_service_create_resolve_receiver_time_ms_sum[$__rate_interval])/rate(quote_service_create_resolve_receiver_time_ms_count[$__rate_interval])", + "hide": false, + "instant": false, + "legendFormat": "{{description}}", + "range": true, + "refId": "B" + }, + { + "datasource": { + "type": "prometheus", + "uid": "PBFA97CFB590B2093" + }, + "editorMode": "code", + "expr": "rate(quote_service_create_get_quote_time_ms_sum[$__rate_interval])/rate(quote_service_create_get_quote_time_ms_count[$__rate_interval])", + "hide": false, + "instant": false, + "legendFormat": "{{description}}", + "range": true, + "refId": "C" + }, + { + "datasource": { + "type": "prometheus", + "uid": "PBFA97CFB590B2093" + }, + "editorMode": "code", + "expr": "rate(quote_service_create_get_latest_fee_time_ms_sum[$__rate_interval])/rate(quote_service_create_get_latest_fee_time_ms_count[$__rate_interval])", + "hide": false, + "instant": false, + "legendFormat": "{{description}}", + "range": true, + "refId": "D" + }, + { + "datasource": { + "type": "prometheus", + "uid": "PBFA97CFB590B2093" + }, + "editorMode": "code", + "expr": "rate(quote_service_create_insert_time_ms_sum[$__rate_interval])/rate(quote_service_create_insert_time_ms_count[$__rate_interval])", + "hide": false, + "instant": false, + "legendFormat": "{{description}}", + "range": true, + "refId": "E" + }, + { + "datasource": { + "type": "prometheus", + "uid": "PBFA97CFB590B2093" + }, + "editorMode": "code", + "expr": "rate(quote_service_finalize_quote_ms_sum[$__rate_interval])/rate(quote_service_finalize_quote_ms_count[$__rate_interval])", + "hide": false, + "instant": false, + "legendFormat": "{{description}}", + "range": true, + "refId": "F" + } + ], + "title": "Quote Service Create Time (ms)", + "type": "timeseries" + }, + { + "datasource": { + "type": "prometheus", + "uid": "PBFA97CFB590B2093" + }, + "fieldConfig": { + "defaults": { + "color": { + "mode": "palette-classic" + }, + "custom": { + "axisBorderShow": false, + "axisCenteredZero": false, + "axisColorMode": "text", + "axisLabel": "", + "axisPlacement": "auto", + "barAlignment": 0, + "drawStyle": "line", + "fillOpacity": 0, + "gradientMode": "none", + "hideFrom": { + "legend": false, + "tooltip": false, + "viz": false + }, + "insertNulls": false, + "lineInterpolation": "linear", + "lineWidth": 1, + "pointSize": 5, + "scaleDistribution": { + "type": "linear" + }, + "showPoints": "auto", + "spanNulls": false, + "stacking": { + "group": "A", + "mode": "none" + }, + "thresholdsStyle": { + "mode": "off" + } + }, + "mappings": [], + "thresholds": { + "mode": "absolute", + "steps": [ + { + "color": "green", + "value": null + }, + { + "color": "red", + "value": 80 + } + ] + } + }, + "overrides": [] + }, + "gridPos": { + "h": 8, + "w": 12, + "x": 12, + "y": 0 + }, + "id": 9, + "options": { + "legend": { + "calcs": [], + "displayMode": "list", + "placement": "bottom", + "showLegend": true + }, + "tooltip": { + "mode": "single", + "sort": "none" + } + }, + "targets": [ + { + "datasource": { + "type": "prometheus", + "uid": "PBFA97CFB590B2093" + }, + "editorMode": "code", + "expr": "rate(quote_service_create_get_quote_time_ms_sum[$__rate_interval])/rate(quote_service_create_get_quote_time_ms_count[$__rate_interval])", + "hide": false, + "instant": false, + "legendFormat": "{{description}}", + "range": true, + "refId": "C" + }, + { + "datasource": { + "type": "prometheus", + "uid": "PBFA97CFB590B2093" + }, + "editorMode": "code", + "expr": "rate(ilp_rate_probe_time_ms_sum[$__rate_interval])/rate(ilp_rate_probe_time_ms_count[$__rate_interval])", + "hide": false, + "instant": false, + "legendFormat": "{{description}}", + "range": true, + "refId": "F" + }, + { + "datasource": { + "type": "prometheus", + "uid": "PBFA97CFB590B2093" + }, + "editorMode": "code", + "expr": "rate(ilp_get_quote_rate_time_ms_sum[$__rate_interval])/rate(ilp_get_quote_rate_time_ms_count[$__rate_interval])", + "hide": false, + "instant": false, + "legendFormat": "{{description}}", + "range": true, + "refId": "A" + }, + { + "datasource": { + "type": "prometheus", + "uid": "PBFA97CFB590B2093" + }, + "editorMode": "code", + "expr": "rate(ilp_make_ilp_plugin_connect_time_ms_sum[$__rate_interval])/rate(ilp_make_ilp_plugin_connect_time_ms_count[$__rate_interval])", + "hide": false, + "instant": false, + "legendFormat": "{{description}}", + "range": true, + "refId": "B" + }, + { + "datasource": { + "type": "prometheus", + "uid": "PBFA97CFB590B2093" + }, + "editorMode": "code", + "expr": "rate(ilp_plugin_close_connect_time_ms_sum[$__rate_interval])/rate(ilp_plugin_close_connect_time_ms_count[$__rate_interval])", + "hide": false, + "instant": false, + "legendFormat": "{{description}}", + "range": true, + "refId": "D" + }, + { + "datasource": { + "type": "prometheus", + "uid": "PBFA97CFB590B2093" + }, + "editorMode": "code", + "expr": "rate(ilp_plugin_disconnect_time_ms_sum[$__rate_interval])/rate(ilp_plugin_disconnect_time_ms_count[$__rate_interval])", + "hide": false, + "instant": false, + "legendFormat": "{{description}}", + "range": true, + "refId": "E" + } + ], + "title": "ILP Payment Service getQuote", + "type": "timeseries" + }, + { + "datasource": { + "type": "prometheus", + "uid": "PBFA97CFB590B2093" + }, + "fieldConfig": { + "defaults": { + "color": { + "mode": "palette-classic" + }, + "custom": { + "axisBorderShow": false, + "axisCenteredZero": false, + "axisColorMode": "text", + "axisLabel": "", + "axisPlacement": "auto", + "barAlignment": 0, + "drawStyle": "line", + "fillOpacity": 0, + "gradientMode": "none", + "hideFrom": { + "legend": false, + "tooltip": false, + "viz": false + }, + "insertNulls": false, + "lineInterpolation": "linear", + "lineWidth": 1, + "pointSize": 5, + "scaleDistribution": { + "type": "linear" + }, + "showPoints": "auto", + "spanNulls": false, + "stacking": { + "group": "A", + "mode": "none" + }, + "thresholdsStyle": { + "mode": "off" + } + }, + "mappings": [], + "thresholds": { + "mode": "absolute", + "steps": [ + { + "color": "green", + "value": null + }, + { + "color": "red", + "value": 80 + } + ] + } + }, + "overrides": [] + }, + "gridPos": { + "h": 8, + "w": 12, + "x": 0, + "y": 8 + }, "id": 2, "interval": "15s", "options": { @@ -120,20 +442,45 @@ }, { "datasource": { - "type": "tempo", - "uid": "P214B5B846CF3925F" + "type": "prometheus", + "uid": "PBFA97CFB590B2093" }, "fieldConfig": { "defaults": { "color": { - "mode": "thresholds" + "mode": "palette-classic" }, "custom": { - "align": "auto", - "cellOptions": { - "type": "auto" + "axisBorderShow": false, + "axisCenteredZero": false, + "axisColorMode": "text", + "axisLabel": "", + "axisPlacement": "auto", + "barAlignment": 0, + "drawStyle": "line", + "fillOpacity": 0, + "gradientMode": "none", + "hideFrom": { + "legend": false, + "tooltip": false, + "viz": false + }, + "insertNulls": false, + "lineInterpolation": "linear", + "lineWidth": 1, + "pointSize": 5, + "scaleDistribution": { + "type": "linear" }, - "inspect": false + "showPoints": "auto", + "spanNulls": false, + "stacking": { + "group": "A", + "mode": "none" + }, + "thresholdsStyle": { + "mode": "off" + } }, "mappings": [], "thresholds": { @@ -156,70 +503,37 @@ "h": 8, "w": 12, "x": 12, - "y": 0 + "y": 8 }, - "id": 4, + "id": 8, "options": { - "cellHeight": "sm", - "footer": { - "countRows": false, - "fields": "", - "reducer": ["sum"], - "show": false + "legend": { + "calcs": [], + "displayMode": "list", + "placement": "bottom", + "showLegend": true }, - "showHeader": true, - "sortBy": [ - { - "desc": true, - "displayName": "Duration" - } - ] + "tooltip": { + "mode": "single", + "sort": "none" + } }, - "pluginVersion": "11.1.3", "targets": [ { "datasource": { - "type": "tempo", - "uid": "P214B5B846CF3925F" + "type": "prometheus", + "uid": "PBFA97CFB590B2093" }, - "filters": [ - { - "id": "9bab4a0a", - "operator": "=", - "scope": "span" - }, - { - "id": "service-name", - "operator": "=", - "scope": "resource", - "tag": "service.name", - "value": ["RAFIKI_NETWORK"], - "valueType": "string" - }, - { - "id": "span-name", - "operator": "=", - "scope": "span", - "tag": "name", - "value": [], - "valueType": "string" - }, - { - "id": "min-duration", - "operator": ">", - "tag": "duration", - "value": "100ms", - "valueType": "duration" - } - ], - "limit": 20, - "queryType": "traceqlSearch", - "refId": "A", - "tableType": "traces" + "editorMode": "code", + "expr": "rate(quote_service_create_time_ms_sum[$__rate_interval])/rate(quote_service_create_time_ms_sum[$__rate_interval])", + "instant": false, + "legendFormat": "__auto", + "range": true, + "refId": "A" } ], - "title": "Traces > 100ms", - "type": "table" + "title": "Quote Service Create Time (ms)", + "type": "timeseries" }, { "datasource": { @@ -284,7 +598,7 @@ "h": 8, "w": 12, "x": 0, - "y": 8 + "y": 16 }, "id": 1, "interval": "15s", @@ -321,16 +635,21 @@ }, { "datasource": { - "type": "prometheus", - "uid": "PBFA97CFB590B2093" + "type": "tempo", + "uid": "P214B5B846CF3925F" }, - "description": "", "fieldConfig": { "defaults": { "color": { - "mode": "continuous-GrYlRd" + "mode": "thresholds" + }, + "custom": { + "align": "auto", + "cellOptions": { + "type": "auto" + }, + "inspect": false }, - "fieldMinMax": false, "mappings": [], "thresholds": { "mode": "absolute", @@ -344,51 +663,78 @@ "value": 80 } ] - }, - "unit": "s" + } }, "overrides": [] }, "gridPos": { - "h": 12, + "h": 8, "w": 12, "x": 12, - "y": 8 + "y": 16 }, - "id": 6, + "id": 4, "options": { - "displayMode": "gradient", - "maxVizHeight": 300, - "minVizHeight": 16, - "minVizWidth": 8, - "namePlacement": "auto", - "orientation": "horizontal", - "reduceOptions": { - "calcs": ["lastNotNull"], + "cellHeight": "sm", + "footer": { + "countRows": false, "fields": "", - "values": false + "reducer": ["sum"], + "show": false }, - "showUnfilled": true, - "sizing": "auto", - "valueMode": "color" + "showHeader": true, + "sortBy": [ + { + "desc": true, + "displayName": "Duration" + } + ] }, - "pluginVersion": "11.1.3", + "pluginVersion": "11.1.4", "targets": [ { "datasource": { - "type": "prometheus", - "uid": "PBFA97CFB590B2093" + "type": "tempo", + "uid": "P214B5B846CF3925F" }, - "editorMode": "code", - "expr": "histogram_quantile(0.95, sum(rate(traces_spanmetrics_latency_bucket{span_name=~\"^(mutation|query).*\"}[$__rate_interval])) by (le, span_name))", - "instant": false, - "legendFormat": "__auto", - "range": true, - "refId": "A" + "filters": [ + { + "id": "9bab4a0a", + "operator": "=", + "scope": "span" + }, + { + "id": "service-name", + "operator": "=", + "scope": "resource", + "tag": "service.name", + "value": ["RAFIKI_NETWORK"], + "valueType": "string" + }, + { + "id": "span-name", + "operator": "=", + "scope": "span", + "tag": "name", + "value": [], + "valueType": "string" + }, + { + "id": "min-duration", + "operator": ">", + "tag": "duration", + "value": "100ms", + "valueType": "duration" + } + ], + "limit": 20, + "queryType": "traceqlSearch", + "refId": "A", + "tableType": "traces" } ], - "title": "Graphql Resolver Duration (95th Percentile)", - "type": "bargauge" + "title": "Traces > 100ms", + "type": "table" }, { "datasource": { @@ -406,8 +752,7 @@ "mode": "absolute", "steps": [ { - "color": "green", - "value": null + "color": "green" }, { "color": "red", @@ -423,7 +768,7 @@ "h": 5, "w": 12, "x": 0, - "y": 16 + "y": 24 }, "id": 3, "options": { @@ -441,7 +786,7 @@ "textMode": "auto", "wideLayout": true }, - "pluginVersion": "11.1.3", + "pluginVersion": "11.1.4", "targets": [ { "datasource": { @@ -485,6 +830,76 @@ "title": "ILP Pay Time Quartile Approximations", "type": "stat" }, + { + "datasource": { + "type": "prometheus", + "uid": "PBFA97CFB590B2093" + }, + "description": "", + "fieldConfig": { + "defaults": { + "color": { + "mode": "continuous-GrYlRd" + }, + "fieldMinMax": false, + "mappings": [], + "thresholds": { + "mode": "absolute", + "steps": [ + { + "color": "green" + }, + { + "color": "red", + "value": 80 + } + ] + }, + "unit": "s" + }, + "overrides": [] + }, + "gridPos": { + "h": 12, + "w": 12, + "x": 12, + "y": 24 + }, + "id": 6, + "options": { + "displayMode": "gradient", + "maxVizHeight": 300, + "minVizHeight": 16, + "minVizWidth": 8, + "namePlacement": "auto", + "orientation": "horizontal", + "reduceOptions": { + "calcs": ["lastNotNull"], + "fields": "", + "values": false + }, + "showUnfilled": true, + "sizing": "auto", + "valueMode": "color" + }, + "pluginVersion": "11.1.4", + "targets": [ + { + "datasource": { + "type": "prometheus", + "uid": "PBFA97CFB590B2093" + }, + "editorMode": "code", + "expr": "histogram_quantile(0.95, sum(rate(traces_spanmetrics_latency_bucket{span_name=~\"^(mutation|query).*\"}[$__rate_interval])) by (le, span_name))", + "instant": false, + "legendFormat": "__auto", + "range": true, + "refId": "A" + } + ], + "title": "Graphql Resolver Duration (95th Percentile)", + "type": "bargauge" + }, { "datasource": { "type": "prometheus", @@ -501,8 +916,7 @@ "mode": "absolute", "steps": [ { - "color": "green", - "value": null + "color": "green" }, { "color": "red", @@ -518,7 +932,7 @@ "h": 5, "w": 12, "x": 0, - "y": 21 + "y": 29 }, "id": 5, "options": { @@ -536,7 +950,7 @@ "textMode": "auto", "wideLayout": true }, - "pluginVersion": "11.1.3", + "pluginVersion": "11.1.4", "targets": [ { "datasource": { @@ -588,7 +1002,7 @@ "list": [] }, "time": { - "from": "now-15m", + "from": "now-30m", "to": "now" }, "timepicker": { diff --git a/packages/backend/src/fee/service.ts b/packages/backend/src/fee/service.ts index 4979cb18a4..865228ea72 100644 --- a/packages/backend/src/fee/service.ts +++ b/packages/backend/src/fee/service.ts @@ -66,6 +66,7 @@ async function getLatestFee( type: FeeType ): Promise { return await Fee.query(deps.knex) + // TODO: index on assetId/type .where({ assetId, type }) .orderBy('createdAt', 'desc') .first() diff --git a/packages/backend/src/index.ts b/packages/backend/src/index.ts index a34d784ef7..c36baa05de 100644 --- a/packages/backend/src/index.ts +++ b/packages/backend/src/index.ts @@ -456,7 +456,12 @@ export function initIocContainer( receiverService: await deps.use('receiverService'), feeService: await deps.use('feeService'), walletAddressService: await deps.use('walletAddressService'), - paymentMethodHandlerService: await deps.use('paymentMethodHandlerService') + paymentMethodHandlerService: await deps.use( + 'paymentMethodHandlerService' + ), + telemetry: config.enableTelemetry + ? await deps.use('telemetry') + : undefined }) }) diff --git a/packages/backend/src/open_payments/quote/service.ts b/packages/backend/src/open_payments/quote/service.ts index 04d9df7f87..3b518c9ddd 100644 --- a/packages/backend/src/open_payments/quote/service.ts +++ b/packages/backend/src/open_payments/quote/service.ts @@ -20,6 +20,7 @@ import { PaymentMethodHandlerError, PaymentMethodHandlerErrorCode } from '../../payment-method/handler/errors' +import { TelemetryService } from '../../telemetry/service' const MAX_INT64 = BigInt('9223372036854775807') @@ -34,6 +35,7 @@ export interface ServiceDependencies extends BaseService { walletAddressService: WalletAddressService feeService: FeeService paymentMethodHandlerService: PaymentMethodHandlerService + telemetry?: TelemetryService } export async function createQuoteService( @@ -84,6 +86,7 @@ async function createQuote( deps: ServiceDependencies, options: CreateQuoteOptions ): Promise { + const start = Date.now() if (options.debitAmount && options.receiveAmount) { return QuoteError.InvalidAmount } @@ -112,22 +115,61 @@ async function createQuote( } try { + const receiverStart = Date.now() const receiver = await resolveReceiver(deps, options) + const receiverEnd = Date.now() + const receiverDuration = receiverEnd - receiverStart + + if (deps.telemetry) { + deps.telemetry.recordHistogram( + 'quote_service_create_resolve_receiver_time_ms', + receiverDuration, + { + description: 'Time to resolve receiver' + } + ) + } + + const getQuoteStart = Date.now() const quote = await deps.paymentMethodHandlerService.getQuote('ILP', { walletAddress, receiver, receiveAmount: options.receiveAmount, debitAmount: options.debitAmount }) + const getQuoteEnd = Date.now() + const getQuoteDuration = getQuoteEnd - getQuoteStart + if (deps.telemetry) { + deps.telemetry.recordHistogram( + 'quote_service_create_get_quote_time_ms', + getQuoteDuration, + { + description: 'Time to getQuote' + } + ) + } const maxPacketAmount = quote.additionalFields.maxPacketAmount as bigint + const getLatestFeeStart = Date.now() const sendingFee = await deps.feeService.getLatestFee( walletAddress.assetId, FeeType.Sending ) + const getLatestFeeEnd = Date.now() + const getLatestFeeDuration = getLatestFeeEnd - getLatestFeeStart + if (deps.telemetry) { + deps.telemetry.recordHistogram( + 'quote_service_create_get_latest_fee_time_ms', + getLatestFeeDuration, + { + description: 'Time to getLatestFee' + } + ) + } - return await Quote.transaction(deps.knex, async (trx) => { + const q = await Quote.transaction(deps.knex, async (trx) => { + const createQuoteStart = Date.now() const createdQuote = await Quote.query(trx) .insertAndFetch({ walletAddressId: options.walletAddressId, @@ -148,8 +190,21 @@ async function createQuote( estimatedExchangeRate: quote.estimatedExchangeRate }) .withGraphFetched('[asset, fee, walletAddress]') + const createQuoteEnd = Date.now() + const createQuoteDuration = createQuoteEnd - createQuoteStart + + if (deps.telemetry) { + deps.telemetry.recordHistogram( + 'quote_service_create_insert_time_ms', + createQuoteDuration, + { + description: 'Time to insert quote' + } + ) + } - return await finalizeQuote( + const finalizeQuoteStart = Date.now() + const finalizedQuote = await finalizeQuote( { ...deps, knex: trx @@ -158,7 +213,32 @@ async function createQuote( createdQuote, receiver ) + const finalizeQuoteEnd = Date.now() + const finalizeQuoteDuration = finalizeQuoteEnd - finalizeQuoteStart + + if (deps.telemetry) { + deps.telemetry.recordHistogram( + 'quote_service_finalize_quote_ms', + finalizeQuoteDuration, + { + description: 'Time to finalize quote' + } + ) + } + + return finalizedQuote }) + + const end = Date.now() + const duration = end - start + + if (deps.telemetry) { + deps.telemetry.recordHistogram('quote_service_create_time_ms', duration, { + description: 'Time to create a quote' + }) + } + + return q } catch (err) { if (isQuoteError(err)) { return err diff --git a/packages/backend/src/payment-method/ilp/service.ts b/packages/backend/src/payment-method/ilp/service.ts index 4974ffab24..2d0b4ba32a 100644 --- a/packages/backend/src/payment-method/ilp/service.ts +++ b/packages/backend/src/payment-method/ilp/service.ts @@ -43,6 +43,7 @@ async function getQuote( deps: ServiceDependencies, options: StartQuoteOptions ): Promise { + const rateStart = Date.now() const rates = await deps.ratesService .rates(options.walletAddress.asset.code) .catch((_err: Error) => { @@ -51,15 +52,47 @@ async function getQuote( retryable: false }) }) + const rateEnd = Date.now() + const rateDuration = rateEnd - rateStart + if (deps.telemetry) { + deps.telemetry.recordHistogram('ilp_get_quote_rate_time_ms', rateDuration, { + description: 'Time to get rates' + }) + } + + const pluginStart = Date.now() const plugin = deps.makeIlpPlugin({ sourceAccount: options.walletAddress, unfulfillable: true }) + const pluginEnd = Date.now() + const pluginDuration = pluginEnd - pluginStart + if (deps.telemetry) { + deps.telemetry.recordHistogram( + 'ilp_make_ilp_plugin_time_ms', + pluginDuration, + { + description: 'Time to make ilp plugin' + } + ) + } const destination = options.receiver.toResolvedPayment() try { + const pluginConnectStart = Date.now() await plugin.connect() + const pluginConnectEnd = Date.now() + const pluginConnectDuration = pluginConnectEnd - pluginConnectStart + if (deps.telemetry) { + deps.telemetry.recordHistogram( + 'ilp_make_ilp_plugin_connect_time_ms', + pluginConnectDuration, + { + description: 'Time to connect ilp plugin' + } + ) + } const quoteOptions: Pay.QuoteOptions = { plugin, destination, @@ -76,7 +109,7 @@ async function getQuote( } let ilpQuote: Pay.Quote | undefined - const rateProbeStartTime = Date.now() + const payStartTime = Date.now() try { ilpQuote = await Pay.startQuote({ ...quoteOptions, @@ -95,12 +128,12 @@ async function getQuote( const payEndTime = Date.now() if (deps.telemetry) { - const rateProbeDuraiton = payEndTime - rateProbeStartTime + const rateProbeDuraiton = payEndTime - payStartTime deps.telemetry.recordHistogram( 'ilp_rate_probe_time_ms', rateProbeDuraiton, { - description: 'Time to get an ILP quote' + description: 'Time to get an ILP quote (Pay.startQuote)' } ) } @@ -174,7 +207,19 @@ async function getQuote( } } finally { try { + const pluginCloseStart = Date.now() await Pay.closeConnection(plugin, destination) + const pluginCloseEnd = Date.now() + const pluginCloseDuration = pluginCloseEnd - pluginCloseStart + if (deps.telemetry) { + deps.telemetry.recordHistogram( + 'ilp_plugin_close_connect_time_ms', + pluginCloseDuration, + { + description: 'Time to close ilp plugin' + } + ) + } } catch (error) { deps.logger.warn( { @@ -186,7 +231,20 @@ async function getQuote( } try { + const pluginDisconnectStart = Date.now() await plugin.disconnect() + const pluginDisconnectEnd = Date.now() + const pluginDisconnectDuration = + pluginDisconnectEnd - pluginDisconnectStart + if (deps.telemetry) { + deps.telemetry.recordHistogram( + 'ilp_plugin_disconnect_time_ms', + pluginDisconnectDuration, + { + description: 'Time to disconnect ilp plugin' + } + ) + } } catch (error) { deps.logger.warn( { error: error instanceof Error && error.message }, diff --git a/test/performance/scripts/create-outgoing-payments.js b/test/performance/scripts/create-outgoing-payments.js index 1b3b883206..c8251f9221 100644 --- a/test/performance/scripts/create-outgoing-payments.js +++ b/test/performance/scripts/create-outgoing-payments.js @@ -2,9 +2,9 @@ import http from 'k6/http' import { fail } from 'k6' export const options = { // A number specifying the number of VUs to run concurrently. - vus: 1, + vus: 5, // A string specifying the total duration of the test run. - duration: '600s' + duration: '120s' } const HEADERS = {