add common handler decorator and metrics for buzzer client

.gitea/workflows/build-homeassistant.yaml

@@ -15,7 +15,6 @@ jobs:
       token: ${{ github.token }}
   deploy-gitainer:
     needs: docker
-    runs-on: ubuntu-22.04
+    uses: martin/chromart-gitea-actions/.gitea/workflows/gitainer-deploy.yaml@main
-    steps:
+    with:
-      - name: Call Gitainer stack webhooks
+      stack_name: doorman-homeassistant
-        run: curl --request POST http://192.168.1.150:9080/api/stacks/doorman-homeassistant?pretty

packages/doorman-api/package.json

@@ -12,14 +12,15 @@
   },
   "dependencies": {
     "@aws-sdk/client-dynamodb": "^3.609.0",
-    "@twilio-labs/serverless-runtime-types": "^4.0.1",
     "@twilio/runtime-handler": "1.3.0",
     "discord.js": "^14.16.3",
+    "prom-client": "^15.1.3",
     "twilio": "^3.56"
   },
   "devDependencies": {
     "twilio-run": "^3.5.4",
-    "concurrently": "^9.1.0"
+    "concurrently": "^9.1.0",
+    "@twilio-labs/serverless-runtime-types": "^3.0.0"
   },
   "engines": {
     "node": "18"

packages/doorman-api/src/common/DoormanHandler.ts

@@ -0,0 +1,91 @@
+import { ServerlessCallback, ServerlessFunctionSignature } from "@twilio-labs/serverless-runtime-types/types";
+import { PrometheusContentType, Registry, Pushgateway, Summary } from "prom-client";
+import { DoormanLambdaContext } from "./DoormanHandlerContext";
+
+export type BaseEvent = { request: { cookies: {}; headers: {}; }; }
+
+export type DoormanLambda<T extends DoormanLambdaContext, U extends BaseEvent> = (
+  context: Parameters<ServerlessFunctionSignature<T, U>>[0],
+  event: Parameters<ServerlessFunctionSignature<T, U>>[1],
+  callback: Parameters<ServerlessFunctionSignature<T, U>>[2],
+  metricsRegistry: Registry<PrometheusContentType>,
+) => void;
+
+export enum CommonMetrics {
+  RUNTIME = "FunctionRuntime",
+};
+
+/**
+ * A decorator for twilio handlers. It provides a metrics registry and 
+ * should implement timeout and cleanup jobs based on lambda timeout
+ * @param handler 
+ */
+export function withMetrics<T extends DoormanLambdaContext, U extends BaseEvent>(
+  functionName: string,
+  handler: DoormanLambda<T, U>
+): ServerlessFunctionSignature<T, U> {
+  return async (context, event, callback) => {
+    console.log("[CommonHandler] creating metrics registry");
+    const metricsRegistry = new Registry();
+    const pushGateway = new Pushgateway(context.PUSHGATEWAY_URL, {}, metricsRegistry);
+
+    metricsRegistry.registerMetric(new Summary({
+      name: CommonMetrics.RUNTIME,
+      help: "Runtime of the function",
+    }));
+
+    const summaryTimer = (metricsRegistry.getSingleMetric(CommonMetrics.RUNTIME) as Summary).startTimer();
+
+    const startTime = Date.now();
+    console.log(`[CommonHandler] started handler at ${startTime}`);
+
+    const handlerResponsePromise: Promise<Parameters<ServerlessCallback>> = new Promise(async (resolve, reject) => {
+      // intercept the callbackResult
+      let callbackResult: Parameters<ServerlessCallback> | undefined;
+      const tempCallback: ServerlessCallback = (err, payload) => {
+        callbackResult = [err, payload];
+      }
+
+      await handler(context, event, tempCallback, metricsRegistry);
+
+      if (!callbackResult) {
+        reject("No callback was given");
+      }
+      resolve(callbackResult as Parameters<ServerlessCallback>);
+    });
+
+    console.time("[CommonHandler] nested handler time");
+
+    const result = await handlerResponsePromise;
+
+    console.timeEnd("[CommonHandler] nested handler time");
+
+    const endTime = Date.now();
+    const remainingTime = 10000 - (endTime - startTime);
+
+    console.log(`[CommonHandler] there is ${remainingTime} ms left to send metrics`);
+
+    let metricsTimeout = setTimeout(() => {
+      console.log("[CommonHandler] cutting it too close, abandoning metrics");
+      callback(...result);
+    }, remainingTime - 250);
+
+    summaryTimer();
+
+    console.log("[CommonHandler] attempting to push metrics...");
+    try {
+      await pushGateway.push({
+        jobName: functionName,
+        groupings: {
+          stage: context.STAGE,
+        },
+      });
+      console.log("[CommonHandler] pushed metrics successfully");
+    } catch (e: any) {
+      console.log("[CommonHandler] failed to push metrics, quietly discarding them", e);
+    }
+    
+    clearTimeout(metricsTimeout);
+    callback(...result);
+  };
+};

packages/doorman-api/src/common/DoormanHandlerContext.ts

@@ -0,0 +1,11 @@
+import { EnvironmentVariables } from "@twilio-labs/serverless-runtime-types/types";
+
+export enum Stage {
+  DEV = "dev",
+  PROD = "prod",
+};
+
+export interface DoormanLambdaContext extends EnvironmentVariables {
+  PUSHGATEWAY_URL: string;
+  STAGE: string;
+};

packages/doorman-client/.env.example

@@ -2,4 +2,8 @@ DOORMAN_URL=https://doorman.chromart.cc
 
 # twilio auth
 ACCOUNT_SID=
-AUTH_TOKEN=
+AUTH_TOKEN=
+
+# metrics
+PUSHGATEWAY_URL=https://metrics.chromart.cc
+STAGE=prod

packages/doorman-client/package.json

@@ -11,21 +11,23 @@
     "deploy": "twilio-run deploy --load-system-env --env .env.example --service-name buzzer --environment=prod --override-existing-project"
   },
   "dependencies": {
-    "@twilio-labs/serverless-runtime-types": "^3.0.0",
     "@twilio/runtime-handler": "1.3.0",
-    "node-fetch": "2",
+    "node-fetch": "^2.7.0",
-    "twilio": "^3.56"
+    "prom-client": "^15.1.3",
+    "prometheus-remote-write": "^0.5.0",
+    "twilio": "^3.84.1"
   },
   "devDependencies": {
     "@types/bun": "latest",
     "concurrently": "^9.1.0",
-    "twilio-run": "^3.5.4"
+    "twilio-run": "^3.5.4",
+    "@twilio-labs/serverless-runtime-types": "^3.0.0"
   },
   "engines": {
     "node": "18"
   },
   "type": "commonjs",
   "peerDependencies": {
-    "typescript": "^5.0.0"
+    "typescript": "^5.2.2"
   }
 }

packages/doorman-client/src/functions/buzzer-activated.ts

@@ -15,8 +15,14 @@ import VoiceResponse from 'twilio/lib/twiml/VoiceResponse';
 import { DoorStatus } from '../../../doorman-api/src/types/DoorStatus';
 import { StatusResponse } from '../../../doorman-api/src/functions/api/door/status';
 import { InfoResponseClient } from '../../../doorman-api/src/functions/api/door/info';
+import { withMetrics } from '../../../doorman-api/src/common/DoormanHandler';
+import { Counter, Summary } from 'prom-client';
+import { BuzzerActivatedMetrics, registerMetrics } from '../metrics/BuzzerActivatedMetrics';
 
-export const handler: ServerlessFunctionSignature<TwilioContext, BuzzerDialEvent> = async function(context, event, callback) {
+export const handler: ServerlessFunctionSignature<TwilioContext, BuzzerDialEvent> = withMetrics('buzzer-activated', async function(context, event, callback, metricsRegistry) {
+  // metrics
+  registerMetrics(metricsRegistry);
+  
   let invokeId = `[${randomUUID()}]`;
   let configString = event.config;
   let config: InfoResponseClient | undefined;
@@ -37,6 +43,7 @@ export const handler: ServerlessFunctionSignature<TwilioContext, BuzzerDialEvent
   if (!config || !config.door) {
     let twiml = new Twilio.twiml.VoiceResponse();
     twiml.reject();
+    (metricsRegistry.getSingleMetric(BuzzerActivatedMetrics.CALL_REJECTED) as Counter).inc({ From: event.From }, 1);
     callback(null, twiml);
     return;
   }
@@ -47,7 +54,7 @@ export const handler: ServerlessFunctionSignature<TwilioContext, BuzzerDialEvent
     msg + u + ')'
   );
 
-  await notifyDiscord(context, msgs, config.discordUsers, config.discordUsers.map(() => ""));
+  await notifyDiscord(context, msgs, config.discordUsers, config.discordUsers.map(() => ""), metricsRegistry);
 
   let discordLock = false;
   let intervals: Timer[] = [];
@@ -55,10 +62,14 @@ export const handler: ServerlessFunctionSignature<TwilioContext, BuzzerDialEvent
 
   const unlockPromise = new Promise<VoiceResponse>((resolve, reject) => {
     intervals.push(setInterval(() => {
+      (metricsRegistry.getSingleMetric(BuzzerActivatedMetrics.POLL_ATTEMPTS) as Counter).inc({ door: config.door }, 1);
+      const recordPollLatency = (metricsRegistry.getSingleMetric(BuzzerActivatedMetrics.POLL_LATENCY) as Summary).startTimer({ door: config.door });
+      
       fetch(context.DOORMAN_URL + `/api/door/status?door=${config.door}`)
         .then(res => res.json())
         .then(async (rawBody) => {
           let body = rawBody as StatusResponse;
+          recordPollLatency();
           if (body?.status === DoorStatus.OPEN) {
             clearInterval(intervals[0]);
             const twiml = doorOpenTwiml(config);
@@ -68,7 +79,9 @@ export const handler: ServerlessFunctionSignature<TwilioContext, BuzzerDialEvent
               console.log(
                 invokeId, "UnlockPromise: I was the fastest, so I will attempt to notify discord users before resolving with unlock"
               );
-              await notifyAllDiscord(context, config, `🔓 Doorman buzzed someone up @ Door "${config.door}"`, JSON.stringify(body.fingerprint));
+              (metricsRegistry.getSingleMetric(BuzzerActivatedMetrics.API_UNLOCK) as Counter).inc({ door: config.door }, 1);
+              await notifyAllDiscord(context, config, `🔓 Doorman buzzed someone up @ Door "${config.door}"`, metricsRegistry, JSON.stringify(body.fingerprint));
+  
               resolve(twiml);
             } else {
               console.log(
@@ -86,6 +99,7 @@ export const handler: ServerlessFunctionSignature<TwilioContext, BuzzerDialEvent
 
       if (!discordLock) {
         discordLock = true;
+        (metricsRegistry.getSingleMetric(BuzzerActivatedMetrics.DIAL_THROUGH) as Counter).inc({ door: config.door }, 1);
 
         console.log(
           invokeId, "GracefulFallbackPromise: I was the fastest, so I will attempt to notify discord users before resolving with a call"
@@ -93,7 +107,8 @@ export const handler: ServerlessFunctionSignature<TwilioContext, BuzzerDialEvent
         await notifyAllDiscord(
           context, 
           config, 
-          `📞 Somebody buzzed the door and it dialed through to fallback phone numbers @ Door "${config.door}"`
+          `📞 Somebody buzzed the door and it dialed through to fallback phone numbers @ Door "${config.door}"`,
+          metricsRegistry,
         );
         resolve(twiml);
       } else {
@@ -106,6 +121,9 @@ export const handler: ServerlessFunctionSignature<TwilioContext, BuzzerDialEvent
 
   const ungracefulFallbackPromise = new Promise<VoiceResponse>((resolve, reject) => {
     timeouts.push(setTimeout(async () => {
+      (metricsRegistry.getSingleMetric(BuzzerActivatedMetrics.RESULT_NOTIFICATION_FATE_UNKNOWN) as Counter).inc({ door: config.door }, 1);
+      (metricsRegistry.getSingleMetric(BuzzerActivatedMetrics.DIAL_THROUGH) as Counter).inc({ door: config.door }, 1);
+
       const twiml = dialFallbackTwiml(config);
       console.error(
         invokeId, "UngracefulFallbackPromise: Cutting it too close to timeout! Skipping notifying users and calling fallback"
@@ -119,4 +137,4 @@ export const handler: ServerlessFunctionSignature<TwilioContext, BuzzerDialEvent
   timeouts.forEach(timeout => clearTimeout(timeout));
   intervals.forEach(interval => clearInterval(interval));
   callback(null, twiml);
-};
+});

packages/doorman-client/src/metrics/BuzzerActivatedMetrics.ts

@@ -0,0 +1,54 @@
+import { Counter, Registry, Summary } from "prom-client";
+
+export enum BuzzerActivatedMetrics {
+  CALL_REJECTED = "CallRejected",
+  API_UNLOCK = "ApiUnlocked",
+  DIAL_THROUGH = "DialThrough",
+  RESULT_NOTIFICATION_FATE_UNKNOWN = "ResultNotificationFateUnknown",
+  POLL_ATTEMPTS = "PollAttempts",
+  POLL_LATENCY = "PollLatency",
+  NOTIFY_LATENCY = "NotifyLatency",
+}
+
+export const registerMetrics = (metricsRegistry: Registry) => {
+  metricsRegistry.registerMetric(new Counter({
+    name: BuzzerActivatedMetrics.CALL_REJECTED,
+    help: "A call is rejected because the dialer / door is not registered",
+    labelNames: ["From"],
+  }));
+
+  metricsRegistry.registerMetric(new Counter({
+    name: BuzzerActivatedMetrics.API_UNLOCK,
+    help: "Door was unlocked with the API",
+    labelNames: ["door"],
+  }));
+
+  metricsRegistry.registerMetric(new Counter({
+    name: BuzzerActivatedMetrics.DIAL_THROUGH,
+    help: "Dialed through to fallback numbers",
+    labelNames: ["door"],
+  }));
+
+  metricsRegistry.registerMetric(new Counter({
+    name: BuzzerActivatedMetrics.RESULT_NOTIFICATION_FATE_UNKNOWN,
+    help: "Discord result notification may or may not have been delivered due to time constraints",
+    labelNames: ["door"],
+  }));
+
+  metricsRegistry.registerMetric(new Counter({
+    name: BuzzerActivatedMetrics.POLL_ATTEMPTS,
+    help: "Number of times the door status was polled",
+    labelNames: ["door"],
+  }));
+
+  metricsRegistry.registerMetric(new Summary({
+    name: BuzzerActivatedMetrics.POLL_LATENCY,
+    help: "Latency for the door status poll",
+    labelNames: ["door"],
+  }));
+
+  metricsRegistry.registerMetric(new Summary({
+    name: BuzzerActivatedMetrics.NOTIFY_LATENCY,
+    help: "Latency for notify api calls",
+  }));
+}

packages/doorman-client/src/types/TwilioContext.ts

@@ -1,5 +1,5 @@
-import { EnvironmentVariables } from "@twilio-labs/serverless-runtime-types/types";
+import { DoormanLambdaContext } from "../../../doorman-api/src/common/DoormanHandlerContext";
 
-export interface TwilioContext extends EnvironmentVariables {
+export interface TwilioContext extends DoormanLambdaContext {
   DOORMAN_URL: string;
-}
+};

packages/doorman-client/src/utils/DoormanUtils.ts

@@ -1,8 +1,10 @@
+import { register, Registry, Summary } from "prom-client";
+import { InfoResponseClient } from "../../../doorman-api/src/functions/api/door/info";
 import { TwilioContext } from "../types/TwilioContext";
-import { DoorConfig } from "../types/DoorConfig";
 import { lambdaFastHttp } from "./LambdaUtils";
+import { BuzzerActivatedMetrics } from "../metrics/BuzzerActivatedMetrics";
 
-export async function getConfig(context: TwilioContext, buzzer: string): Promise<DoorConfig | undefined> {
+export async function getConfig(context: TwilioContext, buzzer: string): Promise<InfoResponseClient | undefined> {
   return await fetch(context.DOORMAN_URL + `/api/door/info?buzzer=${buzzer}`)
     .then(res => res.json())
     .catch(err => {
@@ -10,12 +12,15 @@ export async function getConfig(context: TwilioContext, buzzer: string): Promise
     });
 }
 
-export function notifyDiscord(context: TwilioContext, msg: string[], u: string[], optionalJsonStr: string[]){
+export async function notifyDiscord(context: TwilioContext, msg: string[], u: string[], optionalJsonStr: string[], metricsRegistry: Registry){
-  return lambdaFastHttp(context.DOORMAN_URL + 
+  const endTimer = (metricsRegistry.getSingleMetric(BuzzerActivatedMetrics.NOTIFY_LATENCY) as Summary).startTimer();
+  const res = await lambdaFastHttp(context.DOORMAN_URL + 
     `/api/door/notify?discordUser=${encodeURIComponent(JSON.stringify(u))}&msg=${encodeURIComponent(JSON.stringify(msg))}&json=${encodeURIComponent(JSON.stringify(optionalJsonStr))}`,
-  ).catch(err => console.log(err))
+  ).catch(err => console.log(err));
+  endTimer();
+  return res;
 }
 
-export async function notifyAllDiscord(context: TwilioContext, config: DoorConfig, msg: string, optionalJsonStr: string = "") {
+export async function notifyAllDiscord(context: TwilioContext, config: InfoResponseClient, msg: string, metricsRegistry: Registry, optionalJsonStr: string = "") {
-  return notifyDiscord(context, config.discordUsers.map(() => msg), config.discordUsers, config.discordUsers.map(() => optionalJsonStr));
+  return notifyDiscord(context, config.discordUsers.map(() => msg), config.discordUsers, config.discordUsers.map(() => optionalJsonStr), metricsRegistry);
 }

packages/doorman-client/src/utils/TwimlUtils.ts

@@ -1,7 +1,7 @@
 import VoiceResponse from 'twilio/lib/twiml/VoiceResponse';
-import { DoorConfig } from '../types/DoorConfig';
+import { InfoResponseClient } from '../../../doorman-api/src/functions/api/door/info';
 
-export function doorOpenTwiml(config: DoorConfig): VoiceResponse {
+export function doorOpenTwiml(config: InfoResponseClient): VoiceResponse {
   const twiml = new Twilio.twiml.VoiceResponse();
 
   twiml.play('https://buzzer-2439-prod.twil.io/buzzing_up_boosted.mp3');
@@ -12,7 +12,7 @@ export function doorOpenTwiml(config: DoorConfig): VoiceResponse {
   return twiml;
 }
 
-export function dialFallbackTwiml(config: DoorConfig): VoiceResponse {
+export function dialFallbackTwiml(config: InfoResponseClient): VoiceResponse {
   const twiml = new Twilio.twiml.VoiceResponse();
 
   let dial = twiml.dial({