Execution Logs

The execution log system (ADR-observability-003) captures per-node I/O for every firing during graph execution. It is two layers: the executor automatically records port data and timing (the exterior layer — zero node-author effort), while a node may voluntarily emit domain-specific details like LLM prompts and token counts (the interior layer, opt-in). Logs persist as one JSONL line per firing with images saved as sidecar assets — queryable over REST and replayable in the frontend Log Viewer. This page owns the record shape, serialization, and storage layout; the live viewer is covered under Real-time Observability.

"Two layers" is the mental model. The first figure draws it; the second shows how the code actually realizes it (they differ — see the note).

Mental model — two layers, one entry.

How the code does it — one log_node call, two data sources in, several sinks out.

1. What the log captures — two layers

Every node firing produces a NodeLogEntry with data from both layers:

The exterior layer requires zero effort from node authors — the executor instruments every firing automatically. The interior layer is opt-in: nodes that want to expose internal reasoning call _self_log() during execution.

1.1 The smallest thing a node logs

BaseCanvasNode provides two methods in app/components/bases.py:

def _self_log(self, key: str, value: Any) -> None:
    """Record an internal detail during forward().
    Call inside forward() to log domain-specific data that the executor
    cannot see from the outside (e.g. assembled LLM prompts, API responses).
    """
    self._log_buffer.append({"key": key, "value": value})

def log(self) -> list[dict]:
    """Return voluntary log entries from the last forward() call.
    Called by the executor after forward() completes. Override to
    filter, transform, or add computed summaries.
    """
    return self._log_buffer

Example usage in a node's forward():

async def forward(self, inputs: dict, ctx: Any) -> dict:
    prompt = self._build_prompt(inputs["instruction"], inputs["history"])
    self._self_log("prompt", prompt)            # voluntary: log assembled prompt

    response = await call_llm(prompt)
    self._self_log("response", response.text)   # voluntary: log raw response
    self._self_log("tokens", response.usage)     # voluntary: log token counts

    return {"action": parse_action(response)}
    # executor automatically logs inputs, outputs, and timing

2. Backend: ExecutionLogger

ExecutionLogger (app/logging/logger.py) manages in-memory buffering and JSONL persistence.

2.1 Data Model

Two Pydantic models in app/logging/models.py:

NodeLogEntry — one node firing:

Both provenance fields are present on every JSONL line (null for ordinary, non-spawned firings).

ExecutionSummary — aggregate stats:

2.2 Ring Buffer + Write Queue

• Ring buffer: collections.deque(maxlen=2000) — thread-safe, fixed-size window for real-time queries via REST
• Write queue: accumulates entries during an iteration; flush() batch-writes them to JSONL at iterOut boundaries (not per-node)
• Final flush: on GraphComplete or GraphError, the executor calls flush() one last time

2.3 Key Methods

3. Serialization & Asset Storage

Large values (images, tensors, long strings) cannot go into JSONL as-is. Two serialization functions handle this.

3.1 log_serialize()

Recursive serializer that normalizes non-JSON values into JSON-safe forms. Strings are persisted in full — there is no length cap or truncation (logger.py · log_serialize; module docstring: "Strings are persisted in full"):

The max_str_len parameter still exists in the signature (and inner_log passes 50000) but is inert — no value of it triggers truncation. Image/array bytes are the only payloads diverted out of the JSONL, via save_asset() (§3.2).

3.2 log_serialize_with_assets()

Wire-type-aware serializer that saves images as sidecar files instead of embedding them:

Saved assets are referenced in the JSONL as:

{
  "__type": "asset",
  "path": "assets/s0_f0_Habitat__Observe__rgb.jpg",
  "wire_type": "IMAGE",
  "shape": [480, 640, 3],
  "dtype": "uint8"
}

Composite observations produce grouped references:

{
  "__type": "asset_group",
  "wire_type": "OBSERVATION",
  "rgb": {"__type": "asset", "path": "assets/s0_f0_Habitat__Observe__obs_rgb.jpg", ...},
  "depth": {"__type": "asset", "path": "assets/s0_f0_Habitat__Observe__obs_depth.png", ...}
}

