mirror/ditto
mirror/ditto
1
0
Fork 0
mirror of https://gitlab.com/soapbox-pub/ditto.git synced 2025-12-06 11:29:46 +00:00
Code Issues Projects Releases Packages Wiki Activity Actions

Merge branch 'logi' into 'main'

Browse source 
Switch to JSON logging

See merge request soapbox-pub/ditto!626
This commit is contained in:
Alex Gleason 2025-01-28 00:15:58 +00:00
commit 05c90fb677
34 changed files with 295 additions and 171 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

2
deno.json
View file

@ -52,8 +52,8 @@
"@scure/base": "npm:@scure/base@^1.1.6",
"@sentry/deno": "https://deno.land/x/sentry@7.112.2/index.mjs",
"@soapbox/kysely-pglite": "jsr:@soapbox/kysely-pglite@^1.0.0",
"@soapbox/logi": "jsr:@soapbox/logi@^0.1.3",
"@soapbox/safe-fetch": "jsr:@soapbox/safe-fetch@^2.0.0",
"@soapbox/stickynotes": "jsr:@soapbox/stickynotes@^0.4.0",
"@std/assert": "jsr:@std/assert@^0.225.1",
"@std/cli": "jsr:@std/cli@^0.223.0",
"@std/crypto": "jsr:@std/crypto@^0.224.0",

10
deno.lock generated
View file

@ -49,8 +49,8 @@
"jsr:@nostrify/types@0.36": "0.36.0",
"jsr:@nostrify/types@~0.30.1": "0.30.1",
"jsr:@soapbox/kysely-pglite@1": "1.0.0",
"jsr:@soapbox/logi@~0.1.3": "0.1.3",
"jsr:@soapbox/safe-fetch@2": "2.0.0",
"jsr:@soapbox/stickynotes@0.4": "0.4.0",
"jsr:@std/assert@0.223": "0.223.0",
"jsr:@std/assert@0.224": "0.224.0",
"jsr:@std/assert@~0.213.1": "0.213.1",
@ -526,15 +526,15 @@
"npm:kysely@~0.27.4"
]
},
"@soapbox/logi@0.1.3": {
"integrity": "1b974f26550d2eba08171f2374ae39876b55a5e7c2780a08b8d04cda86f6f5f2"
},
"@soapbox/safe-fetch@2.0.0": {
"integrity": "f451d686501c76a0faa058fe9d2073676282a8a42c3b93c59159eb9191f11b5f",
"dependencies": [
"npm:tldts@^6.1.61"
]
},
"@soapbox/stickynotes@0.4.0": {
"integrity": "60bfe61ab3d7e04bf708273b1e2d391a59534bdf29e54160e98d7afd328ca1ec"
},
"@std/assert@0.213.1": {
"integrity": "24c28178b30c8e0782c18e8e94ea72b16282207569cdd10ffb9d1d26f2edebfe"
},
@ -2353,8 +2353,8 @@
"jsr:@nostrify/policies@~0.36.1",
"jsr:@nostrify/types@0.36",
"jsr:@soapbox/kysely-pglite@1",
"jsr:@soapbox/logi@~0.1.3",
"jsr:@soapbox/safe-fetch@2",
"jsr:@soapbox/stickynotes@0.4",
"jsr:@std/assert@~0.225.1",
"jsr:@std/cli@0.223",
"jsr:@std/crypto@0.224",

7
src/DittoPush.ts
View file

@ -1,4 +1,5 @@
import { ApplicationServer, PushMessageOptions, PushSubscriber, PushSubscription } from '@negrel/webpush';
import { logi } from '@soapbox/logi';
import { Conf } from '@/config.ts';
import { Storages } from '@/storages.ts';
@ -20,7 +21,11 @@ export class DittoPush {
vapidKeys: keys,
});
} else {
console.warn('VAPID keys are not set. Push notifications will be disabled.');
logi({
level: 'warn',
ns: 'ditto.push',
message: 'VAPID keys are not set. Push notifications will be disabled.',
});
}
})();
}

13
src/app.ts
View file

