From 4c1c09f0c0fc4c2f41c965380f60d7833524f7aa Mon Sep 17 00:00:00 2001 From: James Newton-King Date: Sun, 25 Aug 2024 14:58:37 +0800 Subject: [PATCH 1/3] Fix dashboard log parsing in host --- src/Aspire.Hosting/Aspire.Hosting.csproj | 1 + .../Dashboard/DashboardLifecycleHook.cs | 9 +- src/Shared/ConsoleLogs/TimestampParser.cs | 79 ++++++++++ .../Dashboard/DashboardLifecycleHookTests.cs | 143 ++++++++++++++++++ 4 files changed, 231 insertions(+), 1 deletion(-) create mode 100644 src/Shared/ConsoleLogs/TimestampParser.cs create mode 100644 tests/Aspire.Hosting.Tests/Dashboard/DashboardLifecycleHookTests.cs diff --git a/src/Aspire.Hosting/Aspire.Hosting.csproj b/src/Aspire.Hosting/Aspire.Hosting.csproj index 8208c241d15..2e0a6af4da3 100644 --- a/src/Aspire.Hosting/Aspire.Hosting.csproj +++ b/src/Aspire.Hosting/Aspire.Hosting.csproj @@ -37,6 +37,7 @@ + diff --git a/src/Aspire.Hosting/Dashboard/DashboardLifecycleHook.cs b/src/Aspire.Hosting/Dashboard/DashboardLifecycleHook.cs index 3eb1d8f20ca..e1cde4ff49f 100644 --- a/src/Aspire.Hosting/Dashboard/DashboardLifecycleHook.cs +++ b/src/Aspire.Hosting/Dashboard/DashboardLifecycleHook.cs @@ -6,6 +6,7 @@ using System.Text.Json; using System.Text.Json.Nodes; using System.Text.Json.Serialization; +using Aspire.Dashboard.ConsoleLogs; using Aspire.Dashboard.Model; using Aspire.Hosting.ApplicationModel; using Aspire.Hosting.Dcp; @@ -300,7 +301,13 @@ private static async Task WatchResourceLogsAsync(string dashboardResourceId, try { - logMessage = JsonSerializer.Deserialize(logLine.Content, DashboardLogMessageContext.Default.DashboardLogMessage); + var content = logLine.Content; + if (TimestampParser.TryParseConsoleTimestamp(content, out var result)) + { + content = result.Value.ModifiedText; + } + + logMessage = JsonSerializer.Deserialize(content, DashboardLogMessageContext.Default.DashboardLogMessage); } catch (JsonException) { diff --git a/src/Shared/ConsoleLogs/TimestampParser.cs b/src/Shared/ConsoleLogs/TimestampParser.cs new file mode 100644 index 00000000000..36cc412dbb4 --- /dev/null +++ b/src/Shared/ConsoleLogs/TimestampParser.cs @@ -0,0 +1,79 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System.Diagnostics.CodeAnalysis; +using System.Globalization; +using System.Text.RegularExpressions; + +namespace Aspire.Dashboard.ConsoleLogs; + +internal static partial class TimestampParser +{ + private static readonly Regex s_rfc3339RegEx = GenerateRfc3339RegEx(); + + public static bool TryParseConsoleTimestamp(string text, [NotNullWhen(true)] out TimestampParserResult? result) + { + var match = s_rfc3339RegEx.Match(text); + + if (match.Success) + { + var span = text.AsSpan(); + var timestamp = span[match.Index..(match.Index + match.Length)]; + + ReadOnlySpan content; + if (match.Index + match.Length >= span.Length) + { + content = ""; + } + else + { + content = span[(match.Index + match.Length)..]; + + // Trim whitespace added by logging between timestamp and content. + if (char.IsWhiteSpace(content[0])) + { + content = content.Slice(1); + } + } + + result = new(content.ToString(), DateTimeOffset.Parse(timestamp.ToString(), CultureInfo.InvariantCulture)); + return true; + } + + result = default; + return false; + } + + // Regular Expression for an RFC3339 timestamp, including RFC3339Nano + // + // Example timestamps: + // 2023-10-02T12:56:35.123456789Z + // 2023-10-02T13:56:35.123456789+10:00 + // 2023-10-02T13:56:35.123456789-10:00 + // 2023-10-02T13:56:35.123456789Z10:00 + // 2023-10-02T13:56:35.123456Z + // 2023-10-02T13:56:35Z + // + // Explanation: + // ^ - Starts the string + // (?:\\d{4}) - Four digits for the year + // - - Separator for the date + // (?:0[1-9]|1[0-2]) - Two digits for the month, restricted to 01-12 + // - - Separator for the date + // (?:0[1-9]|[12][0-9]|3[01]) - Two digits for the day, restricted to 01-31 + // [T ] - Literal, separator between date and time, either a T or a space + // (?:[01][0-9]|2[0-3]) - Two digits for the hour, restricted to 00-23 + // : - Separator for the time + // (?:[0-5][0-9]) - Two digits for the minutes, restricted to 00-59 + // : - Separator for the time + // (?:[0-5][0-9]) - Two digits for the seconds, restricted to 00-59 + // (?:\\.\\d{1,9}) - A period and up to nine digits for the partial seconds + // Z - Literal, same as +00:00 + // (?:[Z+-](?:[01][0-9]|2[0-3]):(?:[0-5][0-9])) - Time Zone offset, in the form ZHH:MM or +HH:MM or -HH:MM + // + // Note: (?:) is a non-capturing group, since we don't care about the values, we are just interested in whether or not there is a match + [GeneratedRegex("^(?:\\d{4})-(?:0[1-9]|1[0-2])-(?:0[1-9]|[12][0-9]|3[01])T(?:[01][0-9]|2[0-3]):(?:[0-5][0-9]):(?:[0-5][0-9])(?:\\.\\d{1,9})?(?:Z|(?:[Z+-](?:[01][0-9]|2[0-3]):(?:[0-5][0-9])))?")] + private static partial Regex GenerateRfc3339RegEx(); + + public readonly record struct TimestampParserResult(string ModifiedText, DateTimeOffset Timestamp); +} diff --git a/tests/Aspire.Hosting.Tests/Dashboard/DashboardLifecycleHookTests.cs b/tests/Aspire.Hosting.Tests/Dashboard/DashboardLifecycleHookTests.cs new file mode 100644 index 00000000000..6b002e36d38 --- /dev/null +++ b/tests/Aspire.Hosting.Tests/Dashboard/DashboardLifecycleHookTests.cs @@ -0,0 +1,143 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System.Globalization; +using System.Text.Json; +using System.Threading.Channels; +using Aspire.Hosting.Dashboard; +using Aspire.Hosting.Dcp; +using Microsoft.Extensions.Configuration; +using Microsoft.Extensions.Hosting; +using Microsoft.Extensions.Logging; +using Microsoft.Extensions.Logging.Abstractions; +using Microsoft.Extensions.Logging.Testing; +using Microsoft.Extensions.Options; +using Xunit; + +namespace Aspire.Hosting.Tests.Dashboard; + +public class DashboardLifecycleHookTests +{ + [Theory] + [MemberData(nameof(Data))] + public async Task WatchDashboardLogs_WrittenToHostLoggerFactory(string logMessage, string expectedMessage, string expectedCategory, LogLevel expectedLevel) + { + // Arrange + var testSink = new TestSink(); + var factory = LoggerFactory.Create(b => + { + b.SetMinimumLevel(LogLevel.Trace); + b.AddProvider(new TestLoggerProvider(testSink)); + }); + var logChannel = Channel.CreateUnbounded(); + testSink.MessageLogged += c => logChannel.Writer.TryWrite(c); + + var resourceLoggerService = new ResourceLoggerService(); + var resourceNotificationService = new ResourceNotificationService(NullLogger.Instance, new TestHostApplicationLifetime()); + var configuration = new ConfigurationBuilder().Build(); + var hook = new DashboardLifecycleHook( + configuration, + Options.Create(new DashboardOptions { DashboardPath = "test.dll" }), + NullLogger.Instance, + new TestDashboardEndpointProvider(), + new DistributedApplicationExecutionContext(DistributedApplicationOperation.Run), + resourceNotificationService, + resourceLoggerService, + factory); + + var model = new DistributedApplicationModel(new ResourceCollection()); + await hook.BeforeStartAsync(model, CancellationToken.None); + + await resourceNotificationService.PublishUpdateAsync(model.Resources.Single(), s => s); + + await foreach (var item in resourceLoggerService.WatchAnySubscribersAsync()) + { + if (item.Name == KnownResourceNames.AspireDashboard && item.AnySubscribers) + { + break; + } + } + + // Act + var dashboardLogger = resourceLoggerService.GetLogger(KnownResourceNames.AspireDashboard); + dashboardLogger.LogError(logMessage); + + // Assert + var logContext = await logChannel.Reader.ReadAsync(); + Assert.Equal(expectedCategory, logContext.LoggerName); + Assert.Equal(expectedMessage, logContext.Message); + Assert.Equal(expectedLevel, logContext.LogLevel); + } + + public static IEnumerable Data() + { + var timestamp = new DateTime(2001, 12, 29, 23, 59, 59, DateTimeKind.Utc); + var message = new DashboardLogMessage + { + LogLevel = LogLevel.Error, + Category = "TestCategory", + Message = "Hello world", + Timestamp = timestamp.ToString(KnownFormats.ConsoleLogsTimestampFormat, CultureInfo.InvariantCulture), + }; + var messageJson = JsonSerializer.Serialize(message, DashboardLogMessageContext.Default.DashboardLogMessage); + + yield return new object[] + { + $"{DateTime.UtcNow.ToString(KnownFormats.ConsoleLogsTimestampFormat, CultureInfo.InvariantCulture)} {messageJson}", + "Hello world", + "Aspire.Hosting.Dashboard.TestCategory", + LogLevel.Error + }; + yield return new object[] + { + $"{DateTime.UtcNow.ToString(KnownFormats.ConsoleLogsTimestampFormat, CultureInfo.InvariantCulture)}{messageJson}", + "Hello world", + "Aspire.Hosting.Dashboard.TestCategory", + LogLevel.Error + }; + yield return new object[] + { + messageJson, + "Hello world", + "Aspire.Hosting.Dashboard.TestCategory", + LogLevel.Error + }; + + message = new DashboardLogMessage + { + LogLevel = LogLevel.Critical, + Category = "TestCategory.TestSubCategory", + Message = "Error message", + Exception = new InvalidOperationException("Error!").ToString(), + Timestamp = timestamp.ToString(KnownFormats.ConsoleLogsTimestampFormat, CultureInfo.InvariantCulture), + }; + messageJson = JsonSerializer.Serialize(message, DashboardLogMessageContext.Default.DashboardLogMessage); + + yield return new object[] + { + messageJson, + "Error message\r\nSystem.InvalidOperationException: Error!", + "Aspire.Hosting.Dashboard.TestCategory.TestSubCategory", + LogLevel.Critical + }; + } + + private sealed class TestDashboardEndpointProvider : IDashboardEndpointProvider + { + public Task GetResourceServiceUriAsync(CancellationToken cancellationToken = default) + { + throw new NotImplementedException(); + } + } + + private sealed class TestHostApplicationLifetime : IHostApplicationLifetime + { + public CancellationToken ApplicationStarted { get; } + public CancellationToken ApplicationStopped { get; } + public CancellationToken ApplicationStopping { get; } + + public void StopApplication() + { + } + } +} From d35a1c4e67bc43195350aa6131c5d8b2a91eac99 Mon Sep 17 00:00:00 2001 From: James Newton-King Date: Sun, 25 Aug 2024 15:25:42 +0800 Subject: [PATCH 2/3] Fix test --- .../Dashboard/DashboardLifecycleHookTests.cs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/tests/Aspire.Hosting.Tests/Dashboard/DashboardLifecycleHookTests.cs b/tests/Aspire.Hosting.Tests/Dashboard/DashboardLifecycleHookTests.cs index 6b002e36d38..440e662369d 100644 --- a/tests/Aspire.Hosting.Tests/Dashboard/DashboardLifecycleHookTests.cs +++ b/tests/Aspire.Hosting.Tests/Dashboard/DashboardLifecycleHookTests.cs @@ -116,7 +116,7 @@ public static IEnumerable Data() yield return new object[] { messageJson, - "Error message\r\nSystem.InvalidOperationException: Error!", + $"Error message{Environment.NewLine}System.InvalidOperationException: Error!", "Aspire.Hosting.Dashboard.TestCategory.TestSubCategory", LogLevel.Critical }; From fef79ab7862cb4ce54830fe47ccb81b3f9d6875c Mon Sep 17 00:00:00 2001 From: James Newton-King Date: Mon, 26 Aug 2024 10:21:51 +0800 Subject: [PATCH 3/3] Update src/Aspire.Hosting/Aspire.Hosting.csproj --- src/Aspire.Hosting/Aspire.Hosting.csproj | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/Aspire.Hosting/Aspire.Hosting.csproj b/src/Aspire.Hosting/Aspire.Hosting.csproj index 2e0a6af4da3..db204a745a2 100644 --- a/src/Aspire.Hosting/Aspire.Hosting.csproj +++ b/src/Aspire.Hosting/Aspire.Hosting.csproj @@ -37,7 +37,7 @@ - +