From 5de7ad92e20ca791d4afd1b545c9ffd82754bfaf Mon Sep 17 00:00:00 2001 From: Blair Currey <12960453+BlairCurrey@users.noreply.github.com> Date: Thu, 19 Sep 2024 13:35:27 -0400 Subject: [PATCH 01/31] refactor(backend): add NoopTelemetryServiceImpl to make tel optional --- packages/backend/src/app.ts | 4 +- packages/backend/src/index.ts | 76 +- .../backend/src/telemetry/service.test.ts | 705 +++++++++--------- packages/backend/src/telemetry/service.ts | 62 +- 4 files changed, 462 insertions(+), 385 deletions(-) diff --git a/packages/backend/src/app.ts b/packages/backend/src/app.ts index c56544f38f..d0cdd19f35 100644 --- a/packages/backend/src/app.ts +++ b/packages/backend/src/app.ts @@ -215,8 +215,8 @@ const WALLET_ADDRESS_PATH = '/:walletAddressPath+' export interface AppServices { logger: Promise - telemetry?: Promise - internalRatesService?: Promise + telemetry: Promise + internalRatesService: Promise knex: Promise axios: Promise config: Promise diff --git a/packages/backend/src/index.ts b/packages/backend/src/index.ts index a34d784ef7..fd60a245e5 100644 --- a/packages/backend/src/index.ts +++ b/packages/backend/src/index.ts @@ -47,14 +47,11 @@ import { } from './payment-method/ilp/ilp_plugin' import { createHttpTokenService } from './payment-method/ilp/peer-http-token/service' import { createPeerService } from './payment-method/ilp/peer/service' -import { - createIlpPaymentService, - ServiceDependencies as IlpPaymentServiceDependencies -} from './payment-method/ilp/service' +import { createIlpPaymentService } from './payment-method/ilp/service' import { createSPSPRoutes } from './payment-method/ilp/spsp/routes' import { createStreamCredentialsService } from './payment-method/ilp/stream-credentials/service' import { createRatesService } from './rates/service' -import { TelemetryService, createTelemetryService } from './telemetry/service' +import { createTelemetryService } from './telemetry/service' import { createWebhookService } from './webhook/service' BigInt.prototype.toJSON = function () { @@ -135,29 +132,28 @@ export function initIocContainer( }) }) - if (config.enableTelemetry) { - container.singleton('internalRatesService', async (deps) => { - return createRatesService({ - logger: await deps.use('logger'), - exchangeRatesUrl: config.telemetryExchangeRatesUrl, - exchangeRatesLifetime: config.telemetryExchangeRatesLifetime - }) + container.singleton('internalRatesService', async (deps) => { + return createRatesService({ + logger: await deps.use('logger'), + exchangeRatesUrl: config.telemetryExchangeRatesUrl, + exchangeRatesLifetime: config.telemetryExchangeRatesLifetime }) + }) - container.singleton('telemetry', async (deps) => { - const config = await deps.use('config') - return createTelemetryService({ - logger: await deps.use('logger'), - aseRatesService: await deps.use('ratesService'), - internalRatesService: await deps.use('internalRatesService')!, - instanceName: config.instanceName, - collectorUrls: config.openTelemetryCollectors, - exportIntervalMillis: config.openTelemetryExportInterval, - baseAssetCode: 'USD', - baseScale: 4 - }) + container.singleton('telemetry', async (deps) => { + const config = await deps.use('config') + return createTelemetryService({ + logger: await deps.use('logger'), + aseRatesService: await deps.use('ratesService'), + internalRatesService: await deps.use('internalRatesService')!, + instanceName: config.instanceName, + collectorUrls: config.openTelemetryCollectors, + exportIntervalMillis: config.openTelemetryExportInterval, + enableTelemetry: config.enableTelemetry, + baseAssetCode: 'USD', + baseScale: 4 }) - } + }) container.singleton('openApi', async () => { const resourceServerSpec = await getResourceServerOpenAPI() @@ -356,10 +352,6 @@ export function initIocContainer( container.singleton('connectorApp', async (deps) => { const config = await deps.use('config') - let telemetry: TelemetryService | undefined - if (config.enableTelemetry) { - telemetry = await deps.use('telemetry') - } return await createConnectorService({ logger: await deps.use('logger'), redis: await deps.use('redis'), @@ -370,7 +362,7 @@ export function initIocContainer( ratesService: await deps.use('ratesService'), streamServer: await deps.use('streamServer'), ilpAddress: config.ilpAddress, - telemetry + telemetry: await deps.use('telemetry') }) }) @@ -425,19 +417,14 @@ export function initIocContainer( }) container.singleton('ilpPaymentService', async (deps) => { - const serviceDependencies: IlpPaymentServiceDependencies = { + return await createIlpPaymentService({ logger: await deps.use('logger'), knex: await deps.use('knex'), config: await deps.use('config'), makeIlpPlugin: await deps.use('makeIlpPlugin'), - ratesService: await deps.use('ratesService') - } - - if (config.enableTelemetry) { - serviceDependencies.telemetry = await deps.use('telemetry') - } - - return createIlpPaymentService(serviceDependencies) + ratesService: await deps.use('ratesService'), + telemetry: await deps.use('telemetry') + }) }) container.singleton('paymentMethodHandlerService', async (deps) => { @@ -469,7 +456,6 @@ export function initIocContainer( }) container.singleton('outgoingPaymentService', async (deps) => { - const config = await deps.use('config') return await createOutgoingPaymentService({ logger: await deps.use('logger'), knex: await deps.use('knex'), @@ -481,9 +467,7 @@ export function initIocContainer( peerService: await deps.use('peerService'), walletAddressService: await deps.use('walletAddressService'), quoteService: await deps.use('quoteService'), - telemetry: config.enableTelemetry - ? await deps.use('telemetry') - : undefined + telemetry: await deps.use('telemetry') }) }) @@ -548,10 +532,8 @@ export const gracefulShutdown = async ( await redis.quit() redis.disconnect() - if (config.enableTelemetry) { - const telemetry = await container.use('telemetry') - telemetry?.shutdown() - } + const telemetry = await container.use('telemetry') + telemetry.shutdown() } export const start = async ( diff --git a/packages/backend/src/telemetry/service.test.ts b/packages/backend/src/telemetry/service.test.ts index 3834212f01..e507ff470c 100644 --- a/packages/backend/src/telemetry/service.test.ts +++ b/packages/backend/src/telemetry/service.test.ts @@ -5,7 +5,13 @@ import { Config } from '../config/app' import { ConvertError, RatesService } from '../rates/service' import { TestContainer, createTestApp } from '../tests/app' import { mockCounter, mockHistogram } from '../tests/telemetry' -import { TelemetryService } from './service' +import { + createTelemetryService, + NoopTelemetryServiceImpl, + TelemetryService, + TelemetryServiceImpl, + TelemetryServiceDependencies +} from './service' import { Counter, Histogram } from '@opentelemetry/api' import { privacy } from './privacy' import { mockRatesApi } from '../tests/rates' @@ -30,406 +36,439 @@ jest.mock('@opentelemetry/sdk-metrics', () => ({ })) })) -describe('TelemetryServiceImpl', () => { - let deps: IocContract - let appContainer: TestContainer - let telemetryService: TelemetryService - let aseRatesService: RatesService - let internalRatesService: RatesService - - let apiRequestCount = 0 - const exchangeRatesUrl = 'http://example-rates.com' - - const exampleRates = { - USD: { - EUR: 2 - }, - EUR: { - USD: 1.12 +describe('Telemetry Service', () => { + describe('Telemtry Enabled', () => { + let deps: IocContract + let appContainer: TestContainer + let telemetryService: TelemetryService + let aseRatesService: RatesService + let internalRatesService: RatesService + + let apiRequestCount = 0 + const exchangeRatesUrl = 'http://example-rates.com' + + const exampleRates = { + USD: { + EUR: 2 + }, + EUR: { + USD: 1.12 + } } - } - beforeAll(async (): Promise => { - deps = initIocContainer({ - ...Config, - enableTelemetry: true, - telemetryExchangeRatesUrl: 'http://example-rates.com', - telemetryExchangeRatesLifetime: 100, - openTelemetryCollectors: [] - }) + beforeAll(async (): Promise => { + deps = initIocContainer({ + ...Config, + enableTelemetry: true, + telemetryExchangeRatesUrl: 'http://example-rates.com', + telemetryExchangeRatesLifetime: 100, + openTelemetryCollectors: [] + }) - appContainer = await createTestApp(deps) - telemetryService = await deps.use('telemetry')! - aseRatesService = await deps.use('ratesService')! - internalRatesService = await deps.use('internalRatesService')! + appContainer = await createTestApp(deps) + telemetryService = await deps.use('telemetry')! + aseRatesService = await deps.use('ratesService')! + internalRatesService = await deps.use('internalRatesService')! - mockRatesApi(exchangeRatesUrl, (base) => { - apiRequestCount++ - return exampleRates[base as keyof typeof exampleRates] + mockRatesApi(exchangeRatesUrl, (base) => { + apiRequestCount++ + return exampleRates[base as keyof typeof exampleRates] + }) }) - }) - afterAll(async (): Promise => { - await appContainer.shutdown() - }) + afterAll(async (): Promise => { + await appContainer.shutdown() + }) - it('should create a counter with source attribute for a new metric', () => { - const name = 'test_counter' - const amount = 1 - const attributes = { test: 'attribute' } + it('should create a counter with source attribute for a new metric', () => { + const name = 'test_counter' + const amount = 1 + const attributes = { test: 'attribute' } - telemetryService.incrementCounter(name, amount, attributes) + telemetryService.incrementCounter(name, amount, attributes) - expect(mockCounter.add).toHaveBeenCalledWith( - amount, - expect.objectContaining({ - ...attributes, - source: expect.any(String) - }) - ) - }) + expect(mockCounter.add).toHaveBeenCalledWith( + amount, + expect.objectContaining({ + ...attributes, + source: expect.any(String) + }) + ) + }) - it('should create a histogram with source attribute for a new metric', () => { - const name = 'test_histogram' - const amount = 1 - const attributes = { test: 'attribute' } + it('should create a histogram with source attribute for a new metric', () => { + const name = 'test_histogram' + const amount = 1 + const attributes = { test: 'attribute' } - telemetryService.recordHistogram(name, amount, attributes) + telemetryService.recordHistogram(name, amount, attributes) - expect(mockHistogram.record).toHaveBeenCalledWith( - amount, - expect.objectContaining({ - ...attributes, - source: expect.any(String) - }) - ) - }) + expect(mockHistogram.record).toHaveBeenCalledWith( + amount, + expect.objectContaining({ + ...attributes, + source: expect.any(String) + }) + ) + }) - it('should use existing counter when incrementCounter is called for an existing metric', () => { - const name = 'test_counter' + it('should use existing counter when incrementCounter is called for an existing metric', () => { + const name = 'test_counter' - telemetryService.incrementCounter(name, 1) - telemetryService.incrementCounter(name, 1) + telemetryService.incrementCounter(name, 1) + telemetryService.incrementCounter(name, 1) - //"any" to access private ts class member variable - // eslint-disable-next-line @typescript-eslint/no-explicit-any - const counters: Map = (telemetryService as any).counters + //"any" to access private ts class member variable + // eslint-disable-next-line @typescript-eslint/no-explicit-any + const counters: Map = (telemetryService as any).counters - expect(counters.size).toBe(1) - expect(counters.has(name)).toBe(true) + expect(counters.size).toBe(1) + expect(counters.has(name)).toBe(true) - const counter = counters.get(name) - expect(counter?.add).toHaveBeenCalledTimes(2) - }) + const counter = counters.get(name) + expect(counter?.add).toHaveBeenCalledTimes(2) + }) - it('should use existing histogram when recordHistogram is called for an existing metric', () => { - const name = 'test_histogram' + it('should use existing histogram when recordHistogram is called for an existing metric', () => { + const name = 'test_histogram' - telemetryService.recordHistogram(name, 1) - telemetryService.recordHistogram(name, 1) + telemetryService.recordHistogram(name, 1) + telemetryService.recordHistogram(name, 1) - //"any" to access private ts class member variable - // eslint-disable-next-line @typescript-eslint/no-explicit-any - const histograms: Map = (telemetryService as any) - .histograms + //"any" to access private ts class member variable + // eslint-disable-next-line @typescript-eslint/no-explicit-any + const histograms: Map = (telemetryService as any) + .histograms - expect(histograms.size).toBe(1) - expect(histograms.has(name)).toBe(true) + expect(histograms.size).toBe(1) + expect(histograms.has(name)).toBe(true) - const histogram = histograms.get(name) - expect(histogram?.record).toHaveBeenCalledTimes(2) - }) + const histogram = histograms.get(name) + expect(histogram?.record).toHaveBeenCalledTimes(2) + }) - describe('incrementCounterWithTransactionAmountDifference', () => { - it('should not record fee when there is no fee value', async () => { - const spyAseConvert = jest.spyOn(aseRatesService, 'convert') - const spyIncCounter = jest.spyOn(telemetryService, 'incrementCounter') + describe('incrementCounterWithTransactionAmountDifference', () => { + it('should not record fee when there is no fee value', async () => { + const spyAseConvert = jest.spyOn(aseRatesService, 'convert') + const spyIncCounter = jest.spyOn(telemetryService, 'incrementCounter') + + await telemetryService.incrementCounterWithTransactionAmountDifference( + 'test_amount_diff_counter', + { + value: 100n, + assetCode: 'USD', + assetScale: 2 + }, + { + value: 100n, + assetCode: 'USD', + assetScale: 2 + } + ) - await telemetryService.incrementCounterWithTransactionAmountDifference( - 'test_amount_diff_counter', - { - value: 100n, - assetCode: 'USD', - assetScale: 2 - }, - { - value: 100n, - assetCode: 'USD', - assetScale: 2 - } - ) + expect(spyAseConvert).toHaveBeenCalled() + expect(spyIncCounter).not.toHaveBeenCalled() + }) - expect(spyAseConvert).toHaveBeenCalled() - expect(spyIncCounter).not.toHaveBeenCalled() - }) + it('should not record fee negative fee value', async () => { + const spyConvert = jest.spyOn(aseRatesService, 'convert') + const spyIncCounter = jest.spyOn(telemetryService, 'incrementCounter') + + await telemetryService.incrementCounterWithTransactionAmountDifference( + 'test_amount_diff_counter', + { + value: 100n, + assetCode: 'USD', + assetScale: 2 + }, + { + value: 101n, + assetCode: 'USD', + assetScale: 2 + } + ) + + expect(spyConvert).toHaveBeenCalled() + expect(spyIncCounter).not.toHaveBeenCalled() + }) + + it('should not record zero amounts', async () => { + const spyConvert = jest.spyOn(aseRatesService, 'convert') + const spyIncCounter = jest.spyOn(telemetryService, 'incrementCounter') + + await telemetryService.incrementCounterWithTransactionAmountDifference( + 'test_amount_diff_counter', + { + value: 0n, + assetCode: 'USD', + assetScale: 2 + }, + { + value: 0n, + assetCode: 'USD', + assetScale: 2 + } + ) + + expect(spyConvert).not.toHaveBeenCalled() + expect(spyIncCounter).not.toHaveBeenCalled() + }) - it('should not record fee negative fee value', async () => { - const spyConvert = jest.spyOn(aseRatesService, 'convert') - const spyIncCounter = jest.spyOn(telemetryService, 'incrementCounter') + it('should record since it is a valid fee', async () => { + const spyConvert = jest.spyOn(aseRatesService, 'convert') + const spyIncCounter = jest.spyOn(telemetryService, 'incrementCounter') - await telemetryService.incrementCounterWithTransactionAmountDifference( - 'test_amount_diff_counter', - { + const source = { value: 100n, assetCode: 'USD', assetScale: 2 - }, - { - value: 101n, + } + const destination = { + value: 50n, assetCode: 'USD', assetScale: 2 } - ) - expect(spyConvert).toHaveBeenCalled() - expect(spyIncCounter).not.toHaveBeenCalled() - }) + const name = 'test_amount_diff_counter' + await telemetryService.incrementCounterWithTransactionAmountDifference( + name, + source, + destination + ) + + expect(spyConvert).toHaveBeenCalledTimes(2) + expect(spyConvert).toHaveBeenNthCalledWith( + 1, + expect.objectContaining({ + sourceAmount: source.value, + sourceAsset: { code: source.assetCode, scale: source.assetScale } + }) + ) + expect(spyConvert).toHaveBeenNthCalledWith( + 2, + expect.objectContaining({ + sourceAmount: destination.value, + sourceAsset: { + code: destination.assetCode, + scale: destination.assetScale + } + }) + ) + // Ensure the [incrementCounter] was called with the correct calculated value. Expected 5000 due to scale = 4. + expect(spyIncCounter).toHaveBeenCalledWith(name, 5000, {}) + }) - it('should not record zero amounts', async () => { - const spyConvert = jest.spyOn(aseRatesService, 'convert') - const spyIncCounter = jest.spyOn(telemetryService, 'incrementCounter') + it('should record since it is a valid fee for different assets', async () => { + const spyConvert = jest.spyOn(aseRatesService, 'convert') + const spyIncCounter = jest.spyOn(telemetryService, 'incrementCounter') - await telemetryService.incrementCounterWithTransactionAmountDifference( - 'test_amount_diff_counter', - { - value: 0n, + const source = { + value: 100n, assetCode: 'USD', assetScale: 2 - }, - { - value: 0n, - assetCode: 'USD', + } + const destination = { + value: 50n, + assetCode: 'EUR', assetScale: 2 } - ) - expect(spyConvert).not.toHaveBeenCalled() - expect(spyIncCounter).not.toHaveBeenCalled() - }) + const name = 'test_amount_diff_counter' + await telemetryService.incrementCounterWithTransactionAmountDifference( + name, + source, + destination + ) - it('should record since it is a valid fee', async () => { - const spyConvert = jest.spyOn(aseRatesService, 'convert') - const spyIncCounter = jest.spyOn(telemetryService, 'incrementCounter') + expect(spyConvert).toHaveBeenCalledTimes(2) + expect(spyConvert).toHaveBeenNthCalledWith( + 1, + expect.objectContaining({ + sourceAmount: source.value, + sourceAsset: { code: source.assetCode, scale: source.assetScale } + }) + ) + expect(spyConvert).toHaveBeenNthCalledWith( + 2, + expect.objectContaining({ + sourceAmount: destination.value, + sourceAsset: { + code: destination.assetCode, + scale: destination.assetScale + } + }) + ) + expect(spyIncCounter).toHaveBeenCalledWith(name, 4400, {}) + expect(apiRequestCount).toBe(1) + }) + }) - const source = { - value: 100n, - assetCode: 'USD', - assetScale: 2 - } - const destination = { - value: 50n, - assetCode: 'USD', - assetScale: 2 - } + describe('incrementCounterWithTransactionAmount', () => { + it('should try to convert using aseRatesService and fallback to internalRatesService', async () => { + const aseConvertSpy = jest + .spyOn(aseRatesService, 'convert') + .mockImplementation(() => + Promise.resolve(ConvertError.InvalidDestinationPrice) + ) + const internalConvertSpy = jest + .spyOn(internalRatesService, 'convert') + .mockImplementation(() => Promise.resolve(10000n)) + + await telemetryService.incrementCounterWithTransactionAmount( + 'test_counter', + { + value: 100n, + assetCode: 'USD', + assetScale: 2 + } + ) - const name = 'test_amount_diff_counter' - await telemetryService.incrementCounterWithTransactionAmountDifference( - name, - source, - destination - ) + expect(aseConvertSpy).toHaveBeenCalled() + expect(internalConvertSpy).toHaveBeenCalled() + }) - expect(spyConvert).toHaveBeenCalledTimes(2) - expect(spyConvert).toHaveBeenNthCalledWith( - 1, - expect.objectContaining({ - sourceAmount: source.value, - sourceAsset: { code: source.assetCode, scale: source.assetScale } - }) - ) - expect(spyConvert).toHaveBeenNthCalledWith( - 2, - expect.objectContaining({ - sourceAmount: destination.value, - sourceAsset: { - code: destination.assetCode, - scale: destination.assetScale + it('should not call the fallback internalRatesService if aseRatesService call is successful', async () => { + const aseConvertSpy = jest + .spyOn(aseRatesService, 'convert') + .mockImplementation(() => Promise.resolve(500n)) + const internalConvertSpy = jest.spyOn(internalRatesService, 'convert') + + await telemetryService.incrementCounterWithTransactionAmount( + 'test_counter', + { + value: 100n, + assetCode: 'USD', + assetScale: 2 } - }) - ) - // Ensure the [incrementCounter] was called with the correct calculated value. Expected 5000 due to scale = 4. - expect(spyIncCounter).toHaveBeenCalledWith(name, 5000, {}) - }) - - it('should record since it is a valid fee for different assets', async () => { - const spyConvert = jest.spyOn(aseRatesService, 'convert') - const spyIncCounter = jest.spyOn(telemetryService, 'incrementCounter') + ) - const source = { - value: 100n, - assetCode: 'USD', - assetScale: 2 - } - const destination = { - value: 50n, - assetCode: 'EUR', - assetScale: 2 - } + expect(aseConvertSpy).toHaveBeenCalled() + expect(internalConvertSpy).not.toHaveBeenCalled() + }) - const name = 'test_amount_diff_counter' - await telemetryService.incrementCounterWithTransactionAmountDifference( - name, - source, - destination - ) + it('should apply privacy', async () => { + const convertedAmount = 500n + + jest + //"any" to access private ts class member variable + // eslint-disable-next-line @typescript-eslint/no-explicit-any + .spyOn(telemetryService as any, 'convertAmount') + .mockImplementation(() => Promise.resolve(convertedAmount)) + const applyPrivacySpy = jest + .spyOn(privacy, 'applyPrivacy') + .mockReturnValue(123) + const incrementCounterSpy = jest.spyOn( + telemetryService, + 'incrementCounter' + ) - expect(spyConvert).toHaveBeenCalledTimes(2) - expect(spyConvert).toHaveBeenNthCalledWith( - 1, - expect.objectContaining({ - sourceAmount: source.value, - sourceAsset: { code: source.assetCode, scale: source.assetScale } - }) - ) - expect(spyConvert).toHaveBeenNthCalledWith( - 2, - expect.objectContaining({ - sourceAmount: destination.value, - sourceAsset: { - code: destination.assetCode, - scale: destination.assetScale + const counterName = 'test_counter' + await telemetryService.incrementCounterWithTransactionAmount( + counterName, + { + value: 100n, + assetCode: 'USD', + assetScale: 2 } - }) - ) - expect(spyIncCounter).toHaveBeenCalledWith(name, 4400, {}) - expect(apiRequestCount).toBe(1) - }) - }) - - describe('incrementCounterWithTransactionAmount', () => { - it('should try to convert using aseRatesService and fallback to internalRatesService', async () => { - const aseConvertSpy = jest - .spyOn(aseRatesService, 'convert') - .mockImplementation(() => - Promise.resolve(ConvertError.InvalidDestinationPrice) ) - const internalConvertSpy = jest - .spyOn(internalRatesService, 'convert') - .mockImplementation(() => Promise.resolve(10000n)) - await telemetryService.incrementCounterWithTransactionAmount( - 'test_counter', - { - value: 100n, - assetCode: 'USD', - assetScale: 2 - } - ) - - expect(aseConvertSpy).toHaveBeenCalled() - expect(internalConvertSpy).toHaveBeenCalled() - }) + expect(applyPrivacySpy).toHaveBeenCalledWith(Number(convertedAmount)) + expect(incrementCounterSpy).toHaveBeenCalledWith( + counterName, + 123, + expect.any(Object) + ) + }) - it('should not call the fallback internalRatesService if aseRatesService call is successful', async () => { - const aseConvertSpy = jest - .spyOn(aseRatesService, 'convert') - .mockImplementation(() => Promise.resolve(500n)) - const internalConvertSpy = jest.spyOn(internalRatesService, 'convert') + it('should not collect telemetry when conversion returns InvalidDestinationPrice', async () => { + const convertSpy = jest + //"any" to access private ts class member variable + // eslint-disable-next-line @typescript-eslint/no-explicit-any + .spyOn(telemetryService as any, 'convertAmount') + .mockImplementation(() => + Promise.resolve(ConvertError.InvalidDestinationPrice) + ) + + const incrementCounterSpy = jest.spyOn( + telemetryService, + 'incrementCounter' + ) - await telemetryService.incrementCounterWithTransactionAmount( - 'test_counter', - { - value: 100n, - assetCode: 'USD', - assetScale: 2 - } - ) + await telemetryService.incrementCounterWithTransactionAmount( + 'test_counter', + { + value: 100n, + assetCode: 'USD', + assetScale: 2 + } + ) - expect(aseConvertSpy).toHaveBeenCalled() - expect(internalConvertSpy).not.toHaveBeenCalled() - }) + expect(convertSpy).toHaveBeenCalled() + expect(incrementCounterSpy).not.toHaveBeenCalled() + }) - it('should apply privacy', async () => { - const convertedAmount = 500n - - jest - //"any" to access private ts class member variable - // eslint-disable-next-line @typescript-eslint/no-explicit-any - .spyOn(telemetryService as any, 'convertAmount') - .mockImplementation(() => Promise.resolve(convertedAmount)) - const applyPrivacySpy = jest - .spyOn(privacy, 'applyPrivacy') - .mockReturnValue(123) - const incrementCounterSpy = jest.spyOn( - telemetryService, - 'incrementCounter' - ) + it('should collect telemetry when conversion is successful', async () => { + const convertSpy = jest + //"any" to access private ts class member variable + // eslint-disable-next-line @typescript-eslint/no-explicit-any + .spyOn(telemetryService as any, 'convertAmount') + .mockImplementation(() => Promise.resolve(10000n)) + const incrementCounterSpy = jest.spyOn( + telemetryService, + 'incrementCounter' + ) + const obfuscatedAmount = 12000 + jest.spyOn(privacy, 'applyPrivacy').mockReturnValue(obfuscatedAmount) - const counterName = 'test_counter' - await telemetryService.incrementCounterWithTransactionAmount( - counterName, - { - value: 100n, - assetCode: 'USD', - assetScale: 2 - } - ) + const counterName = 'test_counter' - expect(applyPrivacySpy).toHaveBeenCalledWith(Number(convertedAmount)) - expect(incrementCounterSpy).toHaveBeenCalledWith( - counterName, - 123, - expect.any(Object) - ) - }) + await telemetryService.incrementCounterWithTransactionAmount( + counterName, + { + value: 100n, + assetCode: 'USD', + assetScale: 2 + } + ) - it('should not collect telemetry when conversion returns InvalidDestinationPrice', async () => { - const convertSpy = jest - //"any" to access private ts class member variable - // eslint-disable-next-line @typescript-eslint/no-explicit-any - .spyOn(telemetryService as any, 'convertAmount') - .mockImplementation(() => - Promise.resolve(ConvertError.InvalidDestinationPrice) + expect(convertSpy).toHaveBeenCalled() + expect(incrementCounterSpy).toHaveBeenCalledWith( + counterName, + obfuscatedAmount, + expect.any(Object) ) + }) + }) + }) + describe('Telemetry Disabled', () => { + let deps: TelemetryServiceDependencies - const incrementCounterSpy = jest.spyOn( - telemetryService, - 'incrementCounter' - ) + beforeEach(() => { + deps = { + enableTelemetry: false + } as TelemetryServiceDependencies + }) - await telemetryService.incrementCounterWithTransactionAmount( - 'test_counter', - { - value: 100n, - assetCode: 'USD', - assetScale: 2 - } - ) + test('should return NoopTelemetryServiceImpl when enableTelemetry is false', () => { + const telemetryService = createTelemetryService(deps) - expect(convertSpy).toHaveBeenCalled() - expect(incrementCounterSpy).not.toHaveBeenCalled() + expect(telemetryService).toBeInstanceOf(NoopTelemetryServiceImpl) }) - it('should collect telemetry when conversion is successful', async () => { - const convertSpy = jest - //"any" to access private ts class member variable - // eslint-disable-next-line @typescript-eslint/no-explicit-any - .spyOn(telemetryService as any, 'convertAmount') - .mockImplementation(() => Promise.resolve(10000n)) - const incrementCounterSpy = jest.spyOn( - telemetryService, - 'incrementCounter' - ) - const obfuscatedAmount = 12000 - jest.spyOn(privacy, 'applyPrivacy').mockReturnValue(obfuscatedAmount) + test('should return TelemetryServiceImpl when enableTelemetry is true', () => { + deps.enableTelemetry = true + const telemetryService = createTelemetryService(deps) - const counterName = 'test_counter' + expect(telemetryService).toBeInstanceOf(TelemetryServiceImpl) + }) - await telemetryService.incrementCounterWithTransactionAmount( - counterName, - { - value: 100n, - assetCode: 'USD', - assetScale: 2 - } - ) + test('NoopTelemetryServiceImpl should not get meter ', () => { + const telemetryService = createTelemetryService(deps) + telemetryService.recordHistogram('testhistogram', 1) + telemetryService.incrementCounter('testcounter', 1) - expect(convertSpy).toHaveBeenCalled() - expect(incrementCounterSpy).toHaveBeenCalledWith( - counterName, - obfuscatedAmount, - expect.any(Object) - ) + expect(mockCounter.add).toHaveBeenCalledTimes(0) + expect(mockHistogram.record).toHaveBeenCalledTimes(0) }) }) }) diff --git a/packages/backend/src/telemetry/service.ts b/packages/backend/src/telemetry/service.ts index d0c03435a9..13d4eb6481 100644 --- a/packages/backend/src/telemetry/service.ts +++ b/packages/backend/src/telemetry/service.ts @@ -32,7 +32,7 @@ export interface TelemetryService { ): void } -interface TelemetryServiceDependencies extends BaseService { +export interface TelemetryServiceDependencies extends BaseService { instanceName: string collectorUrls: string[] exportIntervalMillis?: number @@ -40,6 +40,7 @@ interface TelemetryServiceDependencies extends BaseService { internalRatesService: RatesService baseAssetCode: string baseScale: number + enableTelemetry: boolean } const METER_NAME = 'Rafiki' @@ -47,10 +48,13 @@ const METER_NAME = 'Rafiki' export function createTelemetryService( deps: TelemetryServiceDependencies ): TelemetryService { + if (!deps.enableTelemetry) { + return new NoopTelemetryServiceImpl(deps) + } return new TelemetryServiceImpl(deps) } -class TelemetryServiceImpl implements TelemetryService { +export class TelemetryServiceImpl implements TelemetryService { private instanceName: string private meterProvider?: MeterProvider private internalRatesService: RatesService @@ -178,7 +182,7 @@ class TelemetryServiceImpl implements TelemetryService { public recordHistogram( name: string, value: number, - attributes: Record = {} + attributes?: Record ): void { const histogram = this.getOrCreateHistogram(name) histogram.record(value, { @@ -216,3 +220,55 @@ class TelemetryServiceImpl implements TelemetryService { return converted } } + +/* eslint-disable @typescript-eslint/no-unused-vars */ +export class NoopTelemetryServiceImpl implements TelemetryService { + private instanceName: string + private meterProvider?: MeterProvider + private internalRatesService: RatesService + private aseRatesService: RatesService + + constructor(private deps: TelemetryServiceDependencies) { + this.instanceName = deps.instanceName + this.internalRatesService = deps.internalRatesService + this.aseRatesService = deps.aseRatesService + } + + public async shutdown(): Promise { + // do nothing + } + + public incrementCounter( + name: string, + value: number, + attributes?: Record + ): void { + // do nothing + } + + public recordHistogram( + name: string, + value: number, + attributes?: Record + ): void { + // do nothing + } + + public async incrementCounterWithTransactionAmountDifference( + name: string, + amountSource: { value: bigint; assetCode: string; assetScale: number }, + amountDestination: { value: bigint; assetCode: string; assetScale: number }, + attributes?: Record + ): Promise { + // do nothing + } + + public async incrementCounterWithTransactionAmount( + name: string, + amount: { value: bigint; assetCode: string; assetScale: number }, + attributes: Record = {}, + preservePrivacy = true + ): Promise { + // do nothing + } +} From 751ffa96d1f1ea15eb298bdc0cdb15496b37071e Mon Sep 17 00:00:00 2001 From: Blair Currey <12960453+BlairCurrey@users.noreply.github.com> Date: Thu, 19 Sep 2024 13:59:56 -0400 Subject: [PATCH 02/31] refactor(backend): rm unecessary telemetry exists check --- .../payment/outgoing/lifecycle.ts | 38 +++++++++--------- .../open_payments/payment/outgoing/service.ts | 2 +- .../ilp/connector/core/rafiki.ts | 40 +++++++++---------- .../src/payment-method/ilp/connector/index.ts | 2 +- .../backend/src/payment-method/ilp/service.ts | 20 +++++----- 5 files changed, 47 insertions(+), 55 deletions(-) diff --git a/packages/backend/src/open_payments/payment/outgoing/lifecycle.ts b/packages/backend/src/open_payments/payment/outgoing/lifecycle.ts index f273e008a1..1b402db2d3 100644 --- a/packages/backend/src/open_payments/payment/outgoing/lifecycle.ts +++ b/packages/backend/src/open_payments/payment/outgoing/lifecycle.ts @@ -85,26 +85,24 @@ export async function handleSending( }) const payEndTime = Date.now() - if (deps.telemetry) { - const payDuration = payEndTime - payStartTime - await Promise.all([ - deps.telemetry.incrementCounter('transactions_total', 1, { - description: 'Count of funded transactions' - }), - deps.telemetry.recordHistogram('ilp_pay_time_ms', payDuration, { - description: 'Time to complete an ILP payment' - }), - deps.telemetry.incrementCounterWithTransactionAmountDifference( - 'transaction_fee_amounts', - payment.sentAmount, - payment.receiveAmount, - { - description: 'Amount sent through the network as fees', - valueType: ValueType.DOUBLE - } - ) - ]) - } + const payDuration = payEndTime - payStartTime + await Promise.all([ + deps.telemetry.incrementCounter('transactions_total', 1, { + description: 'Count of funded transactions' + }), + deps.telemetry.recordHistogram('ilp_pay_time_ms', payDuration, { + description: 'Time to complete an ILP payment' + }), + deps.telemetry.incrementCounterWithTransactionAmountDifference( + 'transaction_fee_amounts', + payment.sentAmount, + payment.receiveAmount, + { + description: 'Amount sent through the network as fees', + valueType: ValueType.DOUBLE + } + ) + ]) await handleCompleted(deps, payment) } diff --git a/packages/backend/src/open_payments/payment/outgoing/service.ts b/packages/backend/src/open_payments/payment/outgoing/service.ts index 050700aca1..336444e518 100644 --- a/packages/backend/src/open_payments/payment/outgoing/service.ts +++ b/packages/backend/src/open_payments/payment/outgoing/service.ts @@ -66,7 +66,7 @@ export interface ServiceDependencies extends BaseService { paymentMethodHandlerService: PaymentMethodHandlerService walletAddressService: WalletAddressService quoteService: QuoteService - telemetry?: TelemetryService + telemetry: TelemetryService } export async function createOutgoingPaymentService( diff --git a/packages/backend/src/payment-method/ilp/connector/core/rafiki.ts b/packages/backend/src/payment-method/ilp/connector/core/rafiki.ts index a6095fb064..6740d21886 100644 --- a/packages/backend/src/payment-method/ilp/connector/core/rafiki.ts +++ b/packages/backend/src/payment-method/ilp/connector/core/rafiki.ts @@ -63,7 +63,7 @@ export interface TransferOptions { export interface RafikiServices { //router: Router accounting: AccountingService - telemetry?: TelemetryService + telemetry: TelemetryService walletAddresses: WalletAddressService logger: Logger incomingPayments: IncomingPaymentService @@ -143,7 +143,7 @@ export class Rafiki { get walletAddresses(): WalletAddressService { return config.walletAddresses }, - get telemetry(): TelemetryService | undefined { + get telemetry(): TelemetryService { return config.telemetry }, logger @@ -162,9 +162,7 @@ export class Rafiki { const response = new IlpResponse() const telemetry = this.publicServer.context.services.telemetry - if (telemetry) { - incrementPreparePacketCount(unfulfillable, prepare.amount, telemetry) - } + incrementPreparePacketCount(unfulfillable, prepare.amount, telemetry) await this.routes( { @@ -194,23 +192,21 @@ export class Rafiki { ) if (!response.rawReply) throw new Error('error generating reply') - if (telemetry) { - const { code, scale } = sourceAccount.asset - incrementFulfillOrRejectPacketCount( - unfulfillable, - prepare.amount, - response, - telemetry - ) - await incrementAmount( - unfulfillable, - prepare.amount, - response, - code, - scale, - telemetry - ) - } + const { code, scale } = sourceAccount.asset + incrementFulfillOrRejectPacketCount( + unfulfillable, + prepare.amount, + response, + telemetry + ) + await incrementAmount( + unfulfillable, + prepare.amount, + response, + code, + scale, + telemetry + ) return response.rawReply } diff --git a/packages/backend/src/payment-method/ilp/connector/index.ts b/packages/backend/src/payment-method/ilp/connector/index.ts index 9f3ecc3f95..8dd2f27f0d 100644 --- a/packages/backend/src/payment-method/ilp/connector/index.ts +++ b/packages/backend/src/payment-method/ilp/connector/index.ts @@ -38,7 +38,7 @@ interface ServiceDependencies extends BaseService { peerService: PeerService streamServer: StreamServer ilpAddress: string - telemetry?: TelemetryService + telemetry: TelemetryService } export async function createConnectorService({ diff --git a/packages/backend/src/payment-method/ilp/service.ts b/packages/backend/src/payment-method/ilp/service.ts index 4974ffab24..b21c80db32 100644 --- a/packages/backend/src/payment-method/ilp/service.ts +++ b/packages/backend/src/payment-method/ilp/service.ts @@ -22,7 +22,7 @@ export interface ServiceDependencies extends BaseService { config: IAppConfig ratesService: RatesService makeIlpPlugin: (options: IlpPluginOptions) => IlpPlugin - telemetry?: TelemetryService + telemetry: TelemetryService } export async function createIlpPaymentService( @@ -94,16 +94,14 @@ async function getQuote( } const payEndTime = Date.now() - if (deps.telemetry) { - const rateProbeDuraiton = payEndTime - rateProbeStartTime - deps.telemetry.recordHistogram( - 'ilp_rate_probe_time_ms', - rateProbeDuraiton, - { - description: 'Time to get an ILP quote' - } - ) - } + const rateProbeDuraiton = payEndTime - rateProbeStartTime + deps.telemetry.recordHistogram( + 'ilp_rate_probe_time_ms', + rateProbeDuraiton, + { + description: 'Time to get an ILP quote' + } + ) // Pay.startQuote should return PaymentError.InvalidSourceAmount or // PaymentError.InvalidDestinationAmount for non-positive amounts. // Outgoing payments' sendAmount or receiveAmount should never be From a003c3ed9a9784e4e99212bd1b2e6098f7a70045 Mon Sep 17 00:00:00 2001 From: Blair Currey <12960453+BlairCurrey@users.noreply.github.com> Date: Thu, 19 Sep 2024 14:08:38 -0400 Subject: [PATCH 03/31] fix(localenv): rm telemetry log noise --- localenv/telemetry/otel-collector-config.yaml | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/localenv/telemetry/otel-collector-config.yaml b/localenv/telemetry/otel-collector-config.yaml index 32e08f8902..d577a0ec78 100644 --- a/localenv/telemetry/otel-collector-config.yaml +++ b/localenv/telemetry/otel-collector-config.yaml @@ -8,6 +8,8 @@ processors: batch: exporters: + logging: + loglevel: info debug: verbosity: detailed prometheus: @@ -18,6 +20,9 @@ exporters: insecure: true service: + telemetry: + logs: + level: warn pipelines: metrics: receivers: [otlp] From 10b4ea4f7a443b20d6bb5f44a73cffe8c3d07e45 Mon Sep 17 00:00:00 2001 From: Blair Currey <12960453+BlairCurrey@users.noreply.github.com> Date: Fri, 20 Sep 2024 11:40:50 -0400 Subject: [PATCH 04/31] feat(backend): add startTimer tel method --- packages/backend/src/telemetry/service.ts | 20 ++++++++++++++++++++ packages/backend/src/tests/telemetry.ts | 3 +++ 2 files changed, 23 insertions(+) diff --git a/packages/backend/src/telemetry/service.ts b/packages/backend/src/telemetry/service.ts index 13d4eb6481..c317570f45 100644 --- a/packages/backend/src/telemetry/service.ts +++ b/packages/backend/src/telemetry/service.ts @@ -30,6 +30,7 @@ export interface TelemetryService { value: number, attributes?: Record ): void + startTimer(name: string, attributes?: Record): () => void } export interface TelemetryServiceDependencies extends BaseService { @@ -219,6 +220,16 @@ export class TelemetryServiceImpl implements TelemetryService { } return converted } + + public startTimer( + name: string, + attributes: Record = {} + ): () => void { + const start = Date.now() + return () => { + this.recordHistogram(name, Date.now() - start, attributes) + } + } } /* eslint-disable @typescript-eslint/no-unused-vars */ @@ -271,4 +282,13 @@ export class NoopTelemetryServiceImpl implements TelemetryService { ): Promise { // do nothing } + + public startTimer( + name: string, + attributes: Record = {} + ): () => void { + return () => { + // do nothing + } + } } diff --git a/packages/backend/src/tests/telemetry.ts b/packages/backend/src/tests/telemetry.ts index 22b375d68e..2e13a6b5ba 100644 --- a/packages/backend/src/tests/telemetry.ts +++ b/packages/backend/src/tests/telemetry.ts @@ -40,6 +40,9 @@ export class MockTelemetryService implements TelemetryService { return 'serviceName' } public async shutdown(): Promise {} + public startTimer(): () => void { + return () => undefined + } public async convertAmount( _convertOptions: Omit From 6c660ad891ff9176f1feb926ea8e977831d8bcad Mon Sep 17 00:00:00 2001 From: Blair Currey <12960453+BlairCurrey@users.noreply.github.com> Date: Fri, 20 Sep 2024 12:21:09 -0400 Subject: [PATCH 05/31] feat: update local grafana dash w/ performance metrics - the underlying metrics for the new promql queries/grafana visualizations do not exist yet and should be added in later commit --- .../provisioning/dashboards/example.json | 1600 +++++++++++++++-- 1 file changed, 1438 insertions(+), 162 deletions(-) diff --git a/localenv/telemetry/grafana/provisioning/dashboards/example.json b/localenv/telemetry/grafana/provisioning/dashboards/example.json index 513c1b1448..276dd8c647 100644 --- a/localenv/telemetry/grafana/provisioning/dashboards/example.json +++ b/localenv/telemetry/grafana/provisioning/dashboards/example.json @@ -18,12 +18,1295 @@ "editable": true, "fiscalYearStartMonth": 0, "graphTooltip": 0, + "id": 1, "links": [], "panels": [ { "datasource": { + "default": false, "type": "prometheus", - "uid": "PBFA97CFB590B2093" + "uid": "${PrometheusDS}" + }, + "fieldConfig": { + "defaults": { + "color": { + "mode": "thresholds" + }, + "mappings": [], + "thresholds": { + "mode": "absolute", + "steps": [ + { + "color": "green", + "value": null + }, + { + "color": "red", + "value": 80 + } + ] + } + }, + "overrides": [] + }, + "gridPos": { + "h": 7, + "w": 3, + "x": 0, + "y": 0 + }, + "id": 17, + "options": { + "colorMode": "value", + "graphMode": "area", + "justifyMode": "auto", + "orientation": "auto", + "percentChangeColorMode": "standard", + "reduceOptions": { + "calcs": ["lastNotNull"], + "fields": "", + "values": false + }, + "showPercentChange": false, + "textMode": "auto", + "wideLayout": true + }, + "pluginVersion": "11.2.0", + "targets": [ + { + "datasource": { + "type": "prometheus", + "uid": "PBFA97CFB590B2093" + }, + "editorMode": "code", + "expr": "avg_over_time(rate(transactions_total[30s])[5m:])", + "instant": false, + "legendFormat": "__auto", + "range": true, + "refId": "A" + } + ], + "title": "Panel Title", + "type": "stat" + }, + { + "datasource": { + "default": false, + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "description": "", + "fieldConfig": { + "defaults": { + "color": { + "mode": "palette-classic" + }, + "custom": { + "axisBorderShow": false, + "axisCenteredZero": false, + "axisColorMode": "text", + "axisLabel": "", + "axisPlacement": "auto", + "barAlignment": 0, + "barWidthFactor": 0.6, + "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 + } + ] + }, + "unit": "ms" + }, + "overrides": [] + }, + "gridPos": { + "h": 7, + "w": 21, + "x": 3, + "y": 0 + }, + "id": 10, + "options": { + "legend": { + "calcs": ["p95"], + "displayMode": "table", + "placement": "right", + "showLegend": true + }, + "tooltip": { + "mode": "single", + "sort": "none" + } + }, + "targets": [ + { + "datasource": { + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "editorMode": "code", + "expr": "sum by (callName) (rate(getPendingPayment_sum[$__rate_interval])/rate(getPendingPayment_count[$__rate_interval]))", + "instant": false, + "legendFormat": "{{caller}}", + "range": true, + "refId": "A" + }, + { + "datasource": { + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "editorMode": "code", + "expr": "sum by (callName) (rate(handleSending_sum[$__rate_interval])/rate(handleSending_count[$__rate_interval]))", + "hide": false, + "instant": false, + "legendFormat": "__auto", + "range": true, + "refId": "B" + }, + { + "datasource": { + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "editorMode": "code", + "expr": "sum by (callName) (rate(getReceiver_sum[$__rate_interval])/rate(getReceiver_count[$__rate_interval]))", + "hide": false, + "instant": false, + "legendFormat": "__auto", + "range": true, + "refId": "C" + }, + { + "datasource": { + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "editorMode": "code", + "expr": "sum by (callName) (rate(psql_getAccountTotalSent_sum[$__rate_interval])/rate(psql_getAccountTotalSent_count[$__rate_interval]))", + "hide": false, + "instant": false, + "legendFormat": "__auto", + "range": true, + "refId": "D" + }, + { + "datasource": { + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "editorMode": "code", + "expr": "sum by (callName) (rate(tb_getAccountTotalSent_sum[$__rate_interval])/rate(tb_getAccountTotalSent_count[$__rate_interval]))", + "hide": false, + "instant": false, + "legendFormat": "__auto", + "range": true, + "refId": "E" + }, + { + "datasource": { + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "editorMode": "code", + "expr": "sum by (callName) (rate(handleCompleted_sum[$__rate_interval])/rate(handleCompleted_count[$__rate_interval]))", + "hide": false, + "instant": false, + "legendFormat": "__auto", + "range": true, + "refId": "F" + }, + { + "datasource": { + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "editorMode": "code", + "expr": "sum by (callName) (rate(sendWebhookEvent_sum[$__rate_interval])/rate(sendWebhookEvent_count[$__rate_interval]))", + "hide": false, + "instant": false, + "legendFormat": "__auto", + "range": true, + "refId": "G" + }, + { + "datasource": { + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "editorMode": "code", + "expr": "sum by (callName) (rate(handleFailed_sum[$__rate_interval])/rate(handleFailed_count[$__rate_interval]))", + "hide": false, + "instant": false, + "legendFormat": "__auto", + "range": true, + "refId": "H" + }, + { + "datasource": { + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "editorMode": "code", + "expr": "sum by (callName) (rate(processPendingPayment_sum[$__rate_interval])/rate(processPendingPayment_count[$__rate_interval]))", + "hide": false, + "instant": false, + "legendFormat": "__auto", + "range": true, + "refId": "I" + } + ], + "title": "Outgoing Payment Worker", + "type": "timeseries" + }, + { + "datasource": { + "name": "${PrometheusDS}", + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "description": "", + "fieldConfig": { + "defaults": { + "color": { + "mode": "continuous-GrYlRd" + }, + "fieldMinMax": false, + "mappings": [], + "thresholds": { + "mode": "absolute", + "steps": [ + { + "color": "green", + "value": null + }, + { + "color": "red", + "value": 80 + } + ] + }, + "unit": "s" + }, + "overrides": [] + }, + "gridPos": { + "h": 12, + "w": 12, + "x": 0, + "y": 7 + }, + "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.2.0", + "targets": [ + { + "datasource": { + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "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": { + "name": "${PrometheusDS}", + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "fieldConfig": { + "defaults": { + "color": { + "mode": "palette-classic" + }, + "custom": { + "axisBorderShow": false, + "axisCenteredZero": false, + "axisColorMode": "text", + "axisLabel": "", + "axisPlacement": "auto", + "barAlignment": 0, + "barWidthFactor": 0.6, + "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 + } + ] + }, + "unit": "ms" + }, + "overrides": [] + }, + "gridPos": { + "h": 6, + "w": 12, + "x": 12, + "y": 7 + }, + "id": 9, + "options": { + "legend": { + "calcs": ["p95"], + "displayMode": "table", + "placement": "right", + "showLegend": true + }, + "tooltip": { + "mode": "single", + "sort": "none" + } + }, + "targets": [ + { + "datasource": { + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "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": "${PrometheusDS}" + }, + "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": "${PrometheusDS}" + }, + "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": "${PrometheusDS}" + }, + "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": "${PrometheusDS}" + }, + "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": "${PrometheusDS}" + }, + "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": { + "name": "${PrometheusDS}", + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "fieldConfig": { + "defaults": { + "color": { + "mode": "palette-classic" + }, + "custom": { + "axisBorderShow": false, + "axisCenteredZero": false, + "axisColorMode": "text", + "axisLabel": "", + "axisPlacement": "auto", + "barAlignment": 0, + "barWidthFactor": 0.6, + "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 + } + ] + }, + "unit": "ms" + }, + "overrides": [] + }, + "gridPos": { + "h": 6, + "w": 12, + "x": 12, + "y": 13 + }, + "id": 11, + "options": { + "legend": { + "calcs": ["p95"], + "displayMode": "table", + "placement": "right", + "showLegend": true + }, + "tooltip": { + "mode": "single", + "sort": "none" + } + }, + "targets": [ + { + "datasource": { + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "editorMode": "code", + "expr": "sum by (callName) (rate(psql_getAccountBalances_sum[$__rate_interval])/rate(psql_getAccountBalances_count[$__rate_interval]))", + "instant": false, + "legendFormat": "__auto", + "range": true, + "refId": "A" + } + ], + "title": "PSQL Get Account Balance", + "type": "timeseries" + }, + { + "datasource": { + "name": "${PrometheusDS}", + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "description": "", + "fieldConfig": { + "defaults": { + "color": { + "mode": "palette-classic" + }, + "custom": { + "axisBorderShow": false, + "axisCenteredZero": false, + "axisColorMode": "text", + "axisLabel": "", + "axisPlacement": "auto", + "barAlignment": 0, + "barWidthFactor": 0.6, + "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": 7, + "w": 12, + "x": 0, + "y": 19 + }, + "id": 14, + "options": { + "legend": { + "calcs": [], + "displayMode": "list", + "placement": "bottom", + "showLegend": true + }, + "tooltip": { + "mode": "single", + "sort": "none" + } + }, + "targets": [ + { + "datasource": { + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "editorMode": "code", + "expr": "rate(outgoing_payment_service_create_time_ms_sum[$__rate_interval])/rate(outgoing_payment_service_create_time_ms_count[$__rate_interval])", + "instant": false, + "legendFormat": "{{description}}", + "range": true, + "refId": "A" + }, + { + "datasource": { + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "editorMode": "code", + "expr": "rate(outgoing_payment_service_create_quote_time_ms_sum[$__rate_interval])/rate(outgoing_payment_service_create_quote_time_ms_count[$__rate_interval])", + "hide": false, + "instant": false, + "legendFormat": "{{description}}", + "range": true, + "refId": "B" + }, + { + "datasource": { + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "editorMode": "code", + "expr": "rate(outgoing_payment_service_getwalletaddress_time_ms_sum[$__rate_interval])/rate(outgoing_payment_service_getwalletaddress_time_ms_count[$__rate_interval])", + "hide": false, + "instant": false, + "legendFormat": "{{description}}", + "range": true, + "refId": "E" + }, + { + "datasource": { + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "editorMode": "code", + "expr": "rate(outgoing_payment_service_insertgrant_time_ms_sum[$__rate_interval])/rate(outgoing_payment_service_insertgrant_time_ms_count[$__rate_interval])", + "hide": false, + "instant": false, + "legendFormat": "{{description}}", + "range": true, + "refId": "D" + }, + { + "datasource": { + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "editorMode": "code", + "expr": "rate(outgoing_payment_service_insertpayment_time_ms_sum[$__rate_interval])/rate(outgoing_payment_service_insertpayment_time_ms_count[$__rate_interval])", + "hide": false, + "instant": false, + "legendFormat": "{{description}}", + "range": true, + "refId": "F" + }, + { + "datasource": { + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "editorMode": "code", + "expr": "rate(outgoing_payment_service_getreceiver_time_ms_sum[$__rate_interval])/rate(outgoing_payment_service_getreceiver_time_ms_count[$__rate_interval])", + "hide": false, + "instant": false, + "legendFormat": "{{description}}", + "range": true, + "refId": "H" + }, + { + "datasource": { + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "editorMode": "code", + "expr": "rate(outgoing_payment_service_getpeer_time_ms_sum[$__rate_interval])/rate(outgoing_payment_service_getpeer_time_ms_count[$__rate_interval])", + "hide": false, + "instant": false, + "legendFormat": "{{description}}", + "range": true, + "refId": "G" + }, + { + "datasource": { + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "editorMode": "code", + "expr": "rate(outgoing_payment_service_patchpeer_time_ms_sum[$__rate_interval])/rate(outgoing_payment_service_patchpeer_time_ms_count[$__rate_interval])", + "hide": false, + "instant": false, + "legendFormat": "{{description}}", + "range": true, + "refId": "I" + }, + { + "datasource": { + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "editorMode": "code", + "expr": "rate(outgoing_payment_service_webhook_event_time_ms_sum[$__rate_interval])/rate(outgoing_payment_service_webhook_event_time_ms_count[$__rate_interval])", + "hide": false, + "instant": false, + "legendFormat": "{{description}}", + "range": true, + "refId": "C" + } + ], + "title": "Outgoing Payment Service Create Time (ms)", + "type": "timeseries" + }, + { + "datasource": { + "name": "${PrometheusDS}", + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "fieldConfig": { + "defaults": { + "color": { + "mode": "palette-classic" + }, + "custom": { + "axisBorderShow": false, + "axisCenteredZero": false, + "axisColorMode": "text", + "axisLabel": "", + "axisPlacement": "auto", + "barAlignment": 0, + "barWidthFactor": 0.6, + "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": 6, + "w": 12, + "x": 12, + "y": 19 + }, + "id": 13, + "options": { + "legend": { + "calcs": ["p95"], + "displayMode": "table", + "placement": "right", + "showLegend": true + }, + "tooltip": { + "mode": "single", + "sort": "none" + } + }, + "targets": [ + { + "datasource": { + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "editorMode": "code", + "expr": "sum by (callName) (rate(createLiquidityAccount_sum[$__rate_interval])/rate(createLiquidityAccount_count[$__rate_interval]))", + "instant": false, + "legendFormat": "__auto", + "range": true, + "refId": "A" + } + ], + "title": "Ilp Connector > Balance Middleware > createLiquidityAccount", + "type": "timeseries" + }, + { + "datasource": { + "name": "${TempoDS}", + "type": "tempo", + "uid": "${TempoDS}" + }, + "fieldConfig": { + "defaults": { + "color": { + "mode": "thresholds" + }, + "custom": { + "align": "auto", + "cellOptions": { + "type": "auto" + }, + "inspect": false + }, + "mappings": [], + "thresholds": { + "mode": "absolute", + "steps": [ + { + "color": "green", + "value": null + }, + { + "color": "red", + "value": 80 + } + ] + } + }, + "overrides": [] + }, + "gridPos": { + "h": 8, + "w": 12, + "x": 12, + "y": 25 + }, + "id": 4, + "options": { + "cellHeight": "sm", + "footer": { + "countRows": false, + "fields": "", + "reducer": ["sum"], + "show": false + }, + "showHeader": true, + "sortBy": [ + { + "desc": true, + "displayName": "Duration" + } + ] + }, + "pluginVersion": "11.2.0", + "targets": [ + { + "datasource": { + "type": "tempo", + "uid": "${TempoDS}" + }, + "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": "Traces > 100ms", + "type": "table" + }, + { + "datasource": { + "default": false, + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "fieldConfig": { + "defaults": { + "color": { + "mode": "palette-classic" + }, + "custom": { + "axisBorderShow": false, + "axisCenteredZero": false, + "axisColorMode": "text", + "axisLabel": "", + "axisPlacement": "auto", + "barAlignment": 0, + "barWidthFactor": 0.6, + "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": 6, + "w": 12, + "x": 0, + "y": 26 + }, + "id": 16, + "options": { + "legend": { + "calcs": [], + "displayMode": "list", + "placement": "bottom", + "showLegend": true + }, + "tooltip": { + "mode": "single", + "sort": "none" + } + }, + "targets": [ + { + "datasource": { + "type": "prometheus", + "uid": "PBFA97CFB590B2093" + }, + "editorMode": "code", + "expr": "rate(depositOutgoingPaymentLiquidity_sum[$__rate_interval])/rate(depositOutgoingPaymentLiquidity_count[$__rate_interval])", + "instant": false, + "legendFormat": "{{callName}}", + "range": true, + "refId": "A" + }, + { + "datasource": { + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "editorMode": "code", + "expr": "rate(fundPayment_sum[$__rate_interval])/rate(fundPayment_count[$__rate_interval])", + "hide": false, + "instant": false, + "legendFormat": "{{callName}}", + "range": true, + "refId": "B" + } + ], + "title": "Deposit Outgoing Payment Liquidity ", + "type": "timeseries" + }, + { + "datasource": { + "name": "${PrometheusDS}", + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "fieldConfig": { + "defaults": { + "color": { + "mode": "palette-classic" + }, + "custom": { + "axisBorderShow": false, + "axisCenteredZero": false, + "axisColorMode": "text", + "axisLabel": "", + "axisPlacement": "auto", + "barAlignment": 0, + "barWidthFactor": 0.6, + "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 + } + ] + }, + "unit": "ms" + }, + "overrides": [] + }, + "gridPos": { + "h": 6, + "w": 12, + "x": 0, + "y": 32 + }, + "id": 7, + "options": { + "legend": { + "calcs": ["p95"], + "displayMode": "table", + "placement": "right", + "showLegend": true + }, + "tooltip": { + "mode": "single", + "sort": "none" + } + }, + "targets": [ + { + "datasource": { + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "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": "${PrometheusDS}" + }, + "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": "${PrometheusDS}" + }, + "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": "${PrometheusDS}" + }, + "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": "${PrometheusDS}" + }, + "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": "${PrometheusDS}" + }, + "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": { + "name": "${PrometheusDS}", + "type": "prometheus", + "uid": "${PrometheusDS}" }, "fieldConfig": { "defaults": { @@ -37,6 +1320,7 @@ "axisLabel": "", "axisPlacement": "auto", "barAlignment": 0, + "barWidthFactor": 0.6, "drawStyle": "line", "fillOpacity": 0, "gradientMode": "none", @@ -75,23 +1359,23 @@ "value": 80 } ] - } + }, + "unit": "ms" }, "overrides": [] }, "gridPos": { - "h": 8, + "h": 6, "w": 12, "x": 0, - "y": 0 + "y": 38 }, - "id": 2, - "interval": "15s", + "id": 12, "options": { "legend": { - "calcs": [], - "displayMode": "list", - "placement": "bottom", + "calcs": ["p95"], + "displayMode": "table", + "placement": "right", "showLegend": true }, "tooltip": { @@ -103,128 +1387,50 @@ { "datasource": { "type": "prometheus", - "uid": "PBFA97CFB590B2093" + "uid": "${PrometheusDS}" }, "editorMode": "code", - "expr": "(increase(packet_amount_fulfill_total[30s]) * 0.5 * 0.0001)", - "hide": false, + "expr": "sum by (callName) (rate(connector_middleware_sum[$__rate_interval])/rate(connector_middleware_count[$__rate_interval]))", "instant": false, - "interval": "", - "legendFormat": "__auto", + "legendFormat": "{{caller}}", "range": true, "refId": "A" - } - ], - "title": "Transaction Amount", - "type": "timeseries" - }, - { - "datasource": { - "type": "tempo", - "uid": "P214B5B846CF3925F" - }, - "fieldConfig": { - "defaults": { - "color": { - "mode": "thresholds" - }, - "custom": { - "align": "auto", - "cellOptions": { - "type": "auto" - }, - "inspect": false - }, - "mappings": [], - "thresholds": { - "mode": "absolute", - "steps": [ - { - "color": "green", - "value": null - }, - { - "color": "red", - "value": 80 - } - ] - } }, - "overrides": [] - }, - "gridPos": { - "h": 8, - "w": 12, - "x": 12, - "y": 0 - }, - "id": 4, - "options": { - "cellHeight": "sm", - "footer": { - "countRows": false, - "fields": "", - "reducer": ["sum"], - "show": false + { + "datasource": { + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "editorMode": "code", + "expr": "sum by (callName) (rate(connector_middleware_stack_sum[$__rate_interval])/rate(connector_middleware_stack_count[$__rate_interval]))", + "hide": false, + "instant": false, + "legendFormat": "__auto", + "range": true, + "refId": "B" }, - "showHeader": true, - "sortBy": [ - { - "desc": true, - "displayName": "Duration" - } - ] - }, - "pluginVersion": "11.1.3", - "targets": [ { "datasource": { - "type": "tempo", - "uid": "P214B5B846CF3925F" + "type": "prometheus", + "uid": "${PrometheusDS}" }, - "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": "sum by (callName) (rate(balanceMiddleware_sum[$__rate_interval])/rate(balanceMiddleware_count[$__rate_interval]))", + "hide": false, + "instant": false, + "legendFormat": "__auto", + "range": true, + "refId": "C" } ], - "title": "Traces > 100ms", - "type": "table" + "title": "ILP Connector", + "type": "timeseries" }, { "datasource": { + "name": "${PrometheusDS}", "type": "prometheus", - "uid": "PBFA97CFB590B2093" + "uid": "${PrometheusDS}" }, "fieldConfig": { "defaults": { @@ -238,6 +1444,7 @@ "axisLabel": "", "axisPlacement": "auto", "barAlignment": 0, + "barWidthFactor": 0.6, "drawStyle": "line", "fillOpacity": 0, "gradientMode": "none", @@ -284,9 +1491,9 @@ "h": 8, "w": 12, "x": 0, - "y": 8 + "y": 44 }, - "id": 1, + "id": 2, "interval": "15s", "options": { "legend": { @@ -304,10 +1511,10 @@ { "datasource": { "type": "prometheus", - "uid": "PBFA97CFB590B2093" + "uid": "${PrometheusDS}" }, "editorMode": "code", - "expr": "sum by (source) (round(increase(transactions_total[30s]) * 0.5))", + "expr": "(increase(packet_amount_fulfill_total[30s]) * 0.5 * 0.0001)", "hide": false, "instant": false, "interval": "", @@ -316,21 +1523,53 @@ "refId": "A" } ], - "title": "Transaction Count", + "title": "Transaction Amount", "type": "timeseries" }, { "datasource": { + "name": "${PrometheusDS}", "type": "prometheus", - "uid": "PBFA97CFB590B2093" + "uid": "${PrometheusDS}" }, - "description": "", "fieldConfig": { "defaults": { "color": { - "mode": "continuous-GrYlRd" + "mode": "palette-classic" + }, + "custom": { + "axisBorderShow": false, + "axisCenteredZero": false, + "axisColorMode": "text", + "axisLabel": "", + "axisPlacement": "auto", + "barAlignment": 0, + "barWidthFactor": 0.6, + "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" + } }, - "fieldMinMax": false, "mappings": [], "thresholds": { "mode": "absolute", @@ -344,56 +1583,54 @@ "value": 80 } ] - }, - "unit": "s" + } }, "overrides": [] }, "gridPos": { - "h": 12, + "h": 8, "w": 12, - "x": 12, - "y": 8 + "x": 0, + "y": 52 }, - "id": 6, + "id": 1, + "interval": "15s", "options": { - "displayMode": "gradient", - "maxVizHeight": 300, - "minVizHeight": 16, - "minVizWidth": 8, - "namePlacement": "auto", - "orientation": "horizontal", - "reduceOptions": { - "calcs": ["lastNotNull"], - "fields": "", - "values": false + "legend": { + "calcs": [], + "displayMode": "list", + "placement": "bottom", + "showLegend": true }, - "showUnfilled": true, - "sizing": "auto", - "valueMode": "color" + "tooltip": { + "mode": "single", + "sort": "none" + } }, - "pluginVersion": "11.1.3", "targets": [ { "datasource": { "type": "prometheus", - "uid": "PBFA97CFB590B2093" + "uid": "${PrometheusDS}" }, "editorMode": "code", - "expr": "histogram_quantile(0.95, sum(rate(traces_spanmetrics_latency_bucket{span_name=~\"^(mutation|query).*\"}[$__rate_interval])) by (le, span_name))", + "expr": "sum by (source) (round(increase(transactions_total[30s]) * 0.5))", + "hide": false, "instant": false, + "interval": "", "legendFormat": "__auto", "range": true, "refId": "A" } ], - "title": "Graphql Resolver Duration (95th Percentile)", - "type": "bargauge" + "title": "Transaction Count", + "type": "timeseries" }, { "datasource": { + "name": "${PrometheusDS}", "type": "prometheus", - "uid": "PBFA97CFB590B2093" + "uid": "${PrometheusDS}" }, "description": "Maximum time it takes to complete the fastest 25%/50%/75% of ILP payments.", "fieldConfig": { @@ -423,7 +1660,7 @@ "h": 5, "w": 12, "x": 0, - "y": 16 + "y": 60 }, "id": 3, "options": { @@ -441,12 +1678,12 @@ "textMode": "auto", "wideLayout": true }, - "pluginVersion": "11.1.3", + "pluginVersion": "11.2.0", "targets": [ { "datasource": { "type": "prometheus", - "uid": "PBFA97CFB590B2093" + "uid": "${PrometheusDS}" }, "editorMode": "code", "expr": "histogram_quantile(0.25, ilp_pay_time_ms_bucket)", @@ -458,7 +1695,7 @@ { "datasource": { "type": "prometheus", - "uid": "PBFA97CFB590B2093" + "uid": "${PrometheusDS}" }, "editorMode": "code", "expr": "histogram_quantile(0.50, ilp_pay_time_ms_bucket)", @@ -471,7 +1708,7 @@ { "datasource": { "type": "prometheus", - "uid": "PBFA97CFB590B2093" + "uid": "${PrometheusDS}" }, "editorMode": "code", "expr": "histogram_quantile(0.75, ilp_pay_time_ms_bucket)", @@ -487,8 +1724,9 @@ }, { "datasource": { + "name": "${PrometheusDS}", "type": "prometheus", - "uid": "PBFA97CFB590B2093" + "uid": "${PrometheusDS}" }, "description": "Maximum time it takes to complete the fastest 25%/50%/75% of ILP quotes.", "fieldConfig": { @@ -518,7 +1756,7 @@ "h": 5, "w": 12, "x": 0, - "y": 21 + "y": 65 }, "id": 5, "options": { @@ -536,12 +1774,12 @@ "textMode": "auto", "wideLayout": true }, - "pluginVersion": "11.1.3", + "pluginVersion": "11.2.0", "targets": [ { "datasource": { "type": "prometheus", - "uid": "PBFA97CFB590B2093" + "uid": "${PrometheusDS}" }, "editorMode": "code", "expr": "histogram_quantile(0.25, ilp_rate_probe_time_ms_bucket)", @@ -553,7 +1791,7 @@ { "datasource": { "type": "prometheus", - "uid": "PBFA97CFB590B2093" + "uid": "${PrometheusDS}" }, "editorMode": "code", "expr": "histogram_quantile(0.50, ilp_rate_probe_time_ms_bucket)", @@ -566,7 +1804,7 @@ { "datasource": { "type": "prometheus", - "uid": "PBFA97CFB590B2093" + "uid": "${PrometheusDS}" }, "editorMode": "code", "expr": "histogram_quantile(0.75, ilp_rate_probe_time_ms_bucket)", @@ -585,10 +1823,48 @@ "schemaVersion": 39, "tags": [], "templating": { - "list": [] + "list": [ + { + "current": { + "selected": false, + "text": "Prometheus", + "value": "PBFA97CFB590B2093" + }, + "description": "The Prometheus data-source.", + "hide": 0, + "includeAll": false, + "multi": false, + "name": "PrometheusDS", + "options": [], + "query": "prometheus", + "queryValue": "", + "refresh": 1, + "regex": "", + "skipUrlSync": false, + "type": "datasource" + }, + { + "current": { + "selected": false, + "text": "Tempo", + "value": "P214B5B846CF3925F" + }, + "description": "The Tempo datasource uid.", + "hide": 0, + "includeAll": false, + "multi": false, + "name": "TempoDS", + "options": [], + "query": "tempo", + "refresh": 1, + "regex": "", + "skipUrlSync": false, + "type": "datasource" + } + ] }, "time": { - "from": "now-15m", + "from": "now-5m", "to": "now" }, "timepicker": { From 46e00aa285aed7f7f55e8913a48e8cf4a4939571 Mon Sep 17 00:00:00 2001 From: Blair Currey <12960453+BlairCurrey@users.noreply.github.com> Date: Fri, 20 Sep 2024 12:39:28 -0400 Subject: [PATCH 06/31] feat(backend): add telemetry service dep to services --- packages/backend/src/accounting/psql/service.ts | 2 ++ .../backend/src/accounting/tigerbeetle/service.ts | 2 ++ packages/backend/src/index.ts | 15 +++++++++++---- .../backend/src/open_payments/quote/service.ts | 2 ++ .../backend/src/open_payments/receiver/service.ts | 2 ++ 5 files changed, 19 insertions(+), 4 deletions(-) diff --git a/packages/backend/src/accounting/psql/service.ts b/packages/backend/src/accounting/psql/service.ts index e427cd26b5..4607238260 100644 --- a/packages/backend/src/accounting/psql/service.ts +++ b/packages/backend/src/accounting/psql/service.ts @@ -34,9 +34,11 @@ import { getAccountTransfers } from './ledger-transfer' import { LedgerTransfer, LedgerTransferType } from './ledger-transfer/model' +import { TelemetryService } from '../../telemetry/service' export interface ServiceDependencies extends BaseService { knex: TransactionOrKnex + telemetry: TelemetryService withdrawalThrottleDelay?: number } diff --git a/packages/backend/src/accounting/tigerbeetle/service.ts b/packages/backend/src/accounting/tigerbeetle/service.ts index 79b9105be1..f983aa3f9c 100644 --- a/packages/backend/src/accounting/tigerbeetle/service.ts +++ b/packages/backend/src/accounting/tigerbeetle/service.ts @@ -31,6 +31,7 @@ import { getAccountTransfers } from './transfers' import { toTigerBeetleId } from './utils' +import { TelemetryService } from '../../telemetry/service' export enum TigerBeetleAccountCode { LIQUIDITY_WEB_MONETIZATION = 1, @@ -68,6 +69,7 @@ export const convertToTigerBeetleTransferCode: { export interface ServiceDependencies extends BaseService { tigerBeetle: Client + telemetry: TelemetryService withdrawalThrottleDelay?: number } diff --git a/packages/backend/src/index.ts b/packages/backend/src/index.ts index fd60a245e5..94a4154a37 100644 --- a/packages/backend/src/index.ts +++ b/packages/backend/src/index.ts @@ -208,6 +208,7 @@ export function initIocContainer( const logger = await deps.use('logger') const knex = await deps.use('knex') const config = await deps.use('config') + const telemetry = await deps.use('telemetry') if (config.useTigerBeetle) { container.singleton('tigerBeetle', async (deps) => { @@ -224,14 +225,16 @@ export function initIocContainer( logger, knex, tigerBeetle, - withdrawalThrottleDelay: config.withdrawalThrottleDelay + withdrawalThrottleDelay: config.withdrawalThrottleDelay, + telemetry }) } return createPsqlAccountingService({ logger, knex, - withdrawalThrottleDelay: config.withdrawalThrottleDelay + withdrawalThrottleDelay: config.withdrawalThrottleDelay, + telemetry }) }) container.singleton('peerService', async (deps) => { @@ -339,7 +342,8 @@ export function initIocContainer( walletAddressService: await deps.use('walletAddressService'), remoteIncomingPaymentService: await deps.use( 'remoteIncomingPaymentService' - ) + ), + telemetry: await deps.use('telemetry') }) }) @@ -443,7 +447,10 @@ 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: await deps.use('telemetry') }) }) diff --git a/packages/backend/src/open_payments/quote/service.ts b/packages/backend/src/open_payments/quote/service.ts index 04d9df7f87..f802f1c6fd 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( diff --git a/packages/backend/src/open_payments/receiver/service.ts b/packages/backend/src/open_payments/receiver/service.ts index adb022e78f..38636b80f1 100644 --- a/packages/backend/src/open_payments/receiver/service.ts +++ b/packages/backend/src/open_payments/receiver/service.ts @@ -14,6 +14,7 @@ import { errorToMessage as receiverErrorToMessage } from './errors' import { isRemoteIncomingPaymentError } from '../payment/incoming_remote/errors' +import { TelemetryService } from '../../telemetry/service' interface CreateReceiverArgs { walletAddressUrl: string @@ -33,6 +34,7 @@ export interface ServiceDependencies extends BaseService { incomingPaymentService: IncomingPaymentService walletAddressService: WalletAddressService remoteIncomingPaymentService: RemoteIncomingPaymentService + telemetry: TelemetryService } const INCOMING_PAYMENT_URL_REGEX = From bbddc36d3a5bca0f40cda3873a19f84716ae216f Mon Sep 17 00:00:00 2001 From: Blair Currey <12960453+BlairCurrey@users.noreply.github.com> Date: Fri, 20 Sep 2024 12:50:16 -0400 Subject: [PATCH 07/31] feat(backend): add accounting service timer metrics --- packages/backend/src/accounting/psql/balance.ts | 5 +++++ packages/backend/src/accounting/psql/service.ts | 10 +++++++++- packages/backend/src/accounting/tigerbeetle/service.ts | 5 +++++ 3 files changed, 19 insertions(+), 1 deletion(-) diff --git a/packages/backend/src/accounting/psql/balance.ts b/packages/backend/src/accounting/psql/balance.ts index 6a58b359bf..e130f136ff 100644 --- a/packages/backend/src/accounting/psql/balance.ts +++ b/packages/backend/src/accounting/psql/balance.ts @@ -14,6 +14,9 @@ export async function getAccountBalances( account: LedgerAccount, trx?: TransactionOrKnex ): Promise { + const stopTimer = deps.telemetry.startTimer('psql_getAccountBalances', { + callName: 'psql_getAccountBalances' + }) try { const queryResult = await (trx ?? deps.knex).raw( ` @@ -54,5 +57,7 @@ export async function getAccountBalances( ) throw err + } finally { + stopTimer() } } diff --git a/packages/backend/src/accounting/psql/service.ts b/packages/backend/src/accounting/psql/service.ts index 4607238260..f0f15023b7 100644 --- a/packages/backend/src/accounting/psql/service.ts +++ b/packages/backend/src/accounting/psql/service.ts @@ -147,13 +147,21 @@ export async function getAccountTotalSent( deps: ServiceDependencies, accountRef: string ): Promise { + const stopTimer = deps.telemetry.startTimer('psql_getAccountTotalSent', { + callName: 'psql_getAccountTotalSent' + }) const account = await getLiquidityAccount(deps, accountRef) if (!account) { + stopTimer() return } - return (await getAccountBalances(deps, account)).debitsPosted + const totalsSent = (await getAccountBalances(deps, account)).debitsPosted + + stopTimer() + + return totalsSent } export async function getAccountsTotalSent( diff --git a/packages/backend/src/accounting/tigerbeetle/service.ts b/packages/backend/src/accounting/tigerbeetle/service.ts index f983aa3f9c..1ca4539518 100644 --- a/packages/backend/src/accounting/tigerbeetle/service.ts +++ b/packages/backend/src/accounting/tigerbeetle/service.ts @@ -220,10 +220,15 @@ export async function getAccountTotalSent( deps: ServiceDependencies, id: string ): Promise { + const stopTimer = deps.telemetry.startTimer('tb_getAccountTotalSent', { + callName: 'tb_getAccountTotalSent' + }) const account = (await getAccounts(deps, [id]))[0] if (account) { + stopTimer() return account.debits_posted } + stopTimer() } export async function getAccountsTotalSent( From ff3fd70e48655876b61e9d83c2b6ed364053cc12 Mon Sep 17 00:00:00 2001 From: Blair Currey <12960453+BlairCurrey@users.noreply.github.com> Date: Fri, 20 Sep 2024 13:06:31 -0400 Subject: [PATCH 08/31] feat(backend): add service timer metrics - liquidity resolver, op lifecycle, op service create --- .../src/graphql/resolvers/liquidity.ts | 8 ++ .../payment/outgoing/lifecycle.ts | 24 +++-- .../open_payments/payment/outgoing/service.ts | 89 ++++++++++++++++++- 3 files changed, 114 insertions(+), 7 deletions(-) diff --git a/packages/backend/src/graphql/resolvers/liquidity.ts b/packages/backend/src/graphql/resolvers/liquidity.ts index ba434e31ea..ad76f0493e 100644 --- a/packages/backend/src/graphql/resolvers/liquidity.ts +++ b/packages/backend/src/graphql/resolvers/liquidity.ts @@ -440,6 +440,10 @@ export const depositOutgoingPaymentLiquidity: MutationResolvers[' args, ctx ): Promise => { + const telemetry = await ctx.container.use('telemetry') + const stopTimer = telemetry.startTimer('depositOutgoingPaymentLiquidity', { + callName: 'depositOutgoingPaymentLiquidity' + }) const { outgoingPaymentId } = args.input const webhookService = await ctx.container.use('webhookService') const event = await webhookService.getLatestByResourceId({ @@ -447,6 +451,7 @@ export const depositOutgoingPaymentLiquidity: MutationResolvers[' types: [OutgoingPaymentDepositType.PaymentCreated] }) if (!event || !isOutgoingPaymentEvent(event)) { + stopTimer() throw new GraphQLError(errorToMessage[LiquidityError.InvalidId], { extensions: { code: errorToCode[LiquidityError.InvalidId] @@ -455,6 +460,7 @@ export const depositOutgoingPaymentLiquidity: MutationResolvers[' } if (!event.data.debitAmount) { + stopTimer() throw new Error('No debit amount') } const outgoingPaymentService = await ctx.container.use( @@ -466,12 +472,14 @@ export const depositOutgoingPaymentLiquidity: MutationResolvers[' transferId: event.id }) if (isFundingError(paymentOrErr)) { + stopTimer() throw new GraphQLError(fundingErrorToMessage[paymentOrErr], { extensions: { code: fundingErrorToCode[paymentOrErr] } }) } + stopTimer() return { success: true } diff --git a/packages/backend/src/open_payments/payment/outgoing/lifecycle.ts b/packages/backend/src/open_payments/payment/outgoing/lifecycle.ts index 1b402db2d3..9a5ac22046 100644 --- a/packages/backend/src/open_payments/payment/outgoing/lifecycle.ts +++ b/packages/backend/src/open_payments/payment/outgoing/lifecycle.ts @@ -76,23 +76,22 @@ export async function handleSending( throw LifecycleError.BadState } - const payStartTime = Date.now() + const stopTimer = deps.telemetry.startTimer('ilp_pay_time_ms', { + description: 'Time to complete an ILP payment', + callName: 'paymentMethodHandlerService.pay (ILP)' + }) await deps.paymentMethodHandlerService.pay('ILP', { receiver, outgoingPayment: payment, finalDebitAmount: maxDebitAmount, finalReceiveAmount: maxReceiveAmount }) - const payEndTime = Date.now() + stopTimer() - const payDuration = payEndTime - payStartTime await Promise.all([ deps.telemetry.incrementCounter('transactions_total', 1, { description: 'Count of funded transactions' }), - deps.telemetry.recordHistogram('ilp_pay_time_ms', payDuration, { - description: 'Time to complete an ILP payment' - }), deps.telemetry.incrementCounterWithTransactionAmountDifference( 'transaction_fee_amounts', payment.sentAmount, @@ -142,17 +141,24 @@ export async function handleFailed( payment: OutgoingPayment, error: string ): Promise { + const stopTimer = deps.telemetry.startTimer('handleFailed', { + callName: 'handleFailed' + }) await payment.$query(deps.knex).patch({ state: OutgoingPaymentState.Failed, error }) await sendWebhookEvent(deps, payment, OutgoingPaymentEventType.PaymentFailed) + stopTimer() } async function handleCompleted( deps: ServiceDependencies, payment: OutgoingPayment ): Promise { + const stopTimer = deps.telemetry?.startTimer('handleCompleted', { + callName: 'handleCompleted' + }) await payment.$query(deps.knex).patch({ state: OutgoingPaymentState.Completed }) @@ -162,6 +168,7 @@ async function handleCompleted( payment, OutgoingPaymentEventType.PaymentCompleted ) + stopTimer() } export async function sendWebhookEvent( @@ -170,6 +177,9 @@ export async function sendWebhookEvent( type: OutgoingPaymentEventType, trx?: TransactionOrKnex ): Promise { + const stopTimer = deps.telemetry?.startTimer('sendWebhookEvent', { + callName: 'outgoingPaymentLifecycle_sendwebhookEvent' + }) // TigerBeetle accounts are only created as the OutgoingPayment is funded. // So default the amountSent and balance to 0 for outgoing payments still in the funding state const amountSent = @@ -182,6 +192,7 @@ export async function sendWebhookEvent( : await deps.accountingService.getBalance(payment.id) if (amountSent === undefined || balance === undefined) { + stopTimer() throw LifecycleError.MissingBalance } @@ -199,6 +210,7 @@ export async function sendWebhookEvent( data: payment.toData({ amountSent, balance }), withdrawal }) + stopTimer() } function validateAssets( diff --git a/packages/backend/src/open_payments/payment/outgoing/service.ts b/packages/backend/src/open_payments/payment/outgoing/service.ts index 336444e518..0fe3e3f498 100644 --- a/packages/backend/src/open_payments/payment/outgoing/service.ts +++ b/packages/backend/src/open_payments/payment/outgoing/service.ts @@ -215,10 +215,22 @@ async function createOutgoingPayment( deps: ServiceDependencies, options: CreateOutgoingPaymentOptions ): Promise { + const stopTimerOP = deps.telemetry.startTimer( + 'outgoing_payment_service_create_time_ms', + { + description: 'Time to create an outgoing payment' + } + ) const { walletAddressId } = options let quoteId: string if (isCreateFromIncomingPayment(options)) { + const stopTimerQuote = deps.telemetry.startTimer( + 'outgoing_payment_service_create_quote_time_ms', + { + description: 'Time to create a quote in outgoing payment' + } + ) const { debitAmount, incomingPayment } = options const quoteOrError = await deps.quoteService.create({ receiver: incomingPayment, @@ -226,6 +238,7 @@ async function createOutgoingPayment( method: 'ilp', walletAddressId }) + stopTimerQuote() if (isQuoteError(quoteOrError)) { return quoteErrorToOutgoingPaymentError[quoteOrError] @@ -238,7 +251,14 @@ async function createOutgoingPayment( const grantId = options.grant?.id try { return await OutgoingPayment.transaction(deps.knex, async (trx) => { + const stopTimerWA = deps.telemetry.startTimer( + 'outgoing_payment_service_getwalletaddress_time_ms', + { + description: 'Time to get wallet address in outgoing payment' + } + ) const walletAddress = await deps.walletAddressService.get(walletAddressId) + stopTimerWA() if (!walletAddress) { throw OutgoingPaymentError.UnknownWalletAddress } @@ -247,13 +267,26 @@ async function createOutgoingPayment( } if (grantId) { + const stopTimerGrant = deps.telemetry.startTimer( + 'outgoing_payment_service_insertgrant_time_ms', + { + description: 'Time to insert grant in outgoing payment' + } + ) await OutgoingPaymentGrant.query(trx) .insert({ id: grantId }) .onConflict('id') .ignore() + stopTimerGrant() } + const stopTimerInsertPayment = deps.telemetry.startTimer( + 'outgoing_payment_service_insertpayment_time_ms', + { + description: 'Time to insert payment in outgoing payment' + } + ) const payment = await OutgoingPayment.query(trx) .insertAndFetch({ id: quoteId, @@ -264,6 +297,7 @@ async function createOutgoingPayment( grantId }) .withGraphFetched('[quote.asset, walletAddress]') + stopTimerInsertPayment() if ( payment.walletAddressId !== payment.quote.walletAddressId || @@ -273,6 +307,12 @@ async function createOutgoingPayment( } if (options.grant) { + const stopTimerValidateGrant = deps.telemetry.startTimer( + 'outgoing_payment_service_validate_grant_time_ms', + { + description: 'Time to validate a grant' + } + ) const isValid = await validateGrantAndAddSpentAmountsToPayment( deps, payment, @@ -281,27 +321,72 @@ async function createOutgoingPayment( options.callback, options.grantLockTimeoutMs ) + stopTimerValidateGrant() if (!isValid) { throw OutgoingPaymentError.InsufficientGrant } } + const stopTimerReceiver = deps.telemetry.startTimer( + 'outgoing_payment_service_getreceiver_time_ms', + { + description: 'Time to retrieve receiver in outgoing payment' + } + ) const receiver = await deps.receiverService.get(payment.receiver) + stopTimerReceiver() if (!receiver) { throw OutgoingPaymentError.InvalidQuote } + const stopTimerPeer = deps.telemetry.startTimer( + 'outgoing_payment_service_getpeer_time_ms', + { + description: 'Time to retrieve peer in outgoing payment' + } + ) const peer = await deps.peerService.getByDestinationAddress( receiver.ilpAddress ) + stopTimerPeer() + + const stopTimerPeerUpdate = deps.telemetry.startTimer( + 'outgoing_payment_service_patchpeer_time_ms', + { + description: 'Time to patch peer in outgoing payment' + } + ) if (peer) await payment.$query(trx).patch({ peerId: peer.id }) + stopTimerPeerUpdate() + const stopTimerWebhook = deps.telemetry.startTimer( + 'outgoing_payment_service_webhook_event_time_ms', + { + description: 'Time to add outgoing payment webhook event' + } + ) await sendWebhookEvent( deps, payment, OutgoingPaymentEventType.PaymentCreated, trx ) + stopTimerWebhook() + + const stopTimerAddAmount = deps.telemetry.startTimer( + 'outgoing_payment_service_add_sent_time_ms', + { + description: 'Time to add sent amount to outgoing payment' + } + ) + + const paymentWithSentAmount = await addSentAmount( + deps, + payment, + BigInt(0) + ) + + stopTimerAddAmount() - return await addSentAmount(deps, payment, BigInt(0)) + return paymentWithSentAmount }) } catch (err) { if (err instanceof UniqueViolationError) { @@ -325,6 +410,8 @@ async function createOutgoingPayment( ) } throw err + } finally { + stopTimerOP() } } From 6357f79ee60ca770bc833f105f74e4f66cc09eea Mon Sep 17 00:00:00 2001 From: Blair Currey <12960453+BlairCurrey@users.noreply.github.com> Date: Fri, 20 Sep 2024 14:12:47 -0400 Subject: [PATCH 09/31] feat(backend): add more performance timer metrics --- .../payment/outgoing/lifecycle.ts | 4 +- .../open_payments/payment/outgoing/service.ts | 11 +- .../open_payments/payment/outgoing/worker.ts | 18 ++- .../src/open_payments/quote/service.ts | 35 +++++- .../src/open_payments/receiver/service.ts | 11 +- .../ilp/connector/core/middleware/balance.ts | 9 ++ .../core/middleware/error-handler.ts | 9 ++ .../core/middleware/stream-address.ts | 6 +- .../src/payment-method/ilp/connector/index.ts | 108 +++++++++++++----- .../backend/src/payment-method/ilp/service.ts | 43 +++++-- packages/backend/src/webhook/service.ts | 57 +++++---- 11 files changed, 240 insertions(+), 71 deletions(-) diff --git a/packages/backend/src/open_payments/payment/outgoing/lifecycle.ts b/packages/backend/src/open_payments/payment/outgoing/lifecycle.ts index 9a5ac22046..367c211c06 100644 --- a/packages/backend/src/open_payments/payment/outgoing/lifecycle.ts +++ b/packages/backend/src/open_payments/payment/outgoing/lifecycle.ts @@ -156,7 +156,7 @@ async function handleCompleted( deps: ServiceDependencies, payment: OutgoingPayment ): Promise { - const stopTimer = deps.telemetry?.startTimer('handleCompleted', { + const stopTimer = deps.telemetry.startTimer('handleCompleted', { callName: 'handleCompleted' }) await payment.$query(deps.knex).patch({ @@ -177,7 +177,7 @@ export async function sendWebhookEvent( type: OutgoingPaymentEventType, trx?: TransactionOrKnex ): Promise { - const stopTimer = deps.telemetry?.startTimer('sendWebhookEvent', { + const stopTimer = deps.telemetry.startTimer('sendWebhookEvent', { callName: 'outgoingPaymentLifecycle_sendwebhookEvent' }) // TigerBeetle accounts are only created as the OutgoingPayment is funded. diff --git a/packages/backend/src/open_payments/payment/outgoing/service.ts b/packages/backend/src/open_payments/payment/outgoing/service.ts index 0fe3e3f498..da368b0feb 100644 --- a/packages/backend/src/open_payments/payment/outgoing/service.ts +++ b/packages/backend/src/open_payments/payment/outgoing/service.ts @@ -587,7 +587,11 @@ async function fundPayment( deps: ServiceDependencies, { id, amount, transferId }: FundOutgoingPaymentOptions ): Promise { - return deps.knex.transaction(async (trx) => { + const stopTimer = deps.telemetry.startTimer('fundPayment', { + callName: 'fundPayment' + }) + + const outgoingPaymentOrError = deps.knex.transaction(async (trx) => { const payment = await OutgoingPayment.query(trx) .findById(id) .forUpdate() @@ -612,6 +616,7 @@ async function fundPayment( if (err instanceof AccountAlreadyExistsError) { // Do nothing. } else { + stopTimer() throw err } } @@ -627,6 +632,10 @@ async function fundPayment( await payment.$query(trx).patch({ state: OutgoingPaymentState.Sending }) return await addSentAmount(deps, payment) }) + + stopTimer() + + return outgoingPaymentOrError } async function getWalletAddressPage( diff --git a/packages/backend/src/open_payments/payment/outgoing/worker.ts b/packages/backend/src/open_payments/payment/outgoing/worker.ts index 0df698f960..20aad9ee82 100644 --- a/packages/backend/src/open_payments/payment/outgoing/worker.ts +++ b/packages/backend/src/open_payments/payment/outgoing/worker.ts @@ -21,8 +21,11 @@ export async function processPendingPayment( return tracer.startActiveSpan( 'outgoingPaymentLifecycle', async (span: Span) => { + const stopTimer = deps_.telemetry.startTimer('processPendingPayment', { + callName: 'processPendingPayment' + }) const paymentId = await deps_.knex.transaction(async (trx) => { - const payment = await getPendingPayment(trx) + const payment = await getPendingPayment(trx, deps_) if (!payment) return await handlePaymentLifecycle( @@ -39,6 +42,7 @@ export async function processPendingPayment( return payment.id }) + stopTimer() span.end() return paymentId } @@ -47,8 +51,12 @@ export async function processPendingPayment( // Fetch (and lock) a payment for work. async function getPendingPayment( - trx: Knex.Transaction + trx: Knex.Transaction, + deps: ServiceDependencies ): Promise { + const stopTimer = deps.telemetry.startTimer('getPendingPayment', { + callName: 'getPendingPayment' + }) const now = new Date(Date.now()).toISOString() const payments = await OutgoingPayment.query(trx) .limit(1) @@ -67,6 +75,7 @@ async function getPendingPayment( ) }) .withGraphFetched('[walletAddress, quote.asset]') + stopTimer() return payments[0] } @@ -79,10 +88,15 @@ async function handlePaymentLifecycle( return } + const stopTimer = deps.telemetry.startTimer('handleSending', { + callName: 'handleSending' + }) try { await lifecycle.handleSending(deps, payment) + stopTimer() } catch (error) { await onLifecycleError(deps, payment, error as Error | PaymentError) + stopTimer() } } diff --git a/packages/backend/src/open_payments/quote/service.ts b/packages/backend/src/open_payments/quote/service.ts index f802f1c6fd..60ece00a59 100644 --- a/packages/backend/src/open_payments/quote/service.ts +++ b/packages/backend/src/open_payments/quote/service.ts @@ -86,16 +86,22 @@ async function createQuote( deps: ServiceDependencies, options: CreateQuoteOptions ): Promise { + const stopTimer = deps.telemetry.startTimer('quote_service_create_time_ms', { + description: 'Time to create a quote' + }) if (options.debitAmount && options.receiveAmount) { + stopTimer() return QuoteError.InvalidAmount } const walletAddress = await deps.walletAddressService.get( options.walletAddressId ) if (!walletAddress) { + stopTimer() return QuoteError.UnknownWalletAddress } if (!walletAddress.isActive) { + stopTimer() return QuoteError.InactiveWalletAddress } if (options.debitAmount) { @@ -104,30 +110,54 @@ async function createQuote( options.debitAmount.assetCode !== walletAddress.asset.code || options.debitAmount.assetScale !== walletAddress.asset.scale ) { + stopTimer() return QuoteError.InvalidAmount } } if (options.receiveAmount) { if (options.receiveAmount.value <= BigInt(0)) { + stopTimer() return QuoteError.InvalidAmount } } try { + const stopTimerReceiver = deps.telemetry.startTimer( + 'quote_service_create_resolve_receiver_time_ms', + { + description: 'Time to resolve receiver' + } + ) const receiver = await resolveReceiver(deps, options) + stopTimerReceiver && stopTimerReceiver() + + const stopTimerQuote = deps.telemetry.startTimer( + 'quote_service_create_get_quote_time_ms', + { + description: 'Time to getQuote' + } + ) const quote = await deps.paymentMethodHandlerService.getQuote('ILP', { walletAddress, receiver, receiveAmount: options.receiveAmount, debitAmount: options.debitAmount }) + stopTimerQuote() const maxPacketAmount = quote.additionalFields.maxPacketAmount as bigint + const stopTimerFee = deps.telemetry.startTimer( + 'quote_service_create_get_latest_fee_time_ms', + { + description: 'Time to getLatestFee' + } + ) const sendingFee = await deps.feeService.getLatestFee( walletAddress.assetId, FeeType.Sending ) + stopTimerFee() return await Quote.transaction(deps.knex, async (trx) => { const createdQuote = await Quote.query(trx) @@ -151,7 +181,7 @@ async function createQuote( }) .withGraphFetched('[asset, fee, walletAddress]') - return await finalizeQuote( + const finalizedQuote = await finalizeQuote( { ...deps, knex: trx @@ -160,6 +190,7 @@ async function createQuote( createdQuote, receiver ) + return finalizedQuote }) } catch (err) { if (isQuoteError(err)) { @@ -175,6 +206,8 @@ async function createQuote( deps.logger.error({ err }, 'error creating a quote') throw err + } finally { + stopTimer() } } diff --git a/packages/backend/src/open_payments/receiver/service.ts b/packages/backend/src/open_payments/receiver/service.ts index 38636b80f1..e9ee6e3878 100644 --- a/packages/backend/src/open_payments/receiver/service.ts +++ b/packages/backend/src/open_payments/receiver/service.ts @@ -138,21 +138,28 @@ async function getReceiver( deps: ServiceDependencies, url: string ): Promise { + const stopTimer = deps.telemetry.startTimer('getReceiver', { + callName: 'getReceiver' + }) try { const localIncomingPayment = await getLocalIncomingPayment(deps, url) if (localIncomingPayment) { - return new Receiver(localIncomingPayment, true) + const receiver = new Receiver(localIncomingPayment, true) + return receiver } const remoteIncomingPayment = await getRemoteIncomingPayment(deps, url) if (remoteIncomingPayment) { - return new Receiver(remoteIncomingPayment, false) + const receiver = new Receiver(remoteIncomingPayment, false) + return receiver } } catch (err) { deps.logger.error( { errorMessage: err instanceof Error && err.message }, 'Could not get incoming payment' ) + } finally { + stopTimer() } } diff --git a/packages/backend/src/payment-method/ilp/connector/core/middleware/balance.ts b/packages/backend/src/payment-method/ilp/connector/core/middleware/balance.ts index 512ef863d1..52af882fe0 100644 --- a/packages/backend/src/payment-method/ilp/connector/core/middleware/balance.ts +++ b/packages/backend/src/payment-method/ilp/connector/core/middleware/balance.ts @@ -20,6 +20,9 @@ export function createBalanceMiddleware(): ILPMiddleware { }: ILPContext, next: () => Promise ): Promise => { + const stopTimer = services.telemetry.startTimer('balanceMiddleware', { + callName: 'balanceMiddleware' + }) const { amount } = request.prepare const logger = services.logger.child( { module: 'balance-middleware' }, @@ -31,6 +34,7 @@ export function createBalanceMiddleware(): ILPMiddleware { // Ignore zero amount packets if (amount === '0') { await next() + stopTimer() return } @@ -51,6 +55,7 @@ export function createBalanceMiddleware(): ILPMiddleware { }, 'Could not get rates' ) + stopTimer() throw new CannotReceiveError( `Exchange rate error: ${destinationAmountOrError}` ) @@ -60,6 +65,7 @@ export function createBalanceMiddleware(): ILPMiddleware { if (state.unfulfillable) { await next() + stopTimer() return } @@ -85,8 +91,10 @@ export function createBalanceMiddleware(): ILPMiddleware { switch (trxOrError) { case TransferError.InsufficientBalance: case TransferError.InsufficientLiquidity: + stopTimer() throw new InsufficientLiquidityError(trxOrError) default: + stopTimer() // TODO: map transfer errors to ILP errors ctxThrow(500, destinationAmountOrError.toString()) } @@ -110,6 +118,7 @@ export function createBalanceMiddleware(): ILPMiddleware { await trx.void() } } + stopTimer() } } } diff --git a/packages/backend/src/payment-method/ilp/connector/core/middleware/error-handler.ts b/packages/backend/src/payment-method/ilp/connector/core/middleware/error-handler.ts index 63802851c8..87368fb523 100644 --- a/packages/backend/src/payment-method/ilp/connector/core/middleware/error-handler.ts +++ b/packages/backend/src/payment-method/ilp/connector/core/middleware/error-handler.ts @@ -11,8 +11,15 @@ export function createIncomingErrorHandlerMiddleware( serverAddress: string ): ILPMiddleware { return async (ctx: ILPContext, next: () => Promise): Promise => { + let stopTimer try { await next() + stopTimer = ctx.services.telemetry.startTimer( + 'createIncomingErrorHandlerMiddleware', + { + callName: 'createIncomingErrorHandlerMiddleware' + } + ) if (!ctx.response.rawReply) { ctx.services.logger.error('handler did not return a valid value.') throw new Error('handler did not return a value.') @@ -37,6 +44,8 @@ export function createIncomingErrorHandlerMiddleware( name: '' }) } + } finally { + stopTimer && stopTimer() } } } diff --git a/packages/backend/src/payment-method/ilp/connector/core/middleware/stream-address.ts b/packages/backend/src/payment-method/ilp/connector/core/middleware/stream-address.ts index a4b9158c63..132429ec74 100644 --- a/packages/backend/src/payment-method/ilp/connector/core/middleware/stream-address.ts +++ b/packages/backend/src/payment-method/ilp/connector/core/middleware/stream-address.ts @@ -2,12 +2,16 @@ import { ILPMiddleware, ILPContext } from '../rafiki' export function createStreamAddressMiddleware(): ILPMiddleware { return async ( - { request, services: { streamServer }, state }: ILPContext, + { request, services: { streamServer, telemetry }, state }: ILPContext, next: () => Promise ): Promise => { + const stopTimer = telemetry.startTimer('createStreamAddressMiddleware', { + callName: 'createStreamAddressMiddleware' + }) const { destination } = request.prepare // To preserve sender privacy, the accountId wasn't included in the original destination address. state.streamDestination = streamServer.decodePaymentTag(destination) + stopTimer() await next() } } diff --git a/packages/backend/src/payment-method/ilp/connector/index.ts b/packages/backend/src/payment-method/ilp/connector/index.ts index 8dd2f27f0d..624b982df1 100644 --- a/packages/backend/src/payment-method/ilp/connector/index.ts +++ b/packages/backend/src/payment-method/ilp/connector/index.ts @@ -68,49 +68,103 @@ export async function createConnectorService({ streamServer, telemetry }, - compose([ - // Incoming Rules - createIncomingErrorHandlerMiddleware(ilpAddress), - createStreamAddressMiddleware(), - createAccountMiddleware(ilpAddress), - createIncomingMaxPacketAmountMiddleware(), - createIncomingRateLimitMiddleware({}), - createIncomingThroughputMiddleware(), - createIldcpMiddleware(ilpAddress), + compose( + [ + // Incoming Rules + { + name: 'createIncomingErrorHandlerMiddleware', + fn: createIncomingErrorHandlerMiddleware(ilpAddress) + }, + { + name: 'createStreamAddressMiddleware', + fn: createStreamAddressMiddleware() + }, + { + name: 'createAccountMiddleware', + fn: createAccountMiddleware(ilpAddress) + }, + { + name: 'createIncomingMaxPacketAmountMiddleware', + fn: createIncomingMaxPacketAmountMiddleware() + }, + { + name: 'createIncomingRateLimitMiddleware', + fn: createIncomingRateLimitMiddleware({}) + }, + { + name: 'createIncomingThroughputMiddleware', + fn: createIncomingThroughputMiddleware() + }, + { + name: 'createIldcpMiddleware', + fn: createIldcpMiddleware(ilpAddress) + }, - // Local pay - createBalanceMiddleware(), + // Local pay + { name: 'createBalanceMiddleware', fn: createBalanceMiddleware() }, - // Outgoing Rules - createStreamController(), - createOutgoingThroughputMiddleware(), - createOutgoingReduceExpiryMiddleware({}), - createOutgoingExpireMiddleware(), - createOutgoingValidateFulfillmentMiddleware(), + // Outgoing Rules + { name: 'createStreamController', fn: createStreamController() }, + { + name: 'createOutgoingThroughputMiddleware', + fn: createOutgoingThroughputMiddleware() + }, + { + name: 'createOutgoingReduceExpiryMiddleware', + fn: createOutgoingReduceExpiryMiddleware({}) + }, + { + name: 'createOutgoingExpireMiddleware', + fn: createOutgoingExpireMiddleware() + }, + { + name: 'createOutgoingValidateFulfillmentMiddleware', + fn: createOutgoingValidateFulfillmentMiddleware() + }, - // Send outgoing packets - createClientController() - ]) + // Send outgoing packets + { name: 'createClientController', fn: createClientController() } + ], + telemetry + ) ) } // Adapted from koa-compose -function compose(middlewares: ILPMiddleware[]): ILPMiddleware { +function compose( + middlewares: { name: string; fn: ILPMiddleware }[], + telemetry: TelemetryService +): ILPMiddleware { return function (ctx: ILPContext, next: () => Promise): Promise { // last called middleware let index = -1 - return (function dispatch(i: number): Promise { + + const stopTimer = telemetry.startTimer('connector_middleware_stack', { + callName: 'connector_middleware_stack' + }) + + async function dispatch(i: number): Promise { if (i <= index) return Promise.reject(new Error('next() called multiple times')) index = i - let fn = middlewares[i] - if (i === middlewares.length) fn = next - if (!fn) return Promise.resolve() + const m = middlewares[i] + if (i === middlewares.length) m.fn = next + if (!m.fn) return Promise.resolve() try { - return Promise.resolve(fn(ctx, dispatch.bind(null, i + 1))) + const stopTimerMiddleware = telemetry.startTimer( + 'connector_middleware', + { callName: m.name } + ) + const p = Promise.resolve(m.fn(ctx, dispatch.bind(null, i + 1))) + stopTimerMiddleware && stopTimerMiddleware() + return p } catch (err) { return Promise.reject(err) } - })(0) + } + + return dispatch(0).finally(() => { + stopTimer && stopTimer() + }) } } diff --git a/packages/backend/src/payment-method/ilp/service.ts b/packages/backend/src/payment-method/ilp/service.ts index b21c80db32..fa0cfd52a0 100644 --- a/packages/backend/src/payment-method/ilp/service.ts +++ b/packages/backend/src/payment-method/ilp/service.ts @@ -43,6 +43,12 @@ async function getQuote( deps: ServiceDependencies, options: StartQuoteOptions ): Promise { + const stopTimerRates = deps.telemetry.startTimer( + 'ilp_get_quote_rate_time_ms', + { + description: 'Time to get rates' + } + ) const rates = await deps.ratesService .rates(options.walletAddress.asset.code) .catch((_err: Error) => { @@ -51,15 +57,30 @@ async function getQuote( retryable: false }) }) + .finally(() => stopTimerRates()) + const stopTimerPlugin = deps.telemetry.startTimer( + 'ilp_make_ilp_plugin_time_ms', + { + description: 'Time to make ilp plugin' + } + ) const plugin = deps.makeIlpPlugin({ sourceAccount: options.walletAddress, unfulfillable: true }) + stopTimerPlugin() const destination = options.receiver.toResolvedPayment() try { + const stopTimerConnect = deps.telemetry.startTimer( + 'ilp_make_ilp_plugin_connect_time_ms', + { + description: 'Time to connect ilp plugin' + } + ) await plugin.connect() + stopTimerConnect() const quoteOptions: Pay.QuoteOptions = { plugin, destination, @@ -76,7 +97,9 @@ async function getQuote( } let ilpQuote: Pay.Quote | undefined - const rateProbeStartTime = Date.now() + const stopTimerProbe = deps.telemetry.startTimer('ilp_rate_probe_time_ms', { + description: 'Time to get an ILP quote (Pay.startQuote)' + }) try { ilpQuote = await Pay.startQuote({ ...quoteOptions, @@ -91,17 +114,9 @@ async function getQuote( description: Pay.isPaymentError(err) ? err : 'Unknown error', retryable: canRetryError(err as Error | Pay.PaymentError) }) + } finally { + stopTimerProbe() } - const payEndTime = Date.now() - - const rateProbeDuraiton = payEndTime - rateProbeStartTime - deps.telemetry.recordHistogram( - 'ilp_rate_probe_time_ms', - rateProbeDuraiton, - { - description: 'Time to get an ILP quote' - } - ) // Pay.startQuote should return PaymentError.InvalidSourceAmount or // PaymentError.InvalidDestinationAmount for non-positive amounts. // Outgoing payments' sendAmount or receiveAmount should never be @@ -171,6 +186,10 @@ async function getQuote( } } } finally { + const stopTimerClose = deps.telemetry.startTimer( + 'ilp_plugin_close_connect_time_ms', + { description: 'Time to close ilp plugin' } + ) try { await Pay.closeConnection(plugin, destination) } catch (error) { @@ -181,6 +200,8 @@ async function getQuote( }, 'close quote connection failed' ) + } finally { + stopTimerClose() } try { diff --git a/packages/backend/src/webhook/service.ts b/packages/backend/src/webhook/service.ts index cb2c46687e..c49bdfcb36 100644 --- a/packages/backend/src/webhook/service.ts +++ b/packages/backend/src/webhook/service.ts @@ -7,6 +7,7 @@ import { IAppConfig } from '../config/app' import { BaseService } from '../shared/baseService' import { Pagination, SortOrder } from '../shared/baseModel' import { FilterString } from '../shared/filters' +import { trace, Span } from '@opentelemetry/api' // First retry waits 10 seconds // Second retry waits 20 (more) seconds @@ -121,32 +122,40 @@ async function processNextWebhookEvent( if (!deps_.knex) { throw new Error('Knex undefined') } - return deps_.knex.transaction(async (trx) => { - const now = Date.now() - const events = await WebhookEvent.query(trx) - .limit(1) - // Ensure the webhook event cannot be processed concurrently by multiple workers. - .forUpdate() - // If a webhook event is locked, don't wait — just come back for it later. - .skipLocked() - .where('attempts', '<', deps_.config.webhookMaxRetry) - .where('processAt', '<=', new Date(now).toISOString()) - - const event = events[0] - if (!event) return - - const deps = { - ...deps_, - knex: trx, - logger: deps_.logger.child({ - event: event.id + + const tracer = trace.getTracer('webhook_worker') + + return tracer.startActiveSpan( + 'processNextWebhookEvent', + async (span: Span) => { + return deps_.knex!.transaction(async (trx) => { + const now = Date.now() + const events = await WebhookEvent.query(trx) + .limit(1) + // Ensure the webhook event cannot be processed concurrently by multiple workers. + .forUpdate() + // If a webhook event is locked, don't wait — just come back for it later. + .skipLocked() + .where('attempts', '<', deps_.config.webhookMaxRetry) + .where('processAt', '<=', new Date(now).toISOString()) + + const event = events[0] + if (!event) return + + const deps = { + ...deps_, + knex: trx, + logger: deps_.logger.child({ + event: event.id + }) + } + + await sendWebhookEvent(deps, event) + span.end() + return event.id }) } - - await sendWebhookEvent(deps, event) - - return event.id - }) + ) } type WebhookHeaders = { From 0b83806fa3e9348bfdc89ea635f57daefcc93f5a Mon Sep 17 00:00:00 2001 From: Blair Currey <12960453+BlairCurrey@users.noreply.github.com> Date: Mon, 23 Sep 2024 13:55:15 -0400 Subject: [PATCH 10/31] chore: rename performance metrics, update dashbaord --- .../provisioning/dashboards/example.json | 1070 ++++++++--------- .../backend/src/accounting/psql/service.ts | 9 +- .../src/accounting/tigerbeetle/service.ts | 2 +- .../payment/outgoing/lifecycle.ts | 8 +- .../open_payments/payment/outgoing/service.ts | 11 + .../open_payments/payment/outgoing/worker.ts | 13 +- .../src/open_payments/quote/service.ts | 20 + .../backend/src/payment-method/ilp/service.ts | 18 +- 8 files changed, 567 insertions(+), 584 deletions(-) diff --git a/localenv/telemetry/grafana/provisioning/dashboards/example.json b/localenv/telemetry/grafana/provisioning/dashboards/example.json index 276dd8c647..783b90fc77 100644 --- a/localenv/telemetry/grafana/provisioning/dashboards/example.json +++ b/localenv/telemetry/grafana/provisioning/dashboards/example.json @@ -50,8 +50,8 @@ "overrides": [] }, "gridPos": { - "h": 7, - "w": 3, + "h": 5, + "w": 5, "x": 0, "y": 0 }, @@ -63,7 +63,9 @@ "orientation": "auto", "percentChangeColorMode": "standard", "reduceOptions": { - "calcs": ["lastNotNull"], + "calcs": [ + "lastNotNull" + ], "fields": "", "values": false }, @@ -89,6 +91,384 @@ "title": "Panel Title", "type": "stat" }, + { + "datasource": { + "name": "${PrometheusDS}", + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "description": "Maximum time it takes to complete the fastest 25%/50%/75% of ILP quotes.", + "fieldConfig": { + "defaults": { + "color": { + "mode": "thresholds" + }, + "mappings": [], + "thresholds": { + "mode": "absolute", + "steps": [ + { + "color": "green", + "value": null + }, + { + "color": "red", + "value": 80 + } + ] + }, + "unit": "ms" + }, + "overrides": [] + }, + "gridPos": { + "h": 5, + "w": 9, + "x": 5, + "y": 0 + }, + "id": 5, + "options": { + "colorMode": "value", + "graphMode": "none", + "justifyMode": "auto", + "orientation": "auto", + "percentChangeColorMode": "standard", + "reduceOptions": { + "calcs": [ + "lastNotNull" + ], + "fields": "", + "values": false + }, + "showPercentChange": false, + "textMode": "auto", + "wideLayout": true + }, + "pluginVersion": "11.2.0", + "targets": [ + { + "datasource": { + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "editorMode": "code", + "expr": "histogram_quantile(0.25, ilp_rate_probe_time_ms_bucket)", + "instant": false, + "legendFormat": "First Quartile", + "range": true, + "refId": "A" + }, + { + "datasource": { + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "editorMode": "code", + "expr": "histogram_quantile(0.50, ilp_rate_probe_time_ms_bucket)", + "hide": false, + "instant": false, + "legendFormat": "Second Quartile", + "range": true, + "refId": "B" + }, + { + "datasource": { + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "editorMode": "code", + "expr": "histogram_quantile(0.75, ilp_rate_probe_time_ms_bucket)", + "hide": false, + "instant": false, + "legendFormat": "Third Quartile", + "range": true, + "refId": "C" + } + ], + "title": "ILP Quote Time Quartile Approximations", + "type": "stat" + }, + { + "datasource": { + "name": "${PrometheusDS}", + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "description": "Maximum time it takes to complete the fastest 25%/50%/75% of ILP payments.", + "fieldConfig": { + "defaults": { + "color": { + "mode": "thresholds" + }, + "mappings": [], + "thresholds": { + "mode": "absolute", + "steps": [ + { + "color": "green", + "value": null + }, + { + "color": "red", + "value": 80 + } + ] + }, + "unit": "ms" + }, + "overrides": [] + }, + "gridPos": { + "h": 5, + "w": 10, + "x": 14, + "y": 0 + }, + "id": 3, + "options": { + "colorMode": "value", + "graphMode": "none", + "justifyMode": "auto", + "orientation": "auto", + "percentChangeColorMode": "standard", + "reduceOptions": { + "calcs": [ + "lastNotNull" + ], + "fields": "", + "values": false + }, + "showPercentChange": false, + "textMode": "auto", + "wideLayout": true + }, + "pluginVersion": "11.2.0", + "targets": [ + { + "datasource": { + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "editorMode": "code", + "expr": "histogram_quantile(0.25, ilp_pay_time_ms_bucket)", + "instant": false, + "legendFormat": "First Quartile", + "range": true, + "refId": "A" + }, + { + "datasource": { + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "editorMode": "code", + "expr": "histogram_quantile(0.50, ilp_pay_time_ms_bucket)", + "hide": false, + "instant": false, + "legendFormat": "Second Quartile", + "range": true, + "refId": "B" + }, + { + "datasource": { + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "editorMode": "code", + "expr": "histogram_quantile(0.75, ilp_pay_time_ms_bucket)", + "hide": false, + "instant": false, + "legendFormat": "Third Quartile", + "range": true, + "refId": "C" + } + ], + "title": "ILP Pay Time Quartile Approximations", + "type": "stat" + }, + { + "datasource": { + "name": "${PrometheusDS}", + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "description": "", + "fieldConfig": { + "defaults": { + "color": { + "mode": "continuous-GrYlRd" + }, + "fieldMinMax": false, + "mappings": [], + "thresholds": { + "mode": "absolute", + "steps": [ + { + "color": "green", + "value": null + }, + { + "color": "red", + "value": 80 + } + ] + }, + "unit": "s" + }, + "overrides": [] + }, + "gridPos": { + "h": 12, + "w": 12, + "x": 0, + "y": 5 + }, + "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.2.0", + "targets": [ + { + "datasource": { + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "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": { + "name": "${TempoDS}", + "type": "tempo", + "uid": "${TempoDS}" + }, + "fieldConfig": { + "defaults": { + "color": { + "mode": "thresholds" + }, + "custom": { + "align": "auto", + "cellOptions": { + "type": "auto" + }, + "inspect": false + }, + "mappings": [], + "thresholds": { + "mode": "absolute", + "steps": [ + { + "color": "green", + "value": null + }, + { + "color": "red", + "value": 80 + } + ] + } + }, + "overrides": [] + }, + "gridPos": { + "h": 12, + "w": 12, + "x": 12, + "y": 5 + }, + "id": 4, + "options": { + "cellHeight": "sm", + "footer": { + "countRows": false, + "fields": "", + "reducer": [ + "sum" + ], + "show": false + }, + "showHeader": true, + "sortBy": [ + { + "desc": true, + "displayName": "Duration" + } + ] + }, + "pluginVersion": "11.2.0", + "targets": [ + { + "datasource": { + "type": "tempo", + "uid": "${TempoDS}" + }, + "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": "Traces > 100ms", + "type": "table" + }, { "datasource": { "default": false, @@ -153,15 +533,17 @@ "overrides": [] }, "gridPos": { - "h": 7, - "w": 21, - "x": 3, - "y": 0 + "h": 6, + "w": 12, + "x": 0, + "y": 17 }, "id": 10, "options": { "legend": { - "calcs": ["p95"], + "calcs": [ + "p95" + ], "displayMode": "table", "placement": "right", "showLegend": true @@ -178,7 +560,7 @@ "uid": "${PrometheusDS}" }, "editorMode": "code", - "expr": "sum by (callName) (rate(getPendingPayment_sum[$__rate_interval])/rate(getPendingPayment_count[$__rate_interval]))", + "expr": "sum by (callName) (rate(get_pending_payment_ms_sum[$__rate_interval])/rate(get_pending_payment_ms_count[$__rate_interval]))", "instant": false, "legendFormat": "{{caller}}", "range": true, @@ -190,7 +572,7 @@ "uid": "${PrometheusDS}" }, "editorMode": "code", - "expr": "sum by (callName) (rate(handleSending_sum[$__rate_interval])/rate(handleSending_count[$__rate_interval]))", + "expr": "sum by (callName) (rate(handle_sending_ms_sum[$__rate_interval])/rate(handle_sending_ms_count[$__rate_interval]))", "hide": false, "instant": false, "legendFormat": "__auto", @@ -216,7 +598,7 @@ "uid": "${PrometheusDS}" }, "editorMode": "code", - "expr": "sum by (callName) (rate(psql_getAccountTotalSent_sum[$__rate_interval])/rate(psql_getAccountTotalSent_count[$__rate_interval]))", + "expr": "sum by (callName) (rate(psql_get_account_total_sent_ms_sum[$__rate_interval])/rate(psql_get_account_total_sent_ms_count[$__rate_interval]))", "hide": false, "instant": false, "legendFormat": "__auto", @@ -229,7 +611,7 @@ "uid": "${PrometheusDS}" }, "editorMode": "code", - "expr": "sum by (callName) (rate(tb_getAccountTotalSent_sum[$__rate_interval])/rate(tb_getAccountTotalSent_count[$__rate_interval]))", + "expr": "sum by (callName) (rate(tb_get_account_total_sent_ms_sum[$__rate_interval])/rate(tb_get_account_total_sent_ms_count[$__rate_interval]))", "hide": false, "instant": false, "legendFormat": "__auto", @@ -242,7 +624,7 @@ "uid": "${PrometheusDS}" }, "editorMode": "code", - "expr": "sum by (callName) (rate(handleCompleted_sum[$__rate_interval])/rate(handleCompleted_count[$__rate_interval]))", + "expr": "sum by (callName) (rate(handle_completed_ms_sum[$__rate_interval])/rate(handle_completed_ms_count[$__rate_interval]))", "hide": false, "instant": false, "legendFormat": "__auto", @@ -255,7 +637,7 @@ "uid": "${PrometheusDS}" }, "editorMode": "code", - "expr": "sum by (callName) (rate(sendWebhookEvent_sum[$__rate_interval])/rate(sendWebhookEvent_count[$__rate_interval]))", + "expr": "sum by (callName) (rate(op_send_webhook_event_ms_sum[$__rate_interval])/rate(op_send_webhook_event_ms_count[$__rate_interval]))", "hide": false, "instant": false, "legendFormat": "__auto", @@ -268,7 +650,7 @@ "uid": "${PrometheusDS}" }, "editorMode": "code", - "expr": "sum by (callName) (rate(handleFailed_sum[$__rate_interval])/rate(handleFailed_count[$__rate_interval]))", + "expr": "sum by (callName) (rate(handle_failed_ms_sum[$__rate_interval])/rate(handle_failed_ms_count[$__rate_interval]))", "hide": false, "instant": false, "legendFormat": "__auto", @@ -281,7 +663,7 @@ "uid": "${PrometheusDS}" }, "editorMode": "code", - "expr": "sum by (callName) (rate(processPendingPayment_sum[$__rate_interval])/rate(processPendingPayment_count[$__rate_interval]))", + "expr": "sum by (callName) (rate(process_pending_payment_ms_sum[$__rate_interval])/rate(process_pending_payment_ms_count[$__rate_interval]))", "hide": false, "instant": false, "legendFormat": "__auto", @@ -294,79 +676,7 @@ }, { "datasource": { - "name": "${PrometheusDS}", - "type": "prometheus", - "uid": "${PrometheusDS}" - }, - "description": "", - "fieldConfig": { - "defaults": { - "color": { - "mode": "continuous-GrYlRd" - }, - "fieldMinMax": false, - "mappings": [], - "thresholds": { - "mode": "absolute", - "steps": [ - { - "color": "green", - "value": null - }, - { - "color": "red", - "value": 80 - } - ] - }, - "unit": "s" - }, - "overrides": [] - }, - "gridPos": { - "h": 12, - "w": 12, - "x": 0, - "y": 7 - }, - "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.2.0", - "targets": [ - { - "datasource": { - "type": "prometheus", - "uid": "${PrometheusDS}" - }, - "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": { - "name": "${PrometheusDS}", + "default": false, "type": "prometheus", "uid": "${PrometheusDS}" }, @@ -430,12 +740,14 @@ "h": 6, "w": 12, "x": 12, - "y": 7 + "y": 17 }, "id": 9, "options": { "legend": { - "calcs": ["p95"], + "calcs": [ + "p95" + ], "displayMode": "table", "placement": "right", "showLegend": true @@ -455,7 +767,7 @@ "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}}", + "legendFormat": "{{callName}}", "range": true, "refId": "C" }, @@ -468,7 +780,7 @@ "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}}", + "legendFormat": "{{callName}}", "range": true, "refId": "F" }, @@ -481,7 +793,7 @@ "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}}", + "legendFormat": "{{callName}}", "range": true, "refId": "A" }, @@ -494,7 +806,7 @@ "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}}", + "legendFormat": "{{callName}}", "range": true, "refId": "B" }, @@ -507,7 +819,7 @@ "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}}", + "legendFormat": "{{callName}}", "range": true, "refId": "D" }, @@ -520,7 +832,7 @@ "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}}", + "legendFormat": "{{callName}}", "range": true, "refId": "E" } @@ -530,7 +842,7 @@ }, { "datasource": { - "name": "${PrometheusDS}", + "default": false, "type": "prometheus", "uid": "${PrometheusDS}" }, @@ -585,21 +897,22 @@ "value": 80 } ] - }, - "unit": "ms" + } }, "overrides": [] }, "gridPos": { - "h": 6, + "h": 7, "w": 12, - "x": 12, - "y": 13 + "x": 0, + "y": 23 }, - "id": 11, + "id": 16, "options": { "legend": { - "calcs": ["p95"], + "calcs": [ + "p95" + ], "displayMode": "table", "placement": "right", "showLegend": true @@ -613,22 +926,35 @@ { "datasource": { "type": "prometheus", - "uid": "${PrometheusDS}" + "uid": "PBFA97CFB590B2093" }, "editorMode": "code", - "expr": "sum by (callName) (rate(psql_getAccountBalances_sum[$__rate_interval])/rate(psql_getAccountBalances_count[$__rate_interval]))", + "expr": "rate(depositOutgoingPaymentLiquidity_sum[$__rate_interval])/rate(depositOutgoingPaymentLiquidity_count[$__rate_interval])", "instant": false, - "legendFormat": "__auto", + "legendFormat": "{{callName}}", "range": true, "refId": "A" + }, + { + "datasource": { + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "editorMode": "code", + "expr": "rate(fundPayment_sum[$__rate_interval])/rate(fundPayment_count[$__rate_interval])", + "hide": false, + "instant": false, + "legendFormat": "{{callName}}", + "range": true, + "refId": "B" } ], - "title": "PSQL Get Account Balance", + "title": "Deposit Outgoing Payment Liquidity ", "type": "timeseries" }, { "datasource": { - "name": "${PrometheusDS}", + "default": false, "type": "prometheus", "uid": "${PrometheusDS}" }, @@ -684,22 +1010,25 @@ "value": 80 } ] - } + }, + "unit": "ms" }, "overrides": [] }, "gridPos": { "h": 7, "w": 12, - "x": 0, - "y": 19 + "x": 12, + "y": 23 }, "id": 14, "options": { "legend": { - "calcs": [], - "displayMode": "list", - "placement": "bottom", + "calcs": [ + "p95" + ], + "displayMode": "table", + "placement": "right", "showLegend": true }, "tooltip": { @@ -716,7 +1045,7 @@ "editorMode": "code", "expr": "rate(outgoing_payment_service_create_time_ms_sum[$__rate_interval])/rate(outgoing_payment_service_create_time_ms_count[$__rate_interval])", "instant": false, - "legendFormat": "{{description}}", + "legendFormat": "{{callName}}", "range": true, "refId": "A" }, @@ -729,7 +1058,7 @@ "expr": "rate(outgoing_payment_service_create_quote_time_ms_sum[$__rate_interval])/rate(outgoing_payment_service_create_quote_time_ms_count[$__rate_interval])", "hide": false, "instant": false, - "legendFormat": "{{description}}", + "legendFormat": "{{callName}}", "range": true, "refId": "B" }, @@ -742,7 +1071,7 @@ "expr": "rate(outgoing_payment_service_getwalletaddress_time_ms_sum[$__rate_interval])/rate(outgoing_payment_service_getwalletaddress_time_ms_count[$__rate_interval])", "hide": false, "instant": false, - "legendFormat": "{{description}}", + "legendFormat": "{{callName}}", "range": true, "refId": "E" }, @@ -755,7 +1084,7 @@ "expr": "rate(outgoing_payment_service_insertgrant_time_ms_sum[$__rate_interval])/rate(outgoing_payment_service_insertgrant_time_ms_count[$__rate_interval])", "hide": false, "instant": false, - "legendFormat": "{{description}}", + "legendFormat": "{{callName}}", "range": true, "refId": "D" }, @@ -768,7 +1097,7 @@ "expr": "rate(outgoing_payment_service_insertpayment_time_ms_sum[$__rate_interval])/rate(outgoing_payment_service_insertpayment_time_ms_count[$__rate_interval])", "hide": false, "instant": false, - "legendFormat": "{{description}}", + "legendFormat": "{{callName}}", "range": true, "refId": "F" }, @@ -781,7 +1110,7 @@ "expr": "rate(outgoing_payment_service_getreceiver_time_ms_sum[$__rate_interval])/rate(outgoing_payment_service_getreceiver_time_ms_count[$__rate_interval])", "hide": false, "instant": false, - "legendFormat": "{{description}}", + "legendFormat": "{{callName}}", "range": true, "refId": "H" }, @@ -794,7 +1123,7 @@ "expr": "rate(outgoing_payment_service_getpeer_time_ms_sum[$__rate_interval])/rate(outgoing_payment_service_getpeer_time_ms_count[$__rate_interval])", "hide": false, "instant": false, - "legendFormat": "{{description}}", + "legendFormat": "{{callName}}", "range": true, "refId": "G" }, @@ -807,7 +1136,7 @@ "expr": "rate(outgoing_payment_service_patchpeer_time_ms_sum[$__rate_interval])/rate(outgoing_payment_service_patchpeer_time_ms_count[$__rate_interval])", "hide": false, "instant": false, - "legendFormat": "{{description}}", + "legendFormat": "{{callName}}", "range": true, "refId": "I" }, @@ -820,7 +1149,7 @@ "expr": "rate(outgoing_payment_service_webhook_event_time_ms_sum[$__rate_interval])/rate(outgoing_payment_service_webhook_event_time_ms_count[$__rate_interval])", "hide": false, "instant": false, - "legendFormat": "{{description}}", + "legendFormat": "{{callName}}", "range": true, "refId": "C" } @@ -885,20 +1214,23 @@ "value": 80 } ] - } + }, + "unit": "ms" }, "overrides": [] }, "gridPos": { - "h": 6, + "h": 7, "w": 12, - "x": 12, - "y": 19 + "x": 0, + "y": 30 }, - "id": 13, + "id": 12, "options": { "legend": { - "calcs": ["p95"], + "calcs": [ + "p95" + ], "displayMode": "table", "placement": "right", "showLegend": true @@ -915,212 +1247,24 @@ "uid": "${PrometheusDS}" }, "editorMode": "code", - "expr": "sum by (callName) (rate(createLiquidityAccount_sum[$__rate_interval])/rate(createLiquidityAccount_count[$__rate_interval]))", + "expr": "sum by (callName) (rate(connector_middleware_sum[$__rate_interval])/rate(connector_middleware_count[$__rate_interval]))", "instant": false, - "legendFormat": "__auto", + "legendFormat": "{{caller}}", "range": true, "refId": "A" - } - ], - "title": "Ilp Connector > Balance Middleware > createLiquidityAccount", - "type": "timeseries" - }, - { - "datasource": { - "name": "${TempoDS}", - "type": "tempo", - "uid": "${TempoDS}" - }, - "fieldConfig": { - "defaults": { - "color": { - "mode": "thresholds" - }, - "custom": { - "align": "auto", - "cellOptions": { - "type": "auto" - }, - "inspect": false - }, - "mappings": [], - "thresholds": { - "mode": "absolute", - "steps": [ - { - "color": "green", - "value": null - }, - { - "color": "red", - "value": 80 - } - ] - } - }, - "overrides": [] - }, - "gridPos": { - "h": 8, - "w": 12, - "x": 12, - "y": 25 - }, - "id": 4, - "options": { - "cellHeight": "sm", - "footer": { - "countRows": false, - "fields": "", - "reducer": ["sum"], - "show": false - }, - "showHeader": true, - "sortBy": [ - { - "desc": true, - "displayName": "Duration" - } - ] - }, - "pluginVersion": "11.2.0", - "targets": [ - { - "datasource": { - "type": "tempo", - "uid": "${TempoDS}" - }, - "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": "Traces > 100ms", - "type": "table" - }, - { - "datasource": { - "default": false, - "type": "prometheus", - "uid": "${PrometheusDS}" - }, - "fieldConfig": { - "defaults": { - "color": { - "mode": "palette-classic" - }, - "custom": { - "axisBorderShow": false, - "axisCenteredZero": false, - "axisColorMode": "text", - "axisLabel": "", - "axisPlacement": "auto", - "barAlignment": 0, - "barWidthFactor": 0.6, - "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": 6, - "w": 12, - "x": 0, - "y": 26 - }, - "id": 16, - "options": { - "legend": { - "calcs": [], - "displayMode": "list", - "placement": "bottom", - "showLegend": true }, - "tooltip": { - "mode": "single", - "sort": "none" - } - }, - "targets": [ { "datasource": { "type": "prometheus", - "uid": "PBFA97CFB590B2093" + "uid": "${PrometheusDS}" }, "editorMode": "code", - "expr": "rate(depositOutgoingPaymentLiquidity_sum[$__rate_interval])/rate(depositOutgoingPaymentLiquidity_count[$__rate_interval])", + "expr": "sum by (callName) (rate(connector_middleware_stack_sum[$__rate_interval])/rate(connector_middleware_stack_count[$__rate_interval]))", + "hide": false, "instant": false, - "legendFormat": "{{callName}}", + "legendFormat": "__auto", "range": true, - "refId": "A" + "refId": "B" }, { "datasource": { @@ -1128,20 +1272,20 @@ "uid": "${PrometheusDS}" }, "editorMode": "code", - "expr": "rate(fundPayment_sum[$__rate_interval])/rate(fundPayment_count[$__rate_interval])", + "expr": "sum by (callName) (rate(balanceMiddleware_sum[$__rate_interval])/rate(balanceMiddleware_count[$__rate_interval]))", "hide": false, "instant": false, - "legendFormat": "{{callName}}", + "legendFormat": "__auto", "range": true, - "refId": "B" + "refId": "C" } ], - "title": "Deposit Outgoing Payment Liquidity ", + "title": "ILP Connector", "type": "timeseries" }, { "datasource": { - "name": "${PrometheusDS}", + "default": false, "type": "prometheus", "uid": "${PrometheusDS}" }, @@ -1204,13 +1348,15 @@ "gridPos": { "h": 6, "w": 12, - "x": 0, - "y": 32 + "x": 12, + "y": 30 }, "id": 7, "options": { "legend": { - "calcs": ["p95"], + "calcs": [ + "p95" + ], "displayMode": "table", "placement": "right", "showLegend": true @@ -1229,7 +1375,7 @@ "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}}", + "legendFormat": "{{callName}}", "range": true, "refId": "A" }, @@ -1242,7 +1388,7 @@ "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}}", + "legendFormat": "{{callName}}", "range": true, "refId": "B" }, @@ -1255,7 +1401,7 @@ "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}}", + "legendFormat": "{{callName}}", "range": true, "refId": "C" }, @@ -1268,7 +1414,7 @@ "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}}", + "legendFormat": "{{callName}}", "range": true, "refId": "D" }, @@ -1281,7 +1427,7 @@ "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}}", + "legendFormat": "{{callName}}", "range": true, "refId": "E" }, @@ -1294,7 +1440,7 @@ "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}}", + "legendFormat": "{{callName}}", "range": true, "refId": "F" } @@ -1365,15 +1511,17 @@ "overrides": [] }, "gridPos": { - "h": 6, - "w": 12, + "h": 7, + "w": 24, "x": 0, - "y": 38 + "y": 37 }, - "id": 12, + "id": 11, "options": { "legend": { - "calcs": ["p95"], + "calcs": [ + "p95" + ], "displayMode": "table", "placement": "right", "showLegend": true @@ -1390,40 +1538,14 @@ "uid": "${PrometheusDS}" }, "editorMode": "code", - "expr": "sum by (callName) (rate(connector_middleware_sum[$__rate_interval])/rate(connector_middleware_count[$__rate_interval]))", - "instant": false, - "legendFormat": "{{caller}}", - "range": true, - "refId": "A" - }, - { - "datasource": { - "type": "prometheus", - "uid": "${PrometheusDS}" - }, - "editorMode": "code", - "expr": "sum by (callName) (rate(connector_middleware_stack_sum[$__rate_interval])/rate(connector_middleware_stack_count[$__rate_interval]))", - "hide": false, - "instant": false, - "legendFormat": "__auto", - "range": true, - "refId": "B" - }, - { - "datasource": { - "type": "prometheus", - "uid": "${PrometheusDS}" - }, - "editorMode": "code", - "expr": "sum by (callName) (rate(balanceMiddleware_sum[$__rate_interval])/rate(balanceMiddleware_count[$__rate_interval]))", - "hide": false, + "expr": "sum by (callName) (rate(psql_getAccountBalances_sum[$__rate_interval])/rate(psql_getAccountBalances_count[$__rate_interval]))", "instant": false, "legendFormat": "__auto", "range": true, - "refId": "C" + "refId": "A" } ], - "title": "ILP Connector", + "title": "PSQL Get Account Balance", "type": "timeseries" }, { @@ -1590,8 +1712,8 @@ "gridPos": { "h": 8, "w": 12, - "x": 0, - "y": 52 + "x": 12, + "y": 44 }, "id": 1, "interval": "15s", @@ -1625,198 +1747,6 @@ ], "title": "Transaction Count", "type": "timeseries" - }, - { - "datasource": { - "name": "${PrometheusDS}", - "type": "prometheus", - "uid": "${PrometheusDS}" - }, - "description": "Maximum time it takes to complete the fastest 25%/50%/75% of ILP payments.", - "fieldConfig": { - "defaults": { - "color": { - "mode": "thresholds" - }, - "mappings": [], - "thresholds": { - "mode": "absolute", - "steps": [ - { - "color": "green", - "value": null - }, - { - "color": "red", - "value": 80 - } - ] - }, - "unit": "ms" - }, - "overrides": [] - }, - "gridPos": { - "h": 5, - "w": 12, - "x": 0, - "y": 60 - }, - "id": 3, - "options": { - "colorMode": "value", - "graphMode": "none", - "justifyMode": "auto", - "orientation": "auto", - "percentChangeColorMode": "standard", - "reduceOptions": { - "calcs": ["lastNotNull"], - "fields": "", - "values": false - }, - "showPercentChange": false, - "textMode": "auto", - "wideLayout": true - }, - "pluginVersion": "11.2.0", - "targets": [ - { - "datasource": { - "type": "prometheus", - "uid": "${PrometheusDS}" - }, - "editorMode": "code", - "expr": "histogram_quantile(0.25, ilp_pay_time_ms_bucket)", - "instant": false, - "legendFormat": "First Quartile", - "range": true, - "refId": "A" - }, - { - "datasource": { - "type": "prometheus", - "uid": "${PrometheusDS}" - }, - "editorMode": "code", - "expr": "histogram_quantile(0.50, ilp_pay_time_ms_bucket)", - "hide": false, - "instant": false, - "legendFormat": "Second Quartile", - "range": true, - "refId": "B" - }, - { - "datasource": { - "type": "prometheus", - "uid": "${PrometheusDS}" - }, - "editorMode": "code", - "expr": "histogram_quantile(0.75, ilp_pay_time_ms_bucket)", - "hide": false, - "instant": false, - "legendFormat": "Third Quartile", - "range": true, - "refId": "C" - } - ], - "title": "ILP Pay Time Quartile Approximations", - "type": "stat" - }, - { - "datasource": { - "name": "${PrometheusDS}", - "type": "prometheus", - "uid": "${PrometheusDS}" - }, - "description": "Maximum time it takes to complete the fastest 25%/50%/75% of ILP quotes.", - "fieldConfig": { - "defaults": { - "color": { - "mode": "thresholds" - }, - "mappings": [], - "thresholds": { - "mode": "absolute", - "steps": [ - { - "color": "green", - "value": null - }, - { - "color": "red", - "value": 80 - } - ] - }, - "unit": "ms" - }, - "overrides": [] - }, - "gridPos": { - "h": 5, - "w": 12, - "x": 0, - "y": 65 - }, - "id": 5, - "options": { - "colorMode": "value", - "graphMode": "none", - "justifyMode": "auto", - "orientation": "auto", - "percentChangeColorMode": "standard", - "reduceOptions": { - "calcs": ["lastNotNull"], - "fields": "", - "values": false - }, - "showPercentChange": false, - "textMode": "auto", - "wideLayout": true - }, - "pluginVersion": "11.2.0", - "targets": [ - { - "datasource": { - "type": "prometheus", - "uid": "${PrometheusDS}" - }, - "editorMode": "code", - "expr": "histogram_quantile(0.25, ilp_rate_probe_time_ms_bucket)", - "instant": false, - "legendFormat": "First Quartile", - "range": true, - "refId": "A" - }, - { - "datasource": { - "type": "prometheus", - "uid": "${PrometheusDS}" - }, - "editorMode": "code", - "expr": "histogram_quantile(0.50, ilp_rate_probe_time_ms_bucket)", - "hide": false, - "instant": false, - "legendFormat": "Second Quartile", - "range": true, - "refId": "B" - }, - { - "datasource": { - "type": "prometheus", - "uid": "${PrometheusDS}" - }, - "editorMode": "code", - "expr": "histogram_quantile(0.75, ilp_rate_probe_time_ms_bucket)", - "hide": false, - "instant": false, - "legendFormat": "Third Quartile", - "range": true, - "refId": "C" - } - ], - "title": "ILP Quote Time Quartile Approximations", - "type": "stat" } ], "refresh": "15s", @@ -1864,7 +1794,7 @@ ] }, "time": { - "from": "now-5m", + "from": "now-30m", "to": "now" }, "timepicker": { @@ -1885,4 +1815,4 @@ "uid": "fdr58stwkr6yof", "version": 1, "weekStart": "" -} +} \ No newline at end of file diff --git a/packages/backend/src/accounting/psql/service.ts b/packages/backend/src/accounting/psql/service.ts index f0f15023b7..6bef5ffd1b 100644 --- a/packages/backend/src/accounting/psql/service.ts +++ b/packages/backend/src/accounting/psql/service.ts @@ -147,9 +147,12 @@ export async function getAccountTotalSent( deps: ServiceDependencies, accountRef: string ): Promise { - const stopTimer = deps.telemetry.startTimer('psql_getAccountTotalSent', { - callName: 'psql_getAccountTotalSent' - }) + const stopTimer = deps.telemetry.startTimer( + 'psql_get_account_total_sent_ms', + { + callName: 'psql_getAccountTotalSent' + } + ) const account = await getLiquidityAccount(deps, accountRef) if (!account) { diff --git a/packages/backend/src/accounting/tigerbeetle/service.ts b/packages/backend/src/accounting/tigerbeetle/service.ts index 1ca4539518..ea79628d70 100644 --- a/packages/backend/src/accounting/tigerbeetle/service.ts +++ b/packages/backend/src/accounting/tigerbeetle/service.ts @@ -220,7 +220,7 @@ export async function getAccountTotalSent( deps: ServiceDependencies, id: string ): Promise { - const stopTimer = deps.telemetry.startTimer('tb_getAccountTotalSent', { + const stopTimer = deps.telemetry.startTimer('tb_get_account_total_sent_ms', { callName: 'tb_getAccountTotalSent' }) const account = (await getAccounts(deps, [id]))[0] diff --git a/packages/backend/src/open_payments/payment/outgoing/lifecycle.ts b/packages/backend/src/open_payments/payment/outgoing/lifecycle.ts index 367c211c06..c2a7a41955 100644 --- a/packages/backend/src/open_payments/payment/outgoing/lifecycle.ts +++ b/packages/backend/src/open_payments/payment/outgoing/lifecycle.ts @@ -141,7 +141,7 @@ export async function handleFailed( payment: OutgoingPayment, error: string ): Promise { - const stopTimer = deps.telemetry.startTimer('handleFailed', { + const stopTimer = deps.telemetry.startTimer('handle_failed_ms', { callName: 'handleFailed' }) await payment.$query(deps.knex).patch({ @@ -156,7 +156,7 @@ async function handleCompleted( deps: ServiceDependencies, payment: OutgoingPayment ): Promise { - const stopTimer = deps.telemetry.startTimer('handleCompleted', { + const stopTimer = deps.telemetry.startTimer('handle_completed_ms', { callName: 'handleCompleted' }) await payment.$query(deps.knex).patch({ @@ -177,8 +177,8 @@ export async function sendWebhookEvent( type: OutgoingPaymentEventType, trx?: TransactionOrKnex ): Promise { - const stopTimer = deps.telemetry.startTimer('sendWebhookEvent', { - callName: 'outgoingPaymentLifecycle_sendwebhookEvent' + const stopTimer = deps.telemetry.startTimer('op_send_webhook_event_ms', { + callName: 'opLifecycle_sendWebhookEvent' }) // TigerBeetle accounts are only created as the OutgoingPayment is funded. // So default the amountSent and balance to 0 for outgoing payments still in the funding state diff --git a/packages/backend/src/open_payments/payment/outgoing/service.ts b/packages/backend/src/open_payments/payment/outgoing/service.ts index da368b0feb..b6b7e34133 100644 --- a/packages/backend/src/open_payments/payment/outgoing/service.ts +++ b/packages/backend/src/open_payments/payment/outgoing/service.ts @@ -218,6 +218,7 @@ async function createOutgoingPayment( const stopTimerOP = deps.telemetry.startTimer( 'outgoing_payment_service_create_time_ms', { + callName: 'createOutgoingPayment', description: 'Time to create an outgoing payment' } ) @@ -228,6 +229,7 @@ async function createOutgoingPayment( const stopTimerQuote = deps.telemetry.startTimer( 'outgoing_payment_service_create_quote_time_ms', { + callName: 'quoteService.create', description: 'Time to create a quote in outgoing payment' } ) @@ -254,6 +256,7 @@ async function createOutgoingPayment( const stopTimerWA = deps.telemetry.startTimer( 'outgoing_payment_service_getwalletaddress_time_ms', { + callName: 'walletAddressService.get', description: 'Time to get wallet address in outgoing payment' } ) @@ -270,6 +273,7 @@ async function createOutgoingPayment( const stopTimerGrant = deps.telemetry.startTimer( 'outgoing_payment_service_insertgrant_time_ms', { + callName: 'OutgoingPaymentGrant.insert', description: 'Time to insert grant in outgoing payment' } ) @@ -284,6 +288,7 @@ async function createOutgoingPayment( const stopTimerInsertPayment = deps.telemetry.startTimer( 'outgoing_payment_service_insertpayment_time_ms', { + callName: 'OutgoingPayment.insert', description: 'Time to insert payment in outgoing payment' } ) @@ -310,6 +315,7 @@ async function createOutgoingPayment( const stopTimerValidateGrant = deps.telemetry.startTimer( 'outgoing_payment_service_validate_grant_time_ms', { + callName: 'validateGrantAndAddSpentAmountsToPayment', description: 'Time to validate a grant' } ) @@ -329,6 +335,7 @@ async function createOutgoingPayment( const stopTimerReceiver = deps.telemetry.startTimer( 'outgoing_payment_service_getreceiver_time_ms', { + callName: 'receiverService.get', description: 'Time to retrieve receiver in outgoing payment' } ) @@ -340,6 +347,7 @@ async function createOutgoingPayment( const stopTimerPeer = deps.telemetry.startTimer( 'outgoing_payment_service_getpeer_time_ms', { + callName: 'peerService.getByDestinationAddress', description: 'Time to retrieve peer in outgoing payment' } ) @@ -351,6 +359,7 @@ async function createOutgoingPayment( const stopTimerPeerUpdate = deps.telemetry.startTimer( 'outgoing_payment_service_patchpeer_time_ms', { + callName: 'payment.patch', description: 'Time to patch peer in outgoing payment' } ) @@ -360,6 +369,7 @@ async function createOutgoingPayment( const stopTimerWebhook = deps.telemetry.startTimer( 'outgoing_payment_service_webhook_event_time_ms', { + callName: 'sendWebhookEvent', description: 'Time to add outgoing payment webhook event' } ) @@ -374,6 +384,7 @@ async function createOutgoingPayment( const stopTimerAddAmount = deps.telemetry.startTimer( 'outgoing_payment_service_add_sent_time_ms', { + callName: 'addSentAmount', description: 'Time to add sent amount to outgoing payment' } ) diff --git a/packages/backend/src/open_payments/payment/outgoing/worker.ts b/packages/backend/src/open_payments/payment/outgoing/worker.ts index 20aad9ee82..e7a780fb28 100644 --- a/packages/backend/src/open_payments/payment/outgoing/worker.ts +++ b/packages/backend/src/open_payments/payment/outgoing/worker.ts @@ -21,9 +21,12 @@ export async function processPendingPayment( return tracer.startActiveSpan( 'outgoingPaymentLifecycle', async (span: Span) => { - const stopTimer = deps_.telemetry.startTimer('processPendingPayment', { - callName: 'processPendingPayment' - }) + const stopTimer = deps_.telemetry.startTimer( + 'process_pending_payment_ms', + { + callName: 'processPendingPayment' + } + ) const paymentId = await deps_.knex.transaction(async (trx) => { const payment = await getPendingPayment(trx, deps_) if (!payment) return @@ -54,7 +57,7 @@ async function getPendingPayment( trx: Knex.Transaction, deps: ServiceDependencies ): Promise { - const stopTimer = deps.telemetry.startTimer('getPendingPayment', { + const stopTimer = deps.telemetry.startTimer('get_pending_payment_ms', { callName: 'getPendingPayment' }) const now = new Date(Date.now()).toISOString() @@ -88,7 +91,7 @@ async function handlePaymentLifecycle( return } - const stopTimer = deps.telemetry.startTimer('handleSending', { + const stopTimer = deps.telemetry.startTimer('handle_sending_ms', { callName: 'handleSending' }) try { diff --git a/packages/backend/src/open_payments/quote/service.ts b/packages/backend/src/open_payments/quote/service.ts index 60ece00a59..2754bd9a47 100644 --- a/packages/backend/src/open_payments/quote/service.ts +++ b/packages/backend/src/open_payments/quote/service.ts @@ -87,6 +87,7 @@ async function createQuote( options: CreateQuoteOptions ): Promise { const stopTimer = deps.telemetry.startTimer('quote_service_create_time_ms', { + callName: 'createQuote', description: 'Time to create a quote' }) if (options.debitAmount && options.receiveAmount) { @@ -125,6 +126,7 @@ async function createQuote( const stopTimerReceiver = deps.telemetry.startTimer( 'quote_service_create_resolve_receiver_time_ms', { + callName: 'resolveReceiver', description: 'Time to resolve receiver' } ) @@ -134,6 +136,7 @@ async function createQuote( const stopTimerQuote = deps.telemetry.startTimer( 'quote_service_create_get_quote_time_ms', { + callName: 'getQuote', description: 'Time to getQuote' } ) @@ -150,6 +153,7 @@ async function createQuote( const stopTimerFee = deps.telemetry.startTimer( 'quote_service_create_get_latest_fee_time_ms', { + callName: 'getLatestFee', description: 'Time to getLatestFee' } ) @@ -160,6 +164,13 @@ async function createQuote( stopTimerFee() return await Quote.transaction(deps.knex, async (trx) => { + const stopQuoteCreate = deps.telemetry.startTimer( + 'quote_service_create_insert_time_ms', + { + callName: 'Quote.insert', + description: 'Time to insert quote' + } + ) const createdQuote = await Quote.query(trx) .insertAndFetch({ walletAddressId: options.walletAddressId, @@ -180,7 +191,15 @@ async function createQuote( estimatedExchangeRate: quote.estimatedExchangeRate }) .withGraphFetched('[asset, fee, walletAddress]') + stopQuoteCreate() + const stopFinalize = deps.telemetry.startTimer( + 'quote_service_finalize_quote_ms', + { + callName: 'finalizedQuote', + description: 'Time to finalize quote' + } + ) const finalizedQuote = await finalizeQuote( { ...deps, @@ -190,6 +209,7 @@ async function createQuote( createdQuote, receiver ) + stopFinalize() return finalizedQuote }) } catch (err) { diff --git a/packages/backend/src/payment-method/ilp/service.ts b/packages/backend/src/payment-method/ilp/service.ts index fa0cfd52a0..9d3363dc02 100644 --- a/packages/backend/src/payment-method/ilp/service.ts +++ b/packages/backend/src/payment-method/ilp/service.ts @@ -46,6 +46,7 @@ async function getQuote( const stopTimerRates = deps.telemetry.startTimer( 'ilp_get_quote_rate_time_ms', { + callName: 'rates', description: 'Time to get rates' } ) @@ -62,6 +63,7 @@ async function getQuote( const stopTimerPlugin = deps.telemetry.startTimer( 'ilp_make_ilp_plugin_time_ms', { + callName: 'makeIlpPlugin', description: 'Time to make ilp plugin' } ) @@ -76,6 +78,7 @@ async function getQuote( const stopTimerConnect = deps.telemetry.startTimer( 'ilp_make_ilp_plugin_connect_time_ms', { + callName: 'plugin.connect', description: 'Time to connect ilp plugin' } ) @@ -98,6 +101,7 @@ async function getQuote( let ilpQuote: Pay.Quote | undefined const stopTimerProbe = deps.telemetry.startTimer('ilp_rate_probe_time_ms', { + callName: 'Pay.startQuote', description: 'Time to get an ILP quote (Pay.startQuote)' }) try { @@ -188,7 +192,10 @@ async function getQuote( } finally { const stopTimerClose = deps.telemetry.startTimer( 'ilp_plugin_close_connect_time_ms', - { description: 'Time to close ilp plugin' } + { + callName: 'Pay.closeConnection', + description: 'Time to close ilp plugin' + } ) try { await Pay.closeConnection(plugin, destination) @@ -204,6 +211,13 @@ async function getQuote( stopTimerClose() } + const stopTimerDisconnect = deps.telemetry.startTimer( + 'ilp_plugin_disconnect_time_ms', + { + callName: 'plugin.disconnect', + description: 'Time to disconnect ilp plugin' + } + ) try { await plugin.disconnect() } catch (error) { @@ -211,6 +225,8 @@ async function getQuote( { error: error instanceof Error && error.message }, 'error disconnecting ilp plugin' ) + } finally { + stopTimerDisconnect() } } } From 29143f44b35e463f2a8b85862c2190dbf221872f Mon Sep 17 00:00:00 2001 From: Blair Currey <12960453+BlairCurrey@users.noreply.github.com> Date: Mon, 23 Sep 2024 15:31:45 -0400 Subject: [PATCH 11/31] chore: format --- .../provisioning/dashboards/example.json | 56 +++++-------------- 1 file changed, 15 insertions(+), 41 deletions(-) diff --git a/localenv/telemetry/grafana/provisioning/dashboards/example.json b/localenv/telemetry/grafana/provisioning/dashboards/example.json index 783b90fc77..cd26f39d57 100644 --- a/localenv/telemetry/grafana/provisioning/dashboards/example.json +++ b/localenv/telemetry/grafana/provisioning/dashboards/example.json @@ -63,9 +63,7 @@ "orientation": "auto", "percentChangeColorMode": "standard", "reduceOptions": { - "calcs": [ - "lastNotNull" - ], + "calcs": ["lastNotNull"], "fields": "", "values": false }, @@ -135,9 +133,7 @@ "orientation": "auto", "percentChangeColorMode": "standard", "reduceOptions": { - "calcs": [ - "lastNotNull" - ], + "calcs": ["lastNotNull"], "fields": "", "values": false }, @@ -233,9 +229,7 @@ "orientation": "auto", "percentChangeColorMode": "standard", "reduceOptions": { - "calcs": [ - "lastNotNull" - ], + "calcs": ["lastNotNull"], "fields": "", "values": false }, @@ -333,9 +327,7 @@ "namePlacement": "auto", "orientation": "horizontal", "reduceOptions": { - "calcs": [ - "lastNotNull" - ], + "calcs": ["lastNotNull"], "fields": "", "values": false }, @@ -408,9 +400,7 @@ "footer": { "countRows": false, "fields": "", - "reducer": [ - "sum" - ], + "reducer": ["sum"], "show": false }, "showHeader": true, @@ -439,9 +429,7 @@ "operator": "=", "scope": "resource", "tag": "service.name", - "value": [ - "RAFIKI_NETWORK" - ], + "value": ["RAFIKI_NETWORK"], "valueType": "string" }, { @@ -541,9 +529,7 @@ "id": 10, "options": { "legend": { - "calcs": [ - "p95" - ], + "calcs": ["p95"], "displayMode": "table", "placement": "right", "showLegend": true @@ -745,9 +731,7 @@ "id": 9, "options": { "legend": { - "calcs": [ - "p95" - ], + "calcs": ["p95"], "displayMode": "table", "placement": "right", "showLegend": true @@ -910,9 +894,7 @@ "id": 16, "options": { "legend": { - "calcs": [ - "p95" - ], + "calcs": ["p95"], "displayMode": "table", "placement": "right", "showLegend": true @@ -1024,9 +1006,7 @@ "id": 14, "options": { "legend": { - "calcs": [ - "p95" - ], + "calcs": ["p95"], "displayMode": "table", "placement": "right", "showLegend": true @@ -1228,9 +1208,7 @@ "id": 12, "options": { "legend": { - "calcs": [ - "p95" - ], + "calcs": ["p95"], "displayMode": "table", "placement": "right", "showLegend": true @@ -1346,7 +1324,7 @@ "overrides": [] }, "gridPos": { - "h": 6, + "h": 7, "w": 12, "x": 12, "y": 30 @@ -1354,9 +1332,7 @@ "id": 7, "options": { "legend": { - "calcs": [ - "p95" - ], + "calcs": ["p95"], "displayMode": "table", "placement": "right", "showLegend": true @@ -1519,9 +1495,7 @@ "id": 11, "options": { "legend": { - "calcs": [ - "p95" - ], + "calcs": ["p95"], "displayMode": "table", "placement": "right", "showLegend": true @@ -1815,4 +1789,4 @@ "uid": "fdr58stwkr6yof", "version": 1, "weekStart": "" -} \ No newline at end of file +} From 522b3395728c3b108c2d2737675d04dd06c32f38 Mon Sep 17 00:00:00 2001 From: Blair Currey <12960453+BlairCurrey@users.noreply.github.com> Date: Tue, 24 Sep 2024 13:24:08 -0400 Subject: [PATCH 12/31] fix(backend): rm problematic connector middleware timers --- .../ilp/connector/core/middleware/balance.ts | 9 -- .../core/middleware/error-handler.ts | 9 -- .../core/middleware/stream-address.ts | 4 - .../src/payment-method/ilp/connector/index.ts | 108 +++++------------- 4 files changed, 27 insertions(+), 103 deletions(-) diff --git a/packages/backend/src/payment-method/ilp/connector/core/middleware/balance.ts b/packages/backend/src/payment-method/ilp/connector/core/middleware/balance.ts index 52af882fe0..512ef863d1 100644 --- a/packages/backend/src/payment-method/ilp/connector/core/middleware/balance.ts +++ b/packages/backend/src/payment-method/ilp/connector/core/middleware/balance.ts @@ -20,9 +20,6 @@ export function createBalanceMiddleware(): ILPMiddleware { }: ILPContext, next: () => Promise ): Promise => { - const stopTimer = services.telemetry.startTimer('balanceMiddleware', { - callName: 'balanceMiddleware' - }) const { amount } = request.prepare const logger = services.logger.child( { module: 'balance-middleware' }, @@ -34,7 +31,6 @@ export function createBalanceMiddleware(): ILPMiddleware { // Ignore zero amount packets if (amount === '0') { await next() - stopTimer() return } @@ -55,7 +51,6 @@ export function createBalanceMiddleware(): ILPMiddleware { }, 'Could not get rates' ) - stopTimer() throw new CannotReceiveError( `Exchange rate error: ${destinationAmountOrError}` ) @@ -65,7 +60,6 @@ export function createBalanceMiddleware(): ILPMiddleware { if (state.unfulfillable) { await next() - stopTimer() return } @@ -91,10 +85,8 @@ export function createBalanceMiddleware(): ILPMiddleware { switch (trxOrError) { case TransferError.InsufficientBalance: case TransferError.InsufficientLiquidity: - stopTimer() throw new InsufficientLiquidityError(trxOrError) default: - stopTimer() // TODO: map transfer errors to ILP errors ctxThrow(500, destinationAmountOrError.toString()) } @@ -118,7 +110,6 @@ export function createBalanceMiddleware(): ILPMiddleware { await trx.void() } } - stopTimer() } } } diff --git a/packages/backend/src/payment-method/ilp/connector/core/middleware/error-handler.ts b/packages/backend/src/payment-method/ilp/connector/core/middleware/error-handler.ts index 87368fb523..63802851c8 100644 --- a/packages/backend/src/payment-method/ilp/connector/core/middleware/error-handler.ts +++ b/packages/backend/src/payment-method/ilp/connector/core/middleware/error-handler.ts @@ -11,15 +11,8 @@ export function createIncomingErrorHandlerMiddleware( serverAddress: string ): ILPMiddleware { return async (ctx: ILPContext, next: () => Promise): Promise => { - let stopTimer try { await next() - stopTimer = ctx.services.telemetry.startTimer( - 'createIncomingErrorHandlerMiddleware', - { - callName: 'createIncomingErrorHandlerMiddleware' - } - ) if (!ctx.response.rawReply) { ctx.services.logger.error('handler did not return a valid value.') throw new Error('handler did not return a value.') @@ -44,8 +37,6 @@ export function createIncomingErrorHandlerMiddleware( name: '' }) } - } finally { - stopTimer && stopTimer() } } } diff --git a/packages/backend/src/payment-method/ilp/connector/core/middleware/stream-address.ts b/packages/backend/src/payment-method/ilp/connector/core/middleware/stream-address.ts index 132429ec74..2e4fd99775 100644 --- a/packages/backend/src/payment-method/ilp/connector/core/middleware/stream-address.ts +++ b/packages/backend/src/payment-method/ilp/connector/core/middleware/stream-address.ts @@ -5,13 +5,9 @@ export function createStreamAddressMiddleware(): ILPMiddleware { { request, services: { streamServer, telemetry }, state }: ILPContext, next: () => Promise ): Promise => { - const stopTimer = telemetry.startTimer('createStreamAddressMiddleware', { - callName: 'createStreamAddressMiddleware' - }) const { destination } = request.prepare // To preserve sender privacy, the accountId wasn't included in the original destination address. state.streamDestination = streamServer.decodePaymentTag(destination) - stopTimer() await next() } } diff --git a/packages/backend/src/payment-method/ilp/connector/index.ts b/packages/backend/src/payment-method/ilp/connector/index.ts index 624b982df1..8dd2f27f0d 100644 --- a/packages/backend/src/payment-method/ilp/connector/index.ts +++ b/packages/backend/src/payment-method/ilp/connector/index.ts @@ -68,103 +68,49 @@ export async function createConnectorService({ streamServer, telemetry }, - compose( - [ - // Incoming Rules - { - name: 'createIncomingErrorHandlerMiddleware', - fn: createIncomingErrorHandlerMiddleware(ilpAddress) - }, - { - name: 'createStreamAddressMiddleware', - fn: createStreamAddressMiddleware() - }, - { - name: 'createAccountMiddleware', - fn: createAccountMiddleware(ilpAddress) - }, - { - name: 'createIncomingMaxPacketAmountMiddleware', - fn: createIncomingMaxPacketAmountMiddleware() - }, - { - name: 'createIncomingRateLimitMiddleware', - fn: createIncomingRateLimitMiddleware({}) - }, - { - name: 'createIncomingThroughputMiddleware', - fn: createIncomingThroughputMiddleware() - }, - { - name: 'createIldcpMiddleware', - fn: createIldcpMiddleware(ilpAddress) - }, + compose([ + // Incoming Rules + createIncomingErrorHandlerMiddleware(ilpAddress), + createStreamAddressMiddleware(), + createAccountMiddleware(ilpAddress), + createIncomingMaxPacketAmountMiddleware(), + createIncomingRateLimitMiddleware({}), + createIncomingThroughputMiddleware(), + createIldcpMiddleware(ilpAddress), - // Local pay - { name: 'createBalanceMiddleware', fn: createBalanceMiddleware() }, + // Local pay + createBalanceMiddleware(), - // Outgoing Rules - { name: 'createStreamController', fn: createStreamController() }, - { - name: 'createOutgoingThroughputMiddleware', - fn: createOutgoingThroughputMiddleware() - }, - { - name: 'createOutgoingReduceExpiryMiddleware', - fn: createOutgoingReduceExpiryMiddleware({}) - }, - { - name: 'createOutgoingExpireMiddleware', - fn: createOutgoingExpireMiddleware() - }, - { - name: 'createOutgoingValidateFulfillmentMiddleware', - fn: createOutgoingValidateFulfillmentMiddleware() - }, + // Outgoing Rules + createStreamController(), + createOutgoingThroughputMiddleware(), + createOutgoingReduceExpiryMiddleware({}), + createOutgoingExpireMiddleware(), + createOutgoingValidateFulfillmentMiddleware(), - // Send outgoing packets - { name: 'createClientController', fn: createClientController() } - ], - telemetry - ) + // Send outgoing packets + createClientController() + ]) ) } // Adapted from koa-compose -function compose( - middlewares: { name: string; fn: ILPMiddleware }[], - telemetry: TelemetryService -): ILPMiddleware { +function compose(middlewares: ILPMiddleware[]): ILPMiddleware { return function (ctx: ILPContext, next: () => Promise): Promise { // last called middleware let index = -1 - - const stopTimer = telemetry.startTimer('connector_middleware_stack', { - callName: 'connector_middleware_stack' - }) - - async function dispatch(i: number): Promise { + return (function dispatch(i: number): Promise { if (i <= index) return Promise.reject(new Error('next() called multiple times')) index = i - const m = middlewares[i] - if (i === middlewares.length) m.fn = next - if (!m.fn) return Promise.resolve() + let fn = middlewares[i] + if (i === middlewares.length) fn = next + if (!fn) return Promise.resolve() try { - const stopTimerMiddleware = telemetry.startTimer( - 'connector_middleware', - { callName: m.name } - ) - const p = Promise.resolve(m.fn(ctx, dispatch.bind(null, i + 1))) - stopTimerMiddleware && stopTimerMiddleware() - return p + return Promise.resolve(fn(ctx, dispatch.bind(null, i + 1))) } catch (err) { return Promise.reject(err) } - } - - return dispatch(0).finally(() => { - stopTimer && stopTimer() - }) + })(0) } } From 3033c2acbb3998c94859f67fc1b466020cf6a76f Mon Sep 17 00:00:00 2001 From: Blair Currey <12960453+BlairCurrey@users.noreply.github.com> Date: Tue, 24 Sep 2024 13:24:57 -0400 Subject: [PATCH 13/31] fix(backend): fix deposit outgoing payment liquidity performance metrics --- .../provisioning/dashboards/example.json | 212 ++++++------------ .../src/graphql/resolvers/liquidity.ts | 18 +- .../open_payments/payment/outgoing/service.ts | 11 +- 3 files changed, 79 insertions(+), 162 deletions(-) diff --git a/localenv/telemetry/grafana/provisioning/dashboards/example.json b/localenv/telemetry/grafana/provisioning/dashboards/example.json index cd26f39d57..7feb19f961 100644 --- a/localenv/telemetry/grafana/provisioning/dashboards/example.json +++ b/localenv/telemetry/grafana/provisioning/dashboards/example.json @@ -63,7 +63,9 @@ "orientation": "auto", "percentChangeColorMode": "standard", "reduceOptions": { - "calcs": ["lastNotNull"], + "calcs": [ + "lastNotNull" + ], "fields": "", "values": false }, @@ -133,7 +135,9 @@ "orientation": "auto", "percentChangeColorMode": "standard", "reduceOptions": { - "calcs": ["lastNotNull"], + "calcs": [ + "lastNotNull" + ], "fields": "", "values": false }, @@ -229,7 +233,9 @@ "orientation": "auto", "percentChangeColorMode": "standard", "reduceOptions": { - "calcs": ["lastNotNull"], + "calcs": [ + "lastNotNull" + ], "fields": "", "values": false }, @@ -327,7 +333,9 @@ "namePlacement": "auto", "orientation": "horizontal", "reduceOptions": { - "calcs": ["lastNotNull"], + "calcs": [ + "lastNotNull" + ], "fields": "", "values": false }, @@ -400,7 +408,9 @@ "footer": { "countRows": false, "fields": "", - "reducer": ["sum"], + "reducer": [ + "sum" + ], "show": false }, "showHeader": true, @@ -429,7 +439,9 @@ "operator": "=", "scope": "resource", "tag": "service.name", - "value": ["RAFIKI_NETWORK"], + "value": [ + "RAFIKI_NETWORK" + ], "valueType": "string" }, { @@ -529,7 +541,9 @@ "id": 10, "options": { "legend": { - "calcs": ["p95"], + "calcs": [ + "p95" + ], "displayMode": "table", "placement": "right", "showLegend": true @@ -731,7 +745,9 @@ "id": 9, "options": { "legend": { - "calcs": ["p95"], + "calcs": [ + "p95" + ], "displayMode": "table", "placement": "right", "showLegend": true @@ -881,7 +897,8 @@ "value": 80 } ] - } + }, + "unit": "ms" }, "overrides": [] }, @@ -894,7 +911,9 @@ "id": 16, "options": { "legend": { - "calcs": ["p95"], + "calcs": [ + "p95" + ], "displayMode": "table", "placement": "right", "showLegend": true @@ -911,7 +930,7 @@ "uid": "PBFA97CFB590B2093" }, "editorMode": "code", - "expr": "rate(depositOutgoingPaymentLiquidity_sum[$__rate_interval])/rate(depositOutgoingPaymentLiquidity_count[$__rate_interval])", + "expr": "rate(deposit_outgoing_payment_liquidity_ms_sum[$__rate_interval])/rate(deposit_outgoing_payment_liquidity_ms_count[$__rate_interval])", "instant": false, "legendFormat": "{{callName}}", "range": true, @@ -923,12 +942,25 @@ "uid": "${PrometheusDS}" }, "editorMode": "code", - "expr": "rate(fundPayment_sum[$__rate_interval])/rate(fundPayment_count[$__rate_interval])", + "expr": "rate(fund_payment_ms_sum[$__rate_interval])/rate(fund_payment_ms_count[$__rate_interval])", "hide": false, "instant": false, "legendFormat": "{{callName}}", "range": true, - "refId": "B" + "refId": "C" + }, + { + "datasource": { + "type": "prometheus", + "uid": "${PrometheusDS}" + }, + "editorMode": "code", + "expr": "rate(wh_get_latest_ms_sum[$__rate_interval])/rate(wh_get_latest_ms_count[$__rate_interval])", + "hide": false, + "instant": false, + "legendFormat": "{{callName}}", + "range": true, + "refId": "D" } ], "title": "Deposit Outgoing Payment Liquidity ", @@ -1006,7 +1038,9 @@ "id": 14, "options": { "legend": { - "calcs": ["p95"], + "calcs": [ + "p95" + ], "displayMode": "table", "placement": "right", "showLegend": true @@ -1137,130 +1171,6 @@ "title": "Outgoing Payment Service Create Time (ms)", "type": "timeseries" }, - { - "datasource": { - "name": "${PrometheusDS}", - "type": "prometheus", - "uid": "${PrometheusDS}" - }, - "fieldConfig": { - "defaults": { - "color": { - "mode": "palette-classic" - }, - "custom": { - "axisBorderShow": false, - "axisCenteredZero": false, - "axisColorMode": "text", - "axisLabel": "", - "axisPlacement": "auto", - "barAlignment": 0, - "barWidthFactor": 0.6, - "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 - } - ] - }, - "unit": "ms" - }, - "overrides": [] - }, - "gridPos": { - "h": 7, - "w": 12, - "x": 0, - "y": 30 - }, - "id": 12, - "options": { - "legend": { - "calcs": ["p95"], - "displayMode": "table", - "placement": "right", - "showLegend": true - }, - "tooltip": { - "mode": "single", - "sort": "none" - } - }, - "targets": [ - { - "datasource": { - "type": "prometheus", - "uid": "${PrometheusDS}" - }, - "editorMode": "code", - "expr": "sum by (callName) (rate(connector_middleware_sum[$__rate_interval])/rate(connector_middleware_count[$__rate_interval]))", - "instant": false, - "legendFormat": "{{caller}}", - "range": true, - "refId": "A" - }, - { - "datasource": { - "type": "prometheus", - "uid": "${PrometheusDS}" - }, - "editorMode": "code", - "expr": "sum by (callName) (rate(connector_middleware_stack_sum[$__rate_interval])/rate(connector_middleware_stack_count[$__rate_interval]))", - "hide": false, - "instant": false, - "legendFormat": "__auto", - "range": true, - "refId": "B" - }, - { - "datasource": { - "type": "prometheus", - "uid": "${PrometheusDS}" - }, - "editorMode": "code", - "expr": "sum by (callName) (rate(balanceMiddleware_sum[$__rate_interval])/rate(balanceMiddleware_count[$__rate_interval]))", - "hide": false, - "instant": false, - "legendFormat": "__auto", - "range": true, - "refId": "C" - } - ], - "title": "ILP Connector", - "type": "timeseries" - }, { "datasource": { "default": false, @@ -1326,13 +1236,15 @@ "gridPos": { "h": 7, "w": 12, - "x": 12, + "x": 0, "y": 30 }, "id": 7, "options": { "legend": { - "calcs": ["p95"], + "calcs": [ + "p95" + ], "displayMode": "table", "placement": "right", "showLegend": true @@ -1488,14 +1400,16 @@ }, "gridPos": { "h": 7, - "w": 24, - "x": 0, - "y": 37 + "w": 12, + "x": 12, + "y": 30 }, "id": 11, "options": { "legend": { - "calcs": ["p95"], + "calcs": [ + "p95" + ], "displayMode": "table", "placement": "right", "showLegend": true @@ -1587,7 +1501,7 @@ "h": 8, "w": 12, "x": 0, - "y": 44 + "y": 37 }, "id": 2, "interval": "15s", @@ -1687,7 +1601,7 @@ "h": 8, "w": 12, "x": 12, - "y": 44 + "y": 37 }, "id": 1, "interval": "15s", @@ -1768,7 +1682,7 @@ ] }, "time": { - "from": "now-30m", + "from": "now-5m", "to": "now" }, "timepicker": { @@ -1787,6 +1701,6 @@ "timezone": "browser", "title": "Example Dashboard", "uid": "fdr58stwkr6yof", - "version": 1, + "version": 3, "weekStart": "" -} +} \ No newline at end of file diff --git a/packages/backend/src/graphql/resolvers/liquidity.ts b/packages/backend/src/graphql/resolvers/liquidity.ts index ad76f0493e..d767e03fe2 100644 --- a/packages/backend/src/graphql/resolvers/liquidity.ts +++ b/packages/backend/src/graphql/resolvers/liquidity.ts @@ -441,15 +441,22 @@ export const depositOutgoingPaymentLiquidity: MutationResolvers[' ctx ): Promise => { const telemetry = await ctx.container.use('telemetry') - const stopTimer = telemetry.startTimer('depositOutgoingPaymentLiquidity', { - callName: 'depositOutgoingPaymentLiquidity' - }) + const stopTimer = telemetry.startTimer( + 'deposit_outgoing_payment_liquidity_ms', + { + callName: 'depositOutgoingPaymentLiquidity' + } + ) const { outgoingPaymentId } = args.input const webhookService = await ctx.container.use('webhookService') + const stopTimerWh = telemetry.startTimer('wh_get_latest_ms', { + callName: 'webhookService.getLatestByResourceId' + }) const event = await webhookService.getLatestByResourceId({ outgoingPaymentId, types: [OutgoingPaymentDepositType.PaymentCreated] }) + stopTimerWh() if (!event || !isOutgoingPaymentEvent(event)) { stopTimer() throw new GraphQLError(errorToMessage[LiquidityError.InvalidId], { @@ -466,11 +473,16 @@ export const depositOutgoingPaymentLiquidity: MutationResolvers[' const outgoingPaymentService = await ctx.container.use( 'outgoingPaymentService' ) + const stopTimerFund = telemetry.startTimer('fund_payment_ms', { + callName: 'outgoingPaymentService.fund' + }) const paymentOrErr = await outgoingPaymentService.fund({ id: outgoingPaymentId, amount: BigInt(event.data.debitAmount.value), transferId: event.id }) + stopTimerFund() + if (isFundingError(paymentOrErr)) { stopTimer() throw new GraphQLError(fundingErrorToMessage[paymentOrErr], { diff --git a/packages/backend/src/open_payments/payment/outgoing/service.ts b/packages/backend/src/open_payments/payment/outgoing/service.ts index b6b7e34133..a5f1ad4580 100644 --- a/packages/backend/src/open_payments/payment/outgoing/service.ts +++ b/packages/backend/src/open_payments/payment/outgoing/service.ts @@ -598,11 +598,7 @@ async function fundPayment( deps: ServiceDependencies, { id, amount, transferId }: FundOutgoingPaymentOptions ): Promise { - const stopTimer = deps.telemetry.startTimer('fundPayment', { - callName: 'fundPayment' - }) - - const outgoingPaymentOrError = deps.knex.transaction(async (trx) => { + return await deps.knex.transaction(async (trx) => { const payment = await OutgoingPayment.query(trx) .findById(id) .forUpdate() @@ -627,7 +623,6 @@ async function fundPayment( if (err instanceof AccountAlreadyExistsError) { // Do nothing. } else { - stopTimer() throw err } } @@ -643,10 +638,6 @@ async function fundPayment( await payment.$query(trx).patch({ state: OutgoingPaymentState.Sending }) return await addSentAmount(deps, payment) }) - - stopTimer() - - return outgoingPaymentOrError } async function getWalletAddressPage( From 0ede073b8a8fad5f8027c629f475dcd70daac473 Mon Sep 17 00:00:00 2001 From: Blair Currey <12960453+BlairCurrey@users.noreply.github.com> Date: Tue, 24 Sep 2024 13:27:38 -0400 Subject: [PATCH 14/31] chore: format --- .../provisioning/dashboards/example.json | 50 +++++-------------- .../core/middleware/stream-address.ts | 2 +- 2 files changed, 14 insertions(+), 38 deletions(-) diff --git a/localenv/telemetry/grafana/provisioning/dashboards/example.json b/localenv/telemetry/grafana/provisioning/dashboards/example.json index 7feb19f961..04a41a7058 100644 --- a/localenv/telemetry/grafana/provisioning/dashboards/example.json +++ b/localenv/telemetry/grafana/provisioning/dashboards/example.json @@ -63,9 +63,7 @@ "orientation": "auto", "percentChangeColorMode": "standard", "reduceOptions": { - "calcs": [ - "lastNotNull" - ], + "calcs": ["lastNotNull"], "fields": "", "values": false }, @@ -135,9 +133,7 @@ "orientation": "auto", "percentChangeColorMode": "standard", "reduceOptions": { - "calcs": [ - "lastNotNull" - ], + "calcs": ["lastNotNull"], "fields": "", "values": false }, @@ -233,9 +229,7 @@ "orientation": "auto", "percentChangeColorMode": "standard", "reduceOptions": { - "calcs": [ - "lastNotNull" - ], + "calcs": ["lastNotNull"], "fields": "", "values": false }, @@ -333,9 +327,7 @@ "namePlacement": "auto", "orientation": "horizontal", "reduceOptions": { - "calcs": [ - "lastNotNull" - ], + "calcs": ["lastNotNull"], "fields": "", "values": false }, @@ -408,9 +400,7 @@ "footer": { "countRows": false, "fields": "", - "reducer": [ - "sum" - ], + "reducer": ["sum"], "show": false }, "showHeader": true, @@ -439,9 +429,7 @@ "operator": "=", "scope": "resource", "tag": "service.name", - "value": [ - "RAFIKI_NETWORK" - ], + "value": ["RAFIKI_NETWORK"], "valueType": "string" }, { @@ -541,9 +529,7 @@ "id": 10, "options": { "legend": { - "calcs": [ - "p95" - ], + "calcs": ["p95"], "displayMode": "table", "placement": "right", "showLegend": true @@ -745,9 +731,7 @@ "id": 9, "options": { "legend": { - "calcs": [ - "p95" - ], + "calcs": ["p95"], "displayMode": "table", "placement": "right", "showLegend": true @@ -911,9 +895,7 @@ "id": 16, "options": { "legend": { - "calcs": [ - "p95" - ], + "calcs": ["p95"], "displayMode": "table", "placement": "right", "showLegend": true @@ -1038,9 +1020,7 @@ "id": 14, "options": { "legend": { - "calcs": [ - "p95" - ], + "calcs": ["p95"], "displayMode": "table", "placement": "right", "showLegend": true @@ -1242,9 +1222,7 @@ "id": 7, "options": { "legend": { - "calcs": [ - "p95" - ], + "calcs": ["p95"], "displayMode": "table", "placement": "right", "showLegend": true @@ -1407,9 +1385,7 @@ "id": 11, "options": { "legend": { - "calcs": [ - "p95" - ], + "calcs": ["p95"], "displayMode": "table", "placement": "right", "showLegend": true @@ -1703,4 +1679,4 @@ "uid": "fdr58stwkr6yof", "version": 3, "weekStart": "" -} \ No newline at end of file +} diff --git a/packages/backend/src/payment-method/ilp/connector/core/middleware/stream-address.ts b/packages/backend/src/payment-method/ilp/connector/core/middleware/stream-address.ts index 2e4fd99775..a4b9158c63 100644 --- a/packages/backend/src/payment-method/ilp/connector/core/middleware/stream-address.ts +++ b/packages/backend/src/payment-method/ilp/connector/core/middleware/stream-address.ts @@ -2,7 +2,7 @@ import { ILPMiddleware, ILPContext } from '../rafiki' export function createStreamAddressMiddleware(): ILPMiddleware { return async ( - { request, services: { streamServer, telemetry }, state }: ILPContext, + { request, services: { streamServer }, state }: ILPContext, next: () => Promise ): Promise => { const { destination } = request.prepare From a3efc733b503e4647abf50361263df72a5f0cfbd Mon Sep 17 00:00:00 2001 From: Blair Currey <12960453+BlairCurrey@users.noreply.github.com> Date: Tue, 24 Sep 2024 13:30:47 -0400 Subject: [PATCH 15/31] chore: rename metric for case --- .../telemetry/grafana/provisioning/dashboards/example.json | 4 ++-- packages/backend/src/accounting/psql/balance.ts | 4 ++-- 2 files changed, 4 insertions(+), 4 deletions(-) diff --git a/localenv/telemetry/grafana/provisioning/dashboards/example.json b/localenv/telemetry/grafana/provisioning/dashboards/example.json index 04a41a7058..b57be049b7 100644 --- a/localenv/telemetry/grafana/provisioning/dashboards/example.json +++ b/localenv/telemetry/grafana/provisioning/dashboards/example.json @@ -1316,7 +1316,7 @@ }, { "datasource": { - "name": "${PrometheusDS}", + "default": false, "type": "prometheus", "uid": "${PrometheusDS}" }, @@ -1402,7 +1402,7 @@ "uid": "${PrometheusDS}" }, "editorMode": "code", - "expr": "sum by (callName) (rate(psql_getAccountBalances_sum[$__rate_interval])/rate(psql_getAccountBalances_count[$__rate_interval]))", + "expr": "sum by (callName) (rate(psql_get_account_balances_sum[$__rate_interval])/rate(psql_get_account_balances_count[$__rate_interval]))", "instant": false, "legendFormat": "__auto", "range": true, diff --git a/packages/backend/src/accounting/psql/balance.ts b/packages/backend/src/accounting/psql/balance.ts index e130f136ff..3cb314f010 100644 --- a/packages/backend/src/accounting/psql/balance.ts +++ b/packages/backend/src/accounting/psql/balance.ts @@ -14,8 +14,8 @@ export async function getAccountBalances( account: LedgerAccount, trx?: TransactionOrKnex ): Promise { - const stopTimer = deps.telemetry.startTimer('psql_getAccountBalances', { - callName: 'psql_getAccountBalances' + const stopTimer = deps.telemetry.startTimer('psql_get_account_balances', { + callName: 'psql_get_account_balances' }) try { const queryResult = await (trx ?? deps.knex).raw( From 84f825fadc86d95aac4a394af4e0cd90a699e163 Mon Sep 17 00:00:00 2001 From: Blair Currey <12960453+BlairCurrey@users.noreply.github.com> Date: Tue, 24 Sep 2024 13:42:29 -0400 Subject: [PATCH 16/31] fix(backend): balance tests, missing tel dep --- packages/backend/src/accounting/psql/balance.test.ts | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/packages/backend/src/accounting/psql/balance.test.ts b/packages/backend/src/accounting/psql/balance.test.ts index 057d38e733..559bbb229c 100644 --- a/packages/backend/src/accounting/psql/balance.test.ts +++ b/packages/backend/src/accounting/psql/balance.test.ts @@ -24,7 +24,8 @@ describe('Balances', (): void => { appContainer = await createTestApp(deps) serviceDeps = { logger: await deps.use('logger'), - knex: await deps.use('knex') + knex: await deps.use('knex'), + telemetry: await deps.use('telemetry') } knex = appContainer.knex }) From dfd8b2b04e54920433756aee169fa3d831baae9f Mon Sep 17 00:00:00 2001 From: Blair Currey <12960453+BlairCurrey@users.noreply.github.com> Date: Tue, 24 Sep 2024 14:09:37 -0400 Subject: [PATCH 17/31] feat(backend): switch tel servive impl in dep definition --- packages/backend/src/index.ts | 11 ++++- .../backend/src/telemetry/service.test.ts | 41 ++++++++++--------- packages/backend/src/telemetry/service.ts | 19 +++------ 3 files changed, 35 insertions(+), 36 deletions(-) diff --git a/packages/backend/src/index.ts b/packages/backend/src/index.ts index fd60a245e5..dfa64c0ef4 100644 --- a/packages/backend/src/index.ts +++ b/packages/backend/src/index.ts @@ -51,7 +51,10 @@ import { createIlpPaymentService } from './payment-method/ilp/service' import { createSPSPRoutes } from './payment-method/ilp/spsp/routes' import { createStreamCredentialsService } from './payment-method/ilp/stream-credentials/service' import { createRatesService } from './rates/service' -import { createTelemetryService } from './telemetry/service' +import { + createTelemetryService, + createNoopTelemetryService +} from './telemetry/service' import { createWebhookService } from './webhook/service' BigInt.prototype.toJSON = function () { @@ -142,6 +145,11 @@ export function initIocContainer( container.singleton('telemetry', async (deps) => { const config = await deps.use('config') + + if (!config.enableTelemetry) { + return createNoopTelemetryService() + } + return createTelemetryService({ logger: await deps.use('logger'), aseRatesService: await deps.use('ratesService'), @@ -149,7 +157,6 @@ export function initIocContainer( instanceName: config.instanceName, collectorUrls: config.openTelemetryCollectors, exportIntervalMillis: config.openTelemetryExportInterval, - enableTelemetry: config.enableTelemetry, baseAssetCode: 'USD', baseScale: 4 }) diff --git a/packages/backend/src/telemetry/service.test.ts b/packages/backend/src/telemetry/service.test.ts index e507ff470c..da0ae289cb 100644 --- a/packages/backend/src/telemetry/service.test.ts +++ b/packages/backend/src/telemetry/service.test.ts @@ -6,11 +6,9 @@ import { ConvertError, RatesService } from '../rates/service' import { TestContainer, createTestApp } from '../tests/app' import { mockCounter, mockHistogram } from '../tests/telemetry' import { - createTelemetryService, NoopTelemetryServiceImpl, TelemetryService, - TelemetryServiceImpl, - TelemetryServiceDependencies + TelemetryServiceImpl } from './service' import { Counter, Histogram } from '@opentelemetry/api' import { privacy } from './privacy' @@ -66,9 +64,9 @@ describe('Telemetry Service', () => { }) appContainer = await createTestApp(deps) - telemetryService = await deps.use('telemetry')! - aseRatesService = await deps.use('ratesService')! - internalRatesService = await deps.use('internalRatesService')! + telemetryService = await deps.use('telemetry') + aseRatesService = await deps.use('ratesService') + internalRatesService = await deps.use('internalRatesService') mockRatesApi(exchangeRatesUrl, (base) => { apiRequestCount++ @@ -80,6 +78,10 @@ describe('Telemetry Service', () => { await appContainer.shutdown() }) + test('telemetryService instance should be real implementation', () => { + expect(telemetryService instanceof TelemetryServiceImpl).toBe(true) + }) + it('should create a counter with source attribute for a new metric', () => { const name = 'test_counter' const amount = 1 @@ -441,29 +443,28 @@ describe('Telemetry Service', () => { }) }) describe('Telemetry Disabled', () => { - let deps: TelemetryServiceDependencies + let deps: IocContract + let appContainer: TestContainer + let telemetryService: TelemetryService - beforeEach(() => { - deps = { + beforeAll(async (): Promise => { + deps = initIocContainer({ + ...Config, enableTelemetry: false - } as TelemetryServiceDependencies + }) + appContainer = await createTestApp(deps) + telemetryService = await deps.use('telemetry')! }) - test('should return NoopTelemetryServiceImpl when enableTelemetry is false', () => { - const telemetryService = createTelemetryService(deps) - - expect(telemetryService).toBeInstanceOf(NoopTelemetryServiceImpl) + afterAll(async (): Promise => { + await appContainer.shutdown() }) - test('should return TelemetryServiceImpl when enableTelemetry is true', () => { - deps.enableTelemetry = true - const telemetryService = createTelemetryService(deps) - - expect(telemetryService).toBeInstanceOf(TelemetryServiceImpl) + test('telemetryService instance should be no-op implementation', () => { + expect(telemetryService instanceof NoopTelemetryServiceImpl).toBe(true) }) test('NoopTelemetryServiceImpl should not get meter ', () => { - const telemetryService = createTelemetryService(deps) telemetryService.recordHistogram('testhistogram', 1) telemetryService.incrementCounter('testcounter', 1) diff --git a/packages/backend/src/telemetry/service.ts b/packages/backend/src/telemetry/service.ts index 13d4eb6481..520e241964 100644 --- a/packages/backend/src/telemetry/service.ts +++ b/packages/backend/src/telemetry/service.ts @@ -40,7 +40,6 @@ export interface TelemetryServiceDependencies extends BaseService { internalRatesService: RatesService baseAssetCode: string baseScale: number - enableTelemetry: boolean } const METER_NAME = 'Rafiki' @@ -48,12 +47,13 @@ const METER_NAME = 'Rafiki' export function createTelemetryService( deps: TelemetryServiceDependencies ): TelemetryService { - if (!deps.enableTelemetry) { - return new NoopTelemetryServiceImpl(deps) - } return new TelemetryServiceImpl(deps) } +export function createNoopTelemetryService(): TelemetryService { + return new NoopTelemetryServiceImpl() +} + export class TelemetryServiceImpl implements TelemetryService { private instanceName: string private meterProvider?: MeterProvider @@ -223,16 +223,7 @@ export class TelemetryServiceImpl implements TelemetryService { /* eslint-disable @typescript-eslint/no-unused-vars */ export class NoopTelemetryServiceImpl implements TelemetryService { - private instanceName: string - private meterProvider?: MeterProvider - private internalRatesService: RatesService - private aseRatesService: RatesService - - constructor(private deps: TelemetryServiceDependencies) { - this.instanceName = deps.instanceName - this.internalRatesService = deps.internalRatesService - this.aseRatesService = deps.aseRatesService - } + constructor() {} public async shutdown(): Promise { // do nothing From b1b1866d72b2ddc20dec4b5a1a275fd7abc034cc Mon Sep 17 00:00:00 2001 From: Blair Currey <12960453+BlairCurrey@users.noreply.github.com> Date: Wed, 25 Sep 2024 09:01:41 -0400 Subject: [PATCH 18/31] fix(backend): test deps setup --- .../psql/ledger-account/index.test.ts | 3 +- .../psql/ledger-transfer/index.test.ts | 3 +- .../backend/src/telemetry/service.test.ts | 60 +++++++++---------- 3 files changed, 34 insertions(+), 32 deletions(-) diff --git a/packages/backend/src/accounting/psql/ledger-account/index.test.ts b/packages/backend/src/accounting/psql/ledger-account/index.test.ts index fd9c35fff5..4d5b0140ec 100644 --- a/packages/backend/src/accounting/psql/ledger-account/index.test.ts +++ b/packages/backend/src/accounting/psql/ledger-account/index.test.ts @@ -25,7 +25,8 @@ describe('Ledger Account', (): void => { appContainer = await createTestApp(deps) serviceDeps = { logger: await deps.use('logger'), - knex: await deps.use('knex') + knex: await deps.use('knex'), + telemetry: await deps.use('telemetry') } knex = appContainer.knex }) diff --git a/packages/backend/src/accounting/psql/ledger-transfer/index.test.ts b/packages/backend/src/accounting/psql/ledger-transfer/index.test.ts index 86fbb2ec68..239ada549d 100644 --- a/packages/backend/src/accounting/psql/ledger-transfer/index.test.ts +++ b/packages/backend/src/accounting/psql/ledger-transfer/index.test.ts @@ -34,7 +34,8 @@ describe('Ledger Transfer', (): void => { appContainer = await createTestApp(deps) serviceDeps = { logger: await deps.use('logger'), - knex: await deps.use('knex') + knex: await deps.use('knex'), + telemetry: await deps.use('telemetry') } knex = appContainer.knex }) diff --git a/packages/backend/src/telemetry/service.test.ts b/packages/backend/src/telemetry/service.test.ts index da0ae289cb..1af6130519 100644 --- a/packages/backend/src/telemetry/service.test.ts +++ b/packages/backend/src/telemetry/service.test.ts @@ -442,34 +442,34 @@ describe('Telemetry Service', () => { }) }) }) - describe('Telemetry Disabled', () => { - let deps: IocContract - let appContainer: TestContainer - let telemetryService: TelemetryService - - beforeAll(async (): Promise => { - deps = initIocContainer({ - ...Config, - enableTelemetry: false - }) - appContainer = await createTestApp(deps) - telemetryService = await deps.use('telemetry')! - }) - - afterAll(async (): Promise => { - await appContainer.shutdown() - }) - - test('telemetryService instance should be no-op implementation', () => { - expect(telemetryService instanceof NoopTelemetryServiceImpl).toBe(true) - }) - - test('NoopTelemetryServiceImpl should not get meter ', () => { - telemetryService.recordHistogram('testhistogram', 1) - telemetryService.incrementCounter('testcounter', 1) - - expect(mockCounter.add).toHaveBeenCalledTimes(0) - expect(mockHistogram.record).toHaveBeenCalledTimes(0) - }) - }) + // describe('Telemetry Disabled', () => { + // let deps: IocContract + // let appContainer: TestContainer + // let telemetryService: TelemetryService + + // beforeAll(async (): Promise => { + // deps = initIocContainer({ + // ...Config, + // enableTelemetry: false + // }) + // appContainer = await createTestApp(deps) + // telemetryService = await deps.use('telemetry')! + // }) + + // afterAll(async (): Promise => { + // await appContainer.shutdown() + // }) + + // test('telemetryService instance should be no-op implementation', () => { + // expect(telemetryService instanceof NoopTelemetryServiceImpl).toBe(true) + // }) + + // test('NoopTelemetryServiceImpl should not get meter ', () => { + // telemetryService.recordHistogram('testhistogram', 1) + // telemetryService.incrementCounter('testcounter', 1) + + // expect(mockCounter.add).toHaveBeenCalledTimes(0) + // expect(mockHistogram.record).toHaveBeenCalledTimes(0) + // }) + // }) }) From 87e73d3656a9c5f2440a393496b349e24849b0ab Mon Sep 17 00:00:00 2001 From: Blair Currey <12960453+BlairCurrey@users.noreply.github.com> Date: Wed, 25 Sep 2024 09:08:40 -0400 Subject: [PATCH 19/31] chore(backend): cleanup test --- .../backend/src/telemetry/service.test.ts | 36 +------------------ 1 file changed, 1 insertion(+), 35 deletions(-) diff --git a/packages/backend/src/telemetry/service.test.ts b/packages/backend/src/telemetry/service.test.ts index 1af6130519..71bb74099a 100644 --- a/packages/backend/src/telemetry/service.test.ts +++ b/packages/backend/src/telemetry/service.test.ts @@ -5,11 +5,7 @@ import { Config } from '../config/app' import { ConvertError, RatesService } from '../rates/service' import { TestContainer, createTestApp } from '../tests/app' import { mockCounter, mockHistogram } from '../tests/telemetry' -import { - NoopTelemetryServiceImpl, - TelemetryService, - TelemetryServiceImpl -} from './service' +import { TelemetryService, TelemetryServiceImpl } from './service' import { Counter, Histogram } from '@opentelemetry/api' import { privacy } from './privacy' import { mockRatesApi } from '../tests/rates' @@ -442,34 +438,4 @@ describe('Telemetry Service', () => { }) }) }) - // describe('Telemetry Disabled', () => { - // let deps: IocContract - // let appContainer: TestContainer - // let telemetryService: TelemetryService - - // beforeAll(async (): Promise => { - // deps = initIocContainer({ - // ...Config, - // enableTelemetry: false - // }) - // appContainer = await createTestApp(deps) - // telemetryService = await deps.use('telemetry')! - // }) - - // afterAll(async (): Promise => { - // await appContainer.shutdown() - // }) - - // test('telemetryService instance should be no-op implementation', () => { - // expect(telemetryService instanceof NoopTelemetryServiceImpl).toBe(true) - // }) - - // test('NoopTelemetryServiceImpl should not get meter ', () => { - // telemetryService.recordHistogram('testhistogram', 1) - // telemetryService.incrementCounter('testcounter', 1) - - // expect(mockCounter.add).toHaveBeenCalledTimes(0) - // expect(mockHistogram.record).toHaveBeenCalledTimes(0) - // }) - // }) }) From e050a4013b2d524703f5e4378f0c7ae74aebd866 Mon Sep 17 00:00:00 2001 From: Blair Currey <12960453+BlairCurrey@users.noreply.github.com> Date: Wed, 25 Sep 2024 09:34:18 -0400 Subject: [PATCH 20/31] chore: restore erroneously rm test, fix dep --- .../open_payments/receiver/service.test.ts | 3 +- .../backend/src/telemetry/service.test.ts | 36 ++++++++++++++++++- 2 files changed, 37 insertions(+), 2 deletions(-) diff --git a/packages/backend/src/open_payments/receiver/service.test.ts b/packages/backend/src/open_payments/receiver/service.test.ts index a603ba1bc1..ed3d05ebd7 100644 --- a/packages/backend/src/open_payments/receiver/service.test.ts +++ b/packages/backend/src/open_payments/receiver/service.test.ts @@ -63,7 +63,8 @@ describe('Receiver Service', (): void => { incomingPaymentService, remoteIncomingPaymentService, walletAddressService, - streamCredentialsService + streamCredentialsService, + telemetry: await deps.use('telemetry') } }) diff --git a/packages/backend/src/telemetry/service.test.ts b/packages/backend/src/telemetry/service.test.ts index 71bb74099a..da0ae289cb 100644 --- a/packages/backend/src/telemetry/service.test.ts +++ b/packages/backend/src/telemetry/service.test.ts @@ -5,7 +5,11 @@ import { Config } from '../config/app' import { ConvertError, RatesService } from '../rates/service' import { TestContainer, createTestApp } from '../tests/app' import { mockCounter, mockHistogram } from '../tests/telemetry' -import { TelemetryService, TelemetryServiceImpl } from './service' +import { + NoopTelemetryServiceImpl, + TelemetryService, + TelemetryServiceImpl +} from './service' import { Counter, Histogram } from '@opentelemetry/api' import { privacy } from './privacy' import { mockRatesApi } from '../tests/rates' @@ -438,4 +442,34 @@ describe('Telemetry Service', () => { }) }) }) + describe('Telemetry Disabled', () => { + let deps: IocContract + let appContainer: TestContainer + let telemetryService: TelemetryService + + beforeAll(async (): Promise => { + deps = initIocContainer({ + ...Config, + enableTelemetry: false + }) + appContainer = await createTestApp(deps) + telemetryService = await deps.use('telemetry')! + }) + + afterAll(async (): Promise => { + await appContainer.shutdown() + }) + + test('telemetryService instance should be no-op implementation', () => { + expect(telemetryService instanceof NoopTelemetryServiceImpl).toBe(true) + }) + + test('NoopTelemetryServiceImpl should not get meter ', () => { + telemetryService.recordHistogram('testhistogram', 1) + telemetryService.incrementCounter('testcounter', 1) + + expect(mockCounter.add).toHaveBeenCalledTimes(0) + expect(mockHistogram.record).toHaveBeenCalledTimes(0) + }) + }) }) From 328ebbe4f4f3c1a5cff0060c78c1abbf89c757c4 Mon Sep 17 00:00:00 2001 From: Blair Currey <12960453+BlairCurrey@users.noreply.github.com> Date: Wed, 25 Sep 2024 09:36:14 -0400 Subject: [PATCH 21/31] fix(localenv): dashboard visualization name --- .../provisioning/dashboards/example.json | 61 +++++++++++++------ 1 file changed, 42 insertions(+), 19 deletions(-) diff --git a/localenv/telemetry/grafana/provisioning/dashboards/example.json b/localenv/telemetry/grafana/provisioning/dashboards/example.json index b57be049b7..002857ed4b 100644 --- a/localenv/telemetry/grafana/provisioning/dashboards/example.json +++ b/localenv/telemetry/grafana/provisioning/dashboards/example.json @@ -27,6 +27,7 @@ "type": "prometheus", "uid": "${PrometheusDS}" }, + "description": "Crude measure of transactions per second.", "fieldConfig": { "defaults": { "color": { @@ -63,7 +64,9 @@ "orientation": "auto", "percentChangeColorMode": "standard", "reduceOptions": { - "calcs": ["lastNotNull"], + "calcs": [ + "lastNotNull" + ], "fields": "", "values": false }, @@ -86,7 +89,7 @@ "refId": "A" } ], - "title": "Panel Title", + "title": "TPS", "type": "stat" }, { @@ -133,7 +136,9 @@ "orientation": "auto", "percentChangeColorMode": "standard", "reduceOptions": { - "calcs": ["lastNotNull"], + "calcs": [ + "lastNotNull" + ], "fields": "", "values": false }, @@ -229,7 +234,9 @@ "orientation": "auto", "percentChangeColorMode": "standard", "reduceOptions": { - "calcs": ["lastNotNull"], + "calcs": [ + "lastNotNull" + ], "fields": "", "values": false }, @@ -327,7 +334,9 @@ "namePlacement": "auto", "orientation": "horizontal", "reduceOptions": { - "calcs": ["lastNotNull"], + "calcs": [ + "lastNotNull" + ], "fields": "", "values": false }, @@ -400,7 +409,9 @@ "footer": { "countRows": false, "fields": "", - "reducer": ["sum"], + "reducer": [ + "sum" + ], "show": false }, "showHeader": true, @@ -429,7 +440,9 @@ "operator": "=", "scope": "resource", "tag": "service.name", - "value": ["RAFIKI_NETWORK"], + "value": [ + "RAFIKI_NETWORK" + ], "valueType": "string" }, { @@ -529,7 +542,9 @@ "id": 10, "options": { "legend": { - "calcs": ["p95"], + "calcs": [ + "p95" + ], "displayMode": "table", "placement": "right", "showLegend": true @@ -731,7 +746,9 @@ "id": 9, "options": { "legend": { - "calcs": ["p95"], + "calcs": [ + "p95" + ], "displayMode": "table", "placement": "right", "showLegend": true @@ -895,7 +912,9 @@ "id": 16, "options": { "legend": { - "calcs": ["p95"], + "calcs": [ + "p95" + ], "displayMode": "table", "placement": "right", "showLegend": true @@ -1020,7 +1039,9 @@ "id": 14, "options": { "legend": { - "calcs": ["p95"], + "calcs": [ + "p95" + ], "displayMode": "table", "placement": "right", "showLegend": true @@ -1222,7 +1243,9 @@ "id": 7, "options": { "legend": { - "calcs": ["p95"], + "calcs": [ + "p95" + ], "displayMode": "table", "placement": "right", "showLegend": true @@ -1385,7 +1408,9 @@ "id": 11, "options": { "legend": { - "calcs": ["p95"], + "calcs": [ + "p95" + ], "displayMode": "table", "placement": "right", "showLegend": true @@ -1461,8 +1486,7 @@ "mode": "absolute", "steps": [ { - "color": "green", - "value": null + "color": "green" }, { "color": "red", @@ -1561,8 +1585,7 @@ "mode": "absolute", "steps": [ { - "color": "green", - "value": null + "color": "green" }, { "color": "red", @@ -1677,6 +1700,6 @@ "timezone": "browser", "title": "Example Dashboard", "uid": "fdr58stwkr6yof", - "version": 3, + "version": 1, "weekStart": "" -} +} \ No newline at end of file From 5c0603909ffa9e26a03705c44cd055593ac605e0 Mon Sep 17 00:00:00 2001 From: Blair Currey <12960453+BlairCurrey@users.noreply.github.com> Date: Tue, 1 Oct 2024 14:51:36 -0400 Subject: [PATCH 22/31] chore: format --- .../provisioning/dashboards/example.json | 50 +++++-------------- 1 file changed, 13 insertions(+), 37 deletions(-) diff --git a/localenv/telemetry/grafana/provisioning/dashboards/example.json b/localenv/telemetry/grafana/provisioning/dashboards/example.json index 002857ed4b..42ed96baaa 100644 --- a/localenv/telemetry/grafana/provisioning/dashboards/example.json +++ b/localenv/telemetry/grafana/provisioning/dashboards/example.json @@ -64,9 +64,7 @@ "orientation": "auto", "percentChangeColorMode": "standard", "reduceOptions": { - "calcs": [ - "lastNotNull" - ], + "calcs": ["lastNotNull"], "fields": "", "values": false }, @@ -136,9 +134,7 @@ "orientation": "auto", "percentChangeColorMode": "standard", "reduceOptions": { - "calcs": [ - "lastNotNull" - ], + "calcs": ["lastNotNull"], "fields": "", "values": false }, @@ -234,9 +230,7 @@ "orientation": "auto", "percentChangeColorMode": "standard", "reduceOptions": { - "calcs": [ - "lastNotNull" - ], + "calcs": ["lastNotNull"], "fields": "", "values": false }, @@ -334,9 +328,7 @@ "namePlacement": "auto", "orientation": "horizontal", "reduceOptions": { - "calcs": [ - "lastNotNull" - ], + "calcs": ["lastNotNull"], "fields": "", "values": false }, @@ -409,9 +401,7 @@ "footer": { "countRows": false, "fields": "", - "reducer": [ - "sum" - ], + "reducer": ["sum"], "show": false }, "showHeader": true, @@ -440,9 +430,7 @@ "operator": "=", "scope": "resource", "tag": "service.name", - "value": [ - "RAFIKI_NETWORK" - ], + "value": ["RAFIKI_NETWORK"], "valueType": "string" }, { @@ -542,9 +530,7 @@ "id": 10, "options": { "legend": { - "calcs": [ - "p95" - ], + "calcs": ["p95"], "displayMode": "table", "placement": "right", "showLegend": true @@ -746,9 +732,7 @@ "id": 9, "options": { "legend": { - "calcs": [ - "p95" - ], + "calcs": ["p95"], "displayMode": "table", "placement": "right", "showLegend": true @@ -912,9 +896,7 @@ "id": 16, "options": { "legend": { - "calcs": [ - "p95" - ], + "calcs": ["p95"], "displayMode": "table", "placement": "right", "showLegend": true @@ -1039,9 +1021,7 @@ "id": 14, "options": { "legend": { - "calcs": [ - "p95" - ], + "calcs": ["p95"], "displayMode": "table", "placement": "right", "showLegend": true @@ -1243,9 +1223,7 @@ "id": 7, "options": { "legend": { - "calcs": [ - "p95" - ], + "calcs": ["p95"], "displayMode": "table", "placement": "right", "showLegend": true @@ -1408,9 +1386,7 @@ "id": 11, "options": { "legend": { - "calcs": [ - "p95" - ], + "calcs": ["p95"], "displayMode": "table", "placement": "right", "showLegend": true @@ -1702,4 +1678,4 @@ "uid": "fdr58stwkr6yof", "version": 1, "weekStart": "" -} \ No newline at end of file +} From fb19aeb4dae55e93a806627034c562a646cc70fa Mon Sep 17 00:00:00 2001 From: Blair Currey <12960453+BlairCurrey@users.noreply.github.com> Date: Wed, 2 Oct 2024 08:14:33 -0400 Subject: [PATCH 23/31] fix(backend): rm dupe class from merge --- packages/backend/src/telemetry/service.ts | 43 ----------------------- 1 file changed, 43 deletions(-) diff --git a/packages/backend/src/telemetry/service.ts b/packages/backend/src/telemetry/service.ts index 6ad6238ef9..c146ce56ab 100644 --- a/packages/backend/src/telemetry/service.ts +++ b/packages/backend/src/telemetry/service.ts @@ -283,46 +283,3 @@ export class NoopTelemetryServiceImpl implements TelemetryService { } } } - -/* eslint-disable @typescript-eslint/no-unused-vars */ -export class NoopTelemetryServiceImpl implements TelemetryService { - constructor() {} - - public async shutdown(): Promise { - // do nothing - } - - public incrementCounter( - name: string, - value: number, - attributes?: Record - ): void { - // do nothing - } - - public recordHistogram( - name: string, - value: number, - attributes?: Record - ): void { - // do nothing - } - - public async incrementCounterWithTransactionAmountDifference( - name: string, - amountSource: { value: bigint; assetCode: string; assetScale: number }, - amountDestination: { value: bigint; assetCode: string; assetScale: number }, - attributes?: Record - ): Promise { - // do nothing - } - - public async incrementCounterWithTransactionAmount( - name: string, - amount: { value: bigint; assetCode: string; assetScale: number }, - attributes: Record = {}, - preservePrivacy = true - ): Promise { - // do nothing - } -} From 4ae9649b1dc8ae3fdde3ef5e367369fa2e95ca34 Mon Sep 17 00:00:00 2001 From: Blair Currey <12960453+BlairCurrey@users.noreply.github.com> Date: Tue, 15 Oct 2024 11:35:28 -0400 Subject: [PATCH 24/31] Update packages/backend/src/open_payments/quote/service.ts Co-authored-by: Max Kurapov --- packages/backend/src/open_payments/quote/service.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/backend/src/open_payments/quote/service.ts b/packages/backend/src/open_payments/quote/service.ts index 2754bd9a47..1517f1ca6b 100644 --- a/packages/backend/src/open_payments/quote/service.ts +++ b/packages/backend/src/open_payments/quote/service.ts @@ -131,7 +131,7 @@ async function createQuote( } ) const receiver = await resolveReceiver(deps, options) - stopTimerReceiver && stopTimerReceiver() + stopTimerReceiver const stopTimerQuote = deps.telemetry.startTimer( 'quote_service_create_get_quote_time_ms', From 2ad883b59a124be96c987f2b23d71aeca382c1ef Mon Sep 17 00:00:00 2001 From: Blair Currey <12960453+BlairCurrey@users.noreply.github.com> Date: Tue, 15 Oct 2024 13:03:30 -0400 Subject: [PATCH 25/31] refactor(backend): use try/catch/finally to enforce stopTimer --- .../src/graphql/resolvers/liquidity.ts | 89 ++++++++++--------- .../open_payments/payment/outgoing/worker.ts | 2 +- .../backend/src/payment-method/ilp/service.ts | 19 ++-- 3 files changed, 58 insertions(+), 52 deletions(-) diff --git a/packages/backend/src/graphql/resolvers/liquidity.ts b/packages/backend/src/graphql/resolvers/liquidity.ts index d767e03fe2..05f428af76 100644 --- a/packages/backend/src/graphql/resolvers/liquidity.ts +++ b/packages/backend/src/graphql/resolvers/liquidity.ts @@ -447,53 +447,56 @@ export const depositOutgoingPaymentLiquidity: MutationResolvers[' callName: 'depositOutgoingPaymentLiquidity' } ) - const { outgoingPaymentId } = args.input - const webhookService = await ctx.container.use('webhookService') - const stopTimerWh = telemetry.startTimer('wh_get_latest_ms', { - callName: 'webhookService.getLatestByResourceId' - }) - const event = await webhookService.getLatestByResourceId({ - outgoingPaymentId, - types: [OutgoingPaymentDepositType.PaymentCreated] - }) - stopTimerWh() - if (!event || !isOutgoingPaymentEvent(event)) { - stopTimer() - throw new GraphQLError(errorToMessage[LiquidityError.InvalidId], { - extensions: { - code: errorToCode[LiquidityError.InvalidId] - } + + try { + const { outgoingPaymentId } = args.input + const webhookService = await ctx.container.use('webhookService') + const stopTimerWh = telemetry.startTimer('wh_get_latest_ms', { + callName: 'webhookService.getLatestByResourceId' }) - } + const event = await webhookService.getLatestByResourceId({ + outgoingPaymentId, + types: [OutgoingPaymentDepositType.PaymentCreated] + }) + stopTimerWh() + if (!event || !isOutgoingPaymentEvent(event)) { + throw new GraphQLError(errorToMessage[LiquidityError.InvalidId], { + extensions: { + code: errorToCode[LiquidityError.InvalidId] + } + }) + } - if (!event.data.debitAmount) { - stopTimer() - throw new Error('No debit amount') - } - const outgoingPaymentService = await ctx.container.use( - 'outgoingPaymentService' - ) - const stopTimerFund = telemetry.startTimer('fund_payment_ms', { - callName: 'outgoingPaymentService.fund' - }) - const paymentOrErr = await outgoingPaymentService.fund({ - id: outgoingPaymentId, - amount: BigInt(event.data.debitAmount.value), - transferId: event.id - }) - stopTimerFund() + if (!event.data.debitAmount) { + throw new Error('No debit amount') + } + const outgoingPaymentService = await ctx.container.use( + 'outgoingPaymentService' + ) + const stopTimerFund = telemetry.startTimer('fund_payment_ms', { + callName: 'outgoingPaymentService.fund' + }) + const paymentOrErr = await outgoingPaymentService.fund({ + id: outgoingPaymentId, + amount: BigInt(event.data.debitAmount.value), + transferId: event.id + }) + stopTimerFund() - if (isFundingError(paymentOrErr)) { + if (isFundingError(paymentOrErr)) { + throw new GraphQLError(fundingErrorToMessage[paymentOrErr], { + extensions: { + code: fundingErrorToCode[paymentOrErr] + } + }) + } + return { + success: true + } + } catch (err) { + throw err + } finally { stopTimer() - throw new GraphQLError(fundingErrorToMessage[paymentOrErr], { - extensions: { - code: fundingErrorToCode[paymentOrErr] - } - }) - } - stopTimer() - return { - success: true } } diff --git a/packages/backend/src/open_payments/payment/outgoing/worker.ts b/packages/backend/src/open_payments/payment/outgoing/worker.ts index e7a780fb28..f58143f4b7 100644 --- a/packages/backend/src/open_payments/payment/outgoing/worker.ts +++ b/packages/backend/src/open_payments/payment/outgoing/worker.ts @@ -96,9 +96,9 @@ async function handlePaymentLifecycle( }) try { await lifecycle.handleSending(deps, payment) - stopTimer() } catch (error) { await onLifecycleError(deps, payment, error as Error | PaymentError) + } finally { stopTimer() } } diff --git a/packages/backend/src/payment-method/ilp/service.ts b/packages/backend/src/payment-method/ilp/service.ts index 9d3363dc02..d8f2f04e2f 100644 --- a/packages/backend/src/payment-method/ilp/service.ts +++ b/packages/backend/src/payment-method/ilp/service.ts @@ -50,15 +50,18 @@ async function getQuote( description: 'Time to get rates' } ) - const rates = await deps.ratesService - .rates(options.walletAddress.asset.code) - .catch((_err: Error) => { - throw new PaymentMethodHandlerError('Received error during ILP quoting', { - description: 'Could not get rates from service', - retryable: false - }) + + let rates + try { + rates = await deps.ratesService.rates(options.walletAddress.asset.code) + } catch (_err) { + throw new PaymentMethodHandlerError('Received error during ILP quoting', { + description: 'Could not get rates from service', + retryable: false }) - .finally(() => stopTimerRates()) + } finally { + stopTimerRates() + } const stopTimerPlugin = deps.telemetry.startTimer( 'ilp_make_ilp_plugin_time_ms', From 24a5eff4dae0aff6f3a475584c3179502cad309e Mon Sep 17 00:00:00 2001 From: Blair Currey <12960453+BlairCurrey@users.noreply.github.com> Date: Tue, 15 Oct 2024 13:20:25 -0400 Subject: [PATCH 26/31] feat(backend): support additional attributes on stopTimer and add tests --- .../backend/src/telemetry/service.test.ts | 111 ++++++++++++++++++ packages/backend/src/telemetry/service.ts | 16 ++- 2 files changed, 121 insertions(+), 6 deletions(-) diff --git a/packages/backend/src/telemetry/service.test.ts b/packages/backend/src/telemetry/service.test.ts index da0ae289cb..fa148ab942 100644 --- a/packages/backend/src/telemetry/service.test.ts +++ b/packages/backend/src/telemetry/service.test.ts @@ -441,6 +441,117 @@ describe('Telemetry Service', () => { ) }) }) + + describe('startTimer', () => { + beforeEach(() => { + jest.useFakeTimers() + }) + + afterEach(() => { + jest.useRealTimers() + }) + + it('should return a function', () => { + const stopTimer = telemetryService.startTimer('test_timer') + expect(typeof stopTimer).toBe('function') + }) + + it('should record histogram with elapsed time and initial attributes', () => { + const recordHistogramSpy = jest.spyOn( + telemetryService, + 'recordHistogram' + ) + const stopTimer = telemetryService.startTimer('test_timer', { + initialAttr: 'value' + }) + + jest.advanceTimersByTime(1000) + stopTimer() + + expect(recordHistogramSpy).toHaveBeenCalledWith( + 'test_timer', + 1000, + expect.objectContaining({ initialAttr: 'value' }) + ) + }) + + it('should merge initial attributes with additional attributes', () => { + const recordHistogramSpy = jest.spyOn( + telemetryService, + 'recordHistogram' + ) + const stopTimer = telemetryService.startTimer('test_timer', { + initialAttr: 'value' + }) + + jest.advanceTimersByTime(1000) + stopTimer({ additionalAttr: 'newValue' }) + + expect(recordHistogramSpy).toHaveBeenCalledWith( + 'test_timer', + 1000, + expect.objectContaining({ + initialAttr: 'value', + additionalAttr: 'newValue' + }) + ) + }) + + it('should override initial attributes with additional attributes if keys conflict', () => { + const recordHistogramSpy = jest.spyOn( + telemetryService, + 'recordHistogram' + ) + const stopTimer = telemetryService.startTimer('test_timer', { + attr: 'initialValue' + }) + + jest.advanceTimersByTime(1000) + stopTimer({ attr: 'newValue' }) + + expect(recordHistogramSpy).toHaveBeenCalledWith( + 'test_timer', + 1000, + expect.objectContaining({ attr: 'newValue' }) + ) + }) + + it('should work without initial attributes', () => { + const recordHistogramSpy = jest.spyOn( + telemetryService, + 'recordHistogram' + ) + const stopTimer = telemetryService.startTimer('test_timer') + + jest.advanceTimersByTime(1000) + stopTimer({ attr: 'value' }) + + expect(recordHistogramSpy).toHaveBeenCalledWith( + 'test_timer', + 1000, + expect.objectContaining({ attr: 'value' }) + ) + }) + + it('should work without additional attributes', () => { + const recordHistogramSpy = jest.spyOn( + telemetryService, + 'recordHistogram' + ) + const stopTimer = telemetryService.startTimer('test_timer', { + initialAttr: 'value' + }) + + jest.advanceTimersByTime(1000) + stopTimer() + + expect(recordHistogramSpy).toHaveBeenCalledWith( + 'test_timer', + 1000, + expect.objectContaining({ initialAttr: 'value' }) + ) + }) + }) }) describe('Telemetry Disabled', () => { let deps: IocContract diff --git a/packages/backend/src/telemetry/service.ts b/packages/backend/src/telemetry/service.ts index c146ce56ab..dd705b2548 100644 --- a/packages/backend/src/telemetry/service.ts +++ b/packages/backend/src/telemetry/service.ts @@ -30,7 +30,10 @@ export interface TelemetryService { value: number, attributes?: Record ): void - startTimer(name: string, attributes?: Record): () => void + startTimer( + name: string, + attributes?: Record + ): (additionalAttributes?: Record) => void } export interface TelemetryServiceDependencies extends BaseService { @@ -224,10 +227,11 @@ export class TelemetryServiceImpl implements TelemetryService { public startTimer( name: string, attributes: Record = {} - ): () => void { + ): (additionalAttributes?: Record) => void { const start = Date.now() - return () => { - this.recordHistogram(name, Date.now() - start, attributes) + return (additionalAttributes: Record = {}) => { + const mergedAttributes = { ...attributes, ...additionalAttributes } + this.recordHistogram(name, Date.now() - start, mergedAttributes) } } } @@ -277,8 +281,8 @@ export class NoopTelemetryServiceImpl implements TelemetryService { public startTimer( name: string, attributes: Record = {} - ): () => void { - return () => { + ): (additionalAttributes?: Record) => void { + return (additionalAttributes?: Record) => { // do nothing } } From ba42a294c06b7671388e250d5e441f465fee10ef Mon Sep 17 00:00:00 2001 From: Blair Currey <12960453+BlairCurrey@users.noreply.github.com> Date: Tue, 15 Oct 2024 13:28:10 -0400 Subject: [PATCH 27/31] chore: format --- packages/backend/src/graphql/resolvers/liquidity.ts | 3 +++ 1 file changed, 3 insertions(+) diff --git a/packages/backend/src/graphql/resolvers/liquidity.ts b/packages/backend/src/graphql/resolvers/liquidity.ts index 05f428af76..90720da98a 100644 --- a/packages/backend/src/graphql/resolvers/liquidity.ts +++ b/packages/backend/src/graphql/resolvers/liquidity.ts @@ -493,6 +493,9 @@ export const depositOutgoingPaymentLiquidity: MutationResolvers[' return { success: true } + // Not a useless catch. Wrapped resolver in try and simply re-throwing + // errors to enforce stopTimer always being called once at end of the resolver + // eslint-disable-next-line no-useless-catch } catch (err) { throw err } finally { From ef85d8b1d6354ad00b77020143867978fb213f4d Mon Sep 17 00:00:00 2001 From: Blair Currey <12960453+BlairCurrey@users.noreply.github.com> Date: Tue, 15 Oct 2024 13:35:25 -0400 Subject: [PATCH 28/31] chore: format --- packages/auth/src/graphql/schema.graphql | 5 +---- 1 file changed, 1 insertion(+), 4 deletions(-) diff --git a/packages/auth/src/graphql/schema.graphql b/packages/auth/src/graphql/schema.graphql index efe49d4f07..0511ff0add 100644 --- a/packages/auth/src/graphql/schema.graphql +++ b/packages/auth/src/graphql/schema.graphql @@ -16,10 +16,7 @@ type Query { ): GrantsConnection! "Fetch a specific grant by its ID." - grant( - "Unique identifier of the grant." - id: ID! - ): Grant! + grant("Unique identifier of the grant." id: ID!): Grant! } type Mutation { From 658f85f264aac00e2c2fa4817c115d22c3d38c51 Mon Sep 17 00:00:00 2001 From: Blair Currey <12960453+BlairCurrey@users.noreply.github.com> Date: Tue, 15 Oct 2024 13:41:33 -0400 Subject: [PATCH 29/31] chore: generate auth gql --- .../auth/src/graphql/generated/graphql.ts | 87 +++++++++++-------- 1 file changed, 53 insertions(+), 34 deletions(-) diff --git a/packages/auth/src/graphql/generated/graphql.ts b/packages/auth/src/graphql/generated/graphql.ts index dfc10637f5..3926b739d1 100644 --- a/packages/auth/src/graphql/generated/graphql.ts +++ b/packages/auth/src/graphql/generated/graphql.ts @@ -14,114 +14,130 @@ export type Scalars = { Boolean: { input: boolean; output: boolean; } Int: { input: number; output: number; } Float: { input: number; output: number; } + /** The `UInt8` scalar type represents unsigned 8-bit whole numeric values, ranging from 0 to 255. */ UInt8: { input: any; output: any; } + /** The `UInt64` scalar type represents unsigned 64-bit whole numeric values. It is capable of handling values that are larger than the JavaScript `Number` type limit (greater than 2^53). */ UInt64: { input: any; output: any; } }; export type Access = Model & { __typename?: 'Access'; - /** Access action (create, read, list or complete) */ + /** Actions allowed with this access. */ actions: Array>; - /** Date-time of creation */ + /** The date and time when the access was created. */ createdAt: Scalars['String']['output']; - /** Access id */ + /** Unique identifier of the access object. */ id: Scalars['ID']['output']; - /** Wallet address of a sub-resource (incoming payment, outgoing payment, or quote) */ + /** Wallet address of the sub-resource (incoming payment, outgoing payment, or quote). */ identifier?: Maybe; - /** Payment limits */ + /** Limits for an outgoing payment associated with this access. */ limits?: Maybe; - /** Access type (incoming payment, outgoing payment, or quote) */ + /** Type of access (incoming payment, outgoing payment, or quote). */ type: Scalars['String']['output']; }; export type FilterFinalizationReason = { + /** List of finalization reasons to include in the filter. */ in?: InputMaybe>; + /** List of finalization reasons to exclude in the filter. */ notIn?: InputMaybe>; }; export type FilterGrantState = { + /** List of states to include in the filter. */ in?: InputMaybe>; + /** List of states to exclude in the filter. */ notIn?: InputMaybe>; }; export type FilterString = { + /** Array of strings to filter by. */ in?: InputMaybe>; }; export type Grant = Model & { __typename?: 'Grant'; - /** Access details */ + /** Details of the access provided by the grant. */ access: Array; - /** Wallet address of the grantee's account */ + /** Wallet address of the grantee's account. */ client: Scalars['String']['output']; - /** Date-time of creation */ + /** The date and time when the grant was created. */ createdAt: Scalars['String']['output']; - /** Reason a grant was finalized */ + /** Specific outcome of a finalized grant, indicating whether the grant was issued, revoked, or rejected. */ finalizationReason?: Maybe; - /** Grant id */ + /** Unique identifier of the grant. */ id: Scalars['ID']['output']; - /** State of the grant */ + /** Current state of the grant. */ state: GrantState; }; export type GrantEdge = { __typename?: 'GrantEdge'; + /** A cursor for paginating through the grants. */ cursor: Scalars['String']['output']; + /** A grant node in the list. */ node: Grant; }; export type GrantFilter = { + /** Filter grants by their finalization reason. */ finalizationReason?: InputMaybe; + /** Filter grants by their unique identifier. */ identifier?: InputMaybe; + /** Filter grants by their state. */ state?: InputMaybe; }; export enum GrantFinalization { - /** grant was issued */ + /** The grant was issued successfully. */ Issued = 'ISSUED', - /** grant was rejected */ + /** The grant request was rejected. */ Rejected = 'REJECTED', - /** grant was revoked */ + /** The grant was revoked. */ Revoked = 'REVOKED' } export enum GrantState { - /** grant was approved */ + /** The grant request has been approved. */ Approved = 'APPROVED', - /** grant was finalized and no more access tokens or interactions can be made on it */ + /** The grant request has been finalized, and no more access tokens or interactions can be made. */ Finalized = 'FINALIZED', - /** grant request is awaiting interaction */ + /** The grant request is awaiting interaction. */ Pending = 'PENDING', - /** grant request is determining what state to enter next */ + /** The grant request is processing. */ Processing = 'PROCESSING' } export type GrantsConnection = { __typename?: 'GrantsConnection'; + /** A list of edges representing grants and cursors for pagination. */ edges: Array; + /** Information to aid in pagination. */ pageInfo: PageInfo; }; export type LimitData = { __typename?: 'LimitData'; - /** Amount to debit */ + /** Amount to debit. */ debitAmount?: Maybe; - /** Interval between payments */ + /** Interval between payments. */ interval?: Maybe; - /** Amount to receive */ + /** Amount to receive. */ receiveAmount?: Maybe; - /** Wallet address URL of the receiver */ + /** Wallet address URL of the receiver. */ receiver?: Maybe; }; export type Model = { + /** The date and time when the model was created. */ createdAt: Scalars['String']['output']; + /** Unique identifier for the model. */ id: Scalars['ID']['output']; }; export type Mutation = { __typename?: 'Mutation'; - /** Revoke Grant */ + /** Revoke an existing grant. */ revokeGrant: RevokeGrantMutationResponse; }; @@ -132,30 +148,31 @@ export type MutationRevokeGrantArgs = { export type PageInfo = { __typename?: 'PageInfo'; - /** Paginating forwards: the cursor to continue. */ + /** The cursor used to fetch the next page when paginating forward. */ endCursor?: Maybe; - /** Paginating forwards: Are there more pages? */ + /** Indicates if there are more pages when paginating forward. */ hasNextPage: Scalars['Boolean']['output']; - /** Paginating backwards: Are there more pages? */ + /** Indicates if there are more pages when paginating backward. */ hasPreviousPage: Scalars['Boolean']['output']; - /** Paginating backwards: the cursor to continue. */ + /** The cursor used to fetch the next page when paginating backward. */ startCursor?: Maybe; }; export type PaymentAmount = { __typename?: 'PaymentAmount'; - /** [ISO 4217 currency code](https://en.wikipedia.org/wiki/ISO_4217), e.g. `USD` */ + /** Should be an ISO 4217 currency code whenever possible, e.g. `USD`. For more information, refer to [assets](https://rafiki.dev/overview/concepts/accounting/#assets). */ assetCode: Scalars['String']['output']; - /** Difference in orders of magnitude between the standard unit of an asset and a corresponding fractional unit */ + /** Difference in orders of magnitude between the standard unit of an asset and a corresponding fractional unit. */ assetScale: Scalars['UInt8']['output']; + /** The value of the payment amount. */ value: Scalars['UInt64']['output']; }; export type Query = { __typename?: 'Query'; - /** Fetch a grant */ + /** Fetch a specific grant by its ID. */ grant: Grant; - /** Fetch a page of grants. */ + /** Fetch a paginated list of grants. */ grants: GrantsConnection; }; @@ -175,18 +192,20 @@ export type QueryGrantsArgs = { }; export type RevokeGrantInput = { + /** Unique identifier of the grant to revoke. */ grantId: Scalars['String']['input']; }; export type RevokeGrantMutationResponse = { __typename?: 'RevokeGrantMutationResponse'; + /** Unique identifier of the revoked grant. */ id: Scalars['ID']['output']; }; export enum SortOrder { - /** Choose ascending order for results. */ + /** Sort the results in ascending order. */ Asc = 'ASC', - /** Choose descending order for results. */ + /** Sort the results in descending order. */ Desc = 'DESC' } From 03d929bda28aa43fb8e99b36d9f95b6fec043f44 Mon Sep 17 00:00:00 2001 From: Blair Currey <12960453+BlairCurrey@users.noreply.github.com> Date: Wed, 16 Oct 2024 10:38:47 -0400 Subject: [PATCH 30/31] refactor(backend): timer callNames to include scope --- .../backend/src/accounting/psql/balance.ts | 2 +- .../backend/src/accounting/psql/service.ts | 2 +- .../src/accounting/tigerbeetle/service.ts | 2 +- .../src/graphql/resolvers/liquidity.ts | 6 +++--- .../payment/outgoing/lifecycle.ts | 8 +++---- .../open_payments/payment/outgoing/service.ts | 21 ++++++++++--------- .../open_payments/payment/outgoing/worker.ts | 6 +++--- .../src/open_payments/quote/service.ts | 12 +++++------ .../src/open_payments/receiver/service.ts | 2 +- .../backend/src/payment-method/ilp/service.ts | 12 +++++------ 10 files changed, 37 insertions(+), 36 deletions(-) diff --git a/packages/backend/src/accounting/psql/balance.ts b/packages/backend/src/accounting/psql/balance.ts index 3cb314f010..771183bd95 100644 --- a/packages/backend/src/accounting/psql/balance.ts +++ b/packages/backend/src/accounting/psql/balance.ts @@ -15,7 +15,7 @@ export async function getAccountBalances( trx?: TransactionOrKnex ): Promise { const stopTimer = deps.telemetry.startTimer('psql_get_account_balances', { - callName: 'psql_get_account_balances' + callName: 'AccountingService:Postgres:getAccountBalances' }) try { const queryResult = await (trx ?? deps.knex).raw( diff --git a/packages/backend/src/accounting/psql/service.ts b/packages/backend/src/accounting/psql/service.ts index 6bef5ffd1b..e6af38d9f9 100644 --- a/packages/backend/src/accounting/psql/service.ts +++ b/packages/backend/src/accounting/psql/service.ts @@ -150,7 +150,7 @@ export async function getAccountTotalSent( const stopTimer = deps.telemetry.startTimer( 'psql_get_account_total_sent_ms', { - callName: 'psql_getAccountTotalSent' + callName: 'AccountingService:Postgres:getAccountTotalSent' } ) const account = await getLiquidityAccount(deps, accountRef) diff --git a/packages/backend/src/accounting/tigerbeetle/service.ts b/packages/backend/src/accounting/tigerbeetle/service.ts index ea79628d70..b9a92b38ad 100644 --- a/packages/backend/src/accounting/tigerbeetle/service.ts +++ b/packages/backend/src/accounting/tigerbeetle/service.ts @@ -221,7 +221,7 @@ export async function getAccountTotalSent( id: string ): Promise { const stopTimer = deps.telemetry.startTimer('tb_get_account_total_sent_ms', { - callName: 'tb_getAccountTotalSent' + callName: 'AccountingService:Tigerbeetle:getAccountTotalSent' }) const account = (await getAccounts(deps, [id]))[0] if (account) { diff --git a/packages/backend/src/graphql/resolvers/liquidity.ts b/packages/backend/src/graphql/resolvers/liquidity.ts index 90720da98a..e402a8f8ac 100644 --- a/packages/backend/src/graphql/resolvers/liquidity.ts +++ b/packages/backend/src/graphql/resolvers/liquidity.ts @@ -444,7 +444,7 @@ export const depositOutgoingPaymentLiquidity: MutationResolvers[' const stopTimer = telemetry.startTimer( 'deposit_outgoing_payment_liquidity_ms', { - callName: 'depositOutgoingPaymentLiquidity' + callName: 'Resolver:depositOutgoingPaymentLiquidity' } ) @@ -452,7 +452,7 @@ export const depositOutgoingPaymentLiquidity: MutationResolvers[' const { outgoingPaymentId } = args.input const webhookService = await ctx.container.use('webhookService') const stopTimerWh = telemetry.startTimer('wh_get_latest_ms', { - callName: 'webhookService.getLatestByResourceId' + callName: 'WebhookService:getLatestByResourceId' }) const event = await webhookService.getLatestByResourceId({ outgoingPaymentId, @@ -474,7 +474,7 @@ export const depositOutgoingPaymentLiquidity: MutationResolvers[' 'outgoingPaymentService' ) const stopTimerFund = telemetry.startTimer('fund_payment_ms', { - callName: 'outgoingPaymentService.fund' + callName: 'OutgoingPaymentService:fund' }) const paymentOrErr = await outgoingPaymentService.fund({ id: outgoingPaymentId, diff --git a/packages/backend/src/open_payments/payment/outgoing/lifecycle.ts b/packages/backend/src/open_payments/payment/outgoing/lifecycle.ts index c2a7a41955..7539f03407 100644 --- a/packages/backend/src/open_payments/payment/outgoing/lifecycle.ts +++ b/packages/backend/src/open_payments/payment/outgoing/lifecycle.ts @@ -78,7 +78,7 @@ export async function handleSending( const stopTimer = deps.telemetry.startTimer('ilp_pay_time_ms', { description: 'Time to complete an ILP payment', - callName: 'paymentMethodHandlerService.pay (ILP)' + callName: 'PaymentMethodHandlerService:pay' }) await deps.paymentMethodHandlerService.pay('ILP', { receiver, @@ -142,7 +142,7 @@ export async function handleFailed( error: string ): Promise { const stopTimer = deps.telemetry.startTimer('handle_failed_ms', { - callName: 'handleFailed' + callName: 'OutgoingPaymentLifecycle:handleFailed' }) await payment.$query(deps.knex).patch({ state: OutgoingPaymentState.Failed, @@ -157,7 +157,7 @@ async function handleCompleted( payment: OutgoingPayment ): Promise { const stopTimer = deps.telemetry.startTimer('handle_completed_ms', { - callName: 'handleCompleted' + callName: 'OutgoingPaymentLifecycle:handleCompleted' }) await payment.$query(deps.knex).patch({ state: OutgoingPaymentState.Completed @@ -178,7 +178,7 @@ export async function sendWebhookEvent( trx?: TransactionOrKnex ): Promise { const stopTimer = deps.telemetry.startTimer('op_send_webhook_event_ms', { - callName: 'opLifecycle_sendWebhookEvent' + callName: 'OutgoingPaymentLifecycle:sendWebhookEvent' }) // TigerBeetle accounts are only created as the OutgoingPayment is funded. // So default the amountSent and balance to 0 for outgoing payments still in the funding state diff --git a/packages/backend/src/open_payments/payment/outgoing/service.ts b/packages/backend/src/open_payments/payment/outgoing/service.ts index 271d1632c3..308057437f 100644 --- a/packages/backend/src/open_payments/payment/outgoing/service.ts +++ b/packages/backend/src/open_payments/payment/outgoing/service.ts @@ -220,7 +220,7 @@ async function createOutgoingPayment( const stopTimerOP = deps.telemetry.startTimer( 'outgoing_payment_service_create_time_ms', { - callName: 'createOutgoingPayment', + callName: 'OutgoingPaymentService:create', description: 'Time to create an outgoing payment' } ) @@ -231,7 +231,7 @@ async function createOutgoingPayment( const stopTimerQuote = deps.telemetry.startTimer( 'outgoing_payment_service_create_quote_time_ms', { - callName: 'quoteService.create', + callName: 'QuoteService:create', description: 'Time to create a quote in outgoing payment' } ) @@ -258,7 +258,7 @@ async function createOutgoingPayment( const stopTimerWA = deps.telemetry.startTimer( 'outgoing_payment_service_getwalletaddress_time_ms', { - callName: 'walletAddressService.get', + callName: 'WalletAddressService:get', description: 'Time to get wallet address in outgoing payment' } ) @@ -275,7 +275,7 @@ async function createOutgoingPayment( const stopTimerGrant = deps.telemetry.startTimer( 'outgoing_payment_service_insertgrant_time_ms', { - callName: 'OutgoingPaymentGrant.insert', + callName: 'OutgoingPaymentGrantModel:insert', description: 'Time to insert grant in outgoing payment' } ) @@ -317,7 +317,8 @@ async function createOutgoingPayment( const stopTimerValidateGrant = deps.telemetry.startTimer( 'outgoing_payment_service_validate_grant_time_ms', { - callName: 'validateGrantAndAddSpentAmountsToPayment', + callName: + 'OutgoingPaymentService:validateGrantAndAddSpentAmountsToPayment', description: 'Time to validate a grant' } ) @@ -337,7 +338,7 @@ async function createOutgoingPayment( const stopTimerReceiver = deps.telemetry.startTimer( 'outgoing_payment_service_getreceiver_time_ms', { - callName: 'receiverService.get', + callName: 'ReceiverService:get', description: 'Time to retrieve receiver in outgoing payment' } ) @@ -349,7 +350,7 @@ async function createOutgoingPayment( const stopTimerPeer = deps.telemetry.startTimer( 'outgoing_payment_service_getpeer_time_ms', { - callName: 'peerService.getByDestinationAddress', + callName: 'PeerService:getByDestinationAddress', description: 'Time to retrieve peer in outgoing payment' } ) @@ -361,7 +362,7 @@ async function createOutgoingPayment( const stopTimerPeerUpdate = deps.telemetry.startTimer( 'outgoing_payment_service_patchpeer_time_ms', { - callName: 'payment.patch', + callName: 'OutgoingPaymentModel:patch', description: 'Time to patch peer in outgoing payment' } ) @@ -371,7 +372,7 @@ async function createOutgoingPayment( const stopTimerWebhook = deps.telemetry.startTimer( 'outgoing_payment_service_webhook_event_time_ms', { - callName: 'sendWebhookEvent', + callName: 'OutgoingPaymentService:sendWebhookEvent', description: 'Time to add outgoing payment webhook event' } ) @@ -386,7 +387,7 @@ async function createOutgoingPayment( const stopTimerAddAmount = deps.telemetry.startTimer( 'outgoing_payment_service_add_sent_time_ms', { - callName: 'addSentAmount', + callName: 'OutgoingPaymentService:addSentAmount', description: 'Time to add sent amount to outgoing payment' } ) diff --git a/packages/backend/src/open_payments/payment/outgoing/worker.ts b/packages/backend/src/open_payments/payment/outgoing/worker.ts index ef9eef2f35..a2e688036f 100644 --- a/packages/backend/src/open_payments/payment/outgoing/worker.ts +++ b/packages/backend/src/open_payments/payment/outgoing/worker.ts @@ -22,7 +22,7 @@ export async function processPendingPayment( const stopTimer = deps_.telemetry.startTimer( 'process_pending_payment_ms', { - callName: 'processPendingPayment' + callName: 'OutgoingPaymentWorker:processPendingPayment' } ) const paymentId = await deps_.knex.transaction(async (trx) => { @@ -56,7 +56,7 @@ async function getPendingPayment( deps: ServiceDependencies ): Promise { const stopTimer = deps.telemetry.startTimer('get_pending_payment_ms', { - callName: 'getPendingPayment' + callName: 'OutoingPaymentWorker:getPendingPayment' }) const now = new Date(Date.now()).toISOString() const payments = await OutgoingPayment.query(trx) @@ -90,7 +90,7 @@ async function handlePaymentLifecycle( } const stopTimer = deps.telemetry.startTimer('handle_sending_ms', { - callName: 'handleSending' + callName: 'OutoingPaymentWorker:handleSending' }) try { await lifecycle.handleSending(deps, payment) diff --git a/packages/backend/src/open_payments/quote/service.ts b/packages/backend/src/open_payments/quote/service.ts index 1517f1ca6b..67b3ebdc45 100644 --- a/packages/backend/src/open_payments/quote/service.ts +++ b/packages/backend/src/open_payments/quote/service.ts @@ -87,7 +87,7 @@ async function createQuote( options: CreateQuoteOptions ): Promise { const stopTimer = deps.telemetry.startTimer('quote_service_create_time_ms', { - callName: 'createQuote', + callName: 'QuoteService:create', description: 'Time to create a quote' }) if (options.debitAmount && options.receiveAmount) { @@ -126,7 +126,7 @@ async function createQuote( const stopTimerReceiver = deps.telemetry.startTimer( 'quote_service_create_resolve_receiver_time_ms', { - callName: 'resolveReceiver', + callName: 'QuoteService:resolveReceiver', description: 'Time to resolve receiver' } ) @@ -136,7 +136,7 @@ async function createQuote( const stopTimerQuote = deps.telemetry.startTimer( 'quote_service_create_get_quote_time_ms', { - callName: 'getQuote', + callName: 'PaymentMethodHandlerService:getQuote', description: 'Time to getQuote' } ) @@ -153,7 +153,7 @@ async function createQuote( const stopTimerFee = deps.telemetry.startTimer( 'quote_service_create_get_latest_fee_time_ms', { - callName: 'getLatestFee', + callName: 'FeeService:getLatestFee', description: 'Time to getLatestFee' } ) @@ -167,7 +167,7 @@ async function createQuote( const stopQuoteCreate = deps.telemetry.startTimer( 'quote_service_create_insert_time_ms', { - callName: 'Quote.insert', + callName: 'QuoteModel.insert', description: 'Time to insert quote' } ) @@ -196,7 +196,7 @@ async function createQuote( const stopFinalize = deps.telemetry.startTimer( 'quote_service_finalize_quote_ms', { - callName: 'finalizedQuote', + callName: 'QuoteService:finalizedQuote', description: 'Time to finalize quote' } ) diff --git a/packages/backend/src/open_payments/receiver/service.ts b/packages/backend/src/open_payments/receiver/service.ts index e9ee6e3878..d93c902fda 100644 --- a/packages/backend/src/open_payments/receiver/service.ts +++ b/packages/backend/src/open_payments/receiver/service.ts @@ -139,7 +139,7 @@ async function getReceiver( url: string ): Promise { const stopTimer = deps.telemetry.startTimer('getReceiver', { - callName: 'getReceiver' + callName: 'ReceiverService:get' }) try { const localIncomingPayment = await getLocalIncomingPayment(deps, url) diff --git a/packages/backend/src/payment-method/ilp/service.ts b/packages/backend/src/payment-method/ilp/service.ts index d8f2f04e2f..665c92add8 100644 --- a/packages/backend/src/payment-method/ilp/service.ts +++ b/packages/backend/src/payment-method/ilp/service.ts @@ -46,7 +46,7 @@ async function getQuote( const stopTimerRates = deps.telemetry.startTimer( 'ilp_get_quote_rate_time_ms', { - callName: 'rates', + callName: 'RateService:rates', description: 'Time to get rates' } ) @@ -66,7 +66,7 @@ async function getQuote( const stopTimerPlugin = deps.telemetry.startTimer( 'ilp_make_ilp_plugin_time_ms', { - callName: 'makeIlpPlugin', + callName: 'PaymentMethod:ILP:makeIlpPlugin', description: 'Time to make ilp plugin' } ) @@ -81,7 +81,7 @@ async function getQuote( const stopTimerConnect = deps.telemetry.startTimer( 'ilp_make_ilp_plugin_connect_time_ms', { - callName: 'plugin.connect', + callName: 'PaymentMethod:ILP:connect', description: 'Time to connect ilp plugin' } ) @@ -104,7 +104,7 @@ async function getQuote( let ilpQuote: Pay.Quote | undefined const stopTimerProbe = deps.telemetry.startTimer('ilp_rate_probe_time_ms', { - callName: 'Pay.startQuote', + callName: 'Pay:startQuote', description: 'Time to get an ILP quote (Pay.startQuote)' }) try { @@ -196,7 +196,7 @@ async function getQuote( const stopTimerClose = deps.telemetry.startTimer( 'ilp_plugin_close_connect_time_ms', { - callName: 'Pay.closeConnection', + callName: 'Pay:closeConnection', description: 'Time to close ilp plugin' } ) @@ -217,7 +217,7 @@ async function getQuote( const stopTimerDisconnect = deps.telemetry.startTimer( 'ilp_plugin_disconnect_time_ms', { - callName: 'plugin.disconnect', + callName: 'PaymentMethod:ILP:disconnect', description: 'Time to disconnect ilp plugin' } ) From ed1b5d3e49ad5ff105aaaf2db4f8128da326d9f4 Mon Sep 17 00:00:00 2001 From: Blair Currey <12960453+BlairCurrey@users.noreply.github.com> Date: Wed, 16 Oct 2024 11:45:30 -0400 Subject: [PATCH 31/31] fix(localenv): rm deprecated otel collector log config --- localenv/telemetry/otel-collector-config.yaml | 2 -- 1 file changed, 2 deletions(-) diff --git a/localenv/telemetry/otel-collector-config.yaml b/localenv/telemetry/otel-collector-config.yaml index d577a0ec78..a0fa4e7a1f 100644 --- a/localenv/telemetry/otel-collector-config.yaml +++ b/localenv/telemetry/otel-collector-config.yaml @@ -8,8 +8,6 @@ processors: batch: exporters: - logging: - loglevel: info debug: verbosity: detailed prometheus: