work-in-progress atproto PDS
typescript
atproto
pds
atcute
feat: logging
+231
-36
+1
packages/danaus/package.json
+1
packages/danaus/package.json
+4
-1
packages/danaus/src/actors/blob-store/disk.ts
+4
-1
packages/danaus/src/actors/blob-store/disk.ts
···
6
6
import { nanoid } from 'nanoid';
7
7
8
8
import type { DiskBlobStoreConfig } from '#app/config.ts';
9
+
import { blobStoreLogger } from '#app/logger.ts';
9
10
import { isErrnoException } from '#app/utils/errors.ts';
10
11
11
12
import type { BlobStore } from './types';
···
75
76
return;
76
77
}
77
78
79
+
blobStoreLogger.error('could not delete file from temp storage', { err, tmpPath: tempPath });
78
80
throw err;
79
81
}
80
82
···
85
87
86
88
try {
87
89
await rename(tempPath, path);
88
-
} catch {
90
+
} catch (err) {
91
+
blobStoreLogger.warn('rename failed, falling back to copy', { err, tempPath, path });
89
92
await copyFile(tempPath, path);
90
93
await rm(tempPath, { force: true });
91
94
}
+3
-1
packages/danaus/src/background.ts
+3
-1
packages/danaus/src/background.ts
···
1
1
import PQueue from 'p-queue';
2
2
3
+
import { backgroundLogger } from '#app/logger.ts';
4
+
3
5
export interface BackgroundQueueOptions {
4
6
/** maximum concurrent tasks (default: 5) */
5
7
concurrency?: number;
···
30
32
this.#queue
31
33
.add(() => task())
32
34
.catch((err) => {
33
-
console.error('background queue task failed:', err);
35
+
backgroundLogger.error('background queue task failed', { err });
34
36
});
35
37
}
36
38
+18
-1
packages/danaus/src/config.ts
+18
-1
packages/danaus/src/config.ts
···
5
5
import type { AtprotoAudience, Did, Nsid } from '@atcute/lexicons/syntax';
6
6
7
7
import type { AppEnvironment } from './environment';
8
+
import type { LogLevel } from './logger';
8
9
import { DAY, HOUR, SECOND } from './utils/times';
9
10
10
11
export interface ServiceConfig {
···
112
113
targets: Map<AtprotoAudience, ProxyTargetConfig>;
113
114
}
114
115
116
+
export interface LoggingConfig {
117
+
level: LogLevel;
118
+
json: boolean;
119
+
}
120
+
115
121
export interface AppConfig {
116
122
service: ServiceConfig;
117
123
database: DatabaseConfig;
···
122
128
subscription: SubscriptionConfig;
123
129
email: EmailConfig | null;
124
130
proxy: ProxyConfig;
131
+
logging: LoggingConfig;
125
132
}
126
133
127
134
export const toAppConfig = async (env: AppEnvironment): Promise<AppConfig> => {
···
129
136
return env.PDS_DATA_DIRECTORY ? path.join(env.PDS_DATA_DIRECTORY, name) : name;
130
137
};
131
138
139
+
const devMode = env.PDS_DEV_MODE ?? false;
132
140
const hostname = env.PDS_HOSTNAME ?? 'localhost';
133
141
134
142
let service: ServiceConfig;
···
137
145
138
146
service = {
139
147
version: env.PDS_VERSION ?? `unknown`,
140
-
devMode: env.PDS_DEV_MODE ?? false,
148
+
devMode: devMode,
141
149
142
150
port: port,
143
151
hostname: hostname,
···
328
336
};
329
337
}
330
338
339
+
let logging: LoggingConfig;
340
+
{
341
+
logging = {
342
+
level: env.PDS_LOG_LEVEL ?? (devMode ? 'debug' : 'info'),
343
+
json: env.PDS_LOG_JSON ?? !devMode,
344
+
};
345
+
}
346
+
331
347
return {
332
348
service,
333
349
database,
···
340
356
proxy: {
341
357
targets: new Map(),
342
358
},
359
+
logging,
343
360
};
344
361
};
+4
-1
packages/danaus/src/context.ts
+4
-1
packages/danaus/src/context.ts
···
93
93
serviceUrl: config.identity.plcDirectoryUrl,
94
94
});
95
95
96
-
const accountDb = getAccountDb(config.database.accountDbLocation, config.database.walAutoCheckpointDisabled);
96
+
const accountDb = getAccountDb(
97
+
config.database.accountDbLocation,
98
+
config.database.walAutoCheckpointDisabled,
99
+
);
97
100
98
101
const accountManager = new AccountManager({
99
102
db: accountDb,
+15
-7
packages/danaus/src/crawlers.ts
+15
-7
packages/danaus/src/crawlers.ts
···
1
1
import { ComAtprotoSyncRequestCrawl } from '@atcute/atproto';
2
2
import { Client, simpleFetchHandler } from '@atcute/client';
3
3
4
+
import { crawlerLogger } from '#app/logger.ts';
5
+
4
6
const MINUTE = 60_000;
5
7
const NOTIFY_THRESHOLD = 20 * MINUTE;
6
8
9
+
interface CrawlerClient {
10
+
client: Client;
11
+
service: string;
12
+
}
13
+
7
14
/**
8
15
* manages crawler notification for federation.
9
16
* notifies configured relay/crawler services when repo events occur.
10
17
*/
11
18
export class Crawlers {
12
-
readonly clients: Client[];
19
+
readonly clients: CrawlerClient[];
13
20
private lastNotified = 0;
14
21
private pendingTrailing = false;
15
22
···
22
29
readonly hostname: string,
23
30
crawlers: string[],
24
31
) {
25
-
this.clients = crawlers.map((service) => {
26
-
return new Client({ handler: simpleFetchHandler({ service }) });
27
-
});
32
+
this.clients = crawlers.map((service) => ({
33
+
client: new Client({ handler: simpleFetchHandler({ service }) }),
34
+
service,
35
+
}));
28
36
}
29
37
30
38
/**
···
60
68
this.lastNotified = Date.now();
61
69
62
70
// fire-and-forget notifications to all crawlers
63
-
for (const client of this.clients) {
71
+
for (const { client, service: crawler } of this.clients) {
64
72
client
65
73
.call(ComAtprotoSyncRequestCrawl, {
66
74
input: { hostname: this.hostname },
67
75
})
68
-
.catch(() => {
69
-
// ignore errors - crawlers may be temporarily unavailable
76
+
.catch((err) => {
77
+
crawlerLogger.warn('failed to request crawl', { err, crawler });
70
78
});
71
79
}
72
80
}
+3
packages/danaus/src/environment.ts
+3
packages/danaus/src/environment.ts
···
18
18
PDS_VERSION: v.optional(str),
19
19
PDS_DEV_MODE: v.optional(strbool),
20
20
21
+
PDS_LOG_LEVEL: v.optional(v.picklist(['trace', 'debug', 'info', 'warning', 'error', 'fatal'])),
22
+
PDS_LOG_JSON: v.optional(strbool),
23
+
21
24
PDS_PORT: v.optional(port),
22
25
PDS_HOSTNAME: v.optional(hostname),
23
26
+19
-10
packages/danaus/src/identity/manager.ts
+19
-10
packages/danaus/src/identity/manager.ts
···
4
4
import { eq, lt } from 'drizzle-orm';
5
5
6
6
import type { BackgroundQueue } from '#app/background.ts';
7
+
import { didCacheLogger } from '#app/logger.ts';
7
8
import { HOUR } from '#app/utils/times.ts';
8
9
9
10
import { getIdentityCacheDb, t, type IdentityCacheDb } from './db/index.ts';
···
108
109
*/
109
110
refreshHandle(handle: Handle, resolve: () => Promise<AtprotoDid | null>): void {
110
111
this.#backgroundQueue.add(async () => {
111
-
const did = await resolve();
112
-
if (did) {
113
-
this.setHandle(handle, did);
114
-
} else {
115
-
this.clearHandle(handle);
112
+
try {
113
+
const did = await resolve();
114
+
if (did) {
115
+
this.setHandle(handle, did);
116
+
} else {
117
+
this.clearHandle(handle);
118
+
}
119
+
} catch (err) {
120
+
didCacheLogger.error('refreshing handle cache failed', { handle, err });
116
121
}
117
122
});
118
123
}
···
173
178
*/
174
179
refreshDidDoc(did: AtprotoDid, resolve: () => Promise<DidDocument | null>): void {
175
180
this.#backgroundQueue.add(async () => {
176
-
const doc = await resolve();
177
-
if (doc) {
178
-
this.setDidDoc(did, doc);
179
-
} else {
180
-
this.clearDidDoc(did);
181
+
try {
182
+
const doc = await resolve();
183
+
if (doc) {
184
+
this.setDidDoc(did, doc);
185
+
} else {
186
+
this.clearDidDoc(did);
187
+
}
188
+
} catch (err) {
189
+
didCacheLogger.error('refreshing did cache failed', { did, err });
181
190
}
182
191
});
183
192
}
+93
packages/danaus/src/logger.ts
+93
packages/danaus/src/logger.ts
···
1
+
import { AsyncLocalStorage } from 'node:async_hooks';
2
+
3
+
import { configure, getConsoleSink, getLogger, type LogRecord } from '@logtape/logtape';
4
+
import { nanoid } from 'nanoid';
5
+
6
+
// #region configuration
7
+
8
+
export type LogLevel = 'trace' | 'debug' | 'info' | 'warning' | 'error' | 'fatal';
9
+
10
+
export interface LoggingConfig {
11
+
level: LogLevel;
12
+
json: boolean;
13
+
}
14
+
15
+
/**
16
+
* configure the logging system.
17
+
* @param config logging configuration
18
+
*/
19
+
export const configureLogging = async (config: LoggingConfig): Promise<void> => {
20
+
await configure({
21
+
reset: true,
22
+
contextLocalStorage: new AsyncLocalStorage(),
23
+
sinks: {
24
+
console: getConsoleSink({
25
+
formatter: config.json ? jsonFormatter : textFormatter,
26
+
}),
27
+
},
28
+
loggers: [{ category: ['danaus'], lowestLevel: config.level, sinks: ['console'] }],
29
+
});
30
+
};
31
+
32
+
// #endregion
33
+
34
+
// #region formatters
35
+
36
+
const jsonFormatter = (record: LogRecord): string => {
37
+
return JSON.stringify({
38
+
time: new Date(record.timestamp).toISOString(),
39
+
level: record.level,
40
+
logger: record.category.join(':'),
41
+
msg: record.message.join(''),
42
+
...record.properties,
43
+
});
44
+
};
45
+
46
+
const textFormatter = (record: LogRecord): string => {
47
+
const time = new Date(record.timestamp).toISOString();
48
+
const props = Object.keys(record.properties).length > 0 ? ` ${JSON.stringify(record.properties)}` : '';
49
+
return `${time} ${record.level.toUpperCase().padEnd(7)} [${record.category.join(':')}] ${record.message.join('')}${props}`;
50
+
};
51
+
52
+
// #endregion
53
+
54
+
// #region subsystem loggers
55
+
56
+
/** main HTTP/server logger */
57
+
export const httpLogger = getLogger(['danaus']);
58
+
59
+
/** account & auth operations */
60
+
export const accountLogger = getLogger(['danaus', 'account']);
61
+
62
+
/** blob storage operations */
63
+
export const blobStoreLogger = getLogger(['danaus', 'blob-store']);
64
+
65
+
/** DID/identity cache operations */
66
+
export const didCacheLogger = getLogger(['danaus', 'did-cache']);
67
+
68
+
/** event sequencer */
69
+
export const seqLogger = getLogger(['danaus', 'sequencer']);
70
+
71
+
/** background queue tasks */
72
+
export const backgroundLogger = getLogger(['danaus', 'background']);
73
+
74
+
/** crawler/relay notifications */
75
+
export const crawlerLogger = getLogger(['danaus', 'crawler']);
76
+
77
+
/** service proxy operations */
78
+
export const proxyLogger = getLogger(['danaus', 'proxy']);
79
+
80
+
/** OAuth operations (future) */
81
+
export const oauthLogger = getLogger(['danaus', 'oauth']);
82
+
83
+
// #endregion
84
+
85
+
// #region helpers
86
+
87
+
/**
88
+
* generate short request ID.
89
+
* @returns 8-character request ID
90
+
*/
91
+
export const generateRequestId = () => nanoid(8);
92
+
93
+
// #endregion
+17
-3
packages/danaus/src/pds-server.ts
+17
-3
packages/danaus/src/pds-server.ts
···
8
8
import { localDanaus } from './api/local.danaus/index.ts';
9
9
import type { AppConfig } from './config.ts';
10
10
import { createAppContext, type AppContext } from './context.ts';
11
+
import { configureLogging, httpLogger } from './logger.ts';
11
12
import { createWebRouter } from './web/router.ts';
12
13
import { runWithServer } from './web/server-context.ts';
13
14
···
39
40
if (this.#instance) {
40
41
return;
41
42
}
43
+
44
+
httpLogger.info('server starting');
45
+
46
+
await configureLogging(this.config.logging);
42
47
43
48
await using disposables = new AsyncDisposableStack();
44
49
···
63
68
],
64
69
handleNotFound: context.proxy.handleNotFound,
65
70
handleException(err, request) {
71
+
httpLogger.error('xrpc request failed', { err });
66
72
return defaultExceptionHandler(err, request);
67
73
},
68
74
});
···
77
83
78
84
const corsHeaders = { 'access-control-allow-origin': '*' };
79
85
86
+
const servicePort = this.config.service.port;
87
+
const serviceHostname = this.config.service.hostname;
88
+
80
89
const server: ReturnType<typeof Bun.serve> = Bun.serve({
81
-
port: this.config.service.port,
82
-
hostname: this.config.service.hostname,
90
+
port: servicePort,
91
+
hostname: serviceHostname,
83
92
websocket: wrapped.websocket,
84
93
routes: {
85
94
'/.well-known/atproto-did'(req: Request) {
···
120
129
'/*': (request, server) => runWithServer(server, () => web.fetch(request)),
121
130
},
122
131
});
123
-
disposables.defer(() => server.stop());
132
+
disposables.defer(() => {
133
+
httpLogger.info('server stopping');
134
+
server.stop();
135
+
});
136
+
137
+
httpLogger.info('server started', { port: server.port, hostname: serviceHostname });
124
138
125
139
this.#instance = {
126
140
disposables: disposables.move(),
+8
-1
packages/danaus/src/proxy/index.ts
+8
-1
packages/danaus/src/proxy/index.ts
···
5
5
import type { ActorManager } from '#app/actors/manager.ts';
6
6
import type { AuthVerifier } from '#app/auth/verifier.ts';
7
7
import type { ProxyTargetConfig } from '#app/config.ts';
8
+
import { proxyLogger } from '#app/logger.ts';
8
9
9
10
import {
10
11
buildProxyRequestHeaders,
···
117
118
});
118
119
119
120
// forward request
120
-
const upstreamResponse = await fetch(upstreamRequest);
121
+
let upstreamResponse: Response;
122
+
try {
123
+
upstreamResponse = await fetch(upstreamRequest);
124
+
} catch (err) {
125
+
proxyLogger.error('upstream service unreachable', { err, target: target.url });
126
+
throw err;
127
+
}
121
128
122
129
// build response with filtered headers
123
130
const responseHeaders = filterResponseHeaders(upstreamResponse.headers);
+5
packages/danaus/src/test/test-pds.ts
+5
packages/danaus/src/test/test-pds.ts
+2
-8
packages/danaus/src/web/controllers/login/lib/forms.ts
+2
-8
packages/danaus/src/web/controllers/login/lib/forms.ts
···
290
290
}
291
291
292
292
// update counter
293
-
mfaManager.updateWebAuthnCredentialCounter(
294
-
credential.id,
295
-
verification.authenticationInfo.newCounter,
296
-
);
293
+
mfaManager.updateWebAuthnCredentialCounter(credential.id, verification.authenticationInfo.newCounter);
297
294
} catch {
298
295
invalid(`Passkey verification failed`);
299
296
}
···
356
353
}
357
354
358
355
// update counter
359
-
mfaManager.updateWebAuthnCredentialCounter(
360
-
credential.id,
361
-
verification.authenticationInfo.newCounter,
362
-
);
356
+
mfaManager.updateWebAuthnCredentialCounter(credential.id, verification.authenticationInfo.newCounter);
363
357
} catch {
364
358
invalid(`Security key verification failed`);
365
359
}
+1
-1
packages/danaus/src/web/controllers/verify.tsx
+1
-1
packages/danaus/src/web/controllers/verify.tsx
···
4
4
5
5
import { PreferredMfa } from '#app/accounts/db/schema.ts';
6
6
import type { MfaStatus } from '#app/accounts/mfa.ts';
7
-
import type { VerifyChallenge } from '#app/accounts/web-sessions.ts';
8
7
import {
9
8
RECOVERY_CODE_LENGTH,
10
9
RECOVERY_CODE_RE,
11
10
TOTP_CODE_LENGTH,
12
11
TOTP_CODE_RE,
13
12
} from '#app/accounts/totp.ts';
13
+
import type { VerifyChallenge } from '#app/accounts/web-sessions.ts';
14
14
import { generateWebAuthnAuthenticationOptions } from '#app/accounts/webauthn.ts';
15
15
16
16
import { BaseLayout } from '#web/layouts/base.tsx';
+30
-2
packages/danaus/src/web/router.ts
+30
-2
packages/danaus/src/web/router.ts
···
1
-
import { createRouter } from '@oomfware/fetch-router';
1
+
import { createRouter, type Middleware } from '@oomfware/fetch-router';
2
2
import { asyncContext } from '@oomfware/fetch-router/middlewares/async-context';
3
3
4
+
import { withContext } from '@logtape/logtape';
5
+
4
6
import type { AppContext } from '#app/context.ts';
7
+
import { generateRequestId, httpLogger } from '#app/logger.ts';
5
8
6
9
import accountController from './controllers/account.tsx';
7
10
import adminController from './controllers/admin.tsx';
···
14
17
import { routes } from './routes.ts';
15
18
16
19
/**
20
+
* middleware that logs incoming requests and sets implicit logging context.
21
+
*/
22
+
const requestLogger = (): Middleware => {
23
+
return async ({ request }, next) => {
24
+
const requestId = generateRequestId();
25
+
const { pathname } = new URL(request.url);
26
+
const method = request.method;
27
+
28
+
return withContext({ requestId, path: pathname, method }, async () => {
29
+
const start = performance.now();
30
+
httpLogger.debug('request started');
31
+
32
+
const response = await next();
33
+
34
+
httpLogger.info('request completed', {
35
+
status: response.status,
36
+
durationMs: Math.round(performance.now() - start),
37
+
});
38
+
39
+
return response;
40
+
});
41
+
};
42
+
};
43
+
44
+
/**
17
45
* creates the web router with all routes and middleware.
18
46
* @param ctx application context
19
47
* @returns the configured router
20
48
*/
21
49
export const createWebRouter = (ctx: AppContext) => {
22
50
const router = createRouter({
23
-
middleware: [asyncContext(), provideAppContext(ctx)],
51
+
middleware: [asyncContext(), requestLogger(), provideAppContext(ctx)],
24
52
});
25
53
26
54
router.map(routes.home, homeController);
+8
pnpm-lock.yaml
+8
pnpm-lock.yaml
···
97
97
'@kelinci/danaus-lexicons':
98
98
specifier: workspace:*
99
99
version: link:../lexicons
100
+
'@logtape/logtape':
101
+
specifier: ^2.0.0
102
+
version: 2.0.0
100
103
'@oomfware/fetch-router':
101
104
specifier: ^0.2.1
102
105
version: 0.2.1
···
890
893
891
894
'@levischuck/tiny-cbor@0.2.11':
892
895
resolution: {integrity: sha512-llBRm4dT4Z89aRsm6u2oEZ8tfwL/2l6BwpZ7JcyieouniDECM5AqNgr/y08zalEIvW3RSK4upYyybDcmjXqAow==}
896
+
897
+
'@logtape/logtape@2.0.0':
898
+
resolution: {integrity: sha512-z9Hp44mIRXAzgxSyQfFQiRuJ78EMnZa6g43UCxyGOO3RgHjn/7q+5OhdbhypkeHjiJRPxv6RmRsyF0S+OOYWnA==}
893
899
894
900
'@napi-rs/wasm-runtime@1.1.1':
895
901
resolution: {integrity: sha512-p64ah1M1ld8xjWv3qbvFwHiFVWrq1yFvV4f7w+mzaqiR4IlSgkqhcRdHwsGgomwzBH51sRY4NEowLxnaBjcW/A==}
···
4179
4185
jsbi: 4.3.2
4180
4186
4181
4187
'@levischuck/tiny-cbor@0.2.11': {}
4188
+
4189
+
'@logtape/logtape@2.0.0': {}
4182
4190
4183
4191
'@napi-rs/wasm-runtime@1.1.1':
4184
4192
dependencies: