From 1bc2a58ac8eb328283772dc1bff3fc983746ff35 Mon Sep 17 00:00:00 2001 From: "copilot-swe-agent[bot]" <198982749+Copilot@users.noreply.github.com> Date: Wed, 8 Jul 2026 16:30:35 +0000 Subject: [PATCH 1/4] Initial plan From 566bf117fd9fd61b05b56be4567cf134854b355c Mon Sep 17 00:00:00 2001 From: "copilot-swe-agent[bot]" <198982749+Copilot@users.noreply.github.com> Date: Wed, 8 Jul 2026 16:38:59 +0000 Subject: [PATCH 2/4] feat: add UTC timestamps to console log entries --- src/Cli.Tests/CustomLoggerTests.cs | 4 ++-- src/Cli/CustomLoggerProvider.cs | 6 ++++-- src/Service/Program.cs | 16 +++++++++++++++- 3 files changed, 21 insertions(+), 5 deletions(-) diff --git a/src/Cli.Tests/CustomLoggerTests.cs b/src/Cli.Tests/CustomLoggerTests.cs index cce73f0f75..c02e218f0a 100644 --- a/src/Cli.Tests/CustomLoggerTests.cs +++ b/src/Cli.Tests/CustomLoggerTests.cs @@ -77,8 +77,8 @@ public void LogOutput_UsesAbbreviatedLogLevelLabels(LogLevel logLevel, string ex string actual = expectStderr ? stderr : stdout; string other = expectStderr ? stdout : stderr; - Assert.IsTrue(actual.StartsWith(expectedPrefix), - $"Expected output to start with '{expectedPrefix}' but got: '{actual}'"); + Assert.IsTrue(actual.Contains(expectedPrefix), + $"Expected output to contain '{expectedPrefix}' but got: '{actual}'"); StringAssert.Contains(actual, Message); Assert.AreEqual(string.Empty, other, $"Did not expect output on the other stream but got: '{other}'"); diff --git a/src/Cli/CustomLoggerProvider.cs b/src/Cli/CustomLoggerProvider.cs index a4625b0924..c5af88c7fc 100644 --- a/src/Cli/CustomLoggerProvider.cs +++ b/src/Cli/CustomLoggerProvider.cs @@ -124,13 +124,14 @@ public void Log(LogLevel logLevel, EventId eventId, TState state, Except // Apply colors so the abbreviation matches the visual style of engine logs. // try/finally guarantees the original colors are restored even if Write throws, // otherwise the console would be left tinted (e.g. red on error) for subsequent output. + string mcpTimestamp = DateTime.UtcNow.ToString("yyyy-MM-dd'T'HH:mm:ss.fff'Z'"); ConsoleColor mcpOriginalForeGroundColor = Console.ForegroundColor; ConsoleColor mcpOriginalBackGroundColor = Console.BackgroundColor; try { Console.ForegroundColor = _logLevelToForeGroundConsoleColorMap.GetValueOrDefault(logLevel, ConsoleColor.White); Console.BackgroundColor = _logLevelToBackGroundConsoleColorMap.GetValueOrDefault(logLevel, ConsoleColor.Black); - Console.Error.Write($"{mcpAbbreviation}:"); + Console.Error.Write($"{mcpTimestamp} {mcpAbbreviation}:"); } finally { @@ -153,6 +154,7 @@ public void Log(LogLevel logLevel, EventId eventId, TState state, Except } TextWriter writer = logLevel >= LogLevel.Error ? Console.Error : Console.Out; + string timestamp = DateTime.UtcNow.ToString("yyyy-MM-dd'T'HH:mm:ss.fff'Z'"); // try/finally guarantees the original colors are restored even if Write throws, // otherwise the console would be left tinted (e.g. red on error) for subsequent output. ConsoleColor originalForeGroundColor = Console.ForegroundColor; @@ -161,7 +163,7 @@ public void Log(LogLevel logLevel, EventId eventId, TState state, Except { Console.ForegroundColor = _logLevelToForeGroundConsoleColorMap.GetValueOrDefault(logLevel, ConsoleColor.White); Console.BackgroundColor = _logLevelToBackGroundConsoleColorMap.GetValueOrDefault(logLevel, ConsoleColor.Black); - writer.Write($"{abbreviation}:"); + writer.Write($"{timestamp} {abbreviation}:"); } finally { diff --git a/src/Service/Program.cs b/src/Service/Program.cs index 76af52ba97..924ca81c4e 100644 --- a/src/Service/Program.cs +++ b/src/Service/Program.cs @@ -194,6 +194,11 @@ public static IHostBuilder CreateHostBuilder(string[] args, bool runMcpStdio, st else { logging.SetMinimumLevel(LogLevelProvider.CurrentLogLevel); + logging.AddSimpleConsole(options => + { + options.TimestampFormat = "yyyy-MM-dd'T'HH:mm:ss.fff'Z' "; + options.UseUtcTimestamp = true; + }); } // Add filter for dynamic log level changes (e.g., via MCP logging/setLevel) @@ -464,6 +469,11 @@ public static ILoggerFactory GetLoggerFactoryForLogLevel( // When LogLevel.None, skip the console logger entirely for true silence. if (LogLevelProvider.CurrentLogLevel != LogLevel.None) { + builder.AddSimpleConsole(options => + { + options.TimestampFormat = "yyyy-MM-dd'T'HH:mm:ss.fff'Z' "; + options.UseUtcTimestamp = true; + }); builder.AddConsole(options => { options.LogToStandardErrorThreshold = LogLevel.Trace; @@ -472,7 +482,11 @@ public static ILoggerFactory GetLoggerFactoryForLogLevel( } else { - builder.AddConsole(); + builder.AddSimpleConsole(options => + { + options.TimestampFormat = "yyyy-MM-dd'T'HH:mm:ss.fff'Z' "; + options.UseUtcTimestamp = true; + }); } }); } From 405f145ed2493bb791ff5e0b96d5726b62ec6371 Mon Sep 17 00:00:00 2001 From: "copilot-swe-agent[bot]" <198982749+Copilot@users.noreply.github.com> Date: Wed, 8 Jul 2026 16:41:53 +0000 Subject: [PATCH 3/4] refactor: extract timestamp constant and clarify stdio console config --- src/Cli/CustomLoggerProvider.cs | 6 ++++-- src/Service/Program.cs | 5 ++++- 2 files changed, 8 insertions(+), 3 deletions(-) diff --git a/src/Cli/CustomLoggerProvider.cs b/src/Cli/CustomLoggerProvider.cs index c5af88c7fc..89fbe8b8eb 100644 --- a/src/Cli/CustomLoggerProvider.cs +++ b/src/Cli/CustomLoggerProvider.cs @@ -25,6 +25,8 @@ public ILogger CreateLogger(string categoryName) public class CustomConsoleLogger : ILogger { + private const string UtcTimestampFormat = "yyyy-MM-dd'T'HH:mm:ss.fff'Z'"; + private readonly LogLevel _minimumLogLevel; // Minimum LogLevel for CLI output. @@ -124,7 +126,7 @@ public void Log(LogLevel logLevel, EventId eventId, TState state, Except // Apply colors so the abbreviation matches the visual style of engine logs. // try/finally guarantees the original colors are restored even if Write throws, // otherwise the console would be left tinted (e.g. red on error) for subsequent output. - string mcpTimestamp = DateTime.UtcNow.ToString("yyyy-MM-dd'T'HH:mm:ss.fff'Z'"); + string mcpTimestamp = DateTime.UtcNow.ToString(UtcTimestampFormat); ConsoleColor mcpOriginalForeGroundColor = Console.ForegroundColor; ConsoleColor mcpOriginalBackGroundColor = Console.BackgroundColor; try @@ -154,7 +156,7 @@ public void Log(LogLevel logLevel, EventId eventId, TState state, Except } TextWriter writer = logLevel >= LogLevel.Error ? Console.Error : Console.Out; - string timestamp = DateTime.UtcNow.ToString("yyyy-MM-dd'T'HH:mm:ss.fff'Z'"); + string timestamp = DateTime.UtcNow.ToString(UtcTimestampFormat); // try/finally guarantees the original colors are restored even if Write throws, // otherwise the console would be left tinted (e.g. red on error) for subsequent output. ConsoleColor originalForeGroundColor = Console.ForegroundColor; diff --git a/src/Service/Program.cs b/src/Service/Program.cs index 924ca81c4e..ddef5851a2 100644 --- a/src/Service/Program.cs +++ b/src/Service/Program.cs @@ -26,6 +26,7 @@ using Microsoft.Extensions.Hosting; using Microsoft.Extensions.Logging; using Microsoft.Extensions.Logging.ApplicationInsights; +using Microsoft.Extensions.Logging.Console; using OpenTelemetry.Exporter; using OpenTelemetry.Logs; using OpenTelemetry.Resources; @@ -474,7 +475,9 @@ public static ILoggerFactory GetLoggerFactoryForLogLevel( options.TimestampFormat = "yyyy-MM-dd'T'HH:mm:ss.fff'Z' "; options.UseUtcTimestamp = true; }); - builder.AddConsole(options => + // Route all levels to stderr to keep stdout clean for MCP JSON-RPC. + // Uses Services.Configure (not AddConsole) so no second provider is registered. + builder.Services.Configure(options => { options.LogToStandardErrorThreshold = LogLevel.Trace; }); From 54c882f09c31d0927151c5359bbda5542a51e33f Mon Sep 17 00:00:00 2001 From: "copilot-swe-agent[bot]" <198982749+Copilot@users.noreply.github.com> Date: Mon, 13 Jul 2026 16:09:28 +0000 Subject: [PATCH 4/4] fix: address timestamp logging review feedback --- src/Cli.Tests/CustomLoggerTests.cs | 7 +++++-- src/Cli/CustomLoggerProvider.cs | 7 ++++--- src/Service/Program.cs | 2 +- 3 files changed, 10 insertions(+), 6 deletions(-) diff --git a/src/Cli.Tests/CustomLoggerTests.cs b/src/Cli.Tests/CustomLoggerTests.cs index c02e218f0a..7d66839e58 100644 --- a/src/Cli.Tests/CustomLoggerTests.cs +++ b/src/Cli.Tests/CustomLoggerTests.cs @@ -1,6 +1,8 @@ // Copyright (c) Microsoft Corporation. // Licensed under the MIT License. +using System.Text.RegularExpressions; + namespace Cli.Tests; /// @@ -77,8 +79,9 @@ public void LogOutput_UsesAbbreviatedLogLevelLabels(LogLevel logLevel, string ex string actual = expectStderr ? stderr : stdout; string other = expectStderr ? stdout : stderr; - Assert.IsTrue(actual.Contains(expectedPrefix), - $"Expected output to contain '{expectedPrefix}' but got: '{actual}'"); + Assert.IsTrue( + Regex.IsMatch(actual, $@"^\d{{4}}-\d{{2}}-\d{{2}}T\d{{2}}:\d{{2}}:\d{{2}}\.\d{{3}}Z {Regex.Escape(expectedPrefix)}"), + $"Expected output to start with an ISO 8601 UTC timestamp followed by '{expectedPrefix}' but got: '{actual}'"); StringAssert.Contains(actual, Message); Assert.AreEqual(string.Empty, other, $"Did not expect output on the other stream but got: '{other}'"); diff --git a/src/Cli/CustomLoggerProvider.cs b/src/Cli/CustomLoggerProvider.cs index 89fbe8b8eb..532cd74f2c 100644 --- a/src/Cli/CustomLoggerProvider.cs +++ b/src/Cli/CustomLoggerProvider.cs @@ -1,6 +1,7 @@ // Copyright (c) Microsoft Corporation. // Licensed under the MIT License. +using System.Globalization; using Microsoft.Extensions.Logging; /// @@ -25,7 +26,7 @@ public ILogger CreateLogger(string categoryName) public class CustomConsoleLogger : ILogger { - private const string UtcTimestampFormat = "yyyy-MM-dd'T'HH:mm:ss.fff'Z'"; + private const string UTC_TIMESTAMP_FORMAT = "yyyy-MM-dd'T'HH:mm:ss.fff'Z'"; private readonly LogLevel _minimumLogLevel; @@ -126,7 +127,7 @@ public void Log(LogLevel logLevel, EventId eventId, TState state, Except // Apply colors so the abbreviation matches the visual style of engine logs. // try/finally guarantees the original colors are restored even if Write throws, // otherwise the console would be left tinted (e.g. red on error) for subsequent output. - string mcpTimestamp = DateTime.UtcNow.ToString(UtcTimestampFormat); + string mcpTimestamp = DateTime.UtcNow.ToString(UTC_TIMESTAMP_FORMAT, CultureInfo.InvariantCulture); ConsoleColor mcpOriginalForeGroundColor = Console.ForegroundColor; ConsoleColor mcpOriginalBackGroundColor = Console.BackgroundColor; try @@ -156,7 +157,7 @@ public void Log(LogLevel logLevel, EventId eventId, TState state, Except } TextWriter writer = logLevel >= LogLevel.Error ? Console.Error : Console.Out; - string timestamp = DateTime.UtcNow.ToString(UtcTimestampFormat); + string timestamp = DateTime.UtcNow.ToString(UTC_TIMESTAMP_FORMAT, CultureInfo.InvariantCulture); // try/finally guarantees the original colors are restored even if Write throws, // otherwise the console would be left tinted (e.g. red on error) for subsequent output. ConsoleColor originalForeGroundColor = Console.ForegroundColor; diff --git a/src/Service/Program.cs b/src/Service/Program.cs index ddef5851a2..ca7186698d 100644 --- a/src/Service/Program.cs +++ b/src/Service/Program.cs @@ -195,7 +195,7 @@ public static IHostBuilder CreateHostBuilder(string[] args, bool runMcpStdio, st else { logging.SetMinimumLevel(LogLevelProvider.CurrentLogLevel); - logging.AddSimpleConsole(options => + logging.Services.Configure(options => { options.TimestampFormat = "yyyy-MM-dd'T'HH:mm:ss.fff'Z' "; options.UseUtcTimestamp = true;