wip

dotnet · Demo30 · Feb 12, 2025 · Mar 21, 2025 · Mar 24, 2025 · Mar 24, 2025
commit c36f2852e13543d9549cba974b2616e58e02f7f7
@@ -4,6 +4,9 @@
 using System;
 using System.Collections.Generic;
 using System.Diagnostics;
+using System.Linq;
+using System.Threading;
+using System.Threading.Tasks;
 using Microsoft.Extensions.Options;
 using Microsoft.Shared.Diagnostics;
 
@@ -19,6 +22,8 @@ public class FakeLogCollector
     private readonly List<FakeLogRecord> _records = [];
     private readonly FakeLogCollectorOptions _options;
 
+    private readonly List<Waiter> _waiters = []; // modify only under _records lock
+
     /// <summary>
     /// Initializes a new instance of the <see cref="FakeLogCollector"/> class.
     /// </summary>
@@ -106,6 +111,67 @@ public FakeLogRecord LatestRecord
     /// </summary>
     public int Count => _records.Count;
 
+
+    // TODO TW: add documentation
+    /// <summary>
+    /// 
+    /// </summary>
+    /// <param name="endWaiting"></param>
+    /// <param name="cancellationToken"></param>
+    /// <returns>Task which is completed when the condition is fulfilled or when the cancellation is invoked</returns>
+    public Task WaitForLogAsync(Func<FakeLogRecord, bool> endWaiting, CancellationToken cancellationToken = default)
+    {
+        _ = Throw.IfNull(endWaiting);
+
+        Waiter waiter;
+
+        lock (_records)
+        {
+            if (_records.Count > 0 && endWaiting(LatestRecord))
+            {
+                return Task.CompletedTask;
+            }
+
+            waiter = new Waiter(endWaiting);
+            _waiters.Add(waiter);
+        }
+
+        bool isCancelled = false;
+
+        if (cancellationToken.CanBeCanceled)
+        {
+            lock (_records)
+            {
+                if (cancellationToken.IsCancellationRequested)
+                {
+                    isCancelled = true;
+                    _ = _waiters.Remove(waiter);
+                }
+            }
+
+            _ = cancellationToken.Register(() =>
+            {
+                lock (_records)
+                {
+                    _ = _waiters.Remove(waiter);
+                }
+
+                // trigger the task from outside the lock
+                _ = waiter.TaskSource.TrySetCanceled(cancellationToken);
+            });
+        }
+
+        if (isCancelled)
+        {
+            // trigger the task from outside the lock
+            _ = waiter.TaskSource.TrySetCanceled(cancellationToken); // TODO TW: <<<< is this correct?
+        }
+
+#pragma warning disable VSTHRD003 // Avoid awaiting foreign Tasks
+        return waiter.TaskSource.Task;
+#pragma warning restore VSTHRD003 // Avoid awaiting foreign Tasks
+    }
+
     internal void AddRecord(FakeLogRecord record)
     {
         if (_options.FilteredLevels.Count > 0 && !_options.FilteredLevels.Contains(record.Level))
@@ -129,13 +195,54 @@ internal void AddRecord(FakeLogRecord record)
             return;
         }
 
+        List<Waiter>? waitersToWakeUp = null;
+
         lock (_records)
         {
             _records.Add(record);
+
+            // TODO TW: To consider: 
+            GatherWaitersForWaking(ref waitersToWakeUp, record);
+        }
+
+        if (waitersToWakeUp is not null)
+        {
+            foreach (var waiterToWakeUp in waitersToWakeUp)
+            {
+                // trigger the task from outside the lock
+                waiterToWakeUp.TaskSource.SetResult(true);
+            }
         }
 
         _options.OutputSink?.Invoke(_options.OutputFormatter(record));
     }
 
