summaryrefslogtreecommitdiff
path: root/tests/Agent.Core.Tests/ObservabilityTests.cs
diff options
context:
space:
mode:
authortanaka takashi <isazaka@gmail.com>2026-08-10 00:07:27 +0900
committertanaka takashi <isazaka@gmail.com>2026-08-10 00:07:27 +0900
commite4a951d8b953c37b9078a48bce43cac6fd09edac (patch)
treeaa3e347cf88ce9cc888c9169c81eed7c94853129 /tests/Agent.Core.Tests/ObservabilityTests.cs
parentaee93a9e71bb38e0f48fa067b47d1baa9a69e9e3 (diff)
fix(http): decouple request processing from log I/O
HTTP observability callbacks previously called RollingFileLog synchronously. RollingFileLog writes to Console.Error before the application file, so a paused console or an undrained redirected stderr pipe could block Kestrel request threads for minutes and cause otherwise valid MCP clients to time out. Route ready, connection, request-started, request-completed, and HTTP JSONL work through a bounded 4,096-entry Channel. Request callbacks use TryWrite and never wait for console or file I/O. A dedicated single-reader background task preserves log ordering, performs rotation, reports dropped entries after queue pressure, and contains non-fatal sink failures. Keep the queue bounded so a stalled console cannot cause unbounded memory growth. When capacity is exhausted, request availability takes precedence over observability and the dropped count is emitted as an application warning after the writer resumes. Add a regression test with a deliberately blocked console writer. The background writer remains blocked while the HTTP completion callback returns within 250 ms. Release build passed with zero warnings and errors; Core tests passed 48/48 with skip 0. Regenerate the win-x64 self-contained 1.0.0 Bundle and ZIP. ZIP SHA-256: 62E28C903880A51614EC0C3CE23409580F803C7C124764CA7E1CB0EB2CCAA7A9.
Diffstat (limited to 'tests/Agent.Core.Tests/ObservabilityTests.cs')
-rw-r--r--tests/Agent.Core.Tests/ObservabilityTests.cs52
1 files changed, 52 insertions, 0 deletions
diff --git a/tests/Agent.Core.Tests/ObservabilityTests.cs b/tests/Agent.Core.Tests/ObservabilityTests.cs
index cd86bc2..c259eb0 100644
--- a/tests/Agent.Core.Tests/ObservabilityTests.cs
+++ b/tests/Agent.Core.Tests/ObservabilityTests.cs
@@ -1,6 +1,8 @@
using Agent.App.Logging;
using Agent.Core.Localization;
using Agent.Mcp;
+using System.Diagnostics;
+using System.Text;
namespace Agent.Core.Tests;
@@ -43,4 +45,54 @@ public sealed class ObservabilityTests
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);
+ }
+ }
}