From 991404393252caedc248e33808e34030a29157e4 Mon Sep 17 00:00:00 2001 From: Peli de Halleux Date: Fri, 18 Oct 2024 15:12:31 +0000 Subject: [PATCH] =?UTF-8?q?=F0=9F=94=A7=20feat:=20add=20debug=20logging=20?= =?UTF-8?q?and=20enhance=20error=20handling?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --- .../content/docs/reference/scripts/system.mdx | 4 +- packages/cli/src/run.ts | 3 +- packages/core/bundleprompts.js | 1 + packages/core/src/chat.ts | 314 +++++++++--------- .../system.python_code_interpreter.genai.mjs | 4 +- packages/core/src/types/prompt_template.d.ts | 1 + packages/core/src/util.ts | 2 +- 7 files changed, 173 insertions(+), 156 deletions(-) diff --git a/docs/src/content/docs/reference/scripts/system.mdx b/docs/src/content/docs/reference/scripts/system.mdx index c0d4893a03..c87554f2f3 100644 --- a/docs/src/content/docs/reference/scripts/system.mdx +++ b/docs/src/content/docs/reference/scripts/system.mdx @@ -2635,8 +2635,8 @@ defTool( }, async (args) => { const { context, main = "" } = args - context.log(`python:`) - console.log(main) + context.log(`python: exec`) + context.debug(main) const container = await getContainer() return await container.scheduler.add(async () => { await container.writeText("main.py", main) diff --git a/packages/cli/src/run.ts b/packages/cli/src/run.ts index 2b9f338221..68743286aa 100644 --- a/packages/cli/src/run.ts +++ b/packages/cli/src/run.ts @@ -61,6 +61,7 @@ import { logError, dotGenaiscriptPath, logInfo, + logWarn, } from "../../core/src/util" import { YAMLStringify } from "../../core/src/yaml" import { PromptScriptRunOptions } from "../../core/src/server/messages" @@ -551,7 +552,7 @@ export async function runScript( if (result.status === "success") logInfo(`genaiscript: ${result.status}`) else if (result.status === "cancelled") - logInfo(`genaiscript: ${result.status}`) + logWarn(`genaiscript: ${result.status}`) else logError(`genaiscript: ${result.status}`) stats.log() if (outTraceFilename) logVerbose(` trace: ${outTraceFilename}`) diff --git a/packages/core/bundleprompts.js b/packages/core/bundleprompts.js index 6b0e4475d4..9250ee6ead 100644 --- a/packages/core/bundleprompts.js +++ b/packages/core/bundleprompts.js @@ -16,6 +16,7 @@ async function main() { if (/\.genai\.m?js$/.test(prompt)) promptMap[prompt.replace(/\.genai\.m?js$/i, "")] = text } + console.log(`found ${prompts.length} prompts`) const promptFooDriver = readFileSync( "./src/genaiscript-api-provider.mjs", "utf-8" diff --git a/packages/core/src/chat.ts b/packages/core/src/chat.ts index 5ba84d607c..992f95f269 100644 --- a/packages/core/src/chat.ts +++ b/packages/core/src/chat.ts @@ -11,7 +11,6 @@ import { import { assert, logError, logVerbose, logWarn } from "./util" import { extractFenced, findFirstDataFence, unfence } from "./fence" import { - JSONSchemaToFunctionParameters, toStrictJSONSchema, validateFencesWithSchema, validateJSONWithSchema, @@ -33,7 +32,7 @@ import { ChatCompletionResponse, ChatCompletionsOptions, ChatCompletionTool, - ChatCompletionUsage, + ChatCompletionToolCall, ChatCompletionUserMessageParam, CreateChatCompletionRequest, } from "./chattypes" @@ -153,164 +152,179 @@ async function runToolCalls( // call tool and run again for (const call of resp.toolCalls) { checkCancelled(cancellationToken) - - trace.startDetails(`📠 tool call ${call.name}`) + const toolTrace = trace.startTraceDetails(`📠 tool call ${call.name}`) try { - const callArgs: any = call.arguments // sometimes wrapped in \`\`\`json ... - ? JSONLLMTryParse(call.arguments) - : undefined - trace.fence(call.arguments, "json") - if (callArgs === undefined) trace.error("arguments failed to parse") - - let todos: { tool: ToolCallback; args: any }[] - if (call.name === "multi_tool_use.parallel") { - // special undocumented openai hallucination, argument contains multiple tool calls - // { - // "id": "call_D48fudXi4oBxQ2rNeHhpwIKh", - // "name": "multi_tool_use.parallel", - // "arguments": "{\"tool_uses\":[{\"recipient_name\":\"functions.fs_find_files\",\"parameters\":{\"glob\":\"src/content/docs/**/*.md\"}},{\"recipient_name\":\"functions.fs_find_files\",\"parameters\":{\"glob\":\"src/content/docs/**/*.mdx\"}},{\"recipient_name\":\"functions.fs_find_files\",\"parameters\":{\"glob\":\"../packages/sample/src/*.genai.{js,mjs}\"}},{\"recipient_name\":\"functions.fs_find_files\",\"parameters\":{\"glob\":\"src/assets/*.txt\"}}]}" - // } - const toolUses = callArgs.tool_uses as { - recipient_name: string - parameters: any - }[] - todos = toolUses.map((tu) => { - const toolName = tu.recipient_name.replace( - /^functions\./, - "" - ) - const tool = tools.find((f) => f.spec.name === toolName) - if (!tool) { - logVerbose(JSON.stringify(tu, null, 2)) - throw new Error( - `multi tool ${toolName} not found in ${tools.map((t) => t.spec.name).join(", ")}` - ) - } - return { tool, args: tu.parameters } - }) - } else { - let tool = tools.find((f) => f.spec.name === call.name) - if (!tool) { - logVerbose(JSON.stringify(call, null, 2)) - logVerbose( - `tool ${call.name} not found in ${tools.map((t) => t.spec.name).join(", ")}` - ) - tool = { - spec: { - name: call.name, - description: "unknown tool", - }, - impl: async () => "unknown tool", - } - } - todos = [{ tool, args: callArgs }] - } + await runToolCall( + trace, + call, + tools, + edits, + projFolder, + encoder, + messages + ) + } catch (e) { + logError(e) + toolTrace.error(`tool call ${call.id} error`, e) + throw e + } finally { + toolTrace.endDetails() + } + } - const toolResult: string[] = [] - for (const todo of todos) { - const { tool, args } = todo - const { - maxTokens: maxToolContentTokens = MAX_TOOL_CONTENT_TOKENS, - } = tool.options || {} - const context: ToolCallContext = { - log: (txt: string) => { - logVerbose(txt) - trace.log(txt) - }, - trace, - } + return { edits } +} - let output: ToolCallOutput - try { - output = await tool.impl({ context, ...args }) - } catch (e) { - logWarn(`tool: ${tool.spec.name} error`) - logError(e) - trace.error(`tool: ${tool.spec.name} error`, e) - output = errorMessage(e) - } - if (output === undefined || output === null) - throw new Error( - `error: tool ${tool.spec.name} raised an error` - ) - let toolContent: string = undefined - let toolEdits: Edits[] = undefined - if (typeof output === "string") toolContent = output - else if ( - typeof output === "number" || - typeof output === "boolean" +async function runToolCall( + trace: MarkdownTrace, + call: ChatCompletionToolCall, + tools: ToolCallback[], + edits: Edits[], + projFolder: string, + encoder: TokenEncoder, + messages: ChatCompletionMessageParam[] +) { + const callArgs: any = call.arguments // sometimes wrapped in \`\`\`json ... + ? JSONLLMTryParse(call.arguments) + : undefined + trace.fence(call.arguments, "json") + if (callArgs === undefined) trace.error("arguments failed to parse") + + let todos: { tool: ToolCallback; args: any }[] + if (call.name === "multi_tool_use.parallel") { + // special undocumented openai hallucination, argument contains multiple tool calls + // { + // "id": "call_D48fudXi4oBxQ2rNeHhpwIKh", + // "name": "multi_tool_use.parallel", + // "arguments": "{\"tool_uses\":[{\"recipient_name\":\"functions.fs_find_files\",\"parameters\":{\"glob\":\"src/content/docs/**/*.md\"}},{\"recipient_name\":\"functions.fs_find_files\",\"parameters\":{\"glob\":\"src/content/docs/**/*.mdx\"}},{\"recipient_name\":\"functions.fs_find_files\",\"parameters\":{\"glob\":\"../packages/sample/src/*.genai.{js,mjs}\"}},{\"recipient_name\":\"functions.fs_find_files\",\"parameters\":{\"glob\":\"src/assets/*.txt\"}}]}" + // } + const toolUses = callArgs.tool_uses as { + recipient_name: string + parameters: any + }[] + todos = toolUses.map((tu) => { + const toolName = tu.recipient_name.replace(/^functions\./, "") + const tool = tools.find((f) => f.spec.name === toolName) + if (!tool) { + logVerbose(JSON.stringify(tu, null, 2)) + throw new Error( + `multi tool ${toolName} not found in ${tools.map((t) => t.spec.name).join(", ")}` ) - toolContent = String(output) - else if ( - typeof output === "object" && - (output as ShellOutput).exitCode !== undefined - ) { - toolContent = renderShellOutput(output as ShellOutput) - } else if ( - typeof output === "object" && - (output as WorkspaceFile).filename && - (output as WorkspaceFile).content - ) { - const { filename, content } = output as WorkspaceFile - toolContent = `FILENAME: ${filename} -${fenceMD(content, " ")} -` - } else if ( - typeof output === "object" && - (output as RunPromptResult).text - ) { - const { text } = output as RunPromptResult - toolContent = text - } else { - toolContent = YAMLStringify(output) - } + } + return { tool, args: tu.parameters } + }) + } else { + let tool = tools.find((f) => f.spec.name === call.name) + if (!tool) { + logVerbose(JSON.stringify(call, null, 2)) + logVerbose( + `tool ${call.name} not found in ${tools.map((t) => t.spec.name).join(", ")}` + ) + trace.log(`tool ${call.name} not found`) + tool = { + spec: { + name: call.name, + description: "unknown tool", + }, + impl: async () => "unknown tool", + } + } + todos = [{ tool, args: callArgs }] + } - if (typeof output === "object") - toolEdits = (output as ToolCallContent)?.edits - - if (toolEdits?.length) { - trace.fence(toolEdits) - edits.push( - ...toolEdits.map((e) => { - const { filename, ...rest } = e - const n = e.filename - const fn = /^[^\/]/.test(n) - ? host.resolvePath(projFolder, n) - : n - return { filename: fn, ...rest } - }) - ) - } + const toolResult: string[] = [] + for (const todo of todos) { + const { tool, args } = todo + const { maxTokens: maxToolContentTokens = MAX_TOOL_CONTENT_TOKENS } = + tool.options || {} + const context: ToolCallContext = { + log: (message: string) => { + logVerbose(message) + trace.log(message) + }, + debug: (message: string) => { + logVerbose(message) + trace.log(message) + }, + trace, + } - const toolContentTokens = estimateTokens(toolContent, encoder) - if (toolContentTokens > maxToolContentTokens) { - logWarn( - `tool: ${tool.spec.name} response too long (${toolContentTokens} tokens), truncating ${maxToolContentTokens} tokens` - ) - toolContent = truncateTextToTokens( - toolContent, - maxToolContentTokens, - encoder - ) - } - trace.fence(toolContent, "markdown") - toolResult.push(toolContent) - } - messages.push({ - role: "tool", - content: toolResult.join("\n\n"), - tool_call_id: call.id, - }) + let output: ToolCallOutput + try { + output = await tool.impl({ context, ...args }) } catch (e) { + logWarn(`tool: ${tool.spec.name} error`) logError(e) - trace.error(`tool call ${call.id} error`, e) - throw e - } finally { - trace.endDetails() + trace.error(`tool: ${tool.spec.name} error`, e) + output = errorMessage(e) + } + if (output === undefined || output === null) + throw new Error(`error: tool ${tool.spec.name} raised an error`) + let toolContent: string = undefined + let toolEdits: Edits[] = undefined + if (typeof output === "string") toolContent = output + else if (typeof output === "number" || typeof output === "boolean") + toolContent = String(output) + else if ( + typeof output === "object" && + (output as ShellOutput).exitCode !== undefined + ) { + toolContent = renderShellOutput(output as ShellOutput) + } else if ( + typeof output === "object" && + (output as WorkspaceFile).filename && + (output as WorkspaceFile).content + ) { + const { filename, content } = output as WorkspaceFile + toolContent = `FILENAME: ${filename} +${fenceMD(content, " ")} +` + } else if ( + typeof output === "object" && + (output as RunPromptResult).text + ) { + const { text } = output as RunPromptResult + toolContent = text + } else { + toolContent = YAMLStringify(output) } - } - return { edits } + if (typeof output === "object") + toolEdits = (output as ToolCallContent)?.edits + + if (toolEdits?.length) { + trace.fence(toolEdits) + edits.push( + ...toolEdits.map((e) => { + const { filename, ...rest } = e + const n = e.filename + const fn = /^[^\/]/.test(n) + ? host.resolvePath(projFolder, n) + : n + return { filename: fn, ...rest } + }) + ) + } + + const toolContentTokens = estimateTokens(toolContent, encoder) + if (toolContentTokens > maxToolContentTokens) { + logWarn( + `tool: ${tool.spec.name} response too long (${toolContentTokens} tokens), truncating ${maxToolContentTokens} tokens` + ) + toolContent = truncateTextToTokens( + toolContent, + maxToolContentTokens, + encoder + ) + } + trace.fence(toolContent, "markdown") + toolResult.push(toolContent) + } + messages.push({ + role: "tool", + content: toolResult.join("\n\n"), + tool_call_id: call.id, + }) } async function applyRepairs( diff --git a/packages/core/src/genaisrc/system.python_code_interpreter.genai.mjs b/packages/core/src/genaisrc/system.python_code_interpreter.genai.mjs index 961663aa8a..afe6c39c48 100644 --- a/packages/core/src/genaisrc/system.python_code_interpreter.genai.mjs +++ b/packages/core/src/genaisrc/system.python_code_interpreter.genai.mjs @@ -28,8 +28,8 @@ defTool( }, async (args) => { const { context, main = "" } = args - context.log(`python:`) - console.log(main) + context.log(`python: exec`) + context.debug(main) const container = await getContainer() return await container.scheduler.add(async () => { await container.writeText("main.py", main) diff --git a/packages/core/src/types/prompt_template.d.ts b/packages/core/src/types/prompt_template.d.ts index 323a3f41be..a15919799a 100644 --- a/packages/core/src/types/prompt_template.d.ts +++ b/packages/core/src/types/prompt_template.d.ts @@ -667,6 +667,7 @@ interface WorkspaceFileSystem { interface ToolCallContext { log(message: string): void + debug(message: string): void trace: ToolCallTrace } diff --git a/packages/core/src/util.ts b/packages/core/src/util.ts index 539b056db3..5e4cbe1ff8 100644 --- a/packages/core/src/util.ts +++ b/packages/core/src/util.ts @@ -214,7 +214,7 @@ export function logError(msg: string | Error | SerializedError) { const err = serializeError(msg) const { message, name, stack, ...e } = err || {} if (isCancelError(err)) { - host.log(LogLevel.Info, message || "cancelled") + host.log(LogLevel.Warn, message || "cancelled") return } host.log(LogLevel.Error, message ?? name ?? "error")