+    private void GatherWaitersForWaking(ref List<Waiter>? waitersToWakeUp, FakeLogRecord currentlyLoggedRecord)
+    {
+        for (var waiterIndex = _waiters.Count - 1; waiterIndex >= 0; waiterIndex--)
+        {
+            var waiter = _waiters[waiterIndex];
+            if (!waiter.ShouldEndWaiting(currentlyLoggedRecord))
+            {
+                continue;
+            }
+
+            waitersToWakeUp ??= [];
+            waitersToWakeUp.Add(waiter);
+            _ = _waiters.Remove(waiter);
+        }
+    }
+
     internal TimeProvider TimeProvider => _options.TimeProvider;
+
+    private readonly record struct Waiter(Func<FakeLogRecord, bool> ShouldEndWaiting)
+    {
+        public Func<FakeLogRecord, bool> ShouldEndWaiting { get; } = ShouldEndWaiting;
+
+        // NOTE: In order to avoid potential dead locks, this task should
+        // be completed when the main lock is not being held. Otherwise,
+        // application code being woken up by the task could potentially
+        // call back into the MetricCollector code and thus trigger a deadlock.
+        public TaskCompletionSource<bool> TaskSource { get; } = new();
+    }
 }
@@ -2,7 +2,12 @@
 // The .NET Foundation licenses this file to you under the MIT license.
 
 using System;
+using System.Collections.Concurrent;
+using System.Collections.Generic;
 using System.Globalization;
+using System.Linq;
+using System.Threading;
+using System.Threading.Tasks;
 using Microsoft.Extensions.Time.Testing;
 using Xunit;
 using Xunit.Abstractions;
@@ -177,4 +182,179 @@ public void TestOutputHelperExtensionsGeneric()
         logger.Log((LogLevel)42, "Hello world!");
         Assert.Contains("invld] Hello world!", output.Last);
     }