@ -2,9 +2,7 @@ import { type Context, Env as HonoEnv, Handler, Hono, Input as HonoInput, Middle
import { every } from '@hono/hono/combine';
import { cors } from '@hono/hono/cors';
import { serveStatic } from '@hono/hono/deno';
import { logger } from '@hono/hono/logger';
import { NostrEvent, NostrSigner, NStore, NUploader } from '@nostrify/nostrify';
import Debug from '@soapbox/stickynotes/debug';
import { Kysely } from 'kysely';
import '@/startup.ts';
@ -142,6 +140,7 @@ import { signerMiddleware } from '@/middleware/signerMiddleware.ts';
import { storeMiddleware } from '@/middleware/storeMiddleware.ts';
import { uploaderMiddleware } from '@/middleware/uploaderMiddleware.ts';
import { translatorMiddleware } from '@/middleware/translatorMiddleware.ts';
import { logiMiddleware } from '@/middleware/logiMiddleware.ts';
export interface AppEnv extends HonoEnv {
Variables: {
@ -170,8 +169,6 @@ type AppController = Handler<AppEnv, any, HonoInput, Response | Promise<Response
const app = new Hono<AppEnv>({ strict: false });
const debug = Debug('ditto:http');
/** User-provided files in the gitignored `public/` directory. */
const publicFiles = serveStatic({ root: './public/' });
/** Static files provided by the Ditto repo, checked into git. */
@ -184,10 +181,10 @@ const ratelimit = every(
rateLimitMiddleware(300, Time.minutes(5), false),
);
app.use('/api/*', metricsMiddleware, ratelimit, paginationMiddleware, logger(debug));
app.use('/.well-known/*', metricsMiddleware, ratelimit, logger(debug));
app.use('/nodeinfo/*', metricsMiddleware, ratelimit, logger(debug));
app.use('/oauth/*', metricsMiddleware, ratelimit, logger(debug));
app.use('/api/*', metricsMiddleware, ratelimit, paginationMiddleware, logiMiddleware);
app.use('/.well-known/*', metricsMiddleware, ratelimit, logiMiddleware);
app.use('/nodeinfo/*', metricsMiddleware, ratelimit, logiMiddleware);
app.use('/oauth/*', metricsMiddleware, ratelimit, logiMiddleware);
app.get('/api/v1/streaming', metricsMiddleware, ratelimit, streamingController);
app.get('/relay', metricsMiddleware, ratelimit, relayController);

10
src/controllers/api/admin.ts
View file

@ -1,4 +1,5 @@
import { NostrFilter } from '@nostrify/nostrify';
import { logi } from '@soapbox/logi';
import { z } from 'zod';
import { type AppController } from '@/app.ts';
@ -9,6 +10,7 @@ import { hydrateEvents } from '@/storages/hydrate.ts';
import { createAdminEvent, paginated, parseBody, updateEventInfo, updateUser } from '@/utils/api.ts';
import { renderNameRequest } from '@/views/ditto.ts';
import { renderAdminAccount, renderAdminAccountFromPubkey } from '@/views/mastodon/admin-accounts.ts';
import { errorJson } from '@/utils/log.ts';
const adminAccountQuerySchema = z.object({
local: booleanParamSchema.optional(),
@ -148,11 +150,15 @@ const adminActionController: AppController = async (c) => {
if (data.type === 'suspend') {
n.disabled = true;
n.suspended = true;
store.remove([{ authors: [authorId] }]).catch(console.warn);
store.remove([{ authors: [authorId] }]).catch((e: unknown) => {
logi({ level: 'error', ns: 'ditto.api.admin.account.action', type: data.type, error: errorJson(e) });
});
}
if (data.type === 'revoke_name') {
n.revoke_name = true;
store.remove([{ kinds: [30360], authors: [Conf.pubkey], '#p': [authorId] }]).catch(console.warn);
store.remove([{ kinds: [30360], authors: [Conf.pubkey], '#p': [authorId] }]).catch((e: unknown) => {
logi({ level: 'error', ns: 'ditto.api.admin.account.action', type: data.type, error: errorJson(e) });
});
}
await updateUser(authorId, n, c);

6
src/controllers/api/media.ts
View file

@ -1,11 +1,13 @@
import { logi } from '@soapbox/logi';
import { z } from 'zod';
import { AppController } from '@/app.ts';
import { dittoUploads } from '@/DittoUploads.ts';
import { fileSchema } from '@/schema.ts';
import { parseBody } from '@/utils/api.ts';
import { renderAttachment } from '@/views/mastodon/attachments.ts';
import { errorJson } from '@/utils/log.ts';
import { uploadFile } from '@/utils/upload.ts';
import { dittoUploads } from '@/DittoUploads.ts';
const mediaBodySchema = z.object({
file: fileSchema,
@ -32,7 +34,7 @@ const mediaController: AppController = async (c) => {
const media = await uploadFile(c, file, { pubkey, description }, signal);
return c.json(renderAttachment(media));
} catch (e) {
console.error(e);
logi({ level: 'error', ns: 'ditto.api.media', error: errorJson(e) });
return c.json({ error: 'Failed to upload file.' }, 500);
}
};

8
src/controllers/api/streaming.ts
View file

@ -1,6 +1,6 @@
import TTLCache from '@isaacs/ttlcache';
import { NostrEvent, NostrFilter } from '@nostrify/nostrify';
import { Stickynotes } from '@soapbox/stickynotes';
import { logi } from '@soapbox/logi';
import { z } from 'zod';
import { type AppController } from '@/app.ts';
@ -15,13 +15,12 @@ import { getFeedPubkeys } from '@/queries.ts';
import { hydrateEvents } from '@/storages/hydrate.ts';
import { Storages } from '@/storages.ts';
import { getTokenHash } from '@/utils/auth.ts';
import { errorJson } from '@/utils/log.ts';
import { bech32ToPubkey, Time } from '@/utils.ts';
import { renderReblog, renderStatus } from '@/views/mastodon/statuses.ts';
import { renderNotification } from '@/views/mastodon/notifications.ts';
import { HTTPException } from '@hono/hono/http-exception';
const console = new Stickynotes('ditto:streaming');
/**
* Streaming timelines/categories.
* https://docs.joinmastodon.org/methods/streaming/#streams
@ -101,7 +100,6 @@ const streamingController: AppController = async (c) => {
function send(e: StreamingEvent) {
if (socket.readyState === WebSocket.OPEN) {
console.debug('send', e.event, e.payload);
streamingServerMessagesCounter.inc();
socket.send(JSON.stringify(e));
}
@ -130,7 +128,7 @@ const streamingController: AppController = async (c) => {
}
}
} catch (e) {
console.debug('streaming error:', e);
logi({ level: 'error', ns: 'ditto.streaming', message: 'Error in streaming', error: errorJson(e) });
}
}

38
src/controllers/api/trends.ts
View file

@ -1,4 +1,5 @@
import { NostrEvent, NostrFilter, NStore } from '@nostrify/nostrify';
import { logi } from '@soapbox/logi';
import { z } from 'zod';
import { AppController } from '@/app.ts';
@ -9,10 +10,17 @@ import { Storages } from '@/storages.ts';
import { generateDateRange, Time } from '@/utils/time.ts';
import { unfurlCardCached } from '@/utils/unfurl.ts';
import { paginated } from '@/utils/api.ts';
import { errorJson } from '@/utils/log.ts';
import { renderStatus } from '@/views/mastodon/statuses.ts';
let trendingHashtagsCache = getTrendingHashtags().catch((e) => {
console.error(`Failed to get trending hashtags: ${e}`);
let trendingHashtagsCache = getTrendingHashtags().catch((e: unknown) => {
logi({
level: 'error',
ns: 'ditto.trends.api',
type: 'tags',
message: 'Failed to get trending hashtags',
error: errorJson(e),
});
return Promise.resolve([]);
});
@ -21,7 +29,13 @@ Deno.cron('update trending hashtags cache', '35 * * * *', async () => {
const trends = await getTrendingHashtags();
trendingHashtagsCache = Promise.resolve(trends);
} catch (e) {
console.error(e);
logi({
level: 'error',
ns: 'ditto.trends.api',
type: 'tags',
message: 'Failed to get trending hashtags',
error: errorJson(e),
});
}
});
@ -57,8 +71,14 @@ async function getTrendingHashtags() {
});
}
let trendingLinksCache = getTrendingLinks().catch((e) => {
console.error(`Failed to get trending links: ${e}`);
let trendingLinksCache = getTrendingLinks().catch((e: unknown) => {
logi({
level: 'error',
ns: 'ditto.trends.api',
type: 'links',
message: 'Failed to get trending links',
error: errorJson(e),
});
return Promise.resolve([]);
});
@ -67,7 +87,13 @@ Deno.cron('update trending links cache', '50 * * * *', async () => {
const trends = await getTrendingLinks();
trendingLinksCache = Promise.resolve(trends);
} catch (e) {
console.error(e);
logi({
level: 'error',
ns: 'ditto.trends.api',
type: 'links',
message: 'Failed to get trending links',
error: errorJson(e),
});
}
});

5
src/controllers/error.ts
View file

@ -1,5 +1,8 @@
import { ErrorHandler } from '@hono/hono';
import { HTTPException } from '@hono/hono/http-exception';
import { logi } from '@soapbox/logi';
import { errorJson } from '@/utils/log.ts';
export const errorHandler: ErrorHandler = (err, c) => {
c.header('Cache-Control', 'no-store');
@ -16,7 +19,7 @@ export const errorHandler: ErrorHandler = (err, c) => {
return c.json({ error: 'The server was unable to respond in a timely manner' }, 500);
}
console.error(err);
logi({ level: 'error', ns: 'ditto.http', message: 'Unhandled error', error: errorJson(err) });
return c.json({ error: 'Something went wrong' }, 500);
};

8
src/controllers/frontend.ts
View file

@ -1,16 +1,16 @@
import { logi } from '@soapbox/logi';
import { AppMiddleware } from '@/app.ts';
import { Stickynotes } from '@soapbox/stickynotes';
import { Storages } from '@/storages.ts';
import { getPathParams, MetadataEntities } from '@/utils/og-metadata.ts';
import { getInstanceMetadata } from '@/utils/instance.ts';
import { errorJson } from '@/utils/log.ts';
import { lookupPubkey } from '@/utils/lookup.ts';
import { renderMetadata } from '@/views/meta.ts';
import { getAuthor, getEvent } from '@/queries.ts';
import { renderStatus } from '@/views/mastodon/statuses.ts';
import { renderAccount } from '@/views/mastodon/accounts.ts';
const console = new Stickynotes('ditto:frontend');
/** Placeholder to find & replace with metadata. */
const META_PLACEHOLDER = '<!--server-generated-meta-->' as const;
@ -27,7 +27,7 @@ export const frontendController: AppMiddleware = async (c) => {
const meta = renderMetadata(c.req.url, entities);
return c.html(content.replace(META_PLACEHOLDER, meta));
} catch (e) {
console.log(`Error building meta tags: ${e}`);
logi({ level: 'error', ns: 'ditto.frontend', message: 'Error building meta tags', error: errorJson(e) });
return c.html(content);
}
}

9
src/controllers/nostr/relay.ts
View file

@ -1,4 +1,4 @@
import { Stickynotes } from '@soapbox/stickynotes';
import { logi } from '@soapbox/logi';
import {
NKinds,
NostrClientCLOSE,
@ -17,11 +17,12 @@ import { relayConnectionsGauge, relayEventsCounter, relayMessagesCounter } from
import * as pipeline from '@/pipeline.ts';
import { RelayError } from '@/RelayError.ts';
import { Storages } from '@/storages.ts';
import { Time } from '@/utils/time.ts';
import { errorJson } from '@/utils/log.ts';
import { purifyEvent } from '@/utils/purify.ts';
import { MemoryRateLimiter } from '@/utils/ratelimiter/MemoryRateLimiter.ts';
import { MultiRateLimiter } from '@/utils/ratelimiter/MultiRateLimiter.ts';
import { RateLimiter } from '@/utils/ratelimiter/types.ts';
import { Time } from '@/utils/time.ts';
/** Limit of initial events returned for a subscription. */
const FILTER_LIMIT = 100;
@ -44,8 +45,6 @@ const limiters = {
/** Connections for metrics purposes. */
const connections = new Set<WebSocket>();
const console = new Stickynotes('ditto:relay');
/** Set up the Websocket connection. */
function connectStream(socket: WebSocket, ip: string | undefined) {
const controllers = new Map<string, AbortController>();
@ -169,7 +168,7 @@ function connectStream(socket: WebSocket, ip: string | undefined) {
send(['OK', event.id, false, e.message]);
} else {
send(['OK', event.id, false, 'error: something went wrong']);
console.error(e);
logi({ level: 'error', ns: 'ditto.relay', message: 'Error in relay', error: errorJson(e) });
}
}
}

27
src/db/DittoDB.ts
View file

@ -1,12 +1,15 @@
import fs from 'node:fs/promises';
import path from 'node:path';
import { logi } from '@soapbox/logi';
import { JsonValue } from '@std/json';
import { FileMigrationProvider, Kysely, Migrator } from 'kysely';
import { DittoPglite } from '@/db/adapters/DittoPglite.ts';
import { DittoPostgres } from '@/db/adapters/DittoPostgres.ts';
import { DittoDatabase, DittoDatabaseOpts } from '@/db/DittoDatabase.ts';
import { DittoTables } from '@/db/DittoTables.ts';
import { errorJson } from '@/utils/log.ts';
export class DittoDB {
/** Open a new database connection. */
@ -36,20 +39,30 @@ export class DittoDB {
}),
});
console.warn('Running migrations...');
logi({ level: 'info', ns: 'ditto.db.migration', message: 'Running migrations...', state: 'started' });
const { results, error } = await migrator.migrateToLatest();
if (error) {
console.error(error);
logi({
level: 'fatal',
ns: 'ditto.db.migration',
message: 'Migration failed.',
state: 'failed',
results: results as unknown as JsonValue,
error: errorJson(error),
});
Deno.exit(1);
} else {
if (!results?.length) {
console.warn('Everything up-to-date.');
logi({ level: 'info', ns: 'ditto.db.migration', message: 'Everything up-to-date.', state: 'skipped' });
} else {
console.warn('Migrations finished!');
for (const { migrationName, status } of results!) {
console.warn(` - ${migrationName}: ${status}`);
}
logi({
level: 'info',
ns: 'ditto.db.migration',
message: 'Migrations finished!',
state: 'migrated',
results: results as unknown as JsonValue,
});
}
}
}

33
src/db/KyselyLogger.ts
View file

@ -1,22 +1,33 @@
import { Stickynotes } from '@soapbox/stickynotes';
import { logi } from '@soapbox/logi';
import { Logger } from 'kysely';
import { dbQueriesCounter, dbQueryDurationHistogram } from '@/metrics.ts';
import { errorJson } from '@/utils/log.ts';
/** Log the SQL for queries. */
export const KyselyLogger: Logger = (event) => {
const console = new Stickynotes('ditto:sql');
const { query, queryDurationMillis } = event;
const { sql, parameters } = query;
const { sql } = query;
const queryDurationSeconds = queryDurationMillis / 1000;
const duration = queryDurationMillis / 1000;
dbQueriesCounter.inc();
dbQueryDurationHistogram.observe(queryDurationSeconds);
dbQueryDurationHistogram.observe(duration);
console.debug(
sql,
JSON.stringify(parameters),
`\x1b[90m(${(queryDurationSeconds / 1000).toFixed(2)}s)\x1b[0m`,
);
/** Parameters serialized to JSON. */
const parameters = query.parameters.map((parameter) => {
try {
return JSON.stringify(parameter);
} catch {
return String(parameter);
}
});
if (event.level === 'query') {
logi({ level: 'debug', ns: 'ditto.sql', sql, parameters, duration });
}
if (event.level === 'error') {
logi({ level: 'error', ns: 'ditto.sql', sql, parameters, error: errorJson(event.error), duration });
}
};

9
src/firehose.ts
View file

@ -1,5 +1,5 @@
import { Semaphore } from '@lambdalisue/async';
import { Stickynotes } from '@soapbox/stickynotes';
import { logi } from '@soapbox/logi';
import { Conf } from '@/config.ts';
import { firehoseEventsCounter } from '@/metrics.ts';
@ -8,7 +8,6 @@ import { nostrNow } from '@/utils.ts';
import * as pipeline from '@/pipeline.ts';
const console = new Stickynotes('ditto:firehose');
const sem = new Semaphore(Conf.firehoseConcurrency);
/**
@ -22,14 +21,14 @@ export async function startFirehose(): Promise<void> {
for await (const msg of store.req([{ kinds: Conf.firehoseKinds, limit: 0, since: nostrNow() }])) {
if (msg[0] === 'EVENT') {
const event = msg[2];
console.debug(`NostrEvent<${event.kind}> ${event.id}`);
logi({ level: 'debug', ns: 'ditto.event', source: 'firehose', id: event.id, kind: event.kind });
firehoseEventsCounter.inc({ kind: event.kind });
sem.lock(async () => {
try {
await pipeline.handleEvent(event, { source: 'firehose', signal: AbortSignal.timeout(5000) });
} catch (e) {
console.warn(e);
} catch {
// Ignore
}
});
}

18
src/middleware/logiMiddleware.ts Normal file
View file

@ -0,0 +1,18 @@
import { MiddlewareHandler } from '@hono/hono';
import { logi } from '@soapbox/logi';
export const logiMiddleware: MiddlewareHandler = async (c, next) => {
const { method } = c.req;
const { pathname } = new URL(c.req.url);
logi({ level: 'info', ns: 'ditto.http.request', method, pathname });
const start = new Date();
await next();
const end = new Date();
const delta = (end.getTime() - start.getTime()) / 1000;
logi({ level: 'info', ns: 'ditto.http.response', method, pathname, status: c.res.status, delta });
};

12
src/notify.ts
View file

@ -1,13 +1,12 @@
import { Semaphore } from '@lambdalisue/async';
import { Stickynotes } from '@soapbox/stickynotes';
import { pipelineEncounters } from '@/caches/pipelineEncounters.ts';
import { Conf } from '@/config.ts';
import * as pipeline from '@/pipeline.ts';
import { Storages } from '@/storages.ts';
import { logi } from '@soapbox/logi';
const sem = new Semaphore(1);
const console = new Stickynotes('ditto:notify');
export async function startNotify(): Promise<void> {
const { listen } = await Storages.database();
@ -15,10 +14,12 @@ export async function startNotify(): Promise<void> {
listen('nostr_event', (id) => {
if (pipelineEncounters.has(id)) {
console.debug(`Skip event ${id} because it was already in the pipeline`);
logi({ level: 'debug', ns: 'ditto.notify', id, skipped: true });
return;
}
logi({ level: 'debug', ns: 'ditto.notify', id, skipped: false });
sem.lock(async () => {
try {
const signal = AbortSignal.timeout(Conf.db.timeouts.default);
@ -26,10 +27,11 @@ export async function startNotify(): Promise<void> {
const [event] = await store.query([{ ids: [id], limit: 1 }], { signal });
if (event) {
logi({ level: 'debug', ns: 'ditto.event', source: 'notify', id: event.id, kind: event.kind });
await pipeline.handleEvent(event, { source: 'notify', signal });
}
} catch (e) {
console.warn(e);
} catch {
// Ignore
}
});
});

18
src/pipeline.ts
View file

@ -1,8 +1,9 @@
import { NKinds, NostrEvent, NSchema as n } from '@nostrify/nostrify';
import { Stickynotes } from '@soapbox/stickynotes';
import { logi } from '@soapbox/logi';
import { Kysely, sql } from 'kysely';
import { z } from 'zod';
import { pipelineEncounters } from '@/caches/pipelineEncounters.ts';
import { Conf } from '@/config.ts';
import { DittoTables } from '@/db/DittoTables.ts';
import { DittoPush } from '@/DittoPush.ts';
@ -15,6 +16,7 @@ import { Storages } from '@/storages.ts';
import { eventAge, parseNip05, Time } from '@/utils.ts';
import { getAmount } from '@/utils/bolt11.ts';
import { detectLanguage } from '@/utils/language.ts';
import { errorJson } from '@/utils/log.ts';
import { nip05Cache } from '@/utils/nip05.ts';
import { purifyEvent } from '@/utils/purify.ts';
import { updateStats } from '@/utils/stats.ts';
@ -22,9 +24,6 @@ import { getTagSet } from '@/utils/tags.ts';
import { renderWebPushNotification } from '@/views/mastodon/push.ts';
import { policyWorker } from '@/workers/policy.ts';
import { verifyEventWorker } from '@/workers/verify.ts';
import { pipelineEncounters } from '@/caches/pipelineEncounters.ts';
const console = new Stickynotes('ditto:pipeline');
interface PipelineOpts {
signal: AbortSignal;
@ -69,7 +68,7 @@ async function handleEvent(event: DittoEvent, opts: PipelineOpts): Promise<void>
pipelineEncounters.set(event.id, true);
// Log the event.
console.info(`NostrEvent<${event.kind}> ${event.id}`);
logi({ level: 'debug', ns: 'ditto.event', source: 'pipeline', id: event.id, kind: event.kind });
pipelineEventsCounter.inc({ kind: event.kind });
// NIP-46 events get special treatment.
@ -135,18 +134,17 @@ async function handleEvent(event: DittoEvent, opts: PipelineOpts): Promise<void>
}
async function policyFilter(event: NostrEvent, signal: AbortSignal): Promise<void> {
const console = new Stickynotes('ditto:policy');
try {
const result = await policyWorker.call(event, signal);
policyEventsCounter.inc({ ok: String(result[2]) });
console.debug(JSON.stringify(result));
const [, , ok, reason] = result;
logi({ level: 'debug', ns: 'ditto.policy', id: event.id, kind: event.kind, ok, reason });
policyEventsCounter.inc({ ok: String(ok) });
RelayError.assert(result);
} catch (e) {
if (e instanceof RelayError) {
throw e;
} else {
console.error(e);
logi({ level: 'error', ns: 'ditto.policy', id: event.id, kind: event.kind, error: errorJson(e) });
throw new RelayError('blocked', 'policy error');
}
}

9
src/queries.ts
View file

@ -1,5 +1,4 @@
import { NostrEvent, NostrFilter, NStore } from '@nostrify/nostrify';
import Debug from '@soapbox/stickynotes/debug';
import { Conf } from '@/config.ts';
import { Storages } from '@/storages.ts';
@ -9,8 +8,6 @@ import { hydrateEvents } from '@/storages/hydrate.ts';
import { fallbackAuthor } from '@/utils.ts';
import { findReplyTag, getTagSet } from '@/utils/tags.ts';
const debug = Debug('ditto:queries');
interface GetEventOpts {
/** Signal to abort the request. */
signal?: AbortSignal;
@ -20,12 +17,14 @@ interface GetEventOpts {
relations?: DittoRelation[];
}
/** Get a Nostr event by its ID. */
/**
* Get a Nostr event by its ID.
* @deprecated Use `store.query` directly.
*/
const getEvent = async (
id: string,
opts: GetEventOpts = {},
): Promise<DittoEvent | undefined> => {
debug(`getEvent: ${id}`);
const store = await Storages.db();
const { kind, signal = AbortSignal.timeout(1000) } = opts;

5
src/sentry.ts
View file

@ -1,12 +1,15 @@
import * as Sentry from '@sentry/deno';
import { logi } from '@soapbox/logi';
import { Conf } from '@/config.ts';
// Sentry
if (Conf.sentryDsn) {
console.log('Sentry enabled');
logi({ level: 'info', ns: 'ditto.sentry', message: 'Sentry enabled.', enabled: true });
Sentry.init({
dsn: Conf.sentryDsn,
tracesSampleRate: 1.0,
});
} else {
logi({ level: 'info', ns: 'ditto.sentry', message: 'Sentry not configured. Skipping.', enabled: false });
}

9
src/server.ts
View file

@ -1,7 +1,14 @@
import { logi } from '@soapbox/logi';
import '@/precheck.ts';
import '@/sentry.ts';
import '@/nostr-wasm.ts';
import app from '@/app.ts';
import { Conf } from '@/config.ts';
Deno.serve({ port: Conf.port }, app.fetch);
Deno.serve({
port: Conf.port,
onListen({ hostname, port }): void {
logi({ level: 'info', ns: 'ditto.server', message: `Listening on http://${hostname}:${port}`, hostname, port });
},
}, app.fetch);

9
src/storages.ts
View file

@ -1,4 +1,6 @@
// deno-lint-ignore-file require-await
import { logi } from '@soapbox/logi';
import { Conf } from '@/config.ts';
import { DittoDatabase } from '@/db/DittoDatabase.ts';
import { DittoDB } from '@/db/DittoDB.ts';
@ -89,7 +91,12 @@ export class Storages {
return acc;
}, []);
console.log(`pool: connecting to ${activeRelays.length} relays.`);
logi({
level: 'info',
ns: 'ditto.pool',
message: `connecting to ${activeRelays.length} relays`,
relays: activeRelays,
});
return new NPool({
open(url) {

13
src/storages/EventsDB.ts
View file

@ -3,7 +3,8 @@
import { LanguageCode } from 'iso-639-1';
import { NPostgres, NPostgresSchema } from '@nostrify/db';
import { NIP50, NKinds, NostrEvent, NostrFilter, NSchema as n } from '@nostrify/nostrify';
import { Stickynotes } from '@soapbox/stickynotes';
import { logi } from '@soapbox/logi';
import { JsonValue } from '@std/json';
import { Kysely, SelectQueryBuilder } from 'kysely';
import { nip27 } from 'nostr-tools';
@ -36,8 +37,6 @@ interface EventsDBOpts {
/** SQL database storage adapter for Nostr events. */
class EventsDB extends NPostgres {
private console = new Stickynotes('ditto:db:events');
/** Conditions for when to index certain tags. */
static tagConditions: Record<string, TagCondition> = {
'a': ({ count }) => count < 15,
@ -65,7 +64,7 @@ class EventsDB extends NPostgres {
/** Insert an event (and its tags) into the database. */
override async event(event: NostrEvent, opts: { signal?: AbortSignal; timeout?: number } = {}): Promise<void> {
event = purifyEvent(event);
this.console.debug('EVENT', JSON.stringify(event));
logi({ level: 'debug', ns: 'ditto.event', source: 'db', id: event.id, kind: event.kind });
dbEventsCounter.inc({ kind: event.kind });
if (await this.isDeletedAdmin(event)) {
@ -198,7 +197,7 @@ class EventsDB extends NPostgres {
if (opts.signal?.aborted) return Promise.resolve([]);
this.console.debug('REQ', JSON.stringify(filters));
logi({ level: 'debug', ns: 'ditto.req', source: 'db', filters: filters as JsonValue });
return super.query(filters, { ...opts, timeout: opts.timeout ?? this.opts.timeout });
}
@ -228,7 +227,7 @@ class EventsDB extends NPostgres {
/** Delete events based on filters from the database. */
override async remove(filters: NostrFilter[], opts: { signal?: AbortSignal; timeout?: number } = {}): Promise<void> {
this.console.debug('DELETE', JSON.stringify(filters));
logi({ level: 'debug', ns: 'ditto.remove', source: 'db', filters: filters as JsonValue });
return super.remove(filters, { ...opts, timeout: opts.timeout ?? this.opts.timeout });
}
@ -239,7 +238,7 @@ class EventsDB extends NPostgres {
): Promise<{ count: number; approximate: any }> {
if (opts.signal?.aborted) return Promise.reject(abortError());
this.console.debug('COUNT', JSON.stringify(filters));
logi({ level: 'debug', ns: 'ditto.count', source: 'db', filters: filters as JsonValue });
return super.count(filters, { ...opts, timeout: opts.timeout ?? this.opts.timeout });
}

11
src/storages/search-store.ts
View file

@ -1,5 +1,6 @@
import { NostrEvent, NostrFilter, NRelay1, NStore } from '@nostrify/nostrify';
import Debug from '@soapbox/stickynotes/debug';
import { logi } from '@soapbox/logi';
import { JsonValue } from '@std/json';
import { normalizeFilters } from '@/filter.ts';
import { type DittoEvent } from '@/interfaces/DittoEvent.ts';
@ -13,8 +14,6 @@ interface SearchStoreOpts {
}
class SearchStore implements NStore {
#debug = Debug('ditto:storages:search');
#fallback: NStore;
#hydrator: NStore;
#relay: NRelay1 | undefined;
@ -38,11 +37,11 @@ class SearchStore implements NStore {
if (opts?.signal?.aborted) return Promise.reject(abortError());
if (!filters.length) return Promise.resolve([]);
this.#debug('REQ', JSON.stringify(filters));
logi({ level: 'debug', ns: 'ditto.req', source: 'search', filters: filters as JsonValue });
const query = filters[0]?.search;
if (this.#relay && this.#relay.socket.readyState === WebSocket.OPEN) {
this.#debug(`Searching for "${query}" at ${this.#relay.socket.url}...`);
logi({ level: 'debug', ns: 'ditto.search', query, source: 'relay', relay: this.#relay.socket.url });
const events = await this.#relay.query(filters, opts);
@ -52,7 +51,7 @@ class SearchStore implements NStore {
signal: opts?.signal,
});
} else {
this.#debug(`Searching for "${query}" locally...`);
logi({ level: 'debug', ns: 'ditto.search', query, source: 'db' });
return this.#fallback.query(filters, opts);
}
}

20
src/trends.ts
View file

@ -1,5 +1,5 @@
import { NostrFilter } from '@nostrify/nostrify';
import { Stickynotes } from '@soapbox/stickynotes';
import { logi } from '@soapbox/logi';
import { Kysely, sql } from 'kysely';
import { Conf } from '@/config.ts';
@ -7,10 +7,9 @@ import { DittoTables } from '@/db/DittoTables.ts';
import { handleEvent } from '@/pipeline.ts';
import { AdminSigner } from '@/signers/AdminSigner.ts';
import { Storages } from '@/storages.ts';
import { errorJson } from '@/utils/log.ts';
import { Time } from '@/utils/time.ts';
const console = new Stickynotes('ditto:trends');
/** Get trending tag values for a given tag in the given time frame. */
export async function getTrendingTagValues(
/** Kysely instance to execute queries on. */
@ -75,7 +74,9 @@ export async function updateTrendingTags(
aliases?: string[],
values?: string[],
) {
console.info(`Updating trending ${l}...`);
const params = { l, tagName, kinds, limit, extra, aliases, values };
logi({ level: 'info', ns: 'ditto.trends', message: 'Updating trending', ...params });
const kysely = await Storages.kysely();
const signal = AbortSignal.timeout(1000);
@ -92,9 +93,10 @@ export async function updateTrendingTags(
limit,
}, values);
console.log(trends);
if (!trends.length) {
console.info(`No trending ${l} found. Skipping.`);
if (trends.length) {
logi({ level: 'info', ns: 'ditto.trends', message: 'Trends found', trends, ...params });
} else {
logi({ level: 'info', ns: 'ditto.trends', message: 'No trends found. Skipping.', ...params });
return;
}
@ -112,9 +114,9 @@ export async function updateTrendingTags(
});
await handleEvent(label, { source: 'internal', signal });
console.info(`Trending ${l} updated.`);
logi({ level: 'info', ns: 'ditto.trends', message: 'Trends updated', ...params });
} catch (e) {
console.error(`Error updating trending ${l}: ${e instanceof Error ? e.message : e}`);
logi({ level: 'error', ns: 'ditto.trends', message: 'Error updating trends', ...params, error: errorJson(e) });
}
}

6
src/utils/api.ts
View file

@ -1,7 +1,7 @@
import { type Context } from '@hono/hono';
import { HTTPException } from '@hono/hono/http-exception';
import { NostrEvent, NostrFilter } from '@nostrify/nostrify';
import Debug from '@soapbox/stickynotes/debug';
import { logi } from '@soapbox/logi';
import { EventTemplate } from 'nostr-tools';
import * as TypeFest from 'type-fest';
@ -15,8 +15,6 @@ import { nostrNow } from '@/utils.ts';
import { parseFormData } from '@/utils/formdata.ts';
import { purifyEvent } from '@/utils/purify.ts';
const debug = Debug('ditto:api');
/** EventTemplate with defaults. */
type EventStub = TypeFest.SetOptional<EventTemplate, 'content' | 'created_at' | 'tags'>;
@ -159,7 +157,7 @@ async function updateNames(k: number, d: string, n: Record<string, boolean>, c:
/** Push the event through the pipeline, rethrowing any RelayError. */
async function publishEvent(event: NostrEvent, c: AppContext): Promise<NostrEvent> {
debug('EVENT', event);
logi({ level: 'info', ns: 'ditto.event', source: 'api', id: event.id, kind: event.kind });
try {
await pipeline.handleEvent(event, { source: 'api', signal: c.req.raw.signal });
const client = await Storages.client();

33
src/utils/favicon.ts
View file

@ -1,5 +1,5 @@
import { DOMParser } from '@b-fuze/deno-dom';
import Debug from '@soapbox/stickynotes/debug';
import { logi } from '@soapbox/logi';
import tldts from 'tldts';
import { Conf } from '@/config.ts';
@ -7,18 +7,16 @@ import { cachedFaviconsSizeGauge } from '@/metrics.ts';
import { SimpleLRU } from '@/utils/SimpleLRU.ts';
import { fetchWorker } from '@/workers/fetch.ts';
const debug = Debug('ditto:favicon');
const faviconCache = new SimpleLRU<string, URL>(
async (key, { signal }) => {
debug(`Fetching favicon ${key}`);
const tld = tldts.parse(key);
async (domain, { signal }) => {
logi({ level: 'info', ns: 'ditto.favicon', domain, state: 'started' });
const tld = tldts.parse(domain);
if (!tld.isIcann || tld.isIp || tld.isPrivate) {
throw new Error(`Invalid favicon domain: ${key}`);
throw new Error(`Invalid favicon domain: ${domain}`);
}
const rootUrl = new URL('/', `https://${key}/`);
const rootUrl = new URL('/', `https://${domain}/`);
const response = await fetchWorker(rootUrl, { signal });
const html = await response.text();
@ -28,15 +26,28 @@ const faviconCache = new SimpleLRU<string, URL>(
if (link) {
const href = link.getAttribute('href');
if (href) {
let url: URL | undefined;
try {
return new URL(href);
url = new URL(href);
} catch {
return new URL(href, rootUrl);
try {
url = new URL(href, rootUrl);
} catch {
// fall through
}
}
if (url) {
logi({ level: 'info', ns: 'ditto.favicon', domain, state: 'found', url });
return url;
}
}
}
throw new Error(`Favicon not found: ${key}`);
logi({ level: 'info', ns: 'ditto.favicon', domain, state: 'failed' });
throw new Error(`Favicon not found: ${domain}`);
},
{ ...Conf.caches.favicon, gauge: cachedFaviconsSizeGauge },
);

18
src/utils/lnurl.ts
View file

@ -1,23 +1,23 @@
import { NostrEvent } from '@nostrify/nostrify';
import { LNURL, LNURLDetails } from '@nostrify/nostrify/ln';
import { Stickynotes } from '@soapbox/stickynotes';
import { logi } from '@soapbox/logi';
import { JsonValue } from '@std/json';
import { cachedLnurlsSizeGauge } from '@/metrics.ts';
import { SimpleLRU } from '@/utils/SimpleLRU.ts';
import { errorJson } from '@/utils/log.ts';
import { Time } from '@/utils/time.ts';
import { fetchWorker } from '@/workers/fetch.ts';
import { NostrEvent } from '@nostrify/nostrify';
const console = new Stickynotes('ditto:lnurl');
const lnurlCache = new SimpleLRU<string, LNURLDetails>(
async (lnurl, { signal }) => {
console.debug(`Lookup ${lnurl}`);
logi({ level: 'info', ns: 'ditto.lnurl', lnurl, state: 'started' });
try {
const result = await LNURL.lookup(lnurl, { fetch: fetchWorker, signal });
console.debug(`Found: ${lnurl}`);
return result;
const details = await LNURL.lookup(lnurl, { fetch: fetchWorker, signal });
logi({ level: 'info', ns: 'ditto.lnurl', lnurl, state: 'found', details: details as unknown as JsonValue });
return details;
} catch (e) {
console.debug(`Not found: ${lnurl}`);
logi({ level: 'info', ns: 'ditto.lnurl', lnurl, state: 'failed', error: errorJson(e) });
throw e;
}
},

10
src/utils/log.ts Normal file
View file

@ -0,0 +1,10 @@
import { JsonValue } from '@std/json';
/** Serialize an error into JSON for JSON logging. */
export function errorJson(error: unknown): JsonValue {
if (error instanceof Error) {
return { name: error.name, message: error.message, stack: error.stack };
}
return { name: 'unknown', message: String(error) };
}

6
src/utils/lookup.ts
View file

@ -6,7 +6,6 @@ import tldts from 'tldts';
import { getAuthor } from '@/queries.ts';
import { bech32ToPubkey } from '@/utils.ts';
import { nip05Cache } from '@/utils/nip05.ts';
import { Stickynotes } from '@soapbox/stickynotes';
/** Resolve a bech32 or NIP-05 identifier to an account. */
export async function lookupAccount(
@ -22,8 +21,6 @@ export async function lookupAccount(
/** Resolve a bech32 or NIP-05 identifier to a pubkey. */
export async function lookupPubkey(value: string, signal?: AbortSignal): Promise<string | undefined> {
const console = new Stickynotes('ditto:lookup');
if (n.bech32().safeParse(value).success) {
return bech32ToPubkey(value);
}
@ -31,8 +28,7 @@ export async function lookupPubkey(value: string, signal?: AbortSignal): Promise
try {
const { pubkey } = await nip05Cache.fetch(value, { signal });
return pubkey;
} catch (e) {
console.debug(e);
} catch {
return;
}
}

26
src/utils/nip05.ts
View file

@ -1,45 +1,45 @@
import { nip19 } from 'nostr-tools';
import { NIP05, NStore } from '@nostrify/nostrify';
import Debug from '@soapbox/stickynotes/debug';
import { logi } from '@soapbox/logi';
import tldts from 'tldts';
import { Conf } from '@/config.ts';
import { cachedNip05sSizeGauge } from '@/metrics.ts';
import { Storages } from '@/storages.ts';
import { errorJson } from '@/utils/log.ts';
import { SimpleLRU } from '@/utils/SimpleLRU.ts';
import { Nip05, parseNip05 } from '@/utils.ts';
import { fetchWorker } from '@/workers/fetch.ts';
const debug = Debug('ditto:nip05');
const nip05Cache = new SimpleLRU<string, nip19.ProfilePointer>(
async (key, { signal }) => {
debug(`Lookup ${key}`);
const tld = tldts.parse(key);
async (nip05, { signal }) => {
const tld = tldts.parse(nip05);
if (!tld.isIcann || tld.isIp || tld.isPrivate) {
throw new Error(`Invalid NIP-05: ${key}`);
throw new Error(`Invalid NIP-05: ${nip05}`);
}
const [name, domain] = key.split('@');
const [name, domain] = nip05.split('@');
logi({ level: 'info', ns: 'ditto.nip05', nip05, state: 'started' });
try {
if (domain === Conf.url.host) {
const store = await Storages.db();
const pointer = await localNip05Lookup(store, name);
if (pointer) {
debug(`Found: ${key} is ${pointer.pubkey}`);
logi({ level: 'info', ns: 'ditto.nip05', nip05, state: 'found', pubkey: pointer.pubkey });
return pointer;
} else {
throw new Error(`Not found: ${key}`);
throw new Error(`Not found: ${nip05}`);
}
} else {
const result = await NIP05.lookup(key, { fetch: fetchWorker, signal });
debug(`Found: ${key} is ${result.pubkey}`);
const result = await NIP05.lookup(nip05, { fetch: fetchWorker, signal });
logi({ level: 'info', ns: 'ditto.nip05', nip05, state: 'found', pubkey: result.pubkey });
return result;
}
} catch (e) {
debug(`Not found: ${key}`);
logi({ level: 'info', ns: 'ditto.nip05', nip05, state: 'failed', error: errorJson(e) });
throw e;
}
},

15
src/utils/unfurl.ts
View file

@ -1,17 +1,15 @@
import TTLCache from '@isaacs/ttlcache';
import Debug from '@soapbox/stickynotes/debug';
import { logi } from '@soapbox/logi';
import DOMPurify from 'isomorphic-dompurify';
import { unfurl } from 'unfurl.js';
import { Conf } from '@/config.ts';
import { PreviewCard } from '@/entities/PreviewCard.ts';
import { cachedLinkPreviewSizeGauge } from '@/metrics.ts';
import { errorJson } from '@/utils/log.ts';
import { fetchWorker } from '@/workers/fetch.ts';
const debug = Debug('ditto:unfurl');
async function unfurlCard(url: string, signal: AbortSignal): Promise<PreviewCard | null> {
debug(`Unfurling ${url}...`);
try {
const result = await unfurl(url, {
fetch: (url) =>
@ -26,7 +24,7 @@ async function unfurlCard(url: string, signal: AbortSignal): Promise<PreviewCard
const { oEmbed, title, description, canonical_url, open_graph } = result;
return {
const card = {
type: oEmbed?.type || 'link',
url: canonical_url || url,
title: oEmbed?.title || title || '',
@ -46,9 +44,12 @@ async function unfurlCard(url: string, signal: AbortSignal): Promise<PreviewCard
embed_url: '',
blurhash: null,
};
logi({ level: 'info', ns: 'ditto.unfurl', url, success: true });
return card;
} catch (e) {
debug(`Failed to unfurl ${url}`);
debug(e);
logi({ level: 'info', ns: 'ditto.unfurl', url, success: false, error: errorJson(e) });
return null;
}
}

7
src/utils/upload.ts
View file

@ -1,5 +1,5 @@
import { HTTPException } from '@hono/hono/http-exception';
import { Stickynotes } from '@soapbox/stickynotes';
import { logi } from '@soapbox/logi';
import { crypto } from '@std/crypto';
import { encodeHex } from '@std/encoding/hex';
import { encode } from 'blurhash';
@ -8,8 +8,7 @@ import sharp from 'sharp';
import { AppContext } from '@/app.ts';
import { Conf } from '@/config.ts';
import { DittoUpload, dittoUploads } from '@/DittoUploads.ts';
const console = new Stickynotes('ditto:uploader');
import { errorJson } from '@/utils/log.ts';
interface FileMeta {
pubkey: string;
@ -86,7 +85,7 @@ export async function uploadFile(
tags.push(['blurhash', blurhash]);
}
} catch (e) {
console.error(`Error parsing image metadata: ${e}`);
logi({ level: 'error', ns: 'ditto.upload.analyze', error: errorJson(e) });
}
}

8
src/workers/fetch.worker.ts
View file

@ -1,22 +1,22 @@
/// <reference lib="webworker" />
import { safeFetch } from '@soapbox/safe-fetch';
import { Stickynotes } from '@soapbox/stickynotes';
import { logi } from '@soapbox/logi';
import * as Comlink from 'comlink';
import '@/workers/handlers/abortsignal.ts';
import '@/sentry.ts';
const console = new Stickynotes('ditto:fetch.worker');
export const FetchWorker = {
async fetch(
url: string,
init: Omit<RequestInit, 'signal'>,
signal: AbortSignal | null | undefined,
): Promise<[BodyInit, ResponseInit]> {
console.debug(init.method, url);
logi({ level: 'debug', ns: 'ditto.fetch', method: init.method ?? 'GET', url });
const response = await safeFetch(url, { ...init, signal });
return [
await response.arrayBuffer(),
{

28
src/workers/policy.ts
View file

@ -1,5 +1,5 @@
import { NostrEvent, NostrRelayOK, NPolicy } from '@nostrify/nostrify';
import { Stickynotes } from '@soapbox/stickynotes';
import { logi } from '@soapbox/logi';
import * as Comlink from 'comlink';
import { Conf } from '@/config.ts';
@ -7,8 +7,6 @@ import type { CustomPolicy } from '@/workers/policy.worker.ts';
import '@/workers/handlers/abortsignal.ts';
const console = new Stickynotes('ditto:policy');
class PolicyWorker implements NPolicy {
private worker: Comlink.Remote<CustomPolicy>;
private ready: Promise<void>;
@ -55,16 +53,34 @@ class PolicyWorker implements NPolicy {
pubkey: Conf.pubkey,
});
console.warn(`Using custom policy: ${Conf.policy}`);
logi({
level: 'info',
ns: 'ditto.system.policy',
message: 'Using custom policy',
path: Conf.policy,
enabled: true,
});
} catch (e) {
if (e instanceof Error && e.message.includes('Module not found')) {
console.warn('Custom policy not found <https://docs.soapbox.pub/ditto/policies/>');
logi({
level: 'info',
ns: 'ditto.system.policy',
message: 'Custom policy not found <https://docs.soapbox.pub/ditto/policies/>',
path: null,
enabled: false,
});
this.enabled = false;
return;
}
if (e instanceof Error && e.message.includes('PGlite is not supported in worker threads')) {
console.warn('Custom policies are not supported with PGlite. The policy is disabled.');
logi({
level: 'warn',
ns: 'ditto.system.policy',
message: 'Custom policies are not supported with PGlite. The policy is disabled.',
path: Conf.policy,
enabled: false,
});
this.enabled = false;
return;
}