feat(metrics): export Prometheus metrics

Author: Menci

config-example.yaml

@@ -4,6 +4,10 @@ server:
   trustProxy:
     - loopback
   clusters: 0
+metrics:
+  hostname: 127.0.0.1
+  basePort: 2020
+  allowedIps: []
 services:
   database:
     type: mariadb

package.json

@@ -58,10 +58,12 @@
     "object-path": "^0.11.8",
     "patch-package": "^6.4.7",
     "postinstall-postinstall": "^2.1.0",
+    "prom-client": "^15.1.3",
     "proxy-addr": "^2.0.7",
     "proxy-agent": "^5.0.0",
     "randomstring": "^1.2.2",
     "rate-limiter-flexible": "^2.3.8",
+    "response-time": "^2.3.3",
     "rxjs": "^7.5.6",
     "serialize-javascript": "^6.0.0",
     "socket.io-msgpack-parser": "^3.0.1",
@@ -92,6 +94,7 @@
     "@types/object-path": "^0.11.1",
     "@types/proxy-addr": "^2.0.0",
     "@types/randomstring": "^1.1.8",
+    "@types/response-time": "^2.3.8",
     "@types/serialize-javascript": "^5.0.2",
     "@types/toposort": "^2.0.3",
     "@types/unzipper": "^0.10.5",

src/app.module.ts

@@ -5,6 +5,7 @@ import { AppService } from "./app.service";
 import { ErrorFilter } from "./error.filter";
 import { RecaptchaFilter } from "./recaptcha.filter";
 import { AuthMiddleware } from "./auth/auth.middleware";
+import { MetricsMiddleware } from "./metrics/metrics.middleware";
 
 import { SharedModule } from "./shared.module";
 import { RedisModule } from "./redis/redis.module";
@@ -24,6 +25,7 @@ import { DiscussionModule } from "./discussion/discussion.module";
 import { MigrationModule } from "./migration/migration.module";
 import { EventReportModule } from "./event-report/event-report.module";
 import { HomepageModule } from "./homepage/homepage.module";
+import { MetricsModule } from "./metrics/metrics.module";
 
 @Module({
   imports: [
@@ -44,7 +46,8 @@ import { HomepageModule } from "./homepage/homepage.module";
     forwardRef(() => DiscussionModule),
     forwardRef(() => EventReportModule),
     forwardRef(() => HomepageModule),
-    forwardRef(() => MigrationModule)
+    forwardRef(() => MigrationModule),
+    forwardRef(() => MetricsModule)
   ],
   controllers: [AppController],
   providers: [AppService, ErrorFilter, RecaptchaFilter]
@@ -55,5 +58,9 @@ export class AppModule implements NestModule {
       path: "*",
       method: RequestMethod.ALL
     });
+    consumer.apply(MetricsMiddleware).forRoutes({
+      path: "*",
+      method: RequestMethod.ALL
+    });
   }
 }

src/config/config.schema.ts

@@ -38,6 +38,19 @@ class ServerConfig {
   readonly clusters: number;
 }
 
+class MetricsConfig {
+  @IsIP()
+  readonly hostname: string;
+
+  @IsPortNumber()
+  readonly basePort: number;
+
+  @IsArray()
+  @IsIP(undefined, { each: true })
+  @IsOptional()
+  readonly allowedIps?: string[];
+}
+
 class ServicesConfigDatabase {
   @IsIn(["mysql", "mariadb"])
   readonly type: "mysql" | "mariadb";
@@ -543,6 +556,11 @@ export class AppConfig {
   @Type(() => ServerConfig)
   readonly server: ServerConfig;
 
+  @ValidateNested()
+  @Type(() => MetricsConfig)
+  @IsOptional()
+  readonly metrics?: MetricsConfig;
+
   @ValidateNested()
   @Type(() => ServicesConfig)
   readonly services: ServicesConfig;

src/error.filter.ts

@@ -4,12 +4,18 @@ import { Response } from "express"; // eslint-disable-line import/no-extraneous-
 
 import { RequestWithSession } from "./auth/auth.middleware";
 import { EventReportService, EventReportType } from "./event-report/event-report.service";
+import { MetricsService } from "./metrics/metrics.service";
 
 const logger = new Logger("ErrorFilter");
 
 @Catch()
 export class ErrorFilter implements ExceptionFilter {
-  constructor(private readonly eventReportService: EventReportService) {}
+  constructor(
+    private readonly eventReportService: EventReportService,
+    private readonly metricsService: MetricsService
+  ) {}
+
+  private readonly metricErrorCount = this.metricsService.counter("syzoj_ng_error_count", ["error"]);
 
   catch(error: Error, host: ArgumentsHost) {
     const contextType = host.getType();
@@ -32,6 +38,7 @@ export class ErrorFilter implements ExceptionFilter {
         logger.error(error.message, error.stack);
       } else logger.error(error);
 
+      this.metricErrorCount.inc({ error: error.constructor.name });
       this.eventReportService.report({
         type: EventReportType.Error,
         error,

src/judge/judge-queue.service.ts

@@ -4,6 +4,7 @@ import { Redis } from "ioredis";
 
 import { logger } from "@/logger";
 import { RedisService } from "@/redis/redis.service";
+import { MetricsService } from "@/metrics/metrics.service";
 
 import { JudgeTaskService } from "./judge-task-service.interface";
 import { JudgeTaskProgress } from "./judge-task-progress.interface";
@@ -28,6 +29,10 @@ export interface JudgeTaskMeta {
   type: JudgeTaskType;
 }
 
+export interface QueuedJudgeTaskMeta extends JudgeTaskMeta {
+  enqueueTime: number;
+}
+
 // eslint-disable-next-line @typescript-eslint/no-empty-interface
 export interface JudgeTaskExtraInfo {}
 
@@ -61,11 +66,17 @@ export class JudgeQueueService {
   private readonly taskServices: Map<JudgeTaskType, JudgeTaskService<JudgeTaskProgress, JudgeTaskExtraInfo>> =
     new Map();
 
-  constructor(private readonly redisService: RedisService) {
+  constructor(private readonly redisService: RedisService, private readonly metricsService: MetricsService) {
     this.redisForPush = this.redisService.getClient();
     this.redisForConsume = this.redisService.getClient();
   }
 
+  private readonly metricJudgeTaskQueueTime = this.metricsService.histogram(
+    "syzoj_ng_judge_task_queue_time_seconds",
+    this.metricsService.histogram.BUCKETS_TIME_10M_30,
+    ["type", "priority_type"]
+  );
+
   registerTaskType<TaskProgress>(
     taskType: JudgeTaskType,
     service: JudgeTaskService<TaskProgress, JudgeTaskExtraInfo>
@@ -81,7 +92,8 @@ export class JudgeQueueService {
       priority,
       JSON.stringify({
         taskId,
-        type
+        type,
+        enqueueTime: Date.now()
       })
     );
   }
@@ -102,7 +114,8 @@ export class JudgeQueueService {
 
     const [, taskJson, priorityString] = redisResponse;
     const priority = Number(priorityString);
-    const taskMeta: JudgeTaskMeta = JSON.parse(taskJson);
+    const taskMeta: QueuedJudgeTaskMeta = JSON.parse(taskJson);
+    const dequeuedTime = Date.now();
     const task = await this.taskServices.get(taskMeta.type).getTaskToBeSentToJudgeByTaskId(taskMeta.taskId, priority);
     if (!task) {
       logger.verbose(
@@ -111,6 +124,16 @@ export class JudgeQueueService {
       return null;
     }
 
+    if (taskMeta.enqueueTime) {
+      this.metricJudgeTaskQueueTime.observe(
+        {
+          type: task.type,
+          priority_type: task.priorityType
+        },
+        (Date.now() - dequeuedTime) / 1000
+      );
+    }
+
     logger.verbose(
       `Consumed judge task { taskId: ${task.taskId}, type: ${task.type}, priority: ${priority} (${
         JudgeTaskPriorityType[task.priorityType]

src/judge/judge.module.ts

@@ -4,6 +4,7 @@ import { TypeOrmModule } from "@nestjs/typeorm";
 import { RedisModule } from "@/redis/redis.module";
 import { FileModule } from "@/file/file.module";
 import { EventReportModule } from "@/event-report/event-report.module";
+import { MetricsModule } from "@/metrics/metrics.module";
 
 import { JudgeQueueService } from "./judge-queue.service";
 import { JudgeGateway } from "./judge.gateway";
@@ -16,7 +17,8 @@ import { JudgeClientEntity } from "./judge-client.entity";
     TypeOrmModule.forFeature([JudgeClientEntity]),
     forwardRef(() => RedisModule),
     forwardRef(() => FileModule),
-    forwardRef(() => EventReportModule)
+    forwardRef(() => EventReportModule),
+    forwardRef(() => MetricsModule)
   ],
   controllers: [JudgeClientController],
   providers: [JudgeGateway, JudgeClientService, JudgeQueueService],

src/metrics/metrics.middleware.ts

@@ -0,0 +1,27 @@
+import { NestMiddleware, Injectable } from "@nestjs/common";
+
+import { Request, Response } from "express"; // eslint-disable-line import/no-extraneous-dependencies
+import responseTime from "response-time";
+
+import { MetricsService } from "./metrics.service";
+
+@Injectable()
+export class MetricsMiddleware implements NestMiddleware {
+  constructor(private readonly metricsSerivce: MetricsService) {}
+
+  private readonly metricRequestLatency = this.metricsSerivce.histogram(
+    "syzoj_ng_request_latency_seconds",
+    this.metricsSerivce.histogram.BUCKETS_TIME_5S_10,
+    ["api"]
+  );
+
+  private readonly responseTimeMiddleware = responseTime((req, res, time) => {
+    if (!req.url || !(res.statusCode >= 200 && res.statusCode < 400)) return;
+    const url = new URL(req.url);
+    this.metricRequestLatency.observe({ api: url.pathname }, time / 1000);
+  });
+
+  async use(req: Request, res: Response, next: () => void) {
+    this.responseTimeMiddleware(req, res, next);
+  }
+}

src/metrics/metrics.module.ts

@@ -0,0 +1,9 @@
+import { Module } from "@nestjs/common";
+
+import { MetricsService } from "./metrics.service";
+
+@Module({
+  providers: [MetricsService],
+  exports: [MetricsService]
+})
+export class MetricsModule {}

src/metrics/metrics.service.ts

@@ -0,0 +1,86 @@
+import cluster from "cluster";
+import http from "http";
+
+import { Injectable, Logger } from "@nestjs/common";
+
+import PromClient from "prom-client";
+
+import { ConfigService } from "@/config/config.service";
+
+@Injectable()
+export class MetricsService {
+  private readonly registry = new PromClient.Registry();
+
+  private readonly processName = cluster.isPrimary ? "Master" : `Worker #${cluster.worker.id}`;
+  private readonly logger = new Logger(`${MetricsService.name}/${this.processName}`);
+
+  constructor(private readonly configService: ConfigService) {
+    const config = this.configService.config.metrics;
+    if (!config) {
+      this.logger.warn("Metrics not configured");
+      return;
+    }
+
+    PromClient.collectDefaultMetrics({ register: this.registry });
+
+    const processName = cluster.isPrimary ? "Master" : `Worker #${cluster.worker.id}`;
+    const port = config.basePort + (cluster.isPrimary ? 0 : cluster.worker.id);
+    http
+      .createServer(async (req, res) => {
+        try {
+          if (config.allowedIps?.length > 0 && !config.allowedIps.includes(req.socket.remoteAddress!)) {
+            res.writeHead(403).end();
+            return;
+          }
+          res.writeHead(200, {
+            "Content-Type": this.registry.contentType
+          });
+          res.write(await this.registry.metrics());
+          res.end();
+        } catch (e) {
+          this.logger.error(`Failed to serve metrics request: ${e instanceof Error ? e.stack : String(e)}`);
+          try {
+            res.writeHead(500).end();
+          } catch {
+            res.end();
+          }
+        }
+      })
+      .listen(port, config.hostname, () => {
+        this.logger.log(`Metrics server is listening on ${config.hostname}:${port} (${processName})`);
+      });
+  }
+
+  counter = <T extends string>(name: string, labelNames: readonly T[] = []) =>
+    new PromClient.Counter({
+      name,
+      help: name,
+      labelNames,
+      registers: [this.registry]
+    });
+
+  gauge = <T extends string>(name: string, labelNames: readonly T[] = []) =>
+    new PromClient.Gauge({
+      name,
+      help: name,
+      labelNames,
+      registers: [this.registry]
+    });
+
+  histogram = Object.assign(
+    <T extends string>(name: string, buckets: number[], labelNames: readonly T[] = []) =>
+      new PromClient.Histogram({
+        name,
+        help: name,
+        buckets,
+        labelNames,
+        registers: [this.registry]
+      }),
+    {
+      linearBuckets: PromClient.linearBuckets,
+      exponentialBuckets: PromClient.exponentialBuckets,
+      BUCKETS_TIME_10M_30: PromClient.exponentialBuckets(0.05, 1.368, 30),
+      BUCKETS_TIME_5S_10: PromClient.exponentialBuckets(0.03, 1.79, 10)
+    }
+  );
+}