Refactor debugging and logging more

This commit is contained in:
Jesse Wierzbinski 2024-04-14 01:20:55 -10:00
parent 82c6dc17a8
commit ab6fe6988c
No known key found for this signature in database
20 changed files with 230 additions and 123 deletions

View file

@ -42,10 +42,10 @@ tos_url = "https://my-site.com/tos"
# Whether to enable registrations or not # Whether to enable registrations or not
registration = true registration = true
rules = [ rules = [
"Do not harass others", "Do not harass others",
"Be nice to people", "Be nice to people",
"Don't spam", "Don't spam",
"Don't post illegal content", "Don't post illegal content",
] ]
# Delete this section if you don't want to use custom OAuth providers # Delete this section if you don't want to use custom OAuth providers
@ -72,8 +72,8 @@ bind_port = "8080"
banned_ips = [] banned_ips = []
# Banned user agents, regex format # Banned user agents, regex format
banned_user_agents = [ banned_user_agents = [
# "curl\/7.68.0", # "curl\/7.68.0",
# "wget\/1.20.3", # "wget\/1.20.3",
] ]
[http.bait] [http.bait]
@ -156,32 +156,32 @@ max_field_name_size = 1000
max_field_value_size = 1000 max_field_value_size = 1000
# Forbidden usernames, defaults are from Akkoma # Forbidden usernames, defaults are from Akkoma
username_blacklist = [ username_blacklist = [
".well-known", ".well-known",
"~", "~",
"about", "about",
"activities", "activities",
"api", "api",
"auth", "auth",
"dev", "dev",
"inbox", "inbox",
"internal", "internal",
"main", "main",
"media", "media",
"nodeinfo", "nodeinfo",
"notice", "notice",
"oauth", "oauth",
"objects", "objects",
"proxy", "proxy",
"push", "push",
"registration", "registration",
"relay", "relay",
"settings", "settings",
"status", "status",
"tag", "tag",
"users", "users",
"web", "web",
"search", "search",
"mfa", "mfa",
] ]
# Whether to blacklist known temporary email providers # Whether to blacklist known temporary email providers
blacklist_tempmail = false blacklist_tempmail = false
@ -189,57 +189,57 @@ blacklist_tempmail = false
email_blacklist = [] email_blacklist = []
# Valid URL schemes, otherwise the URL is parsed as text # Valid URL schemes, otherwise the URL is parsed as text
url_scheme_whitelist = [ url_scheme_whitelist = [
"http", "http",
"https", "https",
"ftp", "ftp",
"dat", "dat",
"dweb", "dweb",
"gopher", "gopher",
"hyper", "hyper",
"ipfs", "ipfs",
"ipns", "ipns",
"irc", "irc",
"xmpp", "xmpp",
"ircs", "ircs",
"magnet", "magnet",
"mailto", "mailto",
"mumble", "mumble",
"ssb", "ssb",
"gemini", "gemini",
] ]
# Only allow those MIME types of data to be uploaded # Only allow those MIME types of data to be uploaded
# This can easily be spoofed, but if it is spoofed it will appear broken # This can easily be spoofed, but if it is spoofed it will appear broken
# to normal clients until despoofed # to normal clients until despoofed
enforce_mime_types = false enforce_mime_types = false
allowed_mime_types = [ allowed_mime_types = [
"image/jpeg", "image/jpeg",
"image/png", "image/png",
"image/gif", "image/gif",
"image/heic", "image/heic",
"image/heif", "image/heif",
"image/webp", "image/webp",
"image/avif", "image/avif",
"video/webm", "video/webm",
"video/mp4", "video/mp4",
"video/quicktime", "video/quicktime",
"video/ogg", "video/ogg",
"audio/wave", "audio/wave",
"audio/wav", "audio/wav",
"audio/x-wav", "audio/x-wav",
"audio/x-pn-wave", "audio/x-pn-wave",
"audio/vnd.wave", "audio/vnd.wave",
"audio/ogg", "audio/ogg",
"audio/vorbis", "audio/vorbis",
"audio/mpeg", "audio/mpeg",
"audio/mp3", "audio/mp3",
"audio/webm", "audio/webm",
"audio/flac", "audio/flac",
"audio/aac", "audio/aac",
"audio/m4a", "audio/m4a",
"audio/x-m4a", "audio/x-m4a",
"audio/mp4", "audio/mp4",
"audio/3gpp", "audio/3gpp",
"video/x-ms-asf", "video/x-ms-asf",
] ]
[defaults] [defaults]
@ -294,8 +294,8 @@ banner = ""
# Note contents # Note contents
note_content = [ note_content = [
# "(https?://)?(www\\.)?youtube\\.com/watch\\?v=[a-zA-Z0-9_-]+", # "(https?://)?(www\\.)?youtube\\.com/watch\\?v=[a-zA-Z0-9_-]+",
# "(https?://)?(www\\.)?youtu\\.be/[a-zA-Z0-9_-]+", # "(https?://)?(www\\.)?youtu\\.be/[a-zA-Z0-9_-]+",
] ]
emoji = [] emoji = []
# These will drop users matching the filters # These will drop users matching the filters
@ -308,6 +308,8 @@ bio = []
log_requests = false log_requests = false
# Log request and their contents (warning: this is a lot of data) # Log request and their contents (warning: this is a lot of data)
log_requests_verbose = false log_requests_verbose = false
# Available levels: debug, info, warning, error, critical
log_level = "info"
# For GDPR compliance, you can disable logging of IPs # For GDPR compliance, you can disable logging of IPs
log_ip = false log_ip = false

