log inbound activity duration

3 files changed, 35 insertions, 4 deletions

diff --git a/packages/backend/migration/1731909785724-activity-log-timing.js b/packages/backend/migration/1731909785724-activity-log-timing.js
new file mode 100644
index 0000000000..8b72fb8972
--- /dev/null
+++ b/packages/backend/migration/1731909785724-activity-log-timing.js
@@ -0,0 +1,19 @@
+/*
+ * SPDX-FileCopyrightText: hazelnoot and other Sharkey contributors
+ * SPDX-License-Identifier: AGPL-3.0-only
+ */
+
+export class ActivityLogTiming1731909785724 {
+    name = 'ActivityLogTiming1731909785724'
+
+    async up(queryRunner) {
+        await queryRunner.query(`ALTER TABLE "activity_log" ADD "duration" double precision NOT NULL DEFAULT '0'`);
+        await queryRunner.query(`ALTER TABLE "activity_log" ALTER COLUMN "result" DROP NOT NULL`);
+    }
+
+    async down(queryRunner) {
+				await queryRunner.query(`UPDATE "activity_log" SET "result" = 'not processed' WHERE "result" IS NULL`);
+        await queryRunner.query(`ALTER TABLE "activity_log" ALTER COLUMN "result" SET NOT NULL`);
+        await queryRunner.query(`ALTER TABLE "activity_log" DROP COLUMN "duration"`);
+		}
+}
diff --git a/packages/backend/src/models/SkActivityLog.ts b/packages/backend/src/models/SkActivityLog.ts
index f23c0708b9..f2d11487dd 100644
--- a/packages/backend/src/models/SkActivityLog.ts
+++ b/packages/backend/src/models/SkActivityLog.ts
@@ -20,6 +20,12 @@ export class SkActivityLog {
 	@Column('timestamptz')
 	public at: Date;
 
+	/**
+	 * Processing duration in milliseconds
+	 */
+	@Column('double precision', { default: 0 })
+	public duration = 0;
+
 	@Column({
 		type: 'text',
 		name: 'key_id',
@@ -36,8 +42,8 @@ export class SkActivityLog {
 	@Column('boolean')
 	public accepted: boolean;
 
-	@Column('text')
-	public result: string;
+	@Column('text', { nullable: true })
+	public result: string | null = null;
 
 	@Column('jsonb')
 	// https://github.com/typeorm/typeorm/issues/8559
diff --git a/packages/backend/src/queue/processors/InboxProcessorService.ts b/packages/backend/src/queue/processors/InboxProcessorService.ts
index d40104ee9b..242c67359b 100644
--- a/packages/backend/src/queue/processors/InboxProcessorService.ts
+++ b/packages/backend/src/queue/processors/InboxProcessorService.ts
@@ -98,9 +98,16 @@ export class InboxProcessorService implements OnApplicationShutdown {
 		}
 
 		try {
+			const startTime = process.hrtime.bigint();
 			const result = await this._process(job, log);
+			const endTime = process.hrtime.bigint();
+
+			// Truncate nanoseconds to microseconds, then scale to milliseconds.
+			// 123,456,789 ns -> 123,456 us -> 123.456 ms
+			const duration = Number((endTime - startTime) / 1000n) / 1000;
 
 			log.accepted = result.startsWith('ok');
+			log.duration = duration;
 			log.result = result;
 
 			return result;
@@ -249,7 +256,7 @@ export class InboxProcessorService implements OnApplicationShutdown {
 			delete activity.id;
 		}
 
-		// Attach log to verified user
+		// Record verified user in log
 		if (log) {
 			log.verified = true;
 			log.authUser = authUser.user;
@@ -361,7 +368,6 @@ export class InboxProcessorService implements OnApplicationShutdown {
 			at: new Date(),
 			verified: false,
 			accepted: false,
-			result: 'not processed',
 			activity,
 			keyId,
 			host,