diff --git a/package.json b/package.json index a656f5b..cde6e4a 100644 --- a/package.json +++ b/package.json @@ -16,7 +16,7 @@ "tui": "tsx tui/tui.tsx", "propose:apply": "node scripts/propose-apply.js", "stop": "bash scripts/stop.sh", - "test": "node --test runtime/skills/contract.test.js runtime/skills/groups.test.js runtime/skills/compat.test.js runtime/skills/recovery-tunnel-out.test.js runtime/skills/pillar-up.test.js runtime/curriculum.test.js runtime/social/social.test.js runtime/social/conversation.test.js runtime/social/chat-history.test.js runtime/social/reply-pi.test.js runtime/stuck-incident.test.js runtime/compat.test.js runtime/reflex.test.js runtime/base-site.test.js runtime/locations.test.js runtime/watch-filter.test.js runtime/world-journal.test.js runtime/scenario-memory.test.js runtime/critic.test.js runtime/skill-library.test.js runtime/skill-registry.test.js runtime/modes.test.js runtime/pathfinder-watchdog.test.js runtime/manifesto/needs.test.js runtime/manifesto/state.test.js runtime/awareness/events.test.js runtime/knowledge/knowledge.test.js runtime/llm/provider.test.js runtime/coach/postmortem.test.js runtime/coach/advice.test.js runtime/coach/reflect.test.js runtime/coach/fast-advisor.test.js runtime/persona/chatter.test.js scripts/edit-scope.test.js scripts/lint-patch.test.js" + "test": "node --test runtime/skills/contract.test.js runtime/skills/groups.test.js runtime/skills/compat.test.js runtime/skills/recovery-tunnel-out.test.js runtime/skills/pillar-up.test.js runtime/curriculum.test.js runtime/social/social.test.js runtime/social/conversation.test.js runtime/social/chat-history.test.js runtime/social/reply-pi.test.js runtime/stuck-incident.test.js runtime/compat.test.js runtime/reflex.test.js runtime/base-site.test.js runtime/locations.test.js runtime/watch-filter.test.js runtime/world-journal.test.js runtime/scenario-memory.test.js runtime/critic.test.js runtime/skill-library.test.js runtime/skill-registry.test.js runtime/modes.test.js runtime/pathfinder-watchdog.test.js runtime/manifesto/needs.test.js runtime/manifesto/state.test.js runtime/awareness/events.test.js runtime/knowledge/knowledge.test.js runtime/llm/provider.test.js runtime/coach/postmortem.test.js runtime/coach/advice.test.js runtime/coach/reflect.test.js runtime/coach/fast-advisor.test.js runtime/coach/advisor-trigger.test.js runtime/persona/chatter.test.js scripts/edit-scope.test.js scripts/lint-patch.test.js" }, "dependencies": { "better-sqlite3": "^11.10.0", diff --git a/runtime/bot.js b/runtime/bot.js index dcc1a22..4d962e1 100644 --- a/runtime/bot.js +++ b/runtime/bot.js @@ -239,6 +239,11 @@ function dispatchAction(fn, label, opts = {}) { } reflexCtx.busy = true; reflexCtx.currentActionLabel = label; + // Rolling window of last 8 dispatched skill ids — read by + // runtime/coach/advisor-trigger.js to detect loops (4+ same in a row) + reflexCtx.recentSkillIds = reflexCtx.recentSkillIds ?? []; + reflexCtx.recentSkillIds.push(label); + if (reflexCtx.recentSkillIds.length > 8) reflexCtx.recentSkillIds.shift(); // v0.3.0-rc.3 — pre-emption: each dispatch gets a fresh AbortController. // awareness/events.js#onPreempt fires controller.abort() when the env // shocks (forced move, HP plunge, hostile spawn) the current skill diff --git a/runtime/coach/advisor-trigger.js b/runtime/coach/advisor-trigger.js new file mode 100644 index 0000000..9556a68 --- /dev/null +++ b/runtime/coach/advisor-trigger.js @@ -0,0 +1,164 @@ +// Auto-trigger policy for the fast tactical advisor. +// +// The advisor is too slow for synchronous use inside a reflex tick +// (5-15s via TimeWeb's hosted agent endpoint). The strategy here is +// asynchronous: when conditions warrant tactical advice, fire-and-forget +// an advise() call; when the result eventually arrives, cache it on +// ctx.advisorRecommendation. The next reflex tick reads that cache and +// can substitute the recommended skill before dispatching. +// +// Triggers (any one, AND-ed with the not-recently-asked cooldown): +// +// 1. Wedged > 60s — bot's position hasn't shifted ≥16 blocks in over +// a minute (already tracked by reflex.js as lastSignificantMoveAt) +// 2. Last 4+ dispatches were the same skill — clear loop signal +// 3. Last awareness preempt was very recent AND followed by same +// skill being dispatched again — env-shock-blind retry +// +// The recommendation has a TTL (60s). After that it's stale and the +// reflex falls back to manifesto / curriculum. This keeps the system +// reactive — advice ages out, fresh data drives fresh advice. + +import { advise, isAvailable as advisorAvailable } from "./fast-advisor.js"; +import { isRegistered } from "../skill-registry.js"; +import { info, warn } from "../log.js"; + +const TRIGGER_COOLDOWN_MS = 90_000; +const RECOMMENDATION_TTL_MS = 60_000; +const WEDGED_THRESHOLD_MS = 60_000; +const REPEAT_THRESHOLD = 4; +const PREEMPT_WINDOW_MS = 30_000; + +let _lastTriggerAt = 0; +let _inFlight = false; + +export function _resetForTest() { + _lastTriggerAt = 0; + _inFlight = false; +} + +export function getTriggerState() { + return { + lastTriggerAt: _lastTriggerAt, + inFlight: _inFlight, + }; +} + +/** + * tickAdvisor(ctx) → maybe-fires advise() in background. + * + * Called from reflex AFTER it has chosen a plannedSkillId but BEFORE + * dispatching. Does NOT block — the in-flight call resolves later and + * writes ctx.advisorRecommendation. The caller decides whether to + * consume a fresh recommendation on this tick or wait for the next. + */ +export function tickAdvisor(ctx, { plannedSkillId } = {}) { + if (!advisorAvailable()) return { fired: false, reason: "disabled" }; + if (_inFlight) return { fired: false, reason: "in_flight" }; + + const now = Date.now(); + if (now - _lastTriggerAt < TRIGGER_COOLDOWN_MS) { + return { fired: false, reason: "cooldown" }; + } + + // Drop a recommendation that's already aged out. + if (ctx.advisorRecommendation && now - ctx.advisorRecommendation.at > RECOMMENDATION_TTL_MS) { + ctx.advisorRecommendation = null; + } + + const reason = detectTrigger(ctx, now, plannedSkillId); + if (!reason) return { fired: false, reason: "no_trigger" }; + + _lastTriggerAt = now; + _inFlight = true; + const snapshot = ctx.snapshot ?? null; + const recentSkillIds = (ctx.recentSkillIds ?? []).slice(-8); + + info("advisor-trigger", `firing because ${reason} (planned=${plannedSkillId ?? "?"})`); + // Fire-and-forget. The promise's resolution writes ctx.advisorRecommendation. + advise({ snapshot, reason, recentSkillIds, lessonsTail: ctx.recentLessons ?? [], force: true }) + .then((result) => { + _inFlight = false; + if (result.ok && result.action === "switch_skill" && isRegistered(result.skillId)) { + ctx.advisorRecommendation = { + at: Date.now(), + skillId: result.skillId, + action: "switch_skill", + rationale: result.rationale, + triggerReason: reason, + latencyMs: result.latencyMs, + usage: result.usage ?? null, + }; + info("advisor-trigger", `recommendation cached: ${result.skillId} (${result.latencyMs}ms, in=${result.usage?.in ?? "?"}t/out=${result.usage?.out ?? "?"}t)`); + } else if (result.ok && (result.action === "wait" || result.action === "continue")) { + ctx.advisorRecommendation = { + at: Date.now(), + action: result.action, + rationale: result.rationale, + triggerReason: reason, + latencyMs: result.latencyMs, + usage: result.usage ?? null, + }; + info("advisor-trigger", `recommendation: ${result.action} (${result.latencyMs}ms)`); + } else if (!result.ok) { + warn("advisor-trigger", `advise failed: ${result.code} (${result.detail})`); + } + }) + .catch((e) => { + _inFlight = false; + warn("advisor-trigger", `advise threw: ${e?.message ?? e}`); + }); + + return { fired: true, reason }; +} + +function detectTrigger(ctx, now, plannedSkillId) { + // 1. Wedged > threshold + if (ctx.lastSignificantMoveAt && (now - ctx.lastSignificantMoveAt) > WEDGED_THRESHOLD_MS) { + return `wedged_${Math.round((now - ctx.lastSignificantMoveAt) / 1000)}s`; + } + // 2. Repeat-skill loop + const recent = ctx.recentSkillIds ?? []; + if (recent.length >= REPEAT_THRESHOLD) { + const tail = recent.slice(-REPEAT_THRESHOLD); + const allSame = tail.every((id) => id === tail[0]); + if (allSame && plannedSkillId === tail[0]) { + return `repeat_${REPEAT_THRESHOLD}_${tail[0]}`; + } + } + // 3. Recent preempt followed by same skill again + if (ctx.lastPreempt && now - ctx.lastPreempt.at < PREEMPT_WINDOW_MS) { + const lastDispatched = recent[recent.length - 1]; + if (lastDispatched && lastDispatched === plannedSkillId) { + return `preempt_retry_${ctx.lastPreempt.reason}`; + } + } + return null; +} + +/** + * consumeFreshRecommendation(ctx) → { skillId, action, rationale } | null + * + * Returns a recommendation if one is currently cached and fresh, and + * clears it so subsequent ticks don't re-apply the same advice. + */ +export function consumeFreshRecommendation(ctx) { + const rec = ctx.advisorRecommendation; + if (!rec) return null; + if (Date.now() - rec.at > RECOMMENDATION_TTL_MS) { + ctx.advisorRecommendation = null; + return null; + } + if (rec.action !== "switch_skill" || !rec.skillId) { + // 'continue' / 'wait' don't replace dispatch; surface for telemetry only + return null; + } + ctx.advisorRecommendation = null; + return rec; +} + +// Test exports +export const __testing = { + TRIGGER_COOLDOWN_MS, RECOMMENDATION_TTL_MS, WEDGED_THRESHOLD_MS, + REPEAT_THRESHOLD, PREEMPT_WINDOW_MS, detectTrigger, +}; diff --git a/runtime/coach/advisor-trigger.test.js b/runtime/coach/advisor-trigger.test.js new file mode 100644 index 0000000..97cf59b --- /dev/null +++ b/runtime/coach/advisor-trigger.test.js @@ -0,0 +1,216 @@ +import { test } from "node:test"; +import assert from "node:assert/strict"; + +import { + tickAdvisor, + consumeFreshRecommendation, + getTriggerState, + _resetForTest, + __testing, +} from "./advisor-trigger.js"; +import { _resetForTest as resetAdvisor } from "./fast-advisor.js"; + +const { detectTrigger, WEDGED_THRESHOLD_MS, REPEAT_THRESHOLD, PREEMPT_WINDOW_MS, RECOMMENDATION_TTL_MS } = __testing; + +const API_KEY = "TIMEWEB_API_KEY"; +const MODEL = "TIMEWEB_MODEL"; + +function withEnv(env, fn) { + const prev = {}; + for (const k of Object.keys(env)) { + prev[k] = process.env[k]; + if (env[k] === undefined) delete process.env[k]; + else process.env[k] = env[k]; + } + return Promise.resolve(fn()).finally(() => { + for (const [k, v] of Object.entries(prev)) { + if (v === undefined) delete process.env[k]; + else process.env[k] = v; + } + }); +} + +function stubFetch(reply, latency = 0) { + const orig = globalThis.fetch; + globalThis.fetch = async () => { + if (latency) await new Promise((r) => setTimeout(r, latency)); + return { + ok: true, + json: async () => ({ + choices: [{ message: { content: typeof reply === "string" ? reply : JSON.stringify(reply) } }], + usage: { prompt_tokens: 1500, completion_tokens: 40, total_tokens: 1540 }, + }), + }; + }; + return () => { globalThis.fetch = orig; }; +} + +test("detectTrigger: returns null when nothing matches", () => { + const r = detectTrigger({ recentSkillIds: [] }, Date.now(), "gather.logs"); + assert.equal(r, null); +}); + +test("detectTrigger: wedged > 60s fires", () => { + const now = Date.now(); + const r = detectTrigger( + { recentSkillIds: ["x"], lastSignificantMoveAt: now - WEDGED_THRESHOLD_MS - 5000 }, + now, + "explore.far", + ); + assert.match(r, /^wedged_\d+s/); +}); + +test("detectTrigger: 4 same dispatches in row + same planned → repeat", () => { + const now = Date.now(); + const r = detectTrigger( + { recentSkillIds: ["explore.far", "explore.far", "explore.far", "explore.far"] }, + now, + "explore.far", + ); + assert.match(r, /^repeat_4_explore\.far/); +}); + +test("detectTrigger: same skill repeated but planned is different → no repeat trigger", () => { + const now = Date.now(); + const r = detectTrigger( + { recentSkillIds: ["explore.far", "explore.far", "explore.far", "explore.far"] }, + now, + "gather.logs", + ); + assert.equal(r, null); +}); + +test("detectTrigger: recent preempt + same skill re-planned → preempt_retry", () => { + const now = Date.now(); + const r = detectTrigger( + { + recentSkillIds: ["gather.logs"], + lastPreempt: { at: now - 5000, reason: "forced_move" }, + }, + now, + "gather.logs", + ); + assert.equal(r, "preempt_retry_forced_move"); +}); + +test("detectTrigger: old preempt (> window) does not trigger", () => { + const now = Date.now(); + const r = detectTrigger( + { + recentSkillIds: ["gather.logs"], + lastPreempt: { at: now - PREEMPT_WINDOW_MS - 5000, reason: "forced_move" }, + }, + now, + "gather.logs", + ); + assert.equal(r, null); +}); + +test("tickAdvisor: disabled when TIMEWEB_API_KEY missing", async () => { + await withEnv({ [API_KEY]: undefined }, () => { + _resetForTest(); + const r = tickAdvisor({ recentSkillIds: [] }, { plannedSkillId: "x" }); + assert.equal(r.fired, false); + assert.equal(r.reason, "disabled"); + }); +}); + +test("tickAdvisor: no_trigger when ctx has nothing interesting", async () => { + await withEnv({ [API_KEY]: "k", [MODEL]: "m" }, () => { + _resetForTest(); + resetAdvisor(); + const r = tickAdvisor({ recentSkillIds: [] }, { plannedSkillId: "gather.logs" }); + assert.equal(r.fired, false); + assert.equal(r.reason, "no_trigger"); + }); +}); + +test("tickAdvisor: fires on wedged trigger and caches recommendation", async () => { + const restore = stubFetch({ + action: "switch_skill", + skill_id: "survive.flee", + rationale: "Wedged here, retreat instead.", + }); + try { + await withEnv({ [API_KEY]: "k", [MODEL]: "m" }, async () => { + _resetForTest(); + resetAdvisor(); + const ctx = { + recentSkillIds: ["explore.far"], + lastSignificantMoveAt: Date.now() - 120_000, + }; + const r = tickAdvisor(ctx, { plannedSkillId: "explore.far" }); + assert.equal(r.fired, true); + assert.match(r.reason, /^wedged_/); + assert.equal(getTriggerState().inFlight, true); + + // Wait for the in-flight promise to settle. + await new Promise((res) => setTimeout(res, 20)); + assert.equal(getTriggerState().inFlight, false); + assert.ok(ctx.advisorRecommendation, "recommendation cached"); + assert.equal(ctx.advisorRecommendation.skillId, "survive.flee"); + assert.equal(ctx.advisorRecommendation.usage.total, 1540); + }); + } finally { restore(); } +}); + +test("tickAdvisor: cooldown blocks second trigger right after", async () => { + const restore = stubFetch({ action: "continue", rationale: "ok" }); + try { + await withEnv({ [API_KEY]: "k", [MODEL]: "m" }, async () => { + _resetForTest(); + resetAdvisor(); + const ctx = { + recentSkillIds: ["explore.far"], + lastSignificantMoveAt: Date.now() - 120_000, + }; + const r1 = tickAdvisor(ctx, { plannedSkillId: "explore.far" }); + assert.equal(r1.fired, true); + await new Promise((res) => setTimeout(res, 20)); + const r2 = tickAdvisor(ctx, { plannedSkillId: "explore.far" }); + assert.equal(r2.fired, false); + assert.equal(r2.reason, "cooldown"); + }); + } finally { restore(); } +}); + +test("consumeFreshRecommendation: returns + clears switch_skill recommendation", () => { + _resetForTest(); + const ctx = { + advisorRecommendation: { + at: Date.now(), + action: "switch_skill", + skillId: "survive.flee", + rationale: "x", + }, + }; + const r = consumeFreshRecommendation(ctx); + assert.ok(r); + assert.equal(r.skillId, "survive.flee"); + assert.equal(ctx.advisorRecommendation, null); +}); + +test("consumeFreshRecommendation: stale (> TTL) recommendation dropped", () => { + _resetForTest(); + const ctx = { + advisorRecommendation: { + at: Date.now() - RECOMMENDATION_TTL_MS - 1000, + action: "switch_skill", + skillId: "survive.flee", + }, + }; + const r = consumeFreshRecommendation(ctx); + assert.equal(r, null); + assert.equal(ctx.advisorRecommendation, null); +}); + +test("consumeFreshRecommendation: continue/wait recommendations are not consumed for skill swap", () => { + _resetForTest(); + const ctx = { + advisorRecommendation: { at: Date.now(), action: "continue", rationale: "ok" }, + }; + const r = consumeFreshRecommendation(ctx); + assert.equal(r, null); + // stays cached for telemetry + assert.ok(ctx.advisorRecommendation); +}); diff --git a/runtime/coach/fast-advisor.js b/runtime/coach/fast-advisor.js index 13f4201..f8f25fd 100644 --- a/runtime/coach/fast-advisor.js +++ b/runtime/coach/fast-advisor.js @@ -23,14 +23,33 @@ const COOLDOWN_MS = 30_000; let _callTimes = []; let _lastCallAt = 0; +let _tokensIn = 0; +let _tokensOut = 0; +let _calls = 0; export function isAvailable() { return llmAvailable(); } +export function getUsageSnapshot() { + const now = Date.now(); + const hourAgo = now - 3600_000; + const recentCalls = _callTimes.filter((t) => t > hourAgo).length; + return { + callsLastHour: recentCalls, + callsTotal: _calls, + tokensInTotal: _tokensIn, + tokensOutTotal: _tokensOut, + hourlyBudget: HOURLY_BUDGET, + }; +} + export function _resetForTest() { _callTimes = []; _lastCallAt = 0; + _tokensIn = 0; + _tokensOut = 0; + _calls = 0; } /** @@ -69,6 +88,11 @@ export async function advise({ _lastCallAt = now; const res = await complete({ system, user, json: true }); + _calls += 1; + if (res.usage) { + _tokensIn += res.usage.in; + _tokensOut += res.usage.out; + } if (!res.ok) { warn("advisor", `complete failed: ${res.code} (${res.detail})`); return { ok: false, code: res.code, detail: res.detail, latencyMs: res.latencyMs }; @@ -93,6 +117,7 @@ export async function advise({ rationale, raw: parsed, latencyMs: res.latencyMs, + usage: res.usage, }; } info("advisor", `switch_skill → ${skillId} (${rationale.slice(0, 80)})`); @@ -103,15 +128,16 @@ export async function advise({ rationale, raw: parsed, latencyMs: res.latencyMs, + usage: res.usage, }; } if (action === "continue" || action === "wait") { info("advisor", `${action} (${rationale.slice(0, 80)})`); - return { ok: true, action, rationale, raw: parsed, latencyMs: res.latencyMs }; + return { ok: true, action, rationale, raw: parsed, latencyMs: res.latencyMs, usage: res.usage }; } - return { ok: false, code: "bad_action", detail: action || "missing", raw: parsed, latencyMs: res.latencyMs }; + return { ok: false, code: "bad_action", detail: action || "missing", raw: parsed, latencyMs: res.latencyMs, usage: res.usage }; } function buildSystemPrompt() { diff --git a/runtime/llm/provider.js b/runtime/llm/provider.js index 035d079..f30f526 100644 --- a/runtime/llm/provider.js +++ b/runtime/llm/provider.js @@ -141,8 +141,19 @@ export async function complete({ } } - info("llm", `${useModel} ok (${latencyMs}ms, ${text.length}ch)`); - return { ok: true, text: parsed, raw: text, latencyMs }; + // usage shape per OpenAI / TimeWeb / most compat endpoints: + // { prompt_tokens, completion_tokens, total_tokens } + const usage = normaliseUsage(payload?.usage); + info("llm", `${useModel} ok (${latencyMs}ms, ${text.length}ch, in=${usage.in}/out=${usage.out}t)`); + return { ok: true, text: parsed, raw: text, latencyMs, usage }; +} + +function normaliseUsage(u) { + if (!u || typeof u !== "object") return { in: 0, out: 0, total: 0 }; + const inT = Number(u.prompt_tokens ?? u.input_tokens ?? 0) || 0; + const outT = Number(u.completion_tokens ?? u.output_tokens ?? 0) || 0; + const total = Number(u.total_tokens ?? inT + outT) || (inT + outT); + return { in: inT, out: outT, total }; } function tryParseJson(text) { @@ -155,4 +166,4 @@ function tryParseJson(text) { } // Test exports -export const __testing = { ENV, DEFAULT_BASE_URL, DEFAULT_TIMEOUT_MS, tryParseJson }; +export const __testing = { ENV, DEFAULT_BASE_URL, DEFAULT_TIMEOUT_MS, tryParseJson, normaliseUsage }; diff --git a/runtime/reflex.js b/runtime/reflex.js index e1009c1..1d0819f 100644 --- a/runtime/reflex.js +++ b/runtime/reflex.js @@ -26,6 +26,7 @@ import { } from "./actions.js"; import { runSkill, getSkill } from "./skills/index.js"; import { consult as consultAdvice, reportOutcome as reportAdviceOutcome } from "./coach/advice.js"; +import { tickAdvisor, consumeFreshRecommendation } from "./coach/advisor-trigger.js"; import { pickActiveNeed } from "./manifesto/state.js"; import { situationHash } from "./scenario-memory.js"; import { tickModes } from "./modes.js"; @@ -530,8 +531,25 @@ function curriculumReflex(ctx) { // Pick what to dispatch: manifesto wins over curriculum plan because // it expresses concrete needs rather than abstract "next milestone". - const skillId = manifestoSkillId ?? plan.skillId; - const skillSource = manifestoSkillId ? `manifesto:${activeNeed.need.id}` : "curriculum"; + let skillId = manifestoSkillId ?? plan.skillId; + let skillSource = manifestoSkillId ? `manifesto:${activeNeed.need.id}` : "curriculum"; + + // v0.3.0 fast-advisor: if a fresh recommendation is sitting on ctx + // (the result of a previous tick's async advise() call), use it. + // This is the closing of the awareness → LLM → action loop. + if (!ctx.disableAdvisor) { + const rec = consumeFreshRecommendation(ctx); + if (rec && rec.skillId) { + info(REFLEX_LOG, `advisor override: ${skillId} → ${rec.skillId} (${rec.triggerReason}, ${rec.rationale?.slice(0, 60)})`); + skillId = rec.skillId; + skillSource = `advisor:${rec.triggerReason}`; + } + // Always fire-and-forget another advise() if triggers fire — the + // result lands on a future tick. tickAdvisor handles its own + // cooldown / in-flight checks so this is safe to call every tick. + tickAdvisor(ctx, { plannedSkillId: skillId }); + } + const skill = getSkill(skillId); if (!skill) { // Suggested a skill that isn't registered yet — fall back diff --git a/runtime/reflex.test.js b/runtime/reflex.test.js index e5b8772..8b255b7 100644 --- a/runtime/reflex.test.js +++ b/runtime/reflex.test.js @@ -49,6 +49,8 @@ function makeCtx({ disableManifesto = true, // curriculum branch tests don't construct // full snapshots; manifesto is exercised by // runtime/manifesto/state.test.js separately. + disableAdvisor = true, // advisor-trigger fires real async LLM calls, + // tested directly in advisor-trigger.test.js. } = {}) { const dispatches = []; const ctx = { @@ -62,6 +64,7 @@ function makeCtx({ skillBackoff, metrics, disableManifesto, + disableAdvisor, dispatch(fn, label, opts = {}) { dispatches.push({ fn, label, opts }); }, diff --git a/scripts/check-timeweb.js b/scripts/check-timeweb.js index 17c3b51..7031e03 100644 --- a/scripts/check-timeweb.js +++ b/scripts/check-timeweb.js @@ -11,7 +11,8 @@ import { config as loadDotenv } from "dotenv"; loadDotenv(); import { complete, isAvailable, getConfig } from "../runtime/llm/provider.js"; -import { advise, _resetForTest as resetAdvisor } from "../runtime/coach/fast-advisor.js"; +import { advise, getUsageSnapshot, _resetForTest as resetAdvisor } from "../runtime/coach/fast-advisor.js"; +import { tickAdvisor, consumeFreshRecommendation, _resetForTest as resetTrigger } from "../runtime/coach/advisor-trigger.js"; function redact(key) { if (!key) return "(unset)"; @@ -74,10 +75,56 @@ async function main() { console.log(` action: ${r3.action}`); console.log(` skillId: ${r3.skillId ?? "(n/a)"}`); console.log(` why: ${r3.rationale}`); + if (r3.usage) { + console.log(` tokens: in=${r3.usage.in} out=${r3.usage.out} total=${r3.usage.total}`); + } } else { console.log(` code: ${r3.code}`); console.log(` detail: ${String(r3.detail).slice(0, 200)}`); } + + console.log(""); + console.log("→ probe 4: auto-trigger flow (tickAdvisor → wait → consumeFreshRecommendation)"); + resetAdvisor(); + resetTrigger(); + const ctx = { + snapshot: { position: { x: 608, y: 90, z: 91 }, health: 14, food: 18, isDay: true, + inventory: { dirt: 4 }, activeSkill: "explore.far" }, + recentSkillIds: ["explore.far", "explore.far", "explore.far", "explore.far"], + lastSignificantMoveAt: Date.now() - 90_000, + }; + const t = tickAdvisor(ctx, { plannedSkillId: "explore.far" }); + console.log(` trigger fired: ${t.fired} (${t.reason})`); + // wait up to 25s for async advise to land + const waitStart = Date.now(); + while (!ctx.advisorRecommendation && Date.now() - waitStart < 25_000) { + await new Promise((r) => setTimeout(r, 200)); + } + const consumed = consumeFreshRecommendation(ctx); + if (consumed) { + console.log(` recommendation: ${consumed.skillId}`); + console.log(` rationale: ${consumed.rationale}`); + console.log(` latency: ${consumed.latencyMs}ms`); + if (consumed.usage) { + console.log(` tokens: in=${consumed.usage.in} out=${consumed.usage.out} total=${consumed.usage.total}`); + } + } else { + console.log(` no recommendation (timeout or non-switch action)`); + } + + console.log(""); + console.log("=== Usage budget summary ==="); + const usage = getUsageSnapshot(); + console.log(` calls (last hour): ${usage.callsLastHour}/${usage.hourlyBudget}`); + console.log(` calls total: ${usage.callsTotal}`); + console.log(` tokens in (total): ${usage.tokensInTotal}`); + console.log(` tokens out (total): ${usage.tokensOutTotal}`); + // Rough cost estimate for context — TimeWeb pricing unknown, OpenAI + // gpt-5-mini hypothetical: $0.15/M input + $0.60/M output. + const estUsd = (usage.tokensInTotal * 0.15 + usage.tokensOutTotal * 0.60) / 1_000_000; + console.log(` est. cost (OpenAI gpt-5-mini pricing): $${estUsd.toFixed(6)}`); + console.log(` per-call avg in: ${Math.round(usage.tokensInTotal / Math.max(1, usage.callsTotal))}t`); + console.log(` hourly @ budget: ${Math.round(usage.tokensInTotal / Math.max(1, usage.callsTotal)) * usage.hourlyBudget}t in / ${Math.round(usage.tokensOutTotal / Math.max(1, usage.callsTotal)) * usage.hourlyBudget}t out`); } function logResult(r) {