Skip to content

WIP LogFiltering integration #289

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.

Sign up for GitHub

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

Draft
wants to merge 2 commits into
base: dev
Choose a base branch
from
Draft

WIP LogFiltering integration #289

Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
e0a8481
WIP LogFiltering integration
Aaronontheweb Jun 4, 2024
2421cc4
Merge branch 'dev' into log-filtering
Aaronontheweb Jun 4, 2024
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
29 changes: 25 additions & 4 deletions src/Akka.Logger.Serilog/SerilogLogger.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -24,6 +24,10 @@ namespace Akka.Logger.Serilog
/// </summary>
public class SerilogLogger : ReceiveActor, IRequiresMessageQueue<ILoggerMessageQueueSemantics>
{
/// <summary>
/// Log filter. See https://getakka.net/articles/utilities/logging.html#filtering-log-messages for details.
/// </summary>
public LogFilterEvaluator Filter { get; }
private readonly ILoggingAdapter _log = Logging.GetLogger(Context.System.EventStream, "SerilogLogger");

[MethodImpl(MethodImplOptions.AggressiveInlining)]
Expand Down Expand Up @@ -97,10 +101,27 @@ private static void Handle(Debug logEvent)
/// </summary>
public SerilogLogger()
{
Receive<Error>(Handle);
Receive<Warning>(Handle);
Receive<Info>(Handle);
Receive<Debug>(Handle);
Filter = Context.System.Settings.LogFilter;
Receive<Error>(e =>
{
if(Filter.ShouldTryKeepMessage(e, out _))
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

So the out _ we are discarding here is a pre-computed version of the entire formatted output string from the ILogFormatter. If the user has specified log filtering rules that look at the content of the string payload, it's necessary for us to expand it ahead of time.

If the user only looks at the LogSource then this may not be necessary - we can exclude a log without expanding it first (good for performance.)

However, the worst case scenario is what we're doing here: we expand the log once using the SerilogLogFormatter, check the output, discard it, and then format it again using a totally different algorithm.

My questions are:

  1. Do we still need all of the custom formatting done by this class? Is the SerilogLogFormatterr enough?
  2. If we still need to do all of this formatting, are we absolutely killing the perf of this logger if we allow filtering by log message? We warn in the docs that this setting is for reducing the amount of noise in the logs and will likely have a performance impact, but still - double-formatting is something I would like to avoid if at all possible.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ah the LogFilter expands a message simply by doing a Message.ToString(). This will not contain all the extra details that the SerilogLogger allows for. At least not in its current implementation.
This also means that any content filters will never be able to work on any of the metadata that serilog provides. So the extra LogContext enrichers and any custom registered enrichers will not be available for evaluation by the LogFilter. This seems like an important aspect to note in the documentation.

Considering that Serilog does its own formatting with those enrichers internally. And the api for that (getting a formatted message) is as far as i know (haven't looked very far admittedly) not public. We will probably not be able to provide this feature in such a way.

I do see some other issues in the SerilogLogger implementation. In the past years LogContext support and enrichters have been added. See the GetLogger function at line 54.

I cant add any comments there directly in github for reasons unknown. But the Log.Logger.ForContext api causes an issue that any Log context thats added is persisted on the logger. Instead we should be using the disposable LogContext api there.

using (LogContext.PushProperty("contextname", contextvalue))
{
 using (LogContext.PushProperty() ..//more properties if needed
}

See: https://github.com/serilog/serilog/wiki/Enrichment#the-logcontext

Also this should then probably not be done in the GetLogger function as these LogContext calls should wrap the actual logging call to serilog.

Also the https://github.com/serilog/serilog/wiki/Enrichment#the-logcontext does not seem to allow to set multiple Context Properties. As you seem to get a new logging adapter on each call. I also think thats an outstanding bug.

All those issues aside. I think there is little chance of avoiding the double expand. Although i think the initial expand done by the LoggingFilter, as its a Message.ToString() Is very harmless because unless im remembering wrong, the object message here is practically always a string.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think there is little chance of avoiding the double expand. Although i think the initial expand done by the LoggingFilter, as its a Message.ToString() Is very harmless because unless im remembering wrong, the object message here is practically always a string.

That was my worry and my conclusion too - thank you for confirming.

Handle(e);
});
Receive<Warning>(w =>
{
if(Filter.ShouldTryKeepMessage(w, out _))
Handle(w);
});
Receive<Info>(i =>
{
if(Filter.ShouldTryKeepMessage(i, out _))
Handle(i);
});
Receive<Debug>(d =>
{
if(Filter.ShouldTryKeepMessage(d, out _))
Handle(d);
});
Receive<InitializeLogger>(_ =>
{
_log.Info("SerilogLogger started");
Expand Down