Files
Sylvain Duchesne 70de7afa3c feat(logs): logs données restructurés — identité en préfixe, trace résolution/barrière, inspection outbox
Chemin données bas-niveau du polyfill rendu lisible pour diagnostiquer en session live :

- Format identité-en-premier : `[<identity>][polyfill] OP shortNuri (label)` ;
  console.error épars (store-registry, inbox) unifiés au même préfixe.
- Trace (derrière le flag debug) : issue de la barrière ensureRepoOpen
  (synced|timed-out + durée) et résultat sémantique de chaque étage de résolution
  (resolvePointer/canonicalDoc/resolveAccount/resolveShimDoc/readScopeIndex).
- outbox-log.ts (nouveau) : inspection read-only de l'outbox hors-ligne au
  démarrage de session ; console.warn si non vide (anomalie, toujours visible),
  sous flag si vide. Le comptage seul est fiable (payloads BARE opaques côté JS).

Pas de changement fonctionnel. bun test 126 pass ; tsc 0 erreur.

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_014GbGgNEHRejVKoREvFuDFg
2026-07-14 10:37:46 +02:00

283 lines
10 KiB
TypeScript

/**
* access-log.test.ts — behavioral tests for logAccess / setAccessLog / enabled
* (src/access-log.ts), as wired through the docs primitives (src/docs.ts).
*
* Tests:
* (a) OFF by default: reads + writes via sparqlQuery / sparqlUpdate / docCreate
* emit nothing to console.log.
* (b) ON via configure({ debugAccessLog: true }): each read/write emits a line
* matching `[<identity>][polyfill] READ/WRITE <shortNuri> (<label>)` (identity
* FIRST, `[polyfill]` glued right after) plus row-count suffix on READs. The
* NURI is shortened by shortNuri (did:ng:o: prefix + :v: suffix stripped,
* RepoID truncated to 8 chars + ellipsis).
* (c) ON via env var NG_EVENTUALLY_ACCESS_LOG=1: same behavior without changing
* calling code.
* (d) Identity follows setCurrentUser: after setCurrentUser the prefix changes.
*
* Spy approach: replace console.log with a mock, restore it after each test.
* Env var tests set/delete process.env.NG_EVENTUALLY_ACCESS_LOG and restore it.
*/
import { describe, it, expect, mock, beforeEach, afterEach, afterAll } from "bun:test";
import { setAccessLog, enabled, shortNuri } from "../src/access-log";
import { docCreate, sparqlUpdate, sparqlQuery } from "../src/docs";
import {
configure,
configureStoreRegistry,
resetStoreRegistry,
resetConfig,
setCurrentUser,
getCurrentUser,
} from "../src/polyfill";
// ---------------------------------------------------------------------------
// Helpers
// ---------------------------------------------------------------------------
function fakeNg() {
return {
doc_create: mock(async (..._a: unknown[]) => "did:ng:o:log-doc"),
sparql_update: mock(async (..._a: unknown[]) => undefined),
sparql_query: mock(async (..._a: unknown[]) => ({
results: { bindings: [{ x: { value: "v" } }] }, // 1 row so row-count is visible
})),
};
}
function injectFake(debugAccessLog = false) {
const ng = fakeNg();
configure({ ng: ng as any, useShape: (() => {}) as any, debugAccessLog });
configureStoreRegistry({
getSession: async () => ({ sessionId: "sid-log", privateStoreId: "P" }),
});
return ng;
}
// Capture console.log lines for the duration of a test.
// Returns the captured lines array and a restore function.
function spyConsoleLog(): { lines: string[]; restore: () => void } {
const lines: string[] = [];
const orig = console.log;
console.log = (...args: unknown[]) => {
lines.push(args.map(String).join(" "));
};
return { lines, restore: () => { console.log = orig; } };
}
// ---------------------------------------------------------------------------
// Lifecycle: restore config state after each test to avoid cross-test bleed.
// ---------------------------------------------------------------------------
// Save the env var value that was present BEFORE any test ran, so tests
// that run in an environment where NG_EVENTUALLY_ACCESS_LOG is already set
// don't permanently destroy that value.
const _originalEnvVar = process.env?.NG_EVENTUALLY_ACCESS_LOG;
afterEach(() => {
setAccessLog(false); // always reset the config toggle
setCurrentUser(null); // clear active identity
// Restore the original env var value (don't just delete — it may have existed before)
if ((globalThis as any)?.process?.env) {
if (_originalEnvVar === undefined) {
delete process.env.NG_EVENTUALLY_ACCESS_LOG;
} else {
process.env.NG_EVENTUALLY_ACCESS_LOG = _originalEnvVar;
}
}
});
afterAll(() => {
resetConfig();
resetStoreRegistry();
setAccessLog(false);
setCurrentUser(null);
});
// ---------------------------------------------------------------------------
// Tests
// ---------------------------------------------------------------------------
describe("access-log: OFF by default", () => {
beforeEach(() => {
// Force the env var OFF for these tests, regardless of the shell environment.
if ((globalThis as any)?.process?.env) {
delete process.env.NG_EVENTUALLY_ACCESS_LOG;
}
setAccessLog(false);
});
it("no console.log output for sparqlQuery when disabled", async () => {
injectFake(false);
const { lines, restore } = spyConsoleLog();
try {
await sparqlQuery("sid-log", "SELECT * {}");
} finally {
restore();
}
expect(lines.length).toBe(0);
});
it("no console.log output for sparqlUpdate when disabled", async () => {
injectFake(false);
const { lines, restore } = spyConsoleLog();
try {
await sparqlUpdate("sid-log", "INSERT DATA {}", "did:ng:o:x");
} finally {
restore();
}
expect(lines.length).toBe(0);
});
it("no console.log output for docCreate when disabled", async () => {
injectFake(false);
const { lines, restore } = spyConsoleLog();
try {
await docCreate("sid-log", "Graph", "data:graph", "store");
} finally {
restore();
}
expect(lines.length).toBe(0);
});
it("enabled() returns false when disabled", () => {
setAccessLog(false);
if (process.env) delete process.env.NG_EVENTUALLY_ACCESS_LOG;
expect(enabled()).toBe(false);
});
});
describe("access-log: ON via configure({ debugAccessLog: true })", () => {
beforeEach(() => {
setCurrentUser("alice");
});
it("sparqlQuery emits a READ line with identity, nuri, label, and row-count", async () => {
injectFake(true);
setCurrentUser("alice");
const { lines, restore } = spyConsoleLog();
try {
await sparqlQuery("sid-log", "SELECT * {}", undefined, "did:ng:o:q", "myLabel");
} finally {
restore();
}
expect(lines.length).toBe(1);
expect(lines[0]).toMatch(/^\[alice\]\[polyfill\] /); // identity-first, glued [polyfill] prefix
expect(lines[0]).toMatch(/READ/);
expect(lines[0]).toContain(shortNuri("did:ng:o:q")); // NURI shortened
expect(lines[0]).not.toContain("did:ng:o:"); // full prefix stripped
expect(lines[0]).toMatch(/myLabel/);
expect(lines[0]).toMatch(/→ 1 triple-rows/); // triple-count from the 1-row fake result
});
it("sparqlUpdate emits a WRITE line with identity, anchor nuri, and label", async () => {
injectFake(true);
setCurrentUser("alice");
const { lines, restore } = spyConsoleLog();
try {
await sparqlUpdate("sid-log", "INSERT DATA {}", "did:ng:o:w", "writeLabel");
} finally {
restore();
}
expect(lines.length).toBe(1);
expect(lines[0]).toMatch(/^\[alice\]\[polyfill\] /); // identity-first, glued [polyfill] prefix
expect(lines[0]).toMatch(/WRITE/);
expect(lines[0]).toContain(shortNuri("did:ng:o:w"));
expect(lines[0]).toMatch(/writeLabel/);
});
it("docCreate emits a WRITE line with identity and the returned nuri", async () => {
injectFake(true);
setCurrentUser("alice");
const { lines, restore } = spyConsoleLog();
try {
await docCreate("sid-log", "Graph", "data:graph", "store");
} finally {
restore();
}
expect(lines.length).toBe(1);
expect(lines[0]).toMatch(/^\[alice\]\[polyfill\] /); // identity-first, glued [polyfill] prefix
expect(lines[0]).toMatch(/WRITE/);
// The nuri is the value returned by ng.doc_create, shortened by shortNuri.
expect(lines[0]).toContain(shortNuri("did:ng:o:log-doc"));
});
it("enabled() returns true when set via setAccessLog", () => {
setAccessLog(true);
expect(enabled()).toBe(true);
});
});
describe("access-log: ON via env var NG_EVENTUALLY_ACCESS_LOG=1", () => {
it("emits READ line when env var is set, even without configure() setting", async () => {
// Set env var but do NOT pass debugAccessLog=true to configure
if (!(globalThis as any)?.process?.env) return; // skip in env-less runtimes
process.env.NG_EVENTUALLY_ACCESS_LOG = "1";
injectFake(false); // debugAccessLog = false explicitly
setCurrentUser("bob");
const { lines, restore } = spyConsoleLog();
try {
await sparqlQuery("sid-log", "SELECT * {}", undefined, "did:ng:o:env-q");
} finally {
restore();
}
expect(lines.length).toBe(1);
expect(lines[0]).toMatch(/^\[bob\]\[polyfill\] /); // identity-first, glued [polyfill] prefix
expect(lines[0]).toMatch(/READ/);
expect(lines[0]).toContain(shortNuri("did:ng:o:env-q"));
});
it("env var NG_EVENTUALLY_ACCESS_LOG=true also enables the log", async () => {
if (!(globalThis as any)?.process?.env) return;
process.env.NG_EVENTUALLY_ACCESS_LOG = "true";
injectFake(false);
setCurrentUser("charlie");
const { lines, restore } = spyConsoleLog();
try {
await sparqlUpdate("sid-log", "INSERT DATA {}", "did:ng:o:env-w");
} finally {
restore();
}
expect(lines.length).toBe(1);
expect(lines[0]).toMatch(/^\[charlie\]\[polyfill\] /); // identity-first, glued [polyfill] prefix
expect(lines[0]).toMatch(/WRITE/);
});
it("enabled() returns true when env var is set", () => {
if (!(globalThis as any)?.process?.env) return;
process.env.NG_EVENTUALLY_ACCESS_LOG = "1";
setAccessLog(false); // config toggle is off
expect(enabled()).toBe(true);
});
});
describe("access-log: identity follows setCurrentUser", () => {
it("prefix changes after setCurrentUser", async () => {
injectFake(true);
setCurrentUser("first-user");
const { lines, restore } = spyConsoleLog();
try {
await sparqlUpdate("sid-log", "INSERT DATA {}", "did:ng:o:id1", "step1");
setCurrentUser("second-user");
await sparqlUpdate("sid-log", "INSERT DATA {}", "did:ng:o:id2", "step2");
} finally {
restore();
}
expect(lines.length).toBe(2);
expect(lines[0]).toMatch(/^\[first-user\]\[polyfill\] /); // identity-first, glued [polyfill] prefix
expect(lines[1]).toMatch(/^\[second-user\]\[polyfill\] /);
});
it("prefix is (none) when no identity is set", async () => {
injectFake(true);
setCurrentUser(null); // no active identity
const { lines, restore } = spyConsoleLog();
try {
await sparqlUpdate("sid-log", "INSERT DATA {}", "did:ng:o:anon");
} finally {
restore();
}
expect(lines.length).toBe(1);
expect(lines[0]).toMatch(/^\[\(none\)\]\[polyfill\] /); // identity-first, glued [polyfill] prefix
});
});