Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
6 changes: 5 additions & 1 deletion AGENTS.md
Original file line number Diff line number Diff line change
Expand Up @@ -195,7 +195,11 @@ previous plan) rather than from the conversation, the plan is stored as a
plan is reported (`warning: planning pass skipped (…)`) and the step proceeds
unplanned; a delegated child never plans. The loop seam is `steer`
(`RunAgentOptions.steer`, the pre-step mirror of `review`), and `/steps` renders
the merged history.
the merged history. A planning call is the run's **own** model call made _outside_
the loop, so the Adaptive MCP observation path never sees it — the CLI's run
summary is where it is accounted for (`plans=… plan_tokens=… plan_ms=…`, via
`PlanningPassOptions.onCall` → `PlanUsage`), with a `planning:` line on `/steps`
for the REPL (#73).

`AgentRuntime` is the bridge into Adaptive MCP. It wires `AdaptiveRuntime`
(telemetry → store → evaluation → derived view), `ThinClient` (approval gate +
Expand Down
7 changes: 6 additions & 1 deletion README.md
Original file line number Diff line number Diff line change
Expand Up @@ -140,7 +140,12 @@ history — tasks, actions, plans), `/metadata`, `/cost`,
reported and the step proceeds unplanned, so planning never fails a run. Because
the history is typed, one read (`store.getSteps`) returns tasks, actions and plans
in order, and `/steps` renders exactly that. A delegated child never plans: the
pass reads the leader's session.
pass reads the leader's session. Because a planning call is the run's own model
call and happens **outside** the loop, nothing in the recorded telemetry sees it;
the run summary is where its cost is reported instead —
`stop=completed steps=4 plans=2 plan_tokens=1234 plan_ms=4100` (`plan_tokens` is
omitted when no backend reports usage), and `/steps` ends with a
`planning: plans=…` footer.
- **Cost.** Priced models record their token cost per tool call; `/cost` shows
the recorded totals.
- **Decoding telemetry.** The decoding applied per step is recorded on each tool
Expand Down
6 changes: 5 additions & 1 deletion docs/architecture.md
Original file line number Diff line number Diff line change
Expand Up @@ -91,7 +91,11 @@ pass reads `store.getSteps(session)` rather than the conversation, so a plan
survives a restart and costs a bounded prompt however long the run got, and a pass
that cannot plan (the model errors, or answers with nothing usable) is reported
and skipped — planning never fails a run. A delegated child never plans: the pass
reads the leader's session, and a child is not the leader.
reads the leader's session, and a child is not the leader. Because that call is the
run's own model call made **outside** the loop, the recorded telemetry never sees
it; `PlanningPassOptions.onCall` reports each one and the CLI aggregates it into the
run summary (`plans=… plan_tokens=… plan_ms=…`), so planning is visible rather than
free-looking (#73).
The runtime's two supporting hooks are `queueMessage`/`drainQueuedMessages` (how a
background child reports back without the parent polling) and the `store` option
(how a child shares the parent's memory; a runtime handed a store does not close
Expand Down
3 changes: 3 additions & 0 deletions src/cli.e2e.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -316,6 +316,9 @@ describe("cli, end to end and offline", () => {
expect(run.stdout).toContain("stop=completed");
// The plan reached the model as a turn it could act on.
expect(run.stdout).toContain("Plan (asked before step 1");
// The planning calls happen outside the loop, so the run summary is the one
// place their cost is visible (#73).
expect(run.stdout).toContain("plans=2");

const planningRequests = model.requests.filter((request) =>
request.messages.some(
Expand Down
22 changes: 17 additions & 5 deletions src/cli.ts
Original file line number Diff line number Diff line change
Expand Up @@ -48,7 +48,7 @@ import {
} from "./skills.js";
import { tasksPrompt, tasksToolset } from "./tasks.js";
import { modePrompt, modeTools, tasksStopGuard } from "./modes.js";
import { PlanningPass, formatSteps } from "./steps.js";
import { PlanningPass, PlanUsage, formatSteps } from "./steps.js";
import { renderOneShot, stringify } from "./render.js";
import type { ChatMessage, ChatModel, ToolExecutionResult, ToolSpec } from "./types.js";

Expand Down Expand Up @@ -368,12 +368,18 @@ async function main(): Promise<void> {
// built here, next to the store it uses (the tools read it lazily, and so
// does this). It never fails a run: a pass that cannot plan is reported and
// the step proceeds unplanned.
//
// Its model calls happen outside the loop, so the runtime's cost/telemetry
// never sees them; `planUsage` is where they are counted, and the run summary
// prints them (#73).
const planUsage = new PlanUsage();
const planner = args.planInterval
? new PlanningPass({
model: defaultModel,
session: sessionId,
store: () => activeStore,
interval: args.planInterval,
onCall: (call) => planUsage.record(call),
onError: (error) => {
const detail = error instanceof Error ? error.message : String(error);
console.error(`warning: planning pass skipped (${detail})`);
Expand Down Expand Up @@ -575,7 +581,7 @@ async function main(): Promise<void> {
onEvent: (event) => renderOneShot(event, args.verbose),
});
console.log(`
[agent] stop=${result.stopReason} steps=${result.steps}`);
[agent] stop=${result.stopReason} steps=${result.steps}${planUsage.summary()}`);
if (result.stopReason === "suspended") reportPaused(runtime, result.messages);
return;
}
Expand All @@ -601,8 +607,14 @@ async function main(): Promise<void> {
: undefined,
metadata: () => runtime.toolsMetadata(),
graph: () => runtime.graphView(),
// The typed history the planning pass reads and writes (steps.ts).
steps: () => formatSteps(activeStore?.getSteps?.(sessionId) ?? []),
// The typed history the planning pass reads and writes (steps.ts). The
// footer is what the planning calls cost: they are the run's own model
// calls, so nothing else in the session reports them (#73).
steps: () => {
const history = formatSteps(activeStore?.getSteps?.(sessionId) ?? []);
const usage = planUsage.summary();
return usage ? `${history}\nplanning:${usage.trim()}` : history;
},
models: () => catalog.describe(),
decodingFor: (tool) => {
const recommendation = runtime.suggestDecoding(tool, runConfig.capabilities, {
Expand Down Expand Up @@ -635,7 +647,7 @@ async function main(): Promise<void> {
},
});

console.log(`\n[agent] stop=${result.stopReason} steps=${result.steps}`);
console.log(`\n[agent] stop=${result.stopReason} steps=${result.steps}${planUsage.summary()}`);
if (result.stopReason === "suspended") reportPaused(runtime, result.messages);
if (denials > 0) {
console.log(
Expand Down
93 changes: 89 additions & 4 deletions src/steps.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,7 @@ import { MemoryStore } from "@adaptivemcp/memory";
import type { Task } from "@adaptivemcp/spec";
import {
PlanningPass,
PlanUsage,
actionStep,
actionSummary,
formatSteps,
Expand All @@ -12,9 +13,10 @@ import {
planReasoning,
planningMessages,
recordedLines,
type PlanCall,
} from "./steps.js";
import { AgentRuntime } from "./runtime.js";
import type { ChatMessage, ChatModel, ChatStep, ToolSpec } from "./types.js";
import type { ChatMessage, ChatModel, ChatStep, ChatUsage, ToolSpec } from "./types.js";

function newStore(): MemoryStore {
return new MemoryStore({ path: ":memory:" });
Expand All @@ -25,12 +27,15 @@ class AnsweringModel implements ChatModel {
readonly name = "answering";
readonly calls: ChatMessage[][] = [];

constructor(private readonly answer: string | Error = "ok") {}
constructor(
private readonly answer: string | Error = "ok",
private readonly usage?: ChatUsage,
) {}

async step(messages: ChatMessage[]): Promise<ChatStep> {
this.calls.push(messages);
if (this.answer instanceof Error) throw this.answer;
return { text: this.answer, toolCalls: [], finishReason: "stop" };
return { text: this.answer, toolCalls: [], finishReason: "stop", usage: this.usage };
}
}

Expand Down Expand Up @@ -154,7 +159,8 @@ describe("reading a session's history back", () => {
).toEqual(["- task t2 [completed] audit (reviewer) → clean"]);
});

it("reads only the tail of a long history", () => { const records = Array.from({ length: 60 }, (_, index) => ({
it("reads only the tail of a long history", () => {
const records = Array.from({ length: 60 }, (_, index) => ({
id: `act-${index}`,
sessionId: "s1",
kind: "action" as const,
Expand Down Expand Up @@ -434,6 +440,85 @@ describe("the planning pass", () => {
expect(store.getSteps("s1")).toEqual([]);
store.close();
});

it("reports every planning call, so its cost is not invisible", async () => {
// The planning call happens outside the loop, so the runtime's telemetry and
// cost never see it: this hook is the only report a host gets (#73).
const store = newStore();
const calls: PlanCall[] = [];
const pass = new PlanningPass({
model: new AnsweringModel('{"steps":["read it"]}', { inputTokens: 30, outputTokens: 7 }),
store: () => store,
session: "s1",
interval: 1,
onCall: (call) => calls.push(call),
});

await pass.steer({ step: 0, messages: goal });

expect(calls).toHaveLength(1);
expect(calls[0]).toMatchObject({
step: 0,
ok: true,
usage: { inputTokens: 30, outputTokens: 7 },
});
expect(calls[0]?.durationMs).toBeGreaterThanOrEqual(0);
store.close();
});

it("reports a failed call too, and an unusable answer, because both were paid for", async () => {
const store = newStore();
const calls: PlanCall[] = [];
const options = {
store: () => store,
session: "s1",
interval: 1,
onCall: (call: PlanCall) => calls.push(call),
};

await new PlanningPass({ ...options, model: new AnsweringModel(new Error("down")) }).steer({
step: 0,
messages: goal,
});
// The model answered; the plan was unusable. Tokens still spent.
await new PlanningPass({ ...options, model: new AnsweringModel(" ") }).steer({
step: 1,
messages: goal,
});
// Not due, so nothing was called and nothing is reported.
await new PlanningPass({ ...options, interval: 5, model: new AnsweringModel("x") }).steer({
step: 2,
messages: goal,
});

expect(calls.map((call) => call.ok)).toEqual([false, true]);
expect(store.getSteps("s1", { kind: "plan" })).toEqual([]);
store.close();
});

it("summarises planning for a run, and says nothing when there was none", () => {
const usage = new PlanUsage();
// A run without --plan-interval prints exactly what it printed before.
expect(usage.summary()).toBe("");

usage.record({
step: 0,
durationMs: 40,
ok: true,
usage: { inputTokens: 10, outputTokens: 5 },
});
usage.record({ step: 3, durationMs: 10, ok: false });
// Tokens are reported once any backend reports them, and the failed call
// contributes its latency but no tokens.
expect(usage.summary()).toBe(" plans=2 plan_tokens=15 plan_ms=50");
});

it("omits tokens rather than reporting zero when no backend reports usage", () => {
const usage = new PlanUsage();
usage.record({ step: 0, durationMs: 5, ok: true });
// `plan_tokens=0` would read as "planning is free", which is not what happened.
expect(usage.summary()).toBe(" plans=1 plan_ms=5");
});
});

describe("the runtime records actions", () => {
Expand Down
69 changes: 68 additions & 1 deletion src/steps.ts
Original file line number Diff line number Diff line change
Expand Up @@ -24,7 +24,7 @@
*/
import { randomUUID } from "node:crypto";
import type { ActionStep, PlanStep, StepRecord, Store, Task } from "@adaptivemcp/spec";
import type { ChatMessage, ChatModel, ToolExecutionResult } from "./types.js";
import type { ChatMessage, ChatModel, ChatUsage, ToolExecutionResult } from "./types.js";

/** How much of a tool's error message a step keeps. Enough to act on, not a dump. */
const MAX_ERROR_CHARS = 200;
Expand Down Expand Up @@ -255,6 +255,59 @@ export interface PlanningPassOptions {
interval: number;
/** A pass that produced no plan: reported, never fatal. */
onError?: (error: unknown) => void;
/** Every planning call, including one that failed — so a host can account for it. */
onCall?: (call: PlanCall) => void;
}

/**
* One planning model call.
*
* A planning call is the run's *own* model call outside the loop, so nothing in
* the Adaptive MCP observation path sees it: telemetry is about tool executions.
* Reporting it here is what lets a host put it in front of a user (#73).
*/
export interface PlanCall {
/** The loop step the pass ran for. */
step: number;
durationMs: number;
/** The backend's token usage, when it reports one. */
usage?: ChatUsage;
/** False when the call itself failed; the step then proceeded unplanned. */
ok: boolean;
}

/**
* What a run's planning calls cost, for a run summary.
*
* Deliberately small: a count, tokens and latency, and nothing at all when the run
* never planned — so `--plan-interval` is the only thing that changes what a
* summary says.
*/
export class PlanUsage {
private calls = 0;
private durationMs = 0;
private tokens: number | undefined;

record(call: PlanCall): void {
this.calls += 1;
this.durationMs += call.durationMs;
if (call.usage) {
this.tokens =
(this.tokens ?? 0) + (call.usage.inputTokens ?? 0) + (call.usage.outputTokens ?? 0);
}
}

/**
* The suffix for a run summary, or `""` when nothing was planned — a run
* without `--plan-interval` prints exactly what it printed before. Tokens are
* omitted rather than shown as 0 when no backend reported any, which a count of
* `0` would misrepresent as "planning is free".
*/
summary(): string {
if (this.calls === 0) return "";
const tokens = this.tokens === undefined ? "" : ` plan_tokens=${this.tokens}`;
return ` plans=${this.calls}${tokens} plan_ms=${this.durationMs}`;
}
}

/**
Expand Down Expand Up @@ -283,17 +336,31 @@ export class PlanningPass {
if (!store) return undefined;

const records = store.getSteps?.(this.options.session) ?? [];
const started = Date.now();
let answer: string;
let usage: ChatUsage | undefined;
try {
const step = await this.options.model.step(
planningMessages(goalOf(context.messages), recordedLines(records)),
[],
);
answer = step.text ?? "";
usage = step.usage;
} catch (error) {
// Report the call before the error: it was made, so it was paid for.
this.options.onCall?.({ step: context.step, durationMs: Date.now() - started, ok: false });
this.options.onError?.(error);
return undefined;
}
//
// Reported before the plan is parsed, for the same reason: the tokens were
// spent whether or not the answer was usable.
this.options.onCall?.({
step: context.step,
durationMs: Date.now() - started,
usage,
ok: true,
});

const parsed = parsePlan(answer);
if (parsed.steps.length === 0) {
Expand Down
Loading