View file

@ -35,6 +35,8 @@ import {
statusToMentions, statusToMentions,
user, user,
} from "~drizzle/schema"; } from "~drizzle/schema";
import { dualLogger } from "@loggers";
import { LogLevel } from "~packages/log-manager";
import type { Note } from "~types/lysand/Object"; import type { Note } from "~types/lysand/Object";
import type { Attachment as APIAttachment } from "~types/mastodon/attachment"; import type { Attachment as APIAttachment } from "~types/mastodon/attachment";
import type { Status as APIStatus } from "~types/mastodon/status"; import type { Status as APIStatus } from "~types/mastodon/status";
@ -601,7 +603,11 @@ export const resolveStatus = async (
for (const attachment of note.attachments ?? []) { for (const attachment of note.attachments ?? []) {
const resolvedAttachment = await attachmentFromLysand(attachment).catch( const resolvedAttachment = await attachmentFromLysand(attachment).catch(
(e) => { (e) => {
console.error(e); dualLogger.logError(
LogLevel.ERROR,
"Federation.StatusResolver",
e,
);
return null; return null;
}, },
); );
@ -616,7 +622,7 @@ export const resolveStatus = async (
for (const emoji of note.extensions?.["org.lysand:custom_emojis"]?.emojis ?? for (const emoji of note.extensions?.["org.lysand:custom_emojis"]?.emojis ??
[]) { []) {
const resolvedEmoji = await fetchEmoji(emoji).catch((e) => { const resolvedEmoji = await fetchEmoji(emoji).catch((e) => {
console.error(e); dualLogger.logError(LogLevel.ERROR, "Federation.StatusResolver", e);
return null; return null;
}); });
@ -1010,8 +1016,14 @@ export const federateStatus = async (status: StatusWithRelations) => {
const response = await fetch(request); const response = await fetch(request);
if (!response.ok) { if (!response.ok) {
console.error(await response.text()); dualLogger.log(
throw new Error( LogLevel.DEBUG,
"Federation.Status",
await response.text(),
);
dualLogger.log(
LogLevel.ERROR,
"Federation.Status",
`Failed to federate status ${status.id} to ${user.uri}`, `Failed to federate status ${status.id} to ${user.uri}`,
); );
} }

View file

@ -12,6 +12,8 @@ import {
relationship, relationship,
user, user,
} from "~drizzle/schema"; } from "~drizzle/schema";
import { dualLogger } from "@loggers";
import { LogLevel } from "~packages/log-manager";
import type { Account as APIAccount } from "~types/mastodon/account"; import type { Account as APIAccount } from "~types/mastodon/account";
import type { Source as APISource } from "~types/mastodon/source"; import type { Source as APISource } from "~types/mastodon/source";
import { import {
@ -191,8 +193,15 @@ export const followRequestUser = async (
const response = await fetch(request); const response = await fetch(request);
if (!response.ok) { if (!response.ok) {
console.error(await response.text()); dualLogger.log(
console.error( LogLevel.DEBUG,
"Federation.FollowRequest",
await response.text(),
);
dualLogger.log(
LogLevel.ERROR,
"Federation.FollowRequest",
`Failed to federate follow request from ${follower.id} to ${followee.uri}`, `Failed to federate follow request from ${follower.id} to ${followee.uri}`,
); );
@ -230,8 +239,15 @@ export const sendFollowAccept = async (follower: User, followee: User) => {
const response = await fetch(request); const response = await fetch(request);
if (!response.ok) { if (!response.ok) {
console.error(await response.text()); dualLogger.log(
throw new Error( LogLevel.DEBUG,
"Federation.FollowAccept",
await response.text(),
);
dualLogger.log(
LogLevel.ERROR,
"Federation.FollowAccept",
`Failed to federate follow accept from ${followee.id} to ${follower.uri}`, `Failed to federate follow accept from ${followee.id} to ${follower.uri}`,
); );
} }
@ -249,8 +265,15 @@ export const sendFollowReject = async (follower: User, followee: User) => {
const response = await fetch(request); const response = await fetch(request);
if (!response.ok) { if (!response.ok) {
console.error(await response.text()); dualLogger.log(
throw new Error( LogLevel.DEBUG,
"Federation.FollowReject",
await response.text(),
);
dualLogger.log(
LogLevel.ERROR,
"Federation.FollowReject",
`Failed to federate follow reject from ${followee.id} to ${follower.uri}`, `Failed to federate follow reject from ${followee.id} to ${follower.uri}`,
); );
} }

View file

@ -1,28 +1,15 @@
import { dualLogger } from "@loggers";
import { connectMeili } from "@meilisearch"; import { connectMeili } from "@meilisearch";
import { config } from "config-manager"; import { config } from "config-manager";
import { count } from "drizzle-orm"; import { count } from "drizzle-orm";
import { LogLevel, LogManager, MultiLogManager } from "log-manager"; import { LogLevel } from "log-manager";
import { db, setupDatabase } from "~drizzle/db"; import { db, setupDatabase } from "~drizzle/db";
import { status } from "~drizzle/schema"; import { status } from "~drizzle/schema";
import { createServer } from "~server"; import { createServer } from "~server";
const timeAtStart = performance.now(); const timeAtStart = performance.now();
const requests_log = Bun.file(config.logging.storage.requests);
const isEntry = import.meta.path === Bun.main;
const noColors = process.env.NO_COLORS === "true";
const noFancyDates = process.env.NO_FANCY_DATES === "true";
// If imported as a module, redirect logs to /dev/null to not pollute console (e.g. in tests) // If imported as a module, redirect logs to /dev/null to not pollute console (e.g. in tests)
const logger = new LogManager(isEntry ? requests_log : Bun.file("/dev/null"));
const consoleLogger = new LogManager(
isEntry ? Bun.stdout : Bun.file("/dev/null"),
!noColors,
!noFancyDates,
);
const dualLogger = new MultiLogManager([logger, consoleLogger]);
await dualLogger.log(LogLevel.INFO, "Lysand", "Starting Lysand..."); await dualLogger.log(LogLevel.INFO, "Lysand", "Starting Lysand...");
await setupDatabase(dualLogger); await setupDatabase(dualLogger);
@ -43,11 +30,9 @@ try {
)[0].count; )[0].count;
} catch (e) { } catch (e) {
const error = e as Error; const error = e as Error;
await logger.logError(LogLevel.CRITICAL, "Database", error); await dualLogger.logError(LogLevel.CRITICAL, "Database", error);
await consoleLogger.logError(LogLevel.CRITICAL, "Database", error);
process.exit(1); process.exit(1);
} }
const server = createServer(config, dualLogger, true); const server = createServer(config, dualLogger, true);
await dualLogger.log( await dualLogger.log(

View file

@ -336,6 +336,9 @@ export interface Config {
/** @default false */ /** @default false */
log_requests_verbose: boolean; log_requests_verbose: boolean;
/** @default "info" */
log_level: "info" | "debug" | "warning" | "error" | "critical";
/** @default false */ /** @default false */
log_ip: boolean; log_ip: boolean;
@ -591,6 +594,7 @@ export const defaultConfig: Config = {
logging: { logging: {
log_requests: false, log_requests: false,
log_requests_verbose: false, log_requests_verbose: false,
log_level: "info",
log_ip: false, log_ip: false,
log_filters: true, log_filters: true,
storage: { storage: {

View file

@ -2,6 +2,7 @@ import { appendFile, exists, mkdir } from "node:fs/promises";
import { dirname } from "node:path"; import { dirname } from "node:path";
import type { BunFile } from "bun"; import type { BunFile } from "bun";
import chalk from "chalk"; import chalk from "chalk";
import { config } from "config-manager";
export enum LogLevel { export enum LogLevel {
DEBUG = "debug", DEBUG = "debug",
@ -11,6 +12,14 @@ export enum LogLevel {
CRITICAL = "critical", CRITICAL = "critical",
} }
const logOrder = [
LogLevel.DEBUG,
LogLevel.INFO,
LogLevel.WARNING,
LogLevel.ERROR,
LogLevel.CRITICAL,
];
/** /**
* Class for handling logging to disk or to stdout * Class for handling logging to disk or to stdout
* @param output BunFile of output (can be a normal file or something like Bun.stdout) * @param output BunFile of output (can be a normal file or something like Bun.stdout)
@ -67,6 +76,12 @@ export class LogManager {
message: string, message: string,
showTimestamp = true, showTimestamp = true,
) { ) {
if (
logOrder.indexOf(level) <
logOrder.indexOf(config.logging.log_level as LogLevel)
)
return;
if (this.enableColors) { if (this.enableColors) {
await this.write( await this.write(
`${ `${
@ -113,6 +128,7 @@ export class LogManager {
* @param error Error to log * @param error Error to log
*/ */
async logError(level: LogLevel, entity: string, error: Error) { async logError(level: LogLevel, entity: string, error: Error) {
error.stack && (await this.log(LogLevel.DEBUG, entity, error.stack));
await this.log(level, entity, error.message); await this.log(level, entity, error.message);
} }

View file

@ -164,6 +164,11 @@ export const processRoute = async (
return output; return output;
} catch (err) { } catch (err) {
await logger.log(
LogLevel.DEBUG,
"Server.RouteHandler",
(err as Error).toString(),
);
await logger.logError( await logger.logError(
LogLevel.ERROR, LogLevel.ERROR,
"Server.RouteHandler", "Server.RouteHandler",

View file

@ -24,8 +24,21 @@ export const createServer = (
return errorResponse("Forbidden", 403); return errorResponse("Forbidden", 403);
} }
} catch (e) { } catch (e) {
console.error(`[-] Error while parsing banned IP "${ip}" `); logger.log(
throw e; LogLevel.ERROR,
"Server.IPCheck",
`Error while parsing banned IP "${ip}" `,
);
logger.logError(
LogLevel.ERROR,
"Server.IPCheck",
e as Error,
);
return errorResponse(
`A server error occured: ${(e as Error).message}`,
500,
);
} }
} }
@ -57,10 +70,21 @@ export const createServer = (
); );
} }
} catch (e) { } catch (e) {
console.error( logger.log(
`[-] Error while parsing bait IP "${ip}" `, LogLevel.ERROR,
"Server.IPCheck",
`Error while parsing bait IP "${ip}" `,
);
logger.logError(
LogLevel.ERROR,
"Server.IPCheck",
e as Error,
);
return errorResponse(
`A server error occured: ${(e as Error).message}`,
500,
); );
throw e;
} }
} }

View file

@ -1,5 +1,5 @@
import { afterAll, beforeAll, describe, expect, test } from "bun:test"; import { afterAll, beforeAll, describe, expect, test } from "bun:test";
import { config } from "~index"; import { config } from "config-manager";
import { import {
deleteOldTestUsers, deleteOldTestUsers,
getTestStatuses, getTestStatuses,

View file

@ -1,5 +1,5 @@
import { afterAll, describe, expect, test } from "bun:test"; import { afterAll, describe, expect, test } from "bun:test";
import { config } from "~index"; import { config } from "config-manager";
import { import {
deleteOldTestUsers, deleteOldTestUsers,
getTestUsers, getTestUsers,

View file

@ -17,6 +17,8 @@ import {
resolveWebFinger, resolveWebFinger,
userToAPI, userToAPI,
} from "~database/entities/User"; } from "~database/entities/User";
import { dualLogger } from "@loggers";
import { LogLevel } from "~packages/log-manager";
export const meta = applyConfig({ export const meta = applyConfig({
allowedMethods: ["GET"], allowedMethods: ["GET"],
@ -68,7 +70,11 @@ export default apiRoute<typeof meta, typeof schema>(
const [username, domain] = accountMatches[0].split("@"); const [username, domain] = accountMatches[0].split("@");
const foundAccount = await resolveWebFinger(username, domain).catch( const foundAccount = await resolveWebFinger(username, domain).catch(
(e) => { (e) => {
console.error(e); dualLogger.logError(
LogLevel.ERROR,
"WebFinger.Resolve",
e as Error,
);
return null; return null;
}, },
); );

View file

@ -1,5 +1,5 @@
import { afterAll, describe, expect, test } from "bun:test"; import { afterAll, describe, expect, test } from "bun:test";
import { config } from "~index"; import { config } from "config-manager";
import { import {
deleteOldTestUsers, deleteOldTestUsers,
getTestUsers, getTestUsers,

View file

@ -1,5 +1,5 @@
import { afterAll, beforeAll, describe, expect, test } from "bun:test"; import { afterAll, beforeAll, describe, expect, test } from "bun:test";
import { config } from "~index"; import { config } from "config-manager";
import { import {
deleteOldTestUsers, deleteOldTestUsers,
getTestStatuses, getTestStatuses,

View file

@ -1,5 +1,5 @@
import { afterAll, beforeAll, describe, expect, test } from "bun:test"; import { afterAll, beforeAll, describe, expect, test } from "bun:test";
import { config } from "~index"; import { config } from "config-manager";
import { import {
deleteOldTestUsers, deleteOldTestUsers,
getTestStatuses, getTestStatuses,

View file

@ -1,5 +1,5 @@
import { afterAll, describe, expect, test } from "bun:test"; import { afterAll, describe, expect, test } from "bun:test";
import { config } from "~index"; import { config } from "config-manager";
import { import {
deleteOldTestUsers, deleteOldTestUsers,
getTestUsers, getTestUsers,

View file

@ -1,5 +1,5 @@
import { afterAll, describe, expect, test } from "bun:test"; import { afterAll, describe, expect, test } from "bun:test";
import { config } from "~index"; import { config } from "config-manager";
import { import {
deleteOldTestUsers, deleteOldTestUsers,
getTestStatuses, getTestStatuses,

View file

@ -1,5 +1,5 @@
import { afterAll, describe, expect, test } from "bun:test"; import { afterAll, describe, expect, test } from "bun:test";
import { config } from "~index"; import { config } from "config-manager";
import { import {
deleteOldTestUsers, deleteOldTestUsers,
getTestStatuses, getTestStatuses,

View file

@ -12,6 +12,8 @@ import {
} from "~database/entities/User"; } from "~database/entities/User";
import { db } from "~drizzle/db"; import { db } from "~drizzle/db";
import { instance, user } from "~drizzle/schema"; import { instance, user } from "~drizzle/schema";
import { dualLogger } from "@loggers";
import { LogLevel } from "~packages/log-manager";
export const meta = applyConfig({ export const meta = applyConfig({
allowedMethods: ["GET"], allowedMethods: ["GET"],
@ -117,7 +119,11 @@ export default apiRoute<typeof meta, typeof schema>(
username, username,
domain, domain,
).catch((e) => { ).catch((e) => {
console.error(e); dualLogger.logError(
LogLevel.ERROR,
"WebFinger.Resolve",
e,
);
return null; return null;
}); });

View file

@ -11,6 +11,8 @@ import {
} from "~database/entities/User"; } from "~database/entities/User";
import { db } from "~drizzle/db"; import { db } from "~drizzle/db";
import { notification, relationship } from "~drizzle/schema"; import { notification, relationship } from "~drizzle/schema";
import { dualLogger } from "@loggers";
import { LogLevel } from "~packages/log-manager";
export const meta = applyConfig({ export const meta = applyConfig({
allowedMethods: ["POST"], allowedMethods: ["POST"],
@ -126,7 +128,11 @@ export default apiRoute(async (req, matchedRoute, extraData) => {
const newStatus = await resolveStatus(undefined, note).catch( const newStatus = await resolveStatus(undefined, note).catch(
(e) => { (e) => {
console.error(e); dualLogger.logError(
LogLevel.ERROR,
"Inbox.NoteResolve",
e as Error,
);
return null; return null;
}, },
); );

18
utils/loggers.ts Normal file
View file

@ -0,0 +1,18 @@
import { LogManager, MultiLogManager } from "log-manager";
import { config } from "config-manager";
const noColors = process.env.NO_COLORS === "true";
const noFancyDates = process.env.NO_FANCY_DATES === "true";
const requests_log = Bun.file(config.logging.storage.requests);
export const logger = new LogManager(
true ? requests_log : Bun.file("/dev/null"),
);
export const consoleLogger = new LogManager(
true ? Bun.stdout : Bun.file("/dev/null"),
!noColors,
!noFancyDates,
);
export const dualLogger = new MultiLogManager([logger, consoleLogger]);