+
+    private record WaitingTestCase(
+        int EndWaitAtAttemptCount,
+        int? CancellationWaitInMs,
+        bool StartsWithCancelledToken,
+        string[] ExpectedOperationSequence,
+        bool ExpectedTaskCancelled
+    );
+
+    private const int WaitingTscOverallLogCount = 3;
+    private const int WaitingTscOneLogTimeInMs = 250;
+    private const string WaitingTscLogAttemptPrefix = "Log attempt";
+
+    [Theory]
+    [InlineData(0)]
+    [InlineData(1)]
+    [InlineData(2)]
+    [InlineData(3)]
+    [InlineData(4)]
+    public async Task Waiting(int testCase)
+    {
+        // Arrange
+
+        var testCaseData = WaitingTestCases()[testCase];
+
+        var collector = FakeLogCollector.Create(new FakeLogCollectorOptions());
+
+        var logger = new FakeLogger(collector);
+
+        using var cancellationTokenSource = testCaseData.CancellationWaitInMs is not null
+            ? new CancellationTokenSource(TimeSpan.FromMilliseconds(testCaseData.CancellationWaitInMs.Value))
+            : new CancellationTokenSource();
+
+        if (testCaseData.StartsWithCancelledToken)
+        {
+            cancellationTokenSource.Cancel();
+        }
+
+        var testExecutionCustomLog = new ConcurrentQueue<string>();
+
+        int count = 0;
+
+        bool EndWaiting(FakeLogRecord record)
+        {
+            Interlocked.Increment(ref count);
+            testExecutionCustomLog.Enqueue("Checking if should end waiting #" + count);
+            return count == testCaseData.EndWaitAtAttemptCount;
+        }
+
+        // Act
+
+        testExecutionCustomLog.Enqueue("Started");
+
+        var awaitingTask = collector.WaitForLogAsync(EndWaiting, cancellationTokenSource.Token);
+
+        var loggingBackgroundAction = Task.Run(
+            () =>
+            {
+                for (var logAttempt = 1; logAttempt <= WaitingTscOverallLogCount; logAttempt++)
+                {
+                    Thread.Sleep(WaitingTscOneLogTimeInMs);
+                    var message = $"{WaitingTscLogAttemptPrefix} #{logAttempt:000}";
+                    testExecutionCustomLog.Enqueue(message);
+                    logger.LogDebug(message);
+                }
+            },
+            CancellationToken.None);
+
+        testExecutionCustomLog.Enqueue("Right after starting the background action");
+
+        bool taskCancelled = false;
+
+        try
+        {
+            await awaitingTask;
+        }
+        catch (TaskCanceledException)
+        {
+            taskCancelled = true;
+        }
+
+        testExecutionCustomLog.Enqueue("Finished waiting for the log");
+
+        await loggingBackgroundAction;
+
+        testExecutionCustomLog.Enqueue("Background action has finished");
+
+        // Assert
+        Assert.True(testExecutionCustomLog.SequenceEqual(testCaseData.ExpectedOperationSequence));
+        Assert.Equal(testExecutionCustomLog.Count(r => r.StartsWith(WaitingTscLogAttemptPrefix)), logger.Collector.Count);
+        Assert.Equal(taskCancelled, testCaseData.ExpectedTaskCancelled);
+    }
+
+    private static List<WaitingTestCase> WaitingTestCases()
+    {
+        var testCases = new List<WaitingTestCase>();
+
+        // Waiting for one record
+        testCases.Add(new WaitingTestCase(
+            1, null, false, [
+                "Started",
+                "Right after starting the background action",
+                $"{WaitingTscLogAttemptPrefix} #001",
+                "Checking if should end waiting #1",
+                "Finished waiting for the log",
+                $"{WaitingTscLogAttemptPrefix} #002",
+                $"{WaitingTscLogAttemptPrefix} #003",
+                "Background action has finished"
+            ],
+            false
+        ));
+
+        // Waiting for two records
+        testCases.Add(new WaitingTestCase(
+            2, null, false, [
+                "Started",
+                "Right after starting the background action",
+                $"{WaitingTscLogAttemptPrefix} #001",
+                "Checking if should end waiting #1",
+                $"{WaitingTscLogAttemptPrefix} #002",
+                "Checking if should end waiting #2",
+                "Finished waiting for the log",
+                $"{WaitingTscLogAttemptPrefix} #003",
+                "Background action has finished"
+            ],
+            false
+        ));
+
+        // Waiting for many log records, but cancelling the wait before this condition is reached at the time of one log record being actually logged.
+        const int OneAndHalfRecordTime = WaitingTscOneLogTimeInMs + (WaitingTscOneLogTimeInMs / 2);
+        testCases.Add(new WaitingTestCase(
+            WaitingTscOverallLogCount + 1, OneAndHalfRecordTime, false, [
+                "Started",
+                "Right after starting the background action",
+                $"{WaitingTscLogAttemptPrefix} #001",
+                "Checking if should end waiting #1",
+                "Finished waiting for the log",
+                $"{WaitingTscLogAttemptPrefix} #002",
+                $"{WaitingTscLogAttemptPrefix} #003",
+                "Background action has finished"
+            ],
+            true
+        ));
+
+        // Waiting for many log records, but starting with cancellation token already cancelled.
+        testCases.Add(new WaitingTestCase(
+            WaitingTscOverallLogCount, null, true, [
+                "Started",
+                "Right after starting the background action",
+                "Finished waiting for the log",
+                $"{WaitingTscLogAttemptPrefix} #001",
+                $"{WaitingTscLogAttemptPrefix} #002",
+                $"{WaitingTscLogAttemptPrefix} #003",
+                "Background action has finished"
+            ],
+            true
+        ));
+
+        // Waiting for single log record and supplying a cancellation period that would match three logs to get writter
+        testCases.Add(new WaitingTestCase(
+            1, 3 * WaitingTscOneLogTimeInMs, false, [
+                "Started",
+                "Right after starting the background action",
+                $"{WaitingTscLogAttemptPrefix} #001",
+                "Checking if should end waiting #1",
+                "Finished waiting for the log",
+                $"{WaitingTscLogAttemptPrefix} #002",
+                $"{WaitingTscLogAttemptPrefix} #003",
+                "Background action has finished"
+            ],
+            false
+        ));
+
+        return testCases;
+    }
 }