Skip to content

FE-1221: Add structured correlated logging across the Petrinaut optimization pipeline#9059

Open
kube wants to merge 2 commits into
cf/fe-1220-petrinaut-optimization-execution-isolationfrom
cf/fe-1221-petrinaut-optimization-logging
Open

FE-1221: Add structured correlated logging across the Petrinaut optimization pipeline#9059
kube wants to merge 2 commits into
cf/fe-1220-petrinaut-optimization-execution-isolationfrom
cf/fe-1221-petrinaut-optimization-logging

Conversation

@kube

@kube kube commented Jul 19, 2026

Copy link
Copy Markdown
Collaborator

Closes FE-1221 (part of FE-1217).

Stacked on #9058 (base cf/fe-1220-...).

What

Structured, correlated logs across NodeAPI, the Python optimizer, and the Petrinaut CLI, with one correlation chain traceable end to end:

x-hash-request-id (NodeAPI) → run_id / X-Optimization-Run-ID (optimizer) → PETRINAUT_CORRELATION_ID (CLI spawn env) → correlationId in CLI stderr diagnostics.

NodeAPI (apps/hash-api, @local/petrinaut-optimizer-client)

  • openPetrinautOptimizationStream gains a requestId option (sent as x-hash-request-id) and returns { events, optimizationRunId } (from the X-Optimization-Run-ID response header; also captured from failed responses).
  • The handler builds a request-scoped logger.child({ requestId }) and logs request acceptance, validation failures (issue counts + bounded schema paths only), capacity rejections, stream-opened (with the optimizer run id), and a terminal outcome with durationMs — including the previously-silent client-disconnect case.

Optimizer service (apps/petrinaut-opt)

  • New stdlib-only src/logging_config.py: JSON-lines formatter to stdout (service, correlation fields, HASH_PETRINAUT_OPT_LOG_LEVEL), idempotent config, charset-validated traceparent parsing.
  • Endpoints read x-hash-request-id/traceparent; lifecycle events (admitted, capacity rejection, init started/failed, study started/completed/failed, per-trial outcomes, wall-clock ceiling, client disconnect, worker-join timeout, CLI termination path, slot release) log with run_id/request_id/trace_id.
  • CLI stderr is no longer discarded: each line is forwarded to a pn_cli logger, bounded per-line (2000 chars), in pending memory (16 KiB), and per run (1000 lines, then drained silently).

Petrinaut CLI

  • New src/runtime/diagnostics.ts: JSON-per-line stderr logger. The ready-handshake line remains the exact, unchanged first stderr line; subsequent lines are bootstrap_completed, one request line per handled request (id/method/durationMs/outcome — never params or error text), and stdin_eof.

Redaction

Logs never include the manifest, user-authored code, or raw request bodies. Error strings that can embed user identifiers (per-trial CLI errors, init-failure messages) are truncated and/or replaced with a stable classification in logs; the full message still reaches the requester in the HTTP response. Reviewed adversarially; the confirmed findings (unbounded aggregate stderr forwarding, raw error strings in logs, unbounded validation-path log field, dropped early CLI diagnostic, uncorrelated pre-stream failure, permissive traceparent parsing) are all fixed in this branch.

Tests

  • apps/petrinaut-opt: 89 pytest
  • apps/hash-api petrinaut-optimizer: 19 vitest
  • @local/petrinaut-optimizer-client: 15 vitest
  • libs/@hashintel/petrinaut-cli: 36 vitest

🤖 Generated with Claude Code

kube added 2 commits July 19, 2026 05:12
…ization pipeline

One optimization is now traceable end to end: NodeAPI's x-hash-request-id
is forwarded upstream, the optimizer's run_id comes back as
X-Optimization-Run-ID and is logged on both sides, and the CLI receives
the run id at spawn as PETRINAUT_CORRELATION_ID.

- petrinaut-optimizer-client: openPetrinautOptimizationStream accepts a
  requestId (sent as x-hash-request-id) and returns { events,
  optimizationRunId } read from the X-Optimization-Run-ID header.
- hash-api: request-scoped child logger (Apollo pattern); logs request
  acceptance, validation failures (issue counts and schema paths only),
  capacity rejections, stream opening, and a terminal outcome with
  durationMs (completed / timeout kind / upstream-error /
  client-disconnected — disconnects no longer return silently).
- petrinaut-opt: stdlib JSON-lines logging to stdout (logging_config.py,
  HASH_PETRINAUT_OPT_LOG_LEVEL, idempotent setup); inbound
  x-hash-request-id and traceparent headers threaded into every study
  lifecycle log (admission, capacity rejection, initialization,
  study start/completion, per-trial outcomes, wall-clock ceiling,
  disconnect, worker join timeout, CLI termination path, slot release).
  CLI stderr is no longer discarded: each line is forwarded to a pn_cli
  logger, truncated with a bounded pending buffer.
- petrinaut-cli: minimal JSON stderr diagnostics after the unchanged
  ready handshake (bootstrap_completed, per-request id/method/durationMs/
  outcome, stdin_eof), correlation id injected via cli.ts.

