feat(inbox): logs du cycle de l'inbox virtuelle (dépôt/lecture/watch)
Réutilise le format identité-first [<id>][polyfill] d'access-log : deposit/read/materialize/readSynced + watch (materializing vs unchanged-skip). Gated par debugAccessLog, aucun changement de comportement. tsc 0, bun test 126. Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_014GbGgNEHRejVKoREvFuDFg
This commit is contained in:
@@ -29,7 +29,13 @@ import { subscribeDoc } from "./subscribe";
|
|||||||
import { ensureRepoOpen } from "./open-repo";
|
import { ensureRepoOpen } from "./open-repo";
|
||||||
import { getCurrentUser, getStoreRegistryDeps } from "./polyfill";
|
import { getCurrentUser, getStoreRegistryDeps } from "./polyfill";
|
||||||
import { escapeLiteral } from "./sparql";
|
import { escapeLiteral } from "./sparql";
|
||||||
import { accessLogPrefix } from "./access-log";
|
import {
|
||||||
|
accessLogPrefix,
|
||||||
|
enabled as accessLogEnabled,
|
||||||
|
logAccess,
|
||||||
|
logStage,
|
||||||
|
shortNuri,
|
||||||
|
} from "./access-log";
|
||||||
import type { Nuri, PrincipalId } from "./types";
|
import type { Nuri, PrincipalId } from "./types";
|
||||||
|
|
||||||
// --- deposit model --------------------------------------------------------
|
// --- deposit model --------------------------------------------------------
|
||||||
@@ -76,6 +82,28 @@ async function sessionId(): Promise<string> {
|
|||||||
return (await getStoreRegistryDeps().getSession()).sessionId;
|
return (await getStoreRegistryDeps().getSession()).sessionId;
|
||||||
}
|
}
|
||||||
|
|
||||||
|
// --- diagnostic logging helper ---------------------------------------------
|
||||||
|
|
||||||
|
/**
|
||||||
|
* Best-effort, length-capped JSON rendering of a deposit payload for the
|
||||||
|
* inbox diagnostic log (see {@link enabled}/{@link logAccess}). This module
|
||||||
|
* stays domain-agnostic (see module header) — it never interprets payload
|
||||||
|
* fields, it only dumps them verbatim so the consumer's own shape (e.g. a
|
||||||
|
* Festipod participation: `{ participantId, eventId, … }`) is visible in the
|
||||||
|
* log without this module knowing that shape. Capped so one oversized payload
|
||||||
|
* can't blow up a log line; a payload that fails to stringify (e.g. a
|
||||||
|
* circular structure a caller mistakenly passed) falls back to `String()`.
|
||||||
|
*/
|
||||||
|
function summarizePayload(payload: unknown): string {
|
||||||
|
let s: string;
|
||||||
|
try {
|
||||||
|
s = JSON.stringify(payload) ?? String(payload);
|
||||||
|
} catch {
|
||||||
|
s = String(payload);
|
||||||
|
}
|
||||||
|
return s.length > 200 ? s.slice(0, 200) + "…" : s;
|
||||||
|
}
|
||||||
|
|
||||||
// --- SPARQL result helpers ------------------------------------------------
|
// --- SPARQL result helpers ------------------------------------------------
|
||||||
|
|
||||||
/** Tolerant extraction of SPARQL SELECT bindings across possible shapes. */
|
/** Tolerant extraction of SPARQL SELECT bindings across possible shapes. */
|
||||||
@@ -145,6 +173,17 @@ export async function post(targetInbox: Nuri, opts: PostOptions): Promise<void>
|
|||||||
<${P.ts}> "${ts}"${fromTriple} .
|
<${P.ts}> "${ts}"${fromTriple} .
|
||||||
}`;
|
}`;
|
||||||
await sparqlUpdate(sid, update, targetInbox, "deposit");
|
await sparqlUpdate(sid, update, targetInbox, "deposit");
|
||||||
|
// Domain-level diagnostic (on top of docs.ts's generic access-path WRITE log):
|
||||||
|
// who deposited WHAT into which inbox — the decoded payload, not just the
|
||||||
|
// triple-write. Gated by the same access-log flag; skip the JSON work when off.
|
||||||
|
if (accessLogEnabled()) {
|
||||||
|
logAccess(
|
||||||
|
"WRITE",
|
||||||
|
targetInbox,
|
||||||
|
"inbox deposit",
|
||||||
|
" from=" + (from ?? "anonymous") + " payload=" + summarizePayload(opts.payload ?? null),
|
||||||
|
);
|
||||||
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
// --- read --------------------------------------------------------------
|
// --- read --------------------------------------------------------------
|
||||||
@@ -191,6 +230,26 @@ export async function read(targetInbox: Nuri): Promise<Deposit[]> {
|
|||||||
deposits.push({ from: fromValue ? fromValue : null, payload, ts });
|
deposits.push({ from: fromValue ? fromValue : null, payload, ts });
|
||||||
}
|
}
|
||||||
deposits.sort((a, b) => a.ts - b.ts);
|
deposits.sort((a, b) => a.ts - b.ts);
|
||||||
|
// Domain-level diagnostic (on top of docs.ts's generic access-path READ log
|
||||||
|
// of raw triple-rows): how many DEPOSITS were found, and the decoded data of
|
||||||
|
// each — the exact visibility needed to trace materialization at the owner
|
||||||
|
// side. Gated by the same access-log flag; skip the JSON work when off.
|
||||||
|
if (accessLogEnabled()) {
|
||||||
|
logAccess(
|
||||||
|
"READ",
|
||||||
|
targetInbox,
|
||||||
|
"inbox materialize",
|
||||||
|
" → " + deposits.length + " message(s)",
|
||||||
|
);
|
||||||
|
for (const d of deposits) {
|
||||||
|
logAccess(
|
||||||
|
"READ",
|
||||||
|
targetInbox,
|
||||||
|
"inbox message",
|
||||||
|
" ts=" + d.ts + " from=" + (d.from ?? "anonymous") + " payload=" + summarizePayload(d.payload),
|
||||||
|
);
|
||||||
|
}
|
||||||
|
}
|
||||||
return deposits;
|
return deposits;
|
||||||
}
|
}
|
||||||
|
|
||||||
@@ -218,6 +277,11 @@ export const materialize = read;
|
|||||||
* the unit fake-ng path (no `doc_subscribe`) so `bun test` is unaffected.
|
* the unit fake-ng path (no `doc_subscribe`) so `bun test` is unaffected.
|
||||||
*/
|
*/
|
||||||
export async function readSynced(targetInbox: Nuri): Promise<Deposit[]> {
|
export async function readSynced(targetInbox: Nuri): Promise<Deposit[]> {
|
||||||
|
// Marks the cold, connection-triggered entry point in the trace — the BARRIER
|
||||||
|
// line (open-repo.ts) and the "inbox materialize"/"inbox message" lines below
|
||||||
|
// (from the read() this wraps) follow right after, so a live session shows
|
||||||
|
// the whole owner-reconnect sequence together.
|
||||||
|
logStage("READSYNCED " + shortNuri(targetInbox) + " (cold, barrier-gated)");
|
||||||
await ensureRepoOpen(targetInbox);
|
await ensureRepoOpen(targetInbox);
|
||||||
return read(targetInbox);
|
return read(targetInbox);
|
||||||
}
|
}
|
||||||
@@ -251,7 +315,22 @@ export function watch(
|
|||||||
if (stopped) return;
|
if (stopped) return;
|
||||||
try {
|
try {
|
||||||
const deposits = await read(targetInbox);
|
const deposits = await read(targetInbox);
|
||||||
if (!stopped && deposits.length !== lastCount) {
|
const changed = deposits.length !== lastCount;
|
||||||
|
// Owner-side processing decision: did this push actually grow the
|
||||||
|
// deposit set (→ onDeposits fires, the polyfill's stand-in for
|
||||||
|
// materialization) or was it a no-op push (→ skipped)? This is the
|
||||||
|
// exact line to check for the "must reconnect an extra time" symptom:
|
||||||
|
// a push whose read still sees the OLD count means the barrier/read
|
||||||
|
// raced the write, not that watch itself failed to fire.
|
||||||
|
if (accessLogEnabled()) {
|
||||||
|
logAccess(
|
||||||
|
"READ",
|
||||||
|
targetInbox,
|
||||||
|
"inbox watch",
|
||||||
|
" → " + deposits.length + " message(s)" + (changed ? " (materializing)" : " (unchanged, skip)"),
|
||||||
|
);
|
||||||
|
}
|
||||||
|
if (!stopped && changed) {
|
||||||
lastCount = deposits.length;
|
lastCount = deposits.length;
|
||||||
onDeposits(deposits);
|
onDeposits(deposits);
|
||||||
}
|
}
|
||||||
|
|||||||
Reference in New Issue
Block a user