From 35dfbe2a45486c61993054e3d5bfa50e87fe7567 Mon Sep 17 00:00:00 2001 From: Aaron Stannard Date: Thu, 24 Sep 2026 03:40:48 +0000 Subject: [PATCH] LoggerStartupSpec: gate the slow logger on the test instead of a fixed 1 s delay ActorSystem_should_start_with_loggers_timing_out failed on a 2-vCPU Windows agent: the test subscribes its probe to the EventStream after ActorSystem.Create returns, but on a starved agent the slow logger's 1 s delay elapsed first and LoggingBus published its one-shot "Logger ... started" Debug 1 ms before the subscription existed. The EventStream doesn't replay, so the sync ExpectMsg ate the whole AwaitAssert budget. SlowLoggerActor now answers InitializeLogger only when the test opens a gate, after it has subscribed. The gate is shut for all of Create, so the logger still always misses the 100 ms logger-startup-timeout - which is what the test is about - and the started Debug can no longer be published before anyone is listening. The two sync ExpectMsg-inside-AwaitAssert checks become FishForMessageAsync, since both probes also receive other messages. --- .../Akka.Tests/Loggers/LoggerStartupSpec.cs | 29 ++++++++++--------- 1 file changed, 15 insertions(+), 14 deletions(-) diff --git a/src/core/Akka.Tests/Loggers/LoggerStartupSpec.cs b/src/core/Akka.Tests/Loggers/LoggerStartupSpec.cs index 98e5ec571e5..f6e99b56fe8 100644 --- a/src/core/Akka.Tests/Loggers/LoggerStartupSpec.cs +++ b/src/core/Akka.Tests/Loggers/LoggerStartupSpec.cs @@ -19,8 +19,6 @@ namespace Akka.Tests.Loggers { public class LoggerStartupSpec : TestKit.Xunit.TestKit { - private const int LoggerResponseDelayMs = 1_000; - public LoggerStartupSpec(ITestOutputHelper helper) : base(nameof(LoggerStartupSpec), helper) { XUnitOutLogger.Helper = helper; @@ -43,6 +41,10 @@ public async Task ActorSystem_should_start_with_loggers_timing_out(bool useAsync var config = ConfigurationFactory.ParseString($"akka.logger-async-start = {(useAsync ? "true" : "false")}") .WithFallback(slowLoggerConfig); + // The slow logger answers InitializeLogger only once this gate opens, and the gate stays shut + // for all of ActorSystem.Create - so the logger always misses the 100 ms startup window, and + // the LoggingBus announces it as started only after the test is already subscribed. + SlowLoggerActor.Release = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously); ActorSystem sys = null; try { @@ -53,22 +55,20 @@ public async Task ActorSystem_should_start_with_loggers_timing_out(bool useAsync var logProbe = CreateTestProbe(sys); sys.EventStream.Subscribe(logProbe, typeof(LogEvent)); + SlowLoggerActor.Release.SetResult(Done.Instance); + // Logger actor should eventually initialize - await AwaitAssertAsync(() => - { - var dbg = logProbe.ExpectMsg(); - dbg.Message.ToString().Should().Contain(nameof(SlowLoggerActor)).And.Contain("started"); - }); - + await logProbe.FishForMessageAsync( + dbg => dbg.Message.ToString().Contains(nameof(SlowLoggerActor)) && dbg.Message.ToString().Contains("started"), + TimeSpan.FromSeconds(5)); + var logger = Logging.GetLogger(sys, this); logger.Error("TEST"); - await AwaitAssertAsync(() => - { - probe.ExpectMsg().Should().Be("TEST"); - }); + await probe.FishForMessageAsync(msg => msg == "TEST", TimeSpan.FromSeconds(5)); } finally { + SlowLoggerActor.Release.TrySetResult(Done.Instance); if(sys != null) Shutdown(sys); } @@ -168,6 +168,8 @@ protected override bool Receive(object message) private class SlowLoggerActor : ActorBase, IWithUnboundedStash, IRequiresMessageQueue { public static TestProbe Probe; + + public static TaskCompletionSource Release; public SlowLoggerActor() { @@ -179,8 +181,7 @@ private bool Starting(object message) switch (message) { case InitializeLogger _: - var sender = Sender; - Task.Delay(LoggerResponseDelayMs).PipeTo(Self, sender, success: () => Done.Instance); + Release.Task.PipeTo(Self, Sender); Become(Initializing); return true; default: