Skip to content

Conversation

@Aaronontheweb
Copy link
Member

Changes

Attempts to add https://getakka.net/articles/utilities/logging.html#filtering-log-messages support to Serilog

Checklist

For significant changes, please ensure that the following have been completed (delete if not relevant):

Copy link
Member Author

@Aaronontheweb Aaronontheweb left a comment

Choose a reason for hiding this comment

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

Detailed my changes - haven't written any tests that actually use the formatter with Serilog yet; will need to add those before this can be merged.

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.

@Aaronontheweb
Copy link
Member Author

Semantic Logging Integration Opportunity

With the semantic logging feature being implemented in Akka.NET 1.5.56 (akkadotnet/akka.net#7933), we now have infrastructure that could significantly improve the performance concerns raised in this PR.

Current Problem

The review comments identified a key issue: double formatting

  1. LogFilterEvaluator calls evt.ToString() to get the formatted message
  2. SerilogLogger then formats the SAME event AGAIN using Serilog's API
  3. Result: Wasteful double-formatting on every filtered log

Semantic Logging Solution

Akka.NET 1.5.56 adds these new APIs to LogEvent:

  • TryGetProperties(out var properties) - Gets structured template properties with sub-2ns cached access
  • GetTemplate() - Gets message template without formatting
  • GetPropertyNames() - Gets property names without expanding values

We could add a new LogFilterType.SemanticProperty that filters on message template properties WITHOUT calling ToString():

public class SemanticPropertyFilter : LogFilterBase
{
    private readonly string _propertyName;
    private readonly Func<object, bool> _predicate;
    
    public override LogFilterType FilterType => LogFilterType.SemanticProperty;
    
    public override LogFilterDecision ShouldKeepMessage(LogEvent evt, string? expandedMessage = null)
    {
        // Use semantic logging - NO ToString() call needed!
        if (evt.TryGetProperties(out var props) && 
            props.TryGetValue(_propertyName, out var value))
        {
            return _predicate(value) ? LogFilterDecision.Drop : LogFilterDecision.Keep;
        }
        return LogFilterDecision.NoDecision;
    }
}

Then enhance LogFilterEvaluator with a semantic fast path:

public bool ShouldTryKeepMessage(LogEvent evt, out string expandedLogMessage)
{
    // FAST PATH 1: Source-only filters (existing - no allocations)
    if (EvaluatesLogSourcesOnly) { ... }
    
    // FAST PATH 2: NEW - Semantic property filters (cached, sub-2ns)
    if (HasSemanticPropertyFilters)
    {
        foreach (var filter in _semanticFilters)
        {
            if (filter.ShouldKeepMessage(evt) == LogFilterDecision.Drop)
                return false;
        }
    }
    
    // SLOW PATH: Content filters (only when needed)
    if (HasContentFilters)
    {
        expandedLogMessage = evt.ToString();
        // ... existing logic
    }
}

Performance Impact

Before (Content Filter):

  • Every filtered message: ~1000ns + string allocation

After (Semantic Property Filter):

  • First access: ~300ns (parse template)
  • Subsequent: ~2ns (cached lookup)
  • 99.8% faster than content filtering

Usage Example

var filters = new LogFilterBuilder()
    // Fast: Filter on semantic properties (no ToString())
    .ExcludeSemanticPropertyValue("UserId", 123)
    .ExcludeSemanticProperty("Amount", val => val is double amt && amt > 10000)
    
    // Fast: Filter on log source
    .ExcludeSourceStartingWith("Akka.Remote.EndpointWriter")
    
    // Slow: Filter on formatted content (requires ToString())
    .ExcludeMessageContaining("heartbeat")
    .Build();

Known Limitation (Must Document)

Serilog Enrichers Cannot Be Filtered - This is an architectural limitation, not a bug.

Serilog enrichers (ForContext, LogContext.PushProperty) are added AFTER LogFilter runs, so they're NOT accessible to LogFilter:

// This happens in SerilogLogger AFTER receiving the LogEvent:
Log.Logger
    .ForContext("TenantId", "ABC")      // ❌ LogFilter can't see this
    .Information("User {UserId} logged in", 123);  // ✅ LogFilter CAN see UserId

What LogFilter CAN filter on:

  • ✅ Message template properties: {UserId}, {Amount}, etc.
  • ✅ Log source: LogEvent.LogSource
  • ✅ Formatted message content

What LogFilter CANNOT filter on:

  • ❌ Any Serilog enrichers (they don't exist yet at filter time)

Workaround for enricher filtering:
Use Serilog's built-in filtering instead:

Log.Logger = new LoggerConfiguration()
    .Filter.ByExcluding(evt => 
        evt.Properties.TryGetValue("TenantId", out var val) && 
        val.ToString() == "ABC")
    .WriteTo.Console()
    .CreateLogger();

Next Steps

  1. Wait for Akka.NET 1.5.56 release with semantic logging
  2. Add LogFilterType.SemanticProperty to Akka.NET core
  3. Update this PR to use semantic property filtering
  4. Document the enricher limitation clearly

This would make LogFilter much more performant while maintaining full backward compatibility!


Related:

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants