Add Pi inference request diagnostics to provider logging #33886
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -82,6 +82,94 @@ function resolveGatewayUrl(provider) { | |
| return `http://api-proxy:${port}`; | ||
| } | ||
|
|
||
| /** | ||
| * Join a base URL and relative API path without duplicating slashes. | ||
| * | ||
| * @param {string} baseUrl | ||
| * @param {string} apiPath | ||
| * @returns {string} | ||
| */ | ||
|
Contributor
There was a problem hiding this comment. [/tdd] Missing edge case tests for 💡 Suggested testsdescribe("joinApiUrl", () => {
it("removes single trailing slash from baseUrl", () => {
expect(module.joinApiUrl("(api.com/redacted) "/path"))
.toBe("(api.com/redacted)
});
it("removes multiple trailing slashes from baseUrl", () => {
expect(module.joinApiUrl("(api.com/redacted) "/path"))
.toBe("(api.com/redacted)
});
it("handles baseUrl without trailing slash", () => {
expect(module.joinApiUrl("(api.com/redacted) "/path"))
.toBe("(api.com/redacted)
});
it("handles empty apiPath", () => {
expect(module.joinApiUrl("(api.com/redacted) ""))
.toBe("(api.com/redacted)
});
});The current implementation looks correct, but explicit tests prevent future regressions when someone "simplifies" it.
Contributor
There was a problem hiding this comment. Nit (smoke-test): |
||
| function joinApiUrl(baseUrl, apiPath) { | ||
| return `${baseUrl.replace(/\/+$/, "")}${apiPath}`; | ||
|
Contributor
There was a problem hiding this comment. Regex pattern may fail on URLs with multiple consecutive slashes: The regex 💡 Suggested fixfunction joinApiUrl(baseUrl, apiPath) {
const cleanBase = baseUrl.replace(/\/+$/, "");
const cleanPath = apiPath.replace(/^\/+/, "");
return `${cleanBase}/${cleanPath}`;
}This ensures exactly one slash between base and path regardless of input formatting. |
||
| } | ||
|
Comment on lines
+92
to
+94
|
||
|
|
||
| /** | ||
| * Resolve the Pi model's inferred provider request target for logging. | ||
| * | ||
| * @param {any} model | ||
| * @returns {{ api: string, method: string, url: string }} | ||
|
Contributor
There was a problem hiding this comment. Returning |
||
| */ | ||
|
Contributor
There was a problem hiding this comment. Type annotation could be more precise: 💡 Suggested improvement/**
* `@typedef` {Object} PiModel
* `@property` {string} [api]
* `@property` {string} [baseUrl]
* `@property` {string} [provider]
* `@property` {string} [id]
*/
/**
* Resolve the Pi model's inferred provider request target for logging.
*
* `@param` {PiModel|undefined} model
* `@returns` {{ api: string, method: string, url: string }}
*/
function resolveProviderRequestTarget(model) {
// ...
}Improves IntelliSense and catches type errors at authoring time. |
||
| function resolveProviderRequestTarget(model) { | ||
| const api = typeof model?.api === "string" && model.api ? model.api : "(unknown api)"; | ||
| const method = "POST"; | ||
| const baseUrl = typeof model?.baseUrl === "string" && model.baseUrl ? model.baseUrl : ""; | ||
|
|
||
| if (!baseUrl) { | ||
| return { api, method, url: "(baseUrl unavailable)" }; | ||
|
Contributor
There was a problem hiding this comment. Good defensive check here - handles missing baseUrl gracefully. |
||
| } | ||
|
|
||
| switch (api) { | ||
| case "openai-completions": | ||
| return { api, method, url: joinApiUrl(baseUrl, "/chat/completions") }; | ||
| case "openai-responses": | ||
| case "azure-openai-responses": | ||
| case "openai-codex-responses": | ||
| return { api, method, url: joinApiUrl(baseUrl, "/responses") }; | ||
| case "anthropic": | ||
| case "anthropic-messages": | ||
| return { api, method, url: joinApiUrl(baseUrl, "/messages") }; | ||
| case "mistral-conversations": | ||
| return { api, method, url: joinApiUrl(baseUrl, "/conversations") }; | ||
| default: | ||
| return { api, method, url: baseUrl }; | ||
| } | ||
| } | ||
|
|
||
| /** | ||
| * Format response header names for logs without printing sensitive values. | ||
| * | ||
| * @param {Record<string, string>|undefined|null} headers | ||
| * @returns {string} | ||
| */ | ||
| function formatResponseHeaderNames(headers) { | ||
| const names = Object.keys(headers || {}) | ||
| .map(name => String(name).toLowerCase()) | ||
| .sort(); | ||
|
Contributor
There was a problem hiding this comment. [/tdd] Missing test coverage for 💡 Suggested testsdescribe("formatResponseHeaderNames", () => {
it("formats multiple headers alphabetically", () => {
expect(module.formatResponseHeaderNames({
"X-Request-ID": "123",
"Content-Type": "application/json",
"Accept": "*/*"
})).toBe("accept,content-type,x-request-id");
});
it("returns 'none' for empty object", () => {
expect(module.formatResponseHeaderNames({})).toBe("none");
});
it("handles null safely", () => {
expect(module.formatResponseHeaderNames(null)).toBe("none");
});
it("handles undefined safely", () => {
expect(module.formatResponseHeaderNames(undefined)).toBe("none");
});
});This function is exported and reusable — nail down its contract with tests.
Contributor
There was a problem hiding this comment. Nit (smoke-test): |
||
| return names.length > 0 ? names.join(",") : "none"; | ||
| } | ||
|
Comment on lines
+134
to
+139
Contributor
There was a problem hiding this comment. Good catch on Headers instance! Me agree this important fix. Warning Firewall blocked 6 domainsThe following domains were blocked by the firewall during workflow execution:
network:
allowed:
- defaults
- "accounts.google.com"
- "android.clients.google.com"
- "clients2.google.com"
- "contentautofill.googleapis.com"
- "safebrowsingohttpgateway.googleapis.com"
- "www.google.com"See Network Configuration for more information.
Contributor
There was a problem hiding this comment. Great catch on the Headers instance handling! 🎯 Warning Firewall blocked 6 domainsThe following domains were blocked by the firewall during workflow execution:
network:
allowed:
- defaults
- "accounts.google.com"
- "android.clients.google.com"
- "clients2.google.com"
- "contentautofill.googleapis.com"
- "safebrowsingohttpgateway.googleapis.com"
- "www.google.com"See Network Configuration for more information.
|
||
|
|
||
| /** | ||
| * Log extra context when the AWF /reflect call does not produce a snapshot. | ||
| * | ||
| * @param {{ | ||
| * phase: string, | ||
| * provider: string, | ||
| * model: string, | ||
| * result: { | ||
| * ok: boolean, | ||
| * reflectUrl: string, | ||
| * outputPath: string, | ||
| * reason?: string, | ||
| * status?: number, | ||
| * error?: string, | ||
| * }, | ||
| * logger: (msg: string) => void, | ||
| * }} params | ||
| * @returns {void} | ||
| */ | ||
| function logReflectFailure(params) { | ||
| const { phase, provider, model, result, logger } = params; | ||
| if (!result || result.ok) { | ||
| return; | ||
| } | ||
|
|
||
| const status = typeof result.status === "number" ? ` status=${result.status}` : ""; | ||
| const error = result.error ? ` error=${JSON.stringify(result.error)}` : ""; | ||
| logger( | ||
| `reflect_failure phase=${phase} provider=${provider || "(no provider prefix)"} model=${model || "(not set)"} url=${result.reflectUrl} output=${result.outputPath} reason=${result.reason || "unknown"}${status}${error}` | ||
| ); | ||
| } | ||
|
|
||
| /** | ||
| * Register a Pi provider and any aliases. | ||
| * | ||
|
|
@@ -175,8 +263,44 @@ function registerConfiguredProviders(pi, logger) { | |
| */ | ||
| function piProviderExtension(pi) { | ||
| const log = DEFAULT_LOGGER; | ||
| /** @type {{ api: string, method: string, url: string }|null} */ | ||
| let lastProviderRequest = null; | ||
|
Contributor
There was a problem hiding this comment. Mutable state in module scope could cause issues across multiple Pi sessions: 💡 ConsiderationIf multiple Pi sessions run concurrently (unlikely in current workflows but possible in future parallel agent scenarios), their requests could overwrite each other's For now this is acceptable given single-agent workflows, but consider encapsulating this state per Pi instance if parallel sessions become a requirement: function piProviderExtension(pi) {
const log = DEFAULT_LOGGER;
const state = {
lastProviderRequest: null,
lastProviderResponse: null,
};
registerConfiguredProviders(pi, log);
pi.on("before_provider_request", (_event, ctx) => {
state.lastProviderRequest = resolveProviderRequestTarget(ctx && ctx.model);
// ...
});
}This keeps state local to each Pi extension instance. |
||
| /** @type {{ status: number, responseHeaders: string }|null} */ | ||
| let lastProviderResponse = null; | ||
| registerConfiguredProviders(pi, log); | ||
|
|
||
| pi.on("before_provider_request", (_event, ctx) => { | ||
| lastProviderRequest = resolveProviderRequestTarget(ctx && ctx.model); | ||
| lastProviderResponse = null; | ||
| const provider = ctx?.model?.provider || "(unknown provider)"; | ||
| const model = ctx?.model?.id || getConfiguredModel() || "(unknown model)"; | ||
|
Contributor
There was a problem hiding this comment. [/diagnose] Race condition risk: 💡 DiagnosisIf Pi makes overlapping inference calls:
This misattribution could confuse debugging. Suggested fix: Use a const requestMap = new Map(); // or WeakMap if ctx objects are GC-able
pi.on("before_provider_request", (event, ctx) => {
const target = resolveProviderRequestTarget(ctx?.model);
const correlationId = event.correlationId || crypto.randomUUID();
requestMap.set(correlationId, { target, timestamp: Date.now() });
log(`provider_request correlation_id=${correlationId} ...`);
});
pi.on("after_provider_response", (event, ctx) => {
const correlationId = event.correlationId;
const request = requestMap.get(correlationId) || { target: resolveProviderRequestTarget(ctx?.model) };
requestMap.delete(correlationId);
log(`provider_response correlation_id=${correlationId} ...`);
});Only worth fixing if Pi actually makes concurrent requests — verify behavior first. |
||
| log(`provider_request provider=${provider} model=${model} api=${lastProviderRequest.api} method=${lastProviderRequest.method} url=${lastProviderRequest.url}`); | ||
| }); | ||
|
|
||
| pi.on("after_provider_response", (event, ctx) => { | ||
| const request = lastProviderRequest || resolveProviderRequestTarget(ctx && ctx.model); | ||
| lastProviderResponse = { | ||
| status: event.status, | ||
| responseHeaders: formatResponseHeaderNames(event.headers), | ||
| }; | ||
| const provider = ctx?.model?.provider || "(unknown provider)"; | ||
| const model = ctx?.model?.id || getConfiguredModel() || "(unknown model)"; | ||
| log(`provider_response provider=${provider} model=${model} status=${event.status} method=${request.method} url=${request.url} response_headers=${lastProviderResponse.responseHeaders}`); | ||
| }); | ||
|
|
||
| pi.on("message_end", event => { | ||
|
Contributor
There was a problem hiding this comment. [/diagnose] Fallback logic masks null context: 💡 Instrumentation opportunityIf const request = lastProviderRequest || resolveProviderRequestTarget(ctx && ctx.model);But this hides a potential Pi SDK contract violation. Consider logging when fallback is used: let request = lastProviderRequest;
if (!request) {
log("warning: lastProviderRequest unavailable, resolving from context");
request = resolveProviderRequestTarget(ctx?.model);
if (request.url === "(baseUrl unavailable)") {
log("warning: model context incomplete, missing baseUrl");
}
}This makes it obvious when event ordering is unexpected or context is incomplete.
Contributor
There was a problem hiding this comment. Thanks for catching this! 🎯 Warning Firewall blocked 6 domainsThe following domains were blocked by the firewall during workflow execution:
network:
allowed:
- defaults
- "accounts.google.com"
- "android.clients.google.com"
- "clients2.google.com"
- "contentautofill.googleapis.com"
- "safebrowsingohttpgateway.googleapis.com"
- "www.google.com"See Network Configuration for more information.
|
||
| const message = event && event.message; | ||
| if (message?.role !== "assistant" || message?.stopReason !== "error" || !message?.errorMessage) { | ||
| return; | ||
| } | ||
| const request = lastProviderRequest || { api: message.api || "(unknown api)", method: "POST", url: "(request unavailable)" }; | ||
| const status = lastProviderResponse ? String(lastProviderResponse.status) : "no-response"; | ||
| const responseHeaders = lastProviderResponse ? lastProviderResponse.responseHeaders : "none"; | ||
| log( | ||
| `provider_error provider=${message.provider || "(unknown provider)"} model=${message.model || "(unknown model)"} api=${request.api} status=${status} method=${request.method} url=${request.url} response_headers=${responseHeaders} error=${JSON.stringify(message.errorMessage)}` | ||
| ); | ||
| }); | ||
|
|
||
| pi.on("agent_start", async () => { | ||
| const model = getConfiguredModel(); | ||
| const provider = extractProviderFromModel(model); | ||
|
|
@@ -196,13 +320,14 @@ function piProviderExtension(pi) { | |
| // This is best-effort: failures are logged but do not affect the agent session. | ||
| // Skip when AWF_REFLECT_ENABLED is not "1" (e.g. sandbox.agent: false — no api-proxy running). | ||
| if (process.env.AWF_REFLECT_ENABLED === "1") { | ||
| const result = await fetchAWFReflect({ | ||
| reflectUrl: AWF_API_PROXY_REFLECT_URL, | ||
| outputPath: AWF_REFLECT_OUTPUT_PATH, | ||
| timeoutMs: AWF_REFLECT_TIMEOUT_MS, | ||
| modelsTimeoutMs: AWF_MODELS_URL_TIMEOUT_MS, | ||
| logger: log, | ||
| }); | ||
| logReflectFailure({ phase: "agent_start", provider, model, result, logger: log }); | ||
| } | ||
| }); | ||
|
|
||
|
|
@@ -211,13 +336,16 @@ function piProviderExtension(pi) { | |
| // This is best-effort: failures are logged but do not affect the agent exit code. | ||
| // Skip when AWF_REFLECT_ENABLED is not "1" (e.g. sandbox.agent: false — no api-proxy running). | ||
| if (process.env.AWF_REFLECT_ENABLED === "1") { | ||
| const model = getConfiguredModel(); | ||
| const provider = extractProviderFromModel(model); | ||
| const result = await fetchAWFReflect({ | ||
| reflectUrl: AWF_API_PROXY_REFLECT_URL, | ||
| outputPath: AWF_REFLECT_OUTPUT_PATH, | ||
| timeoutMs: AWF_REFLECT_TIMEOUT_MS, | ||
| modelsTimeoutMs: AWF_MODELS_URL_TIMEOUT_MS, | ||
| logger: log, | ||
| }); | ||
| logReflectFailure({ phase: "agent_end", provider, model, result, logger: log }); | ||
| } | ||
| }); | ||
| } | ||
|
|
@@ -227,3 +355,6 @@ module.exports.getConfiguredModel = getConfiguredModel; | |
| module.exports.extractProviderFromModel = extractProviderFromModel; | ||
| module.exports.resolveGatewayUrl = resolveGatewayUrl; | ||
| module.exports.registerConfiguredProviders = registerConfiguredProviders; | ||
| module.exports.resolveProviderRequestTarget = resolveProviderRequestTarget; | ||
| module.exports.formatResponseHeaderNames = formatResponseHeaderNames; | ||
| module.exports.logReflectFailure = logReflectFailure; | ||
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Nice helper — consider also normalizing leading slashes on
apiPathto defend against an accidental//injoinApiUrl. (smoke test review)