Logs never include manifests, user-authored code, or raw request bodies;
docs updated (README logging section, CLI stderr contract, threat model).
- Cap forwarded CLI stderr at 1000 lines/run (drain the rest) so a chatty
  or hostile CLI cannot flood the log pipeline; seed the drain thread with
  bytes read past the bootstrap handshake so an early CLI diagnostic is
  forwarded rather than dropped.
- Truncate the per-trial pruned-error field and stop interpolating the raw
  CLI error into the log message; correct the docstring.
- Log an error type and coarse category instead of the raw initialization
  error string, which can embed a user identifier or expression error; the
  full message still reaches the requester in the 500 detail.
- Cap validation issue-path segments before they reach the 400 response or
  the log, since manifest keys are user-controlled and unbounded.
- Capture the optimizer run id from a failed response so a pre-stream
  upstream failure still correlates end to end.
- Charset-validate the traceparent trace id instead of int(..., 16), which
  accepted 0x-prefixed, underscored, and signed values.
- Document the aggregate stderr cap and header validation in the threat
  model.
@kube kube self-assigned this Jul 19, 2026
@vercel

vercel Bot commented Jul 19, 2026

Copy link
Copy Markdown

The latest updates on your projects. Learn more about Vercel for GitHub.

3 Skipped Deployments
Project Deployment Actions Updated (UTC)
hash Ignored Ignored Jul 19, 2026 3:50am
hashdotdesign-tokens Ignored Ignored Jul 19, 2026 3:50am
petrinaut Skipped Skipped Jul 19, 2026 3:50am

@github-actions github-actions Bot added area/apps > hash* Affects HASH (a `hash-*` app) area/infra Relates to version control, CI, CD or IaC (area) area/apps > hash-api Affects the HASH API (app) area/libs Relates to first-party libraries/crates/packages (area) type/eng > frontend Owned by the @frontend team type/eng > backend Owned by the @backend team area/tests New or updated tests area/apps labels Jul 19, 2026
@kube
kube marked this pull request as ready for review July 19, 2026 04:18
@kube
kube requested a review from YannisZa July 19, 2026 04:18
@cursor

cursor Bot commented Jul 19, 2026

Copy link
Copy Markdown

PR Summary

Medium Risk
Touches the authenticated optimization proxy and optimizer admission path with new observability; logging is deliberately redacted but failure paths and stderr forwarding still need correct bounds in production.

Overview
Adds end-to-end correlated structured logging for Petrinaut optimization so NodeAPI, the Python optimizer, and the CLI can be joined in one chain: x-hash-request-id → optimizer run_id / X-Optimization-Run-IDPETRINAUT_CORRELATION_ID on the CLI.

NodeAPI now uses a request-scoped child logger and logs acceptance, validation failures (counts and bounded paths only), capacity rejections, stream open, and terminal outcomes including client disconnect. It forwards x-hash-request-id upstream and reads optimizationRunId from the optimizer client (including on pre-stream HTTP errors). Validation path segments are capped before they appear in responses or logs.

petrinaut-opt adds JSON-lines stdout logging with request_id, trace_id (from validated traceparent), and run_id on lifecycle events. CLI stderr is forwarded into logs with per-line, buffer, and per-run caps. Init failures log a stable category, not raw CLI text that may embed user content.

Petrinaut CLI emits JSON stderr diagnostics after the unchanged ready line (bootstrap_completed, per-request summaries without params/errors, stdin_eof), driven by PETRINAUT_CORRELATION_ID from the parent spawn env only.

Docs and tests assert redaction (no manifests, user code, or unbounded user-controlled strings in logs).

Reviewed by Cursor Bugbot for commit 2f81742. Bugbot is set up for automated code reviews on this repo. Configure here.

@cursor cursor Bot left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Cursor Bugbot has reviewed your changes and found 1 potential issue.

Fix All in Cursor

❌ Bugbot Autofix is OFF. To automatically fix reported issues with cloud agents, enable autofix in the Cursor dashboard.

Reviewed by Cursor Bugbot for commit 2f81742. Configure here.

optimizationRunId,
outcome: "completed",
userId,
});

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Terminal log marks failures completed

Medium Severity

After forwardOptimizationEvents returns, the handler always logs Petrinaut optimization finished with outcome: "completed". That path runs even when the last forwarded NDJSON event was type: "error" from upstream SSE, so failed studies are recorded as completed in structured logs.

Fix in Cursor Fix in Web

Reviewed by Cursor Bugbot for commit 2f81742. Configure here.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

area/apps > hash* Affects HASH (a `hash-*` app) area/apps > hash-api Affects the HASH API (app) area/apps area/infra Relates to version control, CI, CD or IaC (area) area/libs Relates to first-party libraries/crates/packages (area) area/tests New or updated tests type/eng > backend Owned by the @backend team type/eng > frontend Owned by the @frontend team

Development

Successfully merging this pull request may close these issues.

2 participants