Skip to content

Commit c8b46b4

Browse files
ArkatufusAaronontheweb
Arkatufus
and
Aaronontheweb
authored
Fix faulty AddLogger in LoggingBus (#6028)
* Fix faulty AddLogger in LoggingBus * Ignore logger async start setting, not relevant anymore * Simplify unit test * Send Stop instead of PoisonPill * Make loggers load asynchronously by default * Change logging back to exceptions * Remove _startupState, use closure instead Co-authored-by: Aaron Stannard <aaron@petabridge.com>
1 parent fc2ed1a commit c8b46b4

File tree

2 files changed

+285
-74
lines changed

2 files changed

+285
-74
lines changed

‎src/core/Akka.Tests/Loggers/LoggerStartupSpec.cs

+203-21
Original file line numberDiff line numberDiff line change
@@ -9,47 +9,229 @@
99
using System.Threading.Tasks;
1010
using Akka.Actor;
1111
using Akka.Configuration;
12+
using Akka.Dispatch;
1213
using Akka.Event;
14+
using Akka.TestKit;
1315
using FluentAssertions;
1416
using Xunit;
17+
using Xunit.Abstractions;
1518

1619
namespace Akka.Tests.Loggers
1720
{
1821
public class LoggerStartupSpec : TestKit.Xunit2.TestKit
1922
{
20-
private const int LoggerResponseDelayMs = 10_000;
23+
private const int LoggerResponseDelayMs = 1_000;
24+
25+
public LoggerStartupSpec(ITestOutputHelper helper) : base(nameof(LoggerStartupSpec), helper)
26+
{
27+
XUnitOutLogger.Helper = helper;
28+
}
2129

22-
[Fact]
23-
public async Task Logger_async_start_configuration_helps_to_ignore_hanging_loggers()
30+
[Theory(DisplayName = "ActorSystem should start with loggers timing out")]
31+
[InlineData(false)]
32+
[InlineData(true)]
33+
public async Task ActorSystem_should_start_with_loggers_timing_out(bool useAsync)
2434
{
25-
var loggerAsyncStartDisabledConfig = ConfigurationFactory.ParseString($"akka.logger-async-start = false");
26-
var loggerAsyncStartEnabledConfig = ConfigurationFactory.ParseString($"akka.logger-async-start = true");
27-
28-
var slowLoggerConfig = ConfigurationFactory.ParseString($"akka.loggers = [\"{typeof(SlowLoggerActor).FullName}, {typeof(SlowLoggerActor).Assembly.GetName().Name}\"]");
35+
var slowLoggerConfig = ConfigurationFactory.ParseString($@"
36+
akka.loglevel = DEBUG
37+
akka.stdout-logger-class = ""{typeof(XUnitOutLogger).FullName}, {typeof(XUnitOutLogger).Assembly.GetName().Name}""
38+
akka.loggers = [
39+
""Akka.Event.DefaultLogger"",
40+
""{typeof(SlowLoggerActor).FullName}, {typeof(SlowLoggerActor).Assembly.GetName().Name}""
41+
]
42+
akka.logger-startup-timeout = 100ms").WithFallback(DefaultConfig);
2943

30-
// Without logger async start, ActorSystem creation will hang
31-
this.Invoking(_ => ActorSystem.Create("handing", slowLoggerConfig.WithFallback(loggerAsyncStartDisabledConfig))).Should()
32-
.Throw<Exception>("System can not start - logger timed out");
33-
34-
// With logger async start, ActorSystem is created without issues
35-
// Created without timeouts
36-
var system = ActorSystem.Create("working", slowLoggerConfig.WithFallback(loggerAsyncStartEnabledConfig));
44+
var config = ConfigurationFactory.ParseString($"akka.logger-async-start = {(useAsync ? "true" : "false")}")
45+
.WithFallback(slowLoggerConfig);
46+
47+
ActorSystem sys = null;
48+
try
49+
{
50+
this.Invoking(_ => sys = ActorSystem.Create("test", config)).Should()
51+
.NotThrow("System should not fail to start when a logger timed out");
52+
var probe = CreateTestProbe(sys);
53+
SlowLoggerActor.Probe = probe;
54+
var logProbe = CreateTestProbe(sys);
55+
sys.EventStream.Subscribe(logProbe, typeof(LogEvent));
56+
57+
// Logger actor should eventually initialize
58+
await AwaitAssertAsync(() =>
59+
{
60+
var dbg = logProbe.ExpectMsg<Debug>();
61+
dbg.Message.ToString().Should().Contain(nameof(SlowLoggerActor)).And.Contain("started");
62+
});
63+
64+
var logger = Logging.GetLogger(sys, this);
65+
logger.Error("TEST");
66+
await AwaitAssertAsync(() =>
67+
{
68+
probe.ExpectMsg<string>().Should().Be("TEST");
69+
});
70+
}
71+
finally
72+
{
73+
if(sys != null)
74+
Shutdown(sys);
75+
}
76+
}
77+
78+
[Theory(DisplayName = "ActorSystem should start with loggers throwing exceptions")]
79+
[InlineData("ctor")]
80+
[InlineData("PreStart")]
81+
[InlineData("Receive")]
82+
public void ActorSystem_should_start_with_logger_exception(string when)
83+
{
84+
var config = ConfigurationFactory.ParseString($@"
85+
akka.loglevel = DEBUG
86+
akka.stdout-logger-class = ""{typeof(XUnitOutLogger).FullName}, {typeof(XUnitOutLogger).Assembly.GetName().Name}""
87+
akka.loggers = [
88+
""Akka.Event.DefaultLogger"",
89+
""{typeof(ThrowingLogger).FullName}, {typeof(ThrowingLogger).Assembly.GetName().Name}""
90+
]
91+
akka.logger-startup-timeout = 100ms").WithFallback(DefaultConfig);
92+
93+
ThrowingLogger.ThrowWhen = when;
94+
ActorSystem sys = null;
95+
try
96+
{
97+
this.Invoking(_ => sys = ActorSystem.Create("test", config)).Should()
98+
.NotThrow("System should not fail to start when a logger throws an exception");
99+
}
100+
finally
101+
{
102+
if(sys != null)
103+
Shutdown(sys);
104+
}
37105
}
38106

39-
public class SlowLoggerActor : ReceiveActor
107+
[Fact(DisplayName = "ActorSystem should throw and fail to start on invalid logger FQCN entry")]
108+
public void ActorSystem_should_fail_on_invalid_logger()
40109
{
41-
public SlowLoggerActor()
110+
var config = ConfigurationFactory.ParseString($@"
111+
akka.loglevel = DEBUG
112+
akka.stdout-logger-class = ""{typeof(XUnitOutLogger).FullName}, {typeof(XUnitOutLogger).Assembly.GetName().Name}""
113+
akka.loggers = [
114+
""Akka.Event.InvalidLogger, NonExistantAssembly""
115+
]
116+
akka.logger-startup-timeout = 100ms").WithFallback(DefaultConfig);
117+
118+
ActorSystem sys = null;
119+
try
120+
{
121+
this.Invoking(_ => sys = ActorSystem.Create("test", config)).Should()
122+
.ThrowExactly<ConfigurationException>("System should fail to start with invalid logger FQCN");
123+
}
124+
finally
125+
{
126+
if(sys != null)
127+
Shutdown(sys);
128+
}
129+
}
130+
131+
private class TestException: Exception
132+
{
133+
public TestException(string message) : base(message)
134+
{ }
135+
}
136+
137+
private class ThrowingLogger : ActorBase, IRequiresMessageQueue<ILoggerMessageQueueSemantics>
138+
{
139+
public static string ThrowWhen = "Receive";
140+
141+
public ThrowingLogger()
42142
{
43-
ReceiveAsync<InitializeLogger>(async _ =>
143+
if(ThrowWhen == "ctor")
144+
throw new TestException(".ctor BOOM!");
145+
}
146+
147+
protected override void PreStart()
148+
{
149+
base.PreStart();
150+
if(ThrowWhen == "PreStart")
151+
throw new TestException("PreStart BOOM!");
152+
}
153+
154+
protected override bool Receive(object message)
155+
{
156+
if(message is InitializeLogger)
44157
{
45-
// Ooops... Logger is responding too slow
46-
await Task.Delay(LoggerResponseDelayMs);
158+
if(ThrowWhen == "Receive")
159+
throw new TestException("Receive BOOM!");
160+
47161
Sender.Tell(new LoggerInitialized());
48-
});
162+
return true;
163+
}
164+
165+
return false;
166+
}
167+
}
168+
169+
private class SlowLoggerActor : ActorBase, IWithUnboundedStash, IRequiresMessageQueue<ILoggerMessageQueueSemantics>
170+
{
171+
public static TestProbe Probe;
172+
173+
public SlowLoggerActor()
174+
{
175+
Become(Starting);
49176
}
50177

51-
private void Log(LogLevel level, string str)
178+
private bool Starting(object message)
179+
{
180+
switch (message)
181+
{
182+
case InitializeLogger _:
183+
var sender = Sender;
184+
Task.Delay(LoggerResponseDelayMs).PipeTo(Self, sender, success: () => Done.Instance);
185+
Become(Initializing);
186+
return true;
187+
default:
188+
Stash.Stash();
189+
return true;
190+
}
191+
}
192+
193+
private bool Initializing(object message)
194+
{
195+
switch (message)
196+
{
197+
case Done _:
198+
Sender.Tell(new LoggerInitialized());
199+
Become(Initialized);
200+
Stash.UnstashAll();
201+
return true;
202+
default:
203+
Stash.Stash();
204+
return true;
205+
}
206+
}
207+
208+
private bool Initialized(object message)
209+
{
210+
switch (message)
211+
{
212+
case LogEvent evt:
213+
Probe.Tell(evt.Message.ToString());
214+
return true;
215+
default:
216+
return false;
217+
}
218+
}
219+
220+
protected override bool Receive(object message)
221+
{
222+
throw new NotImplementedException();
223+
}
224+
225+
public IStash Stash { get; set; }
226+
}
227+
228+
public class XUnitOutLogger : MinimalLogger
229+
{
230+
public static ITestOutputHelper Helper;
231+
232+
protected override void Log(object message)
52233
{
234+
Helper.WriteLine(message.ToString());
53235
}
54236
}
55237
}

0 commit comments

Comments
 (0)