Log handler dispatch failures in the SDKs

dotnet/test/E2E/ToolsE2ETests.cs

@@ -5,6 +5,7 @@
 using GitHub.Copilot.Rpc;
 using GitHub.Copilot.Test.Harness;
 using Microsoft.Extensions.AI;
+using Microsoft.Extensions.Logging;
 using System.Collections.ObjectModel;
 using System.ComponentModel;
 using System.Text.Json;
@@ -156,6 +157,16 @@ public async Task Handles_Tool_Calling_Errors()
         // exception information as if it was the tool's output.
         Assert.DoesNotContain("Melbourne", answer?.Data.Content);
         Assert.Contains("unknown", answer?.Data.Content?.ToLowerInvariant());
+
+        // The failure must also be diagnosable from the host: the SDK swallows the
+        // exception on the wire (by design) but has to leave a trace in the log,
+        // including the stage so a handler that threw is distinguishable from one
+        // that never ran.
+        var failureLog = Assert.Single(LogEntries, e =>
+            e.Level == LogLevel.Error && e.Message.Contains("get_user_location", StringComparison.Ordinal));
+        Assert.Contains("Tool call failed", failureLog.Message, StringComparison.Ordinal);
+        Assert.Contains("Stage=InvokingHandler", failureLog.Message, StringComparison.Ordinal);
+        Assert.Equal("Melbourne", failureLog.Exception?.Message);
     }
 
     [Fact]

dotnet/test/Harness/E2ETestBase.cs

@@ -35,15 +35,33 @@ protected E2ETestBase(E2ETestFixture fixture, string snapshotCategory, ITestOutp
     /// <summary>Logger that forwards warnings and above to xunit test output.</summary>
     protected ILogger Logger { get; }
 
+    /// <summary>
+    /// Warning-and-above messages the SDK logged during this test, in order. Populated by
+    /// <see cref="Logger"/>, which is wired into every client created through <see cref="Ctx"/>.
+    /// </summary>
+    protected IReadOnlyList<LogEntry> LogEntries => ((XunitLogger)Logger).Entries;
+
+    /// <summary>A single captured log message.</summary>
+    protected sealed record LogEntry(LogLevel Level, string Message, Exception? Exception);
+
     /// <summary>Bridges <see cref="ILogger"/> to xunit's <see cref="ITestOutputHelper"/>.</summary>
     private sealed class XunitLogger(ITestOutputHelper output) : ILogger
     {
+        private readonly List<LogEntry> _entries = [];
+
+        public IReadOnlyList<LogEntry> Entries
+        {
+            get { lock (_entries) { return [.. _entries]; } }
+        }
+
         public IDisposable? BeginScope<TState>(TState state) where TState : notnull => null;
         public bool IsEnabled(LogLevel logLevel) => logLevel >= LogLevel.Warning;
         public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception? exception, Func<TState, Exception?, string> formatter)
         {
             if (!IsEnabled(logLevel)) return;
-            try { output.WriteLine($"[{logLevel}] {formatter(state, exception)}"); }
+            var message = formatter(state, exception);
+            lock (_entries) { _entries.Add(new LogEntry(logLevel, message, exception)); }
+            try { output.WriteLine($"[{logLevel}] {message}"); }
             catch (InvalidOperationException) { /* test already finished */ }
         }
     }

dotnet/test/Harness/E2ETestContext.cs

@@ -25,6 +25,7 @@ public sealed class E2ETestContext : IAsyncDisposable
 
     private readonly ReplayProxy _proxy;
     private readonly string _repoRoot;
+    private readonly ILogger _loggerForwarder;
     private readonly object _clientsLock = new();
     private readonly List<CopilotClient> _persistentClients = [];
     private readonly List<CopilotClient> _transientClients = [];
@@ -36,6 +37,25 @@ private E2ETestContext(string homeDir, string workDir, string proxyUrl, ReplayPr
         ProxyUrl = proxyUrl;
         _proxy = proxy;
         _repoRoot = repoRoot;
+        _loggerForwarder = new CurrentLoggerForwarder(this);
+    }
+
+    /// <summary>
+    /// Forwards log calls to whatever <see cref="Logger"/> is current at the time of the call.
+    /// A <see cref="CopilotClient"/> captures its logger at construction, and the shared
+    /// persistent client is constructed before any test assigns <see cref="Logger"/>; forwarding
+    /// lets its SDK-side warnings and errors still reach the test that is currently running.
+    /// </summary>
+    private sealed class CurrentLoggerForwarder(E2ETestContext context) : ILogger
+    {
+        public IDisposable? BeginScope<TState>(TState state) where TState : notnull
+            => context.Logger?.BeginScope(state);
+
+        public bool IsEnabled(LogLevel logLevel)
+            => context.Logger?.IsEnabled(logLevel) ?? false;
+
+        public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception? exception, Func<TState, Exception?, string> formatter)
+            => context.Logger?.Log(logLevel, eventId, state, exception, formatter);
     }
 
     public static async Task<E2ETestContext> CreateAsync()
@@ -276,7 +296,7 @@ public CopilotClient CreateClient(
     {
         options ??= new CopilotClientOptions();
 
-        options.Logger ??= Logger;
+        options.Logger ??= _loggerForwarder;
 
         // Resolve the working directory the worker should run in. Child-process and
         // URI transports take it as a per-client option; the in-process transport

go/client.go

@@ -970,6 +970,7 @@ func (c *Client) CreateSession(ctx context.Context, config *SessionConfig) (*Ses
 			c.client,
 			"",
 			hasManagedSettings(config.EnableManagedSettings, config.ManagedSettings),
+			c.options.LogLevel,
 		)
 
 		s.registerTools(config.Tools)
@@ -1327,6 +1328,7 @@ func (c *Client) ResumeSessionWithOptions(ctx context.Context, sessionID string,
 		c.client,
 		"",
 		hasManagedSettings(config.EnableManagedSettings, config.ManagedSettings),
+		c.options.LogLevel,
 	)
 
 	session.registerTools(config.Tools)

go/github_token_provider_test.go

@@ -208,7 +208,7 @@ func TestGitHubTokenProviderCleanupOnDisconnectError(t *testing.T) {
 	registrationID := client.registerGitHubTokenProvider(func(GitHubTokenProviderArgs) (*GitHubTokenProviderResult, error) {
 		return GitHubTokenCancelled(), nil
 	})
-	session := newSession("cleanup-session", rpcClient, "", false)
+	session := newSession("cleanup-session", rpcClient, "", false, "")
 	session.setGitHubTokenProviderRegistrationRelease(func() {
 		client.unregisterGitHubTokenProvider(registrationID)
 	})
@@ -252,7 +252,7 @@ func TestGitHubTokenProviderCleanupOnDelete(t *testing.T) {
 	registrationID := client.registerGitHubTokenProvider(func(GitHubTokenProviderArgs) (*GitHubTokenProviderResult, error) {
 		return GitHubTokenCancelled(), nil
 	})
-	session := newSession("delete-session", rpcClient, "", false)
+	session := newSession("delete-session", rpcClient, "", false, "")
 	session.setGitHubTokenProviderRegistrationRelease(func() {
 		client.unregisterGitHubTokenProvider(registrationID)
 	})