From 765ae641d765fa21b2a68e2ed9fd23e8247cdb85 Mon Sep 17 00:00:00 2001 From: "Roscoe A. Bartlett" Date: Tue, 1 Sep 2026 16:17:03 -0400 Subject: [PATCH] fix(core): Fix for incorrect time.start reset in tool call logging (#32574) (#32596) --- packages/opencode/src/session/tools.ts | 2 +- packages/opencode/test/session/tools.test.ts | 163 +++++++++++++++++++ 2 files changed, 164 insertions(+), 1 deletion(-) create mode 100644 packages/opencode/test/session/tools.test.ts diff --git a/packages/opencode/src/session/tools.ts b/packages/opencode/src/session/tools.ts index 0f401c7562..99f7aec4fd 100644 --- a/packages/opencode/src/session/tools.ts +++ b/packages/opencode/src/session/tools.ts @@ -74,7 +74,7 @@ export const resolve = Effect.fn("SessionTools.resolve")(function* (input: { metadata: val.metadata, status: "running", input: args, - time: { start: Date.now() }, + time: match.state.status === "running" ? match.state.time : { start: Date.now() }, }, } }), diff --git a/packages/opencode/test/session/tools.test.ts b/packages/opencode/test/session/tools.test.ts new file mode 100644 index 0000000000..53d28de169 --- /dev/null +++ b/packages/opencode/test/session/tools.test.ts @@ -0,0 +1,163 @@ +import { expect } from "bun:test" +import { ModelV2 } from "@opencode-ai/core/model" +import { ProviderV2 } from "@opencode-ai/core/provider" +import { SessionV1 } from "@opencode-ai/core/v1/session" +import { Agent } from "@/agent/agent" +import { MCP } from "@/mcp" +import { Permission } from "@/permission" +import { Provider } from "@/provider/provider" +import { Session } from "@/session/session" +import { MessageID, PartID, SessionID } from "@/session/schema" +import { SessionProcessor } from "@/session/processor" +import { SessionTools } from "@/session/tools" +import { Tool } from "@/tool/tool" +import { ToolRegistry } from "@/tool/registry" +import { Truncate } from "@/tool/truncate" +import { Plugin } from "@/plugin" +import { Effect, Layer, Schema } from "effect" +import { testEffect } from "../lib/effect" + +const callID = "call-test" +const sessionID = SessionID.make("ses_test") +const messageID = MessageID.ascending() +const partID = PartID.ascending() + +const agent: Agent.Info = { + name: "build", + mode: "primary", + options: {}, + permission: [{ permission: "*", pattern: "*", action: "allow" }], +} + +const model = { + providerID: ProviderV2.ID.make("test"), + api: { id: "test-model" }, +} as Provider.Model + +function fakeMcp() { + return MCP.Service.of({ + tools: () => Effect.succeed({}), + } as Partial as MCP.Interface) +} + +const fakePlugin = Plugin.Service.of({ + init: () => Effect.void, + list: () => Effect.succeed([]), + trigger: (_name, _input, output) => Effect.succeed(output), +} satisfies Plugin.Interface) + +const fakePermission = Permission.Service.of({ + ask: () => Effect.void, + reply: () => Effect.void, + list: () => Effect.succeed([]), +} satisfies Permission.Interface) + +const fakeTruncate = Truncate.Service.of({ + cleanup: () => Effect.void, + write: () => Effect.succeed("output.txt"), + output: (text: string) => Effect.succeed({ content: text, truncated: false }), + limits: () => Effect.succeed({ maxLines: 2000, maxBytes: 50 * 1024 }), +} satisfies Truncate.Interface) + +const layer = Layer.mergeAll( + Layer.succeed(Plugin.Service, fakePlugin), + Layer.succeed(Permission.Service, fakePermission), + Layer.succeed(MCP.Service, fakeMcp()), + Layer.succeed(Truncate.Service, fakeTruncate), + Layer.succeed( + ToolRegistry.Service, + ToolRegistry.Service.of({ + ids: () => Effect.succeed(["timing"]), + all: () => Effect.succeed([]), + named: () => Effect.die("unused"), + tools: () => + Effect.succeed([ + { + id: "timing", + description: "updates metadata more than once", + parameters: Schema.Struct({}), + jsonSchema: { type: "object", properties: {} }, + execute: (_args, ctx) => + Effect.gen(function* () { + yield* ctx.metadata({ metadata: { output: "first" } }) + yield* ctx.metadata({ metadata: { output: "second" } }) + return { title: "timing", metadata: {}, output: "done" } + }), + } satisfies Tool.Def, + ]), + }), + ), +) + +const it = testEffect(layer) + +it.effect("preserves running tool start time across metadata updates", () => + Effect.gen(function* () { + const state: SessionV1.ToolPart = { + id: partID, + sessionID, + messageID, + type: "tool", + tool: "timing", + callID, + state: { + status: "running", + input: {}, + time: { start: 100 }, + }, + } + const updates: number[] = [] + const processor = { + message: { + id: messageID, + sessionID, + role: "assistant", + parentID: MessageID.ascending(), + agent: "build", + mode: "build", + path: { cwd: "/tmp", root: "/tmp" }, + cost: 0, + tokens: { input: 0, output: 0, reasoning: 0, cache: { read: 0, write: 0 } }, + modelID: ModelV2.ID.make("test-model"), + providerID: ProviderV2.ID.make("test"), + time: { created: 1 }, + } satisfies SessionV1.Assistant, + updateToolCall: (_toolCallID, update) => + Effect.sync(() => { + const next = update(state) + state.state = next.state + if (state.state.status === "running") updates.push(state.state.time.start) + return state + }), + completeToolCall: () => Effect.void, + } satisfies Pick + + const tools = yield* SessionTools.resolve({ + agent, + model, + session: { id: sessionID, permission: [] } as Session.Info, + processor, + bypassAgentCheck: false, + messages: [], + promptOps: {} as never, + }) + const execute = tools.timing.execute + if (!execute) throw new Error("timing tool is missing execute") + + yield* Effect.promise(() => + execute( + {}, + { + toolCallId: callID, + abortSignal: new AbortController().signal, + }, + ), + ) + + expect(updates).toEqual([100, 100]) + expect(state.state.status).toBe("running") + if (state.state.status === "running") { + expect(state.state.time.start).toBe(100) + } + }), +)