Warning log event is filtered but never shows up in the actual log #6354
Labels
Comments
Aaronontheweb
added
akka-testkit
|
Looks like this might be a testkit bug - going to mark this issue as "up for grabs" in case any new contributors are interested |
F0b0s
added a commit
to F0b0s/akka.net
that referenced
this issue
Jan 24, 2023
3 tasks
|
I modified the following test: [Fact]
public async Task Unhandled_message_should_produce_info_message()
{
await EventFilter
.Info(new Regex("^Unhandled message from"))
.ExpectOneAsync(() => {
_unhandledMessageActor.Tell("whatever");
return Task.CompletedTask;
});
}To: [Fact]
public async Task Unhandled_message_should_produce_info_message()
{
await EventFilter
.Info()
.ExpectOneAsync(() => {
_unhandledMessageActor.Tell("whatever");
return Task.CompletedTask;
});
}This caused the test to fail. Test log:
Akka.TestKit.Tests.TestEventListenerTests.UnhandledMessageEventFilterTests.Unhandled_message_should_produce_info_message
Source: UnhandledMessageEventFilterTests.cs line 32
Duration: 2.2 sec
Message:
Received 1 message too many. Expected 1 message but received 2 that matched filter [Info]
Expected: True
Actual: False
Stack Trace:
XunitAssertions.Fail(String format, Object[] args) line 26
<InterceptAsync>d__32`1.MoveNext() line 526
--- End of stack trace from previous location where exception was thrown ---
ExceptionDispatchInfo.Throw()
TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
ConfiguredTaskAwaiter.GetResult()
<InternalExpectAsync>d__36.MoveNext() line 602
--- End of stack trace from previous location where exception was thrown ---
ExceptionDispatchInfo.Throw()
TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
ConfiguredTaskAwaiter.GetResult()
<ExpectOneAsync>d__6.MoveNext() line 80
--- End of stack trace from previous location where exception was thrown ---
ExceptionDispatchInfo.Throw()
TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
TaskAwaiter.GetResult()
<Unhandled_message_should_produce_info_message>d__3.MoveNext() line 34
--- End of stack trace from previous location where exception was thrown ---
ExceptionDispatchInfo.Throw()
TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
--- End of stack trace from previous location where exception was thrown ---
ExceptionDispatchInfo.Throw()
TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
--- End of stack trace from previous location where exception was thrown ---
ExceptionDispatchInfo.Throw()
TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)When I run with logging enabled: ..Actors.Specs.MessageSpecs.MessageThatWillNotBeHandledSpec.Spec
Source: MessageThatWillNotBeHandledSpec.cs line 35
Duration: 677 ms
Standard Output:
[DEBUG][03/20/2023 05:23:06.045Z][Thread 0010][EventStream] subscribing [akka://test/system/log-test#447241130] to channel Akka.Event.LogEvent
[DEBUG][03/20/2023 05:23:06.045Z][Thread 0118][EventStreamUnsubscriber] watching [akka://test/system/log-test#447241130] in order to unsubscribe from EventStream when it terminates
[DEBUG][03/20/2023 05:23:06.045Z][Thread 0010][akka://test/system/log-test] now watched by [akka://test/system/EventStreamUnsubscriber-2#883213924]
[DEBUG][03/20/2023 05:23:06.058Z][Thread 0296][akka://test/system/deadLetterListener] now watched by [akka://test/system/EventStreamUnsubscriber-2#883213924]
[DEBUG][03/20/2023 05:23:06.066Z][Thread 0036][akka://test/user] now supervising akka://test/user/$a
[DEBUG][03/20/2023 05:23:06.067Z][Thread 0287][akka://test/user/$a] Started (UnhandledMessageActor)
[DEBUG][03/20/2023 05:23:06.085Z][Thread 0294][akka://test/user/$a] Unhandled message from akka://test/system/testActor1 : whatever
[INFO][03/20/2023 05:23:06.086Z][Thread 0290][akka://test/user/$a] Message [String] from [akka://test/system/testActor1#551529727] to [akka://test/user/$a#37104401] was unhandled. [1] dead letters encountered. This logging can be turned off or adjusted with configuration settings 'akka.log-dead-letters' and 'akka.log-dead-letters-during-shutdown'. Message content: whatever
[DEBUG][03/20/2023 05:23:06.113Z][Thread 0025][CoordinatedShutdown (akka://test)] Performing phase [before-service-unbind] with [0] tasks.
[DEBUG][03/20/2023 05:23:06.173Z][Thread 0290][CoordinatedShutdown (akka://test)] Performing phase [service-unbind] with [0] tasks.
[DEBUG][03/20/2023 05:23:06.173Z][Thread 0290][CoordinatedShutdown (akka://test)] Performing phase [service-requests-done] with [0] tasks.
[DEBUG][03/20/2023 05:23:06.173Z][Thread 0290][CoordinatedShutdown (akka://test)] Performing phase [service-stop] with [0] tasks.
[DEBUG][03/20/2023 05:23:06.173Z][Thread 0290][CoordinatedShutdown (akka://test)] Performing phase [before-cluster-shutdown] with [0] tasks.
[DEBUG][03/20/2023 05:23:06.173Z][Thread 0290][CoordinatedShutdown (akka://test)] Performing phase [cluster-sharding-shutdown-region] with [0] tasks.
[DEBUG][03/20/2023 05:23:06.173Z][Thread 0290][CoordinatedShutdown (akka://test)] Performing phase [cluster-leave] with [0] tasks.
[DEBUG][03/20/2023 05:23:06.173Z][Thread 0290][CoordinatedShutdown (akka://test)] Performing phase [cluster-exiting] with [0] tasks.
[DEBUG][03/20/2023 05:23:06.173Z][Thread 0290][CoordinatedShutdown (akka://test)] Performing phase [cluster-exiting-done] with [0] tasks.
[DEBUG][03/20/2023 05:23:06.173Z][Thread 0290][CoordinatedShutdown (akka://test)] Performing phase [cluster-shutdown] with [0] tasks.
[DEBUG][03/20/2023 05:23:06.173Z][Thread 0290][CoordinatedShutdown (akka://test)] Performing phase [before-actor-system-terminate] with [0] tasks.
[DEBUG][03/20/2023 05:23:06.184Z][Thread 0290][CoordinatedShutdown (akka://test)] Performing phase [actor-system-terminate] with [1] tasks: [terminate-system]
[DEBUG][03/20/2023 05:23:06.187Z][Thread 0290][ActorSystem(test)] System shutdown initiated
[DEBUG][03/20/2023 05:23:06.195Z][Thread 0150][akka://test/user] Stopping
[DEBUG][03/20/2023 05:23:06.195Z][Thread 0295][EventStream] unsubscribing [akka://test/system/deadLetterListener#820708298] from all channels
[DEBUG][03/20/2023 05:23:06.196Z][Thread 0186][EventStreamUnsubscriber] unwatching [akka://test/system/deadLetterListener#820708298] since has no subscriptions
[DEBUG][03/20/2023 05:23:06.200Z][Thread 0296][akka://test/user/$a] Stopped
[DEBUG][03/20/2023 05:23:06.201Z][Thread 0295][akka://test/system/deadLetterListener] Stopped
[DEBUG][03/20/2023 05:23:06.203Z][Thread 0169][akka://test/user] Stopped
[DEBUG][03/20/2023 05:23:06.207Z][Thread 0250][akka://test/system] received AutoReceiveMessage <Terminated>: [akka://test/user] - ExistenceConfirmed=True
[DEBUG][03/20/2023 05:23:06.210Z][Thread 0250][EventStream] subscribing [akka://all-systems/] to channel Akka.Event.Debug
[DEBUG][03/20/2023 05:23:06.210Z][Thread 0234][EventStreamUnsubscriber] watching [akka://all-systems/] in order to unsubscribe from EventStream when it terminates
[DEBUG][03/20/2023 05:23:06.212Z][Thread 0250][EventStream] subscribing [akka://all-systems/] to channel Akka.Event.Info
[DEBUG][03/20/2023 05:23:06.216Z][Thread 0234][EventStreamUnsubscriber] watching [akka://all-systems/] in order to unsubscribe from EventStream when it terminates
[DEBUG][03/20/2023 05:23:06.217Z][Thread 0250][EventStream] subscribing [akka://all-systems/] to channel Akka.Event.WarningAs can be seen, only one info message is visible. |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
I created a repository to reproduce this issue.
https://github.com/brah-mcdude/MyCompany.Akka.TestKit
As can be seen in the log, I received mostly debug messages and one info message. But no warning messages.
But the Predicate filters error and warnings.
When debugging, I saw that a warning message is generated. But it is never displayed in the log.
Here is the debug-watch warning log-event that is filtered:
Here is the entire log:
The text was updated successfully, but these errors were encountered: