247 lines
9.4 KiB
JavaScript
247 lines
9.4 KiB
JavaScript
const assert = require("assert");
|
|
const fs = require("fs");
|
|
const path = require("path");
|
|
|
|
const root = path.join(__dirname, "..");
|
|
const sandbox = fs.mkdtempSync(path.join(root, ".tmp-lumi-logging-"));
|
|
const serviceDir = path.join(sandbox, "src", "services");
|
|
fs.mkdirSync(serviceDir, { recursive: true });
|
|
for (const file of ["db.js", "logger.js", "web-events.js"]) {
|
|
fs.copyFileSync(path.join(root, "src", "services", file), path.join(serviceDir, file));
|
|
}
|
|
|
|
let database;
|
|
try {
|
|
database = require(path.join(serviceDir, "db.js"));
|
|
database.db.exec(`CREATE TABLE logs (
|
|
id INTEGER PRIMARY KEY AUTOINCREMENT,
|
|
level TEXT NOT NULL,
|
|
message TEXT NOT NULL,
|
|
details TEXT,
|
|
created_at INTEGER NOT NULL
|
|
)`);
|
|
database.migrate();
|
|
const logger = require(path.join(serviceDir, "logger.js"));
|
|
const { db } = database;
|
|
const columns = db.prepare("PRAGMA table_info(logs)").all().map((column) => column.name);
|
|
for (const column of ["source", "category", "event", "request_id"]) {
|
|
assert(columns.includes(column), `logs.${column} migration`);
|
|
}
|
|
|
|
logger.log("info", "Legacy-compatible entry", { status: "ready" });
|
|
const pluginLog = logger.createLogger("plugin:example", { category: "plugin" });
|
|
pluginLog.warn("Example warning", {
|
|
access_token: "must-not-be-stored",
|
|
nested: { password: "also-secret", safe: "visible" },
|
|
webhook_signature: "signature-must-not-be-stored",
|
|
cookie_header: "Cookie: session=also-hidden",
|
|
device_header: "LumiDevice device-id.device-secret",
|
|
url: "https://example.com/run?token=hidden&mode=safe"
|
|
}, { event: "example_warning", requestId: "request-123" });
|
|
logger.withLogContext({ source: "core:test", category: "verification", event: "context_entry" }, () => {
|
|
logger.log("debug", "Context-aware entry", "authorization=private-value");
|
|
});
|
|
|
|
const all = logger.listLogs({ limit: 20 });
|
|
assert.equal(all.length, 3);
|
|
const warning = all.find((entry) => entry.event === "example_warning");
|
|
assert.equal(warning.source, "plugin:example");
|
|
assert.equal(warning.category, "plugin");
|
|
assert.equal(warning.request_id, "request-123");
|
|
assert(warning.details.includes("[REDACTED]"));
|
|
assert.equal(warning.details.includes("must-not-be-stored"), false);
|
|
assert.equal(warning.details.includes("also-secret"), false);
|
|
assert.equal(warning.details.includes("signature-must-not-be-stored"), false);
|
|
assert.equal(warning.details.includes("also-hidden"), false);
|
|
assert.equal(warning.details.includes("device-secret"), false);
|
|
assert.equal(warning.details.includes("token=hidden"), false);
|
|
assert(warning.details.includes("visible"));
|
|
|
|
assert.equal(logger.listLogs({ sources: ["plugin:example"] }).length, 1);
|
|
assert.equal(logger.listLogs({ categories: ["verification"] }).length, 1);
|
|
assert.equal(logger.listLogs({ search: "request-123" }).length, 1);
|
|
assert.equal(logger.listLogs({ levels: ["error"] }).length, 0);
|
|
const summary = logger.summarizeLogs({});
|
|
assert.equal(summary.total, 3);
|
|
assert.equal(summary.levels.warn, 1);
|
|
assert(logger.listLogFacets().sources.some((item) => item.value === "plugin:example" && item.count === 1));
|
|
|
|
db.prepare("UPDATE logs SET created_at = ? WHERE message = ?").run(
|
|
Date.now() - 45 * 24 * 60 * 60 * 1000,
|
|
"Legacy-compatible entry"
|
|
);
|
|
const cleanup = logger.cleanupLogs({ maxAgeDays: 30, maxEntries: 1000 });
|
|
assert.equal(cleanup.expired, 1);
|
|
assert.equal(logger.listLogs({ search: "Legacy-compatible" }).length, 0);
|
|
|
|
const logView = fs.readFileSync(path.join(root, "src", "web", "views", "admin-logs.ejs"), "utf8");
|
|
assert.match(logView, /data-log-source/);
|
|
assert.match(logView, /data-log-category/);
|
|
assert.match(logView, /data-log-live-status/);
|
|
assert.match(logView, /name="format"/);
|
|
const serverSource = fs.readFileSync(path.join(root, "src", "web", "server.js"), "utf8");
|
|
assert.match(serverSource, /app\.post\("\/admin\/logs\/retention"/);
|
|
assert.match(serverSource, /summarizeLogs\(query\)/);
|
|
assert.match(serverSource, /"admin_action"/);
|
|
|
|
verifyRuntimeLoggingConventions();
|
|
|
|
console.log("Logging verification passed: structured scope, redaction, search, summaries, retention, runtime conventions, admin audit, and live UI wiring.");
|
|
} finally {
|
|
try { database?.db?.close(); } catch {}
|
|
fs.rmSync(sandbox, { recursive: true, force: true });
|
|
}
|
|
|
|
function verifyRuntimeLoggingConventions() {
|
|
const files = [
|
|
...runtimeJavaScriptFiles(path.join(root, "src")),
|
|
...runtimeJavaScriptFiles(path.join(root, "plugins"))
|
|
];
|
|
const directConsoleExceptions = new Set([
|
|
path.join(root, "src", "services", "logger.js")
|
|
]);
|
|
const sourcePattern = /createLogger\(\s*["']([^"']+)["']/g;
|
|
const loggerCallPattern =
|
|
/\b(?:[A-Za-z_$][\w$]*(?:Log|Logger)|logger)\.(?:log|debug|info|warn|error)(?:\?\.)?\s*\(/g;
|
|
|
|
for (const file of files) {
|
|
const source = fs.readFileSync(file, "utf8");
|
|
if (!directConsoleExceptions.has(file)) {
|
|
assert.doesNotMatch(
|
|
source,
|
|
/\bconsole\.(?:debug|info|log|warn|error)\s*\(/,
|
|
`${path.relative(root, file)} must use a named operational logger`
|
|
);
|
|
}
|
|
assert.doesNotMatch(
|
|
source,
|
|
/\{\s*log\s*\}\s*=\s*require\(["'][^"']*services\/logger["']\)/,
|
|
`${path.relative(root, file)} must not use the legacy global log function`
|
|
);
|
|
|
|
for (const match of source.matchAll(sourcePattern)) {
|
|
assert.match(
|
|
match[1],
|
|
/^(?:companion|core|platform|plugin):[a-z0-9_.:-]+$/,
|
|
`${path.relative(root, file)} has an unscoped logger source: ${match[1]}`
|
|
);
|
|
}
|
|
|
|
for (const match of source.matchAll(loggerCallPattern)) {
|
|
const openIndex = source.indexOf("(", match.index);
|
|
const closeIndex = matchingParenthesis(source, openIndex);
|
|
assert(closeIndex > openIndex, `${path.relative(root, file)} contains an unreadable logger call`);
|
|
const call = source.slice(match.index, closeIndex + 1);
|
|
assert.match(
|
|
call,
|
|
/\bevent\s*:/,
|
|
`${path.relative(root, file)} operational logger call is missing a stable event ID: ${call.split(/\r?\n/, 1)[0]}`
|
|
);
|
|
const eventLiteral = /\bevent\s*:\s*["'`]([^"'`]+)["'`]/.exec(call)?.[1];
|
|
if (eventLiteral && !eventLiteral.includes("${")) {
|
|
assert.match(
|
|
eventLiteral,
|
|
/^[a-z0-9]+(?:_[a-z0-9]+)*$/,
|
|
`${path.relative(root, file)} has a non-standard event ID: ${eventLiteral}`
|
|
);
|
|
}
|
|
}
|
|
}
|
|
|
|
const companionRuntime = fs.readFileSync(
|
|
path.join(root, "companion", "src", "Lumi.Companion.App", "CompanionRuntime.cs"),
|
|
"utf8"
|
|
);
|
|
assert.match(companionRuntime, /source = "companion:core"/);
|
|
assert.match(companionRuntime, /@event = eventId/);
|
|
assert.match(companionRuntime, /CompanionLogSanitizer\.Sanitize\(message\)/);
|
|
assert.match(companionRuntime, /PruneLogs\(\)/);
|
|
|
|
const songRuntime = fs.readFileSync(
|
|
path.join(root, "companion", "plugins", "Lumi.Companion.SongOverlay", "SongOverlayRuntime.cs"),
|
|
"utf8"
|
|
);
|
|
assert.match(songRuntime, /source = \$"plugin:\{PluginId\}"/);
|
|
assert.match(songRuntime, /CompanionLogSanitizer\.Sanitize\(error\.ToString\(\)\)/);
|
|
assert.match(songRuntime, /song-overlay-\{DateTime\.UtcNow:yyyy-MM-dd\}\.jsonl/);
|
|
assert.doesNotMatch(songRuntime, /song-overlay-\{DateTime\.UtcNow:yyyyMMdd\}\.log/);
|
|
|
|
const obsBridge = fs.readFileSync(
|
|
path.join(root, "companion", "native", "obs-bridge", "src", "plugin.cpp"),
|
|
"utf8"
|
|
);
|
|
const nativeLogCalls = [...obsBridge.matchAll(/\bblog\([\s\S]*?\);/g)].map((match) => match[0]);
|
|
assert(nativeLogCalls.length > 0, "the OBS Bridge logging boundary must remain covered");
|
|
for (const call of nativeLogCalls) {
|
|
assert.match(call, /\[Lumi Companion\] event=[a-z0-9]+(?:_[a-z0-9]+)*/);
|
|
}
|
|
}
|
|
|
|
function runtimeJavaScriptFiles(start) {
|
|
const skippedDirectories = new Set(["bin", "node_modules", "obj", "public", "scripts", "tests"]);
|
|
const files = [];
|
|
for (const entry of fs.readdirSync(start, { withFileTypes: true })) {
|
|
if (entry.name.startsWith(".")) continue;
|
|
const target = path.join(start, entry.name);
|
|
if (entry.isDirectory()) {
|
|
if (!skippedDirectories.has(entry.name)) files.push(...runtimeJavaScriptFiles(target));
|
|
} else if (entry.isFile() && entry.name.endsWith(".js")) {
|
|
files.push(target);
|
|
}
|
|
}
|
|
return files;
|
|
}
|
|
|
|
function matchingParenthesis(source, openIndex) {
|
|
let depth = 0;
|
|
let quote = "";
|
|
let escaped = false;
|
|
let lineComment = false;
|
|
let blockComment = false;
|
|
for (let index = openIndex; index < source.length; index += 1) {
|
|
const character = source[index];
|
|
const next = source[index + 1];
|
|
if (lineComment) {
|
|
if (character === "\n") lineComment = false;
|
|
continue;
|
|
}
|
|
if (blockComment) {
|
|
if (character === "*" && next === "/") {
|
|
blockComment = false;
|
|
index += 1;
|
|
}
|
|
continue;
|
|
}
|
|
if (quote) {
|
|
if (escaped) {
|
|
escaped = false;
|
|
} else if (character === "\\") {
|
|
escaped = true;
|
|
} else if (character === quote) {
|
|
quote = "";
|
|
}
|
|
continue;
|
|
}
|
|
if (character === "/" && next === "/") {
|
|
lineComment = true;
|
|
index += 1;
|
|
continue;
|
|
}
|
|
if (character === "/" && next === "*") {
|
|
blockComment = true;
|
|
index += 1;
|
|
continue;
|
|
}
|
|
if (character === "'" || character === "\"" || character === "`") {
|
|
quote = character;
|
|
continue;
|
|
}
|
|
if (character === "(") depth += 1;
|
|
if (character === ")") {
|
|
depth -= 1;
|
|
if (depth === 0) return index;
|
|
}
|
|
}
|
|
return -1;
|
|
}
|