diff --git a/SHA256SUMS b/SHA256SUMS index 83f0e45..8704fa5 100644 --- a/SHA256SUMS +++ b/SHA256SUMS @@ -402,7 +402,7 @@ ba6fb59bda1bf219d1e09d787a52437bf4a0ae6bfabfbda2bcfb37bced886adc server/durable 89e116491a077a347c18b0b0c6a2801f867f0005c224ab5ed6e2dd3d783c047a server/evaluate-cli.ts 6e00b4f2c76c2b68165105b9ca9a00dbc74183043d15ba4d5ffb82967b84130f server/gateway.ts f72b36e636d98f35f21d9e185aaf5ca7376ef20de2769e5c4a8a107022bcf832 server/historical.ts -d30042908815d3d04f455456f39728078c217cf281edab0c81372b638a6dfce0 server/http.ts +78955eb8836d39e72cc5be4d95938bd4805ef6913f8c697cf0feb359f0f09b5a server/http.ts 98a99e3407ace650bc8b1c9140d31548c378e0b2e1069e43dbed6325f5acf26b server/images.ts 6af6aa0e5917a1ec062d2076c6ae60a4cb94af546266e9fd4b746502a7a743a3 server/jev.ts b556bb54b61153d824e83a5a931c7031974736e065dc63633e259090c3e7eb0d server/leadership.ts @@ -451,7 +451,7 @@ f9c22e2e2b1b12d1463e433966978b3cffb6f57e6903aae9d97d2d47a13eaed7 tests/compose. 4b9b9b42437ba56db989269d4f46b5d25a9a54d89b70ed3cb15bcc66a0281366 tests/gateway.test.ts 05ba15dd56aee6d4eb42697f0dae7b7ca242b443aa1119d39ed97bf885bfeec2 tests/helpers.ts b666285fc34870d9396562e38e6eaabeeae0058bf9f8acff68e710b89ba9c05e tests/historical.test.ts -eac971f393e25829a52546dfc1113d78d4f0f707ac0e15a5748d62948cf8151d tests/http.test.ts +dffbe9389634894b95e6401723fa0201a7d473f6cb53a45dee69a9eb19bf6dd6 tests/http.test.ts 99e193edfc23993f6020844712e50ce17c2e00b87d77f512ec93270f3d733cef tests/images.test.ts 2f4aea258b076c5d21ac66f6152d09a243f8ea09dc9a810a24df87b5e6fd9069 tests/leadership.test.ts 0e9bd7d68fc492b8880cd7a6689524a3d6d5baa2c0b00dc2b031c017044a973f tests/match-configuration.test.ts diff --git a/server/http.ts b/server/http.ts index 1b1ff68..a3a465b 100644 --- a/server/http.ts +++ b/server/http.ts @@ -83,6 +83,19 @@ export function createHttp(services: Services, config: Config, root = process.cw for (const [k, v] of limits) if (v.at < now - 60000) limits.delete(k); } + // Operational log lines carry codes, timings and request IDs only: never tokens, bodies or member data. + const log = (event: Record) => console.log(JSON.stringify(event)); + // Starter references are copied after the sign-in reply. The copy normalizes 33 images in one transaction, + // which can outlast the hosting/Discord proxy timeout and turn a completed sign-in into a 502. + const seeding = new Map>(); + const seedInBackground = (guild: string) => { + if (seeding.has(guild)) return; + const started = Date.now(); + seeding.set(guild, seedStarterReferences(services, guild, root) + .then(() => log({ event: 'starter_references_seed', guild, outcome: 'done', ms: Date.now() - started }), + e => log({ event: 'starter_references_seed', guild, outcome: safeError(e), ms: Date.now() - started })) + .finally(() => seeding.delete(guild))); + }; async function dispatch(req: IncomingMessage, url: URL, origin: string): Promise { const method = req.method ?? 'GET'; const p = url.pathname.split('/').filter(Boolean); @@ -107,15 +120,23 @@ export function createHttp(services: Services, config: Config, root = process.cw onlyKeys(b, renewing ? ['accessToken', 'nonce', 'guildId'] : ['code', 'nonce', 'guildId']); assert(snowflake(b.guildId), 'invalid_guild'); assert(typeof b.nonce === 'string' && await store.consumeNonce(digest(b.nonce), origin), 'invalid_or_expired_nonce', 401); - const auth = renewing ? { userId: await discord.oauthIdentity(text(b.accessToken, 2048)), accessToken: undefined } : await discord.exchange(text(b.code, 2048)); - await store.getSettings(b.guildId); - const a = await services.authority(b.guildId, auth.userId); - assert(a.capabilities.length > 0, 'no_delegated_access', 403); - await seedStarterReferences(services, b.guildId, root); - const sessionToken = token(); - await store.createSession(digest(sessionToken), { userId: auth.userId, guildId: b.guildId, expiresAt: Date.now() + 15 * 60000 }); - await services.audit(b.guildId, auth.userId, 'session.created', 'session'); - return { body: { sessionToken, accessToken: auth.accessToken, authority: a, expiresIn: 900 } }; + const guildId = b.guildId as string; + const stages: Record = {}; + const stage = async (name: string, run: () => Promise) => { const s = Date.now(); try { return await run(); } finally { stages[name] = Date.now() - s; } }; + try { + const auth = await stage('discord_oauth', async () => renewing ? { userId: await discord.oauthIdentity(text(b.accessToken, 2048)), accessToken: undefined } : await discord.exchange(text(b.code, 2048))); + await stage('settings', () => store.getSettings(guildId)); + const a = await stage('authority', () => services.authority(guildId, auth.userId)); + assert(a.capabilities.length > 0, 'no_delegated_access', 403); + seedInBackground(guildId); + const sessionToken = token(); + await stage('session', async () => { + await store.createSession(digest(sessionToken), { userId: auth.userId, guildId: guildId, expiresAt: Date.now() + 15 * 60000 }); + await services.audit(guildId, auth.userId, 'session.created', 'session'); + }); + return { body: { sessionToken, accessToken: auth.accessToken, authority: a, expiresIn: 900 } }; + } + finally { log({ event: 'auth_stages', path: url.pathname, guild: guildId, stages }); } } // Independent browser OAuth: state is one-use, origin/guild/browser-bound; no Activity SDK. const cookie = (name: string) => (req.headers.cookie ?? '').split('; ').find(v => v.startsWith(name + '='))?.slice(name.length + 1) ?? ''; @@ -136,7 +157,7 @@ export function createHttp(services: Services, config: Config, root = process.cw assert(snowflake(guild) && state && verifier && url.searchParams.get('state') === state && await store.consumeNonce(digest(state), `${config.publicOrigin}:${guild}:${digest(verifier)}`), 'invalid_or_expired_state', 401); const auth = await discord.exchange(text(url.searchParams.get('code'), 2048), config.publicOrigin + '/api/auth/browser/callback'); const a = await services.authority(guild, auth.userId); requireManager(a); - await seedStarterReferences(services, guild, root); + seedInBackground(guild); const sessionToken = token(); await store.createSession(digest(sessionToken), {userId:auth.userId, guildId:guild, expiresAt:Date.now()+15*60000}); await services.audit(guild, auth.userId, 'session.browser_created', 'session'); @@ -618,7 +639,12 @@ export function createHttp(services: Services, config: Config, root = process.cw return { bytes, type: file.endsWith('.html') ? 'text/html; charset=utf-8' : file.endsWith('.css') ? 'text/css; charset=utf-8' : file.endsWith('.txt') ? 'text/plain; charset=utf-8' : 'text/javascript; charset=utf-8' }; } const server = createServer(async (req, res) => { - const requestId = randomUUID(); + const requestId = randomUUID(), started = Date.now(); + let path = ''; + res.once('finish', () => { + if (path.startsWith('/api/auth/') || res.statusCode >= 500) + log({ event: 'http_request', method: req.method, path, status: res.statusCode, ms: Date.now() - started, requestId }); + }); res.setHeader('X-Request-Id', requestId); res.setHeader('Cache-Control', 'no-store'); res.setHeader('X-Content-Type-Options', 'nosniff'); @@ -628,6 +654,7 @@ export function createHttp(services: Services, config: Config, root = process.cw res.setHeader('Strict-Transport-Security', 'max-age=31536000'); try { const url = new URL(req.url ?? '/', config.publicOrigin); + path = url.pathname; const origin = req.headers.origin ?? ''; if (origin) { assert(origins.has(origin), 'origin_denied', 403); @@ -655,6 +682,7 @@ export function createHttp(services: Services, config: Config, root = process.cw catch (e) { if(e instanceof Deferred) res.setHeader('Retry-After',String(Math.max(1,Math.ceil((e.until-Date.now())/1000)))); res.statusCode = e instanceof AppError ? e.status : 500; + if (res.statusCode >= 500) log({ event: 'http_error', code: safeError(e), path, requestId }); res.setHeader('Content-Type', 'application/json; charset=utf-8'); res.end(JSON.stringify({ error: safeError(e), requestId, ...(e instanceof Deferred?{nextAttempt:e.until}:{}) })); } diff --git a/tests/http.test.ts b/tests/http.test.ts index 6cd2af1..89e48bc 100644 --- a/tests/http.test.ts +++ b/tests/http.test.ts @@ -98,10 +98,10 @@ test('historical API previews scope, starts, lists, pauses, resumes and cancels assert.equal((await f.request(base,'POST',{...payload,enforcement:true},token)).status,400); const usage=await f.request('/api/g/'+G+'/analytics/summary?correlationId='+id,'GET',undefined,token);assert.equal(usage.status,200); }); -async function setup(t: TestContext, production = false, readiness?: () => Promise, controllerState?: () => string, deployment?: Deployment) { +async function setup(t: TestContext, production = false, readiness?: () => Promise, controllerState?: () => string, deployment?: Deployment, root = process.cwd()) { const f = await fixture(t); const config = { port: 3000, production, publicOrigin: ORIGIN, clientId: G, clientSecret: 'fake-secret', botToken: 'fake-token', databaseUrl: 'not-used', masterKey: 'not-used', objectDir: 'not-used', model: 'jev-1.14.0', apiOnly: true }; - const server = createHttp(f.services, config, process.cwd(), readiness, controllerState, deployment); + const server = createHttp(f.services, config, root, readiness, controllerState, deployment); await new Promise(r => server.listen(0, '127.0.0.1', r)); const address = server.address() as { port: number; @@ -129,6 +129,13 @@ test('HTTP unauthenticated guild request is denied', async (t) => { const f = aw test('HTTP rejects a mutation from an untrusted origin', async (t) => { const f = await setup(t); assert.equal((await f.request('/api/auth/start', 'POST', {}, undefined, 'https://evil.invalid')).status, 403); }); test('HTTP mutation without Origin is denied', async (t) => { const f = await setup(t); assert.equal((await f.request('/api/auth/start', 'POST', {}, undefined, '')).status, 403); }); test('HTTP accepts the exact Discord proxy origin', async (t) => { const f = await setup(t); assert.equal((await f.request('/api/auth/start', 'POST', {}, undefined, `https://${G}.discordsays.com`)).status, 200); }); +test('sign-in does not wait for or fail on first-time starter references', async (t) => { + const f = await setup(t, false, undefined, undefined, undefined, 'missing-starter-root'); + await f.store.remove('images', G, f.ref.id, f.ref.revision); + const login = await f.login(); + assert.equal(login.status, 200); + assert.ok(login.data.sessionToken); +}); test('OAuth nonce is one-use', async (t) => { const f = await setup(t); const n = await f.request('/api/auth/start', 'POST', {}); const payload = { code: 'admin-code', nonce: n.data.nonce, guildId: G }; assert.equal((await f.request('/api/auth/exchange', 'POST', payload)).status, 200); assert.equal((await f.request('/api/auth/exchange', 'POST', payload)).status, 401); }); test('Discord administrator receives a usable management session', async (t) => { const f = await setup(t); const login = await f.login(); assert.equal(login.status, 200); assert.ok(login.data.authority.capabilities.includes('credentials.manage')); assert.equal((await f.request(`/api/g/${G}/me`, 'GET', undefined, login.data.sessionToken)).status, 200); }); test('ungranted moderator cannot get a session', async (t) => { const f = await setup(t); assert.equal((await f.login('moderator-code')).status, 403); });