Skip to content

Commit 3ca0f59

Browse files
MichaelAndersvishal veerareddy
andauthored
Fix audit logging (#27)
* Fix audit logging Problem: PR #20 introduced new code but unintentionally introduced inconsistent code. Changes implemented: 1. Files cleaned up 2. Missing dns-logger.js added 3. New code added Testing: success: npm run test:unit success: Claude connects to Lynkr correctly * Add audit logging integration to orchestrator Integrates the audit logging infrastructure with the orchestrator's runAgentLoop function to capture all LLM request/response pairs for compliance and debugging purposes. Changes: - Add crypto module import for correlation ID generation - Add getDestinationUrl() helper to resolve provider endpoints - Instantiate audit logger at the start of runAgentLoop - Log LLM requests before invokeModel() with correlation IDs - Log LLM responses after invokeModel() with token usage and latency - Handle streaming, success, and error response cases - Add logs/ directory to .gitignore The audit logger is a no-op when disabled, ensuring zero overhead when not in use. All logs use structured JSON format with correlation IDs to link request/response pairs. Implements plan from PR #27 for intelligent audit logging. * Fix Ollama system prompt handling and add diagnostic logging After adding more comprehensive logging to track context flow through the request pipeline, discovered a bug in Ollama system prompt handling. BUG FIX: Ollama System Prompt Handling - Problem: System prompts were being flattened into the first user message for Ollama - Impact: Models received instructions as conversational context instead of system directives, causing meta-commentary responses instead of tool execution - Fix: Keep system prompt separate for Ollama (same pattern as other providers) - Files: src/orchestrator/index.js, src/clients/databricks.js Diagnostic Logging Added: - MEMORY_DEBUG: Track memory retrieval, formatting, and injection (src/memory/retriever.js) - SESSION_DEBUG: Track session reuse vs creation, age, and history size (src/sessions/store.js) - CONTEXT_FLOW: Track system prompt transformations through the pipeline (src/orchestrator/index.js) The diagnostic logging revealed how system prompts flow through the request pipeline and helped identify where the flattening was occurring. * Added tool capable models --------- Co-authored-by: vishal veerareddy <vishalveera.reddy@servicenow.com>
1 parent cac4458 commit 3ca0f59

17 files changed

Lines changed: 3446 additions & 55 deletions

.gitignore

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,7 @@
11
node_modules/
22
data/
33
*.db
4+
logs/
45
npm-debug.log
56
SUBAGENT_IMPLEMENTATION_PLAN_V2.md
67
.DS_Store

docs/memory-stale-context-fix.md

Lines changed: 255 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,255 @@
1+
# Memory System Stale Context Issue - RESOLVED
2+
3+
## Problem
4+
5+
User typed "ls" → got strange response about "bd ready", "testLynkr directory", issue tracking workflow instead of file listing.
6+
7+
## Root Cause Found
8+
9+
The context flow logging revealed the exact problem:
10+
11+
```
12+
after_sanitize: systemPromptLength: 0 (clean)
13+
after_compression: systemPromptLength: 0 (still clean)
14+
after_memory: systemPromptLength: 201 (STALE CONTEXT INJECTED!)
15+
```
16+
17+
**Memory system injecting 5 stale memories from previous conversation:**
18+
1. "a `Glob` pattern to list files and directories in the specified path"
19+
2. "help with using Claude Code"
20+
3. "help or want to give feedback, type /help or report issues at https://github"
21+
4. "to explore the contents of the `testLynkr` directory, list its files and directories, or perform ano"
22+
5. "further assistance or specific actions based on this listing, please let me know"
23+
24+
These memories were retrieved for EVERY new command ("ls", "pwd", etc.), confusing the LLM.
25+
26+
## Temporary Fix
27+
28+
**Disable memory injection** by setting environment variable:
29+
```bash
30+
export MEMORY_ENABLED=false
31+
```
32+
33+
Added to `~/start_lynkr` script.
34+
35+
## Verification Steps
36+
37+
1. Restart Lynkr with updated script: `~/start_lynkr`
38+
2. Test "ls" command - should return actual file listing
39+
3. Check logs: `grep "MEMORY_DEBUG" ~/Lynkr_original/Lynkr/logs/llm-audit.log`
40+
- Should show NO memories retrieved when MEMORY_ENABLED=false
41+
42+
## Proper Fix (TODO)
43+
44+
The real solution is to fix memory relevance scoring:
45+
46+
1. **Improve relevance matching**: Old memories about "testLynkr" should NOT match simple "ls" command
47+
2. **Add recency weighting**: Prefer recent context over old conversations
48+
3. **Filter irrelevant memories**: Don't inject generic help text into every request
49+
4. **Clear stale memories**: Option to purge old memories from database
50+
51+
### Files to modify for proper fix:
52+
- `src/memory/retriever.js` - `retrieveRelevantMemories()` function
53+
- `src/memory/search.js` - Relevance scoring algorithm
54+
- Add memory cleanup command/script
55+
56+
## Impact
57+
58+
With memory disabled:
59+
- ✅ "ls" returns file listing
60+
- ✅ "pwd" returns current directory
61+
- ✅ No stale context pollution
62+
- ✅ Correct tool calls (Bash instead of Read)
63+
- ❌ Loses legitimate long-term memory benefits
64+
65+
## Context Flow Logging
66+
67+
The CONTEXT_FLOW logging added in commit e55679b was essential for finding this issue.
68+
69+
Keeps logging in place for future debugging:
70+
- `[CONTEXT_FLOW]` - Tracks system prompt transformations
71+
- `[MEMORY_DEBUG]` - Shows memory injection details
72+
- `[SESSION_DEBUG]` - Monitors session reuse
73+
74+
## Timeline
75+
76+
- Jan 29 16:34 - User reported "ls" returning strange bd/beads workflow text
77+
- Jan 29 16:35 - Analyzed logs, found memory injection at fault
78+
- Jan 29 16:36 - Disabled memory as temporary fix
79+
- Next: Implement proper relevance scoring fix
80+
81+
---
82+
83+
# Update: Ollama System Prompt Issue Found (Root Cause)
84+
85+
## The REAL Problem
86+
87+
After disabling memory, user still got meta-commentary responses from llama3.2:
88+
```
89+
"It seems like you're ready to start a conversation! However, I want to clarify..."
90+
```
91+
92+
Investigation revealed the actual root cause: **System prompt embedded in user message content**.
93+
94+
## Evidence from Logs
95+
96+
```json
97+
{
98+
"systemPrompt": null,
99+
"userMessages": "[{\"role\":\"user\",\"content\":\"x-anthropic-billing-header:...You are Claude Code...ls\"}]"
100+
}
101+
```
102+
103+
The ~12KB system prompt (including SessionStart hook) was wrapped into the user message, so llama3.2 saw:
104+
```
105+
User: [6000 chars of system prompt] + [5000 chars of system reminders] + "ls"
106+
```
107+
108+
This caused llama3.2 to roleplay as "Claude Code" instead of executing commands.
109+
110+
## Fix Applied
111+
112+
### 1. src/orchestrator/index.js (lines 839-840)
113+
**Removed** Ollama-specific system flattening that was embedding system prompts into user messages.
114+
115+
**Before:**
116+
```javascript
117+
// Flatten system messages into the first user message
118+
const systemChunks = [];
119+
clean.messages = clean.messages.filter((msg) => {
120+
if (msg?.role === "system") {
121+
systemChunks.push(msg.content.trim());
122+
return false;
123+
}
124+
return true;
125+
});
126+
127+
if (systemChunks.length > 0 && clean.messages.length > 0) {
128+
const firstMsg = clean.messages[0];
129+
if (firstMsg.role === "user") {
130+
firstMsg.content = `${systemContent}\n\n${firstMsg.content}`;
131+
}
132+
}
133+
134+
delete clean.system;
135+
```
136+
137+
**After:**
138+
```javascript
139+
// Keep system prompt separate for Ollama (same as other providers)
140+
// Let invokeOllama() handle body.system properly
141+
```
142+
143+
### 2. src/clients/databricks.js - invokeOllama() (lines 267-293)
144+
**Added** proper system prompt handling as first message with `role: "system"`.
145+
146+
**Before:**
147+
```javascript
148+
const convertedMessages = (body.messages || []).map(msg => {
149+
// Convert messages...
150+
});
151+
```
152+
153+
**After:**
154+
```javascript
155+
const convertedMessages = [];
156+
157+
// Handle system prompt (same pattern as other providers)
158+
if (body.system && typeof body.system === "string" && body.system.trim().length > 0) {
159+
convertedMessages.push({
160+
role: "system",
161+
content: body.system.trim()
162+
});
163+
}
164+
165+
// Add user/assistant messages
166+
(body.messages || []).forEach(msg => {
167+
// Convert messages...
168+
});
169+
```
170+
171+
### 3. src/clients/databricks.js - invokeOllamaFallback() (lines 401-427)
172+
**Applied same change** as invokeOllama().
173+
174+
## Result
175+
176+
Now Ollama receives properly formatted messages:
177+
178+
```json
179+
{
180+
"messages": [
181+
{
182+
"role": "system",
183+
"content": "You are Claude Code, Anthropic's official CLI..."
184+
},
185+
{
186+
"role": "user",
187+
"content": "ls"
188+
}
189+
]
190+
}
191+
```
192+
193+
## Benefits
194+
195+
1. ✅ System prompt sent as separate message (not embedded in user content)
196+
2. ✅ Audit logs show proper `systemPrompt: "You are Claude Code..."` (not null)
197+
3. ✅ User message contains only user input ("ls")
198+
4. ✅ LLM understands its role and uses tools correctly
199+
5. ✅ Consistent with other providers (OpenRouter, Azure OpenAI, llama.cpp, LM Studio)
200+
6. ✅ SessionStart hook instructions properly respected as system context
201+
202+
## Alignment with Other Providers
203+
204+
This fix makes Ollama consistent with all other providers in the codebase:
205+
206+
- OpenRouter: `if (body.system) { messages.unshift({ role: "system", content: body.system }); }`
207+
- Azure OpenAI: `if (body.system) { messages.unshift({ role: "system", content: body.system }); }`
208+
- llama.cpp: `if (body.system) { messages.unshift({ role: "system", content: body.system }); }`
209+
- LM Studio: `if (body.system) { messages.unshift({ role: "system", content: body.system }); }`
210+
211+
## Testing Required
212+
213+
1. **Verify system prompt in logs:**
214+
```bash
215+
grep "systemPrompt" ~/Lynkr_original/Lynkr/logs/llm-audit.log | tail -5
216+
```
217+
Expected: `systemPrompt: "You are Claude Code..."` (not null)
218+
219+
2. **Verify command execution:**
220+
- Type "ls" → Should return file listing via Bash tool call
221+
- Type "pwd" → Should return current directory
222+
- NOT: "It seems like you're ready to start a conversation..."
223+
224+
3. **Verify message structure:**
225+
```bash
226+
cat logs/llm-audit-dictionary.jsonl | tail -1 | jq -r '.content[0]'
227+
```
228+
Expected: First message has `role: "system"`, second has `role: "user"` with just "ls"
229+
230+
## Next Steps
231+
232+
- [ ] Test with user's gpt-oss:20b model
233+
- [ ] Verify tool calls work correctly
234+
- [ ] Re-enable memory system after confirming fix works
235+
- [ ] Close related issues
236+
237+
## Commit Message
238+
239+
```
240+
Fix Ollama system prompt handling to send as separate message
241+
242+
Previously, system prompts were embedded into user message content,
243+
causing llama3.2 to see instructions as conversational context and
244+
roleplay instead of executing commands.
245+
246+
Now system prompts are sent as first message with role: "system",
247+
consistent with other providers (OpenRouter, Azure OpenAI, etc.).
248+
249+
Changes:
250+
- orchestrator: Remove Ollama-specific system flattening
251+
- databricks: Add body.system handling to invokeOllama()
252+
- databricks: Add body.system handling to invokeOllamaFallback()
253+
254+
Fixes: User typing "ls" got meta-commentary instead of file listing
255+
```

0 commit comments

Comments
 (0)