From 639623eb75dfc7abef0cdb3e5f5be8104e917c56 Mon Sep 17 00:00:00 2001 From: Will Hunt Date: Wed, 22 May 2019 21:42:16 +0100 Subject: [PATCH 01/22] Add support for metrics --- package.json | 1 + src/bot.ts | 14 +++++++++++--- src/config.ts | 1 + src/db/roomstore.ts | 9 +++++++++ src/db/userstore.ts | 7 ++++++- src/discordas.ts | 8 +++++++- src/presencehandler.ts | 4 ++++ 7 files changed, 39 insertions(+), 5 deletions(-) diff --git a/package.json b/package.json index 4e19eaaf..aa0b475d 100644 --- a/package.json +++ b/package.json @@ -47,6 +47,7 @@ "node-html-parser": "^1.1.11", "p-queue": "^5.0.0", "pg-promise": "^8.5.1", + "prom-client": "^11.3.0", "tslint": "^5.11.0", "typescript": "^3.1.3", "winston": "^3.0.0", diff --git a/src/bot.ts b/src/bot.ts index 2c7ec056..13b0ecf9 100644 --- a/src/bot.ts +++ b/src/bot.ts @@ -37,6 +37,7 @@ import * as Discord from "discord.js"; import * as mime from "mime"; import { IMatrixEvent, IMatrixMediaInfo } from "./matrixtypes"; import { DiscordCommandHandler } from "./discordcommandhandler"; +import { MetricPeg } from "./metrics"; const log = new Log("DiscordBot"); @@ -288,12 +289,14 @@ export class DiscordBot { }); client.on("message", async (msg: Discord.Message) => { try { + MetricPeg.get.registerRequest(msg.id); await this.waitUnlock(msg.channel); this.discordMessageQueue[msg.channel.id] = (async () => { await (this.discordMessageQueue[msg.channel.id] || Promise.resolve()); try { await this.OnMessage(msg); } catch (err) { + MetricPeg.get.requestOutcome(msg.id, true, "fail"); log.error("Caught while handing 'message'", err); } })(); @@ -738,11 +741,13 @@ export class DiscordBot { if (indexOfMsg !== -1) { log.verbose("Got repeated message, ignoring."); delete this.sentMessages[indexOfMsg]; + MetricPeg.get.requestOutcome(msg.id, true, "dropped"); return; // Skip *our* messages } const chan = msg.channel as Discord.TextChannel; if (msg.author.id === this.bot.user.id) { // We don't support double bridging. + MetricPeg.get.requestOutcome(msg.id, true, "dropped"); return; } // Test for webhooks @@ -751,6 +756,7 @@ export class DiscordBot { .filterArray((h) => h.name === "_matrix").pop(); if (webhook && msg.webhookID === webhook.id) { // Filter out our own webhook messages. + MetricPeg.get.requestOutcome(msg.id, true, "dropped"); return; } } @@ -758,6 +764,7 @@ export class DiscordBot { // check if it is a command to process by the bot itself if (msg.content.startsWith("!matrix")) { await this.discordCommandHandler.Process(msg); + MetricPeg.get.requestOutcome(msg.id, true, "success"); return; } @@ -766,14 +773,13 @@ export class DiscordBot { let rooms; try { rooms = await this.channelSync.GetRoomIdsFromChannel(msg.channel); + if (rooms === null) { throw Error() } } catch (err) { log.verbose("No bridged rooms to send message to. Oh well."); + MetricPeg.get.requestOutcome(msg.id, true, "dropped"); return null; } try { - if (rooms === null) { - return null; - } const intent = this.GetIntentFromDiscordMember(msg.author, msg.webhookID); // Check Attachements await Util.AsyncForEach(msg.attachments.array(), async (attachment) => { @@ -854,7 +860,9 @@ export class DiscordBot { await afterSend(res); } }); + MetricPeg.get.requestOutcome(msg.id, true, "success"); } catch (err) { + MetricPeg.get.requestOutcome(msg.id, true, "fail"); log.verbose("Failed to send message into room.", err); } } diff --git a/src/config.ts b/src/config.ts index 16660431..0fd5c6df 100644 --- a/src/config.ts +++ b/src/config.ts @@ -56,6 +56,7 @@ class DiscordBridgeConfigBridge { public disableEveryoneMention: boolean = false; public disableHereMention: boolean = false; public disableJoinLeaveNotifications: boolean = false; + public enableMetrics: boolean = false; } export class DiscordBridgeConfigDatabase { diff --git a/src/db/roomstore.ts b/src/db/roomstore.ts index c04230e0..72677cc9 100644 --- a/src/db/roomstore.ts +++ b/src/db/roomstore.ts @@ -19,6 +19,7 @@ import { Util } from "../util"; import * as uuid from "uuid/v4"; import { Postgres } from "./postgres"; +import { MetricPeg } from "../metrics"; const log = new Log("DbRoomStore"); @@ -155,8 +156,10 @@ export class DbRoomStore { public async getEntriesByMatrixId(matrixId: string): Promise { const cached = this.entriesMatrixIdCache.get(matrixId); if (cached && cached.ts + ENTRY_CACHE_LIMETIME > Date.now()) { + MetricPeg.get.storeCall("getEntriesByMatrixId", true); return cached.e; } + MetricPeg.get.storeCall("getEntriesByMatrixId", false); const entries = await this.db.All( "SELECT * FROM room_entries WHERE matrix_id = $id", {id: matrixId}, ); @@ -190,6 +193,7 @@ export class DbRoomStore { } public async getEntriesByMatrixIds(matrixIds: string[]): Promise { + MetricPeg.get.storeCall("getEntriesByMatrixIds", false); const mxIdMap = { }; matrixIds.forEach((mxId, i) => mxIdMap[i] = mxId); const sql = `SELECT * FROM room_entries WHERE matrix_id IN (${matrixIds.map((_, id) => `\$${id}`).join(", ")})`; @@ -222,6 +226,7 @@ export class DbRoomStore { } public async linkRooms(matrixRoom: MatrixStoreRoom, remoteRoom: RemoteStoreRoom) { + MetricPeg.get.storeCall("linkRooms", false); await this.upsertRoom(remoteRoom); const values = { @@ -244,6 +249,7 @@ export class DbRoomStore { } public async getEntriesByRemoteRoomData(data: IRemoteRoomDataLazy): Promise { + MetricPeg.get.storeCall("getEntriesByRemoteRoomData", false); Object.keys(data).filter((k) => typeof(data[k]) === "boolean").forEach((k) => { data[k] = Number(data[k]); }); @@ -270,11 +276,13 @@ export class DbRoomStore { } public async removeEntriesByRemoteRoomId(remoteId: string) { + MetricPeg.get.storeCall("removeEntriesByRemoteRoomId", false); await this.db.Run(`DELETE FROM room_entries WHERE remote_id = $remoteId`, {remoteId}); await this.db.Run(`DELETE FROM remote_room_data WHERE room_id = $remoteId`, {remoteId}); } public async removeEntriesByMatrixRoomId(matrixId: string) { + MetricPeg.get.storeCall("removeEntriesByMatrixRoomId", false); const entries = (await this.db.All(`SELECT * FROM room_entries WHERE matrix_id = $matrixId`, {matrixId})) || []; await Util.AsyncForEach(entries, async (entry) => { if (entry.remote_id) { @@ -286,6 +294,7 @@ export class DbRoomStore { } private async upsertRoom(room: RemoteStoreRoom) { + MetricPeg.get.storeCall("upsertRoom", false); if (!room.data) { throw new Error("Tried to upsert a room with undefined data"); } diff --git a/src/db/userstore.ts b/src/db/userstore.ts index cb1251e2..c8542074 100644 --- a/src/db/userstore.ts +++ b/src/db/userstore.ts @@ -15,8 +15,8 @@ limitations under the License. */ import { IDatabaseConnector } from "./connector"; -import * as uuid from "uuid/v4"; import { Log } from "../log"; +import { MetricPeg } from "../metrics"; /** * A UserStore compatible with @@ -54,8 +54,11 @@ export class DbUserStore { public async getRemoteUser(remoteId: string): Promise { const cached = this.remoteUserCache.get(remoteId); if (cached && cached.ts + ENTRY_CACHE_LIMETIME > Date.now()) { + MetricPeg.get.storeCall("getRemoteUser", true); return cached.e; } + MetricPeg.get.storeCall("getRemoteUser", false); + const row = await this.db.Get( "SELECT * FROM user_entries WHERE remote_id = $id", {id: remoteId}, ); @@ -86,6 +89,7 @@ export class DbUserStore { } public async setRemoteUser(user: RemoteUser) { + MetricPeg.get.storeCall("setRemoteUser", false); this.remoteUserCache.delete(user.id); const existingData = await this.db.Get( "SELECT * FROM remote_user_data WHERE remote_id = $remoteId", @@ -156,6 +160,7 @@ AND guild_id = $guild_id`, } public async linkUsers(matrixId: string, remoteId: string) { + MetricPeg.get.storeCall("linkUsers", false); // This is used ONCE in the bridge to link two IDs, so do not UPSURT data. try { await this.db.Run(`INSERT INTO user_entries VALUES ($matrixId, $remoteId)`, { diff --git a/src/discordas.ts b/src/discordas.ts index 0f4b5e11..6b74b7dc 100644 --- a/src/discordas.ts +++ b/src/discordas.ts @@ -22,6 +22,7 @@ import { DiscordBot } from "./bot"; import { DiscordStore } from "./store"; import { Log } from "./log"; import "source-map-support/register"; +import { MetricPeg } from "./metrics"; const log = new Log("DiscordAS"); @@ -93,13 +94,16 @@ async function run(port: number, fileConfig: DiscordBridgeConfig) { } catch (err) { log.error("Exception thrown while handling \"onAliasQuery\" event", err); } }, onEvent: async (request) => { + const data = request.getData(); try { + MetricPeg.get.registerRequest(data.event_id); // Build our own context. if (!store.roomStore) { log.warn("Discord store not ready yet, dropping message"); + MetricPeg.get.requestOutcome(data.event_id, false, "dropped"); return; } - const roomId = request.getData().room_id; + const roomId = data.room_id; const context: BridgeContext = { rooms: {}, @@ -111,7 +115,9 @@ async function run(port: number, fileConfig: DiscordBridgeConfig) { } await request.outcomeFrom(callbacks.onEvent(request, context)); + MetricPeg.get.requestOutcome(data.event_id, false, "success"); } catch (err) { + MetricPeg.get.requestOutcome(data.event_id, false, "fail"); log.error("Exception thrown while handling \"onEvent\" event", err); await request.outcomeFrom(Promise.reject("Failed to handle")); } diff --git a/src/presencehandler.ts b/src/presencehandler.ts index 16fa4a97..91343e60 100644 --- a/src/presencehandler.ts +++ b/src/presencehandler.ts @@ -17,6 +17,7 @@ limitations under the License. import { User, Presence } from "discord.js"; import { DiscordBot } from "./bot"; import { Log } from "./log"; +import { MetricPeg } from "./metrics"; const log = new Log("PresenceHandler"); export class PresenceHandlerStatus { @@ -66,6 +67,7 @@ export class PresenceHandler { if (user.id !== this.bot.GetBotId() && this.presenceQueue.find((u) => u.id === user.id) === undefined) { log.info(`Adding ${user.id} (${user.username}) to the presence queue`); this.presenceQueue.push(user); + MetricPeg.get.setPresenceCount(this.presenceQueue.length); } } @@ -75,6 +77,7 @@ export class PresenceHandler { }); if (index !== -1) { this.presenceQueue.splice(index, 1); + MetricPeg.get.setPresenceCount(this.presenceQueue.length); } else { log.warn( `Tried to remove ${user.id} from the presence queue but it could not be found`, @@ -96,6 +99,7 @@ export class PresenceHandler { this.presenceQueue.push(user); } else { log.info(`Dropping ${user.id} from the presence queue.`); + MetricPeg.get.setPresenceCount(this.presenceQueue.length); } } } From c4ae6be5182ea1dc8d94dec50273982f86d68e0a Mon Sep 17 00:00:00 2001 From: Will Hunt Date: Wed, 22 May 2019 21:52:05 +0100 Subject: [PATCH 02/22] Dammit metrics.ts --- src/metrics.ts | 132 +++++++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 132 insertions(+) create mode 100644 src/metrics.ts diff --git a/src/metrics.ts b/src/metrics.ts new file mode 100644 index 00000000..82329d82 --- /dev/null +++ b/src/metrics.ts @@ -0,0 +1,132 @@ +import { PrometheusMetrics } from "matrix-appservice-bridge"; +import { Gauge, Counter, Histogram } from "prom-client"; +import { Log } from "./log"; + +const AgeCounters = PrometheusMetrics.AgeCounters; +const log = new Log("BridgeMetrics"); + +interface IAgeCounter { + setGauge(gauge: Gauge, morelabels: any); + bump(age: number); +} + +interface IBridgeGauges { + matrixRoomConfigs: number; + remoteRoomConfigs: number; + matrixGhosts: number; + remoteGhosts: number; + matrixRoomsByAge: IAgeCounter; + remoteRoomsByAge: IAgeCounter; + matrixUsersByAge: IAgeCounter; + remoteUsersByAge: IAgeCounter; +} + +export interface IBridgeMetrics { + registerRequest(id: string); + requestOutcome(id: string, isRemote: boolean, outcome: string); + remoteCall(method: string); + setPresenceCount(count: number); + storeCall(method: string, cached: boolean); +} + +export class DummyBridgeMetrics implements IBridgeMetrics { + registerRequest() {} + requestOutcome() {} + remoteCall() {} + setPresenceCount() {} + storeCall() {} +} + +export class MetricPeg { + private static _metrics: IBridgeMetrics = new DummyBridgeMetrics(); + + public static get get() : IBridgeMetrics { + return this._metrics; + } + + public static setMetrics(metrics: IBridgeMetrics) { + this._metrics = metrics; + } +} + + +export class PrometheusBridgeMetrics implements IBridgeMetrics { + private metrics; + private remoteCallCounter: Counter; + private storeCallCounter: Counter; + private presenceGauge: Gauge; + private remoteRequest: Histogram; + private matrixRequest: Histogram; + private requestsInFlight: Map; + private bridgeGauges: IBridgeGauges = { + matrixRoomConfigs: 0, + remoteRoomConfigs: 0, + matrixGhosts: 0, + remoteGhosts: 0, + matrixRoomsByAge: new AgeCounters(), + remoteRoomsByAge: new AgeCounters(), + matrixUsersByAge: new AgeCounters(), + remoteUsersByAge: new AgeCounters(), + }; + + public init(bridge: any) { + this.metrics = new PrometheusMetrics(); + this.metrics.registerMatrixSdkMetrics(); + this.metrics.registerBridgeGauges(() => this.bridgeGauges); + this.metrics.addAppServicePath(bridge); + this.remoteCallCounter = this.metrics.addCounter({ + name: "remote_api_calls", + help: "Count of remote API calls made", + labels: ["method"], + }); + this.storeCallCounter = this.metrics.addCounter({ + name: "store_calls", + help: "Count of store function calls made", + labels: ["method", "cached"], + }); + this.presenceGauge = this.metrics.addGauge({ + name: "active_presence_users", + help: "Count of users in the presence queue", + labels: [], + }); + this.matrixRequest = this.metrics.addTimer({ + name: "matrix_request_seconds", + help: "Histogram of processing durations of received Matrix messages", + labels: ["outcome"], + }); + this.remoteRequest = this.metrics.addTimer({ + name: "remote_request_seconds", + help: "Histogram of processing durations of received remote messages", + labels: ["outcome"], + }); + this.requestsInFlight = new Map(); + return this; + } + + public registerRequest(id: string) { + this.requestsInFlight.set(id, Date.now()); + } + + public requestOutcome(id: string, isRemote: boolean, outcome: string) { + const startTime = this.requestsInFlight.get(id); + if (!startTime) { + log.verbose(`Got "requestOutcome" for ${id}, but this request was never started`); + return; + } + const duration = Date.now() - startTime; + (isRemote ? this.remoteRequest : this.matrixRequest).observe({outcome}, duration / 1000); + } + + public setPresenceCount(count: number) { + this.presenceGauge.set(count); + } + + public remoteCall(method: string) { + this.remoteCallCounter.inc({method}); + } + + public storeCall(method: string, cached: boolean) { + this.storeCallCounter.inc({method, cached: cached ? "yes" : "no"}); + } +}; + From 3d9a6777fd5bc2b8c1537e67ca1b5b4f67be2398 Mon Sep 17 00:00:00 2001 From: Will Hunt Date: Wed, 22 May 2019 22:00:31 +0100 Subject: [PATCH 03/22] Enable the metrics --- src/discordas.ts | 7 ++++++- 1 file changed, 6 insertions(+), 1 deletion(-) diff --git a/src/discordas.ts b/src/discordas.ts index 6b74b7dc..2bbe88ff 100644 --- a/src/discordas.ts +++ b/src/discordas.ts @@ -22,7 +22,7 @@ import { DiscordBot } from "./bot"; import { DiscordStore } from "./store"; import { Log } from "./log"; import "source-map-support/register"; -import { MetricPeg } from "./metrics"; +import { MetricPeg, PrometheusBridgeMetrics } from "./metrics"; const log = new Log("DiscordAS"); @@ -162,6 +162,11 @@ async function run(port: number, fileConfig: DiscordBridgeConfig) { + "The config option userStorePath no longer has any use."); } + if (config.bridge.enableMetrics) { + log.info("Enabled metrics"); + MetricPeg.setMetrics(new PrometheusBridgeMetrics().init(bridge)); + } + await bridge.run(port, config); log.info(`Started listening on port ${port}`); From 4397227dd6b77e39b6e15686dda5bbfdaef5d61d Mon Sep 17 00:00:00 2001 From: Will Hunt Date: Wed, 22 May 2019 22:02:26 +0100 Subject: [PATCH 04/22] Wait for bridge to start first --- src/discordas.ts | 9 +++++---- 1 file changed, 5 insertions(+), 4 deletions(-) diff --git a/src/discordas.ts b/src/discordas.ts index 2bbe88ff..64e5f6c9 100644 --- a/src/discordas.ts +++ b/src/discordas.ts @@ -162,14 +162,15 @@ async function run(port: number, fileConfig: DiscordBridgeConfig) { + "The config option userStorePath no longer has any use."); } - if (config.bridge.enableMetrics) { - log.info("Enabled metrics"); - MetricPeg.setMetrics(new PrometheusBridgeMetrics().init(bridge)); - } await bridge.run(port, config); log.info(`Started listening on port ${port}`); + if (config.bridge.enableMetrics) { + log.info("Enabled metrics"); + MetricPeg.setMetrics(new PrometheusBridgeMetrics().init(bridge)); + } + try { await store.init(undefined, bridge.getRoomStore(), bridge.getUserStore()); } catch (ex) { From 663eebc7b2f3f81ab986d754ad1a1d59d2915fa5 Mon Sep 17 00:00:00 2001 From: Will Hunt Date: Wed, 22 May 2019 22:31:12 +0100 Subject: [PATCH 05/22] Expire old requests in metrics --- src/metrics.ts | 9 +++++++++ 1 file changed, 9 insertions(+) diff --git a/src/metrics.ts b/src/metrics.ts index 82329d82..698c0daf 100644 --- a/src/metrics.ts +++ b/src/metrics.ts @@ -4,6 +4,7 @@ import { Log } from "./log"; const AgeCounters = PrometheusMetrics.AgeCounters; const log = new Log("BridgeMetrics"); +const REQUEST_EXPIRE_TIME_MS = 30000; interface IAgeCounter { setGauge(gauge: Gauge, morelabels: any); @@ -100,6 +101,13 @@ export class PrometheusBridgeMetrics implements IBridgeMetrics { labels: ["outcome"], }); this.requestsInFlight = new Map(); + setInterval(() => { + this.requestsInFlight.forEach((time, id) => { + if (Date.now() - time) { + this.requestsInFlight.delete(id); + } + }); + }, REQUEST_EXPIRE_TIME_MS) return this; } @@ -109,6 +117,7 @@ export class PrometheusBridgeMetrics implements IBridgeMetrics { public requestOutcome(id: string, isRemote: boolean, outcome: string) { const startTime = this.requestsInFlight.get(id); + this.requestsInFlight.delete(id); if (!startTime) { log.verbose(`Got "requestOutcome" for ${id}, but this request was never started`); return; From d6173469fb1ac180dfe12637743877a41364221b Mon Sep 17 00:00:00 2001 From: Will Hunt Date: Wed, 22 May 2019 22:58:34 +0100 Subject: [PATCH 06/22] Store prefixes --- src/db/roomstore.ts | 16 ++++++++-------- src/db/userstore.ts | 8 ++++---- 2 files changed, 12 insertions(+), 12 deletions(-) diff --git a/src/db/roomstore.ts b/src/db/roomstore.ts index 72677cc9..2cb9d9f0 100644 --- a/src/db/roomstore.ts +++ b/src/db/roomstore.ts @@ -156,10 +156,10 @@ export class DbRoomStore { public async getEntriesByMatrixId(matrixId: string): Promise { const cached = this.entriesMatrixIdCache.get(matrixId); if (cached && cached.ts + ENTRY_CACHE_LIMETIME > Date.now()) { - MetricPeg.get.storeCall("getEntriesByMatrixId", true); + MetricPeg.get.storeCall("RoomStore.getEntriesByMatrixId", true); return cached.e; } - MetricPeg.get.storeCall("getEntriesByMatrixId", false); + MetricPeg.get.storeCall("RoomStore.getEntriesByMatrixId", false); const entries = await this.db.All( "SELECT * FROM room_entries WHERE matrix_id = $id", {id: matrixId}, ); @@ -193,7 +193,7 @@ export class DbRoomStore { } public async getEntriesByMatrixIds(matrixIds: string[]): Promise { - MetricPeg.get.storeCall("getEntriesByMatrixIds", false); + MetricPeg.get.storeCall("RoomStore.getEntriesByMatrixIds", false); const mxIdMap = { }; matrixIds.forEach((mxId, i) => mxIdMap[i] = mxId); const sql = `SELECT * FROM room_entries WHERE matrix_id IN (${matrixIds.map((_, id) => `\$${id}`).join(", ")})`; @@ -226,7 +226,7 @@ export class DbRoomStore { } public async linkRooms(matrixRoom: MatrixStoreRoom, remoteRoom: RemoteStoreRoom) { - MetricPeg.get.storeCall("linkRooms", false); + MetricPeg.get.storeCall("RoomStore.linkRooms", false); await this.upsertRoom(remoteRoom); const values = { @@ -249,7 +249,7 @@ export class DbRoomStore { } public async getEntriesByRemoteRoomData(data: IRemoteRoomDataLazy): Promise { - MetricPeg.get.storeCall("getEntriesByRemoteRoomData", false); + MetricPeg.get.storeCall("RoomStore.getEntriesByRemoteRoomData", false); Object.keys(data).filter((k) => typeof(data[k]) === "boolean").forEach((k) => { data[k] = Number(data[k]); }); @@ -276,13 +276,13 @@ export class DbRoomStore { } public async removeEntriesByRemoteRoomId(remoteId: string) { - MetricPeg.get.storeCall("removeEntriesByRemoteRoomId", false); + MetricPeg.get.storeCall("RoomStore.removeEntriesByRemoteRoomId", false); await this.db.Run(`DELETE FROM room_entries WHERE remote_id = $remoteId`, {remoteId}); await this.db.Run(`DELETE FROM remote_room_data WHERE room_id = $remoteId`, {remoteId}); } public async removeEntriesByMatrixRoomId(matrixId: string) { - MetricPeg.get.storeCall("removeEntriesByMatrixRoomId", false); + MetricPeg.get.storeCall("RoomStore.removeEntriesByMatrixRoomId", false); const entries = (await this.db.All(`SELECT * FROM room_entries WHERE matrix_id = $matrixId`, {matrixId})) || []; await Util.AsyncForEach(entries, async (entry) => { if (entry.remote_id) { @@ -294,7 +294,7 @@ export class DbRoomStore { } private async upsertRoom(room: RemoteStoreRoom) { - MetricPeg.get.storeCall("upsertRoom", false); + MetricPeg.get.storeCall("RoomStore.upsertRoom", false); if (!room.data) { throw new Error("Tried to upsert a room with undefined data"); } diff --git a/src/db/userstore.ts b/src/db/userstore.ts index c8542074..0f307d61 100644 --- a/src/db/userstore.ts +++ b/src/db/userstore.ts @@ -54,10 +54,10 @@ export class DbUserStore { public async getRemoteUser(remoteId: string): Promise { const cached = this.remoteUserCache.get(remoteId); if (cached && cached.ts + ENTRY_CACHE_LIMETIME > Date.now()) { - MetricPeg.get.storeCall("getRemoteUser", true); + MetricPeg.get.storeCall("UserStore.getRemoteUser", true); return cached.e; } - MetricPeg.get.storeCall("getRemoteUser", false); + MetricPeg.get.storeCall("UserStore.getRemoteUser", false); const row = await this.db.Get( "SELECT * FROM user_entries WHERE remote_id = $id", {id: remoteId}, @@ -89,7 +89,7 @@ export class DbUserStore { } public async setRemoteUser(user: RemoteUser) { - MetricPeg.get.storeCall("setRemoteUser", false); + MetricPeg.get.storeCall("UserStore.setRemoteUser", false); this.remoteUserCache.delete(user.id); const existingData = await this.db.Get( "SELECT * FROM remote_user_data WHERE remote_id = $remoteId", @@ -160,7 +160,7 @@ AND guild_id = $guild_id`, } public async linkUsers(matrixId: string, remoteId: string) { - MetricPeg.get.storeCall("linkUsers", false); + MetricPeg.get.storeCall("UserStore.linkUsers", false); // This is used ONCE in the bridge to link two IDs, so do not UPSURT data. try { await this.db.Run(`INSERT INTO user_entries VALUES ($matrixId, $remoteId)`, { From 2370b4d0afe0e3e2561ab2b48d714d5e6c72eaf1 Mon Sep 17 00:00:00 2001 From: Will Hunt Date: Fri, 31 May 2019 16:14:28 +0100 Subject: [PATCH 07/22] Add support for remote send calls in metrics --- src/bot.ts | 3 ++ src/clientfactory.ts | 14 +++++--- src/discordas.ts | 5 ++- src/metrics.ts | 57 +++++++++++++++--------------- test/mocks/discordclientfactory.ts | 2 ++ test/test_discordbot.ts | 2 +- tslint.json | 2 +- 7 files changed, 47 insertions(+), 38 deletions(-) diff --git a/src/bot.ts b/src/bot.ts index 13b0ecf9..562a59f8 100644 --- a/src/bot.ts +++ b/src/bot.ts @@ -392,6 +392,7 @@ export class DiscordBot { } const channel = guild.channels.get(room); if (channel && channel.type === "text") { + this.ClientFactory.bindMetricsToChannel(channel as Discord.TextChannel); const lookupResult = new ChannelLookupResult(); lookupResult.channel = channel as Discord.TextChannel; lookupResult.botUser = this.bot.user.id === client.user.id; @@ -451,6 +452,7 @@ export class DiscordBot { // NOTE: Don't send replies to discord if we are a puppet. msg = await chan.send(embed.description, opts); } else if (hook) { + MetricPeg.get.remoteCall("hook.send"); msg = await hook.send(embed.description, { avatarURL: embed!.author!.icon_url, embeds: embedSet.replyEmbed ? [embedSet.replyEmbed] : undefined, @@ -542,6 +544,7 @@ export class DiscordBot { if (guild) { const channel = client.channels.get(entry.remote!.get("discord_channel") as string); if (channel) { + this.ClientFactory.bindMetricsToChannel(channel as Discord.TextChannel); return channel; } throw Error("Channel given in room entry not found"); diff --git a/src/clientfactory.ts b/src/clientfactory.ts index 54e2694c..22ded344 100644 --- a/src/clientfactory.ts +++ b/src/clientfactory.ts @@ -16,14 +16,12 @@ limitations under the License. import { DiscordBridgeConfigAuth } from "./config"; import { DiscordStore } from "./store"; -import { Client as DiscordClient } from "discord.js"; +import { Client as DiscordClient, TextChannel } from "discord.js"; import { Log } from "./log"; -import { Util } from "./util"; +import { MetricPeg } from "./metrics"; const log = new Log("ClientFactory"); -const READY_TIMEOUT = 30000; - export class DiscordClientFactory { private config: DiscordBridgeConfigAuth; private store: DiscordStore; @@ -110,4 +108,12 @@ export class DiscordClientFactory { return this.botClient; } } + + public bindMetricsToChannel(channel: TextChannel) { + // tslint:disable-next-line:only-arrow-functions + channel.send = function() { + MetricPeg.get.remoteCall("channel.send"); + return channel.send.apply(channel, arguments); + }; + } } diff --git a/src/discordas.ts b/src/discordas.ts index 64e5f6c9..f02ba094 100644 --- a/src/discordas.ts +++ b/src/discordas.ts @@ -162,15 +162,14 @@ async function run(port: number, fileConfig: DiscordBridgeConfig) { + "The config option userStorePath no longer has any use."); } - await bridge.run(port, config); log.info(`Started listening on port ${port}`); if (config.bridge.enableMetrics) { log.info("Enabled metrics"); - MetricPeg.setMetrics(new PrometheusBridgeMetrics().init(bridge)); + MetricPeg.set(new PrometheusBridgeMetrics().init(bridge)); } - + try { await store.init(undefined, bridge.getRoomStore(), bridge.getUserStore()); } catch (ex) { diff --git a/src/metrics.ts b/src/metrics.ts index 698c0daf..e322c77b 100644 --- a/src/metrics.ts +++ b/src/metrics.ts @@ -1,4 +1,4 @@ -import { PrometheusMetrics } from "matrix-appservice-bridge"; +import { PrometheusMetrics, Bridge } from "matrix-appservice-bridge"; import { Gauge, Counter, Histogram } from "prom-client"; import { Log } from "./log"; @@ -7,7 +7,7 @@ const log = new Log("BridgeMetrics"); const REQUEST_EXPIRE_TIME_MS = 30000; interface IAgeCounter { - setGauge(gauge: Gauge, morelabels: any); + setGauge(gauge: Gauge, morelabels: string[]); bump(age: number); } @@ -31,25 +31,24 @@ export interface IBridgeMetrics { } export class DummyBridgeMetrics implements IBridgeMetrics { - registerRequest() {} - requestOutcome() {} - remoteCall() {} - setPresenceCount() {} - storeCall() {} + public registerRequest() {} + public requestOutcome() {} + public remoteCall() {} + public setPresenceCount() {} + public storeCall() {} } export class MetricPeg { - private static _metrics: IBridgeMetrics = new DummyBridgeMetrics(); - - public static get get() : IBridgeMetrics { - return this._metrics; + public static get get(): IBridgeMetrics { + return this.metrics; } - - public static setMetrics(metrics: IBridgeMetrics) { - this._metrics = metrics; + + public static set(metrics: IBridgeMetrics) { + this.metrics = metrics; } -} + private static metrics: IBridgeMetrics = new DummyBridgeMetrics(); +} export class PrometheusBridgeMetrics implements IBridgeMetrics { private metrics; @@ -60,45 +59,46 @@ export class PrometheusBridgeMetrics implements IBridgeMetrics { private matrixRequest: Histogram; private requestsInFlight: Map; private bridgeGauges: IBridgeGauges = { - matrixRoomConfigs: 0, - remoteRoomConfigs: 0, matrixGhosts: 0, - remoteGhosts: 0, + matrixRoomConfigs: 0, matrixRoomsByAge: new AgeCounters(), - remoteRoomsByAge: new AgeCounters(), matrixUsersByAge: new AgeCounters(), + remoteGhosts: 0, + remoteRoomConfigs: 0, + remoteRoomsByAge: new AgeCounters(), remoteUsersByAge: new AgeCounters(), }; - public init(bridge: any) { + public init(bridge: Bridge) { this.metrics = new PrometheusMetrics(); this.metrics.registerMatrixSdkMetrics(); this.metrics.registerBridgeGauges(() => this.bridgeGauges); this.metrics.addAppServicePath(bridge); this.remoteCallCounter = this.metrics.addCounter({ - name: "remote_api_calls", help: "Count of remote API calls made", labels: ["method"], + name: "remote_api_calls", }); this.storeCallCounter = this.metrics.addCounter({ - name: "store_calls", help: "Count of store function calls made", labels: ["method", "cached"], + name: "store_calls", }); this.presenceGauge = this.metrics.addGauge({ - name: "active_presence_users", help: "Count of users in the presence queue", labels: [], + + name: "active_presence_users", }); this.matrixRequest = this.metrics.addTimer({ - name: "matrix_request_seconds", help: "Histogram of processing durations of received Matrix messages", labels: ["outcome"], + name: "matrix_request_seconds", }); this.remoteRequest = this.metrics.addTimer({ - name: "remote_request_seconds", help: "Histogram of processing durations of received remote messages", labels: ["outcome"], + name: "remote_request_seconds", }); this.requestsInFlight = new Map(); setInterval(() => { @@ -107,7 +107,7 @@ export class PrometheusBridgeMetrics implements IBridgeMetrics { this.requestsInFlight.delete(id); } }); - }, REQUEST_EXPIRE_TIME_MS) + }, REQUEST_EXPIRE_TIME_MS); return this; } @@ -121,7 +121,7 @@ export class PrometheusBridgeMetrics implements IBridgeMetrics { if (!startTime) { log.verbose(`Got "requestOutcome" for ${id}, but this request was never started`); return; - } + } const duration = Date.now() - startTime; (isRemote ? this.remoteRequest : this.matrixRequest).observe({outcome}, duration / 1000); } @@ -137,5 +137,4 @@ export class PrometheusBridgeMetrics implements IBridgeMetrics { public storeCall(method: string, cached: boolean) { this.storeCallCounter.inc({method, cached: cached ? "yes" : "no"}); } -}; - +} diff --git a/test/mocks/discordclientfactory.ts b/test/mocks/discordclientfactory.ts index 803dedc1..b174f3d5 100644 --- a/test/mocks/discordclientfactory.ts +++ b/test/mocks/discordclientfactory.ts @@ -31,4 +31,6 @@ export class DiscordClientFactory { } return this.botClient; } + + public bindMetricsToChannel() {} } diff --git a/test/test_discordbot.ts b/test/test_discordbot.ts index f6208be1..17351703 100644 --- a/test/test_discordbot.ts +++ b/test/test_discordbot.ts @@ -453,7 +453,7 @@ describe("DiscordBot", () => { bot.lockChannel(chan); await bot.waitUnlock(chan); const diff = Date.now() - t; - expect(diff).to.be.greaterThan(SHORTDELAY - 1); + expect(diff).to.be.greaterThan(SHORTDELAY - 5); }); }); // }); diff --git a/tslint.json b/tslint.json index cd7de561..ff80b039 100644 --- a/tslint.json +++ b/tslint.json @@ -9,7 +9,7 @@ "object-literal-sort-keys": "off", "no-any": true, "arrow-return-shorthand": true, - "no-magic-numbers": true, + "no-magic-numbers": [true, -1, 0, 1, 1000], "prefer-for-of": true, "typedef": { "severity": "warning" From 95cb6aff953a6a7423256e97872286129299cdb4 Mon Sep 17 00:00:00 2001 From: Will Hunt Date: Fri, 31 May 2019 16:18:11 +0100 Subject: [PATCH 08/22] Linting --- src/bot.ts | 2 +- test/test_discordbot.ts | 4 +++- 2 files changed, 4 insertions(+), 2 deletions(-) diff --git a/src/bot.ts b/src/bot.ts index 562a59f8..7e583f7a 100644 --- a/src/bot.ts +++ b/src/bot.ts @@ -776,7 +776,7 @@ export class DiscordBot { let rooms; try { rooms = await this.channelSync.GetRoomIdsFromChannel(msg.channel); - if (rooms === null) { throw Error() } + if (rooms === null) { throw Error(); } } catch (err) { log.verbose("No bridged rooms to send message to. Oh well."); MetricPeg.get.requestOutcome(msg.id, true, "dropped"); diff --git a/test/test_discordbot.ts b/test/test_discordbot.ts index 17351703..918ff468 100644 --- a/test/test_discordbot.ts +++ b/test/test_discordbot.ts @@ -434,6 +434,7 @@ describe("DiscordBot", () => { it("should lock and unlock a channel early, if unlocked", async () => { const discordSendDelay = 500; const SHORTDELAY = 100; + const MINEXPECTEDDELAY = 95; const bot = new modDiscordBot.DiscordBot( "", { @@ -453,7 +454,8 @@ describe("DiscordBot", () => { bot.lockChannel(chan); await bot.waitUnlock(chan); const diff = Date.now() - t; - expect(diff).to.be.greaterThan(SHORTDELAY - 5); + // Date accuracy can be off by a few ms sometimes. + expect(diff).to.be.greaterThan(MINEXPECTEDDELAY); }); }); // }); From 3a9072188a84493cfe696cd8f5bf5f1db0fec66f Mon Sep 17 00:00:00 2001 From: Will Hunt Date: Fri, 31 May 2019 16:30:15 +0100 Subject: [PATCH 09/22] Add copyright header --- src/metrics.ts | 16 ++++++++++++++++ 1 file changed, 16 insertions(+) diff --git a/src/metrics.ts b/src/metrics.ts index e322c77b..db1556f3 100644 --- a/src/metrics.ts +++ b/src/metrics.ts @@ -1,3 +1,19 @@ +/* +Copyright 2019 matrix-appservice-discord + +Licensed under the Apache License, Version 2.0 (the "License"); +you may not use this file except in compliance with the License. +You may obtain a copy of the License at + + http://www.apache.org/licenses/LICENSE-2.0 + +Unless required by applicable law or agreed to in writing, software +distributed under the License is distributed on an "AS IS" BASIS, +WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +See the License for the specific language governing permissions and +limitations under the License. +*/ + import { PrometheusMetrics, Bridge } from "matrix-appservice-bridge"; import { Gauge, Counter, Histogram } from "prom-client"; import { Log } from "./log"; From 04f30070a9061074b699b8ec99983ed9999a5f10 Mon Sep 17 00:00:00 2001 From: Will Hunt Date: Fri, 31 May 2019 16:49:53 +0100 Subject: [PATCH 10/22] Bind metrics safely --- src/bot.ts | 1 + src/clientfactory.ts | 9 ++++++++- 2 files changed, 9 insertions(+), 1 deletion(-) diff --git a/src/bot.ts b/src/bot.ts index 7e583f7a..102c0ae6 100644 --- a/src/bot.ts +++ b/src/bot.ts @@ -291,6 +291,7 @@ export class DiscordBot { try { MetricPeg.get.registerRequest(msg.id); await this.waitUnlock(msg.channel); + this.clientFactory.bindMetricsToChannel(msg.channel as Discord.TextChannel); this.discordMessageQueue[msg.channel.id] = (async () => { await (this.discordMessageQueue[msg.channel.id] || Promise.resolve()); try { diff --git a/src/clientfactory.ts b/src/clientfactory.ts index 22ded344..1b2adcfb 100644 --- a/src/clientfactory.ts +++ b/src/clientfactory.ts @@ -110,10 +110,17 @@ export class DiscordClientFactory { } public bindMetricsToChannel(channel: TextChannel) { + // tslint:disable-next-line:no-any + const flexChan = channel as any; + if (flexChan._xmet_send !== undefined) { + return; + } + // Prefix the real functions with _xmet_ + flexChan._xmet_send = channel.send; // tslint:disable-next-line:only-arrow-functions channel.send = function() { MetricPeg.get.remoteCall("channel.send"); - return channel.send.apply(channel, arguments); + return flexChan._xmet_send.apply(channel, arguments); }; } } From 980a1a2e082c16e828a61d688f7ebc19445f8e33 Mon Sep 17 00:00:00 2001 From: Will Hunt Date: Wed, 22 May 2019 21:42:16 +0100 Subject: [PATCH 11/22] Add support for metrics --- package.json | 1 + src/bot.ts | 14 +++++++++++--- src/config.ts | 1 + src/db/roomstore.ts | 9 +++++++++ src/db/userstore.ts | 7 ++++++- src/discordas.ts | 8 +++++++- src/presencehandler.ts | 4 ++++ 7 files changed, 39 insertions(+), 5 deletions(-) diff --git a/package.json b/package.json index e79ab464..60894a21 100644 --- a/package.json +++ b/package.json @@ -47,6 +47,7 @@ "node-html-parser": "^1.1.11", "p-queue": "^6.0.1", "pg-promise": "^8.5.1", + "prom-client": "^11.3.0", "tslint": "^5.11.0", "typescript": "^3.1.3", "winston": "^3.0.0", diff --git a/src/bot.ts b/src/bot.ts index d88c10bf..a4ad3f16 100644 --- a/src/bot.ts +++ b/src/bot.ts @@ -37,6 +37,7 @@ import * as Discord from "discord.js"; import * as mime from "mime"; import { IMatrixEvent, IMatrixMediaInfo } from "./matrixtypes"; import { DiscordCommandHandler } from "./discordcommandhandler"; +import { MetricPeg } from "./metrics"; const log = new Log("DiscordBot"); @@ -288,12 +289,14 @@ export class DiscordBot { }); client.on("message", async (msg: Discord.Message) => { try { + MetricPeg.get.registerRequest(msg.id); await this.waitUnlock(msg.channel); this.discordMessageQueue[msg.channel.id] = (async () => { await (this.discordMessageQueue[msg.channel.id] || Promise.resolve()); try { await this.OnMessage(msg); } catch (err) { + MetricPeg.get.requestOutcome(msg.id, true, "fail"); log.error("Caught while handing 'message'", err); } })(); @@ -738,11 +741,13 @@ export class DiscordBot { if (indexOfMsg !== -1) { log.verbose("Got repeated message, ignoring."); delete this.sentMessages[indexOfMsg]; + MetricPeg.get.requestOutcome(msg.id, true, "dropped"); return; // Skip *our* messages } const chan = msg.channel as Discord.TextChannel; if (msg.author.id === this.bot.user.id) { // We don't support double bridging. + MetricPeg.get.requestOutcome(msg.id, true, "dropped"); return; } // Test for webhooks @@ -751,6 +756,7 @@ export class DiscordBot { .filterArray((h) => h.name === "_matrix").pop(); if (webhook && msg.webhookID === webhook.id) { // Filter out our own webhook messages. + MetricPeg.get.requestOutcome(msg.id, true, "dropped"); return; } } @@ -758,6 +764,7 @@ export class DiscordBot { // check if it is a command to process by the bot itself if (msg.content.startsWith("!matrix")) { await this.discordCommandHandler.Process(msg); + MetricPeg.get.requestOutcome(msg.id, true, "success"); return; } @@ -766,14 +773,13 @@ export class DiscordBot { let rooms; try { rooms = await this.channelSync.GetRoomIdsFromChannel(msg.channel); + if (rooms === null) { throw Error() } } catch (err) { log.verbose("No bridged rooms to send message to. Oh well."); + MetricPeg.get.requestOutcome(msg.id, true, "dropped"); return null; } try { - if (rooms === null) { - return null; - } const intent = this.GetIntentFromDiscordMember(msg.author, msg.webhookID); // Check Attachements await Util.AsyncForEach(msg.attachments.array(), async (attachment) => { @@ -854,7 +860,9 @@ export class DiscordBot { await afterSend(res); } }); + MetricPeg.get.requestOutcome(msg.id, true, "success"); } catch (err) { + MetricPeg.get.requestOutcome(msg.id, true, "fail"); log.verbose("Failed to send message into room.", err); } } diff --git a/src/config.ts b/src/config.ts index 2f0eb762..2da5b773 100644 --- a/src/config.ts +++ b/src/config.ts @@ -90,6 +90,7 @@ class DiscordBridgeConfigBridge { public disableEveryoneMention: boolean = false; public disableHereMention: boolean = false; public disableJoinLeaveNotifications: boolean = false; + public enableMetrics: boolean = false; } export class DiscordBridgeConfigDatabase { diff --git a/src/db/roomstore.ts b/src/db/roomstore.ts index c04230e0..72677cc9 100644 --- a/src/db/roomstore.ts +++ b/src/db/roomstore.ts @@ -19,6 +19,7 @@ import { Util } from "../util"; import * as uuid from "uuid/v4"; import { Postgres } from "./postgres"; +import { MetricPeg } from "../metrics"; const log = new Log("DbRoomStore"); @@ -155,8 +156,10 @@ export class DbRoomStore { public async getEntriesByMatrixId(matrixId: string): Promise { const cached = this.entriesMatrixIdCache.get(matrixId); if (cached && cached.ts + ENTRY_CACHE_LIMETIME > Date.now()) { + MetricPeg.get.storeCall("getEntriesByMatrixId", true); return cached.e; } + MetricPeg.get.storeCall("getEntriesByMatrixId", false); const entries = await this.db.All( "SELECT * FROM room_entries WHERE matrix_id = $id", {id: matrixId}, ); @@ -190,6 +193,7 @@ export class DbRoomStore { } public async getEntriesByMatrixIds(matrixIds: string[]): Promise { + MetricPeg.get.storeCall("getEntriesByMatrixIds", false); const mxIdMap = { }; matrixIds.forEach((mxId, i) => mxIdMap[i] = mxId); const sql = `SELECT * FROM room_entries WHERE matrix_id IN (${matrixIds.map((_, id) => `\$${id}`).join(", ")})`; @@ -222,6 +226,7 @@ export class DbRoomStore { } public async linkRooms(matrixRoom: MatrixStoreRoom, remoteRoom: RemoteStoreRoom) { + MetricPeg.get.storeCall("linkRooms", false); await this.upsertRoom(remoteRoom); const values = { @@ -244,6 +249,7 @@ export class DbRoomStore { } public async getEntriesByRemoteRoomData(data: IRemoteRoomDataLazy): Promise { + MetricPeg.get.storeCall("getEntriesByRemoteRoomData", false); Object.keys(data).filter((k) => typeof(data[k]) === "boolean").forEach((k) => { data[k] = Number(data[k]); }); @@ -270,11 +276,13 @@ export class DbRoomStore { } public async removeEntriesByRemoteRoomId(remoteId: string) { + MetricPeg.get.storeCall("removeEntriesByRemoteRoomId", false); await this.db.Run(`DELETE FROM room_entries WHERE remote_id = $remoteId`, {remoteId}); await this.db.Run(`DELETE FROM remote_room_data WHERE room_id = $remoteId`, {remoteId}); } public async removeEntriesByMatrixRoomId(matrixId: string) { + MetricPeg.get.storeCall("removeEntriesByMatrixRoomId", false); const entries = (await this.db.All(`SELECT * FROM room_entries WHERE matrix_id = $matrixId`, {matrixId})) || []; await Util.AsyncForEach(entries, async (entry) => { if (entry.remote_id) { @@ -286,6 +294,7 @@ export class DbRoomStore { } private async upsertRoom(room: RemoteStoreRoom) { + MetricPeg.get.storeCall("upsertRoom", false); if (!room.data) { throw new Error("Tried to upsert a room with undefined data"); } diff --git a/src/db/userstore.ts b/src/db/userstore.ts index cb1251e2..c8542074 100644 --- a/src/db/userstore.ts +++ b/src/db/userstore.ts @@ -15,8 +15,8 @@ limitations under the License. */ import { IDatabaseConnector } from "./connector"; -import * as uuid from "uuid/v4"; import { Log } from "../log"; +import { MetricPeg } from "../metrics"; /** * A UserStore compatible with @@ -54,8 +54,11 @@ export class DbUserStore { public async getRemoteUser(remoteId: string): Promise { const cached = this.remoteUserCache.get(remoteId); if (cached && cached.ts + ENTRY_CACHE_LIMETIME > Date.now()) { + MetricPeg.get.storeCall("getRemoteUser", true); return cached.e; } + MetricPeg.get.storeCall("getRemoteUser", false); + const row = await this.db.Get( "SELECT * FROM user_entries WHERE remote_id = $id", {id: remoteId}, ); @@ -86,6 +89,7 @@ export class DbUserStore { } public async setRemoteUser(user: RemoteUser) { + MetricPeg.get.storeCall("setRemoteUser", false); this.remoteUserCache.delete(user.id); const existingData = await this.db.Get( "SELECT * FROM remote_user_data WHERE remote_id = $remoteId", @@ -156,6 +160,7 @@ AND guild_id = $guild_id`, } public async linkUsers(matrixId: string, remoteId: string) { + MetricPeg.get.storeCall("linkUsers", false); // This is used ONCE in the bridge to link two IDs, so do not UPSURT data. try { await this.db.Run(`INSERT INTO user_entries VALUES ($matrixId, $remoteId)`, { diff --git a/src/discordas.ts b/src/discordas.ts index 1f350c38..574f3968 100644 --- a/src/discordas.ts +++ b/src/discordas.ts @@ -22,6 +22,7 @@ import { DiscordBot } from "./bot"; import { DiscordStore } from "./store"; import { Log } from "./log"; import "source-map-support/register"; +import { MetricPeg } from "./metrics"; const log = new Log("DiscordAS"); @@ -94,13 +95,16 @@ async function run(port: number, fileConfig: DiscordBridgeConfig) { } catch (err) { log.error("Exception thrown while handling \"onAliasQuery\" event", err); } }, onEvent: async (request) => { + const data = request.getData(); try { + MetricPeg.get.registerRequest(data.event_id); // Build our own context. if (!store.roomStore) { log.warn("Discord store not ready yet, dropping message"); + MetricPeg.get.requestOutcome(data.event_id, false, "dropped"); return; } - const roomId = request.getData().room_id; + const roomId = data.room_id; const context: BridgeContext = { rooms: {}, @@ -112,7 +116,9 @@ async function run(port: number, fileConfig: DiscordBridgeConfig) { } await request.outcomeFrom(callbacks.onEvent(request, context)); + MetricPeg.get.requestOutcome(data.event_id, false, "success"); } catch (err) { + MetricPeg.get.requestOutcome(data.event_id, false, "fail"); log.error("Exception thrown while handling \"onEvent\" event", err); await request.outcomeFrom(Promise.reject("Failed to handle")); } diff --git a/src/presencehandler.ts b/src/presencehandler.ts index 16fa4a97..91343e60 100644 --- a/src/presencehandler.ts +++ b/src/presencehandler.ts @@ -17,6 +17,7 @@ limitations under the License. import { User, Presence } from "discord.js"; import { DiscordBot } from "./bot"; import { Log } from "./log"; +import { MetricPeg } from "./metrics"; const log = new Log("PresenceHandler"); export class PresenceHandlerStatus { @@ -66,6 +67,7 @@ export class PresenceHandler { if (user.id !== this.bot.GetBotId() && this.presenceQueue.find((u) => u.id === user.id) === undefined) { log.info(`Adding ${user.id} (${user.username}) to the presence queue`); this.presenceQueue.push(user); + MetricPeg.get.setPresenceCount(this.presenceQueue.length); } } @@ -75,6 +77,7 @@ export class PresenceHandler { }); if (index !== -1) { this.presenceQueue.splice(index, 1); + MetricPeg.get.setPresenceCount(this.presenceQueue.length); } else { log.warn( `Tried to remove ${user.id} from the presence queue but it could not be found`, @@ -96,6 +99,7 @@ export class PresenceHandler { this.presenceQueue.push(user); } else { log.info(`Dropping ${user.id} from the presence queue.`); + MetricPeg.get.setPresenceCount(this.presenceQueue.length); } } } From b336edae603f86706910bec1a7238b71f0b9b72b Mon Sep 17 00:00:00 2001 From: Will Hunt Date: Wed, 22 May 2019 21:52:05 +0100 Subject: [PATCH 12/22] Dammit metrics.ts --- src/metrics.ts | 132 +++++++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 132 insertions(+) create mode 100644 src/metrics.ts diff --git a/src/metrics.ts b/src/metrics.ts new file mode 100644 index 00000000..82329d82 --- /dev/null +++ b/src/metrics.ts @@ -0,0 +1,132 @@ +import { PrometheusMetrics } from "matrix-appservice-bridge"; +import { Gauge, Counter, Histogram } from "prom-client"; +import { Log } from "./log"; + +const AgeCounters = PrometheusMetrics.AgeCounters; +const log = new Log("BridgeMetrics"); + +interface IAgeCounter { + setGauge(gauge: Gauge, morelabels: any); + bump(age: number); +} + +interface IBridgeGauges { + matrixRoomConfigs: number; + remoteRoomConfigs: number; + matrixGhosts: number; + remoteGhosts: number; + matrixRoomsByAge: IAgeCounter; + remoteRoomsByAge: IAgeCounter; + matrixUsersByAge: IAgeCounter; + remoteUsersByAge: IAgeCounter; +} + +export interface IBridgeMetrics { + registerRequest(id: string); + requestOutcome(id: string, isRemote: boolean, outcome: string); + remoteCall(method: string); + setPresenceCount(count: number); + storeCall(method: string, cached: boolean); +} + +export class DummyBridgeMetrics implements IBridgeMetrics { + registerRequest() {} + requestOutcome() {} + remoteCall() {} + setPresenceCount() {} + storeCall() {} +} + +export class MetricPeg { + private static _metrics: IBridgeMetrics = new DummyBridgeMetrics(); + + public static get get() : IBridgeMetrics { + return this._metrics; + } + + public static setMetrics(metrics: IBridgeMetrics) { + this._metrics = metrics; + } +} + + +export class PrometheusBridgeMetrics implements IBridgeMetrics { + private metrics; + private remoteCallCounter: Counter; + private storeCallCounter: Counter; + private presenceGauge: Gauge; + private remoteRequest: Histogram; + private matrixRequest: Histogram; + private requestsInFlight: Map; + private bridgeGauges: IBridgeGauges = { + matrixRoomConfigs: 0, + remoteRoomConfigs: 0, + matrixGhosts: 0, + remoteGhosts: 0, + matrixRoomsByAge: new AgeCounters(), + remoteRoomsByAge: new AgeCounters(), + matrixUsersByAge: new AgeCounters(), + remoteUsersByAge: new AgeCounters(), + }; + + public init(bridge: any) { + this.metrics = new PrometheusMetrics(); + this.metrics.registerMatrixSdkMetrics(); + this.metrics.registerBridgeGauges(() => this.bridgeGauges); + this.metrics.addAppServicePath(bridge); + this.remoteCallCounter = this.metrics.addCounter({ + name: "remote_api_calls", + help: "Count of remote API calls made", + labels: ["method"], + }); + this.storeCallCounter = this.metrics.addCounter({ + name: "store_calls", + help: "Count of store function calls made", + labels: ["method", "cached"], + }); + this.presenceGauge = this.metrics.addGauge({ + name: "active_presence_users", + help: "Count of users in the presence queue", + labels: [], + }); + this.matrixRequest = this.metrics.addTimer({ + name: "matrix_request_seconds", + help: "Histogram of processing durations of received Matrix messages", + labels: ["outcome"], + }); + this.remoteRequest = this.metrics.addTimer({ + name: "remote_request_seconds", + help: "Histogram of processing durations of received remote messages", + labels: ["outcome"], + }); + this.requestsInFlight = new Map(); + return this; + } + + public registerRequest(id: string) { + this.requestsInFlight.set(id, Date.now()); + } + + public requestOutcome(id: string, isRemote: boolean, outcome: string) { + const startTime = this.requestsInFlight.get(id); + if (!startTime) { + log.verbose(`Got "requestOutcome" for ${id}, but this request was never started`); + return; + } + const duration = Date.now() - startTime; + (isRemote ? this.remoteRequest : this.matrixRequest).observe({outcome}, duration / 1000); + } + + public setPresenceCount(count: number) { + this.presenceGauge.set(count); + } + + public remoteCall(method: string) { + this.remoteCallCounter.inc({method}); + } + + public storeCall(method: string, cached: boolean) { + this.storeCallCounter.inc({method, cached: cached ? "yes" : "no"}); + } +}; + From bdc84f748cb3e1339a9a8683f9a55cb52d7f12ae Mon Sep 17 00:00:00 2001 From: Will Hunt Date: Wed, 22 May 2019 22:00:31 +0100 Subject: [PATCH 13/22] Enable the metrics --- src/discordas.ts | 7 ++++++- 1 file changed, 6 insertions(+), 1 deletion(-) diff --git a/src/discordas.ts b/src/discordas.ts index 574f3968..05a1be61 100644 --- a/src/discordas.ts +++ b/src/discordas.ts @@ -22,7 +22,7 @@ import { DiscordBot } from "./bot"; import { DiscordStore } from "./store"; import { Log } from "./log"; import "source-map-support/register"; -import { MetricPeg } from "./metrics"; +import { MetricPeg, PrometheusBridgeMetrics } from "./metrics"; const log = new Log("DiscordAS"); @@ -163,6 +163,11 @@ async function run(port: number, fileConfig: DiscordBridgeConfig) { + "The config option userStorePath no longer has any use."); } + if (config.bridge.enableMetrics) { + log.info("Enabled metrics"); + MetricPeg.setMetrics(new PrometheusBridgeMetrics().init(bridge)); + } + await bridge.run(port, config); log.info(`Started listening on port ${port}`); From c9cad35a3f6067d718da658f2dd08637082fb680 Mon Sep 17 00:00:00 2001 From: Will Hunt Date: Wed, 22 May 2019 22:02:26 +0100 Subject: [PATCH 14/22] Wait for bridge to start first --- src/discordas.ts | 9 +++++---- 1 file changed, 5 insertions(+), 4 deletions(-) diff --git a/src/discordas.ts b/src/discordas.ts index 05a1be61..c39c2dba 100644 --- a/src/discordas.ts +++ b/src/discordas.ts @@ -163,14 +163,15 @@ async function run(port: number, fileConfig: DiscordBridgeConfig) { + "The config option userStorePath no longer has any use."); } - if (config.bridge.enableMetrics) { - log.info("Enabled metrics"); - MetricPeg.setMetrics(new PrometheusBridgeMetrics().init(bridge)); - } await bridge.run(port, config); log.info(`Started listening on port ${port}`); + if (config.bridge.enableMetrics) { + log.info("Enabled metrics"); + MetricPeg.setMetrics(new PrometheusBridgeMetrics().init(bridge)); + } + try { await store.init(undefined, bridge.getRoomStore(), bridge.getUserStore()); } catch (ex) { From 641edc7d56cfe921507696495d52362d36939268 Mon Sep 17 00:00:00 2001 From: Will Hunt Date: Wed, 22 May 2019 22:31:12 +0100 Subject: [PATCH 15/22] Expire old requests in metrics --- src/metrics.ts | 9 +++++++++ 1 file changed, 9 insertions(+) diff --git a/src/metrics.ts b/src/metrics.ts index 82329d82..698c0daf 100644 --- a/src/metrics.ts +++ b/src/metrics.ts @@ -4,6 +4,7 @@ import { Log } from "./log"; const AgeCounters = PrometheusMetrics.AgeCounters; const log = new Log("BridgeMetrics"); +const REQUEST_EXPIRE_TIME_MS = 30000; interface IAgeCounter { setGauge(gauge: Gauge, morelabels: any); @@ -100,6 +101,13 @@ export class PrometheusBridgeMetrics implements IBridgeMetrics { labels: ["outcome"], }); this.requestsInFlight = new Map(); + setInterval(() => { + this.requestsInFlight.forEach((time, id) => { + if (Date.now() - time) { + this.requestsInFlight.delete(id); + } + }); + }, REQUEST_EXPIRE_TIME_MS) return this; } @@ -109,6 +117,7 @@ export class PrometheusBridgeMetrics implements IBridgeMetrics { public requestOutcome(id: string, isRemote: boolean, outcome: string) { const startTime = this.requestsInFlight.get(id); + this.requestsInFlight.delete(id); if (!startTime) { log.verbose(`Got "requestOutcome" for ${id}, but this request was never started`); return; From 5f245e1cb5567e8ba038f727b7cd35ed47184b46 Mon Sep 17 00:00:00 2001 From: Will Hunt Date: Wed, 22 May 2019 22:58:34 +0100 Subject: [PATCH 16/22] Store prefixes --- src/db/roomstore.ts | 16 ++++++++-------- src/db/userstore.ts | 8 ++++---- 2 files changed, 12 insertions(+), 12 deletions(-) diff --git a/src/db/roomstore.ts b/src/db/roomstore.ts index 72677cc9..2cb9d9f0 100644 --- a/src/db/roomstore.ts +++ b/src/db/roomstore.ts @@ -156,10 +156,10 @@ export class DbRoomStore { public async getEntriesByMatrixId(matrixId: string): Promise { const cached = this.entriesMatrixIdCache.get(matrixId); if (cached && cached.ts + ENTRY_CACHE_LIMETIME > Date.now()) { - MetricPeg.get.storeCall("getEntriesByMatrixId", true); + MetricPeg.get.storeCall("RoomStore.getEntriesByMatrixId", true); return cached.e; } - MetricPeg.get.storeCall("getEntriesByMatrixId", false); + MetricPeg.get.storeCall("RoomStore.getEntriesByMatrixId", false); const entries = await this.db.All( "SELECT * FROM room_entries WHERE matrix_id = $id", {id: matrixId}, ); @@ -193,7 +193,7 @@ export class DbRoomStore { } public async getEntriesByMatrixIds(matrixIds: string[]): Promise { - MetricPeg.get.storeCall("getEntriesByMatrixIds", false); + MetricPeg.get.storeCall("RoomStore.getEntriesByMatrixIds", false); const mxIdMap = { }; matrixIds.forEach((mxId, i) => mxIdMap[i] = mxId); const sql = `SELECT * FROM room_entries WHERE matrix_id IN (${matrixIds.map((_, id) => `\$${id}`).join(", ")})`; @@ -226,7 +226,7 @@ export class DbRoomStore { } public async linkRooms(matrixRoom: MatrixStoreRoom, remoteRoom: RemoteStoreRoom) { - MetricPeg.get.storeCall("linkRooms", false); + MetricPeg.get.storeCall("RoomStore.linkRooms", false); await this.upsertRoom(remoteRoom); const values = { @@ -249,7 +249,7 @@ export class DbRoomStore { } public async getEntriesByRemoteRoomData(data: IRemoteRoomDataLazy): Promise { - MetricPeg.get.storeCall("getEntriesByRemoteRoomData", false); + MetricPeg.get.storeCall("RoomStore.getEntriesByRemoteRoomData", false); Object.keys(data).filter((k) => typeof(data[k]) === "boolean").forEach((k) => { data[k] = Number(data[k]); }); @@ -276,13 +276,13 @@ export class DbRoomStore { } public async removeEntriesByRemoteRoomId(remoteId: string) { - MetricPeg.get.storeCall("removeEntriesByRemoteRoomId", false); + MetricPeg.get.storeCall("RoomStore.removeEntriesByRemoteRoomId", false); await this.db.Run(`DELETE FROM room_entries WHERE remote_id = $remoteId`, {remoteId}); await this.db.Run(`DELETE FROM remote_room_data WHERE room_id = $remoteId`, {remoteId}); } public async removeEntriesByMatrixRoomId(matrixId: string) { - MetricPeg.get.storeCall("removeEntriesByMatrixRoomId", false); + MetricPeg.get.storeCall("RoomStore.removeEntriesByMatrixRoomId", false); const entries = (await this.db.All(`SELECT * FROM room_entries WHERE matrix_id = $matrixId`, {matrixId})) || []; await Util.AsyncForEach(entries, async (entry) => { if (entry.remote_id) { @@ -294,7 +294,7 @@ export class DbRoomStore { } private async upsertRoom(room: RemoteStoreRoom) { - MetricPeg.get.storeCall("upsertRoom", false); + MetricPeg.get.storeCall("RoomStore.upsertRoom", false); if (!room.data) { throw new Error("Tried to upsert a room with undefined data"); } diff --git a/src/db/userstore.ts b/src/db/userstore.ts index c8542074..0f307d61 100644 --- a/src/db/userstore.ts +++ b/src/db/userstore.ts @@ -54,10 +54,10 @@ export class DbUserStore { public async getRemoteUser(remoteId: string): Promise { const cached = this.remoteUserCache.get(remoteId); if (cached && cached.ts + ENTRY_CACHE_LIMETIME > Date.now()) { - MetricPeg.get.storeCall("getRemoteUser", true); + MetricPeg.get.storeCall("UserStore.getRemoteUser", true); return cached.e; } - MetricPeg.get.storeCall("getRemoteUser", false); + MetricPeg.get.storeCall("UserStore.getRemoteUser", false); const row = await this.db.Get( "SELECT * FROM user_entries WHERE remote_id = $id", {id: remoteId}, @@ -89,7 +89,7 @@ export class DbUserStore { } public async setRemoteUser(user: RemoteUser) { - MetricPeg.get.storeCall("setRemoteUser", false); + MetricPeg.get.storeCall("UserStore.setRemoteUser", false); this.remoteUserCache.delete(user.id); const existingData = await this.db.Get( "SELECT * FROM remote_user_data WHERE remote_id = $remoteId", @@ -160,7 +160,7 @@ AND guild_id = $guild_id`, } public async linkUsers(matrixId: string, remoteId: string) { - MetricPeg.get.storeCall("linkUsers", false); + MetricPeg.get.storeCall("UserStore.linkUsers", false); // This is used ONCE in the bridge to link two IDs, so do not UPSURT data. try { await this.db.Run(`INSERT INTO user_entries VALUES ($matrixId, $remoteId)`, { From 062d5b1e51b7f0d982c9ef09447431a2c36d2896 Mon Sep 17 00:00:00 2001 From: Will Hunt Date: Fri, 31 May 2019 16:14:28 +0100 Subject: [PATCH 17/22] Add support for remote send calls in metrics --- src/bot.ts | 3 ++ src/clientfactory.ts | 14 +++++--- src/discordas.ts | 5 ++- src/metrics.ts | 57 +++++++++++++++--------------- test/mocks/discordclientfactory.ts | 2 ++ test/test_discordbot.ts | 2 +- tslint.json | 2 +- 7 files changed, 47 insertions(+), 38 deletions(-) diff --git a/src/bot.ts b/src/bot.ts index a4ad3f16..388b017e 100644 --- a/src/bot.ts +++ b/src/bot.ts @@ -392,6 +392,7 @@ export class DiscordBot { } const channel = guild.channels.get(room); if (channel && channel.type === "text") { + this.ClientFactory.bindMetricsToChannel(channel as Discord.TextChannel); const lookupResult = new ChannelLookupResult(); lookupResult.channel = channel as Discord.TextChannel; lookupResult.botUser = this.bot.user.id === client.user.id; @@ -451,6 +452,7 @@ export class DiscordBot { // NOTE: Don't send replies to discord if we are a puppet. msg = await chan.send(embed.description, opts); } else if (hook) { + MetricPeg.get.remoteCall("hook.send"); msg = await hook.send(embed.description, { avatarURL: embed!.author!.icon_url, embeds: embedSet.replyEmbed ? [embedSet.replyEmbed] : undefined, @@ -542,6 +544,7 @@ export class DiscordBot { if (guild) { const channel = client.channels.get(entry.remote!.get("discord_channel") as string); if (channel) { + this.ClientFactory.bindMetricsToChannel(channel as Discord.TextChannel); return channel; } throw Error("Channel given in room entry not found"); diff --git a/src/clientfactory.ts b/src/clientfactory.ts index 54e2694c..22ded344 100644 --- a/src/clientfactory.ts +++ b/src/clientfactory.ts @@ -16,14 +16,12 @@ limitations under the License. import { DiscordBridgeConfigAuth } from "./config"; import { DiscordStore } from "./store"; -import { Client as DiscordClient } from "discord.js"; +import { Client as DiscordClient, TextChannel } from "discord.js"; import { Log } from "./log"; -import { Util } from "./util"; +import { MetricPeg } from "./metrics"; const log = new Log("ClientFactory"); -const READY_TIMEOUT = 30000; - export class DiscordClientFactory { private config: DiscordBridgeConfigAuth; private store: DiscordStore; @@ -110,4 +108,12 @@ export class DiscordClientFactory { return this.botClient; } } + + public bindMetricsToChannel(channel: TextChannel) { + // tslint:disable-next-line:only-arrow-functions + channel.send = function() { + MetricPeg.get.remoteCall("channel.send"); + return channel.send.apply(channel, arguments); + }; + } } diff --git a/src/discordas.ts b/src/discordas.ts index c39c2dba..2e989cea 100644 --- a/src/discordas.ts +++ b/src/discordas.ts @@ -163,15 +163,14 @@ async function run(port: number, fileConfig: DiscordBridgeConfig) { + "The config option userStorePath no longer has any use."); } - await bridge.run(port, config); log.info(`Started listening on port ${port}`); if (config.bridge.enableMetrics) { log.info("Enabled metrics"); - MetricPeg.setMetrics(new PrometheusBridgeMetrics().init(bridge)); + MetricPeg.set(new PrometheusBridgeMetrics().init(bridge)); } - + try { await store.init(undefined, bridge.getRoomStore(), bridge.getUserStore()); } catch (ex) { diff --git a/src/metrics.ts b/src/metrics.ts index 698c0daf..e322c77b 100644 --- a/src/metrics.ts +++ b/src/metrics.ts @@ -1,4 +1,4 @@ -import { PrometheusMetrics } from "matrix-appservice-bridge"; +import { PrometheusMetrics, Bridge } from "matrix-appservice-bridge"; import { Gauge, Counter, Histogram } from "prom-client"; import { Log } from "./log"; @@ -7,7 +7,7 @@ const log = new Log("BridgeMetrics"); const REQUEST_EXPIRE_TIME_MS = 30000; interface IAgeCounter { - setGauge(gauge: Gauge, morelabels: any); + setGauge(gauge: Gauge, morelabels: string[]); bump(age: number); } @@ -31,25 +31,24 @@ export interface IBridgeMetrics { } export class DummyBridgeMetrics implements IBridgeMetrics { - registerRequest() {} - requestOutcome() {} - remoteCall() {} - setPresenceCount() {} - storeCall() {} + public registerRequest() {} + public requestOutcome() {} + public remoteCall() {} + public setPresenceCount() {} + public storeCall() {} } export class MetricPeg { - private static _metrics: IBridgeMetrics = new DummyBridgeMetrics(); - - public static get get() : IBridgeMetrics { - return this._metrics; + public static get get(): IBridgeMetrics { + return this.metrics; } - - public static setMetrics(metrics: IBridgeMetrics) { - this._metrics = metrics; + + public static set(metrics: IBridgeMetrics) { + this.metrics = metrics; } -} + private static metrics: IBridgeMetrics = new DummyBridgeMetrics(); +} export class PrometheusBridgeMetrics implements IBridgeMetrics { private metrics; @@ -60,45 +59,46 @@ export class PrometheusBridgeMetrics implements IBridgeMetrics { private matrixRequest: Histogram; private requestsInFlight: Map; private bridgeGauges: IBridgeGauges = { - matrixRoomConfigs: 0, - remoteRoomConfigs: 0, matrixGhosts: 0, - remoteGhosts: 0, + matrixRoomConfigs: 0, matrixRoomsByAge: new AgeCounters(), - remoteRoomsByAge: new AgeCounters(), matrixUsersByAge: new AgeCounters(), + remoteGhosts: 0, + remoteRoomConfigs: 0, + remoteRoomsByAge: new AgeCounters(), remoteUsersByAge: new AgeCounters(), }; - public init(bridge: any) { + public init(bridge: Bridge) { this.metrics = new PrometheusMetrics(); this.metrics.registerMatrixSdkMetrics(); this.metrics.registerBridgeGauges(() => this.bridgeGauges); this.metrics.addAppServicePath(bridge); this.remoteCallCounter = this.metrics.addCounter({ - name: "remote_api_calls", help: "Count of remote API calls made", labels: ["method"], + name: "remote_api_calls", }); this.storeCallCounter = this.metrics.addCounter({ - name: "store_calls", help: "Count of store function calls made", labels: ["method", "cached"], + name: "store_calls", }); this.presenceGauge = this.metrics.addGauge({ - name: "active_presence_users", help: "Count of users in the presence queue", labels: [], + + name: "active_presence_users", }); this.matrixRequest = this.metrics.addTimer({ - name: "matrix_request_seconds", help: "Histogram of processing durations of received Matrix messages", labels: ["outcome"], + name: "matrix_request_seconds", }); this.remoteRequest = this.metrics.addTimer({ - name: "remote_request_seconds", help: "Histogram of processing durations of received remote messages", labels: ["outcome"], + name: "remote_request_seconds", }); this.requestsInFlight = new Map(); setInterval(() => { @@ -107,7 +107,7 @@ export class PrometheusBridgeMetrics implements IBridgeMetrics { this.requestsInFlight.delete(id); } }); - }, REQUEST_EXPIRE_TIME_MS) + }, REQUEST_EXPIRE_TIME_MS); return this; } @@ -121,7 +121,7 @@ export class PrometheusBridgeMetrics implements IBridgeMetrics { if (!startTime) { log.verbose(`Got "requestOutcome" for ${id}, but this request was never started`); return; - } + } const duration = Date.now() - startTime; (isRemote ? this.remoteRequest : this.matrixRequest).observe({outcome}, duration / 1000); } @@ -137,5 +137,4 @@ export class PrometheusBridgeMetrics implements IBridgeMetrics { public storeCall(method: string, cached: boolean) { this.storeCallCounter.inc({method, cached: cached ? "yes" : "no"}); } -}; - +} diff --git a/test/mocks/discordclientfactory.ts b/test/mocks/discordclientfactory.ts index 803dedc1..b174f3d5 100644 --- a/test/mocks/discordclientfactory.ts +++ b/test/mocks/discordclientfactory.ts @@ -31,4 +31,6 @@ export class DiscordClientFactory { } return this.botClient; } + + public bindMetricsToChannel() {} } diff --git a/test/test_discordbot.ts b/test/test_discordbot.ts index f6208be1..17351703 100644 --- a/test/test_discordbot.ts +++ b/test/test_discordbot.ts @@ -453,7 +453,7 @@ describe("DiscordBot", () => { bot.lockChannel(chan); await bot.waitUnlock(chan); const diff = Date.now() - t; - expect(diff).to.be.greaterThan(SHORTDELAY - 1); + expect(diff).to.be.greaterThan(SHORTDELAY - 5); }); }); // }); diff --git a/tslint.json b/tslint.json index cd7de561..ff80b039 100644 --- a/tslint.json +++ b/tslint.json @@ -9,7 +9,7 @@ "object-literal-sort-keys": "off", "no-any": true, "arrow-return-shorthand": true, - "no-magic-numbers": true, + "no-magic-numbers": [true, -1, 0, 1, 1000], "prefer-for-of": true, "typedef": { "severity": "warning" From 22430301390c6ddb11991aea2e6c4ec33339fc7e Mon Sep 17 00:00:00 2001 From: Will Hunt Date: Fri, 31 May 2019 16:18:11 +0100 Subject: [PATCH 18/22] Linting --- src/bot.ts | 2 +- test/test_discordbot.ts | 4 +++- 2 files changed, 4 insertions(+), 2 deletions(-) diff --git a/src/bot.ts b/src/bot.ts index 388b017e..fc8b34f4 100644 --- a/src/bot.ts +++ b/src/bot.ts @@ -776,7 +776,7 @@ export class DiscordBot { let rooms; try { rooms = await this.channelSync.GetRoomIdsFromChannel(msg.channel); - if (rooms === null) { throw Error() } + if (rooms === null) { throw Error(); } } catch (err) { log.verbose("No bridged rooms to send message to. Oh well."); MetricPeg.get.requestOutcome(msg.id, true, "dropped"); diff --git a/test/test_discordbot.ts b/test/test_discordbot.ts index 17351703..918ff468 100644 --- a/test/test_discordbot.ts +++ b/test/test_discordbot.ts @@ -434,6 +434,7 @@ describe("DiscordBot", () => { it("should lock and unlock a channel early, if unlocked", async () => { const discordSendDelay = 500; const SHORTDELAY = 100; + const MINEXPECTEDDELAY = 95; const bot = new modDiscordBot.DiscordBot( "", { @@ -453,7 +454,8 @@ describe("DiscordBot", () => { bot.lockChannel(chan); await bot.waitUnlock(chan); const diff = Date.now() - t; - expect(diff).to.be.greaterThan(SHORTDELAY - 5); + // Date accuracy can be off by a few ms sometimes. + expect(diff).to.be.greaterThan(MINEXPECTEDDELAY); }); }); // }); From cff2bc18428da1fd476051401224b5f3f7175b41 Mon Sep 17 00:00:00 2001 From: Will Hunt Date: Fri, 31 May 2019 16:30:15 +0100 Subject: [PATCH 19/22] Add copyright header --- src/metrics.ts | 16 ++++++++++++++++ 1 file changed, 16 insertions(+) diff --git a/src/metrics.ts b/src/metrics.ts index e322c77b..db1556f3 100644 --- a/src/metrics.ts +++ b/src/metrics.ts @@ -1,3 +1,19 @@ +/* +Copyright 2019 matrix-appservice-discord + +Licensed under the Apache License, Version 2.0 (the "License"); +you may not use this file except in compliance with the License. +You may obtain a copy of the License at + + http://www.apache.org/licenses/LICENSE-2.0 + +Unless required by applicable law or agreed to in writing, software +distributed under the License is distributed on an "AS IS" BASIS, +WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +See the License for the specific language governing permissions and +limitations under the License. +*/ + import { PrometheusMetrics, Bridge } from "matrix-appservice-bridge"; import { Gauge, Counter, Histogram } from "prom-client"; import { Log } from "./log"; From 55a1248f662987e957533c6d74484b642aba738c Mon Sep 17 00:00:00 2001 From: Will Hunt Date: Fri, 31 May 2019 16:49:53 +0100 Subject: [PATCH 20/22] Bind metrics safely --- src/bot.ts | 1 + src/clientfactory.ts | 9 ++++++++- 2 files changed, 9 insertions(+), 1 deletion(-) diff --git a/src/bot.ts b/src/bot.ts index fc8b34f4..07c33b75 100644 --- a/src/bot.ts +++ b/src/bot.ts @@ -291,6 +291,7 @@ export class DiscordBot { try { MetricPeg.get.registerRequest(msg.id); await this.waitUnlock(msg.channel); + this.clientFactory.bindMetricsToChannel(msg.channel as Discord.TextChannel); this.discordMessageQueue[msg.channel.id] = (async () => { await (this.discordMessageQueue[msg.channel.id] || Promise.resolve()); try { diff --git a/src/clientfactory.ts b/src/clientfactory.ts index 22ded344..1b2adcfb 100644 --- a/src/clientfactory.ts +++ b/src/clientfactory.ts @@ -110,10 +110,17 @@ export class DiscordClientFactory { } public bindMetricsToChannel(channel: TextChannel) { + // tslint:disable-next-line:no-any + const flexChan = channel as any; + if (flexChan._xmet_send !== undefined) { + return; + } + // Prefix the real functions with _xmet_ + flexChan._xmet_send = channel.send; // tslint:disable-next-line:only-arrow-functions channel.send = function() { MetricPeg.get.remoteCall("channel.send"); - return channel.send.apply(channel, arguments); + return flexChan._xmet_send.apply(channel, arguments); }; } } From f64340b63e011015a65eab2012d2a438c39929d0 Mon Sep 17 00:00:00 2001 From: Will Hunt Date: Thu, 13 Jun 2019 11:47:47 +0100 Subject: [PATCH 21/22] More binds --- src/bot.ts | 7 ++++++- 1 file changed, 6 insertions(+), 1 deletion(-) diff --git a/src/bot.ts b/src/bot.ts index 07c33b75..8051c0b3 100644 --- a/src/bot.ts +++ b/src/bot.ts @@ -241,6 +241,7 @@ export class DiscordBot { client.on("messageDelete", async (msg: Discord.Message) => { try { await this.waitUnlock(msg.channel); + this.clientFactory.bindMetricsToChannel(msg.channel as Discord.TextChannel); this.discordMessageQueue[msg.channel.id] = (async () => { await (this.discordMessageQueue[msg.channel.id] || Promise.resolve()); try { @@ -261,6 +262,7 @@ export class DiscordBot { promiseArr.push(async () => { try { await this.waitUnlock(msg.channel); + this.clientFactory.bindMetricsToChannel(msg.channel as Discord.TextChannel); await this.DeleteDiscordMessage(msg); } catch (err) { log.error("Caught while handling 'messageDeleteBulk'", err); @@ -275,6 +277,7 @@ export class DiscordBot { client.on("messageUpdate", async (oldMessage: Discord.Message, newMessage: Discord.Message) => { try { await this.waitUnlock(newMessage.channel); + this.clientFactory.bindMetricsToChannel(newMessage.channel as Discord.TextChannel); this.discordMessageQueue[newMessage.channel.id] = (async () => { await (this.discordMessageQueue[newMessage.channel.id] || Promise.resolve()); try { @@ -777,7 +780,9 @@ export class DiscordBot { let rooms; try { rooms = await this.channelSync.GetRoomIdsFromChannel(msg.channel); - if (rooms === null) { throw Error(); } + if (rooms === null) { + throw Error(); + } } catch (err) { log.verbose("No bridged rooms to send message to. Oh well."); MetricPeg.get.requestOutcome(msg.id, true, "dropped"); From c3eaaa80d5106db22e2abbed34e0a2bed276ed59 Mon Sep 17 00:00:00 2001 From: Will Hunt Date: Thu, 13 Jun 2019 11:56:37 +0100 Subject: [PATCH 22/22] Add a note about metrics --- README.md | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/README.md b/README.md index 95d50c6b..97ab165f 100644 --- a/README.md +++ b/README.md @@ -79,6 +79,10 @@ docker build -t halfshot/matrix-appservice-discord . # Run the container docker run -v /matrix-appservice-discord:/data -p 9005:9005 halfshot/matrix-appservice-discord ``` +#### Metrics + +The bridge supports reporting metrics via Prometheus. You can configure metrics support in the config +file. The metrics will be reported under the URL provided in the registration file, on the `/metrics` endpoint. #### 3PID Protocol Support