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,