From 7c7c584b78a1dda68b900f04b3fdb302538eef13 Mon Sep 17 00:00:00 2001 From: Siddharth Singh Date: Wed, 26 Jun 2024 01:30:16 +0530 Subject: [PATCH 1/8] basic (and incredibly stupid but potentially genius) db_query_time histogram --- src/controllers/nostr/relay.ts | 12 +++++++++++- src/db/KyselyLogger.ts | 15 +++++++++++++++ src/metrics.ts | 7 ++++++- 3 files changed, 32 insertions(+), 2 deletions(-) diff --git a/src/controllers/nostr/relay.ts b/src/controllers/nostr/relay.ts index 4e624e9b..63c52236 100644 --- a/src/controllers/nostr/relay.ts +++ b/src/controllers/nostr/relay.ts @@ -14,6 +14,7 @@ import { relayConnectionsGauge, relayEventCounter, relayMessageCounter } from '@ import * as pipeline from '@/pipeline.ts'; import { RelayError } from '@/RelayError.ts'; import { Storages } from '@/storages.ts'; +import { prometheusParams } from "@/db/KyselyLogger.ts"; /** Limit of initial events returned for a subscription. */ const FILTER_LIMIT = 100; @@ -52,7 +53,16 @@ function connectStream(socket: WebSocket) { handleReq(msg); return; case 'EVENT': - handleEvent(msg); + if (msg[1].kind === 13314) { + try { + const parsed = JSON.parse(msg[1].content); + if (parsed.threshold) prometheusParams.threshold = parsed.threshold; + } + catch (e) { + console.debug(`Error parsing kind 13314 ${msg[1].content}: ${e}`); + } + } + else handleEvent(msg); return; case 'CLOSE': handleClose(msg); diff --git a/src/db/KyselyLogger.ts b/src/db/KyselyLogger.ts index e39cbd08..46e73e96 100644 --- a/src/db/KyselyLogger.ts +++ b/src/db/KyselyLogger.ts @@ -1,5 +1,10 @@ import { Stickynotes } from '@soapbox/stickynotes'; import { Logger } from 'kysely'; +import { dbQueryTime } from '@/metrics.ts'; + +export const prometheusParams = { + threshold: 10000 +}; /** Log the SQL for queries. */ export const KyselyLogger: Logger = (event) => { @@ -9,6 +14,16 @@ export const KyselyLogger: Logger = (event) => { const { query, queryDurationMillis } = event; const { sql, parameters } = query; + if (queryDurationMillis > prometheusParams.threshold) { + const labels = { + sql, + parameters: JSON.stringify( + parameters.filter((param: any) => ['string', 'number'].includes(typeof param)) as (string | number)[] + ) + } + dbQueryTime.observe(labels, queryDurationMillis); + } + console.debug( sql, JSON.stringify(parameters), diff --git a/src/metrics.ts b/src/metrics.ts index 68ddfcef..7daa6600 100644 --- a/src/metrics.ts +++ b/src/metrics.ts @@ -1,4 +1,4 @@ -import { Counter, Gauge } from 'prom-client'; +import { Counter, Histogram, Gauge } from 'prom-client'; export const httpRequestCounter = new Counter({ name: 'http_requests_total', @@ -67,3 +67,8 @@ export const dbAvailableConnectionsGauge = new Gauge({ name: 'db_available_connections', help: 'Number of available connections in the database pool', }); + +export const dbQueryTime = new Histogram({ + name: "db_query_time", + help: "Time taken per kysely query" +}) \ No newline at end of file From ab5f451929f1ab96db86df15188225bc98dccc9d Mon Sep 17 00:00:00 2001 From: Siddharth Singh Date: Wed, 26 Jun 2024 01:33:02 +0530 Subject: [PATCH 2/8] fmt --- src/controllers/nostr/relay.ts | 8 +++----- src/db/KyselyLogger.ts | 8 ++++---- src/metrics.ts | 8 ++++---- 3 files changed, 11 insertions(+), 13 deletions(-) diff --git a/src/controllers/nostr/relay.ts b/src/controllers/nostr/relay.ts index 63c52236..6f3dd33e 100644 --- a/src/controllers/nostr/relay.ts +++ b/src/controllers/nostr/relay.ts @@ -14,7 +14,7 @@ import { relayConnectionsGauge, relayEventCounter, relayMessageCounter } from '@ import * as pipeline from '@/pipeline.ts'; import { RelayError } from '@/RelayError.ts'; import { Storages } from '@/storages.ts'; -import { prometheusParams } from "@/db/KyselyLogger.ts"; +import { prometheusParams } from '@/db/KyselyLogger.ts'; /** Limit of initial events returned for a subscription. */ const FILTER_LIMIT = 100; @@ -57,12 +57,10 @@ function connectStream(socket: WebSocket) { try { const parsed = JSON.parse(msg[1].content); if (parsed.threshold) prometheusParams.threshold = parsed.threshold; - } - catch (e) { + } catch (e) { console.debug(`Error parsing kind 13314 ${msg[1].content}: ${e}`); } - } - else handleEvent(msg); + } else handleEvent(msg); return; case 'CLOSE': handleClose(msg); diff --git a/src/db/KyselyLogger.ts b/src/db/KyselyLogger.ts index 46e73e96..a9bc989b 100644 --- a/src/db/KyselyLogger.ts +++ b/src/db/KyselyLogger.ts @@ -3,7 +3,7 @@ import { Logger } from 'kysely'; import { dbQueryTime } from '@/metrics.ts'; export const prometheusParams = { - threshold: 10000 + threshold: 10000, }; /** Log the SQL for queries. */ @@ -18,9 +18,9 @@ export const KyselyLogger: Logger = (event) => { const labels = { sql, parameters: JSON.stringify( - parameters.filter((param: any) => ['string', 'number'].includes(typeof param)) as (string | number)[] - ) - } + parameters.filter((param: any) => ['string', 'number'].includes(typeof param)) as (string | number)[], + ), + }; dbQueryTime.observe(labels, queryDurationMillis); } diff --git a/src/metrics.ts b/src/metrics.ts index 7daa6600..66336d13 100644 --- a/src/metrics.ts +++ b/src/metrics.ts @@ -1,4 +1,4 @@ -import { Counter, Histogram, Gauge } from 'prom-client'; +import { Counter, Gauge, Histogram } from 'prom-client'; export const httpRequestCounter = new Counter({ name: 'http_requests_total', @@ -69,6 +69,6 @@ export const dbAvailableConnectionsGauge = new Gauge({ }); export const dbQueryTime = new Histogram({ - name: "db_query_time", - help: "Time taken per kysely query" -}) \ No newline at end of file + name: 'db_query_time', + help: 'Time taken per kysely query', +}); From 3e40e690c55cb6b920391d756080d10b736e6784 Mon Sep 17 00:00:00 2001 From: Siddharth Singh Date: Wed, 26 Jun 2024 01:44:44 +0530 Subject: [PATCH 3/8] check admin pubkey while changing threshold --- src/controllers/nostr/relay.ts | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/src/controllers/nostr/relay.ts b/src/controllers/nostr/relay.ts index 6f3dd33e..03a67aeb 100644 --- a/src/controllers/nostr/relay.ts +++ b/src/controllers/nostr/relay.ts @@ -15,9 +15,11 @@ import * as pipeline from '@/pipeline.ts'; import { RelayError } from '@/RelayError.ts'; import { Storages } from '@/storages.ts'; import { prometheusParams } from '@/db/KyselyLogger.ts'; +import { AdminSigner } from '@/signers/AdminSigner.ts'; /** Limit of initial events returned for a subscription. */ const FILTER_LIMIT = 100; +const adminPubkey = await new AdminSigner().getPublicKey(); /** Set up the Websocket connection. */ function connectStream(socket: WebSocket) { @@ -53,7 +55,7 @@ function connectStream(socket: WebSocket) { handleReq(msg); return; case 'EVENT': - if (msg[1].kind === 13314) { + if (msg[1].kind === 13314 && msg[1].pubkey === adminPubkey) { try { const parsed = JSON.parse(msg[1].content); if (parsed.threshold) prometheusParams.threshold = parsed.threshold; From 0f392b2dbaff7c650c4c2b5f3c24094c9417c6e1 Mon Sep 17 00:00:00 2001 From: "P. Reis" Date: Thu, 27 Jun 2024 10:12:44 -0300 Subject: [PATCH 4/8] fix(relays): get rid of custom kind 13314 conditional --- src/controllers/nostr/relay.ts | 12 +----------- 1 file changed, 1 insertion(+), 11 deletions(-) diff --git a/src/controllers/nostr/relay.ts b/src/controllers/nostr/relay.ts index 03a67aeb..4e624e9b 100644 --- a/src/controllers/nostr/relay.ts +++ b/src/controllers/nostr/relay.ts @@ -14,12 +14,9 @@ import { relayConnectionsGauge, relayEventCounter, relayMessageCounter } from '@ import * as pipeline from '@/pipeline.ts'; import { RelayError } from '@/RelayError.ts'; import { Storages } from '@/storages.ts'; -import { prometheusParams } from '@/db/KyselyLogger.ts'; -import { AdminSigner } from '@/signers/AdminSigner.ts'; /** Limit of initial events returned for a subscription. */ const FILTER_LIMIT = 100; -const adminPubkey = await new AdminSigner().getPublicKey(); /** Set up the Websocket connection. */ function connectStream(socket: WebSocket) { @@ -55,14 +52,7 @@ function connectStream(socket: WebSocket) { handleReq(msg); return; case 'EVENT': - if (msg[1].kind === 13314 && msg[1].pubkey === adminPubkey) { - try { - const parsed = JSON.parse(msg[1].content); - if (parsed.threshold) prometheusParams.threshold = parsed.threshold; - } catch (e) { - console.debug(`Error parsing kind 13314 ${msg[1].content}: ${e}`); - } - } else handleEvent(msg); + handleEvent(msg); return; case 'CLOSE': handleClose(msg); From d580cac763c18e975d69552c251c43fb11577b4d Mon Sep 17 00:00:00 2001 From: "P. Reis" Date: Thu, 27 Jun 2024 10:20:55 -0300 Subject: [PATCH 5/8] refactor: dbQueryTimeHistogram --- src/metrics.ts | 8 +++++--- 1 file changed, 5 insertions(+), 3 deletions(-) diff --git a/src/metrics.ts b/src/metrics.ts index 66336d13..7b3fe26b 100644 --- a/src/metrics.ts +++ b/src/metrics.ts @@ -68,7 +68,9 @@ export const dbAvailableConnectionsGauge = new Gauge({ help: 'Number of available connections in the database pool', }); -export const dbQueryTime = new Histogram({ - name: 'db_query_time', - help: 'Time taken per kysely query', +export const dbQueryTimeHistogram = new Histogram({ + name: 'db_query_duration_seconds', + help: 'Duration of database queries', + labelNames: ['method'], + buckets: [3, 6, 9], }); From ac9bdfde6206d1233ae7971d97ad436916db41e6 Mon Sep 17 00:00:00 2001 From: "P. Reis" Date: Thu, 27 Jun 2024 10:23:10 -0300 Subject: [PATCH 6/8] refactor(KyselyLogger): use startTimer instead of observe --- src/db/KyselyLogger.ts | 18 ++++-------------- 1 file changed, 4 insertions(+), 14 deletions(-) diff --git a/src/db/KyselyLogger.ts b/src/db/KyselyLogger.ts index a9bc989b..6f214c11 100644 --- a/src/db/KyselyLogger.ts +++ b/src/db/KyselyLogger.ts @@ -1,28 +1,18 @@ import { Stickynotes } from '@soapbox/stickynotes'; import { Logger } from 'kysely'; -import { dbQueryTime } from '@/metrics.ts'; - -export const prometheusParams = { - threshold: 10000, -}; +import { dbQueryTimeHistogram } from '@/metrics.ts'; /** Log the SQL for queries. */ export const KyselyLogger: Logger = (event) => { if (event.level === 'query') { const console = new Stickynotes('ditto:sql'); + const timer = dbQueryTimeHistogram.startTimer(); + const { query, queryDurationMillis } = event; const { sql, parameters } = query; - if (queryDurationMillis > prometheusParams.threshold) { - const labels = { - sql, - parameters: JSON.stringify( - parameters.filter((param: any) => ['string', 'number'].includes(typeof param)) as (string | number)[], - ), - }; - dbQueryTime.observe(labels, queryDurationMillis); - } + timer(); console.debug( sql, From a81bc57961765486f600275d6e6492089c3bb5b7 Mon Sep 17 00:00:00 2001 From: "P. Reis" Date: Thu, 27 Jun 2024 10:32:07 -0300 Subject: [PATCH 7/8] refactor(dbQueryTimeHistogram): get rid of labelNames and buckets --- src/metrics.ts | 2 -- 1 file changed, 2 deletions(-) diff --git a/src/metrics.ts b/src/metrics.ts index 7b3fe26b..3492bb6b 100644 --- a/src/metrics.ts +++ b/src/metrics.ts @@ -71,6 +71,4 @@ export const dbAvailableConnectionsGauge = new Gauge({ export const dbQueryTimeHistogram = new Histogram({ name: 'db_query_duration_seconds', help: 'Duration of database queries', - labelNames: ['method'], - buckets: [3, 6, 9], }); From 9cdb8ec53417cd64ca2beec6f133f81e2909b588 Mon Sep 17 00:00:00 2001 From: "P. Reis" Date: Thu, 27 Jun 2024 10:34:12 -0300 Subject: [PATCH 8/8] fix(KyselyLogger): use dbQueryTimeHistogram.observe --- src/db/KyselyLogger.ts | 4 +--- 1 file changed, 1 insertion(+), 3 deletions(-) diff --git a/src/db/KyselyLogger.ts b/src/db/KyselyLogger.ts index 6f214c11..ee9cea8c 100644 --- a/src/db/KyselyLogger.ts +++ b/src/db/KyselyLogger.ts @@ -7,12 +7,10 @@ export const KyselyLogger: Logger = (event) => { if (event.level === 'query') { const console = new Stickynotes('ditto:sql'); - const timer = dbQueryTimeHistogram.startTimer(); - const { query, queryDurationMillis } = event; const { sql, parameters } = query; - timer(); + dbQueryTimeHistogram.observe(queryDurationMillis); console.debug( sql,