Skip to content

Commit 751aa84

Browse files
habedihabedi
committed
Enhance logging: add detailed logging for tool execution, configuration loading, and error handling
1 parent 27ad0f5 commit 751aa84

File tree

4 files changed

+89
-5
lines changed

4 files changed

+89
-5
lines changed

‎src/agent/llm.ts‎

Lines changed: 17 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -5,15 +5,19 @@ import { createAnthropic } from "@ai-sdk/anthropic";
55
import { createOllama } from "ollama-ai-provider-v2";
66
import { type LanguageModel, type ModelMessage, streamText, tool } from "ai";
77
import "dotenv/config";
8+
import logger from "@/logger.js";
89
import type { Message } from "./types.js";
910
import type { Config, ModelConfig } from "@/config.js";
1011
import { FatalError, TransientError } from "./errors.js";
1112
import { toolArgumentSchemas } from "./tools/definitions/index.js";
1213

1314
export function createLlmProvider(modelConfig: ModelConfig, config: Config): LanguageModel {
15+
logger.info(`Creating LLM provider for: ${modelConfig.provider}`);
1416
const getApiKey = (provider: keyof NonNullable<Config["apiKeys"]>): string | undefined => {
1517
const keyName = config.apiKeys?.[provider];
16-
return keyName ? process.env[keyName] : undefined;
18+
const apiKey = keyName ? process.env[keyName] : undefined;
19+
logger.info(`API key for ${provider}: ${apiKey ? "found" : "not found"}`);
20+
return apiKey;
1721
};
1822

1923
switch (modelConfig.provider) {
@@ -33,26 +37,36 @@ export function createLlmProvider(modelConfig: ModelConfig, config: Config): Lan
3337
return ollama(modelConfig.modelId);
3438
}
3539
default:
40+
logger.error(`Unsupported provider: ${modelConfig.provider}`);
3641
throw new FatalError(`Unsupported provider: ${modelConfig.provider}`);
3742
}
3843
}
3944

