diff --git a/src/Worker/Core/DurableTaskWorkerOptions.cs b/src/Worker/Core/DurableTaskWorkerOptions.cs index 703bbbd4..3aa4eea2 100644 --- a/src/Worker/Core/DurableTaskWorkerOptions.cs +++ b/src/Worker/Core/DurableTaskWorkerOptions.cs @@ -151,6 +151,20 @@ public DataConverter DataConverter [Obsolete("Experimental")] public IOrchestrationFilter? OrchestrationFilter { get; set; } + /// + /// Gets options for the Durable Task worker logging. + /// + /// + /// + /// Logging options control how logging categories are assigned to different components of the worker. + /// Starting from a future version, more specific logging categories will be used for better log filtering. + /// + /// To maintain backward compatibility, legacy logging categories are emitted by default alongside the new + /// categories. This can be disabled by setting to false. + /// + /// + public LoggingOptions Logging { get; } = new(); + /// /// Gets a value indicating whether was explicitly set or not. /// @@ -177,6 +191,7 @@ internal void ApplyTo(DurableTaskWorkerOptions other) other.EnableEntitySupport = this.EnableEntitySupport; other.Versioning = this.Versioning; other.OrchestrationFilter = this.OrchestrationFilter; + other.Logging.UseLegacyCategories = this.Logging.UseLegacyCategories; } } @@ -229,4 +244,46 @@ public class VersioningOptions /// public VersionFailureStrategy FailureStrategy { get; set; } = VersionFailureStrategy.Reject; } + + /// + /// Options for configuring Durable Task worker logging behavior. + /// + public class LoggingOptions + { + /// + /// Gets or sets a value indicating whether to emit logs using legacy logging categories in addition to new categories. + /// + /// + /// + /// Starting from a future version, more specific logging categories will be used for better log filtering: + /// + /// Microsoft.DurableTask.Worker.Grpc for gRPC worker logs (previously Microsoft.DurableTask) + /// Microsoft.DurableTask.Worker.* for worker-specific logs + /// + /// + /// + /// When true (default), logs are emitted to both the new specific categories (e.g., Microsoft.DurableTask.Worker.Grpc) + /// and the legacy broad categories (e.g., Microsoft.DurableTask). This ensures backward compatibility with existing + /// log filters and queries. + /// + /// + /// When false, logs are only emitted to the new specific categories, which provides better log organization + /// and filtering capabilities. + /// + /// + /// Migration Path: + /// + /// Update your log filters to use the new, more specific categories + /// Test your application to ensure logs are captured correctly + /// Once confident, set this property to false to disable legacy category emission + /// + /// + /// + /// Breaking Change Warning: Setting this to false is a breaking change if you have existing log filters, + /// queries, or monitoring rules that depend on the legacy category names. Ensure you update those before disabling + /// legacy categories. + /// + /// + public bool UseLegacyCategories { get; set; } = true; + } } diff --git a/src/Worker/Grpc/DualCategoryLogger.cs b/src/Worker/Grpc/DualCategoryLogger.cs new file mode 100644 index 00000000..14366ebd --- /dev/null +++ b/src/Worker/Grpc/DualCategoryLogger.cs @@ -0,0 +1,120 @@ +// Copyright (c) Microsoft Corporation. +// Licensed under the MIT License. + +using Microsoft.Extensions.Logging; + +namespace Microsoft.DurableTask.Worker.Grpc; + +/// +/// A logger wrapper that emits logs to both a primary (new) category and an optional legacy category. +/// +/// +/// This logger is used to maintain backward compatibility while transitioning to more specific logging categories. +/// When legacy categories are enabled, log messages are written to both the new specific category +/// (e.g., "Microsoft.DurableTask.Worker.Grpc") and the legacy broad category (e.g., "Microsoft.DurableTask"). +/// +sealed class DualCategoryLogger : ILogger +{ + readonly ILogger primaryLogger; + readonly ILogger? legacyLogger; + + /// + /// Initializes a new instance of the class. + /// + /// The primary logger with the new category. + /// The optional legacy logger with the old category. + public DualCategoryLogger(ILogger primaryLogger, ILogger? legacyLogger) + { + this.primaryLogger = Check.NotNull(primaryLogger); + this.legacyLogger = legacyLogger; + } + + /// + public IDisposable? BeginScope(TState state) + where TState : notnull + { + IDisposable? primaryScope = this.primaryLogger.BeginScope(state); + IDisposable? legacyScope = this.legacyLogger?.BeginScope(state); + + if (primaryScope is not null && legacyScope is not null) + { + return new CompositeDisposable(primaryScope, legacyScope); + } + + return primaryScope ?? legacyScope; + } + + /// + public bool IsEnabled(LogLevel logLevel) + { + // Return true if either logger is enabled at this level + return this.primaryLogger.IsEnabled(logLevel) || + (this.legacyLogger?.IsEnabled(logLevel) ?? false); + } + + /// + public void Log( + LogLevel logLevel, + EventId eventId, + TState state, + Exception? exception, + Func formatter) + { + // Log to primary logger + if (this.primaryLogger.IsEnabled(logLevel)) + { + this.primaryLogger.Log(logLevel, eventId, state, exception, formatter); + } + + // Log to legacy logger if enabled + if (this.legacyLogger?.IsEnabled(logLevel) ?? false) + { + this.legacyLogger.Log(logLevel, eventId, state, exception, formatter); + } + } + + sealed class CompositeDisposable : IDisposable + { + readonly IDisposable first; + readonly IDisposable second; + + public CompositeDisposable(IDisposable first, IDisposable second) + { + this.first = first; + this.second = second; + } + + public void Dispose() + { + Exception? firstException = null; + + try + { + this.first.Dispose(); + } + catch (Exception ex) + { + firstException = ex; + } + + try + { + this.second.Dispose(); + } + catch (Exception ex) + { + if (firstException is null) + { + throw; + } + + throw new AggregateException(firstException, ex); + } + + if (firstException is not null) + { + throw firstException; + } + } + } +} diff --git a/src/Worker/Grpc/GrpcDurableTaskWorker.cs b/src/Worker/Grpc/GrpcDurableTaskWorker.cs index da61d884..93875961 100644 --- a/src/Worker/Grpc/GrpcDurableTaskWorker.cs +++ b/src/Worker/Grpc/GrpcDurableTaskWorker.cs @@ -45,7 +45,7 @@ public GrpcDurableTaskWorker( this.workerOptions = Check.NotNull(workerOptions).Get(name); this.services = Check.NotNull(services); this.loggerFactory = Check.NotNull(loggerFactory); - this.logger = loggerFactory.CreateLogger("Microsoft.DurableTask"); // TODO: use better category name. + this.logger = CreateLogger(loggerFactory, this.workerOptions); this.orchestrationFilter = orchestrationFilter; this.ExceptionPropertiesProvider = exceptionPropertiesProvider; } @@ -103,4 +103,19 @@ AsyncDisposable GetCallInvoker(out CallInvoker callInvoker, out string address) address = c.Target; return new AsyncDisposable(() => new(c.ShutdownAsync())); } + + static ILogger CreateLogger(ILoggerFactory loggerFactory, DurableTaskWorkerOptions options) + { + // Use the new, more specific category name for gRPC worker logs + ILogger primaryLogger = loggerFactory.CreateLogger("Microsoft.DurableTask.Worker.Grpc"); + + // If legacy categories are enabled, also emit logs to the old broad category + if (options.Logging.UseLegacyCategories) + { + ILogger legacyLogger = loggerFactory.CreateLogger("Microsoft.DurableTask"); + return new DualCategoryLogger(primaryLogger, legacyLogger); + } + + return primaryLogger; + } } diff --git a/test/Grpc.IntegrationTests/IntegrationTestBase.cs b/test/Grpc.IntegrationTests/IntegrationTestBase.cs index 13d92a7a..ded82776 100644 --- a/test/Grpc.IntegrationTests/IntegrationTestBase.cs +++ b/test/Grpc.IntegrationTests/IntegrationTestBase.cs @@ -95,8 +95,11 @@ protected IHostBuilder CreateHostBuilder( protected IReadOnlyCollection GetLogs() { - // NOTE: Renaming the log category is a breaking change! - const string ExpectedCategoryName = "Microsoft.DurableTask"; + // Use the specific Worker.Grpc category to get gRPC worker logs. + // TryGetLogs uses StartsWith matching, so "Microsoft.DurableTask" would match both + // the legacy category AND "Microsoft.DurableTask.Worker.Grpc", causing duplicate entries + // when dual-category logging is enabled. + const string ExpectedCategoryName = "Microsoft.DurableTask.Worker.Grpc"; bool foundCategory = this.logProvider.TryGetLogs(ExpectedCategoryName, out IReadOnlyCollection logs); Assert.True(foundCategory); return logs; diff --git a/test/Worker/Grpc.Tests/LoggingCategoryTests.cs b/test/Worker/Grpc.Tests/LoggingCategoryTests.cs new file mode 100644 index 00000000..0dd5b347 --- /dev/null +++ b/test/Worker/Grpc.Tests/LoggingCategoryTests.cs @@ -0,0 +1,256 @@ +// Copyright (c) Microsoft Corporation. +// Licensed under the MIT License. + +using FluentAssertions; +using Microsoft.DurableTask.Tests.Logging; +using Microsoft.DurableTask.Worker; +using Microsoft.DurableTask.Worker.Grpc; +using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.Logging; +using Microsoft.Extensions.Options; +using Moq; +using Xunit; +using Xunit.Abstractions; + +namespace Microsoft.DurableTask.Worker.Grpc.Tests; + +/// +/// Tests for logging category functionality, including dual-category emission for backward compatibility. +/// +public class LoggingCategoryTests +{ + const string NewGrpcCategory = "Microsoft.DurableTask.Worker.Grpc"; + const string LegacyCategory = "Microsoft.DurableTask"; + + [Fact] + public void Worker_UsesLegacyCategories_ByDefault() + { + // Arrange & Act + var workerOptions = new DurableTaskWorkerOptions(); + + // Assert + workerOptions.Logging.UseLegacyCategories.Should().BeTrue("backward compatibility should be enabled by default"); + } + + [Fact] + public void DualCategoryLogger_LogsToBothLoggers_WhenBothEnabled() + { + // Arrange + var primaryLogger = new Mock(); + var legacyLogger = new Mock(); + + primaryLogger.Setup(l => l.IsEnabled(It.IsAny())).Returns(true); + legacyLogger.Setup(l => l.IsEnabled(It.IsAny())).Returns(true); + + var dualLogger = new DualCategoryLogger(primaryLogger.Object, legacyLogger.Object); + + // Act + dualLogger.LogInformation("Test message"); + + // Assert - verify both loggers received the log call + primaryLogger.Verify( + l => l.Log( + LogLevel.Information, + It.IsAny(), + It.Is((v, t) => v.ToString()!.Contains("Test message")), + null, + It.IsAny>()), + Times.Once, + "primary logger should receive the log"); + + legacyLogger.Verify( + l => l.Log( + LogLevel.Information, + It.IsAny(), + It.Is((v, t) => v.ToString()!.Contains("Test message")), + null, + It.IsAny>()), + Times.Once, + "legacy logger should receive the log"); + } + + [Fact] + public void DualCategoryLogger_LogsToPrimaryOnly_WhenLegacyIsNull() + { + // Arrange + var logProvider = new TestLogProvider(new NullOutput()); + var loggerFactory = new SimpleLoggerFactory(logProvider); + + ILogger primaryLogger = loggerFactory.CreateLogger(NewGrpcCategory); + + var dualLogger = new DualCategoryLogger(primaryLogger, null); + + // Act + dualLogger.LogInformation("Test message"); + + // Assert + logProvider.TryGetLogs(NewGrpcCategory, out var newLogs).Should().BeTrue(); + newLogs.Should().ContainSingle(l => l.Message.Contains("Test message")); + } + + [Fact] + public void DualCategoryLogger_IsEnabled_ReturnsTrueIfEitherLoggerEnabled() + { + // Arrange + var primaryLogger = new Mock(); + var legacyLogger = new Mock(); + + primaryLogger.Setup(l => l.IsEnabled(LogLevel.Information)).Returns(true); + legacyLogger.Setup(l => l.IsEnabled(LogLevel.Information)).Returns(false); + + var dualLogger = new DualCategoryLogger(primaryLogger.Object, legacyLogger.Object); + + // Act + bool result = dualLogger.IsEnabled(LogLevel.Information); + + // Assert + result.Should().BeTrue("at least one logger is enabled"); + } + + [Fact] + public void DualCategoryLogger_IsEnabled_ReturnsFalseIfNeitherLoggerEnabled() + { + // Arrange + var primaryLogger = new Mock(); + var legacyLogger = new Mock(); + + primaryLogger.Setup(l => l.IsEnabled(LogLevel.Information)).Returns(false); + legacyLogger.Setup(l => l.IsEnabled(LogLevel.Information)).Returns(false); + + var dualLogger = new DualCategoryLogger(primaryLogger.Object, legacyLogger.Object); + + // Act + bool result = dualLogger.IsEnabled(LogLevel.Information); + + // Assert + result.Should().BeFalse("neither logger is enabled"); + } + + [Fact] + public void DualCategoryLogger_BeginScope_CreatesScopeInBothLoggers() + { + // Arrange + var primaryLogger = new Mock(); + var legacyLogger = new Mock(); + + var primaryDisposable = new Mock(); + var legacyDisposable = new Mock(); + + primaryLogger.Setup(l => l.BeginScope(It.IsAny())).Returns(primaryDisposable.Object); + legacyLogger.Setup(l => l.BeginScope(It.IsAny())).Returns(legacyDisposable.Object); + + var dualLogger = new DualCategoryLogger(primaryLogger.Object, legacyLogger.Object); + + // Act + using IDisposable? scope = dualLogger.BeginScope("test"); + + // Assert + primaryLogger.Verify(l => l.BeginScope("test"), Times.Once); + legacyLogger.Verify(l => l.BeginScope("test"), Times.Once); + + scope.Should().NotBeNull(); + } + + [Fact] + public void GrpcDurableTaskWorker_UsesDualCategoryLogger_WhenLegacyCategoriesEnabled() + { + // Arrange & Act + var worker = CreateWorkerWithLoggingOptions(useLegacyCategories: true); + var logger = GetWorkerLogger(worker); + + // Assert - verify the worker uses DualCategoryLogger when legacy categories are enabled + logger.Should().NotBeNull("worker should have a logger"); + logger.Should().BeOfType("worker should use DualCategoryLogger when UseLegacyCategories is true"); + } + + [Fact] + public void GrpcDurableTaskWorker_UsesRegularLogger_WhenLegacyCategoriesDisabled() + { + // Arrange & Act + var worker = CreateWorkerWithLoggingOptions(useLegacyCategories: false); + var logger = GetWorkerLogger(worker); + + // Assert - verify the worker uses a regular logger (not DualCategoryLogger) when legacy categories are disabled + logger.Should().NotBeNull("worker should have a logger"); + logger.Should().NotBeOfType("worker should not use DualCategoryLogger when UseLegacyCategories is false"); + } + + static GrpcDurableTaskWorker CreateWorkerWithLoggingOptions(bool useLegacyCategories) + { + var logProvider = new TestLogProvider(new NullOutput()); + var loggerFactory = new SimpleLoggerFactory(logProvider); + + var workerOptions = new DurableTaskWorkerOptions + { + Logging = { UseLegacyCategories = useLegacyCategories } + }; + + var grpcOptions = new GrpcDurableTaskWorkerOptions(); + var factoryMock = new Mock(MockBehavior.Strict); + var services = new ServiceCollection().BuildServiceProvider(); + + return new GrpcDurableTaskWorker( + name: "Test", + factory: factoryMock.Object, + grpcOptions: new OptionsMonitorStub(grpcOptions), + workerOptions: new OptionsMonitorStub(workerOptions), + services: services, + loggerFactory: loggerFactory, + orchestrationFilter: null, + exceptionPropertiesProvider: null); + } + + static object? GetWorkerLogger(GrpcDurableTaskWorker worker) + { + var loggerField = typeof(GrpcDurableTaskWorker).GetField("logger", System.Reflection.BindingFlags.NonPublic | System.Reflection.BindingFlags.Instance); + return loggerField?.GetValue(worker); + } + +} + +sealed class OptionsMonitorStub : IOptionsMonitor +{ + readonly T value; + + public OptionsMonitorStub(T value) + { + this.value = value; + } + + public T CurrentValue => this.value; + + public T Get(string? name) => this.value; + + public IDisposable OnChange(Action listener) => NullDisposable.Instance; + + sealed class NullDisposable : IDisposable + { + public static readonly NullDisposable Instance = new(); + public void Dispose() { } + } +} + +sealed class NullOutput : ITestOutputHelper +{ + public void WriteLine(string message) { } + public void WriteLine(string format, params object[] args) { } +} + +sealed class SimpleLoggerFactory : ILoggerFactory +{ + readonly ILoggerProvider provider; + + public SimpleLoggerFactory(ILoggerProvider provider) + { + this.provider = provider; + } + + public void AddProvider(ILoggerProvider loggerProvider) + { + // No-op; single provider + } + + public ILogger CreateLogger(string categoryName) => this.provider.CreateLogger(categoryName); + + public void Dispose() { } +} diff --git a/test/Worker/Grpc.Tests/RunBackgroundTaskLoggingTests.cs b/test/Worker/Grpc.Tests/RunBackgroundTaskLoggingTests.cs index 2a907865..86f9afec 100644 --- a/test/Worker/Grpc.Tests/RunBackgroundTaskLoggingTests.cs +++ b/test/Worker/Grpc.Tests/RunBackgroundTaskLoggingTests.cs @@ -20,7 +20,7 @@ namespace Microsoft.DurableTask.Worker.Grpc.Tests; public class RunBackgroundTaskLoggingTests { - const string Category = "Microsoft.DurableTask"; + const string Category = "Microsoft.DurableTask.Worker.Grpc"; [Fact] public async Task Logs_Abandoning_And_Abandoned_For_Orchestrator()