1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
|
using Agent.App.Logging;
using Agent.Core.Localization;
using Agent.Core.Ollama;
using Agent.Core.Runtime;
using Agent.Core.Tools;
using Agent.Mcp;
using System.Diagnostics;
using System.Text;
using System.Text.Json;
namespace Agent.Core.Tests;
public sealed class ObservabilityTests
{
[Fact]
public void Llm_log_carries_correlation_usage_and_tool_iteration_fields()
{
using var directory = new TestDirectory();
Guid sessionId = Guid.NewGuid();
Guid taskId = Guid.NewGuid();
Guid plannerTaskId = Guid.NewGuid();
Guid callId = Guid.NewGuid();
var context = new AgentLlmCallContext(callId, sessionId, taskId, plannerTaskId, "replan", 7, 2, "model-a");
using (var observer = new JsonLinesRuntimeObserver(directory.Path, 1024 * 1024, 2))
{
observer.LlmRequest(context, [new OllamaMessage("user", "request")]);
observer.LlmResponse(context, new OllamaResult("response", 11, 13));
observer.ToolResult(context, "file_read", new ToolExecutionResult(true, "ok", false));
observer.LlmFailure(context, "planning_failed", "invalid plan");
}
JsonElement[] entries = File.ReadLines(Path.Combine(directory.Path, "llm.jsonl"))
.Select(static line => JsonDocument.Parse(line).RootElement.Clone()).ToArray();
Assert.Equal(4, entries.Length);
Assert.All(entries, entry =>
{
Assert.Equal(callId, entry.GetProperty("call_id").GetGuid());
Assert.Equal(taskId, entry.GetProperty("task_id").GetGuid());
Assert.Equal(sessionId, entry.GetProperty("session_id").GetGuid());
Assert.Equal(plannerTaskId, entry.GetProperty("planner_task_id").GetGuid());
Assert.Equal(7, entry.GetProperty("iteration").GetInt32());
Assert.Equal(2, entry.GetProperty("replan").GetInt32());
});
Assert.Equal(11, entries[1].GetProperty("input_tokens").GetInt64());
Assert.Equal("file_read", entries[2].GetProperty("tool_name").GetString());
Assert.Equal("llm.failure", entries[3].GetProperty("event_name").GetString());
Assert.Equal("planning_failed", entries[3].GetProperty("error_code").GetString());
}
[Fact]
public void Read_agent_log_script_exposes_read_only_filters()
{
DirectoryInfo? root = new(AppContext.BaseDirectory);
while (root is not null && !File.Exists(Path.Combine(root.FullName, "scripts", "Read-AgentLog.ps1"))) root = root.Parent;
Assert.NotNull(root);
string scriptPath = Path.Combine(root!.FullName, "scripts", "Read-AgentLog.ps1");
string script = File.ReadAllText(scriptPath);
Assert.Contains("[string]$TaskId", script, StringComparison.Ordinal);
Assert.Contains("[string]$SessionId", script, StringComparison.Ordinal);
Assert.Contains("[string]$Event", script, StringComparison.Ordinal);
Assert.Contains("[string]$CallId", script, StringComparison.Ordinal);
Assert.Contains("[int]$Tail", script, StringComparison.Ordinal);
Assert.DoesNotContain("Set-Content", script, StringComparison.OrdinalIgnoreCase);
Assert.DoesNotContain("Remove-Item", script, StringComparison.OrdinalIgnoreCase);
}
[Fact]
public void Ready_is_always_visible_even_when_log_threshold_is_fatal()
{
using var directory = new TestDirectory();
LocaleCatalog locale = LocaleCatalog.Load(Path.GetFullPath("config/locales"), "en");
using (var application = new RollingFileLog(directory.Path, 1024 * 1024, 2, "fatal"))
using (var observer = new McpHostLogObserver(application, locale, directory.Path, false, 1024 * 1024, 2))
observer.Ready(new McpReadyInfo("http", "http://127.0.0.1:8080/mcp", 42, "2026-07-28", true, true));
Assert.Contains("Agent is ready", File.ReadAllText(Path.Combine(directory.Path, "application.log")), StringComparison.Ordinal);
}
[Fact]
public void Ready_and_http_request_are_logged_without_sensitive_payloads()
{
using var directory = new TestDirectory();
LocaleCatalog locale = LocaleCatalog.Load(Path.GetFullPath("config/locales"), "en");
using (var application = new RollingFileLog(directory.Path, 1024 * 1024, 2))
{
using var observer = new McpHostLogObserver(application, locale, directory.Path, true, 1024 * 1024, 2);
observer.Ready(new McpReadyInfo("http", "http://127.0.0.1:8080/mcp", 42, "2026-07-28", true, true));
observer.HttpRequestStarted(new McpHttpRequestStartInfo("connection", "trace", "127.0.0.1", 50123, "POST", "/mcp"));
observer.HttpRequest(new McpHttpRequestInfo(DateTimeOffset.UtcNow, "connection", "trace", "127.0.0.1", 50123,
"127.0.0.1", 8080, "POST", "/mcp", 200, 12.5, "application/json", 100, "test-client",
"2026-07-28", "tools/list", "agent_run"));
}
string applicationText = File.ReadAllText(Path.Combine(directory.Path, "application.log"));
Assert.Contains("Agent is ready", applicationText, StringComparison.Ordinal);
Assert.Contains("remote=127.0.0.1:50123", applicationText, StringComparison.Ordinal);
string httpText = File.ReadAllText(Path.Combine(directory.Path, "http.jsonl"));
Assert.Contains("\"method\":\"POST\"", httpText, StringComparison.Ordinal);
Assert.Contains("\"remote_ip\":\"127.0.0.1\"", httpText, StringComparison.Ordinal);
Assert.DoesNotContain("Authorization", httpText, StringComparison.OrdinalIgnoreCase);
Assert.DoesNotContain("Cookie", httpText, StringComparison.OrdinalIgnoreCase);
Assert.DoesNotContain("prompt", httpText, StringComparison.OrdinalIgnoreCase);
}
[Fact]
public void Http_request_callbacks_do_not_wait_for_a_blocked_console_writer()
{
using var directory = new TestDirectory();
using var console = new BlockingTextWriter();
LocaleCatalog locale = LocaleCatalog.Load(Path.GetFullPath("config/locales"), "en");
using var application = new RollingFileLog(directory.Path, 1024 * 1024, 2, consoleWriter: console);
using var observer = new McpHostLogObserver(application, locale, directory.Path, true, 1024 * 1024, 2);
observer.HttpRequestStarted(new McpHttpRequestStartInfo("connection", "trace-1", "127.0.0.1", 50123, "POST", "/mcp"));
Assert.True(console.WaitUntilBlocked(TimeSpan.FromSeconds(5)), "Background writer did not reach the blocking console.");
var stopwatch = Stopwatch.StartNew();
observer.HttpRequest(new McpHttpRequestInfo(DateTimeOffset.UtcNow, "connection", "trace-2", "127.0.0.1", 50124,
"127.0.0.1", 8080, "POST", "/mcp", 200, 12.5, "application/json", 100, "test-client",
"2026-07-28", "tools/list", null));
stopwatch.Stop();
Assert.True(stopwatch.Elapsed < TimeSpan.FromMilliseconds(250), $"HTTP callback blocked for {stopwatch.Elapsed}.");
console.Release();
}
private sealed class BlockingTextWriter : TextWriter
{
private readonly ManualResetEventSlim _entered = new(false);
private readonly ManualResetEventSlim _release = new(false);
public override Encoding Encoding => Encoding.UTF8;
public override void WriteLine(string? value)
{
_entered.Set();
_release.Wait(TimeSpan.FromSeconds(30));
}
public bool WaitUntilBlocked(TimeSpan timeout) => _entered.Wait(timeout);
public void Release() => _release.Set();
protected override void Dispose(bool disposing)
{
if (disposing)
{
_release.Set();
_entered.Dispose();
_release.Dispose();
}
base.Dispose(disposing);
}
}
}
|
