From cdea55ab254fc540eb5867de1a70eba1fe451e0c Mon Sep 17 00:00:00 2001
From: naskya <m@naskya.net>
Date: Thu, 25 Apr 2024 11:42:16 +0900
Subject: [PATCH] chore (backend): revise apLogger log levels (#10907)
---
.../src/remote/activitypub/deliver-manager.ts | 3 +-
.../remote/activitypub/kernel/accept/index.ts | 7 ++-
.../activitypub/kernel/announce/index.ts | 4 +-
.../activitypub/kernel/announce/note.ts | 11 +++--
.../remote/activitypub/kernel/create/index.ts | 9 ++--
.../remote/activitypub/kernel/delete/actor.ts | 4 +-
.../remote/activitypub/kernel/delete/note.ts | 4 +-
.../src/remote/activitypub/kernel/index.ts | 15 ++++--
.../remote/activitypub/kernel/reject/index.ts | 5 +-
.../remote/activitypub/kernel/undo/index.ts | 7 ++-
.../remote/activitypub/kernel/update/index.ts | 5 +-
.../src/remote/activitypub/models/image.ts | 4 +-
.../src/remote/activitypub/models/note.ts | 47 ++++++++++---------
.../src/remote/activitypub/models/person.ts | 31 ++++++------
.../src/remote/activitypub/resolver.ts | 12 +++--
15 files changed, 88 insertions(+), 80 deletions(-)
diff --git a/packages/backend/src/remote/activitypub/deliver-manager.ts b/packages/backend/src/remote/activitypub/deliver-manager.ts
index 71e1c89232..47db9ef273 100644
--- a/packages/backend/src/remote/activitypub/deliver-manager.ts
+++ b/packages/backend/src/remote/activitypub/deliver-manager.ts
@@ -133,7 +133,8 @@ export default class DeliverManager {
host: new URL(inbox).host,
});
} catch (error) {
- apLogger.error(`Invalid Inbox ${inbox}:\n${inspect(error)}`);
+ apLogger.info(`Invalid Inbox ${inbox}`);
+ apLogger.debug(inspect(error));
}
}
diff --git a/packages/backend/src/remote/activitypub/kernel/accept/index.ts b/packages/backend/src/remote/activitypub/kernel/accept/index.ts
index bb03bf9a62..486bab635f 100644
--- a/packages/backend/src/remote/activitypub/kernel/accept/index.ts
+++ b/packages/backend/src/remote/activitypub/kernel/accept/index.ts
@@ -6,20 +6,19 @@ import { isFollow, getApType } from "../../type.js";
import { apLogger } from "../../logger.js";
import { inspect } from "node:util";
-const logger = apLogger;
-
export default async (
actor: CacheableRemoteUser,
activity: IAccept,
): Promise<string> => {
const uri = activity.id || activity;
- logger.info(`Accept: ${uri}`);
+ apLogger.info(`Accept: ${uri}`);
const resolver = new Resolver();
const object = await resolver.resolve(activity.object).catch((e) => {
- logger.error(`Resolution failed:\n${inspect(e)}`);
+ apLogger.info(`Failed to resolve AP object: ${e}`);
+ apLogger.debug(inspect(e));
throw e;
});
diff --git a/packages/backend/src/remote/activitypub/kernel/announce/index.ts b/packages/backend/src/remote/activitypub/kernel/announce/index.ts
index 975e070f92..83dac26294 100644
--- a/packages/backend/src/remote/activitypub/kernel/announce/index.ts
+++ b/packages/backend/src/remote/activitypub/kernel/announce/index.ts
@@ -5,15 +5,13 @@ import type { IAnnounce } from "../../type.js";
import { getApId } from "../../type.js";
import { apLogger } from "../../logger.js";
-const logger = apLogger;
-
export default async (
actor: CacheableRemoteUser,
activity: IAnnounce,
): Promise<void> => {
const uri = getApId(activity);
- logger.info(`Announce: ${uri}`);
+ apLogger.info(`Announce: ${uri}`);
const resolver = new Resolver();
diff --git a/packages/backend/src/remote/activitypub/kernel/announce/note.ts b/packages/backend/src/remote/activitypub/kernel/announce/note.ts
index 41d1319dbd..d40423ac51 100644
--- a/packages/backend/src/remote/activitypub/kernel/announce/note.ts
+++ b/packages/backend/src/remote/activitypub/kernel/announce/note.ts
@@ -13,8 +13,6 @@ import { Notes } from "@/models/index.js";
import { isBlockedServer } from "backend-rs";
import { inspect } from "node:util";
-const logger = apLogger;
-
/**
* Handle announcement activities
*/
@@ -50,11 +48,14 @@ export default async function (
// Skip if target is 4xx
if (e instanceof StatusError) {
if (e.isClientError) {
- logger.warn(`Ignored announce target ${targetUri} - ${e.statusCode}`);
+ apLogger.info(
+ `Ignored announce target ${targetUri} - ${e.statusCode}`,
+ );
return;
}
- logger.warn(`Error in announce target ${targetUri}:\n${inspect(e)}`);
+ apLogger.warn(`Error in announce target ${targetUri}`);
+ apLogger.debug(inspect(e));
}
throw e;
}
@@ -63,7 +64,7 @@ export default async function (
console.log("skip: invalid actor for this activity");
return;
}
- logger.info(`Creating the (Re)Note: ${uri}`);
+ apLogger.info(`Creating (re)note: ${uri}`);
const activityAudience = await parseAudience(
actor,
diff --git a/packages/backend/src/remote/activitypub/kernel/create/index.ts b/packages/backend/src/remote/activitypub/kernel/create/index.ts
index d3bc1936d5..578479e5e7 100644
--- a/packages/backend/src/remote/activitypub/kernel/create/index.ts
+++ b/packages/backend/src/remote/activitypub/kernel/create/index.ts
@@ -7,15 +7,13 @@ import { apLogger } from "../../logger.js";
import { toArray, concat, unique } from "@/prelude/array.js";
import { inspect } from "node:util";
-const logger = apLogger;
-
export default async (
actor: CacheableRemoteUser,
activity: ICreate,
): Promise<void> => {
const uri = getApId(activity);
- logger.info(`Create: ${uri}`);
+ apLogger.info(`Create: ${uri}`);
// copy audiences between activity <=> object.
if (typeof activity.object === "object") {
@@ -40,13 +38,14 @@ export default async (
const resolver = new Resolver();
const object = await resolver.resolve(activity.object).catch((e) => {
- logger.error(`Resolution failed:\n${inspect(e)}`);
+ apLogger.info(`Failed to resolve AP object: ${e}`);
+ apLogger.debug(inspect(e));
throw e;
});
if (isPost(object)) {
createNote(resolver, actor, object, false, activity);
} else {
- logger.warn(`Unknown type: ${getApType(object)}`);
+ apLogger.info(`Unknown type: ${getApType(object)}`);
}
};
diff --git a/packages/backend/src/remote/activitypub/kernel/delete/actor.ts b/packages/backend/src/remote/activitypub/kernel/delete/actor.ts
index 83c6442dde..51b3777a86 100644
--- a/packages/backend/src/remote/activitypub/kernel/delete/actor.ts
+++ b/packages/backend/src/remote/activitypub/kernel/delete/actor.ts
@@ -3,13 +3,11 @@ import { createDeleteAccountJob } from "@/queue/index.js";
import type { CacheableRemoteUser } from "@/models/entities/user.js";
import { Users } from "@/models/index.js";
-const logger = apLogger;
-
export async function deleteActor(
actor: CacheableRemoteUser,
uri: string,
): Promise<string> {
- logger.info(`Deleting the Actor: ${uri}`);
+ apLogger.info(`Deleting Actor: ${uri}`);
if (actor.uri !== uri) {
return `skip: delete actor ${actor.uri} !== ${uri}`;
diff --git a/packages/backend/src/remote/activitypub/kernel/delete/note.ts b/packages/backend/src/remote/activitypub/kernel/delete/note.ts
index ae3a593d05..f298ff903f 100644
--- a/packages/backend/src/remote/activitypub/kernel/delete/note.ts
+++ b/packages/backend/src/remote/activitypub/kernel/delete/note.ts
@@ -5,13 +5,11 @@ import DbResolver from "../../db-resolver.js";
import { getApLock } from "@/misc/app-lock.js";
import { deleteMessage } from "@/services/messages/delete.js";
-const logger = apLogger;
-
export default async function (
actor: CacheableRemoteUser,
uri: string,
): Promise<string> {
- logger.info(`Deleting the Note: ${uri}`);
+ apLogger.info(`Deleting note: ${uri}`);
const lock = await getApLock(uri);
diff --git a/packages/backend/src/remote/activitypub/kernel/index.ts b/packages/backend/src/remote/activitypub/kernel/index.ts
index b556550c5f..fbe8232bda 100644
--- a/packages/backend/src/remote/activitypub/kernel/index.ts
+++ b/packages/backend/src/remote/activitypub/kernel/index.ts
@@ -54,7 +54,8 @@ export async function performActivity(
try {
await performOneActivity(actor, act);
} catch (err) {
- apLogger.error(inspect(err));
+ apLogger.info(`Failed to perform activity: ${err}`);
+ apLogger.debug(inspect(err));
}
}
} else {
@@ -88,9 +89,15 @@ async function performOneActivity(
} else if (isReject(activity)) {
await reject(actor, activity);
} else if (isAdd(activity)) {
- await add(actor, activity).catch((err) => apLogger.error(inspect(err)));
+ await add(actor, activity).catch((err) => {
+ apLogger.warn(`Failed to perform 'add' activity: ${err}`);
+ apLogger.debug(inspect(err));
+ });
} else if (isRemove(activity)) {
- await remove(actor, activity).catch((err) => apLogger.error(inspect(err)));
+ await remove(actor, activity).catch((err) => {
+ apLogger.warn(`Failed to perform 'remove' activity: ${err}`);
+ apLogger.debug(inspect(err));
+ });
} else if (isAnnounce(activity)) {
await announce(actor, activity);
} else if (isLike(activity)) {
@@ -104,7 +111,7 @@ async function performOneActivity(
} else if (isMove(activity)) {
await move(actor, activity);
} else {
- apLogger.warn(
+ apLogger.info(
`Unrecognized activity type: ${(activity as IActivity).type}`,
);
}
diff --git a/packages/backend/src/remote/activitypub/kernel/reject/index.ts b/packages/backend/src/remote/activitypub/kernel/reject/index.ts
index 001231d030..782e0e2aaf 100644
--- a/packages/backend/src/remote/activitypub/kernel/reject/index.ts
+++ b/packages/backend/src/remote/activitypub/kernel/reject/index.ts
@@ -14,12 +14,13 @@ export default async (
): Promise<string> => {
const uri = activity.id || activity;
- logger.info(`Reject: ${uri}`);
+ apLogger.info(`Reject: ${uri}`);
const resolver = new Resolver();
const object = await resolver.resolve(activity.object).catch((e) => {
- logger.error(`Resolution failed:\n${inspect(e)}`);
+ apLogger.info(`Failed to resolve AP object: ${e}`);
+ apLogger.debug(inspect(e));
throw e;
});
diff --git a/packages/backend/src/remote/activitypub/kernel/undo/index.ts b/packages/backend/src/remote/activitypub/kernel/undo/index.ts
index c1c18271f9..00647ec750 100644
--- a/packages/backend/src/remote/activitypub/kernel/undo/index.ts
+++ b/packages/backend/src/remote/activitypub/kernel/undo/index.ts
@@ -17,8 +17,6 @@ import Resolver from "../../resolver.js";
import { apLogger } from "../../logger.js";
import { inspect } from "node:util";
-const logger = apLogger;
-
export default async (
actor: CacheableRemoteUser,
activity: IUndo,
@@ -29,12 +27,13 @@ export default async (
const uri = activity.id || activity;
- logger.info(`Undo: ${uri}`);
+ apLogger.info(`Undo: ${uri}`);
const resolver = new Resolver();
const object = await resolver.resolve(activity.object).catch((e) => {
- logger.error(`Resolution failed:\n${inspect(e)}`);
+ apLogger.info(`Failed to resolve AP object: ${e}`);
+ apLogger.debug(inspect(e));
throw e;
});
diff --git a/packages/backend/src/remote/activitypub/kernel/update/index.ts b/packages/backend/src/remote/activitypub/kernel/update/index.ts
index 933f2c99e0..27969971f3 100644
--- a/packages/backend/src/remote/activitypub/kernel/update/index.ts
+++ b/packages/backend/src/remote/activitypub/kernel/update/index.ts
@@ -18,12 +18,13 @@ export default async (
return "skip: invalid actor";
}
- apLogger.debug("Update");
+ apLogger.info("Update");
const resolver = new Resolver();
const object = await resolver.resolve(activity.object).catch((e) => {
- apLogger.error(`Resolution failed:\n${inspect(e)}`);
+ apLogger.info(`Failed to resolve AP object: ${e}`);
+ apLogger.debug(inspect(e));
throw e;
});
diff --git a/packages/backend/src/remote/activitypub/models/image.ts b/packages/backend/src/remote/activitypub/models/image.ts
index a6ac698feb..0858f48e7b 100644
--- a/packages/backend/src/remote/activitypub/models/image.ts
+++ b/packages/backend/src/remote/activitypub/models/image.ts
@@ -11,8 +11,6 @@ import { DriveFiles } from "@/models/index.js";
import { truncate } from "@/misc/truncate.js";
import { DB_MAX_IMAGE_COMMENT_LENGTH } from "@/misc/hard-limits.js";
-const logger = apLogger;
-
/**
* create an Image.
*/
@@ -36,7 +34,7 @@ export async function createImage(
throw new Error(`Invalid image, unexpected schema: ${image.url}`);
}
- logger.info(`Creating the Image: ${image.url}`);
+ apLogger.info(`Creating an image: ${image.url}`);
const instance = await fetchMeta(true);
diff --git a/packages/backend/src/remote/activitypub/models/note.ts b/packages/backend/src/remote/activitypub/models/note.ts
index 4b685747ba..7f0951246e 100644
--- a/packages/backend/src/remote/activitypub/models/note.ts
+++ b/packages/backend/src/remote/activitypub/models/note.ts
@@ -50,8 +50,6 @@ import { type Size, getEmojiSize } from "@/misc/emoji-meta.js";
import { langmap } from "@/misc/langmap.js";
import { inspect } from "node:util";
-const logger = apLogger;
-
export function validateNote(object: any, uri: string) {
const expectHost = extractHost(uri);
@@ -112,13 +110,16 @@ export async function createNote(
const entryUri = getApId(value);
const err = validateNote(object, entryUri);
if (err) {
- logger.error(`${err.message}`, {
- resolver: {
- history: resolver.getHistory(),
- },
- value: value,
- object: object,
- });
+ apLogger.info(`${err.message}`);
+ apLogger.debug(
+ inspect({
+ resolver: {
+ history: resolver.getHistory(),
+ },
+ value: value,
+ object: object,
+ }),
+ );
throw new Error("invalid note");
}
@@ -140,8 +141,8 @@ export async function createNote(
throw new Error(`unexpected schema of note url: ${url}`);
}
- logger.debug(`Note fetched: ${JSON.stringify(note, null, 2)}`);
- logger.info(`Creating the Note: ${note.id}`);
+ apLogger.trace(`Note fetched: ${JSON.stringify(note, null, 2)}`);
+ apLogger.info(`Creating the Note: ${note.id}`);
// Skip if note is made before 2007 (1yr before Fedi was created)
// OR skip if note is made 3 days in advance
@@ -150,13 +151,13 @@ export async function createNote(
const FutureCheck = new Date();
FutureCheck.setDate(FutureCheck.getDate() + 3); // Allow some wiggle room for misconfigured hosts
if (DateChecker.getFullYear() < 2007) {
- logger.warn(
+ apLogger.info(
"Note somehow made before Activitypub was created; discarding",
);
return null;
}
if (DateChecker > FutureCheck) {
- logger.warn("Note somehow made after today; discarding");
+ apLogger.info("Note somehow made after today; discarding");
return null;
}
}
@@ -169,8 +170,8 @@ export async function createNote(
// Skip if author is suspended.
if (actor.isSuspended) {
- logger.debug(
- `User ${actor.usernameLower}@${actor.host} suspended; discarding.`,
+ apLogger.info(
+ `User ${actor.usernameLower}@${actor.host} is suspended; discarding.`,
);
return null;
}
@@ -224,7 +225,7 @@ export async function createNote(
? await resolveNote(note.inReplyTo, resolver)
.then((x) => {
if (x == null) {
- logger.warn("Specified inReplyTo, but nout found");
+ apLogger.info(`Specified inReplyTo not found: ${note.inReplyTo}`);
throw new Error("inReplyTo not found");
} else {
return x;
@@ -242,7 +243,8 @@ export async function createNote(
}
}
- logger.warn(`Error in inReplyTo ${note.inReplyTo}:\n${inspect(e)}`);
+ apLogger.info(`Error in inReplyTo ${note.inReplyTo}`);
+ apLogger.debug(inspect(e));
throw e;
})
: null;
@@ -336,11 +338,11 @@ export async function createNote(
index: number,
): Promise<null> => {
if (poll.expiresAt && Date.now() > new Date(poll.expiresAt).getTime()) {
- logger.warn(
- `vote to expired poll from AP: actor=${actor.username}@${actor.host}, note=${note.id}, choice=${name}`,
+ apLogger.info(
+ `discarding vote to expired poll: actor=${actor.username}@${actor.host}, note=${note.id}, choice=${name}`,
);
} else if (index >= 0) {
- logger.info(
+ apLogger.info(
`vote from AP: actor=${actor.username}@${actor.host}, note=${note.id}, choice=${name}`,
);
await vote(actor, reply, index);
@@ -357,7 +359,8 @@ export async function createNote(
}
const emojis = await extractEmojis(note.tag || [], actor.host).catch((e) => {
- logger.info(`extractEmojis:\n${inspect(e)}`);
+ apLogger.info("Failed to extract emojis");
+ apLogger.debug(inspect(e));
return [] as Emoji[];
});
@@ -515,7 +518,7 @@ export async function extractEmojis(
return exists;
}
- logger.info(`register emoji host=${host}, name=${name}`);
+ apLogger.info(`register emoji host=${host}, name=${name}`);
let size: Size = { width: 0, height: 0 };
try {
diff --git a/packages/backend/src/remote/activitypub/models/person.ts b/packages/backend/src/remote/activitypub/models/person.ts
index 4baa2c021b..bb7bc7c033 100644
--- a/packages/backend/src/remote/activitypub/models/person.ts
+++ b/packages/backend/src/remote/activitypub/models/person.ts
@@ -48,8 +48,6 @@ import { resolveNote, extractEmojis } from "./note.js";
import { resolveImage } from "./image.js";
import { inspect } from "node:util";
-const logger = apLogger;
-
const nameLength = 128;
const summaryLength = 2048;
@@ -178,7 +176,7 @@ export async function createPerson(
const person = validateActor(object, uri);
- logger.info(`Creating the Person: ${person.id}`);
+ apLogger.info(`Creating Person: ${person.id}`);
const host = toPuny(new URL(object.id).hostname);
@@ -347,7 +345,8 @@ export async function createPerson(
throw new Error("already registered");
}
} else {
- logger.error(inspect(e));
+ apLogger.info(`Failed to create a Person actor: ${person.url}`);
+ apLogger.debug(inspect(e));
throw e;
}
}
@@ -388,7 +387,8 @@ export async function createPerson(
//#region Get custom emoji
const emojis = await extractEmojis(person.tag || [], host).catch((e) => {
- logger.info(`extractEmojis:\n${inspect(e)}`);
+ apLogger.info("Failed to extract emojis");
+ apLogger.debug(inspect(e));
return [] as Emoji[];
});
@@ -399,9 +399,10 @@ export async function createPerson(
});
//#endregion
- await updateFeatured(user!.id, resolver).catch((err) =>
- logger.error(inspect(err)),
- );
+ await updateFeatured(user!.id, resolver).catch((err) => {
+ apLogger.info(`Failed to update featured collection of ${user.uri}`);
+ apLogger.debug(inspect(err));
+ });
return user!;
}
@@ -439,7 +440,7 @@ export async function updatePerson(
const person = validateActor(object, uri);
- logger.info(`Updating the Person: ${person.id}`);
+ apLogger.info(`Updating the Person: ${person.id}`);
// Fetch avatar and header image
const [avatar, banner] = await Promise.all(
@@ -456,7 +457,8 @@ export async function updatePerson(
// Custom pictogram acquisition
const emojis = await extractEmojis(person.tag || [], user.host).catch((e) => {
- logger.info(`extractEmojis:\n${inspect(e)}`);
+ apLogger.info("Failed to extract emojis");
+ apLogger.debug(inspect(e));
return [] as Emoji[];
});
@@ -626,9 +628,10 @@ export async function updatePerson(
},
);
- await updateFeatured(user.id, resolver).catch((err) =>
- logger.error(inspect(err)),
- );
+ await updateFeatured(user.id, resolver).catch((err) => {
+ apLogger.info(`Failed to update featured collection of ${user.uri}`);
+ apLogger.debug(inspect(err));
+ });
}
/**
@@ -681,7 +684,7 @@ export async function updateFeatured(userId: User["id"], resolver?: Resolver) {
if (!Users.isRemoteUser(user)) return;
if (!user.featured) return;
- logger.info(`Updating the featured: ${user.uri}`);
+ apLogger.info(`Updating the featured collection: ${user.uri}`);
if (resolver == null) resolver = new Resolver();
diff --git a/packages/backend/src/remote/activitypub/resolver.ts b/packages/backend/src/remote/activitypub/resolver.ts
index 51419deecf..abb9c2b2a4 100644
--- a/packages/backend/src/remote/activitypub/resolver.ts
+++ b/packages/backend/src/remote/activitypub/resolver.ts
@@ -76,12 +76,12 @@ export default class Resolver {
throw new Error("instance is blocked");
}
}
- apLogger.debug("Returning existing object:");
- apLogger.debug(JSON.stringify(value, null, 2));
+ apLogger.debug("Returning the existing object");
+ apLogger.trace(JSON.stringify(value, null, 2));
return value;
}
- apLogger.debug(`Resolving: ${value}`);
+ apLogger.info(`Resolving: ${value}`);
if (value.includes("#")) {
// URLs with fragment parts cannot be resolved correctly because
@@ -115,8 +115,10 @@ export default class Resolver {
this.user = await getInstanceActor();
}
- apLogger.debug("Getting object from remote, authenticated as user:");
- apLogger.debug(JSON.stringify(this.user, null, 2));
+ apLogger.info(
+ `Getting object from remote, authenticated as user ${this.user.id}`,
+ );
+ apLogger.trace(JSON.stringify(this.user, null, 2));
const { finalUrl, content: object } = await apGet(value, this.user);