From b65b4ecadcd364adeede80f71a2f106671fb434f Mon Sep 17 00:00:00 2001 From: Hazelnoot Date: Thu, 14 Nov 2024 12:11:37 -0500 Subject: [PATCH 01/13] add inbound activity logger for debugging --- .config/ci.yml | 23 ++-- .config/cypress-devcontainer.yml | 15 +++ .config/docker_example.yml | 15 +++ .config/example.yml | 15 +++ .../1731565470048-add-activity-log.js | 28 +++++ packages/backend/src/boot/common.ts | 2 + packages/backend/src/config.ts | 18 ++++ .../src/daemons/ActivityLogCleanupService.ts | 64 +++++++++++ packages/backend/src/daemons/DaemonModule.ts | 3 + packages/backend/src/di-symbols.ts | 3 + .../backend/src/models/RepositoryModule.ts | 20 +++- .../backend/src/models/SkActivityContext.ts | 24 +++++ packages/backend/src/models/SkActivityLog.ts | 82 ++++++++++++++ packages/backend/src/models/_.ts | 6 ++ packages/backend/src/postgres.ts | 4 + .../queue/processors/InboxProcessorService.ts | 102 ++++++++++++++++++ 16 files changed, 414 insertions(+), 10 deletions(-) create mode 100644 packages/backend/migration/1731565470048-add-activity-log.js create mode 100644 packages/backend/src/daemons/ActivityLogCleanupService.ts create mode 100644 packages/backend/src/models/SkActivityContext.ts create mode 100644 packages/backend/src/models/SkActivityLog.ts diff --git a/.config/ci.yml b/.config/ci.yml index 311a98d8fb..790c4704fa 100644 --- a/.config/ci.yml +++ b/.config/ci.yml @@ -263,12 +263,17 @@ checkActivityPubGetSignature: false # # default: false # disableQueryTruncation: false -# Log settings -# logging: -# sql: -# # Outputs query parameters during SQL execution to the log. -# # default: false -# enableQueryParamLogging: false -# # Disable query truncation. If set to true, the full text of the query will be output to the log. -# # default: false -# disableQueryTruncation: false +# Settings for the activity logger, which records inbound activities to the database. +# Disabled by default due to the large volume of data it saves. +#activityLogging: + # Log activities to the database (default: false) + #enabled: false + + # Save the activity before processing, then update later with the results. + # This has the advantage of capturing activities that cause a hard-crash, but doubles the number of queries used. + # Default: false + #preSave: false + + # How long to save each log entry before deleting it. + # Default: 2592000000 (1 week) + #maxAge: 2592000000 diff --git a/.config/cypress-devcontainer.yml b/.config/cypress-devcontainer.yml index 391bc9998c..9a6f9769e6 100644 --- a/.config/cypress-devcontainer.yml +++ b/.config/cypress-devcontainer.yml @@ -272,3 +272,18 @@ allowedPrivateNetworks: [ # # Disable query truncation. If set to true, the full text of the query will be output to the log. # # default: false # disableQueryTruncation: false + +# Settings for the activity logger, which records inbound activities to the database. +# Disabled by default due to the large volume of data it saves. +#activityLogging: + # Log activities to the database (default: false) + #enabled: false + + # Save the activity before processing, then update later with the results. + # This has the advantage of capturing activities that cause a hard-crash, but doubles the number of queries used. + # Default: false + #preSave: false + + # How long to save each log entry before deleting it. + # Default: 2592000000 (1 week) + #maxAge: 2592000000 diff --git a/.config/docker_example.yml b/.config/docker_example.yml index 1e03e902bf..2d088547ba 100644 --- a/.config/docker_example.yml +++ b/.config/docker_example.yml @@ -345,3 +345,18 @@ checkActivityPubGetSignature: false # # Disable query truncation. If set to true, the full text of the query will be output to the log. # # default: false # disableQueryTruncation: false + +# Settings for the activity logger, which records inbound activities to the database. +# Disabled by default due to the large volume of data it saves. +#activityLogging: + # Log activities to the database (default: false) + #enabled: false + + # Save the activity before processing, then update later with the results. + # This has the advantage of capturing activities that cause a hard-crash, but doubles the number of queries used. + # Default: false + #preSave: false + + # How long to save each log entry before deleting it. + # Default: 2592000000 (1 week) + #maxAge: 2592000000 diff --git a/.config/example.yml b/.config/example.yml index 7d4cd0c659..7bca8642be 100644 --- a/.config/example.yml +++ b/.config/example.yml @@ -383,3 +383,18 @@ checkActivityPubGetSignature: false # # Disable query truncation. If set to true, the full text of the query will be output to the log. # # default: false # disableQueryTruncation: false + +# Settings for the activity logger, which records inbound activities to the database. +# Disabled by default due to the large volume of data it saves. +#activityLogging: + # Log activities to the database (default: false) + #enabled: false + + # Save the activity before processing, then update later with the results. + # This has the advantage of capturing activities that cause a hard-crash, but doubles the number of queries used. + # Default: false + #preSave: false + + # How long to save each log entry before deleting it. + # Default: 2592000000 (1 week) + #maxAge: 2592000000 diff --git a/packages/backend/migration/1731565470048-add-activity-log.js b/packages/backend/migration/1731565470048-add-activity-log.js new file mode 100644 index 0000000000..19c6b336af --- /dev/null +++ b/packages/backend/migration/1731565470048-add-activity-log.js @@ -0,0 +1,28 @@ +/* + * SPDX-FileCopyrightText: hazelnoot and other Sharkey contributors + * SPDX-License-Identifier: AGPL-3.0-only + */ + +export class AddActivityLog1731565470048 { + name = 'AddActivityLog1731565470048' + + async up(queryRunner) { + await queryRunner.query(`CREATE TABLE "activity_context" ("md5" text NOT NULL, "json" jsonb NOT NULL, CONSTRAINT "PK_activity_context" PRIMARY KEY ("md5"))`); + await queryRunner.query(`CREATE INDEX "IDK_activity_context_md5" ON "activity_context" ("md5") `); + await queryRunner.query(`CREATE TABLE "activity_log" ("id" character varying(32) NOT NULL, "at" TIMESTAMP WITH TIME ZONE NOT NULL, "key_id" text NOT NULL, "host" text NOT NULL, "verified" boolean NOT NULL, "accepted" boolean NOT NULL, "result" text NOT NULL, "activity" jsonb NOT NULL, "context_hash" text, "auth_user_id" character varying(32), CONSTRAINT "PK_activity_log" PRIMARY KEY ("id"))`); + await queryRunner.query(`CREATE INDEX "IDX_activity_log_at" ON "activity_log" ("at") `); + await queryRunner.query(`CREATE INDEX "IDX_activity_log_host" ON "activity_log" ("host") `); + await queryRunner.query(`ALTER TABLE "activity_log" ADD CONSTRAINT "FK_activity_log_context_hash" FOREIGN KEY ("context_hash") REFERENCES "activity_context"("md5") ON DELETE CASCADE ON UPDATE NO ACTION`); + await queryRunner.query(`ALTER TABLE "activity_log" ADD CONSTRAINT "FK_activity_log_auth_user_id" FOREIGN KEY ("auth_user_id") REFERENCES "user"("id") ON DELETE CASCADE ON UPDATE NO ACTION`); + } + + async down(queryRunner) { + await queryRunner.query(`ALTER TABLE "activity_log" DROP CONSTRAINT "FK_activity_log_auth_user_id"`); + await queryRunner.query(`ALTER TABLE "activity_log" DROP CONSTRAINT "FK_activity_log_context_hash"`); + await queryRunner.query(`DROP INDEX "public"."IDX_activity_log_host"`); + await queryRunner.query(`DROP INDEX "public"."IDX_activity_log_at"`); + await queryRunner.query(`DROP TABLE "activity_log"`); + await queryRunner.query(`DROP INDEX "public"."IDK_activity_context_md5"`); + await queryRunner.query(`DROP TABLE "activity_context"`); + } +} diff --git a/packages/backend/src/boot/common.ts b/packages/backend/src/boot/common.ts index ad59a55688..3584e71153 100644 --- a/packages/backend/src/boot/common.ts +++ b/packages/backend/src/boot/common.ts @@ -13,6 +13,7 @@ import { ServerStatsService } from '@/daemons/ServerStatsService.js'; import { ServerService } from '@/server/ServerService.js'; import { MainModule } from '@/MainModule.js'; import { envOption } from '@/env.js'; +import { ActivityLogCleanupService } from '@/daemons/ActivityLogCleanupService.js'; export async function server() { const app = await NestFactory.createApplicationContext(MainModule, { @@ -28,6 +29,7 @@ export async function server() { if (!envOption.noDaemons) { app.get(QueueStatsService).start(); app.get(ServerStatsService).start(); + app.get(ActivityLogCleanupService).start(); } return app; diff --git a/packages/backend/src/config.ts b/packages/backend/src/config.ts index d35befdc2b..24f3c472a4 100644 --- a/packages/backend/src/config.ts +++ b/packages/backend/src/config.ts @@ -129,6 +129,12 @@ type Source = { enableQueryParamLogging? : boolean, } } + + activityLogging?: { + enabled?: boolean; + preSave?: boolean; + maxAge?: number; + }; }; export type Config = { @@ -238,6 +244,12 @@ export type Config = { pidFile: string; filePermissionBits?: string; + + activityLogging: { + enabled: boolean; + preSave: boolean; + maxAge: number; + }; }; export type FulltextSearchProvider = 'sqlLike' | 'sqlPgroonga' | 'meilisearch'; @@ -380,6 +392,11 @@ export function loadConfig(): Config { pidFile: config.pidFile, filePermissionBits: config.filePermissionBits, logging: config.logging, + activityLogging: { + enabled: config.activityLogging?.enabled ?? false, + preSave: config.activityLogging?.preSave ?? false, + maxAge: config.activityLogging?.maxAge ?? (1000 * 60 * 60 * 24 * 30), + }, }; } @@ -531,4 +548,5 @@ function applyEnvOverrides(config: Source) { _apply_top(['import', ['downloadTimeout', 'maxFileSize']]); _apply_top([['signToActivityPubGet', 'checkActivityPubGetSignature', 'setupPassword']]); _apply_top(['logging', 'sql', ['disableQueryTruncation', 'enableQueryParamLogging']]); + _apply_top(['activityLogging', ['enabled', 'preSave', 'maxAge']]); } diff --git a/packages/backend/src/daemons/ActivityLogCleanupService.ts b/packages/backend/src/daemons/ActivityLogCleanupService.ts new file mode 100644 index 0000000000..e2ffef3c5f --- /dev/null +++ b/packages/backend/src/daemons/ActivityLogCleanupService.ts @@ -0,0 +1,64 @@ +/* + * SPDX-FileCopyrightText: hazelnoot and other Sharkey contributors + * SPDX-License-Identifier: AGPL-3.0-only + */ + +import { Inject, Injectable, type OnApplicationShutdown } from '@nestjs/common'; +import { LessThan } from 'typeorm'; +import { DI } from '@/di-symbols.js'; +import type { Config } from '@/config.js'; +import { bindThis } from '@/decorators.js'; +import type { ActivityLogsRepository } from '@/models/_.js'; + +// 10 minutes +export const scanInterval = 1000 * 60 * 10; + +@Injectable() +export class ActivityLogCleanupService implements OnApplicationShutdown { + private scanTimer: NodeJS.Timeout | null = null; + + constructor( + @Inject(DI.config) + private readonly config: Config, + + @Inject(DI.activityLogsRepository) + private readonly activityLogsRepository: ActivityLogsRepository, + ) {} + + @bindThis + public async start(): Promise { + // Just in case start() gets called multiple times. + this.dispose(); + + // Prune at startup, in case the server was rebooted during the interval. + // noinspection ES6MissingAwait + this.tick(); + + // Prune on a regular interval for the lifetime of the server. + this.scanTimer = setInterval(this.tick, scanInterval); + } + + @bindThis + private async tick(): Promise { + // This is the date in UTC of the oldest log to KEEP + const oldestAllowed = new Date(Date.now() - this.config.activityLogging.maxAge); + + // Delete all logs older than the threshold. + await this.activityLogsRepository.delete({ + at: LessThan(oldestAllowed), + }); + } + + @bindThis + public onApplicationShutdown(): void { + this.dispose(); + } + + @bindThis + public dispose(): void { + if (this.scanTimer) { + clearInterval(this.scanTimer); + this.scanTimer = null; + } + } +} diff --git a/packages/backend/src/daemons/DaemonModule.ts b/packages/backend/src/daemons/DaemonModule.ts index a67907e6dd..12f890b3eb 100644 --- a/packages/backend/src/daemons/DaemonModule.ts +++ b/packages/backend/src/daemons/DaemonModule.ts @@ -8,6 +8,7 @@ import { CoreModule } from '@/core/CoreModule.js'; import { GlobalModule } from '@/GlobalModule.js'; import { QueueStatsService } from './QueueStatsService.js'; import { ServerStatsService } from './ServerStatsService.js'; +import { ActivityLogCleanupService } from './ActivityLogCleanupService.js'; @Module({ imports: [ @@ -17,10 +18,12 @@ import { ServerStatsService } from './ServerStatsService.js'; providers: [ QueueStatsService, ServerStatsService, + ActivityLogCleanupService, ], exports: [ QueueStatsService, ServerStatsService, + ActivityLogCleanupService, ], }) export class DaemonModule {} diff --git a/packages/backend/src/di-symbols.ts b/packages/backend/src/di-symbols.ts index 296cc4815b..e591024fbd 100644 --- a/packages/backend/src/di-symbols.ts +++ b/packages/backend/src/di-symbols.ts @@ -22,6 +22,9 @@ export const DI = { appsRepository: Symbol('appsRepository'), avatarDecorationsRepository: Symbol('avatarDecorationsRepository'), latestNotesRepository: Symbol('latestNotesRepository'), + activityContextRepository: Symbol('activityContextRepository'), + contextUsagesRepository: Symbol('contextUsagesRepository'), + activityLogsRepository: Symbol('activityLogsRepository'), noteFavoritesRepository: Symbol('noteFavoritesRepository'), noteThreadMutingsRepository: Symbol('noteThreadMutingsRepository'), noteReactionsRepository: Symbol('noteReactionsRepository'), diff --git a/packages/backend/src/models/RepositoryModule.ts b/packages/backend/src/models/RepositoryModule.ts index 3a1158a42a..37c4e4fd92 100644 --- a/packages/backend/src/models/RepositoryModule.ts +++ b/packages/backend/src/models/RepositoryModule.ts @@ -80,7 +80,9 @@ import { MiUserPublickey, MiUserSecurityKey, MiWebhook, - NoteEdit + NoteEdit, + SkActivityContext, + SkActivityLog, } from './_.js'; import type { DataSource } from 'typeorm'; @@ -126,6 +128,18 @@ const $latestNotesRepository: Provider = { inject: [DI.db], }; +const $activityContextRepository: Provider = { + provide: DI.activityContextRepository, + useFactory: (db: DataSource) => db.getRepository(SkActivityContext).extend(miRepository as MiRepository), + inject: [DI.db], +}; + +const $activityLogsRepository: Provider = { + provide: DI.activityLogsRepository, + useFactory: (db: DataSource) => db.getRepository(SkActivityLog).extend(miRepository as MiRepository), + inject: [DI.db], +}; + const $noteFavoritesRepository: Provider = { provide: DI.noteFavoritesRepository, useFactory: (db: DataSource) => db.getRepository(MiNoteFavorite).extend(miRepository as MiRepository), @@ -526,6 +540,8 @@ const $noteScheduleRepository: Provider = { $appsRepository, $avatarDecorationsRepository, $latestNotesRepository, + $activityContextRepository, + $activityLogsRepository, $noteFavoritesRepository, $noteThreadMutingsRepository, $noteReactionsRepository, @@ -600,6 +616,8 @@ const $noteScheduleRepository: Provider = { $appsRepository, $avatarDecorationsRepository, $latestNotesRepository, + $activityContextRepository, + $activityLogsRepository, $noteFavoritesRepository, $noteThreadMutingsRepository, $noteReactionsRepository, diff --git a/packages/backend/src/models/SkActivityContext.ts b/packages/backend/src/models/SkActivityContext.ts new file mode 100644 index 0000000000..9fdd0a9525 --- /dev/null +++ b/packages/backend/src/models/SkActivityContext.ts @@ -0,0 +1,24 @@ +/* + * SPDX-FileCopyrightText: hazelnoot and other Sharkey contributors + * SPDX-License-Identifier: AGPL-3.0-only + */ + +import { Column, PrimaryColumn, Entity, Index } from 'typeorm'; + +@Entity('activity_context') +export class SkActivityContext { + @PrimaryColumn('text') + @Index() + public md5: string; + + @Column('jsonb') + // https://github.com/typeorm/typeorm/issues/8559 + // eslint-disable-next-line @typescript-eslint/no-explicit-any + public json: any; + + constructor(data?: Partial) { + if (data) { + Object.assign(this, data); + } + } +} diff --git a/packages/backend/src/models/SkActivityLog.ts b/packages/backend/src/models/SkActivityLog.ts new file mode 100644 index 0000000000..229c333588 --- /dev/null +++ b/packages/backend/src/models/SkActivityLog.ts @@ -0,0 +1,82 @@ +/* + * SPDX-FileCopyrightText: hazelnoot and other Sharkey contributors + * SPDX-License-Identifier: AGPL-3.0-only + */ + +import { Column, Entity, Index, JoinColumn, ManyToOne, PrimaryColumn } from 'typeorm'; +import { SkActivityContext } from '@/models/SkActivityContext.js'; +import { MiUser } from '@/models/_.js'; +import { id } from './util/id.js'; + +@Entity('activity_log') +export class SkActivityLog { + @PrimaryColumn(id()) + public id: string; + + @Index() + @Column('timestamptz') + public at: Date; + + @Column({ + type: 'text', + name: 'key_id', + }) + public keyId: string; + + @Index() + @Column('text') + public host: string; + + @Column('boolean') + public verified: boolean; + + @Column('boolean') + public accepted: boolean; + + @Column('text') + public result: string; + + @Column('jsonb') + // https://github.com/typeorm/typeorm/issues/8559 + // eslint-disable-next-line @typescript-eslint/no-explicit-any + public activity: any; + + @Column({ + type: 'text', + name: 'context_hash', + nullable: true, + }) + public contextHash: string | null; + + @ManyToOne(() => SkActivityContext, { + onDelete: 'CASCADE', + nullable: true, + }) + @JoinColumn({ + name: 'context_hash', + }) + public context: SkActivityContext | null; + + @Column({ + type: 'varchar' as const, + length: 32, + name: 'auth_user_id', + nullable: true, + }) + public authUserId: string | null; + + @ManyToOne(() => MiUser, { + onDelete: 'CASCADE', + nullable: true, + }) + @JoinColumn({ + name: 'auth_user_id', + }) + public authUser: MiUser | null; + + constructor(data?: Partial) { + if (data) { + Object.assign(this, data); + } + } +} diff --git a/packages/backend/src/models/_.ts b/packages/backend/src/models/_.ts index 9a4ebfc90f..aeb6133d70 100644 --- a/packages/backend/src/models/_.ts +++ b/packages/backend/src/models/_.ts @@ -82,6 +82,8 @@ import { NoteEdit } from '@/models/NoteEdit.js'; import { MiBubbleGameRecord } from '@/models/BubbleGameRecord.js'; import { MiReversiGame } from '@/models/ReversiGame.js'; import { MiNoteSchedule } from '@/models/NoteSchedule.js'; +import { SkActivityLog } from '@/models/SkActivityLog.js'; +import { SkActivityContext } from './SkActivityContext.js'; import type { QueryDeepPartialEntity } from 'typeorm/query-builder/QueryPartialEntity.js'; export interface MiRepository { @@ -129,6 +131,8 @@ export const miRepository = { export { SkLatestNote, + SkActivityContext, + SkActivityLog, MiAbuseUserReport, MiAbuseReportNotificationRecipient, MiAccessToken, @@ -229,6 +233,8 @@ export type HashtagsRepository = Repository & MiRepository export type InstancesRepository = Repository & MiRepository; export type MetasRepository = Repository & MiRepository; export type LatestNotesRepository = Repository & MiRepository; +export type ActivityContextRepository = Repository & MiRepository; +export type ActivityLogsRepository = Repository & MiRepository; export type ModerationLogsRepository = Repository & MiRepository; export type MutingsRepository = Repository & MiRepository; export type RenoteMutingsRepository = Repository & MiRepository; diff --git a/packages/backend/src/postgres.ts b/packages/backend/src/postgres.ts index 98405052c6..658830ffcb 100644 --- a/packages/backend/src/postgres.ts +++ b/packages/backend/src/postgres.ts @@ -85,6 +85,8 @@ import { Config } from '@/config.js'; import MisskeyLogger from '@/logger.js'; import { bindThis } from '@/decorators.js'; import { SkLatestNote } from '@/models/LatestNote.js'; +import { SkActivityContext } from '@/models/SkActivityContext.js'; +import { SkActivityLog } from '@/models/SkActivityLog.js'; pg.types.setTypeParser(20, Number); @@ -171,6 +173,8 @@ class MyCustomLogger implements Logger { export const entities = [ SkLatestNote, + SkActivityContext, + SkActivityLog, MiAnnouncement, MiAnnouncementRead, MiMeta, diff --git a/packages/backend/src/queue/processors/InboxProcessorService.ts b/packages/backend/src/queue/processors/InboxProcessorService.ts index 87d4bf52fa..d40104ee9b 100644 --- a/packages/backend/src/queue/processors/InboxProcessorService.ts +++ b/packages/backend/src/queue/processors/InboxProcessorService.ts @@ -4,6 +4,7 @@ */ import { URL } from 'node:url'; +import { createHash } from 'crypto'; import { Inject, Injectable, OnApplicationShutdown } from '@nestjs/common'; import httpSignature from '@peertube/http-signature'; import * as Bull from 'bullmq'; @@ -29,6 +30,11 @@ import { CollapsedQueue } from '@/misc/collapsed-queue.js'; import { MiNote } from '@/models/Note.js'; import { MiMeta } from '@/models/Meta.js'; import { DI } from '@/di-symbols.js'; +import { IdService } from '@/core/IdService.js'; +import { JsonValue } from '@/misc/json-value.js'; +import { SkActivityLog, SkActivityContext } from '@/models/_.js'; +import type { ActivityLogsRepository, ActivityContextRepository } from '@/models/_.js'; +import type { Config } from '@/config.js'; import { QueueLoggerService } from '../QueueLoggerService.js'; import type { InboxJobData } from '../types.js'; @@ -46,6 +52,9 @@ export class InboxProcessorService implements OnApplicationShutdown { @Inject(DI.meta) private meta: MiMeta, + @Inject(DI.config) + private config: Config, + private utilityService: UtilityService, private apInboxService: ApInboxService, private federatedInstanceService: FederatedInstanceService, @@ -57,6 +66,13 @@ export class InboxProcessorService implements OnApplicationShutdown { private apRequestChart: ApRequestChart, private federationChart: FederationChart, private queueLoggerService: QueueLoggerService, + private idService: IdService, + + @Inject(DI.activityContextRepository) + private activityContextRepository: ActivityContextRepository, + + @Inject(DI.activityLogsRepository) + private activityLogsRepository: ActivityLogsRepository, ) { this.logger = this.queueLoggerService.logger.createSubLogger('inbox'); this.updateInstanceQueue = new CollapsedQueue(process.env.NODE_ENV !== 'test' ? 60 * 1000 * 5 : 0, this.collapseUpdateInstanceJobs, this.performUpdateInstance); @@ -64,6 +80,42 @@ export class InboxProcessorService implements OnApplicationShutdown { @bindThis public async process(job: Bull.Job): Promise { + if (this.config.activityLogging.enabled) { + return await this._processLogged(job); + } else { + return await this._process(job); + } + } + + private async _processLogged(job: Bull.Job): Promise { + const payload = job.data.activity; + const keyId = job.data.signature.keyId; + const log = this.createLog(payload, keyId); + + // Pre-save the activity in case it leads to a hard-crash. + if (this.config.activityLogging.preSave) { + await this.recordLog(log); + } + + try { + const result = await this._process(job, log); + + log.accepted = result.startsWith('ok'); + log.result = result; + + return result; + } catch (err) { + log.accepted = false; + log.result = String(err); + + throw err; + } finally { + // Save or finalize asynchronously + this.recordLog(log).catch(err => this.logger.error('Failed to record AP activity:', err)); + } + } + + private async _process(job: Bull.Job, log?: SkActivityLog): Promise { const signature = job.data.signature; // HTTP-signature let activity = job.data.activity; @@ -197,6 +249,13 @@ export class InboxProcessorService implements OnApplicationShutdown { delete activity.id; } + // Attach log to verified user + if (log) { + log.verified = true; + log.authUser = authUser.user; + log.authUserId = authUser.user.id; + } + this.apRequestChart.inbox(); this.federationChart.inbox(authUser.user.host); @@ -292,4 +351,47 @@ export class InboxProcessorService implements OnApplicationShutdown { async onApplicationShutdown(signal?: string) { await this.dispose(); } + + private createLog(payload: IActivity, keyId: string): SkActivityLog { + const activity = Object.assign({}, payload, { '@context': undefined }) as unknown as JsonValue; + const host = this.utilityService.extractDbHost(keyId); + + const log = new SkActivityLog({ + id: this.idService.gen(), + at: new Date(), + verified: false, + accepted: false, + result: 'not processed', + activity, + keyId, + host, + }); + + const context = payload['@context']; + if (context) { + const md5 = createHash('md5').update(JSON.stringify(context)).digest('base64'); + log.contextHash = md5; + log.context = new SkActivityContext({ + md5, + json: context, + }); + } + + return log; + } + + private async recordLog(log: SkActivityLog): Promise { + if (log.context) { + // https://stackoverflow.com/a/47064558 + await this.activityContextRepository + .createQueryBuilder('context_body') + .insert() + .into(SkActivityContext) + .values(log.context) + .orIgnore('md5') + .execute(); + } + + await this.activityLogsRepository.upsert(log, ['id']); + } } From 561f46b8d4a159fe6f2317a112ca7f0464ef74cc Mon Sep 17 00:00:00 2001 From: Hazelnoot Date: Thu, 14 Nov 2024 15:03:58 -0500 Subject: [PATCH 02/13] add logging for ActivityLogCleanupService --- .../src/daemons/ActivityLogCleanupService.ts | 13 +++++++++++-- 1 file changed, 11 insertions(+), 2 deletions(-) diff --git a/packages/backend/src/daemons/ActivityLogCleanupService.ts b/packages/backend/src/daemons/ActivityLogCleanupService.ts index e2ffef3c5f..bf5ddec05d 100644 --- a/packages/backend/src/daemons/ActivityLogCleanupService.ts +++ b/packages/backend/src/daemons/ActivityLogCleanupService.ts @@ -9,12 +9,15 @@ import { DI } from '@/di-symbols.js'; import type { Config } from '@/config.js'; import { bindThis } from '@/decorators.js'; import type { ActivityLogsRepository } from '@/models/_.js'; +import { LoggerService } from '@/core/LoggerService.js'; +import Logger from '@/logger.js'; // 10 minutes export const scanInterval = 1000 * 60 * 10; @Injectable() export class ActivityLogCleanupService implements OnApplicationShutdown { + private readonly logger: Logger; private scanTimer: NodeJS.Timeout | null = null; constructor( @@ -23,7 +26,11 @@ export class ActivityLogCleanupService implements OnApplicationShutdown { @Inject(DI.activityLogsRepository) private readonly activityLogsRepository: ActivityLogsRepository, - ) {} + + loggerService: LoggerService, + ) { + this.logger = loggerService.getLogger('activity-log-cleanup'); + } @bindThis public async start(): Promise { @@ -44,9 +51,11 @@ export class ActivityLogCleanupService implements OnApplicationShutdown { const oldestAllowed = new Date(Date.now() - this.config.activityLogging.maxAge); // Delete all logs older than the threshold. - await this.activityLogsRepository.delete({ + const { affected } = await this.activityLogsRepository.delete({ at: LessThan(oldestAllowed), }); + + this.logger.info(`Activity Log cleanup complete; removed ${affected ?? 0} expired logs.`); } @bindThis From 07cd01ec34fc61f43bc87db943e53f531386b76f Mon Sep 17 00:00:00 2001 From: Hazelnoot Date: Mon, 18 Nov 2024 01:16:12 -0500 Subject: [PATCH 03/13] add missing constraint names to `SkActivityLog` and `SkActivityContext` --- .../1731910422761-rename-activity-log-indexes.js | 16 ++++++++++++++++ packages/backend/src/models/SkActivityContext.ts | 7 ++++--- packages/backend/src/models/SkActivityLog.ts | 14 +++++++++----- 3 files changed, 29 insertions(+), 8 deletions(-) create mode 100644 packages/backend/migration/1731910422761-rename-activity-log-indexes.js diff --git a/packages/backend/migration/1731910422761-rename-activity-log-indexes.js b/packages/backend/migration/1731910422761-rename-activity-log-indexes.js new file mode 100644 index 0000000000..82d5a796e9 --- /dev/null +++ b/packages/backend/migration/1731910422761-rename-activity-log-indexes.js @@ -0,0 +1,16 @@ +/* + * SPDX-FileCopyrightText: hazelnoot and other Sharkey contributors + * SPDX-License-Identifier: AGPL-3.0-only + */ + +export class RenameActivityLogIndexes1731910422761 { + name = 'RenameActivityLogIndexes1731910422761' + + async up(queryRunner) { + await queryRunner.query(`DROP INDEX "public"."IDK_activity_context_md5"`); + } + + async down(queryRunner) { + await queryRunner.query(`CREATE INDEX "IDK_activity_context_md5" ON "activity_context" ("md5") `); + } +} diff --git a/packages/backend/src/models/SkActivityContext.ts b/packages/backend/src/models/SkActivityContext.ts index 9fdd0a9525..349c3e7113 100644 --- a/packages/backend/src/models/SkActivityContext.ts +++ b/packages/backend/src/models/SkActivityContext.ts @@ -3,12 +3,13 @@ * SPDX-License-Identifier: AGPL-3.0-only */ -import { Column, PrimaryColumn, Entity, Index } from 'typeorm'; +import { Column, PrimaryColumn, Entity } from 'typeorm'; @Entity('activity_context') export class SkActivityContext { - @PrimaryColumn('text') - @Index() + @PrimaryColumn('text', { + primaryKeyConstraintName: 'PK_activity_context', + }) public md5: string; @Column('jsonb') diff --git a/packages/backend/src/models/SkActivityLog.ts b/packages/backend/src/models/SkActivityLog.ts index 229c333588..f23c0708b9 100644 --- a/packages/backend/src/models/SkActivityLog.ts +++ b/packages/backend/src/models/SkActivityLog.ts @@ -10,10 +10,13 @@ import { id } from './util/id.js'; @Entity('activity_log') export class SkActivityLog { - @PrimaryColumn(id()) + @PrimaryColumn({ + ...id(), + primaryKeyConstraintName: 'PK_activity_log', + }) public id: string; - @Index() + @Index('IDX_activity_log_at') @Column('timestamptz') public at: Date; @@ -23,7 +26,7 @@ export class SkActivityLog { }) public keyId: string; - @Index() + @Index('IDX_activity_log_host') @Column('text') public host: string; @@ -54,12 +57,12 @@ export class SkActivityLog { }) @JoinColumn({ name: 'context_hash', + foreignKeyConstraintName: 'FK_activity_log_context_hash', }) public context: SkActivityContext | null; @Column({ - type: 'varchar' as const, - length: 32, + ...id(), name: 'auth_user_id', nullable: true, }) @@ -71,6 +74,7 @@ export class SkActivityLog { }) @JoinColumn({ name: 'auth_user_id', + foreignKeyConstraintName: 'FK_activity_log_auth_user_id', }) public authUser: MiUser | null; From e35e92beb9ccdabf5692107966c2cf9c2e91c4dd Mon Sep 17 00:00:00 2001 From: Hazelnoot Date: Mon, 18 Nov 2024 01:18:45 -0500 Subject: [PATCH 04/13] log inbound activity duration --- .../1731909785724-activity-log-timing.js | 19 +++++++++++++++++++ packages/backend/src/models/SkActivityLog.ts | 10 ++++++++-- .../queue/processors/InboxProcessorService.ts | 10 ++++++++-- 3 files changed, 35 insertions(+), 4 deletions(-) create mode 100644 packages/backend/migration/1731909785724-activity-log-timing.js 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, From 871c63b48bd958d301f709260dbb01273462da57 Mon Sep 17 00:00:00 2001 From: Hazelnoot Date: Mon, 18 Nov 2024 01:24:23 -0500 Subject: [PATCH 05/13] print warning when activity processing exceeds 10 seonds --- packages/backend/src/queue/processors/InboxProcessorService.ts | 3 +++ 1 file changed, 3 insertions(+) diff --git a/packages/backend/src/queue/processors/InboxProcessorService.ts b/packages/backend/src/queue/processors/InboxProcessorService.ts index 242c67359b..1dcce0ffc2 100644 --- a/packages/backend/src/queue/processors/InboxProcessorService.ts +++ b/packages/backend/src/queue/processors/InboxProcessorService.ts @@ -105,6 +105,9 @@ export class InboxProcessorService implements OnApplicationShutdown { // 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; + if (duration > 10000) { + this.logger.warn(`Activity ${JSON.stringify(payload.id)} by "${keyId}" took ${(duration / 1000).toFixed(1)} seconds to complete`); + } log.accepted = result.startsWith('ok'); log.duration = duration; From 15148b787527cf62cbd569985b16f788e8a52546 Mon Sep 17 00:00:00 2001 From: Hazelnoot Date: Mon, 18 Nov 2024 08:03:15 -0500 Subject: [PATCH 06/13] fix activity duration calculation * Ensure that timing is recorded even if an exception is thrown. * Round to the correct decimal place. --- .../queue/processors/InboxProcessorService.ts | 27 ++++++++++++------- 1 file changed, 17 insertions(+), 10 deletions(-) diff --git a/packages/backend/src/queue/processors/InboxProcessorService.ts b/packages/backend/src/queue/processors/InboxProcessorService.ts index 1dcce0ffc2..5ed124a049 100644 --- a/packages/backend/src/queue/processors/InboxProcessorService.ts +++ b/packages/backend/src/queue/processors/InboxProcessorService.ts @@ -88,6 +88,7 @@ export class InboxProcessorService implements OnApplicationShutdown { } private async _processLogged(job: Bull.Job): Promise { + const startTime = process.hrtime.bigint(); const payload = job.data.activity; const keyId = job.data.signature.keyId; const log = this.createLog(payload, keyId); @@ -98,19 +99,9 @@ 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; - if (duration > 10000) { - this.logger.warn(`Activity ${JSON.stringify(payload.id)} by "${keyId}" took ${(duration / 1000).toFixed(1)} seconds to complete`); - } log.accepted = result.startsWith('ok'); - log.duration = duration; log.result = result; return result; @@ -120,6 +111,22 @@ export class InboxProcessorService implements OnApplicationShutdown { throw err; } finally { + // Calculate the activity processing time with correct rounding and decimals. + // 1. Truncate nanoseconds to microseconds + // 2. Scale to 1/10 millisecond ticks. + // 3. Round to nearest tick. + // 4. Sale to milliseconds + // Example: 123,456,789 ns -> 123,456 us -> 12,345.6 ticks -> 12,346 ticks -> 123.46 ms + const endTime = process.hrtime.bigint(); + const duration = Math.round(Number((endTime - startTime) / 1000n) / 10) / 100; + log.duration = duration; + + // Activities should time out after roughly 5 seconds. + // A runtime longer than 10 seconds could indicate a problem or attack. + if (duration > 10000) { + this.logger.warn(`Activity ${JSON.stringify(payload.id)} by "${keyId}" took ${(duration / 1000).toFixed(1)} seconds to complete`); + } + // Save or finalize asynchronously this.recordLog(log).catch(err => this.logger.error('Failed to record AP activity:', err)); } From 0979392925aa05e7b86307e17d6dc7e2940038fc Mon Sep 17 00:00:00 2001 From: Hazelnoot Date: Mon, 18 Nov 2024 08:06:30 -0500 Subject: [PATCH 07/13] make `activity_log.duration` nullable --- ...35047347-nullable-activity-log-duration.js | 20 +++++++++++++++++++ packages/backend/src/models/SkActivityLog.ts | 4 ++-- 2 files changed, 22 insertions(+), 2 deletions(-) create mode 100644 packages/backend/migration/1731935047347-nullable-activity-log-duration.js diff --git a/packages/backend/migration/1731935047347-nullable-activity-log-duration.js b/packages/backend/migration/1731935047347-nullable-activity-log-duration.js new file mode 100644 index 0000000000..2acbd2bca5 --- /dev/null +++ b/packages/backend/migration/1731935047347-nullable-activity-log-duration.js @@ -0,0 +1,20 @@ +/* + * SPDX-FileCopyrightText: hazelnoot and other Sharkey contributors + * SPDX-License-Identifier: AGPL-3.0-only + */ + +export class NullableActivityLogDuration1731935047347 { + name = 'NullableActivityLogDuration1731935047347' + + async up(queryRunner) { + await queryRunner.query(`ALTER TABLE "activity_log" ALTER COLUMN "duration" DROP NOT NULL`); + await queryRunner.query(`ALTER TABLE "activity_log" ALTER COLUMN "duration" DROP DEFAULT`); + await queryRunner.query(`UPDATE "activity_log" SET "duration" = NULL WHERE "duration" = 0`); + } + + async down(queryRunner) { + await queryRunner.query(`UPDATE "activity_log" SET "duration" = 0 WHERE "duration" IS NULL`); + await queryRunner.query(`ALTER TABLE "activity_log" ALTER COLUMN "duration" SET DEFAULT '0'`); + await queryRunner.query(`ALTER TABLE "activity_log" ALTER COLUMN "duration" SET NOT NULL`); + } +} diff --git a/packages/backend/src/models/SkActivityLog.ts b/packages/backend/src/models/SkActivityLog.ts index f2d11487dd..6e462eccef 100644 --- a/packages/backend/src/models/SkActivityLog.ts +++ b/packages/backend/src/models/SkActivityLog.ts @@ -23,8 +23,8 @@ export class SkActivityLog { /** * Processing duration in milliseconds */ - @Column('double precision', { default: 0 }) - public duration = 0; + @Column('double precision', { nullable: true }) + public duration: number | null = null; @Column({ type: 'text', From cc2edae7abff566ba968a6027018826099400320 Mon Sep 17 00:00:00 2001 From: Hazelnoot Date: Mon, 9 Dec 2024 10:00:25 -0500 Subject: [PATCH 08/13] rename activity_log and activity_context to ap_inbox_log and ap_context --- ...460-rename_activity_log_to_ap_inbox_log.js | 32 +++++++++++++++ packages/backend/src/boot/common.ts | 4 +- ...eanupService.ts => ApLogCleanupService.ts} | 10 ++--- packages/backend/src/daemons/DaemonModule.ts | 6 +-- packages/backend/src/di-symbols.ts | 5 +-- .../backend/src/models/RepositoryModule.ts | 24 ++++++------ .../{SkActivityContext.ts => SkApContext.ts} | 8 ++-- .../{SkActivityLog.ts => SkApInboxLog.ts} | 39 +++++++++++++------ packages/backend/src/models/_.ts | 12 +++--- packages/backend/src/postgres.ts | 8 ++-- .../queue/processors/InboxProcessorService.ts | 30 +++++++------- 11 files changed, 113 insertions(+), 65 deletions(-) create mode 100644 packages/backend/migration/1733756280460-rename_activity_log_to_ap_inbox_log.js rename packages/backend/src/daemons/{ActivityLogCleanupService.ts => ApLogCleanupService.ts} (85%) rename packages/backend/src/models/{SkActivityContext.ts => SkApContext.ts} (72%) rename packages/backend/src/models/{SkActivityLog.ts => SkApInboxLog.ts} (64%) diff --git a/packages/backend/migration/1733756280460-rename_activity_log_to_ap_inbox_log.js b/packages/backend/migration/1733756280460-rename_activity_log_to_ap_inbox_log.js new file mode 100644 index 0000000000..ad25135188 --- /dev/null +++ b/packages/backend/migration/1733756280460-rename_activity_log_to_ap_inbox_log.js @@ -0,0 +1,32 @@ +/* + * SPDX-FileCopyrightText: hazelnoot and other Sharkey contributors + * SPDX-License-Identifier: AGPL-3.0-only + */ + +export class RenameActivityLogToApInboxLog1733756280460 { + name = 'RenameActivityLogToApInboxLog1733756280460' + + async up(queryRunner) { + await queryRunner.query(`ALTER INDEX "IDX_activity_log_at" RENAME TO "IDX_ap_inbox_log_at"`); + await queryRunner.query(`ALTER INDEX "IDX_activity_log_host" RENAME TO "IDX_ap_inbox_log_host"`); + await queryRunner.query(`ALTER TABLE "activity_log" RENAME CONSTRAINT "PK_activity_log" TO "PK_ap_inbox_log"`); + await queryRunner.query(`ALTER TABLE "activity_log" RENAME CONSTRAINT "FK_activity_log_context_hash" TO "FK_ap_inbox_log_context_hash"`); + await queryRunner.query(`ALTER TABLE "activity_log" RENAME CONSTRAINT "FK_activity_log_auth_user_id" TO "FK_ap_inbox_log_auth_user_id"`); + await queryRunner.query(`ALTER TABLE "activity_log" RENAME TO "ap_inbox_log"`); + + await queryRunner.query(`ALTER TABLE "activity_context" RENAME CONSTRAINT "PK_activity_context" TO "PK_ap_context"`); + await queryRunner.query(`ALTER TABLE "activity_context" RENAME TO "ap_context"`); + } + + async down(queryRunner) { + await queryRunner.query(`ALTER TABLE "ap_context" RENAME TO "activity_context"`); + await queryRunner.query(`ALTER TABLE "activity_context" RENAME CONSTRAINT "PK_ap_context" TO "PK_activity_context"`); + + await queryRunner.query(`ALTER TABLE "ap_inbox_log" RENAME TO "activity_log"`); + await queryRunner.query(`ALTER TABLE "activity_log" RENAME CONSTRAINT "FK_ap_inbox_log_auth_user_id" TO "FK_activity_log_auth_user_id"`); + await queryRunner.query(`ALTER TABLE "activity_log" RENAME CONSTRAINT "FK_ap_inbox_log_context_hash" TO "FK_activity_log_context_hash"`); + await queryRunner.query(`ALTER TABLE "activity_log" RENAME CONSTRAINT "PK_ap_inbox_log" TO "PK_activity_log"`); + await queryRunner.query(`ALTER INDEX "IDX_ap_inbox_log_host" RENAME TO "IDX_activity_log_host"`); + await queryRunner.query(`ALTER INDEX "IDX_ap_inbox_log_at" RENAME TO "IDX_activity_log_at"`); + } +} diff --git a/packages/backend/src/boot/common.ts b/packages/backend/src/boot/common.ts index 3584e71153..2f97980e9a 100644 --- a/packages/backend/src/boot/common.ts +++ b/packages/backend/src/boot/common.ts @@ -13,7 +13,7 @@ import { ServerStatsService } from '@/daemons/ServerStatsService.js'; import { ServerService } from '@/server/ServerService.js'; import { MainModule } from '@/MainModule.js'; import { envOption } from '@/env.js'; -import { ActivityLogCleanupService } from '@/daemons/ActivityLogCleanupService.js'; +import { ApLogCleanupService } from '@/daemons/ApLogCleanupService.js'; export async function server() { const app = await NestFactory.createApplicationContext(MainModule, { @@ -29,7 +29,7 @@ export async function server() { if (!envOption.noDaemons) { app.get(QueueStatsService).start(); app.get(ServerStatsService).start(); - app.get(ActivityLogCleanupService).start(); + app.get(ApLogCleanupService).start(); } return app; diff --git a/packages/backend/src/daemons/ActivityLogCleanupService.ts b/packages/backend/src/daemons/ApLogCleanupService.ts similarity index 85% rename from packages/backend/src/daemons/ActivityLogCleanupService.ts rename to packages/backend/src/daemons/ApLogCleanupService.ts index bf5ddec05d..261c6e3517 100644 --- a/packages/backend/src/daemons/ActivityLogCleanupService.ts +++ b/packages/backend/src/daemons/ApLogCleanupService.ts @@ -8,7 +8,7 @@ import { LessThan } from 'typeorm'; import { DI } from '@/di-symbols.js'; import type { Config } from '@/config.js'; import { bindThis } from '@/decorators.js'; -import type { ActivityLogsRepository } from '@/models/_.js'; +import type { ApInboxLogsRepository } from '@/models/_.js'; import { LoggerService } from '@/core/LoggerService.js'; import Logger from '@/logger.js'; @@ -16,7 +16,7 @@ import Logger from '@/logger.js'; export const scanInterval = 1000 * 60 * 10; @Injectable() -export class ActivityLogCleanupService implements OnApplicationShutdown { +export class ApLogCleanupService implements OnApplicationShutdown { private readonly logger: Logger; private scanTimer: NodeJS.Timeout | null = null; @@ -24,8 +24,8 @@ export class ActivityLogCleanupService implements OnApplicationShutdown { @Inject(DI.config) private readonly config: Config, - @Inject(DI.activityLogsRepository) - private readonly activityLogsRepository: ActivityLogsRepository, + @Inject(DI.apInboxLogsRepository) + private readonly apInboxLogsRepository: ApInboxLogsRepository, loggerService: LoggerService, ) { @@ -51,7 +51,7 @@ export class ActivityLogCleanupService implements OnApplicationShutdown { const oldestAllowed = new Date(Date.now() - this.config.activityLogging.maxAge); // Delete all logs older than the threshold. - const { affected } = await this.activityLogsRepository.delete({ + const { affected } = await this.apInboxLogsRepository.delete({ at: LessThan(oldestAllowed), }); diff --git a/packages/backend/src/daemons/DaemonModule.ts b/packages/backend/src/daemons/DaemonModule.ts index 12f890b3eb..ea71875f19 100644 --- a/packages/backend/src/daemons/DaemonModule.ts +++ b/packages/backend/src/daemons/DaemonModule.ts @@ -8,7 +8,7 @@ import { CoreModule } from '@/core/CoreModule.js'; import { GlobalModule } from '@/GlobalModule.js'; import { QueueStatsService } from './QueueStatsService.js'; import { ServerStatsService } from './ServerStatsService.js'; -import { ActivityLogCleanupService } from './ActivityLogCleanupService.js'; +import { ApLogCleanupService } from './ApLogCleanupService.js'; @Module({ imports: [ @@ -18,12 +18,12 @@ import { ActivityLogCleanupService } from './ActivityLogCleanupService.js'; providers: [ QueueStatsService, ServerStatsService, - ActivityLogCleanupService, + ApLogCleanupService, ], exports: [ QueueStatsService, ServerStatsService, - ActivityLogCleanupService, + ApLogCleanupService, ], }) export class DaemonModule {} diff --git a/packages/backend/src/di-symbols.ts b/packages/backend/src/di-symbols.ts index e591024fbd..6b53d38fb7 100644 --- a/packages/backend/src/di-symbols.ts +++ b/packages/backend/src/di-symbols.ts @@ -22,9 +22,8 @@ export const DI = { appsRepository: Symbol('appsRepository'), avatarDecorationsRepository: Symbol('avatarDecorationsRepository'), latestNotesRepository: Symbol('latestNotesRepository'), - activityContextRepository: Symbol('activityContextRepository'), - contextUsagesRepository: Symbol('contextUsagesRepository'), - activityLogsRepository: Symbol('activityLogsRepository'), + apContextsRepository: Symbol('apContextsRepository'), + apInboxLogsRepository: Symbol('apInboxLogsRepository'), noteFavoritesRepository: Symbol('noteFavoritesRepository'), noteThreadMutingsRepository: Symbol('noteThreadMutingsRepository'), noteReactionsRepository: Symbol('noteReactionsRepository'), diff --git a/packages/backend/src/models/RepositoryModule.ts b/packages/backend/src/models/RepositoryModule.ts index 37c4e4fd92..dd4ba1c0e4 100644 --- a/packages/backend/src/models/RepositoryModule.ts +++ b/packages/backend/src/models/RepositoryModule.ts @@ -81,8 +81,8 @@ import { MiUserSecurityKey, MiWebhook, NoteEdit, - SkActivityContext, - SkActivityLog, + SkApContext, + SkApInboxLog, } from './_.js'; import type { DataSource } from 'typeorm'; @@ -128,15 +128,15 @@ const $latestNotesRepository: Provider = { inject: [DI.db], }; -const $activityContextRepository: Provider = { - provide: DI.activityContextRepository, - useFactory: (db: DataSource) => db.getRepository(SkActivityContext).extend(miRepository as MiRepository), +const $apContextRepository: Provider = { + provide: DI.apContextsRepository, + useFactory: (db: DataSource) => db.getRepository(SkApContext).extend(miRepository as MiRepository), inject: [DI.db], }; -const $activityLogsRepository: Provider = { - provide: DI.activityLogsRepository, - useFactory: (db: DataSource) => db.getRepository(SkActivityLog).extend(miRepository as MiRepository), +const $apInboxLogsRepository: Provider = { + provide: DI.apInboxLogsRepository, + useFactory: (db: DataSource) => db.getRepository(SkApInboxLog).extend(miRepository as MiRepository), inject: [DI.db], }; @@ -540,8 +540,8 @@ const $noteScheduleRepository: Provider = { $appsRepository, $avatarDecorationsRepository, $latestNotesRepository, - $activityContextRepository, - $activityLogsRepository, + $apContextRepository, + $apInboxLogsRepository, $noteFavoritesRepository, $noteThreadMutingsRepository, $noteReactionsRepository, @@ -616,8 +616,8 @@ const $noteScheduleRepository: Provider = { $appsRepository, $avatarDecorationsRepository, $latestNotesRepository, - $activityContextRepository, - $activityLogsRepository, + $apContextRepository, + $apInboxLogsRepository, $noteFavoritesRepository, $noteThreadMutingsRepository, $noteReactionsRepository, diff --git a/packages/backend/src/models/SkActivityContext.ts b/packages/backend/src/models/SkApContext.ts similarity index 72% rename from packages/backend/src/models/SkActivityContext.ts rename to packages/backend/src/models/SkApContext.ts index 349c3e7113..ff4c6d6fbf 100644 --- a/packages/backend/src/models/SkActivityContext.ts +++ b/packages/backend/src/models/SkApContext.ts @@ -5,10 +5,10 @@ import { Column, PrimaryColumn, Entity } from 'typeorm'; -@Entity('activity_context') -export class SkActivityContext { +@Entity('ap_context') +export class SkApContext { @PrimaryColumn('text', { - primaryKeyConstraintName: 'PK_activity_context', + primaryKeyConstraintName: 'PK_ap_context', }) public md5: string; @@ -17,7 +17,7 @@ export class SkActivityContext { // eslint-disable-next-line @typescript-eslint/no-explicit-any public json: any; - constructor(data?: Partial) { + constructor(data?: Partial) { if (data) { Object.assign(this, data); } diff --git a/packages/backend/src/models/SkActivityLog.ts b/packages/backend/src/models/SkApInboxLog.ts similarity index 64% rename from packages/backend/src/models/SkActivityLog.ts rename to packages/backend/src/models/SkApInboxLog.ts index 6e462eccef..867094405c 100644 --- a/packages/backend/src/models/SkActivityLog.ts +++ b/packages/backend/src/models/SkApInboxLog.ts @@ -4,19 +4,22 @@ */ import { Column, Entity, Index, JoinColumn, ManyToOne, PrimaryColumn } from 'typeorm'; -import { SkActivityContext } from '@/models/SkActivityContext.js'; +import { SkApContext } from '@/models/SkApContext.js'; import { MiUser } from '@/models/_.js'; import { id } from './util/id.js'; -@Entity('activity_log') -export class SkActivityLog { +/** + * Records activities received in the inbox + */ +@Entity('ap_inbox_log') +export class SkApInboxLog { @PrimaryColumn({ ...id(), - primaryKeyConstraintName: 'PK_activity_log', + primaryKeyConstraintName: 'PK_ap_inbox_log', }) public id: string; - @Index('IDX_activity_log_at') + @Index('IDX_ap_inbox_log_at') @Column('timestamptz') public at: Date; @@ -26,13 +29,21 @@ export class SkActivityLog { @Column('double precision', { nullable: true }) public duration: number | null = null; + /** + * Key ID that was used to sign this request. + * Untrusted unless verified is true. + */ @Column({ type: 'text', name: 'key_id', }) public keyId: string; - @Index('IDX_activity_log_host') + /** + * Instance that the activity was sent from. + * Untrusted unless verified is true. + */ + @Index('IDX_ap_inbox_log_host') @Column('text') public host: string; @@ -57,16 +68,19 @@ export class SkActivityLog { }) public contextHash: string | null; - @ManyToOne(() => SkActivityContext, { + @ManyToOne(() => SkApContext, { onDelete: 'CASCADE', nullable: true, }) @JoinColumn({ name: 'context_hash', - foreignKeyConstraintName: 'FK_activity_log_context_hash', + foreignKeyConstraintName: 'FK_ap_inbox_log_context_hash', }) - public context: SkActivityContext | null; + public context: SkApContext | null; + /** + * ID of the user who signed this request. + */ @Column({ ...id(), name: 'auth_user_id', @@ -74,17 +88,20 @@ export class SkActivityLog { }) public authUserId: string | null; + /** + * User who signed this request. + */ @ManyToOne(() => MiUser, { onDelete: 'CASCADE', nullable: true, }) @JoinColumn({ name: 'auth_user_id', - foreignKeyConstraintName: 'FK_activity_log_auth_user_id', + foreignKeyConstraintName: 'FK_ap_inbox_log_auth_user_id', }) public authUser: MiUser | null; - constructor(data?: Partial) { + constructor(data?: Partial) { if (data) { Object.assign(this, data); } diff --git a/packages/backend/src/models/_.ts b/packages/backend/src/models/_.ts index aeb6133d70..dabcf89d2c 100644 --- a/packages/backend/src/models/_.ts +++ b/packages/backend/src/models/_.ts @@ -82,8 +82,8 @@ import { NoteEdit } from '@/models/NoteEdit.js'; import { MiBubbleGameRecord } from '@/models/BubbleGameRecord.js'; import { MiReversiGame } from '@/models/ReversiGame.js'; import { MiNoteSchedule } from '@/models/NoteSchedule.js'; -import { SkActivityLog } from '@/models/SkActivityLog.js'; -import { SkActivityContext } from './SkActivityContext.js'; +import { SkApInboxLog } from '@/models/SkApInboxLog.js'; +import { SkApContext } from '@/models/SkApContext.js'; import type { QueryDeepPartialEntity } from 'typeorm/query-builder/QueryPartialEntity.js'; export interface MiRepository { @@ -131,8 +131,8 @@ export const miRepository = { export { SkLatestNote, - SkActivityContext, - SkActivityLog, + SkApContext, + SkApInboxLog, MiAbuseUserReport, MiAbuseReportNotificationRecipient, MiAccessToken, @@ -233,8 +233,8 @@ export type HashtagsRepository = Repository & MiRepository export type InstancesRepository = Repository & MiRepository; export type MetasRepository = Repository & MiRepository; export type LatestNotesRepository = Repository & MiRepository; -export type ActivityContextRepository = Repository & MiRepository; -export type ActivityLogsRepository = Repository & MiRepository; +export type ApContextsRepository = Repository & MiRepository; +export type ApInboxLogsRepository = Repository & MiRepository; export type ModerationLogsRepository = Repository & MiRepository; export type MutingsRepository = Repository & MiRepository; export type RenoteMutingsRepository = Repository & MiRepository; diff --git a/packages/backend/src/postgres.ts b/packages/backend/src/postgres.ts index 658830ffcb..9437ac936a 100644 --- a/packages/backend/src/postgres.ts +++ b/packages/backend/src/postgres.ts @@ -85,8 +85,8 @@ import { Config } from '@/config.js'; import MisskeyLogger from '@/logger.js'; import { bindThis } from '@/decorators.js'; import { SkLatestNote } from '@/models/LatestNote.js'; -import { SkActivityContext } from '@/models/SkActivityContext.js'; -import { SkActivityLog } from '@/models/SkActivityLog.js'; +import { SkApContext } from '@/models/SkApContext.js'; +import { SkApInboxLog } from '@/models/SkApInboxLog.js'; pg.types.setTypeParser(20, Number); @@ -173,8 +173,8 @@ class MyCustomLogger implements Logger { export const entities = [ SkLatestNote, - SkActivityContext, - SkActivityLog, + SkApContext, + SkApInboxLog, MiAnnouncement, MiAnnouncementRead, MiMeta, diff --git a/packages/backend/src/queue/processors/InboxProcessorService.ts b/packages/backend/src/queue/processors/InboxProcessorService.ts index 5ed124a049..4182f3e090 100644 --- a/packages/backend/src/queue/processors/InboxProcessorService.ts +++ b/packages/backend/src/queue/processors/InboxProcessorService.ts @@ -32,8 +32,8 @@ import { MiMeta } from '@/models/Meta.js'; import { DI } from '@/di-symbols.js'; import { IdService } from '@/core/IdService.js'; import { JsonValue } from '@/misc/json-value.js'; -import { SkActivityLog, SkActivityContext } from '@/models/_.js'; -import type { ActivityLogsRepository, ActivityContextRepository } from '@/models/_.js'; +import { SkApInboxLog, SkApContext } from '@/models/_.js'; +import type { ApInboxLogsRepository, ApContextsRepository } from '@/models/_.js'; import type { Config } from '@/config.js'; import { QueueLoggerService } from '../QueueLoggerService.js'; import type { InboxJobData } from '../types.js'; @@ -68,11 +68,11 @@ export class InboxProcessorService implements OnApplicationShutdown { private queueLoggerService: QueueLoggerService, private idService: IdService, - @Inject(DI.activityContextRepository) - private activityContextRepository: ActivityContextRepository, + @Inject(DI.apContextsRepository) + private apContextsRepository: ApContextsRepository, - @Inject(DI.activityLogsRepository) - private activityLogsRepository: ActivityLogsRepository, + @Inject(DI.apInboxLogsRepository) + private apInboxLogsRepository: ApInboxLogsRepository, ) { this.logger = this.queueLoggerService.logger.createSubLogger('inbox'); this.updateInstanceQueue = new CollapsedQueue(process.env.NODE_ENV !== 'test' ? 60 * 1000 * 5 : 0, this.collapseUpdateInstanceJobs, this.performUpdateInstance); @@ -132,7 +132,7 @@ export class InboxProcessorService implements OnApplicationShutdown { } } - private async _process(job: Bull.Job, log?: SkActivityLog): Promise { + private async _process(job: Bull.Job, log?: SkApInboxLog): Promise { const signature = job.data.signature; // HTTP-signature let activity = job.data.activity; @@ -369,11 +369,11 @@ export class InboxProcessorService implements OnApplicationShutdown { await this.dispose(); } - private createLog(payload: IActivity, keyId: string): SkActivityLog { + private createLog(payload: IActivity, keyId: string): SkApInboxLog { const activity = Object.assign({}, payload, { '@context': undefined }) as unknown as JsonValue; const host = this.utilityService.extractDbHost(keyId); - const log = new SkActivityLog({ + const log = new SkApInboxLog({ id: this.idService.gen(), at: new Date(), verified: false, @@ -387,7 +387,7 @@ export class InboxProcessorService implements OnApplicationShutdown { if (context) { const md5 = createHash('md5').update(JSON.stringify(context)).digest('base64'); log.contextHash = md5; - log.context = new SkActivityContext({ + log.context = new SkApContext({ md5, json: context, }); @@ -396,18 +396,18 @@ export class InboxProcessorService implements OnApplicationShutdown { return log; } - private async recordLog(log: SkActivityLog): Promise { + private async recordLog(log: SkApInboxLog): Promise { if (log.context) { // https://stackoverflow.com/a/47064558 - await this.activityContextRepository - .createQueryBuilder('context_body') + await this.apContextsRepository + .createQueryBuilder('activity_context') .insert() - .into(SkActivityContext) + .into(SkApContext) .values(log.context) .orIgnore('md5') .execute(); } - await this.activityLogsRepository.upsert(log, ['id']); + await this.apInboxLogsRepository.upsert(log, ['id']); } } From 81944b3bdf49cf95294adcefc265a568b921dee0 Mon Sep 17 00:00:00 2001 From: Hazelnoot Date: Thu, 30 Jan 2025 22:36:19 -0500 Subject: [PATCH 09/13] implement AP fetch logs --- .../1738293576355-create_ap_fetch_log.js | 19 ++ packages/backend/src/core/ApLogService.ts | 189 ++++++++++++++++++ packages/backend/src/core/CoreModule.ts | 6 + .../src/core/activitypub/ApResolverService.ts | 61 +++++- .../src/daemons/ApLogCleanupService.ts | 29 +-- packages/backend/src/di-symbols.ts | 1 + .../backend/src/models/RepositoryModule.ts | 9 + packages/backend/src/models/SkApFetchLog.ts | 89 +++++++++ packages/backend/src/models/_.ts | 3 + packages/backend/src/postgres.ts | 2 + .../queue/processors/InboxProcessorService.ts | 82 +------- 11 files changed, 395 insertions(+), 95 deletions(-) create mode 100644 packages/backend/migration/1738293576355-create_ap_fetch_log.js create mode 100644 packages/backend/src/core/ApLogService.ts create mode 100644 packages/backend/src/models/SkApFetchLog.ts diff --git a/packages/backend/migration/1738293576355-create_ap_fetch_log.js b/packages/backend/migration/1738293576355-create_ap_fetch_log.js new file mode 100644 index 0000000000..4371f50b4a --- /dev/null +++ b/packages/backend/migration/1738293576355-create_ap_fetch_log.js @@ -0,0 +1,19 @@ +export class CreateApFetchLog1738293576355 { + name = 'CreateApFetchLog1738293576355' + + async up(queryRunner) { + await queryRunner.query(`CREATE TABLE "ap_fetch_log" ("id" character varying(32) NOT NULL, "at" TIMESTAMP WITH TIME ZONE NOT NULL, "duration" double precision, "host" text NOT NULL, "request_uri" text NOT NULL, "object_uri" text, "accepted" boolean, "result" text, "object" jsonb, "context_hash" text, CONSTRAINT "PK_ap_fetch_log" PRIMARY KEY ("id"))`); + await queryRunner.query(`CREATE INDEX "IDX_ap_fetch_log_at" ON "ap_fetch_log" ("at") `); + await queryRunner.query(`CREATE INDEX "IDX_ap_fetch_log_host" ON "ap_fetch_log" ("host") `); + await queryRunner.query(`CREATE INDEX "IDX_ap_fetch_log_object_uri" ON "ap_fetch_log" ("object_uri") `); + await queryRunner.query(`ALTER TABLE "ap_fetch_log" ADD CONSTRAINT "FK_ap_fetch_log_context_hash" FOREIGN KEY ("context_hash") REFERENCES "ap_context"("md5") ON DELETE CASCADE ON UPDATE NO ACTION`); + } + + async down(queryRunner) { + await queryRunner.query(`ALTER TABLE "ap_fetch_log" DROP CONSTRAINT "FK_ap_fetch_log_context_hash"`); + await queryRunner.query(`DROP INDEX "public"."IDX_ap_fetch_log_object_uri"`); + await queryRunner.query(`DROP INDEX "public"."IDX_ap_fetch_log_host"`); + await queryRunner.query(`DROP INDEX "public"."IDX_ap_fetch_log_at"`); + await queryRunner.query(`DROP TABLE "ap_fetch_log"`); + } +} diff --git a/packages/backend/src/core/ApLogService.ts b/packages/backend/src/core/ApLogService.ts new file mode 100644 index 0000000000..362eba24be --- /dev/null +++ b/packages/backend/src/core/ApLogService.ts @@ -0,0 +1,189 @@ +/* + * SPDX-FileCopyrightText: hazelnoot and other Sharkey contributors + * SPDX-License-Identifier: AGPL-3.0-only + */ + +import { createHash } from 'crypto'; +import { Inject, Injectable } from '@nestjs/common'; +import { LessThan } from 'typeorm'; +import { DI } from '@/di-symbols.js'; +import { SkApFetchLog, SkApInboxLog, SkApContext } from '@/models/_.js'; +import type { ApContextsRepository, ApFetchLogsRepository, ApInboxLogsRepository } from '@/models/_.js'; +import type { Config } from '@/config.js'; +import { JsonValue } from '@/misc/json-value.js'; +import { UtilityService } from '@/core/UtilityService.js'; +import { IdService } from '@/core/IdService.js'; +import { IActivity, IObject } from './activitypub/type.js'; + +@Injectable() +export class ApLogService { + constructor( + @Inject(DI.config) + private readonly config: Config, + + @Inject(DI.apContextsRepository) + private apContextsRepository: ApContextsRepository, + + @Inject(DI.apInboxLogsRepository) + private readonly apInboxLogsRepository: ApInboxLogsRepository, + + @Inject(DI.apFetchLogsRepository) + private readonly apFetchLogsRepository: ApFetchLogsRepository, + + private readonly utilityService: UtilityService, + private readonly idService: IdService, + ) {} + + /** + * Creates an inbox log from an activity, and saves it if pre-save is enabled. + */ + public async createInboxLog(data: Partial & { + activity: IActivity, + keyId: string, + }): Promise { + const { object: activity, context, contextHash } = extractObjectContext(data.activity); + const host = this.utilityService.extractDbHost(data.keyId); + + const log = new SkApInboxLog({ + id: this.idService.gen(), + at: new Date(), + verified: false, + accepted: false, + host, + ...data, + activity, + context, + contextHash, + }); + + if (this.config.activityLogging.preSave) { + await this.saveInboxLog(log); + } + + return log; + } + + /** + * Saves or finalizes an inbox log. + */ + public async saveInboxLog(log: SkApInboxLog): Promise { + if (log.context) { + await this.saveContext(log.context); + } + + // Will be UPDATE with preSave, and INSERT without. + await this.apInboxLogsRepository.upsert(log, ['id']); + return log; + } + + /** + * Creates a fetch log from an activity, and saves it if pre-save is enabled. + */ + public async createFetchLog(data: Partial & { + requestUri: string + host: string, + }): Promise { + const log = new SkApFetchLog({ + id: this.idService.gen(), + at: new Date(), + accepted: false, + ...data, + }); + + if (this.config.activityLogging.preSave) { + await this.saveFetchLog(log); + } + + return log; + } + + /** + * Saves or finalizes a fetch log. + */ + public async saveFetchLog(log: SkApFetchLog): Promise { + if (log.context) { + await this.saveContext(log.context); + } + + // Will be UPDATE with preSave, and INSERT without. + await this.apFetchLogsRepository.upsert(log, ['id']); + return log; + } + + private async saveContext(context: SkApContext): Promise { + // https://stackoverflow.com/a/47064558 + await this.apContextsRepository + .createQueryBuilder('activity_context') + .insert() + .into(SkApContext) + .values(context) + .orIgnore('md5') + .execute(); + } + + /** + * Deletes all expired AP logs and garbage-collects the AP context cache. + * Returns the total number of deleted rows. + */ + public async deleteExpiredLogs(): Promise { + // This is the date in UTC of the oldest log to KEEP + const oldestAllowed = new Date(Date.now() - this.config.activityLogging.maxAge); + + // Delete all logs older than the threshold. + const inboxDeleted = await this.deleteExpiredInboxLogs(oldestAllowed); + const fetchDeleted = await this.deleteExpiredFetchLogs(oldestAllowed); + + return inboxDeleted + fetchDeleted; + } + + private async deleteExpiredInboxLogs(oldestAllowed: Date): Promise { + const { affected } = await this.apInboxLogsRepository.delete({ + at: LessThan(oldestAllowed), + }); + + return affected ?? 0; + } + + private async deleteExpiredFetchLogs(oldestAllowed: Date): Promise { + const { affected } = await this.apFetchLogsRepository.delete({ + at: LessThan(oldestAllowed), + }); + + return affected ?? 0; + } +} + +export function extractObjectContext(input: T) { + const object = Object.assign({}, input, { '@context': undefined }) as Omit; + const { context, contextHash } = parseContext(input['@context']); + + return { object, context, contextHash }; +} + +export function parseContext(input: JsonValue | undefined): { contextHash: string | null, context: SkApContext | null } { + // Empty contexts are excluded for easier querying + if (input == null) { + return { + contextHash: null, + context: null, + }; + } + + const contextHash = createHash('md5').update(JSON.stringify(input)).digest('base64'); + const context = new SkApContext({ + md5: contextHash, + json: input, + }); + return { contextHash, context }; +} + +export function calculateDurationSince(startTime: bigint): number { + // Calculate the processing time with correct rounding and decimals. + // 1. Truncate nanoseconds to microseconds + // 2. Scale to 1/10 millisecond ticks. + // 3. Round to nearest tick. + // 4. Sale to milliseconds + // Example: 123,456,789 ns -> 123,456 us -> 12,345.6 ticks -> 12,346 ticks -> 123.46 ms + const endTime = process.hrtime.bigint(); + return Math.round(Number((endTime - startTime) / 1000n) / 10) / 100; +} diff --git a/packages/backend/src/core/CoreModule.ts b/packages/backend/src/core/CoreModule.ts index 8c9f419c44..47be6967d7 100644 --- a/packages/backend/src/core/CoreModule.ts +++ b/packages/backend/src/core/CoreModule.ts @@ -157,6 +157,7 @@ import { QueueService } from './QueueService.js'; import { LoggerService } from './LoggerService.js'; import { SponsorsService } from './SponsorsService.js'; import type { Provider } from '@nestjs/common'; +import { ApLogService } from '@/core/ApLogService.js'; //#region 文字列ベースでのinjection用(循環参照対応のため) const $LoggerService: Provider = { provide: 'LoggerService', useExisting: LoggerService }; @@ -166,6 +167,7 @@ const $AccountMoveService: Provider = { provide: 'AccountMoveService', useExisti const $AccountUpdateService: Provider = { provide: 'AccountUpdateService', useExisting: AccountUpdateService }; const $AnnouncementService: Provider = { provide: 'AnnouncementService', useExisting: AnnouncementService }; const $AntennaService: Provider = { provide: 'AntennaService', useExisting: AntennaService }; +const $ApLogService: Provider = { provide: 'ApLogService', useExisting: ApLogService }; const $AppLockService: Provider = { provide: 'AppLockService', useExisting: AppLockService }; const $AchievementService: Provider = { provide: 'AchievementService', useExisting: AchievementService }; const $AvatarDecorationService: Provider = { provide: 'AvatarDecorationService', useExisting: AvatarDecorationService }; @@ -322,6 +324,7 @@ const $SponsorsService: Provider = { provide: 'SponsorsService', useExisting: Sp AccountUpdateService, AnnouncementService, AntennaService, + ApLogService, AppLockService, AchievementService, AvatarDecorationService, @@ -474,6 +477,7 @@ const $SponsorsService: Provider = { provide: 'SponsorsService', useExisting: Sp $AccountUpdateService, $AnnouncementService, $AntennaService, + $ApLogService, $AppLockService, $AchievementService, $AvatarDecorationService, @@ -627,6 +631,7 @@ const $SponsorsService: Provider = { provide: 'SponsorsService', useExisting: Sp AccountUpdateService, AnnouncementService, AntennaService, + ApLogService, AppLockService, AchievementService, AvatarDecorationService, @@ -778,6 +783,7 @@ const $SponsorsService: Provider = { provide: 'SponsorsService', useExisting: Sp $AccountUpdateService, $AnnouncementService, $AntennaService, + $ApLogService, $AppLockService, $AchievementService, $AvatarDecorationService, diff --git a/packages/backend/src/core/activitypub/ApResolverService.ts b/packages/backend/src/core/activitypub/ApResolverService.ts index a0c3a4846c..410803609c 100644 --- a/packages/backend/src/core/activitypub/ApResolverService.ts +++ b/packages/backend/src/core/activitypub/ApResolverService.ts @@ -7,7 +7,7 @@ import { Inject, Injectable } from '@nestjs/common'; import { IsNull, Not } from 'typeorm'; import type { MiLocalUser, MiRemoteUser } from '@/models/User.js'; import { InstanceActorService } from '@/core/InstanceActorService.js'; -import type { NotesRepository, PollsRepository, NoteReactionsRepository, UsersRepository, FollowRequestsRepository, MiMeta } from '@/models/_.js'; +import type { NotesRepository, PollsRepository, NoteReactionsRepository, UsersRepository, FollowRequestsRepository, MiMeta, SkApFetchLog } from '@/models/_.js'; import type { Config } from '@/config.js'; import { HttpRequestService } from '@/core/HttpRequestService.js'; import { DI } from '@/di-symbols.js'; @@ -17,7 +17,8 @@ import { LoggerService } from '@/core/LoggerService.js'; import type Logger from '@/logger.js'; import { fromTuple } from '@/misc/from-tuple.js'; import { IdentifiableError } from '@/misc/identifiable-error.js'; -import { isCollectionOrOrderedCollection } from './type.js'; +import { ApLogService, calculateDurationSince, extractObjectContext } from '@/core/ApLogService.js'; +import { getNullableApId, isCollectionOrOrderedCollection } from './type.js'; import { ApDbResolverService } from './ApDbResolverService.js'; import { ApRendererService } from './ApRendererService.js'; import { ApRequestService } from './ApRequestService.js'; @@ -43,6 +44,7 @@ export class Resolver { private apRendererService: ApRendererService, private apDbResolverService: ApDbResolverService, private loggerService: LoggerService, + private readonly apLogService: ApLogService, private recursionLimit = 256, ) { this.history = new Set(); @@ -81,6 +83,44 @@ export class Resolver { return value; } + const host = this.utilityService.extractDbHost(value); + if (this.config.activityLogging.enabled && !this.utilityService.isSelfHost(host)) { + return await this._resolveLogged(value, host); + } else { + return await this._resolve(value, host); + } + } + + private async _resolveLogged(requestUri: string, host: string): Promise { + const startTime = process.hrtime.bigint(); + + const log = await this.apLogService.createFetchLog({ + host: host, + requestUri, + }); + + try { + const result = await this._resolve(requestUri, host, log); + + log.accepted = true; + log.result = 'ok'; + + return result; + } catch (err) { + log.accepted = false; + log.result = String(err); + + throw err; + } finally { + log.duration = calculateDurationSince(startTime); + + // Save or finalize asynchronously + this.apLogService.saveFetchLog(log) + .catch(err => this.logger.error('Failed to record AP object fetch:', err)); + } + } + + private async _resolve(value: string, host: string, log?: SkApFetchLog): Promise { if (value.includes('#')) { // URLs with fragment parts cannot be resolved correctly because // the fragment part does not get transmitted over HTTP(S). @@ -98,7 +138,6 @@ export class Resolver { this.history.add(value); - const host = this.utilityService.extractDbHost(value); if (this.utilityService.isSelfHost(host)) { return await this.resolveLocal(value); } @@ -115,6 +154,20 @@ export class Resolver { ? await this.apRequestService.signedGet(value, this.user) as IObject : await this.httpRequestService.getActivityJson(value)) as IObject; + if (log) { + const { object: objectOnly, context, contextHash } = extractObjectContext(object); + const objectUri = getNullableApId(object); + + if (objectUri) { + log.objectUri = objectUri; + log.host = this.utilityService.extractDbHost(objectUri); + } + + log.object = objectOnly; + log.context = context; + log.contextHash = contextHash; + } + if ( Array.isArray(object['@context']) ? !(object['@context'] as unknown[]).includes('https://www.w3.org/ns/activitystreams') : @@ -232,6 +285,7 @@ export class ApResolverService { private apRendererService: ApRendererService, private apDbResolverService: ApDbResolverService, private loggerService: LoggerService, + private readonly apLogService: ApLogService, ) { } @@ -252,6 +306,7 @@ export class ApResolverService { this.apRendererService, this.apDbResolverService, this.loggerService, + this.apLogService, ); } } diff --git a/packages/backend/src/daemons/ApLogCleanupService.ts b/packages/backend/src/daemons/ApLogCleanupService.ts index 261c6e3517..2b6693e19e 100644 --- a/packages/backend/src/daemons/ApLogCleanupService.ts +++ b/packages/backend/src/daemons/ApLogCleanupService.ts @@ -3,14 +3,11 @@ * SPDX-License-Identifier: AGPL-3.0-only */ -import { Inject, Injectable, type OnApplicationShutdown } from '@nestjs/common'; -import { LessThan } from 'typeorm'; -import { DI } from '@/di-symbols.js'; -import type { Config } from '@/config.js'; +import { Injectable, type OnApplicationShutdown } from '@nestjs/common'; import { bindThis } from '@/decorators.js'; -import type { ApInboxLogsRepository } from '@/models/_.js'; import { LoggerService } from '@/core/LoggerService.js'; import Logger from '@/logger.js'; +import { ApLogService } from '@/core/ApLogService.js'; // 10 minutes export const scanInterval = 1000 * 60 * 10; @@ -21,12 +18,7 @@ export class ApLogCleanupService implements OnApplicationShutdown { private scanTimer: NodeJS.Timeout | null = null; constructor( - @Inject(DI.config) - private readonly config: Config, - - @Inject(DI.apInboxLogsRepository) - private readonly apInboxLogsRepository: ApInboxLogsRepository, - + private readonly apLogService: ApLogService, loggerService: LoggerService, ) { this.logger = loggerService.getLogger('activity-log-cleanup'); @@ -47,15 +39,12 @@ export class ApLogCleanupService implements OnApplicationShutdown { @bindThis private async tick(): Promise { - // This is the date in UTC of the oldest log to KEEP - const oldestAllowed = new Date(Date.now() - this.config.activityLogging.maxAge); - - // Delete all logs older than the threshold. - const { affected } = await this.apInboxLogsRepository.delete({ - at: LessThan(oldestAllowed), - }); - - this.logger.info(`Activity Log cleanup complete; removed ${affected ?? 0} expired logs.`); + try { + const affected = this.apLogService.deleteExpiredLogs(); + this.logger.info(`Activity Log cleanup complete; removed ${affected} expired logs.`); + } catch (err) { + this.logger.error('Activity Log cleanup failed:', err as Error); + } } @bindThis diff --git a/packages/backend/src/di-symbols.ts b/packages/backend/src/di-symbols.ts index 6b53d38fb7..9f4ef5e2e9 100644 --- a/packages/backend/src/di-symbols.ts +++ b/packages/backend/src/di-symbols.ts @@ -23,6 +23,7 @@ export const DI = { avatarDecorationsRepository: Symbol('avatarDecorationsRepository'), latestNotesRepository: Symbol('latestNotesRepository'), apContextsRepository: Symbol('apContextsRepository'), + apFetchLogsRepository: Symbol('apFetchLogsRepository'), apInboxLogsRepository: Symbol('apInboxLogsRepository'), noteFavoritesRepository: Symbol('noteFavoritesRepository'), noteThreadMutingsRepository: Symbol('noteThreadMutingsRepository'), diff --git a/packages/backend/src/models/RepositoryModule.ts b/packages/backend/src/models/RepositoryModule.ts index dd4ba1c0e4..78510ba588 100644 --- a/packages/backend/src/models/RepositoryModule.ts +++ b/packages/backend/src/models/RepositoryModule.ts @@ -82,6 +82,7 @@ import { MiWebhook, NoteEdit, SkApContext, + SkApFetchLog, SkApInboxLog, } from './_.js'; import type { DataSource } from 'typeorm'; @@ -134,6 +135,12 @@ const $apContextRepository: Provider = { inject: [DI.db], }; +const $apFetchLogsRepository: Provider = { + provide: DI.apFetchLogsRepository, + useFactory: (db: DataSource) => db.getRepository(SkApFetchLog).extend(miRepository as MiRepository), + inject: [DI.db], +}; + const $apInboxLogsRepository: Provider = { provide: DI.apInboxLogsRepository, useFactory: (db: DataSource) => db.getRepository(SkApInboxLog).extend(miRepository as MiRepository), @@ -541,6 +548,7 @@ const $noteScheduleRepository: Provider = { $avatarDecorationsRepository, $latestNotesRepository, $apContextRepository, + $apFetchLogsRepository, $apInboxLogsRepository, $noteFavoritesRepository, $noteThreadMutingsRepository, @@ -617,6 +625,7 @@ const $noteScheduleRepository: Provider = { $avatarDecorationsRepository, $latestNotesRepository, $apContextRepository, + $apFetchLogsRepository, $apInboxLogsRepository, $noteFavoritesRepository, $noteThreadMutingsRepository, diff --git a/packages/backend/src/models/SkApFetchLog.ts b/packages/backend/src/models/SkApFetchLog.ts new file mode 100644 index 0000000000..1e7d861b6c --- /dev/null +++ b/packages/backend/src/models/SkApFetchLog.ts @@ -0,0 +1,89 @@ +/* + * SPDX-FileCopyrightText: hazelnoot and other Sharkey contributors + * SPDX-License-Identifier: AGPL-3.0-only + */ + +import { Column, Index, JoinColumn, ManyToOne, PrimaryColumn, Entity } from 'typeorm'; +import { SkApContext } from '@/models/SkApContext.js'; +import { id } from './util/id.js'; + +/** + * Records objects fetched via AP + */ +@Entity('ap_fetch_log') +export class SkApFetchLog { + @PrimaryColumn({ + ...id(), + primaryKeyConstraintName: 'PK_ap_fetch_log', + }) + public id: string; + + @Index('IDX_ap_fetch_log_at') + @Column('timestamptz') + public at: Date; + + /** + * Processing duration in milliseconds + */ + @Column('double precision', { nullable: true }) + public duration: number | null = null; + + /** + * DB hostname extracted from responseUri, or requestUri if fetch is incomplete + */ + @Index('IDX_ap_fetch_log_host') + @Column('text') + public host: string; + + /** + * Original requested URI + */ + @Column('text', { + name: 'request_uri', + }) + public requestUri: string; + + /** + * Canonical URI / object ID, taken from the final payload + */ + @Column('text', { + name: 'object_uri', + nullable: true, + }) + @Index('IDX_ap_fetch_log_object_uri') + public objectUri: string | null = null; + + @Column('boolean', { nullable: true }) + public accepted: boolean | null = null; + + @Column('text', { nullable: true }) + public result: string | null = null; + + @Column('jsonb', { nullable: true }) + // https://github.com/typeorm/typeorm/issues/8559 + // eslint-disable-next-line @typescript-eslint/no-explicit-any + public object: any | null = null; + + @Column({ + type: 'text', + name: 'context_hash', + nullable: true, + }) + public contextHash: string | null; + + @ManyToOne(() => SkApContext, { + onDelete: 'CASCADE', + nullable: true, + }) + @JoinColumn({ + name: 'context_hash', + foreignKeyConstraintName: 'FK_ap_fetch_log_context_hash', + }) + public context: SkApContext | null; + + constructor(data?: Partial) { + if (data) { + Object.assign(this, data); + } + } +} diff --git a/packages/backend/src/models/_.ts b/packages/backend/src/models/_.ts index dabcf89d2c..4bd6e78ef4 100644 --- a/packages/backend/src/models/_.ts +++ b/packages/backend/src/models/_.ts @@ -83,6 +83,7 @@ import { MiBubbleGameRecord } from '@/models/BubbleGameRecord.js'; import { MiReversiGame } from '@/models/ReversiGame.js'; import { MiNoteSchedule } from '@/models/NoteSchedule.js'; import { SkApInboxLog } from '@/models/SkApInboxLog.js'; +import { SkApFetchLog } from '@/models/SkApFetchLog.js'; import { SkApContext } from '@/models/SkApContext.js'; import type { QueryDeepPartialEntity } from 'typeorm/query-builder/QueryPartialEntity.js'; @@ -132,6 +133,7 @@ export const miRepository = { export { SkLatestNote, SkApContext, + SkApFetchLog, SkApInboxLog, MiAbuseUserReport, MiAbuseReportNotificationRecipient, @@ -234,6 +236,7 @@ export type InstancesRepository = Repository & MiRepository & MiRepository; export type LatestNotesRepository = Repository & MiRepository; export type ApContextsRepository = Repository & MiRepository; +export type ApFetchLogsRepository = Repository & MiRepository; export type ApInboxLogsRepository = Repository & MiRepository; export type ModerationLogsRepository = Repository & MiRepository; export type MutingsRepository = Repository & MiRepository; diff --git a/packages/backend/src/postgres.ts b/packages/backend/src/postgres.ts index 9437ac936a..1a5fdc8412 100644 --- a/packages/backend/src/postgres.ts +++ b/packages/backend/src/postgres.ts @@ -86,6 +86,7 @@ import MisskeyLogger from '@/logger.js'; import { bindThis } from '@/decorators.js'; import { SkLatestNote } from '@/models/LatestNote.js'; import { SkApContext } from '@/models/SkApContext.js'; +import { SkApFetchLog } from '@/models/SkApFetchLog.js'; import { SkApInboxLog } from '@/models/SkApInboxLog.js'; pg.types.setTypeParser(20, Number); @@ -174,6 +175,7 @@ class MyCustomLogger implements Logger { export const entities = [ SkLatestNote, SkApContext, + SkApFetchLog, SkApInboxLog, MiAnnouncement, MiAnnouncementRead, diff --git a/packages/backend/src/queue/processors/InboxProcessorService.ts b/packages/backend/src/queue/processors/InboxProcessorService.ts index 4182f3e090..557a759136 100644 --- a/packages/backend/src/queue/processors/InboxProcessorService.ts +++ b/packages/backend/src/queue/processors/InboxProcessorService.ts @@ -4,7 +4,6 @@ */ import { URL } from 'node:url'; -import { createHash } from 'crypto'; import { Inject, Injectable, OnApplicationShutdown } from '@nestjs/common'; import httpSignature from '@peertube/http-signature'; import * as Bull from 'bullmq'; @@ -30,11 +29,9 @@ import { CollapsedQueue } from '@/misc/collapsed-queue.js'; import { MiNote } from '@/models/Note.js'; import { MiMeta } from '@/models/Meta.js'; import { DI } from '@/di-symbols.js'; -import { IdService } from '@/core/IdService.js'; -import { JsonValue } from '@/misc/json-value.js'; -import { SkApInboxLog, SkApContext } from '@/models/_.js'; -import type { ApInboxLogsRepository, ApContextsRepository } from '@/models/_.js'; +import { SkApInboxLog } from '@/models/_.js'; import type { Config } from '@/config.js'; +import { ApLogService, calculateDurationSince } from '@/core/ApLogService.js'; import { QueueLoggerService } from '../QueueLoggerService.js'; import type { InboxJobData } from '../types.js'; @@ -66,13 +63,7 @@ export class InboxProcessorService implements OnApplicationShutdown { private apRequestChart: ApRequestChart, private federationChart: FederationChart, private queueLoggerService: QueueLoggerService, - private idService: IdService, - - @Inject(DI.apContextsRepository) - private apContextsRepository: ApContextsRepository, - - @Inject(DI.apInboxLogsRepository) - private apInboxLogsRepository: ApInboxLogsRepository, + private readonly apLogService: ApLogService, ) { this.logger = this.queueLoggerService.logger.createSubLogger('inbox'); this.updateInstanceQueue = new CollapsedQueue(process.env.NODE_ENV !== 'test' ? 60 * 1000 * 5 : 0, this.collapseUpdateInstanceJobs, this.performUpdateInstance); @@ -89,14 +80,9 @@ export class InboxProcessorService implements OnApplicationShutdown { private async _processLogged(job: Bull.Job): Promise { const startTime = process.hrtime.bigint(); - const payload = job.data.activity; + const activity = job.data.activity; const keyId = job.data.signature.keyId; - const log = this.createLog(payload, keyId); - - // Pre-save the activity in case it leads to a hard-crash. - if (this.config.activityLogging.preSave) { - await this.recordLog(log); - } + const log = await this.apLogService.createInboxLog({ activity, keyId }); try { const result = await this._process(job, log); @@ -111,24 +97,18 @@ export class InboxProcessorService implements OnApplicationShutdown { throw err; } finally { - // Calculate the activity processing time with correct rounding and decimals. - // 1. Truncate nanoseconds to microseconds - // 2. Scale to 1/10 millisecond ticks. - // 3. Round to nearest tick. - // 4. Sale to milliseconds - // Example: 123,456,789 ns -> 123,456 us -> 12,345.6 ticks -> 12,346 ticks -> 123.46 ms - const endTime = process.hrtime.bigint(); - const duration = Math.round(Number((endTime - startTime) / 1000n) / 10) / 100; - log.duration = duration; + const duration = log.duration = calculateDurationSince(startTime); + // TODO remove this // Activities should time out after roughly 5 seconds. // A runtime longer than 10 seconds could indicate a problem or attack. if (duration > 10000) { - this.logger.warn(`Activity ${JSON.stringify(payload.id)} by "${keyId}" took ${(duration / 1000).toFixed(1)} seconds to complete`); + this.logger.warn(`Activity ${JSON.stringify(activity.id)} by "${keyId}" took ${(duration / 1000).toFixed(1)} seconds to complete`); } // Save or finalize asynchronously - this.recordLog(log).catch(err => this.logger.error('Failed to record AP activity:', err)); + this.apLogService.saveInboxLog(log) + .catch(err => this.logger.error('Failed to record AP activity:', err)); } } @@ -368,46 +348,4 @@ export class InboxProcessorService implements OnApplicationShutdown { async onApplicationShutdown(signal?: string) { await this.dispose(); } - - private createLog(payload: IActivity, keyId: string): SkApInboxLog { - const activity = Object.assign({}, payload, { '@context': undefined }) as unknown as JsonValue; - const host = this.utilityService.extractDbHost(keyId); - - const log = new SkApInboxLog({ - id: this.idService.gen(), - at: new Date(), - verified: false, - accepted: false, - activity, - keyId, - host, - }); - - const context = payload['@context']; - if (context) { - const md5 = createHash('md5').update(JSON.stringify(context)).digest('base64'); - log.contextHash = md5; - log.context = new SkApContext({ - md5, - json: context, - }); - } - - return log; - } - - private async recordLog(log: SkApInboxLog): Promise { - if (log.context) { - // https://stackoverflow.com/a/47064558 - await this.apContextsRepository - .createQueryBuilder('activity_context') - .insert() - .into(SkApContext) - .values(log.context) - .orIgnore('md5') - .execute(); - } - - await this.apInboxLogsRepository.upsert(log, ['id']); - } } From 4858276465a764f4e0973a463428a653a2a466ab Mon Sep 17 00:00:00 2001 From: Hazelnoot Date: Thu, 30 Jan 2025 22:38:29 -0500 Subject: [PATCH 10/13] don't log slow activities, as this is known to happen under regular circumstances --- .../src/queue/processors/InboxProcessorService.ts | 9 +-------- 1 file changed, 1 insertion(+), 8 deletions(-) diff --git a/packages/backend/src/queue/processors/InboxProcessorService.ts b/packages/backend/src/queue/processors/InboxProcessorService.ts index 557a759136..35a0bf095d 100644 --- a/packages/backend/src/queue/processors/InboxProcessorService.ts +++ b/packages/backend/src/queue/processors/InboxProcessorService.ts @@ -97,14 +97,7 @@ export class InboxProcessorService implements OnApplicationShutdown { throw err; } finally { - const duration = log.duration = calculateDurationSince(startTime); - - // TODO remove this - // Activities should time out after roughly 5 seconds. - // A runtime longer than 10 seconds could indicate a problem or attack. - if (duration > 10000) { - this.logger.warn(`Activity ${JSON.stringify(activity.id)} by "${keyId}" took ${(duration / 1000).toFixed(1)} seconds to complete`); - } + log.duration = calculateDurationSince(startTime); // Save or finalize asynchronously this.apLogService.saveInboxLog(log) From 71be39ecc878201e306365876ee059399418169d Mon Sep 17 00:00:00 2001 From: Hazelnoot Date: Sun, 2 Feb 2025 00:27:03 -0500 Subject: [PATCH 11/13] add missing `await` in ApLogCleanupService --- packages/backend/src/daemons/ApLogCleanupService.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/backend/src/daemons/ApLogCleanupService.ts b/packages/backend/src/daemons/ApLogCleanupService.ts index 2b6693e19e..61f76b4e2c 100644 --- a/packages/backend/src/daemons/ApLogCleanupService.ts +++ b/packages/backend/src/daemons/ApLogCleanupService.ts @@ -40,7 +40,7 @@ export class ApLogCleanupService implements OnApplicationShutdown { @bindThis private async tick(): Promise { try { - const affected = this.apLogService.deleteExpiredLogs(); + const affected = await this.apLogService.deleteExpiredLogs(); this.logger.info(`Activity Log cleanup complete; removed ${affected} expired logs.`); } catch (err) { this.logger.error('Activity Log cleanup failed:', err as Error); From dbaeb7f2ac3ce747d13c928c742e8cf8ea441c61 Mon Sep 17 00:00:00 2001 From: Hazelnoot Date: Sun, 2 Feb 2025 00:49:03 -0500 Subject: [PATCH 12/13] fix unit tests using mock-resolver --- packages/backend/test/misc/mock-resolver.ts | 2 ++ 1 file changed, 2 insertions(+) diff --git a/packages/backend/test/misc/mock-resolver.ts b/packages/backend/test/misc/mock-resolver.ts index c8f3db8aac..791b04e6e2 100644 --- a/packages/backend/test/misc/mock-resolver.ts +++ b/packages/backend/test/misc/mock-resolver.ts @@ -23,6 +23,7 @@ import type { PollsRepository, UsersRepository, } from '@/models/_.js'; +import { ApLogService } from '@/core/ApLogService.js'; type MockResponse = { type: string; @@ -49,6 +50,7 @@ export class MockResolver extends Resolver { {} as ApRendererService, {} as ApDbResolverService, loggerService, + {} as ApLogService, ); } From 9de5ecae518973e29f63bde51062aa0ed7eadb11 Mon Sep 17 00:00:00 2001 From: Hazelnoot Date: Sun, 2 Feb 2025 23:19:41 -0500 Subject: [PATCH 13/13] delete fetch logs when a note or user is deleted --- packages/backend/src/core/ApLogService.ts | 20 ++++++++++++++++++- .../backend/src/core/NoteDeleteService.ts | 16 ++++++++++++++- .../DeleteAccountProcessorService.ts | 16 +++++++++++++++ 3 files changed, 50 insertions(+), 2 deletions(-) diff --git a/packages/backend/src/core/ApLogService.ts b/packages/backend/src/core/ApLogService.ts index 362eba24be..096ec21de7 100644 --- a/packages/backend/src/core/ApLogService.ts +++ b/packages/backend/src/core/ApLogService.ts @@ -5,7 +5,7 @@ import { createHash } from 'crypto'; import { Inject, Injectable } from '@nestjs/common'; -import { LessThan } from 'typeorm'; +import { In, LessThan } from 'typeorm'; import { DI } from '@/di-symbols.js'; import { SkApFetchLog, SkApInboxLog, SkApContext } from '@/models/_.js'; import type { ApContextsRepository, ApFetchLogsRepository, ApInboxLogsRepository } from '@/models/_.js'; @@ -121,6 +121,24 @@ export class ApLogService { .execute(); } + /** + * Deletes all logged copies of an object or objects + * @param objectUris URIs / AP IDs of the objects to delete + */ + public async deleteObjectLogs(objectUris: string | string[]): Promise { + if (Array.isArray(objectUris)) { + const logsDeleted = await this.apFetchLogsRepository.delete({ + objectUri: In(objectUris), + }); + return logsDeleted.affected ?? 0; + } else { + const logsDeleted = await this.apFetchLogsRepository.delete({ + objectUri: objectUris, + }); + return logsDeleted.affected ?? 0; + } + } + /** * Deletes all expired AP logs and garbage-collects the AP context cache. * Returns the total number of deleted rows. diff --git a/packages/backend/src/core/NoteDeleteService.ts b/packages/backend/src/core/NoteDeleteService.ts index b51a3143c9..cb258a4f5a 100644 --- a/packages/backend/src/core/NoteDeleteService.ts +++ b/packages/backend/src/core/NoteDeleteService.ts @@ -24,9 +24,14 @@ import { SearchService } from '@/core/SearchService.js'; import { ModerationLogService } from '@/core/ModerationLogService.js'; import { isQuote, isRenote } from '@/misc/is-renote.js'; import { LatestNoteService } from '@/core/LatestNoteService.js'; +import { ApLogService } from '@/core/ApLogService.js'; +import Logger from '@/logger.js'; +import { LoggerService } from './LoggerService.js'; @Injectable() export class NoteDeleteService { + private readonly logger: Logger; + constructor( @Inject(DI.config) private config: Config, @@ -55,7 +60,11 @@ export class NoteDeleteService { private perUserNotesChart: PerUserNotesChart, private instanceChart: InstanceChart, private latestNoteService: LatestNoteService, - ) {} + private readonly apLogService: ApLogService, + loggerService: LoggerService, + ) { + this.logger = loggerService.getLogger('note-delete-service'); + } /** * 投稿を削除します。 @@ -156,6 +165,11 @@ export class NoteDeleteService { note: note, }); } + + if (note.uri) { + this.apLogService.deleteObjectLogs(note.uri) + .catch(err => this.logger.error(err, `Failed to delete AP logs for note '${note.uri}'`)); + } } @bindThis diff --git a/packages/backend/src/queue/processors/DeleteAccountProcessorService.ts b/packages/backend/src/queue/processors/DeleteAccountProcessorService.ts index e350b97f53..66bed72f18 100644 --- a/packages/backend/src/queue/processors/DeleteAccountProcessorService.ts +++ b/packages/backend/src/queue/processors/DeleteAccountProcessorService.ts @@ -15,6 +15,7 @@ import type { MiNoteReaction } from '@/models/NoteReaction.js'; import { EmailService } from '@/core/EmailService.js'; import { bindThis } from '@/decorators.js'; import { SearchService } from '@/core/SearchService.js'; +import { ApLogService } from '@/core/ApLogService.js'; import { ReactionService } from '@/core/ReactionService.js'; import { QueueLoggerService } from '../QueueLoggerService.js'; import type * as Bull from 'bullmq'; @@ -45,6 +46,7 @@ export class DeleteAccountProcessorService { private queueLoggerService: QueueLoggerService, private searchService: SearchService, private reactionService: ReactionService, + private readonly apLogService: ApLogService, ) { this.logger = this.queueLoggerService.logger.createSubLogger('delete-account'); } @@ -84,6 +86,13 @@ export class DeleteAccountProcessorService { for (const note of notes) { await this.searchService.unindexNote(note); } + + // Delete note AP logs + const noteUris = notes.map(n => n.uri).filter(u => !!u) as string[]; + if (noteUris.length > 0) { + await this.apLogService.deleteObjectLogs(noteUris) + .catch(err => this.logger.error(err, `Failed to delete AP logs for notes of user '${user.uri ?? user.id}'`)); + } } this.logger.succ('All of notes deleted'); @@ -149,6 +158,13 @@ export class DeleteAccountProcessorService { this.logger.succ('All of files deleted'); } + { // Delete actor logs + if (user.uri) { + await this.apLogService.deleteObjectLogs(user.uri) + .catch(err => this.logger.error(err, `Failed to delete AP logs for user '${user.uri}'`)); + } + } + { // Send email notification const profile = await this.userProfilesRepository.findOneByOrFail({ userId: user.id }); if (profile.email && profile.emailVerified) {