diff --git a/src/api/routes/prom-metrics.ts b/src/api/routes/prom-metrics.ts index f6c1ff8..f47e5bf 100644 --- a/src/api/routes/prom-metrics.ts +++ b/src/api/routes/prom-metrics.ts @@ -16,8 +16,10 @@ export const SignerPromMetricsRoutes: FastifyPluginAsync< const signerRegistry = new Registry(); + const metricsPrefix = 'signer_api_'; + new Gauge({ - name: 'time_since_last_pending_block_proposal_ms', + name: metricsPrefix + 'time_since_last_pending_block_proposal_ms', help: 'Time in milliseconds since the oldest pending block proposal', registers: [signerRegistry], async collect() { @@ -30,7 +32,7 @@ export const SignerPromMetricsRoutes: FastifyPluginAsync< }); new Gauge({ - name: 'avg_block_push_time_ms', + name: metricsPrefix + 'avg_block_push_time_ms', help: 'Average time (in milliseconds) taken for block proposals to be accepted and pushed over different block periods', labelNames: ['period'] as const, registers: [signerRegistry], @@ -46,7 +48,7 @@ export const SignerPromMetricsRoutes: FastifyPluginAsync< }); new Gauge({ - name: 'proposal_acceptance_rate', + name: metricsPrefix + 'proposal_acceptance_rate', help: 'The acceptance rate of block proposals for different block ranges (as a float between 0 and 1).', labelNames: ['period'], registers: [signerRegistry], @@ -62,7 +64,7 @@ export const SignerPromMetricsRoutes: FastifyPluginAsync< }); new Gauge({ - name: 'signer_state_count', + name: metricsPrefix + 'signer_state_count', help: 'Count of signer states over different block periods', labelNames: ['signer', 'period', 'state'] as const, registers: [signerRegistry], diff --git a/src/env.ts b/src/env.ts index 280b884..b301cdc 100644 --- a/src/env.ts +++ b/src/env.ts @@ -26,7 +26,7 @@ const schema = Type.Object({ /** Hostname that will be reported to the chainhook node so it can call us back with events */ EXTERNAL_HOSTNAME: Type.String({ default: '127.0.0.1' }), /** Port in which to serve prometheus metrics */ - PROMETHEUS_PORT: Type.Number({ default: 9154 }), + PROMETHEUS_PORT: Type.Number({ default: 9153 }), /** Port in which to serve the profiler */ PROFILER_PORT: Type.Number({ default: 9119 }), diff --git a/tests/db/db-notifications.test.ts b/tests/db/db-notifications.test.ts index 9be5cec..4c85d81 100644 --- a/tests/db/db-notifications.test.ts +++ b/tests/db/db-notifications.test.ts @@ -1,26 +1,33 @@ -import * as fs from 'node:fs'; -import * as readline from 'node:readline/promises'; -import * as zlib from 'node:zlib'; -import * as supertest from 'supertest'; -import { FastifyInstance } from 'fastify'; -import { StacksPayload } from '@hirosystems/chainhook-client'; -import { buildApiServer } from '../../src/api/init'; -import { PgStore } from '../../src/pg/pg-store'; -import { BlockProposalsEntry } from '../../src/api/schemas'; -import { PoxInfo, RpcStackerSetResponse } from '../../src/stacks-core-rpc/stacks-core-rpc-client'; -import { rpcStackerSetToDbRewardSetSigners } from '../../src/stacks-core-rpc/stacker-set-updater'; -import { io, Socket } from 'socket.io-client'; -import { ClientToServerEvents, ServerToClientEvents } from '../../src/api/routes/socket-io'; -import { waitForEvent } from '../../src/helpers'; -import { ENV } from '../../src/env'; - -describe('Db notifications tests', () => { +import * as fs from "node:fs"; +import * as readline from "node:readline/promises"; +import * as zlib from "node:zlib"; +import * as supertest from "supertest"; +import { FastifyInstance } from "fastify"; +import { StacksPayload } from "@hirosystems/chainhook-client"; +import { buildApiServer } from "../../src/api/init"; +import { PgStore } from "../../src/pg/pg-store"; +import { BlockProposalsEntry } from "../../src/api/schemas"; +import { + PoxInfo, + RpcStackerSetResponse, +} from "../../src/stacks-core-rpc/stacks-core-rpc-client"; +import { rpcStackerSetToDbRewardSetSigners } from "../../src/stacks-core-rpc/stacker-set-updater"; +import { io, Socket } from "socket.io-client"; +import { + ClientToServerEvents, + ServerToClientEvents, +} from "../../src/api/routes/socket-io"; +import { waitForEvent } from "../../src/helpers"; +import { ENV } from "../../src/env"; + +describe("Db notifications tests", () => { let db: PgStore; let apiServer: FastifyInstance; let socketClient: Socket; - const testingBlockHash = '0x2f1c4e83fda403682b1ab5dd41383e47d2cb3dfec0fd26f0886883462d7802fb'; + const testingBlockHash = + "0x2f1c4e83fda403682b1ab5dd41383e47d2cb3dfec0fd26f0886883462d7802fb"; let proposalTestPayload: StacksPayload; let blockPushTestPayload: StacksPayload; @@ -28,26 +35,32 @@ describe('Db notifications tests', () => { db = await PgStore.connect(); db.notifications._sqlNotifyDisabled = true; apiServer = await buildApiServer({ db }); - await apiServer.listen({ port: 0, host: '127.0.0.1' }); + await apiServer.listen({ port: 0, host: "127.0.0.1" }); // insert pox-info dump const poxInfoDump = JSON.parse( - fs.readFileSync('./tests/dumps/dump-pox-info-2024-11-02.json', 'utf8') + fs.readFileSync("./tests/dumps/dump-pox-info-2024-11-02.json", "utf8"), ) as PoxInfo; await db.updatePoxInfo(poxInfoDump); // insert stacker-set dump const stackerSetDump = JSON.parse( - fs.readFileSync('./tests/dumps/dump-stacker-set-cycle-72-2024-11-02.json', 'utf8') + fs.readFileSync( + "./tests/dumps/dump-stacker-set-cycle-72-2024-11-02.json", + "utf8", + ), ) as RpcStackerSetResponse; await db.chainhook.insertRewardSetSigners( db.sql, - rpcStackerSetToDbRewardSetSigners(stackerSetDump, 72) + rpcStackerSetToDbRewardSetSigners(stackerSetDump, 72), ); // insert chainhook-payloads dump - const spyInfoLog = jest.spyOn(db.chainhook.logger, 'info').mockImplementation(() => {}); // Surpress noisy logs during bulk insertion test - const payloadDumpFile = './tests/dumps/dump-chainhook-payloads-2024-11-02.ndjson.gz'; + const spyInfoLog = jest + .spyOn(db.chainhook.logger, "info") + .mockImplementation(() => {}); // Surpress noisy logs during bulk insertion test + const payloadDumpFile = + "./tests/dumps/dump-chainhook-payloads-2024-11-02.ndjson.gz"; const rl = readline.createInterface({ input: fs.createReadStream(payloadDumpFile).pipe(zlib.createGunzip()), crlfDelay: Infinity, @@ -57,9 +70,10 @@ describe('Db notifications tests', () => { // find and store the test block proposal payload for later testing if (!proposalTestPayload) { const proposal = payload.events.find( - event => - event.payload.data.message.type === 'BlockProposal' && - event.payload.data.message.data.block.block_hash === testingBlockHash + (event) => + event.payload.data.message.type === "BlockProposal" && + event.payload.data.message.data.block.block_hash === + testingBlockHash, ); if (proposal) { proposalTestPayload = { ...payload, events: [proposal] }; @@ -67,9 +81,10 @@ describe('Db notifications tests', () => { } if (!blockPushTestPayload) { const blockPush = payload.events.find( - event => - event.payload.data.message.type === 'BlockPushed' && - event.payload.data.message.data.block.block_hash === testingBlockHash + (event) => + event.payload.data.message.type === "BlockPushed" && + event.payload.data.message.data.block.block_hash === + testingBlockHash, ); if (blockPush) { blockPushTestPayload = { ...payload, events: [blockPush] }; @@ -80,12 +95,15 @@ describe('Db notifications tests', () => { rl.close(); spyInfoLog.mockRestore(); - socketClient = io(`ws://127.0.0.1:${apiServer.addresses()[0].port}/block-proposals`, { - path: '/signer-metrics/socket.io/', - }); + socketClient = io( + `ws://127.0.0.1:${apiServer.addresses()[0].port}/block-proposals`, + { + path: "/signer-metrics/socket.io/", + }, + ); await new Promise((resolve, reject) => { - socketClient.on('connect', resolve); - socketClient.io.on('error', reject); + socketClient.on("connect", resolve); + socketClient.io.on("error", reject); }); db.notifications._sqlNotifyDisabled = false; }); @@ -96,100 +114,130 @@ describe('Db notifications tests', () => { await db.close(); }); - test('test block proposal write events', async () => { + test("test block proposal write events", async () => { const pgNotifyEvent = waitForEvent( db.notifications.events, - 'signerMessages', - msg => { - return 'proposal' in msg[0] && msg[0].proposal.blockHash === testingBlockHash; + "signerMessages", + (msg) => { + return ( + "proposal" in msg[0] && msg[0].proposal.blockHash === testingBlockHash + ); }, - AbortSignal.timeout(10000) + AbortSignal.timeout(10000), ); const initialWriteEvent = waitForEvent( db.chainhook.events, - 'signerMessages', - msg => { - return 'proposal' in msg[0] && msg[0].proposal.blockHash === testingBlockHash; + "signerMessages", + (msg) => { + return ( + "proposal" in msg[0] && msg[0].proposal.blockHash === testingBlockHash + ); }, - AbortSignal.timeout(10000) + AbortSignal.timeout(10000), ); - const clientSocketEvent = new Promise(resolve => { - socketClient.on('blockProposal', data => { + const clientSocketEvent = new Promise((resolve) => { + socketClient.on("blockProposal", (data) => { resolve(data); }); }); // delete block proposal from db, returning the data so we can re-write it - const blockProposal = await db.chainhook.deleteBlockProposal(db.sql, testingBlockHash); + const blockProposal = await db.chainhook.deleteBlockProposal( + db.sql, + testingBlockHash, + ); expect(blockProposal.block_hash).toBe(testingBlockHash); - const blockResponses = await db.chainhook.deleteBlockResponses(db.sql, testingBlockHash); + const blockResponses = await db.chainhook.deleteBlockResponses( + db.sql, + testingBlockHash, + ); expect(blockResponses.length).toBeGreaterThan(0); expect(blockResponses[0].signer_sighash).toBe(testingBlockHash); await db.chainhook.processPayload(proposalTestPayload); - const promiseResults = await Promise.all([pgNotifyEvent, initialWriteEvent, clientSocketEvent]); + const promiseResults = await Promise.all([ + pgNotifyEvent, + initialWriteEvent, + clientSocketEvent, + ]); expect( - promiseResults[0][0].find(r => 'proposal' in r && r.proposal.blockHash === testingBlockHash) + promiseResults[0][0].find( + (r) => "proposal" in r && r.proposal.blockHash === testingBlockHash, + ), ).toBeTruthy(); expect( - promiseResults[1][0].find(r => 'proposal' in r && r.proposal.blockHash === testingBlockHash) + promiseResults[1][0].find( + (r) => "proposal" in r && r.proposal.blockHash === testingBlockHash, + ), ).toBeTruthy(); expect(promiseResults[2].block_hash).toBe(testingBlockHash); }); - test('test block push write events', async () => { + test("test block push write events", async () => { const pgNotifyEvent = waitForEvent( db.notifications.events, - 'signerMessages', - msg => { - return 'push' in msg[0] && msg[0].push.blockHash === testingBlockHash; + "signerMessages", + (msg) => { + return "push" in msg[0] && msg[0].push.blockHash === testingBlockHash; }, - AbortSignal.timeout(10000) + AbortSignal.timeout(10000), ); const initialWriteEvent = waitForEvent( db.chainhook.events, - 'signerMessages', - msg => { - return 'push' in msg[0] && msg[0].push.blockHash === testingBlockHash; + "signerMessages", + (msg) => { + return "push" in msg[0] && msg[0].push.blockHash === testingBlockHash; }, - AbortSignal.timeout(10000) + AbortSignal.timeout(10000), ); - const clientSocketEvent = new Promise(resolve => { - socketClient.on('blockProposal', data => { + const clientSocketEvent = new Promise((resolve) => { + socketClient.on("blockProposal", (data) => { resolve(data); }); }); // delete block proposal from db, returning the data so we can re-write it - const blockPush = await db.chainhook.deleteBlockPush(db.sql, testingBlockHash); + const blockPush = await db.chainhook.deleteBlockPush( + db.sql, + testingBlockHash, + ); expect(blockPush.block_hash).toBe(testingBlockHash); await db.chainhook.processPayload(blockPushTestPayload); - const promiseResults = await Promise.all([pgNotifyEvent, initialWriteEvent, clientSocketEvent]); + const promiseResults = await Promise.all([ + pgNotifyEvent, + initialWriteEvent, + clientSocketEvent, + ]); expect( - promiseResults[0][0].find(r => 'push' in r && r.push.blockHash === testingBlockHash) + promiseResults[0][0].find( + (r) => "push" in r && r.push.blockHash === testingBlockHash, + ), ).toBeTruthy(); expect( - promiseResults[1][0].find(r => 'push' in r && r.push.blockHash === testingBlockHash) + promiseResults[1][0].find( + (r) => "push" in r && r.push.blockHash === testingBlockHash, + ), ).toBeTruthy(); expect(promiseResults[2].block_hash).toBe(testingBlockHash); }); - test('prometheus signer metrics', async () => { - const bucketsEnvName = 'SIGNER_PROMETHEUS_METRICS_BLOCK_PERIODS'; + test("prometheus signer metrics", async () => { + const bucketsEnvName = "SIGNER_PROMETHEUS_METRICS_BLOCK_PERIODS"; + const metricPrefix = "signer_api_"; const orig = ENV[bucketsEnvName]; const buckets = [1, 2, 3, 5, 10, 100, 1000]; - process.env[bucketsEnvName] = buckets.join(','); + process.env[bucketsEnvName] = buckets.join(","); ENV.reload(); - const blockRanges = ENV[bucketsEnvName].split(',').map(Number); + const blockRanges = ENV[bucketsEnvName].split(",").map(Number); // Delete from confirmed blocks tables to ensure there is a pending block_proposal const [{ block_height }] = await db.sql< @@ -198,11 +246,18 @@ describe('Db notifications tests', () => { await db.sql`DELETE FROM blocks WHERE block_height >= ${block_height}`; await db.sql`DELETE FROM block_pushes WHERE block_height >= ${block_height}`; - const pendingProposalDate = await db.getLastPendingProposalDate({ sql: db.sql }); + const pendingProposalDate = await db.getLastPendingProposalDate({ + sql: db.sql, + }); expect(pendingProposalDate).toBeInstanceOf(Date); - expect(new Date().getTime() - pendingProposalDate!.getTime()).toBeGreaterThan(0); + expect( + new Date().getTime() - pendingProposalDate!.getTime(), + ).toBeGreaterThan(0); - const dbPushMetricsResult = await db.getRecentBlockPushMetrics({ sql: db.sql, blockRanges }); + const dbPushMetricsResult = await db.getRecentBlockPushMetrics({ + sql: db.sql, + blockRanges, + }); expect(dbPushMetricsResult).toEqual([ { block_range: 1, avg_push_time_ms: 27262 }, { block_range: 2, avg_push_time_ms: 30435.5 }, @@ -227,57 +282,69 @@ describe('Db notifications tests', () => { { acceptance_rate: 0.7778, block_range: 1000 }, ]); - const dbMetricsResult = await db.getRecentSignerMetrics({ sql: db.sql, blockRanges }); + const dbMetricsResult = await db.getRecentSignerMetrics({ + sql: db.sql, + blockRanges, + }); expect(dbMetricsResult).toEqual( expect.arrayContaining([ { - signer_key: '0x03fc7cb917698b6137060f434988f7688520972dfb944f9b03c0fbf1c75303e79a', + signer_key: + "0x03fc7cb917698b6137060f434988f7688520972dfb944f9b03c0fbf1c75303e79a", block_ranges: { - '1': { missing: 0, accepted: 1, rejected: 0 }, - '2': { missing: 0, accepted: 2, rejected: 0 }, - '3': { missing: 0, accepted: 3, rejected: 0 }, - '5': { missing: 0, accepted: 5, rejected: 0 }, - '10': { missing: 0, accepted: 10, rejected: 0 }, - '100': { missing: 1, accepted: 86, rejected: 12 }, - '1000': { missing: 1, accepted: 86, rejected: 12 }, + "1": { missing: 0, accepted: 1, rejected: 0 }, + "2": { missing: 0, accepted: 2, rejected: 0 }, + "3": { missing: 0, accepted: 3, rejected: 0 }, + "5": { missing: 0, accepted: 5, rejected: 0 }, + "10": { missing: 0, accepted: 10, rejected: 0 }, + "100": { missing: 1, accepted: 86, rejected: 12 }, + "1000": { missing: 1, accepted: 86, rejected: 12 }, }, }, - ]) + ]), ); const responseTest = await supertest(apiServer.server) - .get('/signer-metrics/metrics') + .get("/signer-metrics/metrics") .expect(200); - const receivedLines = responseTest.text.split('\n'); + const receivedLines = responseTest.text.split("\n"); - const expectedPendingProposalLineRegex = - /# TYPE time_since_last_pending_block_proposal_ms gauge\ntime_since_last_pending_block_proposal_ms [1-9]\d*/; + const expectedPendingProposalLineRegex = new RegExp( + `# TYPE ${metricPrefix}time_since_last_pending_block_proposal_ms gauge\n${metricPrefix}time_since_last_pending_block_proposal_ms [1-9]\d*`, + "g", + ); expect(responseTest.text).toMatch(expectedPendingProposalLineRegex); - const expectedPushTimeLines = `# TYPE avg_block_push_time_ms gauge -avg_block_push_time_ms{period="1"} 27262 -avg_block_push_time_ms{period="2"} 30435.5 -avg_block_push_time_ms{period="3"} 28167.333`; - expect(receivedLines).toEqual(expect.arrayContaining(expectedPushTimeLines.split('\n'))); - - const expectedAcceptanceRateLines = `# TYPE proposal_acceptance_rate gauge -proposal_acceptance_rate{period="1"} 0 -proposal_acceptance_rate{period="2"} 0.5 -proposal_acceptance_rate{period="3"} 0.6667 -proposal_acceptance_rate{period="5"} 0.6 -proposal_acceptance_rate{period="10"} 0.8 -proposal_acceptance_rate{period="100"} 0.7778 -proposal_acceptance_rate{period="1000"} 0.7778`; - expect(receivedLines).toEqual(expect.arrayContaining(expectedAcceptanceRateLines.split('\n'))); - - const expectedSignerStateLines = `# TYPE signer_state_count gauge -signer_state_count{signer="0x03fc7cb917698b6137060f434988f7688520972dfb944f9b03c0fbf1c75303e79a",period="1",state="missing"} 0 -signer_state_count{signer="0x03fc7cb917698b6137060f434988f7688520972dfb944f9b03c0fbf1c75303e79a",period="1",state="accepted"} 1 -signer_state_count{signer="0x03fc7cb917698b6137060f434988f7688520972dfb944f9b03c0fbf1c75303e79a",period="1",state="rejected"} 0 -signer_state_count{signer="0x03fc7cb917698b6137060f434988f7688520972dfb944f9b03c0fbf1c75303e79a",period="2",state="missing"} 0 -signer_state_count{signer="0x03fc7cb917698b6137060f434988f7688520972dfb944f9b03c0fbf1c75303e79a",period="2",state="accepted"} 2 -signer_state_count{signer="0x03fc7cb917698b6137060f434988f7688520972dfb944f9b03c0fbf1c75303e79a",period="2",state="rejected"} 0`; - expect(receivedLines).toEqual(expect.arrayContaining(expectedSignerStateLines.split('\n'))); + const expectedPushTimeLines = `# TYPE ${metricPrefix}avg_block_push_time_ms gauge +${metricPrefix}avg_block_push_time_ms{period="1"} 27262 +${metricPrefix}avg_block_push_time_ms{period="2"} 30435.5 +${metricPrefix}avg_block_push_time_ms{period="3"} 28167.333`; + expect(receivedLines).toEqual( + expect.arrayContaining(expectedPushTimeLines.split("\n")), + ); + + const expectedAcceptanceRateLines = `# TYPE ${metricPrefix}proposal_acceptance_rate gauge +${metricPrefix}proposal_acceptance_rate{period="1"} 0 +${metricPrefix}proposal_acceptance_rate{period="2"} 0.5 +${metricPrefix}proposal_acceptance_rate{period="3"} 0.6667 +${metricPrefix}proposal_acceptance_rate{period="5"} 0.6 +${metricPrefix}proposal_acceptance_rate{period="10"} 0.8 +${metricPrefix}proposal_acceptance_rate{period="100"} 0.7778 +${metricPrefix}proposal_acceptance_rate{period="1000"} 0.7778`; + expect(receivedLines).toEqual( + expect.arrayContaining(expectedAcceptanceRateLines.split("\n")), + ); + + const expectedSignerStateLines = `# TYPE ${metricPrefix}signer_state_count gauge +${metricPrefix}signer_state_count{signer="0x03fc7cb917698b6137060f434988f7688520972dfb944f9b03c0fbf1c75303e79a",period="1",state="missing"} 0 +${metricPrefix}signer_state_count{signer="0x03fc7cb917698b6137060f434988f7688520972dfb944f9b03c0fbf1c75303e79a",period="1",state="accepted"} 1 +${metricPrefix}signer_state_count{signer="0x03fc7cb917698b6137060f434988f7688520972dfb944f9b03c0fbf1c75303e79a",period="1",state="rejected"} 0 +${metricPrefix}signer_state_count{signer="0x03fc7cb917698b6137060f434988f7688520972dfb944f9b03c0fbf1c75303e79a",period="2",state="missing"} 0 +${metricPrefix}signer_state_count{signer="0x03fc7cb917698b6137060f434988f7688520972dfb944f9b03c0fbf1c75303e79a",period="2",state="accepted"} 2 +${metricPrefix}signer_state_count{signer="0x03fc7cb917698b6137060f434988f7688520972dfb944f9b03c0fbf1c75303e79a",period="2",state="rejected"} 0`; + expect(receivedLines).toEqual( + expect.arrayContaining(expectedSignerStateLines.split("\n")), + ); process.env[bucketsEnvName] = orig; ENV.reload();