diff --git a/CHANGELOG.md b/CHANGELOG.md index 885c291cd..b3159c918 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,5 +1,8 @@ # Changelog +## Unreleased +- Add `ReplaySafeLoggerFactory` public property to `TaskOrchestrationContext` to enable context-wrapping scenarios while preserving replay-safe logging guarantees ([#497](https://github.com/microsoft/durabletask-dotnet/issues/497)) + ## v1.22.0 - Changing the default dedupe statuses behavior by sophiatev ([#622](https://github.com/microsoft/durabletask-dotnet/pull/622)) - Bump Analyzers package version to 1.22.0 stable release (from 0.3.0) diff --git a/Microsoft.DurableTask.sln b/Microsoft.DurableTask.sln index ea7d17973..9336d0846 100644 --- a/Microsoft.DurableTask.sln +++ b/Microsoft.DurableTask.sln @@ -111,6 +111,8 @@ Project("{FAE04EC0-301F-11D3-BF4B-00C04F79EFBC}") = "ExportHistory.Tests", "test EndProject Project("{FAE04EC0-301F-11D3-BF4B-00C04F79EFBC}") = "DistributedTracingSample", "samples\DistributedTracingSample\DistributedTracingSample.csproj", "{4A7305AE-AAAE-43AE-AAB2-DA58DACC6FA8}" EndProject +Project("{FAE04EC0-301F-11D3-BF4B-00C04F79EFBC}") = "ReplaySafeLoggerFactorySample", "samples\ReplaySafeLoggerFactorySample\ReplaySafeLoggerFactorySample.csproj", "{8E7BECBC-7226-4778-B8F2-8EBDFF0D3BA4}" +EndProject Global GlobalSection(SolutionConfigurationPlatforms) = preSolution Debug|Any CPU = Debug|Any CPU @@ -660,6 +662,18 @@ Global {4A7305AE-AAAE-43AE-AAB2-DA58DACC6FA8}.Release|x64.Build.0 = Release|Any CPU {4A7305AE-AAAE-43AE-AAB2-DA58DACC6FA8}.Release|x86.ActiveCfg = Release|Any CPU {4A7305AE-AAAE-43AE-AAB2-DA58DACC6FA8}.Release|x86.Build.0 = Release|Any CPU + {8E7BECBC-7226-4778-B8F2-8EBDFF0D3BA4}.Debug|Any CPU.ActiveCfg = Debug|Any CPU + {8E7BECBC-7226-4778-B8F2-8EBDFF0D3BA4}.Debug|Any CPU.Build.0 = Debug|Any CPU + {8E7BECBC-7226-4778-B8F2-8EBDFF0D3BA4}.Debug|x64.ActiveCfg = Debug|Any CPU + {8E7BECBC-7226-4778-B8F2-8EBDFF0D3BA4}.Debug|x64.Build.0 = Debug|Any CPU + {8E7BECBC-7226-4778-B8F2-8EBDFF0D3BA4}.Debug|x86.ActiveCfg = Debug|Any CPU + {8E7BECBC-7226-4778-B8F2-8EBDFF0D3BA4}.Debug|x86.Build.0 = Debug|Any CPU + {8E7BECBC-7226-4778-B8F2-8EBDFF0D3BA4}.Release|Any CPU.ActiveCfg = Release|Any CPU + {8E7BECBC-7226-4778-B8F2-8EBDFF0D3BA4}.Release|Any CPU.Build.0 = Release|Any CPU + {8E7BECBC-7226-4778-B8F2-8EBDFF0D3BA4}.Release|x64.ActiveCfg = Release|Any CPU + {8E7BECBC-7226-4778-B8F2-8EBDFF0D3BA4}.Release|x64.Build.0 = Release|Any CPU + {8E7BECBC-7226-4778-B8F2-8EBDFF0D3BA4}.Release|x86.ActiveCfg = Release|Any CPU + {8E7BECBC-7226-4778-B8F2-8EBDFF0D3BA4}.Release|x86.Build.0 = Release|Any CPU EndGlobalSection GlobalSection(SolutionProperties) = preSolution HideSolutionNode = FALSE @@ -715,6 +729,7 @@ Global {354CE69B-78DB-9B29-C67E-0DBB862C7A65} = {8AFC9781-F6F1-4696-BB4A-9ED7CA9D612B} {05C9EBA6-7221-D458-47D6-DA457C2F893B} = {E5637F81-2FB9-4CD7-900D-455363B142A7} {4A7305AE-AAAE-43AE-AAB2-DA58DACC6FA8} = {EFF7632B-821E-4CFC-B4A0-ED4B24296B17} + {8E7BECBC-7226-4778-B8F2-8EBDFF0D3BA4} = {EFF7632B-821E-4CFC-B4A0-ED4B24296B17} EndGlobalSection GlobalSection(ExtensibilityGlobals) = postSolution SolutionGuid = {AB41CB55-35EA-4986-A522-387AB3402E71} diff --git a/samples/ReplaySafeLoggerFactorySample/Program.cs b/samples/ReplaySafeLoggerFactorySample/Program.cs new file mode 100644 index 000000000..6ee494b44 --- /dev/null +++ b/samples/ReplaySafeLoggerFactorySample/Program.cs @@ -0,0 +1,221 @@ +// Copyright (c) Microsoft Corporation. +// Licensed under the MIT License. + +// This sample demonstrates how to wrap TaskOrchestrationContext and delegate LoggerFactory +// to inner.ReplaySafeLoggerFactory so wrapper helpers can log without breaking replay safety. + +using Microsoft.DurableTask; +using Microsoft.DurableTask.Client; +using Microsoft.DurableTask.Client.AzureManaged; +using Microsoft.DurableTask.Entities; +using Microsoft.DurableTask.Worker; +using Microsoft.DurableTask.Worker.AzureManaged; +using Microsoft.Extensions.Configuration; +using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.Hosting; +using Microsoft.Extensions.Logging; + +namespace ReplaySafeLoggerFactorySample; + +static class Program +{ + static async Task Main(string[] args) + { + HostApplicationBuilder builder = Host.CreateApplicationBuilder(args); + + string? schedulerConnectionString = builder.Configuration.GetValue("DURABLE_TASK_SCHEDULER_CONNECTION_STRING"); + bool useScheduler = !string.IsNullOrWhiteSpace(schedulerConnectionString); + + ConfigureDurableTask(builder, useScheduler, schedulerConnectionString); + + IHost host = builder.Build(); + await host.StartAsync(); + + try + { + await using DurableTaskClient client = host.Services.GetRequiredService(); + + Console.WriteLine("ReplaySafeLoggerFactory Sample"); + Console.WriteLine("================================"); + Console.WriteLine(useScheduler + ? "Configured to use Durable Task Scheduler (DTS)." + : "Configured to use local gRPC. (Set DURABLE_TASK_SCHEDULER_CONNECTION_STRING to use DTS.)"); + Console.WriteLine(); + + string instanceId = await client.ScheduleNewOrchestrationInstanceAsync( + nameof(ReplaySafeLoggingOrchestration), + input: "Seattle"); + + Console.WriteLine($"Started orchestration instance: {instanceId}"); + + using CancellationTokenSource timeoutCts = new(TimeSpan.FromSeconds(60)); + OrchestrationMetadata result = await client.WaitForInstanceCompletionAsync( + instanceId, + getInputsAndOutputs: true, + timeoutCts.Token); + + if (result.RuntimeStatus != OrchestrationRuntimeStatus.Completed) + { + throw new InvalidOperationException( + $"Expected '{nameof(OrchestrationRuntimeStatus.Completed)}' but got '{result.RuntimeStatus}'."); + } + + Console.WriteLine($"Result: {result.ReadOutputAs()}"); + Console.WriteLine(); + Console.WriteLine( + "The wrapper delegates LoggerFactory to inner.ReplaySafeLoggerFactory, " + + "so wrapper-level logging stays replay-safe."); + } + finally + { + await host.StopAsync(); + } + } + + static void ConfigureDurableTask( + HostApplicationBuilder builder, + bool useScheduler, + string? schedulerConnectionString) + { + if (useScheduler) + { + builder.Services.AddDurableTaskClient(clientBuilder => clientBuilder.UseDurableTaskScheduler(schedulerConnectionString!)); + + builder.Services.AddDurableTaskWorker(workerBuilder => + { + workerBuilder.AddTasks(tasks => + { + tasks.AddOrchestrator(); + tasks.AddActivity(); + }); + + workerBuilder.UseDurableTaskScheduler(schedulerConnectionString!); + }); + } + else + { + builder.Services.AddDurableTaskClient().UseGrpc(); + + builder.Services.AddDurableTaskWorker() + .AddTasks(tasks => + { + tasks.AddOrchestrator(); + tasks.AddActivity(); + }) + .UseGrpc(); + } + } +} + +[DurableTask(nameof(ReplaySafeLoggingOrchestration))] +sealed class ReplaySafeLoggingOrchestration : TaskOrchestrator +{ + public override async Task RunAsync(TaskOrchestrationContext context, string input) + { + LoggingTaskOrchestrationContext wrappedContext = new(context); + ILogger logger = wrappedContext.CreateLogger(); + + logger.LogInformation("Wrapping orchestration context for instance {InstanceId}.", wrappedContext.InstanceId); + + string greeting = await wrappedContext.CallActivityWithLoggingAsync(nameof(SayHelloActivity), input); + + logger.LogInformation("Returning activity result for {InstanceId}.", wrappedContext.InstanceId); + return greeting; + } +} + +[DurableTask(nameof(SayHelloActivity))] +sealed class SayHelloActivity : TaskActivity +{ + readonly ILogger logger; + + public SayHelloActivity(ILoggerFactory loggerFactory) + { + this.logger = loggerFactory.CreateLogger(); + } + + public override Task RunAsync(TaskActivityContext context, string input) + { + this.logger.LogInformation("Generating a greeting for {Name}.", input); + return Task.FromResult( + $"Hello, {input}! This orchestration used ReplaySafeLoggerFactory to keep wrapper logging replay-safe."); + } +} + +sealed class LoggingTaskOrchestrationContext : TaskOrchestrationContext +{ + readonly TaskOrchestrationContext innerContext; + + public LoggingTaskOrchestrationContext(TaskOrchestrationContext innerContext) + { + this.innerContext = innerContext ?? throw new ArgumentNullException(nameof(innerContext)); + } + + // Only abstract members need explicit forwarding here. Virtual helpers such as + // ReplaySafeLoggerFactory and the convenience overloads continue to work through these overrides. + public override TaskName Name => this.innerContext.Name; + + public override string InstanceId => this.innerContext.InstanceId; + + public override ParentOrchestrationInstance? Parent => this.innerContext.Parent; + + public override DateTime CurrentUtcDateTime => this.innerContext.CurrentUtcDateTime; + + public override bool IsReplaying => this.innerContext.IsReplaying; + + public override string Version => this.innerContext.Version; + + public override IReadOnlyDictionary Properties => this.innerContext.Properties; + + protected override ILoggerFactory LoggerFactory => this.innerContext.ReplaySafeLoggerFactory; + + public ILogger CreateLogger() + => this.CreateReplaySafeLogger(); + + public async Task CallActivityWithLoggingAsync( + TaskName name, + object? input = null, + TaskOptions? options = null) + { + ILogger logger = this.CreateReplaySafeLogger(); + logger.LogInformation("Calling activity {ActivityName} for instance {InstanceId}.", name.Name, this.InstanceId); + + TResult result = await this.CallActivityAsync(name, input, options); + + logger.LogInformation("Activity {ActivityName} completed for instance {InstanceId}.", name.Name, this.InstanceId); + return result; + } + + public override T GetInput() + => this.innerContext.GetInput()!; + + public override Task CallActivityAsync( + TaskName name, + object? input = null, + TaskOptions? options = null) + => this.innerContext.CallActivityAsync(name, input, options); + + public override Task CreateTimer(DateTime fireAt, CancellationToken cancellationToken) + => this.innerContext.CreateTimer(fireAt, cancellationToken); + + public override Task WaitForExternalEvent(string eventName, CancellationToken cancellationToken = default) + => this.innerContext.WaitForExternalEvent(eventName, cancellationToken); + + public override void SendEvent(string instanceId, string eventName, object payload) + => this.innerContext.SendEvent(instanceId, eventName, payload); + + public override void SetCustomStatus(object? customStatus) + => this.innerContext.SetCustomStatus(customStatus); + + public override Task CallSubOrchestratorAsync( + TaskName orchestratorName, + object? input = null, + TaskOptions? options = null) + => this.innerContext.CallSubOrchestratorAsync(orchestratorName, input, options); + + public override void ContinueAsNew(object? newInput = null, bool preserveUnprocessedEvents = true) + => this.innerContext.ContinueAsNew(newInput, preserveUnprocessedEvents); + + public override Guid NewGuid() + => this.innerContext.NewGuid(); +} diff --git a/samples/ReplaySafeLoggerFactorySample/README.md b/samples/ReplaySafeLoggerFactorySample/README.md new file mode 100644 index 000000000..8b1e74ff7 --- /dev/null +++ b/samples/ReplaySafeLoggerFactorySample/README.md @@ -0,0 +1,78 @@ +# Replay-Safe Logger Factory Sample + +This sample demonstrates how to wrap `TaskOrchestrationContext` and use the new `ReplaySafeLoggerFactory` property to preserve replay-safe logging. + +## Overview + +When you build helper libraries or decorators around `TaskOrchestrationContext`, C# protected access rules prevent you from delegating the protected `LoggerFactory` property from an inner context. This sample shows the recommended pattern: + +```csharp +protected override ILoggerFactory LoggerFactory => innerContext.ReplaySafeLoggerFactory; +``` + +That approach keeps wrapper-level logging replay-safe while still allowing the wrapper to add orchestration-specific helper methods. + +## What This Sample Does + +1. Defines a `LoggingTaskOrchestrationContext` wrapper around `TaskOrchestrationContext` +2. Delegates the wrapper's `LoggerFactory` to `innerContext.ReplaySafeLoggerFactory` +3. Adds a `CallActivityWithLoggingAsync` helper that logs before and after an activity call +4. Runs an orchestration that uses the wrapper and completes with a simple greeting + +## Running the Sample + +This sample can run against either: + +1. **Durable Task Scheduler (DTS)**: set the `DURABLE_TASK_SCHEDULER_CONNECTION_STRING` environment variable. +2. **Local gRPC endpoint**: if the environment variable is not set, the sample uses the default local gRPC configuration. + +### DTS + +Set `DURABLE_TASK_SCHEDULER_CONNECTION_STRING` and run the sample. + +```cmd +set DURABLE_TASK_SCHEDULER_CONNECTION_STRING=Endpoint=https://...;TaskHub=...;Authentication=...; +dotnet run --project samples/ReplaySafeLoggerFactorySample/ReplaySafeLoggerFactorySample.csproj +``` + +```bash +export DURABLE_TASK_SCHEDULER_CONNECTION_STRING="Endpoint=https://...;TaskHub=...;Authentication=...;" +dotnet run --project samples/ReplaySafeLoggerFactorySample/ReplaySafeLoggerFactorySample.csproj +``` + +## Expected Output + +The sample: + +1. Starts a simple orchestration +2. Wraps the orchestration context +3. Calls an activity through a wrapper helper that uses replay-safe logging +4. Prints the orchestration result + +## Code Structure + +- `Program.cs`: Contains the host setup, orchestration, activity, and wrapper context + +## Key Code Snippet + +```csharp +internal sealed class LoggingTaskOrchestrationContext : TaskOrchestrationContext +{ + protected override ILoggerFactory LoggerFactory => this.innerContext.ReplaySafeLoggerFactory; + + public async Task CallActivityWithLoggingAsync(TaskName name, object? input = null) + { + ILogger logger = this.CreateReplaySafeLogger(); + logger.LogInformation("Calling activity {ActivityName}.", name.Name); + TResult result = await this.CallActivityAsync(name, input); + logger.LogInformation("Activity {ActivityName} completed.", name.Name); + return result; + } +} +``` + +## Notes + +- The key design point is that the raw `LoggerFactory` remains protected on `TaskOrchestrationContext` +- `ReplaySafeLoggerFactory` exists specifically for wrapper and delegation scenarios like this one +- The wrapper shown here forwards the core abstract members needed by the sample; real wrappers can forward additional members as needed diff --git a/samples/ReplaySafeLoggerFactorySample/ReplaySafeLoggerFactorySample.csproj b/samples/ReplaySafeLoggerFactorySample/ReplaySafeLoggerFactorySample.csproj new file mode 100644 index 000000000..ebc0466f2 --- /dev/null +++ b/samples/ReplaySafeLoggerFactorySample/ReplaySafeLoggerFactorySample.csproj @@ -0,0 +1,28 @@ + + + + Exe + net6.0;net8.0;net10.0 + enable + + + + + + + + + + + + + + + + + + + diff --git a/src/Abstractions/TaskOrchestrationContext.cs b/src/Abstractions/TaskOrchestrationContext.cs index 9cf5fe7e3..49a1e6b09 100644 --- a/src/Abstractions/TaskOrchestrationContext.cs +++ b/src/Abstractions/TaskOrchestrationContext.cs @@ -13,6 +13,8 @@ namespace Microsoft.DurableTask; /// public abstract class TaskOrchestrationContext { + ILoggerFactory? replaySafeLoggerFactory; + /// /// Gets the name of the task orchestration. /// @@ -76,6 +78,25 @@ public abstract class TaskOrchestrationContext public virtual TaskOrchestrationEntityFeature Entities => throw new NotSupportedException($"Durable entities are not supported by {this.GetType()}."); + /// + /// Gets an whose loggers are replay-safe, meaning they suppress log + /// output during orchestration replay. This is the recommended way to expose logger functionality + /// when wrapping a instance. + /// + /// + /// + /// Loggers created by this factory automatically check and suppress + /// duplicate log messages during replay. This is equivalent to calling + /// for each logger category. + /// + /// + /// Context wrapper implementations can delegate to this property + /// on the inner context: protected override ILoggerFactory LoggerFactory => inner.ReplaySafeLoggerFactory;. + /// + /// + public virtual ILoggerFactory ReplaySafeLoggerFactory + => this.replaySafeLoggerFactory ??= new ReplaySafeLoggerFactoryImpl(this); + /// /// Gets the logger factory for this context. /// @@ -412,17 +433,17 @@ public virtual Task CallSubOrchestratorAsync( /// The logger's category name. /// An instance of that is replay-safe. public virtual ILogger CreateReplaySafeLogger(string categoryName) - => new ReplaySafeLogger(this, this.LoggerFactory.CreateLogger(categoryName)); + => new ReplaySafeLogger(this, this.GetUnwrappedLoggerFactory().CreateLogger(categoryName)); /// /// The type to derive the category name from. public virtual ILogger CreateReplaySafeLogger(Type type) - => new ReplaySafeLogger(this, this.LoggerFactory.CreateLogger(type)); + => new ReplaySafeLogger(this, this.GetUnwrappedLoggerFactory().CreateLogger(type)); /// /// The type to derive category name from. public virtual ILogger CreateReplaySafeLogger() - => new ReplaySafeLogger(this, this.LoggerFactory.CreateLogger()); + => new ReplaySafeLogger(this, this.GetUnwrappedLoggerFactory().CreateLogger()); /// /// Checks if the current orchestration version is greater than the specified version. @@ -445,7 +466,31 @@ public virtual int CompareVersionTo(string version) return TaskOrchestrationVersioningUtils.CompareVersions(this.Version, version); } - class ReplaySafeLogger : ILogger + ILoggerFactory GetUnwrappedLoggerFactory() + { + ILoggerFactory loggerFactory = this.LoggerFactory; + int depth = 0; + + // When a wrapper context delegates LoggerFactory to inner.ReplaySafeLoggerFactory, + // the returned factory is already a ReplaySafeLoggerFactoryImpl. Unwrap it to avoid + // double-wrapping loggers with redundant replay-safe checks. + while (loggerFactory is ReplaySafeLoggerFactoryImpl wrappedFactory) + { + if (++depth > 10) + { + throw new InvalidOperationException( + "Maximum unwrap depth exceeded while resolving the underlying ILoggerFactory. " + + "Ensure the wrapper's LoggerFactory property delegates to the inner context's " + + "ReplaySafeLoggerFactory (e.g., 'inner.ReplaySafeLoggerFactory'), not 'this.ReplaySafeLoggerFactory'."); + } + + loggerFactory = wrappedFactory.UnderlyingLoggerFactory; + } + + return loggerFactory; + } + + sealed class ReplaySafeLogger : ILogger { readonly TaskOrchestrationContext context; readonly ILogger logger; @@ -456,7 +501,9 @@ internal ReplaySafeLogger(TaskOrchestrationContext context, ILogger logger) this.logger = logger ?? throw new ArgumentNullException(nameof(logger)); } - public IDisposable BeginScope(TState state) => this.logger.BeginScope(state); + public IDisposable? BeginScope(TState state) + where TState : notnull + => this.logger.BeginScope(state); public bool IsEnabled(LogLevel logLevel) => this.logger.IsEnabled(logLevel); @@ -473,4 +520,28 @@ public void Log( } } } + + sealed class ReplaySafeLoggerFactoryImpl : ILoggerFactory + { + readonly TaskOrchestrationContext context; + + internal ReplaySafeLoggerFactoryImpl(TaskOrchestrationContext context) + { + this.context = context ?? throw new ArgumentNullException(nameof(context)); + } + + internal ILoggerFactory UnderlyingLoggerFactory => this.context.LoggerFactory; + + public ILogger CreateLogger(string categoryName) + => new ReplaySafeLogger(this.context, this.context.GetUnwrappedLoggerFactory().CreateLogger(categoryName)); + + public void AddProvider(ILoggerProvider provider) + => throw new NotSupportedException( + "Adding providers to the replay-safe logger factory is not supported."); + + public void Dispose() + { + // No-op: this wrapper does not own the underlying logger factory. + } + } } diff --git a/test/Abstractions.Tests/TaskOrchestrationContextReplaySafeLoggerFactoryTests.cs b/test/Abstractions.Tests/TaskOrchestrationContextReplaySafeLoggerFactoryTests.cs new file mode 100644 index 000000000..70d91857e --- /dev/null +++ b/test/Abstractions.Tests/TaskOrchestrationContextReplaySafeLoggerFactoryTests.cs @@ -0,0 +1,378 @@ +// Copyright (c) Microsoft Corporation. +// Licensed under the MIT License. + +using Microsoft.Extensions.Logging; + +namespace Microsoft.DurableTask.Tests; + +public class TaskOrchestrationContextReplaySafeLoggerFactoryTests +{ + [Fact] + public void ReplaySafeLoggerFactory_ReturnsCachedFactoryInstance() + { + // Arrange + TrackingLoggerProvider provider = new(); + TrackingLoggerFactory loggerFactory = new(provider); + TestTaskOrchestrationContext context = new(loggerFactory, isReplaying: false); + + // Act + ILoggerFactory firstFactory = context.ReplaySafeLoggerFactory; + ILoggerFactory secondFactory = context.ReplaySafeLoggerFactory; + + // Assert + secondFactory.Should().BeSameAs(firstFactory); + } + + [Fact] + public void ReplaySafeLoggerFactory_CreateLogger_SuppressesLogsDuringReplay() + { + // Arrange + TrackingLoggerProvider provider = new(); + TrackingLoggerFactory loggerFactory = new(provider); + TestTaskOrchestrationContext context = new(loggerFactory, isReplaying: true); + ILogger logger = context.ReplaySafeLoggerFactory.CreateLogger("ReplaySafe"); + + // Act + logger.LogInformation("This log should be suppressed."); + + // Assert + provider.Entries.Should().BeEmpty(); + } + + [Fact] + public void ReplaySafeLoggerFactory_CreateLogger_WritesLogsWhenNotReplaying() + { + // Arrange + TrackingLoggerProvider provider = new(); + TrackingLoggerFactory loggerFactory = new(provider); + TestTaskOrchestrationContext context = new(loggerFactory, isReplaying: false); + ILogger logger = context.ReplaySafeLoggerFactory.CreateLogger("ReplaySafe"); + + // Act + logger.LogInformation("This log should be written."); + + // Assert + provider.Entries.Should().ContainSingle(entry => + entry.CategoryName == "ReplaySafe" && + entry.Message.Contains("This log should be written.", StringComparison.Ordinal)); + } + + [Fact] + public void ReplaySafeLoggerFactory_AddProvider_ThrowsWithoutMutatingUnderlyingFactory() + { + // Arrange + TrackingLoggerProvider provider = new(); + TrackingLoggerFactory loggerFactory = new(provider); + TestTaskOrchestrationContext context = new(loggerFactory, isReplaying: false); + TrackingLoggerProvider additionalProvider = new(); + + // Act + Action act = () => context.ReplaySafeLoggerFactory.AddProvider(additionalProvider); + + // Assert + act.Should().Throw() + .WithMessage("*replay-safe logger factory*not supported*"); + loggerFactory.AddProviderCallCount.Should().Be(0); + } + + [Fact] + public void ReplaySafeLoggerFactory_CreateLogger_FromWrappedContext_ChecksReplayOnce() + { + // Arrange + TrackingLoggerProvider provider = new(); + TrackingLoggerFactory loggerFactory = new(provider); + TestTaskOrchestrationContext innerContext = new(loggerFactory, isReplaying: false); + WrappingTaskOrchestrationContext wrappedContext = new(innerContext); + ILogger logger = wrappedContext.ReplaySafeLoggerFactory.CreateLogger("ReplaySafe"); + + // Act + logger.LogInformation("This log should be written."); + + // Assert + innerContext.IsReplayingAccessCount.Should().Be(1); + provider.Entries.Should().ContainSingle(entry => + entry.CategoryName == "ReplaySafe" && + entry.Message.Contains("This log should be written.", StringComparison.Ordinal)); + } + + [Fact] + public void ReplaySafeLoggerFactory_CreateLogger_ThrowsOnCyclicLoggerFactory() + { + // Arrange + SelfReferencingContext cyclicContext = new(); + + // Act + Action act = () => cyclicContext.ReplaySafeLoggerFactory.CreateLogger("Test"); + + // Assert + act.Should().Throw() + .WithMessage("*Maximum unwrap depth exceeded*"); + } + + [Fact] + public void ReplaySafeLoggerFactory_Dispose_DoesNotDisposeUnderlyingFactory() + { + // Arrange + TrackingLoggerProvider provider = new(); + TrackingLoggerFactory loggerFactory = new(provider); + TestTaskOrchestrationContext context = new(loggerFactory, isReplaying: false); + + // Act + context.ReplaySafeLoggerFactory.Dispose(); + + // Assert + loggerFactory.DisposeCallCount.Should().Be(0); + } + + sealed class TestTaskOrchestrationContext : TaskOrchestrationContext + { + readonly ILoggerFactory loggerFactory; + readonly bool isReplaying; + + public TestTaskOrchestrationContext(ILoggerFactory loggerFactory, bool isReplaying) + { + this.loggerFactory = loggerFactory; + this.isReplaying = isReplaying; + } + + public override TaskName Name => default; + + public override string InstanceId => "test-instance"; + + public override ParentOrchestrationInstance? Parent => null; + + public override DateTime CurrentUtcDateTime => DateTime.UnixEpoch; + + public int IsReplayingAccessCount { get; private set; } + + public override bool IsReplaying + { + get + { + this.IsReplayingAccessCount++; + return this.isReplaying; + } + } + + public override IReadOnlyDictionary Properties => new Dictionary(); + + protected override ILoggerFactory LoggerFactory => this.loggerFactory; + + public override T GetInput() + => default!; + + public override Task CallActivityAsync(TaskName name, object? input = null, TaskOptions? options = null) + => throw new NotImplementedException(); + + public override Task CreateTimer(DateTime fireAt, CancellationToken cancellationToken) + => throw new NotImplementedException(); + + public override Task WaitForExternalEvent(string eventName, CancellationToken cancellationToken = default) + => throw new NotImplementedException(); + + public override void SendEvent(string instanceId, string eventName, object payload) + => throw new NotImplementedException(); + + public override void SetCustomStatus(object? customStatus) + => throw new NotImplementedException(); + + public override Task CallSubOrchestratorAsync( + TaskName orchestratorName, + object? input = null, + TaskOptions? options = null) + => throw new NotImplementedException(); + + public override void ContinueAsNew(object? newInput = null, bool preserveUnprocessedEvents = true) + => throw new NotImplementedException(); + + public override Guid NewGuid() + => throw new NotImplementedException(); + } + + sealed class WrappingTaskOrchestrationContext : TaskOrchestrationContext + { + readonly TaskOrchestrationContext innerContext; + + public WrappingTaskOrchestrationContext(TaskOrchestrationContext innerContext) + { + this.innerContext = innerContext ?? throw new ArgumentNullException(nameof(innerContext)); + } + + public override TaskName Name => this.innerContext.Name; + + public override string InstanceId => this.innerContext.InstanceId; + + public override ParentOrchestrationInstance? Parent => this.innerContext.Parent; + + public override DateTime CurrentUtcDateTime => this.innerContext.CurrentUtcDateTime; + + public override bool IsReplaying => this.innerContext.IsReplaying; + + public override string Version => this.innerContext.Version; + + public override IReadOnlyDictionary Properties => this.innerContext.Properties; + + protected override ILoggerFactory LoggerFactory => this.innerContext.ReplaySafeLoggerFactory; + + public override T GetInput() + => this.innerContext.GetInput()!; + + public override Task CallActivityAsync(TaskName name, object? input = null, TaskOptions? options = null) + => this.innerContext.CallActivityAsync(name, input, options); + + public override Task CreateTimer(DateTime fireAt, CancellationToken cancellationToken) + => this.innerContext.CreateTimer(fireAt, cancellationToken); + + public override Task WaitForExternalEvent(string eventName, CancellationToken cancellationToken = default) + => this.innerContext.WaitForExternalEvent(eventName, cancellationToken); + + public override void SendEvent(string instanceId, string eventName, object payload) + => this.innerContext.SendEvent(instanceId, eventName, payload); + + public override void SetCustomStatus(object? customStatus) + => this.innerContext.SetCustomStatus(customStatus); + + public override Task CallSubOrchestratorAsync( + TaskName orchestratorName, + object? input = null, + TaskOptions? options = null) + => this.innerContext.CallSubOrchestratorAsync(orchestratorName, input, options); + + public override void ContinueAsNew(object? newInput = null, bool preserveUnprocessedEvents = true) + => this.innerContext.ContinueAsNew(newInput, preserveUnprocessedEvents); + + public override Guid NewGuid() + => this.innerContext.NewGuid(); + } + + sealed class SelfReferencingContext : TaskOrchestrationContext + { + public SelfReferencingContext() + { + } + + public override TaskName Name => default; + + public override string InstanceId => "cyclic-instance"; + + public override ParentOrchestrationInstance? Parent => null; + + public override DateTime CurrentUtcDateTime => DateTime.UnixEpoch; + + public override bool IsReplaying => false; + + public override IReadOnlyDictionary Properties => new Dictionary(); + + // Bug: points at self instead of an inner context — should cause cycle detection. + protected override ILoggerFactory LoggerFactory => this.ReplaySafeLoggerFactory; + + public override T GetInput() + => default!; + + public override Task CallActivityAsync(TaskName name, object? input = null, TaskOptions? options = null) + => throw new NotImplementedException(); + + public override Task CreateTimer(DateTime fireAt, CancellationToken cancellationToken) + => throw new NotImplementedException(); + + public override Task WaitForExternalEvent(string eventName, CancellationToken cancellationToken = default) + => throw new NotImplementedException(); + + public override void SendEvent(string instanceId, string eventName, object payload) + => throw new NotImplementedException(); + + public override void SetCustomStatus(object? customStatus) + => throw new NotImplementedException(); + + public override Task CallSubOrchestratorAsync( + TaskName orchestratorName, + object? input = null, + TaskOptions? options = null) + => throw new NotImplementedException(); + + public override void ContinueAsNew(object? newInput = null, bool preserveUnprocessedEvents = true) + => throw new NotImplementedException(); + + public override Guid NewGuid() + => throw new NotImplementedException(); + } + + sealed class TrackingLoggerFactory : ILoggerFactory + { + readonly TrackingLoggerProvider provider; + + public TrackingLoggerFactory(TrackingLoggerProvider provider) + { + this.provider = provider; + } + + public int AddProviderCallCount { get; private set; } + + public int DisposeCallCount { get; private set; } + + public void AddProvider(ILoggerProvider provider) + { + this.AddProviderCallCount++; + } + + public ILogger CreateLogger(string categoryName) + => this.provider.CreateLogger(categoryName); + + public void Dispose() + { + this.DisposeCallCount++; + } + } + + sealed class TrackingLoggerProvider : ILoggerProvider + { + public List Entries { get; } = new(); + + public ILogger CreateLogger(string categoryName) + => new TrackingLogger(categoryName, this.Entries); + + public void Dispose() + { + } + } + + sealed class TrackingLogger : ILogger + { + readonly string categoryName; + readonly List entries; + + public TrackingLogger(string categoryName, List entries) + { + this.categoryName = categoryName; + this.entries = entries; + } + + public IDisposable? BeginScope(TState state) + where TState : notnull + => NullScope.Instance; + + public bool IsEnabled(LogLevel logLevel) + => true; + + public void Log( + LogLevel logLevel, + EventId eventId, + TState state, + Exception? exception, + Func formatter) + { + this.entries.Add(new LogEntry(this.categoryName, logLevel, formatter(state, exception))); + } + } + + sealed record LogEntry(string CategoryName, LogLevel LogLevel, string Message); + + sealed class NullScope : IDisposable + { + public static readonly NullScope Instance = new(); + + public void Dispose() + { + } + } +} diff --git a/test/Grpc.IntegrationTests/IntegrationTestBase.cs b/test/Grpc.IntegrationTests/IntegrationTestBase.cs index ded827769..93b695dd4 100644 --- a/test/Grpc.IntegrationTests/IntegrationTestBase.cs +++ b/test/Grpc.IntegrationTests/IntegrationTestBase.cs @@ -18,7 +18,7 @@ namespace Microsoft.DurableTask.Grpc.Tests; public class IntegrationTestBase : IClassFixture, IDisposable { readonly CancellationTokenSource testTimeoutSource - = new(Debugger.IsAttached ? TimeSpan.FromMinutes(5) : TimeSpan.FromSeconds(10)); + = new(Debugger.IsAttached ? TimeSpan.FromMinutes(5) : TimeSpan.FromSeconds(30)); readonly TestLogProvider logProvider;