Added extra info to stats metrics

server/index.ts

@@ -24,6 +24,11 @@ async function startServer() {
     });
 
     socket.on("requestJoin", async (event, callback) => {
+      getLogger().stats({
+        name: "user join request",
+        unit: "count",
+        value: 1,
+      });
       const { room, player } = await joinPlayer(
         socket,
         event.username,
@@ -40,6 +45,11 @@ async function startServer() {
     });
 
     socket.on("updateAcceleration", (event) => {
+      getLogger().stats({
+        name: "user acceleration update",
+        unit: "count",
+        value: 1,
+      });
       const player = getPlayer(socket);
 
       if (!player) {

server/logic/logic.ts

@@ -88,11 +88,18 @@ function createRoom(roomWithBots: boolean): Room {
 
       controller.updateRoom(elapsedTime / 1000);
 
-      getLogger().stats("room milliseconds between intervals", elapsedTime);
-      getLogger().stats(
-        "room update milliseconds delay",
-        roomUpdateStopWatch.next(),
-      );
+      getLogger().stats({
+        name: "room interval delay",
+        unit: "milliseconds",
+        extra: `room:${room.id}`,
+        value: elapsedTime,
+      });
+      getLogger().stats({
+        name: "room update delay",
+        unit: "milliseconds",
+        extra: `room:${room.id}`,
+        value: roomUpdateStopWatch.next(),
+      });
     }
   }, 15);
 

server/logic/room-controller.base.ts

@@ -68,13 +68,27 @@ export class BaseRoomController implements RoomController {
   updateRoom(elapsedTime: number) {
     const damages: Damage[] = [];
 
-    getLogger().statsFunction("updateBots", () => {
-      updateBots(this.room);
-    });
+    getLogger().statsFunction(
+      {
+        name: "update bots",
+        unit: "milliseconds",
+        extra: `room:${this.room.id}`,
+      },
+      () => {
+        updateBots(this.room);
+      },
+    );
 
-    getLogger().statsFunction("applyPhysics", () => {
-      applyPhysics(this.room, elapsedTime, (damage) => damages.push(damage));
-    });
+    getLogger().statsFunction(
+      {
+        name: "apply physics",
+        unit: "milliseconds",
+        extra: `room:${this.room.id}`,
+      },
+      () => {
+        applyPhysics(this.room, elapsedTime, (damage) => damages.push(damage));
+      },
+    );
 
     const deadPlayerIds = new Set<string>();
 

server/utils/logger.base.ts

@@ -2,6 +2,15 @@ import { StopWatch } from "./stopwatch";
 
 export const LOGGER_MODULE = "server";
 
+export type StatsUnit = "milliseconds" | "count";
+
+export type StatsRequest = {
+  name: string;
+  unit: StatsUnit;
+  extra?: string;
+  value: number;
+};
+
 export type Logger = {
   info(message: string): void;
   warn(message: string): void;
@@ -11,16 +20,14 @@ export type Logger = {
    *
    * It accumulates metrics with the same name, and flushes them automatically.
    */
-  stats(name: string, value: number): void;
+  stats(statsRequest: StatsRequest): void;
   /**
    * Same as `stats`, but it measures the time it takes to execute the callback.
    */
-  statsFunction<T>(name: string, callback: () => T): T;
-};
-
-export type StatsMetrics = {
-  name: string;
-  add(value: number): void;
+  statsFunction<T>(
+    statsRequest: Omit<StatsRequest, "value">,
+    callback: () => T,
+  ): T;
 };
 
 export type InternalLogger = Logger & {
@@ -34,14 +41,17 @@ export abstract class BaseLogger implements Logger {
 
   abstract error(message: string): void;
 
-  abstract stats(name: string, value: number): void;
+  abstract stats(statsRequest: StatsRequest): void;
 
   abstract destroy(): void;
 
-  statsFunction<T>(name: string, callback: () => T): T {
+  statsFunction<T>(
+    statsRequest: Omit<StatsRequest, "value">,
+    callback: () => T,
+  ): T {
     const stopWatch = new StopWatch();
     const result = callback();
-    this.stats(name, stopWatch.next());
+    this.stats({ ...statsRequest, value: stopWatch.next() });
     return result;
   }
 }

server/utils/logger.console.ts

@@ -1,6 +1,6 @@
 /* eslint-disable no-console */
 
-import { BaseLogger, InternalLogger } from "./logger.base";
+import { BaseLogger, InternalLogger, StatsRequest } from "./logger.base";
 
 export class ConsoleLogger extends BaseLogger {
   constructor(private otherLogger?: InternalLogger) {
@@ -22,8 +22,8 @@ export class ConsoleLogger extends BaseLogger {
     this.otherLogger?.error(message);
   }
 
-  stats(name: string, value: number) {
-    this.otherLogger?.stats(name, value);
+  stats(statsRequest: StatsRequest) {
+    this.otherLogger?.stats(statsRequest);
   }
 
   destroy() {

server/utils/logger.elastic-search.ts

@@ -5,7 +5,12 @@ import {
   PropertyName,
 } from "@elastic/elasticsearch/lib/api/types";
 import os from "os";
-import { BaseLogger, InternalLogger, LOGGER_MODULE } from "./logger.base";
+import {
+  BaseLogger,
+  InternalLogger,
+  LOGGER_MODULE,
+  StatsRequest,
+} from "./logger.base";
 
 export class ElasticSearchLogger extends BaseLogger {
   readonly bufferLimit = 1000;
@@ -14,7 +19,7 @@ export class ElasticSearchLogger extends BaseLogger {
   readonly logsBuffer: Record<string, unknown>[] = [];
   readonly statsBuffer: Record<string, unknown>[] = [];
 
-  autoStatsBuffer: Record<string, number[]> = {};
+  autoStatsBuffer: Record<string, StatsRequest[]> = {};
 
   readonly interval: NodeJS.Timeout;
 
@@ -29,9 +34,8 @@ export class ElasticSearchLogger extends BaseLogger {
 
     this.interval = setInterval(() => {
       this.flushLogs();
-      this.flushAutoStats();
       this.flushStats();
-    }, 5000);
+    }, 10_000);
   }
 
   static async create(
@@ -67,20 +71,21 @@ export class ElasticSearchLogger extends BaseLogger {
     this.addLog("error", message);
   }
 
-  stats(name: string, value: number) {
-    const existingAutoStats = this.autoStatsBuffer[name];
+  stats(statsRequest: StatsRequest) {
+    const key = `${statsRequest.name}__${statsRequest.extra ?? ""}--${statsRequest.unit}`;
+    const existingAutoStats = this.autoStatsBuffer[key];
 
     if (!existingAutoStats) {
-      this.autoStatsBuffer[name] = [value];
+      this.autoStatsBuffer[key] = [statsRequest];
       return;
     }
 
-    existingAutoStats.push(value);
+    existingAutoStats.push(statsRequest);
 
     if (existingAutoStats.length >= 500) {
       const stats = statsFrom(existingAutoStats);
-      this.addStats(name, stats.avg, stats.max, stats.min, stats.count);
-      delete this.autoStatsBuffer[name];
+      this.addStats(statsRequest, stats);
+      delete this.autoStatsBuffer[key];
     }
   }
 
@@ -116,18 +121,17 @@ export class ElasticSearchLogger extends BaseLogger {
     this.flush(this.logsIndex, this.logsBuffer);
   }
 
-  private flushAutoStats() {
-    for (const [name, values] of Object.entries(this.autoStatsBuffer)) {
-      if (values.length > 0) {
-        const stats = statsFrom(values);
-        this.addStats(name, stats.avg, stats.max, stats.min, stats.count);
+  private flushStats() {
+    for (const requests of Object.values(this.autoStatsBuffer)) {
+      const firstRequest = requests[0];
+      if (firstRequest) {
+        const stats = statsFrom(requests);
+        this.addStats(firstRequest, stats);
       }
     }
 
     this.autoStatsBuffer = {};
-  }
 
-  private flushStats() {
     this.flush(this.statsIndex, this.statsBuffer);
   }
 
@@ -145,22 +149,19 @@ export class ElasticSearchLogger extends BaseLogger {
     }
   }
 
-  private addStats(
-    name: string,
-    avg: number,
-    max: number,
-    min: number,
-    count: number,
-  ) {
+  private addStats(statsRequest: StatsRequest, stats: Stats) {
     this.statsBuffer.push({
       hostname: this.hostname,
       module: LOGGER_MODULE,
       timestamp: Date.now(),
-      name,
-      avg,
-      max,
-      min,
-      count,
+      name: statsRequest.name,
+      unit: statsRequest.unit,
+      extra: statsRequest.extra,
+      sum: stats.sum,
+      avg: stats.avg,
+      max: stats.max,
+      min: stats.min,
+      count: stats.count,
     });
 
     if (this.statsBuffer.length >= this.bufferLimit) {
@@ -169,13 +170,22 @@ export class ElasticSearchLogger extends BaseLogger {
   }
 }
 
-function statsFrom(values: number[]) {
+type Stats = {
+  sum: number;
+  avg: number;
+  max: number;
+  min: number;
+  count: number;
+};
+
+function statsFrom(requests: StatsRequest[]): Stats {
+  const values = requests.map((r) => r.value);
   const sum = values.reduce((a, b) => a + b, 0);
   const max = Math.max(...values);
   const min = Math.min(...values);
   const avg = sum / values.length;
 
-  return { avg, max, min, count: values.length };
+  return { sum, avg, max, min, count: values.length };
 }
 
 async function initializeElasticSearch(
@@ -210,6 +220,15 @@ async function initializeElasticSearch(
     name: {
       type: "keyword",
     },
+    unit: {
+      type: "keyword",
+    },
+    extra: {
+      type: "keyword",
+    },
+    sum: {
+      type: "double",
+    },
     avg: {
       type: "double",
     },