Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Fix faulty AddLogger in LoggingBus #6028

Merged
merged 10 commits into from Jul 27, 2022
67 changes: 51 additions & 16 deletions src/core/Akka.Tests/Loggers/LoggerStartupSpec.cs
Expand Up @@ -10,34 +10,59 @@
using Akka.Actor;
using Akka.Configuration;
using Akka.Event;
using Akka.TestKit;
using FluentAssertions;
using FluentAssertions.Extensions;
using Xunit;
using Xunit.Abstractions;

namespace Akka.Tests.Loggers
{
public class LoggerStartupSpec : TestKit.Xunit2.TestKit
{
private const int LoggerResponseDelayMs = 10_000;
private const int LoggerResponseDelayMs = 1_000;

public LoggerStartupSpec(ITestOutputHelper helper) : base(nameof(LoggerStartupSpec), helper)
{
XUnitOutLogger.Helper = helper;
}

[Fact]
public async Task Logger_async_start_configuration_helps_to_ignore_hanging_loggers()
[Theory]
[InlineData(false)]
[InlineData(true)]
public void ActorSystem_should_start_with_loggers_timing_out(bool useAsync)
{
var loggerAsyncStartDisabledConfig = ConfigurationFactory.ParseString($"akka.logger-async-start = false");
var loggerAsyncStartEnabledConfig = ConfigurationFactory.ParseString($"akka.logger-async-start = true");
var slowLoggerConfig = ConfigurationFactory.ParseString($"akka.loggers = [\"{typeof(SlowLoggerActor).FullName}, {typeof(SlowLoggerActor).Assembly.GetName().Name}\"]");
var slowLoggerConfig = ConfigurationFactory.ParseString($@"
akka.stdout-logger-class = ""{typeof(XUnitOutLogger).FullName}, {typeof(XUnitOutLogger).Assembly.GetName().Name}""
akka.loggers = [""{typeof(SlowLoggerActor).FullName}, {typeof(SlowLoggerActor).Assembly.GetName().Name}""]
akka.logger-startup-timeout = 100ms").WithFallback(DefaultConfig);

// Without logger async start, ActorSystem creation will hang
this.Invoking(_ => ActorSystem.Create("handing", slowLoggerConfig.WithFallback(loggerAsyncStartDisabledConfig))).Should()
.Throw<Exception>("System can not start - logger timed out");

// With logger async start, ActorSystem is created without issues
// Created without timeouts
var system = ActorSystem.Create("working", slowLoggerConfig.WithFallback(loggerAsyncStartEnabledConfig));
var config = ConfigurationFactory.ParseString($"akka.logger-async-start = {(useAsync ? "true" : "false")}")
.WithFallback(slowLoggerConfig);

ActorSystem sys = null;
try
{
this.Invoking(_ => sys = ActorSystem.Create("test", config)).Should()
.NotThrow("System should not fail to start when a logger timed out when logger is created synchronously");

// Logger actor should die
var probe = CreateTestProbe(sys);
SlowLoggerActor.Probe = probe;
Logging.GetLogger(sys, this).Error("TEST");
probe.ExpectNoMsg(200.Milliseconds());
}
finally
{
if(sys != null)
Shutdown(sys);
}
}

public class SlowLoggerActor : ReceiveActor
{
public static TestProbe Probe;

public SlowLoggerActor()
{
ReceiveAsync<InitializeLogger>(async _ =>
Expand All @@ -46,10 +71,20 @@ public SlowLoggerActor()
await Task.Delay(LoggerResponseDelayMs);
Sender.Tell(new LoggerInitialized());
});
Receive<LogEvent>(log =>
{
Probe.Tell(log.Message);
});
}
}

private void Log(LogLevel level, string str)
public class XUnitOutLogger : MinimalLogger
{
public static ITestOutputHelper Helper;

protected override void Log(object message)
{
Helper.WriteLine(message.ToString());
}
}
}
Expand Down
28 changes: 7 additions & 21 deletions src/core/Akka/Event/LoggingBus.cs
Expand Up @@ -91,7 +91,6 @@ internal void StartDefaultLoggers(ActorSystemImpl system)
var logLevel = Logging.LogLevelFor(system.Settings.LogLevel);
var loggerTypes = system.Settings.Loggers;
var timeout = system.Settings.LoggerStartTimeout;
var asyncStart = system.Settings.LoggerAsyncStart;
var shouldRemoveStandardOutLogger = true;

foreach (var strLoggerType in loggerTypes)
Expand All @@ -108,28 +107,13 @@ internal void StartDefaultLoggers(ActorSystemImpl system)
continue;
}

if (asyncStart)
Aaronontheweb marked this conversation as resolved.
Show resolved Hide resolved
try
{
// Not awaiting for result, and not depending on current thread context
Task.Run(() => AddLogger(system, loggerType, logLevel, logName, timeout))
.ContinueWith(t =>
{
if (t.Exception != null)
{
Console.WriteLine($"Logger [{strLoggerType}] specified in config cannot be loaded: {t.Exception}");
}
});
AddLogger(system, loggerType, logLevel, logName, timeout);
}
else
catch (Exception ex)
{
try
{
AddLogger(system, loggerType, logLevel, logName, timeout);
}
catch (Exception ex)
{
throw new ConfigurationException($"Logger [{strLoggerType}] specified in config cannot be loaded: {ex}", ex);
}
throw new ConfigurationException($"Logger [{strLoggerType}] specified in config cannot be loaded: {ex}", ex);
}
}

Expand Down Expand Up @@ -188,12 +172,14 @@ private void AddLogger(ActorSystemImpl system, Type loggerType, LogLevel logLeve
object response = null;
try
{
response = askTask.Result;
Arkatufus marked this conversation as resolved.
Show resolved Hide resolved
response = askTask.ConfigureAwait(false).GetAwaiter().GetResult();
}
catch (Exception ex) when (ex is TaskCanceledException || ex is AskTimeoutException)
{
Publish(new Warning(loggingBusName, GetType(),
string.Format("Logger {0} [{2}] did not respond within {1} to InitializeLogger(bus)", loggerName, timeout, loggerType.FullName)));
logger.Tell(PoisonPill.Instance);
return;
Arkatufus marked this conversation as resolved.
Show resolved Hide resolved
}

if (!(response is LoggerInitialized))
Expand Down