4. Executor Integration

4.1 Logger Creation

LoopRunner (app/agent_loop/loop_runner.py) creates the logger at run start — but only when one was not injected. Eval passes in its own per-episode logger (next paragraph); the canvas branch below runs only when logger is None and self._execution_id (loop_runner.py · run):

persist_dir = os.path.join(repo_root, "outputs", "runs", self._execution_id)
logger = ExecutionLogger(
    execution_id=self._execution_id,
    source="canvas",
    persist_dir=persist_dir,
)

For eval runs, the source is "eval" and the logger is created per episode inside BatchEvalRunner._run_one_episode (agent_loop/eval_batch.py) with persist_dir = outputs/eval_runs/{run_id}/episodes/ep{idx:04d}/ and execution_id = "{run_id}_ep{idx:04d}". Each episode owns its own log.jsonl + assets/ — no interleaving across workers (see ADR-eval-004).

4.2 Node Firing Instrumentation

GraphExecutor._fire_node() instruments every node firing:

1. Instantiate the handler (BaseCanvasNode subclass) and inject pending_inputs + persistent state.
2. Run the PreNodeExecute hook, then stamp t0 = time.monotonic().
3. Execute the node: result = await instance.forward(inputs, ctx).
4. Compute elapsed_ms, then run the PostNodeExecute hook.
5. Collect the voluntary log: inner_log = instance.log().
6. logger.log_node(step, node_id, …, inner_log, port_wire_types, error) — records exterior + interior layers in one entry.
7. Broadcast the exec_log WS event (unless suppressed — eval suppresses it).

4.4 Per-node LLM usage hook (ADR-observability-005)

Token usage and dollar cost are tracked per node firing without nodesets having to plumb them. The executor wraps every node.forward() with a ContextVar-scoped accumulator (graph_executor.py · _fire_node):

usage_bucket: dict = {}
usage_token = _current_node_usage.set(usage_bucket)   # call.py · _current_node_usage
try:
    result = await node.forward(inputs, ctx)
finally:
    _current_node_usage.reset(usage_token)

Inside the forward(), every llm_complete / llm_complete_n / vlm_complete call writes its response.usage + litellm.completion_cost() into the bucket via _accumulate_usage() (call.py · _accumulate_usage). The executor then emits one log entry per node with the aggregate attached:

Properties: voluntary (nodes that don't call the LLM helpers get an empty bucket), per firing (multi-scope graphs and iterated nodes get one entry per call site), and ContextVar-propagating (survives the internal await chain). Server-mode nodesets capture usage in the subprocess and surface it on the response so the framework can still attribute it to the proxy node. See LLM Config §12 for the full contract.

4.3 Flush Points

The logger's write queue is flushed at three points:

5. REST API

Five query endpoints + one asset-serving endpoint in app/api/execution/logs.py, mounted at /api/logs:

Query priority: active in-memory logger is checked first; historical JSONL files are the fallback.

Security: _sanitize_id() prevents path traversal attacks on execution_id and filename parameters.

6. WebSocket Events

After each node firing, the executor broadcasts a lightweight exec_log event via WebSocket:

interface ExecLogEvent {
  step: number;
  node_id: string;
  node_type: string;
  node_label: string;
  duration_ms: number;
  error: string | null;
  has_inner_log: boolean;
}

• No inputs/outputs in the WS payload — only metadata. Full data is fetched via REST on demand.
• Suppressed in eval mode when principles.suppress_nav_events = True (avoids flooding during batch evaluation).

7. Frontend: Log Viewer

7.1 Three View Modes

The Log Viewer supports three view modes, toggled via a segmented control in the filter bar:

7.2 Page Structure

The Log Viewer is a full-page inspector (LogViewerPage.tsx) with three areas:

7.3 Canvas Replay Mode

LogCanvasView renders the executed graph as a read-only React Flow canvas. It requires graph.json (saved by the backend at execution start).

Data loading: fetches graph.json, log entries, and node schemas in parallel at mount.

Node rendering: uses the same proxiedNodeTypes, toFlowNodes(), and toFlowEdges() as the real canvas editor — visual parity with the edit canvas.

Node status highlighting via style overrides:

Step controls: First / Prev / Play-Pause / Next / Last. Auto-play at 800ms interval. Step indicator shows firing index, step number, node label, type, and duration.

Resizable detail panel: drag handle between canvas and panel, 80px–600px range.

7.4 Value Renderer Registry

The renderer registry (renderers/registry.ts) dispatches values to specialized React components based on a 4-step resolution:

1. Explicit wire type from port_wire_types[key] → use that wire type's renderer
2. __type marker from log_serialize() (e.g. "asset", "ndarray", "bytes") → use __type's renderer
3. typeof primitive (string, number, boolean) → use primitive renderer
4. Fallback → JsonTreeRenderer

All renderers are lazy-loaded (React.lazy) for bundle splitting.

7.5 Canvas Integration

• LogPanel (canvas/panels/LogPanel.tsx): inline log viewer inside the OutputDrawer's Logs tab, subscribes to exec_log WS events for live updates
• StepLogPanel (canvas/panels/StepLogPanel.tsx): action/thinking log side panel with ActionLog + LLMLog views

7.6 API Client

logApi.ts provides typed fetch wrappers:

listExecutions(): Promise<ExecutionListItem[]>
getEntries(id, filters?): Promise<LogEntry[]>
getNodeHistory(id, nodeId): Promise<LogEntry[]>
getSummary(id): Promise<ExecutionSummary>
assetUrl(id, path): string   // builds URL for <img src>

7.7 Node Color Coding

nodeColors.ts maps node type prefixes to Tailwind color classes for visual categorization in the log list (e.g. env_habitat__* → blue, llm__* → purple).

8. Storage Layout

• outputs/
  • runs/ — canvas executions
    • exec_<id>/
      • graph.json — GraphDefinition snapshot for canvas replay
      • log.jsonl — one NodeLogEntry per line
      • assets/ — sidecar image files, e.g. s0_f0_Habitat__Observe__rgb.jpg / …__depth.png
  • eval_runs/ — eval executions (ADR-eval-004)
    • {run_id}/ — timestamp + collision suffix, e.g. 20260515_143052
      • spec.json, shared_urls.json — input contract
      • summary.json, graph.json — run-level snapshot
      • stdout.log, stderr.log, _DONE
      • episodes/ep{idx:04d}/ — one self-contained dir per episode
        • log.jsonl — stamped execution_id = {run_id}_ep{idx:04d}
        • assets/ — this episode's image artefacts
        • episode.json — self-describing row from summary.json

JSONL format — each line is one NodeLogEntry:

{
  "timestamp": "2026-04-07T14:12:41.757840",
  "execution_id": "exec_1775571161675_2z1w47c",
  "source": "canvas",
  "step": 0,
  "node_id": "episode_info",
  "node_type": "env_habitat__episode_info",
  "node_label": "Habitat: Episode Info",
  "duration_ms": 25.43,
  "inputs": {},
  "outputs": {"instruction": "Walk through the door...", "episode_id": "1"},
  "inner_log": [{"key": "format_length", "value": 640}],
  "port_wire_types": {"instruction": "TEXT", "episode_id": "TEXT"},
  "parent_node_id": null,
  "dynamic_index": null,
  "error": null
}

When a node makes one or more LLM/VLM calls, the per-node usage bucket (§4.4) is appended to that node's inner_log as a {"key": "usage", "value": {calls, prompt_tokens, completion_tokens, total_tokens, cached_tokens, usd_cost, model}} entry — only when calls > 0 (graph_executor.py · _fire_node). It rides inside inner_log, not as a top-level field.

9. File Manifest

9.1 Backend

9.2 Frontend