feat(permission): complete shadow review events for offline analysis

- key inner-cmd decisive review events by requestId so link decisions join offline
- record judge runtime id, prompt and tool schema versions, end-to-end and model latency, input and output usage, and evidence-quality flags on every judge result row
- record forwarded and session-mismatch preflight defers so they stay visible in the offline denominator
This commit is contained in:
2026-08-17 16:58:10 +08:00
parent 81f1da4100
commit 42f0a0aaab
6 changed files with 289 additions and 77 deletions
+121 -24
View File
@@ -2,6 +2,7 @@ import type { ExtensionAPI } from "@earendil-works/pi-coding-agent";
import { import {
getPermissionsService, getPermissionsService,
PERMISSIONS_READY_CHANNEL, PERMISSIONS_READY_CHANNEL,
type PromptPermissionDetails,
} from "@gotgenes/pi-permission-system"; } from "@gotgenes/pi-permission-system";
import { buildBashJudgmentEvidence } from "./evidence"; import { buildBashJudgmentEvidence } from "./evidence";
import { import {
@@ -9,6 +10,7 @@ import {
requestStructuredVerdict, requestStructuredVerdict,
type ModelAvailability, type ModelAvailability,
} from "./model"; } from "./model";
import { PROMPT_VERSION, TOOL_SCHEMA_VERSION } from "./prompt";
const LINK_NAME = "ai-bash-judge"; const LINK_NAME = "ai-bash-judge";
const REVIEW_SCHEMA_VERSION = 1; const REVIEW_SCHEMA_VERSION = 1;
@@ -18,12 +20,64 @@ interface RootSession {
readonly expectedSessionId: string; readonly expectedSessionId: string;
readonly model: ModelAvailability; readonly model: ModelAvailability;
readonly shutdown: AbortController; readonly shutdown: AbortController;
/** Opaque per-runtime identity for cohort segmentation. */
readonly judgeRuntimeId: string;
} }
function reasonLength(reason: string): number { function reasonLength(reason: string): number {
return [...reason].length; return [...reason].length;
} }
/**
* Evidence-quality flags without evidence content (PIEXTENSIO-9).
*
* This bootstrap slice sends command-only input: no conversation, no cwd,
* no explicit user text (see docs/research/ai-bash-judge-input-minimality).
* `false` marks a definitively absent field; `null` marks one this slice
* does not capture, so the analyzer never mistakes absence for zero.
*/
function evidenceQuality(
structuredFullInput: boolean,
forwardedProvenance: boolean | null = null,
): Record<string, unknown> {
return {
structuredFullInput,
legacyMessage: false,
requesterCwd: null,
explicitUserText: false,
forwardedProvenance,
conversationItems: null,
conversationChars: null,
truncated: false,
latestUserPreserved: null,
};
}
/**
* Identity, cohort, and reproducibility fields shared by every result kind.
* End-to-end latency is measured from authorize entry to this call.
*/
function resultBase(
judgeRuntimeId: string,
details: PromptPermissionDetails,
startedAt: number,
): Record<string, unknown> {
return {
schemaVersion: REVIEW_SCHEMA_VERSION,
requestId: details.requestId,
judgeRuntimeId,
mode: "shadow",
origin:
details.forwarding !== undefined ||
details.payload.kind === "forwarded"
? "forwarded"
: "local",
promptVersion: PROMPT_VERSION,
toolSchemaVersion: TOOL_SCHEMA_VERSION,
judgeLatencyMs: Date.now() - startedAt,
};
}
/** Register a Shadow-only structured-output judge for local native Bash asks. */ /** Register a Shadow-only structured-output judge for local native Bash asks. */
export default function permissionAiJudge(pi: ExtensionAPI): void { export default function permissionAiJudge(pi: ExtensionAPI): void {
let root: RootSession | undefined; let root: RootSession | undefined;
@@ -43,39 +97,73 @@ export default function permissionAiJudge(pi: ExtensionAPI): void {
disposeAuthorizer = service.registerAuthorizer( disposeAuthorizer = service.registerAuthorizer(
LINK_NAME, LINK_NAME,
async (details, _query, log) => { async (details, _query, log) => {
const startedAt = Date.now();
try { try {
// Forwarded asks do not carry a structured child full command in // Forwarded asks do not carry a structured child full
// permission-system 25.3/25.4. Never parse the legacy prose. // command in permission-system 25.3/25.4. Never parse the
// legacy prose. The deferral is recorded so the request
// stays visible in the offline denominator instead of
// silently vanishing.
if ( if (
details.forwarding !== undefined || details.forwarding !== undefined ||
details.payload.kind === "forwarded" details.payload.kind === "forwarded"
) { ) {
return { kind: "defer" }; log.review("ai_bash_judge.result", {
} ...resultBase(
captured.judgeRuntimeId,
if (captured.getSessionId() !== captured.expectedSessionId) { details,
log.debug("ai_bash_judge.root_session_mismatch"); startedAt,
),
resultKind: "preflight_defer",
verdict: null,
effectiveVerdict: "defer",
modelCalled: false,
code: "missing_structured_input",
evidenceQuality: evidenceQuality(false, false),
});
return { kind: "defer" }; return { kind: "defer" };
} }
// Ignore unrelated permission surfaces without producing a // Ignore unrelated permission surfaces without producing a
// Shadow row or invoking the model. // Shadow row or invoking the model: the v0.1 cohort selects
// accessSurface = bash only.
if (details.payload.kind !== "bash") { if (details.payload.kind !== "bash") {
return { kind: "defer" }; return { kind: "defer" };
} }
if (
captured.getSessionId() !== captured.expectedSessionId
) {
log.review("ai_bash_judge.result", {
...resultBase(
captured.judgeRuntimeId,
details,
startedAt,
),
resultKind: "preflight_defer",
verdict: null,
effectiveVerdict: "defer",
modelCalled: false,
code: "session_ownership_unproven",
evidenceQuality: evidenceQuality(false),
});
return { kind: "defer" };
}
const evidence = buildBashJudgmentEvidence(details); const evidence = buildBashJudgmentEvidence(details);
if (evidence === undefined) { if (evidence === undefined) {
log.review("ai_bash_judge.result", { log.review("ai_bash_judge.result", {
schemaVersion: REVIEW_SCHEMA_VERSION, ...resultBase(
requestId: details.requestId, captured.judgeRuntimeId,
mode: "shadow", details,
origin: "local", startedAt,
),
resultKind: "preflight_defer", resultKind: "preflight_defer",
verdict: null, verdict: null,
effectiveVerdict: "defer", effectiveVerdict: "defer",
modelCalled: false, modelCalled: false,
code: "invalid_evidence", code: "invalid_evidence",
evidenceQuality: evidenceQuality(false),
}); });
return { kind: "defer" }; return { kind: "defer" };
} }
@@ -90,10 +178,11 @@ export default function permissionAiJudge(pi: ExtensionAPI): void {
if (result.kind === "judgment") { if (result.kind === "judgment") {
log.review("ai_bash_judge.result", { log.review("ai_bash_judge.result", {
schemaVersion: REVIEW_SCHEMA_VERSION, ...resultBase(
requestId: details.requestId, captured.judgeRuntimeId,
mode: "shadow", details,
origin: "local", startedAt,
),
resultKind: "judgment", resultKind: "judgment",
verdict: result.verdict, verdict: result.verdict,
effectiveVerdict: "defer", effectiveVerdict: "defer",
@@ -102,19 +191,23 @@ export default function permissionAiJudge(pi: ExtensionAPI): void {
provider: result.metadata.provider, provider: result.metadata.provider,
model: result.metadata.model, model: result.metadata.model,
api: result.metadata.api, api: result.metadata.api,
// Log key deliberately avoids the substring "token": // Log keys deliberately avoid the substring
// permission-system masks any key matching /token/i // "token": permission-system masks any key matching
// (structural key-name redaction), which would erase // /token/i (structural key-name redaction), which
// this usage telemetry from the review log. // would erase usage telemetry from the review log.
inputUsage: result.inputTokens,
outputUsage: result.outputTokens, outputUsage: result.outputTokens,
modelLatencyMs: result.modelLatencyMs,
reasonLength: reasonLength(result.reason), reasonLength: reasonLength(result.reason),
evidenceQuality: evidenceQuality(true),
}); });
} else { } else {
log.review("ai_bash_judge.result", { log.review("ai_bash_judge.result", {
schemaVersion: REVIEW_SCHEMA_VERSION, ...resultBase(
requestId: details.requestId, captured.judgeRuntimeId,
mode: "shadow", details,
origin: "local", startedAt,
),
resultKind: "infrastructure_failure", resultKind: "infrastructure_failure",
verdict: null, verdict: null,
effectiveVerdict: "defer", effectiveVerdict: "defer",
@@ -123,7 +216,10 @@ export default function permissionAiJudge(pi: ExtensionAPI): void {
provider: result.metadata?.provider ?? null, provider: result.metadata?.provider ?? null,
model: result.metadata?.model ?? null, model: result.metadata?.model ?? null,
api: result.metadata?.api ?? null, api: result.metadata?.api ?? null,
inputUsage: result.inputTokens ?? null,
outputUsage: result.outputTokens ?? null, outputUsage: result.outputTokens ?? null,
modelLatencyMs: result.modelLatencyMs,
evidenceQuality: evidenceQuality(true),
}); });
} }
@@ -156,6 +252,7 @@ export default function permissionAiJudge(pi: ExtensionAPI): void {
expectedSessionId: sessionId, expectedSessionId: sessionId,
model: createModelAvailability(ctx.model, ctx.modelRegistry), model: createModelAvailability(ctx.model, ctx.modelRegistry),
shutdown: new AbortController(), shutdown: new AbortController(),
judgeRuntimeId: crypto.randomUUID(),
}; };
tryRegister(); tryRegister();
}); });
@@ -55,7 +55,9 @@ export type ModelAttempt =
readonly verdict: SemanticVerdict; readonly verdict: SemanticVerdict;
readonly reason: string; readonly reason: string;
readonly metadata: ModelMetadata; readonly metadata: ModelMetadata;
readonly inputTokens: number | null;
readonly outputTokens: number; readonly outputTokens: number;
readonly modelLatencyMs: number;
} }
| { | {
readonly kind: "infrastructure_failure"; readonly kind: "infrastructure_failure";
@@ -64,6 +66,10 @@ export type ModelAttempt =
readonly modelCalled: boolean; readonly modelCalled: boolean;
/** Completion-token usage when a response arrived, else null. */ /** Completion-token usage when a response arrived, else null. */
readonly outputTokens?: number | null; readonly outputTokens?: number | null;
/** Prompt-token usage when a response arrived, else null. */
readonly inputTokens?: number | null;
/** Wall-clock model-call latency; null when the model was not called. */
readonly modelLatencyMs: number | null;
}; };
function forcedToolChoice(api: string): unknown | undefined { function forcedToolChoice(api: string): unknown | undefined {
@@ -158,17 +164,22 @@ export async function requestStructuredVerdict(
? availability.metadata ? availability.metadata
: undefined, : undefined,
modelCalled: false, modelCalled: false,
modelLatencyMs: null,
}; };
} }
let modelCalled = false; let modelCalled = false;
let observedOutputTokens: number | null = null; let observedOutputTokens: number | null = null;
let observedInputTokens: number | null = null;
let callStartedAt = 0;
const failure = (code: InfrastructureCode): ModelAttempt => ({ const failure = (code: InfrastructureCode): ModelAttempt => ({
kind: "infrastructure_failure", kind: "infrastructure_failure",
code, code,
metadata: availability.metadata, metadata: availability.metadata,
modelCalled, modelCalled,
outputTokens: observedOutputTokens, outputTokens: observedOutputTokens,
inputTokens: observedInputTokens,
modelLatencyMs: modelCalled ? Date.now() - callStartedAt : null,
}); });
const timeoutController = new AbortController(); const timeoutController = new AbortController();
const requestController = new AbortController(); const requestController = new AbortController();
@@ -186,6 +197,7 @@ export async function requestStructuredVerdict(
} }
modelCalled = true; modelCalled = true;
callStartedAt = Date.now();
const response = await availability.complete( const response = await availability.complete(
buildJudgeContext(evidence), buildJudgeContext(evidence),
requestController.signal, requestController.signal,
@@ -202,6 +214,10 @@ export async function requestStructuredVerdict(
} }
const outputTokens = response.usage.output; const outputTokens = response.usage.output;
const inputTokens = response.usage.input;
if (Number.isFinite(inputTokens)) {
observedInputTokens = inputTokens;
}
if (Number.isFinite(outputTokens)) { if (Number.isFinite(outputTokens)) {
observedOutputTokens = outputTokens; observedOutputTokens = outputTokens;
} }
@@ -251,7 +267,9 @@ export async function requestStructuredVerdict(
verdict: args.verdict, verdict: args.verdict,
reason, reason,
metadata: availability.metadata, metadata: availability.metadata,
inputTokens: observedInputTokens,
outputTokens, outputTokens,
modelLatencyMs: Date.now() - callStartedAt,
}; };
} catch { } catch {
const code: InfrastructureCode = shutdownSignal.aborted const code: InfrastructureCode = shutdownSignal.aborted
@@ -215,10 +215,22 @@ describe("AI judge lifecycle", () => {
details: expect.objectContaining({ details: expect.objectContaining({
requestId: "req-1", requestId: "req-1",
mode: "shadow", mode: "shadow",
origin: "local",
judgeRuntimeId: expect.any(String),
promptVersion: "bash-shadow-v1",
toolSchemaVersion: "report-verdict-v1",
judgeLatencyMs: expect.any(Number),
modelLatencyMs: expect.any(Number),
inputUsage: 20,
outputUsage: 10,
resultKind: "judgment", resultKind: "judgment",
verdict: "allow", verdict: "allow",
effectiveVerdict: "defer", effectiveVerdict: "defer",
modelCalled: true, modelCalled: true,
evidenceQuality: expect.objectContaining({
structuredFullInput: true,
explicitUserText: false,
}),
}), }),
}, },
]); ]);
@@ -229,6 +241,80 @@ describe("AI judge lifecycle", () => {
expect(dispose).toHaveBeenCalledTimes(1); expect(dispose).toHaveBeenCalledTimes(1);
}); });
it("records a forwarded ask as a preflight defer without calling the model", async () => {
let authorize: Authorizer["authorize"] | undefined;
const service = {
registerAuthorizer: vi.fn((_name, callback) => {
authorize = callback;
return vi.fn();
}),
checkPermission: vi.fn(),
getToolPermission: vi.fn(),
} as unknown as PermissionsService;
publishPermissionsService(service);
publishedService = service;
const complete = vi.fn();
const ctx = {
hasUI: true,
sessionManager: { getSessionId: () => "session-root" },
model: {
id: "test-model",
provider: "test-provider",
api: "openai-codex-responses",
} as Model<any>,
modelRegistry: { complete },
} as unknown as ExtensionContext;
const harness = createFakePi();
extension(harness.pi);
harness.start(ctx);
harness.ready();
const reviews: Array<{
event: string;
details?: Record<string, unknown>;
}> = [];
const forwarded = {
...ask(),
forwarding: { requestId: "fwd-1" } as never,
} as PromptPermissionDetails;
const verdict = await authorize!(
forwarded,
{
checkPermission: vi.fn(),
getToolPermission: vi.fn(),
},
{
review: (event, details) => reviews.push({ event, details }),
debug: vi.fn(),
},
);
expect(verdict).toEqual({ kind: "defer" });
expect(complete).not.toHaveBeenCalled();
expect(reviews).toEqual([
{
event: "ai_bash_judge.result",
details: expect.objectContaining({
requestId: "req-1",
origin: "forwarded",
resultKind: "preflight_defer",
verdict: null,
effectiveVerdict: "defer",
modelCalled: false,
code: "missing_structured_input",
evidenceQuality: expect.objectContaining({
structuredFullInput: false,
forwardedProvenance: false,
}),
}),
},
]);
harness.shutdown();
});
it("does not register from a headless child", () => { it("does not register from a headless child", () => {
const service = { const service = {
registerAuthorizer: vi.fn(), registerAuthorizer: vi.fn(),
@@ -84,7 +84,9 @@ describe("requestStructuredVerdict", () => {
verdict: "defer", verdict: "defer",
reason: "User intent is unavailable.", reason: "User intent is unavailable.",
metadata, metadata,
inputTokens: 10,
outputTokens: 12, outputTokens: 12,
modelLatencyMs: expect.any(Number),
}); });
}); });
@@ -264,6 +266,7 @@ describe("requestStructuredVerdict", () => {
code: "no_model", code: "no_model",
metadata: undefined, metadata: undefined,
modelCalled: false, modelCalled: false,
modelLatencyMs: null,
}); });
await expect( await expect(
@@ -277,6 +280,7 @@ describe("requestStructuredVerdict", () => {
code: "unsupported_api", code: "unsupported_api",
metadata, metadata,
modelCalled: false, modelCalled: false,
modelLatencyMs: null,
}); });
const shutdown = new AbortController(); const shutdown = new AbortController();
@@ -108,13 +108,17 @@ export const timeoutHandler: CommandHandler = {
); );
switch (result.state) { switch (result.state) {
case "allow": case "allow":
// `requestId` joins this link decision to the gate's
// permission_request.* entries for offline analysis.
log.review("inner_cmd.allow", { log.review("inner_cmd.allow", {
requestId: details.requestId,
command: fullCommand, command: fullCommand,
innerCommand, innerCommand,
}); });
return { kind: "allow" }; return { kind: "allow" };
case "deny": case "deny":
log.review("inner_cmd.deny", { log.review("inner_cmd.deny", {
requestId: details.requestId,
command: fullCommand, command: fullCommand,
innerCommand, innerCommand,
}); });
@@ -172,6 +172,7 @@ describe("authorizeInnerCommand — recognized wrapper verdicts", () => {
level: "review", level: "review",
event: "inner_cmd.allow", event: "inner_cmd.allow",
details: { details: {
requestId: "req-1",
command: "timeout 30s pnpm test", command: "timeout 30s pnpm test",
innerCommand: "pnpm test", innerCommand: "pnpm test",
}, },
@@ -211,6 +212,7 @@ describe("authorizeInnerCommand — recognized wrapper verdicts", () => {
level: "review", level: "review",
event: "inner_cmd.deny", event: "inner_cmd.deny",
details: { details: {
requestId: "req-1",
command: "timeout 30s rm -rf /", command: "timeout 30s rm -rf /",
innerCommand: "rm -rf /", innerCommand: "rm -rf /",
}, },
@@ -547,6 +549,7 @@ describe("authorizeInnerCommand — scaffolded commands", () => {
level: "review", level: "review",
event: "inner_cmd.allow", event: "inner_cmd.allow",
details: { details: {
requestId: "req-1",
command: full, command: full,
innerCommand: "pnpm install --frozen-lockfile", innerCommand: "pnpm install --frozen-lockfile",
}, },