4045
export async function streamAssistantResponse(history: Message[], config: Config) {
4146
const modelConfig = config.models.find((m) => m.name === config.defaultModel);
4247
if (!modelConfig) {
48+
logger.error(`Default model "${config.defaultModel}" not found in configuration.`);
4349
throw new FatalError(`Default model "${config.defaultModel}" not found in configuration.`);
4450
}
51+
logger.info(`Using model: ${modelConfig.name}`);
4552

4653
const llmProvider = createLlmProvider(modelConfig, config);
4754

4855
const maxItems = config.history?.maxItems;
4956
const truncatedHistory =
5057
maxItems && history.length > maxItems ? history.slice(-maxItems) : history;
58+
logger.info(`History truncated to ${truncatedHistory.length} items.`);
5159

5260
// Map the history to remove the custom `id` field before sending to the SDK.
5361
// eslint-disable-next-line @typescript-eslint/no-unused-vars
5462
const sdkCompliantHistory: ModelMessage[] = truncatedHistory.map(({ id, ...rest }) => rest);
5563

64+
logger.info("Streaming text from LLM provider.");
65+
logger.debug({
66+
systemPrompt: config.systemPrompt,
67+
messages: sdkCompliantHistory,
68+
});
69+
5670
try {
5771
return await streamText({
5872
model: llmProvider,
@@ -101,6 +115,8 @@ export async function streamAssistantResponse(history: Message[], config: Config
101115
const errorMessage = error instanceof Error ? error.message : "An unknown error occurred.";
102116
const status = (error as Error & { status?: number })?.status;
103117

118+
logger.error(`Error streaming from LLM: ${errorMessage}`, { status });
119+
104120
if (status) {
105121
if (status === 401) {
106122
throw new FatalError(`API authentication failed: ${errorMessage}`);

‎src/agent/state.ts‎

Lines changed: 56 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,7 @@
11
// src/agent/state.ts
22
import { create } from "zustand";
33
import type { Message } from "./types.js";
4+
import logger from "@/logger.js";
45
import { streamAssistantResponse } from "./llm.js";
56
import { runTool } from "./tools/index.js";
67
import { type Config, HISTORY_PATH, loadConfig, saveConfig } from "@/config.js";
@@ -67,49 +68,62 @@ export const useStore = create<AppState & AppActions>((set, get) => ({
6768
branchName: "unknown",
6869
actions: {
6970
loadInitialConfig: async () => {
71+
logger.info("Loading initial configuration.");
7072
try {
7173
const config = await loadConfig();
7274
set({ config, status: "idle" });
75+
logger.info("Configuration loaded successfully.");
7376
await get().actions.updateBranchName();
7477
} catch (error) {
7578
const errorMessage =
7679
error instanceof Error ? error.message : "An unknown error occurred.";
80+
logger.error(`Failed to load configuration: ${errorMessage}`);
7781
set({ error: `Failed to load configuration: ${errorMessage}`, status: "error" });
7882
}
7983
},
8084
updateBranchName: async () => {
85+
logger.info("Updating branch name.");
8186
try {
8287
const git = simpleGit();
8388
const branch = await git.revparse(["--abbrev-ref", "HEAD"]);
8489
set({ branchName: branch });
90+
logger.info(`Branch name updated to: ${branch}`);
8591
} catch (error) {
92+
logger.warn("Failed to update branch name. Are you in a git repository?");
8693
set({ branchName: "unknown" });
8794
}
8895
},
8996
openHelpMenu: () => {
97+
logger.info("Opening help menu.");
9098
set({ helpMenuOpen: true });
9199
},
92100
closeHelpMenu: () => {
101+
logger.info("Closing help menu.");
93102
set({ helpMenuOpen: false });
94103
},
95104
clearOutput: () => {
105+
logger.info("Clearing output.");
96106
set({ history: [] });
97107
},
98108
clearCommandHistory: () => {
109+
logger.info("Clearing command history.");
99110
set({ commandHistory: [], commandHistoryIndex: 0 });
100111
try {
101112
fsSync.writeFileSync(HISTORY_PATH, "");
102113
} catch (err) {
114+
logger.error("Failed to clear history file:", err);
103115
console.error("Failed to clear history file:", err);
104116
}
105117
},
106118
clearError: () => {
107119
const { status } = get();
108120
if (status === "error") {
121+
logger.info("Clearing error.");
109122
set({ error: null, status: "idle" });
110123
}
111124
},
112125
addCommandToHistory: (command) => {
126+
logger.info(`Adding command to history: ${command}`);
113127
const { commandHistory } = get();
114128
const newCommandHistory = [...commandHistory, command];
115129
set({
@@ -119,6 +133,7 @@ export const useStore = create<AppState & AppActions>((set, get) => ({
119133
try {
120134
fsSync.appendFileSync(HISTORY_PATH, command + "\n");
121135
} catch (err) {
136+
logger.error("Failed to write to history file:", err);
122137
console.error("Failed to write to history file:", err);
123138
}
124139
},
@@ -145,6 +160,7 @@ export const useStore = create<AppState & AppActions>((set, get) => ({
145160
return null;
146161
},
147162
setSystemPrompt: (prompt) => {
163+
logger.info(`Setting system prompt to: ${prompt}`);
148164
const { config } = get();
149165
if (config) {
150166
const newConfig = { ...config, systemPrompt: prompt };
@@ -153,37 +169,51 @@ export const useStore = create<AppState & AppActions>((set, get) => ({
153169
}
154170
},
155171
setModel: (modelName) => {
172+
logger.info(`Setting model to: ${modelName}`);
156173
const { config } = get();
157174
if (config) {
158175
const modelExists = config.models.some((m) => m.name === modelName);
159176
if (modelExists) {
160177
const newConfig = { ...config, defaultModel: modelName };
161178
set({ config: newConfig });
162179
saveConfig(newConfig);
180+
logger.info(`Successfully set model to: ${modelName}`);
163181
} else {
182+
logger.error(`Model "${modelName}" not found in config.`);
164183
console.error(`Model "${modelName}" not found in config.`);
165184
}
166185
}
167186
},
168187
startAgent: async (input: string) => {
169-
if (get().status === "error") return;
188+
logger.info(`Starting agent with input: ${input}`);
189+
if (get().status === "error") {
190+
logger.warn("Agent start prevented due to existing error.");
191+
return;
192+
}
170193
const fileRegex = /@([^\s]+)/g;
171194
let processedInput = input;
172195
const matches = Array.from(input.matchAll(fileRegex));
173196
const newHistory: Message[] = [...get().history];
174197
let shouldContinue = true;
175198

199+
if (matches.length > 0) {
200+
logger.info(`Found ${matches.length} file references in input.`);
201+
}
202+
176203
for (const match of matches) {
177204
const filePath = match[1];
178205
if (filePath) {
206+
logger.info(`Reading file content for: ${filePath}`);
179207
try {
180208
const fileContent = await fs.readFile(filePath, "utf-8");
181209
processedInput = processedInput.replace(
182210
`@${filePath}`,
183211
`\n\n\`\`\`${filePath}\n${fileContent}\n\`\`\``,
184212
);
213+
logger.info(`Successfully read and embedded file: ${filePath}`);
185214
} catch (error) {
186215
const errorMessage = `File not found: ${filePath}`;
216+
logger.error(`Error reading file: ${errorMessage}`);
187217
newHistory.push({
188218
id: crypto.randomUUID(),
189219
role: "assistant",
@@ -195,21 +225,30 @@ export const useStore = create<AppState & AppActions>((set, get) => ({
195225
}
196226
}
197227

198-
if (!shouldContinue) return;
228+
if (!shouldContinue) {
229+
logger.warn("Agent execution halted due to file reading error.");
230+
return;
231+
}
199232

200233
newHistory.push({ role: "user", content: processedInput, id: crypto.randomUUID() });
201234
set({ history: newHistory, status: "thinking" });
235+
logger.info("Agent is now thinking.");
202236
await get().actions._runAgentLogic();
203237
},
204238
_runAgentLogic: async (retryCount = 0) => {
239+
logger.info(`Running agent logic, retry count: ${retryCount}`);
205240
try {
206241
const { history, config } = get();
207-
if (!config) return;
242+
if (!config) {
243+
logger.warn("No config found, aborting agent logic.");
244+
return;
245+
}
208246

209247
const { textStream, toolCalls: toolCallPartsPromise } =
210248
await streamAssistantResponse(history, config);
211249

212250
let assistantMessage: Message | null = null;
251+
logger.info("Streaming assistant response.");
213252

214253
for await (const part of textStream) {
215254
if (!assistantMessage) {
@@ -225,8 +264,10 @@ export const useStore = create<AppState & AppActions>((set, get) => ({
225264
assistantMessage.content += part;
226265
set((state) => ({ history: [...state.history] }));
227266
}
267+
logger.info("Finished streaming assistant response.");
228268

229269
const toolCalls = await toolCallPartsPromise;
270+
logger.info("Tool calls received from LLM.", { toolCalls });
230271

231272
if (toolCalls.length > 0) {
232273
const toolCallContents: ToolCallPart[] = toolCalls.map((toolCall) => ({
@@ -257,6 +298,7 @@ export const useStore = create<AppState & AppActions>((set, get) => ({
257298
set((state) => ({ history: [...state.history] }));
258299

259300
set({ status: "executing-tool" });
301+
logger.info("Executing tools.", { toolCalls });
260302
const toolResults: Message[] = [];
261303
for (const toolCall of toolCalls) {
262304
try {
@@ -268,6 +310,7 @@ export const useStore = create<AppState & AppActions>((set, get) => ({
268310
result === "" || result === null || result === undefined
269311
? "Tool executed successfully and produced no output."
270312
: result;
313+
logger.info("Tool executed successfully.", { toolCall, output });
271314
toolResults.push({
272315
id: crypto.randomUUID(),
273316
role: "tool",
@@ -283,6 +326,7 @@ export const useStore = create<AppState & AppActions>((set, get) => ({
283326
});
284327
} catch (error) {
285328
if (error instanceof ToolError) {
329+
logger.error("Tool execution failed.", { toolCall, error });
286330
toolResults.push({
287331
id: crypto.randomUUID(),
288332
role: "tool",
@@ -297,6 +341,10 @@ export const useStore = create<AppState & AppActions>((set, get) => ({
297341
],
298342
});
299343
} else {
344+
logger.error(
345+
"An unexpected error occurred during tool execution.",
346+
{ toolCall, error },
347+
);
300348
throw error;
301349
}
302350
}
@@ -305,12 +353,15 @@ export const useStore = create<AppState & AppActions>((set, get) => ({
305353
history: [...state.history, ...toolResults],
306354
status: "thinking",
307355
}));
356+
logger.info("Tool execution finished, rerunning agent logic.");
308357
await get().actions._runAgentLogic();
309358
} else {
310359
set({ status: "idle" });
360+
logger.info("No tool calls, agent is now idle.");
311361
}
312362
} catch (error) {
313363
if (error instanceof TransientError && retryCount < MAX_RETRIES) {
364+
logger.warn(`Transient error caught, retrying... (${retryCount + 1})`);
314365
set({ status: "idle" });
315366
const backoff = INITIAL_BACKOFF_MS * 2 ** retryCount;
316367
setTimeout(() => {
@@ -324,8 +375,10 @@ export const useStore = create<AppState & AppActions>((set, get) => ({
324375
error instanceof Error ? error.message : "An unknown error occurred.";
325376

326377
if (error instanceof FatalError) {
378+
logger.error(`Fatal error: ${errorMessage}`);
327379
set({ error: errorMessage, status: "error" });
328380
} else {
381+
logger.error(`Unhandled error in agent logic: ${errorMessage}`);
329382
set({ error: errorMessage, status: "error" });
330383
}
331384
}

‎src/agent/tools/index.ts‎

Lines changed: 7 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -3,6 +3,7 @@ import { toolModules, toolSchemas } from "./definitions/index.js";
33
import type { ToolCall } from "../types.js";
44
import { ToolError } from "../errors.js";
55
import type { Config } from "@/config";
6+
import logger from "@/logger.js";
67

78
export { toolSchemas };
89

@@ -18,18 +19,24 @@ export async function runTool(
1819
config: Config,
1920
): Promise<unknown> {
2021
const toolName = toolCall.toolName as ToolCall["name"];
22+
logger.info(`Running tool: ${toolName}`);
23+
logger.debug({ args: toolCall.args });
24+
2125
const implementation = toolImplementations[toolName];
2226
const toolDef = toolModules[toolName as keyof typeof toolModules];
2327

2428
if (!implementation || !toolDef) {
29+
logger.error(`Unknown tool "${toolName}"`);
2530
throw new ToolError(`Unknown tool "${toolName}"`);
2631
}
2732

2833
try {
2934
const validatedArgs = toolDef.schema.shape.arguments.parse(toolCall.args);
35+
logger.info("Tool arguments validated successfully.");
3036
// Pass config to all tools; most will ignore it, but 'mcp' needs it.
3137
return await implementation(validatedArgs, config);
3238
} catch (error) {
39+
logger.error(`Error running tool ${toolName}:`, error);
3340
if (error instanceof ToolError) {
3441
throw error;
3542
}

‎tests/agent/state.test.ts‎

Lines changed: 9 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -5,7 +5,15 @@ import { FatalError, TransientError } from "@/agent/errors";
55
// Mock dependencies
66
vi.mock("@/agent/llm");
77
vi.mock("@/agent/tools");
8-
vi.mock("@/config");
8+
vi.mock("@/config", () => ({
9+
...vi.importActual("@/config"),
10+
getConfigDir: () => "/tmp/tobi-test",
11+
loadConfig: vi.fn().mockResolvedValue({
12+
defaultModel: "test-model",
13+
models: [{ name: "test-model", provider: "test" }],
14+
systemPrompt: "test-prompt",
15+
}),
16+
}));
917
vi.mock("simple-git");
1018

1119
describe("Agent State Machine", () => {

0 commit comments

Comments
 (0)