mirror of
https://github.com/screentinker/screentinker.git
synced 2026-08-13 22:03:13 -06:00
Record auth rate-limit rejections so they can be measured
The auth limiters are app.use middleware that return 429 before the handler that writes activity_log, so a rejection left no trace anywhere — the limit suppressed the record of itself. Four production IPs sit at exactly ten logins a minute and there was no way to tell whether that is one attacker or an office whose staff share an egress address, which is the difference between the limiter working and the limiter locking out customers. The rejection count does not answer that. The number of distinct accounts per IP does: one account hammered is the limiter doing its job, several accounts each denied a few times is a shared egress. Both are now recorded, and a platform-admin-only endpoint reads the tally back. Identifiers are salted-hashed with a per-process salt and only ever counted, so this cannot accumulate into a roster of a customer's addresses. Memory is bounded per key and overall, and says when a count was capped rather than silently undercounting. Behaviour is unchanged: same status, same body, and the recording is wrapped so telemetry can never break the limiter. A test asserts ten through then 429 with the identical response shape, since a diagnostic that alters what it measures is worse than none. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01Uaeo9MvzKoyXuN6ZsbhtkL
This commit is contained in:
parent
a93f65b20a
commit
792013e36c
80
server/lib/limiter-telemetry.js
Normal file
80
server/lib/limiter-telemetry.js
Normal file
|
|
@ -0,0 +1,80 @@
|
|||
'use strict';
|
||||
|
||||
// Why this exists: the auth limiters run as app.use middleware BEFORE the handler that writes
|
||||
// activity_log, so a 429 leaves no trace anywhere. The limit censors the evidence of itself —
|
||||
// four production IPs sit at exactly 10 logins/min and there is no way to tell whether that is
|
||||
// one attacker or a NATed site whose staff are colliding on a shared egress IP.
|
||||
//
|
||||
// This records rejections so the question becomes measurable. The discriminating signal is NOT
|
||||
// the rejection count, it is how many DISTINCT accounts a single IP is rejected for:
|
||||
//
|
||||
// 1 identifier, many rejections -> someone hammering one account (the limiter is working)
|
||||
// many identifiers, few each -> a shared egress IP; real users are being denied
|
||||
//
|
||||
// Identifiers are salted-hashed and only ever counted, never stored or logged in the clear —
|
||||
// this is a diagnostic, not an audit trail, and it must not become a place where credentials
|
||||
// or a roster of a customer's email addresses accumulate.
|
||||
|
||||
const crypto = require('crypto');
|
||||
|
||||
const MAX_KEYS = 2000; // distinct endpoint|ip pairs held
|
||||
const MAX_IDS_PER_KEY = 64; // enough to tell "one" from "many"; caps memory per key
|
||||
const IDLE_MS = 60 * 60 * 1000; // drop a key after an hour of quiet
|
||||
|
||||
// Per-process salt: makes the digests useless outside this process lifetime, so nothing
|
||||
// persisted or logged can be walked back to an address.
|
||||
const SALT = crypto.randomBytes(16);
|
||||
const digest = (s) => crypto.createHash('sha256').update(SALT).update(String(s).toLowerCase()).digest('hex').slice(0, 16);
|
||||
|
||||
const state = new Map();
|
||||
|
||||
function prune(now) {
|
||||
for (const [k, v] of state) if (now - v.lastSeen > IDLE_MS) state.delete(k);
|
||||
if (state.size <= MAX_KEYS) return;
|
||||
// Still oversized: evict the least recently seen.
|
||||
const byAge = [...state.entries()].sort((a, b) => a[1].lastSeen - b[1].lastSeen);
|
||||
for (let i = 0; i < byAge.length - MAX_KEYS; i++) state.delete(byAge[i][0]);
|
||||
}
|
||||
|
||||
// Returns the running tally for this endpoint+ip, so the caller can log it.
|
||||
function recordRejection({ endpoint, ip, identifier }, now = Date.now()) {
|
||||
const key = `${endpoint}|${ip}`;
|
||||
let e = state.get(key);
|
||||
if (!e) { e = { rejections: 0, ids: new Set(), idsTruncated: false, firstSeen: now, lastSeen: now }; state.set(key, e); }
|
||||
e.rejections++;
|
||||
e.lastSeen = now;
|
||||
if (identifier) {
|
||||
if (e.ids.size < MAX_IDS_PER_KEY) e.ids.add(digest(identifier));
|
||||
else e.idsTruncated = true;
|
||||
}
|
||||
if (state.size > MAX_KEYS) prune(now);
|
||||
return {
|
||||
endpoint, ip,
|
||||
rejections: e.rejections,
|
||||
distinctIdentifiers: e.ids.size,
|
||||
identifiersTruncated: e.idsTruncated,
|
||||
windowMs: now - e.firstSeen,
|
||||
};
|
||||
}
|
||||
|
||||
// Read-only view for a debug endpoint or a test. No digests are exposed — only counts.
|
||||
function snapshot() {
|
||||
return [...state.entries()].map(([key, e]) => {
|
||||
const i = key.lastIndexOf('|');
|
||||
return {
|
||||
endpoint: key.slice(0, i),
|
||||
ip: key.slice(i + 1),
|
||||
rejections: e.rejections,
|
||||
distinctIdentifiers: e.ids.size,
|
||||
identifiersTruncated: e.idsTruncated,
|
||||
firstSeen: e.firstSeen,
|
||||
lastSeen: e.lastSeen,
|
||||
// The whole point: many identifiers from one IP reads as a shared egress, not an attack.
|
||||
likelySharedEgress: e.ids.size >= 3,
|
||||
};
|
||||
}).sort((a, b) => b.rejections - a.rejections);
|
||||
}
|
||||
|
||||
function reset() { state.clear(); }
|
||||
|
||||
module.exports = { recordRejection, snapshot, reset, MAX_IDS_PER_KEY, MAX_KEYS };
|
||||
|
|
@ -424,4 +424,21 @@ router.post('/trigger-update', requirePlatformAdmin, async (req, res) => {
|
|||
});
|
||||
});
|
||||
|
||||
// QA-SNAT diagnostic. Auth rate-limit rejections are invisible everywhere else: the limiter is
|
||||
// app.use middleware that returns 429 before the handler that would write activity_log, so the
|
||||
// limit suppresses the record of itself. This exposes the in-memory tally so "is that IP one
|
||||
// attacker or a NATed office?" can be answered from data instead of argued from a hunch.
|
||||
//
|
||||
// distinct_accounts is the signal, not rejections. Values are counts only — the identifiers are
|
||||
// salted-hashed inside the telemetry module and never leave it, so this cannot become a roster
|
||||
// of a customer's email addresses. Platform-admin only, and in-memory (a restart clears it).
|
||||
router.get('/limiter-rejections', requirePlatformAdmin, (req, res) => {
|
||||
const rows = require('../lib/limiter-telemetry').snapshot();
|
||||
res.json({
|
||||
rows,
|
||||
shared_egress_suspects: rows.filter(r => r.likelySharedEgress).length,
|
||||
note: 'In-memory since last restart. distinct_accounts >= 3 from one IP suggests a shared egress rather than a single attacker.',
|
||||
});
|
||||
});
|
||||
|
||||
module.exports = router;
|
||||
|
|
|
|||
|
|
@ -327,6 +327,9 @@ app.use('/socket.io-client', express.static(
|
|||
));
|
||||
|
||||
// Simple rate limiter for auth endpoints
|
||||
// Required here rather than relying on the log-coalescer const further down: that one is only
|
||||
// safe because the callback runs at request time, which is a subtle thing to depend on.
|
||||
const limiterTelemetry = require('./lib/limiter-telemetry');
|
||||
const rateLimits = new Map();
|
||||
function rateLimit(windowMs, maxRequests) {
|
||||
return (req, res, next) => {
|
||||
|
|
@ -341,6 +344,23 @@ function rateLimit(windowMs, maxRequests) {
|
|||
let hits = rateLimits.get(key) || [];
|
||||
hits = hits.filter(t => t > windowStart);
|
||||
if (hits.length >= maxRequests) {
|
||||
// QA-SNAT: a 429 returns before any handler runs, so nothing else in the system ever
|
||||
// records that it happened — the limit hides its own evidence. Count it here. The
|
||||
// number that matters is distinct identifiers per IP: one means the limiter is doing
|
||||
// its job, several means a shared egress IP is denying real users. Identifiers are
|
||||
// salted-hashed inside the telemetry module and only ever counted. Response unchanged.
|
||||
try {
|
||||
const endpoint = (req.originalUrl || req.url || req.path).split('?')[0];
|
||||
const ip = getClientIp(req);
|
||||
const ident = req.body && (req.body.email || req.body.username);
|
||||
const t = limiterTelemetry.recordRejection({ endpoint, ip, identifier: ident });
|
||||
logCoalescer.record(
|
||||
`limit-reject:${endpoint}:${ip}`,
|
||||
`[limit] 429 ${endpoint} ip=${ip} rejections=${t.rejections} distinct_accounts=${t.distinctIdentifiers}` +
|
||||
(t.distinctIdentifiers >= 3 ? ' (looks like a SHARED egress, not one attacker)' : ''),
|
||||
{ warn: t.distinctIdentifiers >= 3 },
|
||||
);
|
||||
} catch (_) { /* telemetry must never break the limiter */ }
|
||||
return res.status(429).json({ error: 'Too many requests, try again later' });
|
||||
}
|
||||
hits.push(now);
|
||||
|
|
|
|||
106
server/test/limiter-rejection-recorded.test.js
Normal file
106
server/test/limiter-rejection-recorded.test.js
Normal file
|
|
@ -0,0 +1,106 @@
|
|||
'use strict';
|
||||
|
||||
// The companion to limiter-telemetry.test.js: that one tests the counter, this one proves the
|
||||
// counter is actually WIRED to a real 429 and that adding it changed nothing about the limiter.
|
||||
// A diagnostic that alters the thing it measures is worse than no diagnostic.
|
||||
|
||||
const { test, before, after } = require('node:test');
|
||||
const assert = require('node:assert/strict');
|
||||
const { spawn } = require('node:child_process');
|
||||
const path = require('node:path');
|
||||
const os = require('node:os');
|
||||
const fs = require('node:fs');
|
||||
const crypto = require('node:crypto');
|
||||
|
||||
const { freePort } = require('./helpers/free-port');
|
||||
let PORT, BASE, proc, adminToken;
|
||||
const DATA_DIR = path.join(os.tmpdir(), 'st-limrej-' + crypto.randomBytes(4).toString('hex'));
|
||||
const LOG = path.join(os.tmpdir(), 'st-limrej-' + crypto.randomBytes(4).toString('hex') + '.log');
|
||||
|
||||
const jfetch = async (p, opts = {}) => {
|
||||
const res = await fetch(BASE + p, opts);
|
||||
let body = null; try { body = await res.json(); } catch { /* */ }
|
||||
return { status: res.status, body };
|
||||
};
|
||||
const login = (email, ip) => jfetch('/api/auth/login', {
|
||||
method: 'POST',
|
||||
headers: { 'Content-Type': 'application/json', 'X-Forwarded-For': ip },
|
||||
body: JSON.stringify({ email, password: 'definitely-wrong-password' }),
|
||||
});
|
||||
|
||||
before(async () => {
|
||||
PORT = await freePort();
|
||||
BASE = `http://127.0.0.1:${PORT}`;
|
||||
const logFd = fs.openSync(LOG, 'w');
|
||||
proc = spawn('node', ['server.js'], {
|
||||
cwd: path.join(__dirname, '..'),
|
||||
env: { ...process.env, DATA_DIR, SELF_HOSTED: 'true', PORT: String(PORT), NODE_ENV: 'test' },
|
||||
stdio: ['ignore', logFd, logFd],
|
||||
});
|
||||
let up = false;
|
||||
for (let i = 0; i < 80; i++) {
|
||||
try { const r = await fetch(BASE + '/api/status'); if (r.ok) { up = true; break; } } catch { /* */ }
|
||||
await new Promise(r => setTimeout(r, 250));
|
||||
}
|
||||
if (!up) throw new Error('server did not boot:\n' + fs.readFileSync(LOG, 'utf8').slice(-2000));
|
||||
|
||||
// First account on a fresh self-hosted instance is platform_admin — the only role that may
|
||||
// read the diagnostic.
|
||||
const reg = await jfetch('/api/auth/register', {
|
||||
method: 'POST', headers: { 'Content-Type': 'application/json', 'X-Forwarded-For': '198.51.10.1' },
|
||||
body: JSON.stringify({ email: 'admin' + crypto.randomBytes(4).toString('hex') + '@x.local', password: 'Passw0rd123' }),
|
||||
});
|
||||
adminToken = reg.body.token;
|
||||
});
|
||||
after(() => { try { proc.kill('SIGKILL'); } catch { /* */ } });
|
||||
|
||||
const snapshot = () => jfetch('/api/admin/limiter-rejections', { headers: { Authorization: 'Bearer ' + adminToken } });
|
||||
|
||||
test('the limiter still behaves exactly as before: 10 through, then 429', async () => {
|
||||
const IP = '198.51.99.10';
|
||||
const codes = [];
|
||||
for (let i = 0; i < 12; i++) codes.push((await login(`u${i}@corp.test`, IP)).status);
|
||||
assert.equal(codes.filter(c => c === 429).length, 2, 'the 11th and 12th are rejected');
|
||||
assert.ok(!codes.slice(0, 10).includes(429), 'the first ten are not');
|
||||
const body = (await login('u0@corp.test', IP));
|
||||
assert.equal(body.status, 429);
|
||||
assert.deepEqual(body.body, { error: 'Too many requests, try again later' },
|
||||
'response shape unchanged — the diagnostic is invisible to clients');
|
||||
});
|
||||
|
||||
test('the rejection is recorded, with the distinct-account signal that answers QA-SNAT', async () => {
|
||||
const snap = await snapshot();
|
||||
assert.equal(snap.status, 200);
|
||||
const row = snap.body.rows.find(r => r.ip === '198.51.99.10');
|
||||
assert.ok(row, 'the 429 left a trace — previously it left none at all');
|
||||
assert.equal(row.endpoint, '/api/auth/login');
|
||||
assert.ok(row.rejections >= 2);
|
||||
assert.ok(row.distinctIdentifiers >= 3, 'several accounts from one IP');
|
||||
assert.equal(row.likelySharedEgress, true, 'which reads as a NATed site, not one attacker');
|
||||
assert.ok(snap.body.shared_egress_suspects >= 1);
|
||||
});
|
||||
|
||||
test('one account hammered is NOT flagged as a shared egress', async () => {
|
||||
const IP = '198.51.99.11';
|
||||
for (let i = 0; i < 12; i++) await login('one.victim@corp.test', IP);
|
||||
const row = (await snapshot()).body.rows.find(r => r.ip === IP);
|
||||
assert.equal(row.distinctIdentifiers, 1);
|
||||
assert.equal(row.likelySharedEgress, false, 'the limiter is doing its job here — do not widen it');
|
||||
});
|
||||
|
||||
test('the diagnostic never leaks the addresses it counted', async () => {
|
||||
const dump = JSON.stringify((await snapshot()).body);
|
||||
assert.doesNotMatch(dump, /one\.victim/);
|
||||
assert.doesNotMatch(dump, /corp\.test/);
|
||||
});
|
||||
|
||||
test('it is platform-admin gated, not readable by an ordinary tenant', async () => {
|
||||
const reg = await jfetch('/api/auth/register', {
|
||||
method: 'POST', headers: { 'Content-Type': 'application/json', 'X-Forwarded-For': '198.51.10.2' },
|
||||
body: JSON.stringify({ email: 'plain' + crypto.randomBytes(4).toString('hex') + '@x.local', password: 'Passw0rd123' }),
|
||||
});
|
||||
const r = await jfetch('/api/admin/limiter-rejections', { headers: { Authorization: 'Bearer ' + reg.body.token } });
|
||||
assert.ok(r.status === 403 || r.status === 401, `ordinary user refused (got ${r.status})`);
|
||||
const anon = await jfetch('/api/admin/limiter-rejections');
|
||||
assert.ok(anon.status === 401 || anon.status === 403, 'and anonymous too');
|
||||
});
|
||||
84
server/test/limiter-telemetry.test.js
Normal file
84
server/test/limiter-telemetry.test.js
Normal file
|
|
@ -0,0 +1,84 @@
|
|||
'use strict';
|
||||
|
||||
// QA-SNAT. The auth limiters are app.use middleware that return 429 before the handler that
|
||||
// writes activity_log, so a rejection leaves no trace anywhere — the limit censors the evidence
|
||||
// of itself. Four production IPs sit at exactly 10 logins/min and there is no way to tell
|
||||
// whether that is one attacker or a NATed office colliding on a shared egress address.
|
||||
//
|
||||
// The count of rejections does NOT answer that. The count of DISTINCT ACCOUNTS per IP does:
|
||||
// one account hammered means the limiter is working as intended; several accounts each denied
|
||||
// a few times means real users are being locked out by a shared IP. That is the measurement
|
||||
// pinned here.
|
||||
//
|
||||
// The second thing pinned here is restraint: this must not quietly become a store of customer
|
||||
// email addresses. Identifiers are salted-hashed and only ever counted.
|
||||
|
||||
const { test, beforeEach } = require('node:test');
|
||||
const assert = require('node:assert/strict');
|
||||
const tel = require('../lib/limiter-telemetry');
|
||||
|
||||
beforeEach(() => tel.reset());
|
||||
|
||||
const rej = (ip, identifier, endpoint = '/api/auth/login') =>
|
||||
tel.recordRejection({ endpoint, ip, identifier });
|
||||
|
||||
test('THE POINT: one account hammered reads differently from many accounts denied', () => {
|
||||
for (let i = 0; i < 20; i++) rej('203.0.113.1', 'victim@example.com');
|
||||
for (const who of ['a@corp.test', 'b@corp.test', 'c@corp.test', 'd@corp.test']) rej('203.0.113.2', who);
|
||||
|
||||
const [attacker] = tel.snapshot().filter(r => r.ip === '203.0.113.1');
|
||||
const [office] = tel.snapshot().filter(r => r.ip === '203.0.113.2');
|
||||
|
||||
assert.equal(attacker.distinctIdentifiers, 1);
|
||||
assert.equal(attacker.likelySharedEgress, false, 'many rejections, one account -> limiter working');
|
||||
assert.equal(office.distinctIdentifiers, 4);
|
||||
assert.equal(office.likelySharedEgress, true, 'few rejections each, many accounts -> shared egress');
|
||||
assert.ok(office.rejections < attacker.rejections,
|
||||
'and the rejection COUNT alone would have ranked these the wrong way round');
|
||||
});
|
||||
|
||||
test('identifiers are never exposed — counts only', () => {
|
||||
rej('203.0.113.3', 'secret.person@customer.example');
|
||||
const dump = JSON.stringify(tel.snapshot());
|
||||
assert.doesNotMatch(dump, /secret\.person/, 'no address in the snapshot');
|
||||
assert.doesNotMatch(dump, /customer\.example/, 'not even the domain');
|
||||
assert.match(dump, /"distinctIdentifiers":1/);
|
||||
});
|
||||
|
||||
test('the same account in different case is one account, not two', () => {
|
||||
rej('203.0.113.4', 'Bob@Example.COM');
|
||||
rej('203.0.113.4', 'bob@example.com');
|
||||
assert.equal(tel.snapshot()[0].distinctIdentifiers, 1, 'or an attacker could inflate the count and look like an office');
|
||||
});
|
||||
|
||||
test('endpoint and IP are keyed separately', () => {
|
||||
rej('203.0.113.5', 'x@y.z', '/api/auth/login');
|
||||
rej('203.0.113.5', 'x@y.z', '/api/auth/register');
|
||||
rej('203.0.113.6', 'x@y.z', '/api/auth/login');
|
||||
assert.equal(tel.snapshot().length, 3, 'three distinct buckets');
|
||||
});
|
||||
|
||||
test('a rejection with no identifier still counts', () => {
|
||||
// Not every limited endpoint carries an email (reset-password redeem, totp verify).
|
||||
const t = rej('203.0.113.7', undefined, '/api/auth/reset-password');
|
||||
assert.equal(t.rejections, 1);
|
||||
assert.equal(t.distinctIdentifiers, 0);
|
||||
});
|
||||
|
||||
test('memory is bounded, and says so rather than silently undercounting', () => {
|
||||
for (let i = 0; i < tel.MAX_IDS_PER_KEY + 25; i++) rej('203.0.113.8', `u${i}@x.test`);
|
||||
const row = tel.snapshot()[0];
|
||||
assert.equal(row.distinctIdentifiers, tel.MAX_IDS_PER_KEY, 'capped');
|
||||
assert.equal(row.identifiersTruncated, true, 'and flagged, so the number is not read as exact');
|
||||
});
|
||||
|
||||
test('key count is bounded under a flood of distinct IPs', () => {
|
||||
for (let i = 0; i < tel.MAX_KEYS + 500; i++) rej(`198.51.100.${i}`, 'x@y.z');
|
||||
assert.ok(tel.snapshot().length <= tel.MAX_KEYS, 'cannot be grown without limit by spraying IPs');
|
||||
});
|
||||
|
||||
test('busiest first, so the snapshot is readable at a glance', () => {
|
||||
rej('203.0.113.9', 'a@x.t');
|
||||
for (let i = 0; i < 5; i++) rej('203.0.113.10', 'b@x.t');
|
||||
assert.equal(tel.snapshot()[0].ip, '203.0.113.10');
|
||||
});
|
||||
Loading…
Reference in a new issue