BC-7235 Add initial PerformanceObserver and use it for tldraw.

apps/server/src/core/logger/types/logging.types.ts

@@ -1,3 +1,6 @@
+/**
+ * Information inside this file should be placed in shared, type are copied to it.
+ */
 export type LogMessage = {
 	message: string;
 	data?: LogMessageData;

apps/server/src/modules/tldraw/config.ts

@@ -17,14 +17,15 @@ export interface TldrawConfig {
 	API_HOST: number;
 	TLDRAW_MAX_DOCUMENT_SIZE: number;
 	TLDRAW_FINALIZE_DELAY: number;
+	PERFORMANCE_MEASURE_ENABLED: boolean;
 }
 
 export const TLDRAW_DB_URL: string = Configuration.get('TLDRAW_DB_URL') as string;
 export const TLDRAW_SOCKET_PORT = Configuration.get('TLDRAW__SOCKET_PORT') as number;
 
 const tldrawConfig = {
 	TLDRAW_DB_URL,
-	NEST_LOG_LEVEL: Configuration.get('NEST_LOG_LEVEL') as string,
+	NEST_LOG_LEVEL: Configuration.get('TLDRAW__LOG_LEVEL') as string,
 	INCOMING_REQUEST_TIMEOUT: Configuration.get('INCOMING_REQUEST_TIMEOUT_API') as number,
 	TLDRAW_DB_COMPRESS_THRESHOLD: Configuration.get('TLDRAW__DB_COMPRESS_THRESHOLD') as number,
 	FEATURE_TLDRAW_ENABLED: Configuration.get('FEATURE_TLDRAW_ENABLED') as boolean,
@@ -39,6 +40,7 @@ const tldrawConfig = {
 	API_HOST: Configuration.get('API_HOST') as string,
 	TLDRAW_MAX_DOCUMENT_SIZE: Configuration.get('TLDRAW__MAX_DOCUMENT_SIZE') as number,
 	TLDRAW_FINALIZE_DELAY: Configuration.get('TLDRAW__FINALIZE_DELAY') as number,
+	PERFORMANCE_MEASURE_ENABLED: Configuration.get('TLDRAW__PERFORMANCE_MEASURE_ENABLED') as boolean,
 };
 
 export const config = () => tldrawConfig;

apps/server/src/modules/tldraw/repo/y-mongodb.spec.ts

@@ -1,17 +1,17 @@
+import { createMock } from '@golevelup/ts-jest';
+import { MongoMemoryDatabaseModule } from '@infra/database';
 import { EntityManager } from '@mikro-orm/mongodb';
+import { ConfigModule } from '@nestjs/config';
 import { Test, TestingModule } from '@nestjs/testing';
 import { cleanupCollections } from '@shared/testing';
-import { MongoMemoryDatabaseModule } from '@infra/database';
-import { ConfigModule } from '@nestjs/config';
-import { createMock } from '@golevelup/ts-jest';
-import * as Yjs from 'yjs';
 import { createConfigModuleOptions } from '@src/config';
 import { DomainErrorHandler } from '@src/core';
-import { tldrawEntityFactory, tldrawTestConfig } from '../testing';
+import * as Yjs from 'yjs';
 import { TldrawDrawing } from '../entities';
+import { tldrawEntityFactory, tldrawTestConfig } from '../testing';
+import { Version } from './key.factory';
 import { TldrawRepo } from './tldraw.repo';
 import { YMongodb } from './y-mongodb';
-import { Version } from './key.factory';
 
 jest.mock('yjs', () => {
 	const moduleMock: unknown = {

apps/server/src/modules/tldraw/repo/y-mongodb.ts

@@ -1,12 +1,12 @@
 import { BulkWriteResult } from '@mikro-orm/mongodb/node_modules/mongodb';
 import { Injectable } from '@nestjs/common';
 import { ConfigService } from '@nestjs/config';
+import { DomainErrorHandler } from '@src/core';
 import { Buffer } from 'buffer';
 import * as binary from 'lib0/binary';
 import * as encoding from 'lib0/encoding';
 import * as promise from 'lib0/promise';
 import { applyUpdate, Doc, encodeStateAsUpdate, encodeStateVector, mergeUpdates } from 'yjs';
-import { DomainErrorHandler } from '@src/core';
 import { TldrawConfig } from '../config';
 import { WsSharedDocDo } from '../domain';
 import { TldrawDrawing } from '../entities';
@@ -94,7 +94,8 @@ export class YMongodb {
 
 	// return value is not void, need to be changed
 	public compressDocumentTransactional(docName: string): Promise<void> {
-		// return value can be null, need to be defined
+		performance.mark('compressDocumentTransactional');
+
 		return this._transact(docName, async () => {
 			const updates = await this.getMongoUpdates(docName);
 			const mergedUpdates = mergeUpdates(updates);
@@ -105,10 +106,16 @@ export class YMongodb {
 			const stateAsUpdate = encodeStateAsUpdate(ydoc);
 			const sv = encodeStateVector(ydoc);
 			const clock = await this.storeUpdate(docName, stateAsUpdate);
+
 			await this.writeStateVector(docName, sv, clock);
 			await this.clearUpdatesRange(docName, 0, clock);
 
 			ydoc.destroy();
+
+			performance.measure('tldraw:YMongodb:compressDocumentTransactional', {
+				start: 'compressDocumentTransactional',
+				detail: { doc_name: docName, clock },
+			});
 		});
 	}
 
@@ -143,20 +150,24 @@ export class YMongodb {
 		return this.repo.readAsCursor(query, opts);
 	}
 
-	private mergeDocsTogether(doc: TldrawDrawing, docs: TldrawDrawing[], docIndex: number): Buffer[] {
-		const parts = [Buffer.from(doc.value.buffer)];
-		let currentPartId: number | undefined = doc.part;
-		for (let i = docIndex + 1; i < docs.length; i += 1) {
-			const part = docs[i];
-
-			if (!this.isSameClock(part, doc)) {
+	private mergeDocsTogether(
+		tldrawDrawingEntity: TldrawDrawing,
+		tldrawDrawingEntities: TldrawDrawing[],
+		docIndex: number
+	): Buffer[] {
+		const parts = [Buffer.from(tldrawDrawingEntity.value.buffer)];
+		let currentPartId: number | undefined = tldrawDrawingEntity.part;
+		for (let i = docIndex + 1; i < tldrawDrawingEntities.length; i += 1) {
+			const entity = tldrawDrawingEntities[i];
+
+			if (!this.isSameClock(entity, tldrawDrawingEntity)) {
 				break;
 			}
 
-			this.checkIfPartIsNextPartAfterCurrent(part, currentPartId);
+			this.checkIfPartIsNextPartAfterCurrent(entity, currentPartId);
 
-			parts.push(Buffer.from(part.value.buffer));
-			currentPartId = part.part;
+			parts.push(Buffer.from(entity.value.buffer));
+			currentPartId = entity.part;
 		}
 
 		return parts;
@@ -165,20 +176,20 @@ export class YMongodb {
 	/**
 	 * Convert the mongo document array to an array of values (as buffers)
 	 */
-	private convertMongoUpdates(docs: TldrawDrawing[]): Buffer[] {
-		if (!Array.isArray(docs) || !docs.length) return [];
+	private convertMongoUpdates(tldrawDrawingEntities: TldrawDrawing[]): Buffer[] {
+		if (!Array.isArray(tldrawDrawingEntities) || !tldrawDrawingEntities.length) return [];
 
 		const updates: Buffer[] = [];
-		for (let i = 0; i < docs.length; i += 1) {
-			const doc = docs[i];
+		for (let i = 0; i < tldrawDrawingEntities.length; i += 1) {
+			const tldrawDrawingEntity = tldrawDrawingEntities[i];
 
-			if (!doc.part) {
-				updates.push(Buffer.from(doc.value.buffer));
+			if (!tldrawDrawingEntity.part) {
+				updates.push(Buffer.from(tldrawDrawingEntity.value.buffer));
 			}
 
-			if (doc.part === 1) {
+			if (tldrawDrawingEntity.part === 1) {
 				// merge the docs together that got split because of mongodb size limits
-				const parts = this.mergeDocsTogether(doc, docs, i);
+				const parts = this.mergeDocsTogether(tldrawDrawingEntity, tldrawDrawingEntities, i);
 				updates.push(Buffer.concat(parts));
 			}
 		}
@@ -189,10 +200,19 @@ export class YMongodb {
 	 * Get all document updates for a specific document.
 	 */
 	private async getMongoUpdates(docName: string, opts = {}): Promise<Buffer[]> {
+		performance.mark('getMongoUpdates');
+
 		const uniqueKey = KeyFactory.createForUpdate(docName);
-		const docs = await this.getMongoBulkData(uniqueKey, opts);
+		const tldrawDrawingEntities = await this.getMongoBulkData(uniqueKey, opts);
+
+		const buffer = this.convertMongoUpdates(tldrawDrawingEntities);
+
+		performance.measure('tldraw:YMongodb:getMongoUpdates', {
+			start: 'getMongoUpdates',
+			detail: { doc_name: docName, loaded_tldraw_entities_total: tldrawDrawingEntities.length },
+		});
 
-		return this.convertMongoUpdates(docs);
+		return buffer;
 	}
 
 	private async writeStateVector(docName: string, sv: Uint8Array, clock: number): Promise<void> {
@@ -247,20 +267,23 @@ export class YMongodb {
 		return clock + 1;
 	}
 
-	private isSameClock(doc1: TldrawDrawing, doc2: TldrawDrawing): boolean {
-		return doc1.clock === doc2.clock;
+	private isSameClock(tldrawDrawingEntity1: TldrawDrawing, tldrawDrawingEntity2: TldrawDrawing): boolean {
+		return tldrawDrawingEntity1.clock === tldrawDrawingEntity2.clock;
 	}
 
-	private checkIfPartIsNextPartAfterCurrent(part: TldrawDrawing, currentPartId: number | undefined): void {
-		if (part.part === undefined || currentPartId !== part.part - 1) {
+	private checkIfPartIsNextPartAfterCurrent(
+		tldrawDrawingEntity: TldrawDrawing,
+		currentPartId: number | undefined
+	): void {
+		if (tldrawDrawingEntity.part === undefined || currentPartId !== tldrawDrawingEntity.part - 1) {
 			throw new Error('Could not merge updates together because a part is missing');
 		}
 	}
 
-	private extractClock(updates: TldrawDrawing[]): number {
-		if (updates.length === 0 || updates[0].clock == null) {
+	private extractClock(tldrawDrawingEntities: TldrawDrawing[]): number {
+		if (tldrawDrawingEntities.length === 0 || tldrawDrawingEntities[0].clock == null) {
 			return -1;
 		}
-		return updates[0].clock;
+		return tldrawDrawingEntities[0].clock;
 	}
 }

apps/server/src/modules/tldraw/service/tldraw.ws.service.spec.ts

@@ -1,29 +1,29 @@
-import { Test } from '@nestjs/testing';
+import { createMock, DeepMocked } from '@golevelup/ts-jest';
+import { MongoMemoryDatabaseModule } from '@infra/database';
+import { HttpService } from '@nestjs/axios';
 import { INestApplication } from '@nestjs/common';
-import WebSocket from 'ws';
+import { ConfigModule } from '@nestjs/config';
 import { WsAdapter } from '@nestjs/platform-ws';
-import { TextEncoder } from 'util';
-import * as Yjs from 'yjs';
-import * as SyncProtocols from 'y-protocols/sync';
-import * as AwarenessProtocol from 'y-protocols/awareness';
-import * as Ioredis from 'ioredis';
-import { encoding } from 'lib0';
-import { TldrawWsFactory } from '@shared/testing/factory/tldraw.ws.factory';
-import { HttpService } from '@nestjs/axios';
+import { Test } from '@nestjs/testing';
 import { WebSocketReadyStateEnum } from '@shared/testing';
-import { createMock, DeepMocked } from '@golevelup/ts-jest';
-import { ConfigModule } from '@nestjs/config';
+import { TldrawWsFactory } from '@shared/testing/factory/tldraw.ws.factory';
 import { createConfigModuleOptions } from '@src/config';
-import { MongoMemoryDatabaseModule } from '@infra/database';
 import { DomainErrorHandler } from '@src/core';
-import { TldrawRedisFactory, TldrawRedisService } from '../redis';
+import * as Ioredis from 'ioredis';
+import { encoding } from 'lib0';
+import { TextEncoder } from 'util';
+import WebSocket from 'ws';
+import * as AwarenessProtocol from 'y-protocols/awareness';
+import * as SyncProtocols from 'y-protocols/sync';
+import * as Yjs from 'yjs';
+import { TldrawWsService } from '.';
 import { TldrawWs } from '../controller';
+import { WsSharedDocDo } from '../domain';
 import { TldrawDrawing } from '../entities';
+import { MetricsService } from '../metrics';
+import { TldrawRedisFactory, TldrawRedisService } from '../redis';
 import { TldrawBoardRepo, TldrawRepo, YMongodb } from '../repo';
 import { TestConnection, tldrawTestConfig } from '../testing';
-import { WsSharedDocDo } from '../domain';
-import { MetricsService } from '../metrics';
-import { TldrawWsService } from '.';
 
 jest.mock('yjs', () => {
 	const moduleMock: unknown = {