fix(#142): dedup repeated content-ack reports (secondary load)

device:content-ack logged + emitted every message, so a device repeatedly
reporting the same "content <id>: ready" (observed from an older app version)
added avoidable load per message.

- Suppress identical (device_id, content_id, status) reports within
  config.contentAckDedupMs (default 10s), modeled on the lastPlayLogAt throttle.
  A status change has a different key and passes immediately; a fresh report after
  the window passes too. In-memory, resets on restart. The handler does no DB
  writes, so this is purely shedding redundant log+emit work.

test: integration over a real authenticated device socket — a burst of identical
"ready" collapses to one log/emit, a "ready" after the window passes, and a status
change is never deduped. Unique PORT (3984).

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
This commit is contained in:
ScreenTinker 2026-06-27 19:35:04 -05:00
parent 29a8896aa8
commit 15448d1c5d
3 changed files with 104 additions and 0 deletions

View file

@ -143,4 +143,10 @@ module.exports = {
// is LOWER than the old hardcoded 7 days (the reporter's bloat happened under 7d); // is LOWER than the old hardcoded 7 days (the reporter's bloat happened under 7d);
// 2-3 days is plenty for the dashboard's 24h uptime view + diagnostics. // 2-3 days is plenty for the dashboard's 24h uptime view + diagnostics.
statusLogRetentionDays: parseFloat(process.env.STATUS_LOG_RETENTION_DAYS) || 3, statusLogRetentionDays: parseFloat(process.env.STATUS_LOG_RETENTION_DAYS) || 3,
// #142 content-ack dedup window (deviceSocket.js). A device (esp. older apps)
// can spam "content <id>: ready" for the same item; suppress identical
// (device_id, content_id, status) reports within this window. A status CHANGE
// has a different key and passes immediately. In-memory; resets on restart.
contentAckDedupMs: parseInt(process.env.CONTENT_ACK_DEDUP_MS) || 10000,
}; };

View file

@ -0,0 +1,85 @@
'use strict';
// #142 step 5 — content-ack dedup. Repeated identical (device_id, content_id, status)
// reports are suppressed within config.contentAckDedupMs; a status change or a report
// after the window passes. Observed via the server log (the handler logs+emits only
// when it does NOT dedup). Unique PORT (3984) to avoid the collision class.
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 ioClient = require('socket.io-client');
const PORT = 3984;
const BASE = `http://127.0.0.1:${PORT}`;
const DATA_DIR = path.join(os.tmpdir(), 'st-ack-' + crypto.randomBytes(4).toString('hex'));
const LOG = path.join(os.tmpdir(), 'st-ack-' + crypto.randomBytes(4).toString('hex') + '.log');
const DEDUP_MS = 600;
let proc;
const sleep = (ms) => new Promise(r => setTimeout(r, ms));
before(async () => {
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', CONTENT_ACK_DEDUP_MS: String(DEDUP_MS) },
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 sleep(250);
}
if (!up) throw new Error('server did not boot:\n' + fs.readFileSync(LOG, 'utf8').slice(-2000));
});
after(() => { try { proc.kill('SIGKILL'); } catch { /* */ } });
function provision() {
const code = String(crypto.randomInt(100000, 1000000));
return new Promise((resolve) => {
const sock = ioClient(`${BASE}/device`, { transports: ['websocket'], reconnection: false, forceNew: true });
sock.on('connect', () => sock.emit('device:register', { pairing_code: code }));
sock.on('device:registered', (d) => { try { sock.close(); } catch { /* */ } resolve({ id: d.device_id, token: d.device_token }); });
setTimeout(() => resolve(null), 4000);
});
}
function openRegistered(dev) {
return new Promise((resolve, reject) => {
const sock = ioClient(`${BASE}/device`, { transports: ['websocket'], reconnection: false, forceNew: true });
sock.on('connect', () => sock.emit('device:register', { device_id: dev.id, device_token: dev.token, device_info: { app_version: 'test' } }));
sock.on('device:registered', () => resolve(sock));
sock.on('device:auth-error', () => reject(new Error('auth-error')));
setTimeout(() => reject(new Error('register timeout')), 4000);
});
}
test('repeated identical content-acks are deduped; window-expiry and status-change pass', async () => {
const dev = await provision();
assert.ok(dev, 'device provisioned');
const sock = await openRegistered(dev);
const cid = 'cid-' + crypto.randomBytes(3).toString('hex');
// 5 rapid identical "ready" within the dedup window -> only ONE should log/emit
for (let i = 0; i < 5; i++) { sock.emit('device:content-ack', { device_id: dev.id, content_id: cid, status: 'ready' }); await sleep(40); }
// wait past the window, then "ready" again -> passes (a fresh report)
await sleep(DEDUP_MS + 250);
sock.emit('device:content-ack', { device_id: dev.id, content_id: cid, status: 'ready' });
// a status CHANGE has a different key -> passes immediately
await sleep(60);
sock.emit('device:content-ack', { device_id: dev.id, content_id: cid, status: 'error' });
await sleep(400);
try { sock.close(); } catch { /* */ }
const log = fs.readFileSync(LOG, 'utf8');
const ready = (log.match(new RegExp(`content ${cid}: ready`, 'g')) || []).length;
const err = (log.match(new RegExp(`content ${cid}: error`, 'g')) || []).length;
assert.equal(ready, 2, 'a burst of identical "ready" collapses to one; a second after the window passes -> 2 total');
assert.equal(err, 1, 'a status change is not deduped');
});

View file

@ -28,6 +28,12 @@ const OFFLINE_DEBOUNCE_MS = 5000;
// event is still forwarded every time, so the UI is unaffected. In-memory only. // event is still forwarded every time, so the UI is unaffected. In-memory only.
const lastPlayLogAt = new Map(); const lastPlayLogAt = new Map();
const PLAY_LOG_MIN_GAP_MS = 2000; const PLAY_LOG_MIN_GAP_MS = 2000;
// #142 content-ack dedup. An older app can spam "content <id>: ready" for the same
// item; each was logged + emitted individually (secondary load). Suppress identical
// (device_id, content_id, status) reports within config.contentAckDedupMs. A status
// CHANGE has a different key and passes immediately. In-memory; resets on restart.
const lastContentAck = new Map();
const { getUserPlan, getUserDeviceCount } = require('../middleware/subscription'); const { getUserPlan, getUserDeviceCount } = require('../middleware/subscription');
// Phase 2.3: deviceRoom() resolves a device_id to its workspace room so // Phase 2.3: deviceRoom() resolves a device_id to its workspace room so
// dashboardNs.emit can be scoped instead of broadcast platform-wide. // dashboardNs.emit can be scoped instead of broadcast platform-wide.
@ -579,6 +585,13 @@ module.exports = function setupDeviceSocket(io) {
if (!requireDeviceAuth()) return; if (!requireDeviceAuth()) return;
const { device_id, content_id, status } = data; const { device_id, content_id, status } = data;
if (device_id !== currentDeviceId) return; if (device_id !== currentDeviceId) return;
// #142: drop repeats of the same (device, content, status) within the dedup
// window. Only a change (new content/status) or a report after the window
// logs+emits, so a device spamming the same "ready" can't add load.
const ackKey = `${device_id}|${content_id}|${status}`;
const nowAck = Date.now();
if (nowAck - (lastContentAck.get(ackKey) || 0) < config.contentAckDedupMs) return;
lastContentAck.set(ackKey, nowAck);
console.log(`Device ${device_id} content ${content_id}: ${status}`); console.log(`Device ${device_id} content ${content_id}: ${status}`);
emitToDeviceWorkspace(dashboardNs, device_id, 'dashboard:content-ack', { device_id, content_id, status }); emitToDeviceWorkspace(dashboardNs, device_id, 'dashboard:content-ack', { device_id, content_id, status });
}); });