Custom log filtering (#95)

* Allow custom log filtering (ConfigCatClientOptions.LogFilter)

* Use modified version of FormattableStringFactory internally to avoid unnecessary heap allocations

* Reduce heap allocation by deferring formatting of log and error messages until actually accessed by consumer

src/ConfigCat.Client.Tests/ConfigCat.Client.Tests.csproj

@@ -8,7 +8,7 @@
     <LangVersion>10.0</LangVersion>
     <Nullable>enable</Nullable>
     <WarningsAsErrors>nullable</WarningsAsErrors>
-    <NoWarn>CS0618</NoWarn>
+    <NoWarn>CS0618;CS1685</NoWarn>
     <AssemblyOriginatorKeyFile>..\ConfigCatClient.snk</AssemblyOriginatorKeyFile>
   </PropertyGroup>
 

src/ConfigCat.Client.Tests/ConfigCatClientTests.cs

@@ -2107,14 +2107,14 @@ public async Task Hooks_MockedClientRaisesEvents()
         hooks.FlagEvaluated += (s, e) => flagEvaluatedEvents.Add(e);
         hooks.Error += (s, e) => errorEvents.Add(e);
 
-        var loggerWrapper = this.loggerMock.Object.AsWrapper(hooks);
+        var loggerWrapper = this.loggerMock.Object.AsWrapper(hooks: hooks);
 
         var errorException = new HttpRequestException();
 
         var onFetch = (ProjectConfig latestConfig, CancellationToken _) =>
         {
             var logMessage = loggerWrapper.FetchFailedDueToUnexpectedError(errorException);
-            return FetchResult.Failure(latestConfig, RefreshErrorCode.HttpRequestFailure, errorMessage: logMessage.InvariantFormattedMessage, errorException: errorException);
+            return FetchResult.Failure(latestConfig, RefreshErrorCode.HttpRequestFailure, errorMessage: logMessage.ToLazyString(), errorException: errorException);
         };
         this.fetcherMock.Setup(m => m.FetchAsync(It.IsAny<ProjectConfig>(), It.IsAny<CancellationToken>())).ReturnsAsync(onFetch);
 
@@ -2306,6 +2306,30 @@ void Unsubscribe(IProvidesHooks hooks)
         Assert.AreEqual(2, errorEvents.Count);
     }
 
+    [TestMethod]
+    public async Task LogFilter_Works()
+    {
+        var logEvents = new List<LogEvent>();
+        var logger = LoggingHelper.CreateCapturingLogger(logEvents, LogLevel.Info);
+
+        var options = new ConfigCatClientOptions
+        {
+            Logger = logger,
+            LogFilter = (LogLevel level, LogEventId eventId, ref FormattableLogMessage message, Exception? exception) => eventId != 3001,
+            FlagOverrides = FlagOverrides.LocalFile(Path.Combine("data", "sample_variationid_v5.json"), autoReload: false, OverrideBehaviour.LocalOnly)
+        };
+
+        using var client = new ConfigCatClient("localonly", options);
+
+        var actualValue = await client.GetValueAsync("boolean", (bool?)null);
+        Assert.IsFalse(actualValue);
+
+        Assert.AreEqual(1, logEvents.Count);
+        Assert.AreEqual(LogLevel.Info, logEvents[0].Level);
+        Assert.AreEqual(5000, logEvents[0].EventId);
+        Assert.IsNull(logEvents[0].Exception);
+    }
+
     private static IConfigCatClient CreateClientWithMockedFetcher(string cacheKey,
         Mock<IConfigCatLogger> loggerMock,
         Mock<IConfigFetcher> fetcherMock,
@@ -2375,7 +2399,7 @@ private static IConfigCatClient CreateClientWithMockedFetcher(string cacheKey,
         var overrideDataSource = overrideDataSourceFactory?.Invoke(loggerWrapper);
 
         configService = configServiceFactory(fetcherMock.Object, cacheParams, loggerWrapper, hooks);
-        return new ConfigCatClient(configService, loggerMock.Object, evaluator, overrideDataSource?.Item1, overrideDataSource?.Item2, hooks);
+        return new ConfigCatClient(configService, loggerMock.Object, evaluator, overrideDataSource?.Item1, overrideDataSource?.Item2, hooks: hooks);
     }
 
     private static int ParseETagAsInt32(string? etag)

src/ConfigCat.Client.Tests/Helpers/LoggingHelper.cs

@@ -19,9 +19,9 @@ public LogEvent(LogLevel level, LogEventId eventId, ref FormattableLogMessage me
 
 internal static class LoggingHelper
 {
-    public static LoggerWrapper AsWrapper(this IConfigCatLogger logger, Hooks? hooks = null)
+    public static LoggerWrapper AsWrapper(this IConfigCatLogger logger, LogFilterCallback? filter = null, Hooks? hooks = null)
     {
-        return new LoggerWrapper(logger, hooks);
+        return new LoggerWrapper(logger, filter, hooks);
     }
 
     public static IConfigCatLogger CreateCapturingLogger(List<LogEvent> logEvents, LogLevel logLevel = LogLevel.Info)

src/ConfigCat.Client.Tests/LoggerTests.cs

@@ -1,4 +1,7 @@
+using System;
+using System.Collections.Generic;
 using Microsoft.VisualStudio.TestTools.UnitTesting;
+using Moq;
 
 namespace ConfigCat.Client.Tests;
 
@@ -112,4 +115,38 @@ public void LoggerBase_LoglevelIsOff_ShouldNotInvokeAnyLogMessage()
 
         Assert.AreEqual(0, l.LogMessageInvokeCount);
     }
+
+    [TestMethod]
+    public void LogFilter_ExcludesLogEvents()
+    {
+        var logEvents = new List<LogEvent>();
+        var loggerMock = new Mock<IConfigCatLogger>();
+        loggerMock.SetupGet(m => m.LogLevel).Returns(LogLevel.Info);
+
+        LogFilterCallback logFilter = (LogLevel level, LogEventId eventId, ref FormattableLogMessage message, Exception? exception)
+            => eventId.Id is not (1001 or 3001 or 5001);
+
+        var logger = loggerMock.Object.AsWrapper(logFilter);
+
+        logger.Log(LogLevel.Debug, 0, "debug");
+        logger.Log(LogLevel.Info, 5000, "info");
+        logger.Log(LogLevel.Warning, 3000, "warn");
+        var ex1 = new Exception();
+        logger.Log(LogLevel.Error, 1000, ex1, "error");
+        logger.Log(LogLevel.Info, 5001, "info");
+        logger.Log(LogLevel.Warning, 3001, "warn");
+        var ex2 = new Exception();
+        logger.Log(LogLevel.Error, 1001, ex2, "error");
+
+        loggerMock.Verify(m => m.Log(LogLevel.Debug, It.IsAny<LogEventId>(), ref It.Ref<FormattableLogMessage>.IsAny, It.IsAny<Exception>()), Times.Never);
+
+        loggerMock.Verify(m => m.Log(LogLevel.Info, It.IsAny<LogEventId>(), ref It.Ref<FormattableLogMessage>.IsAny, It.IsAny<Exception>()), Times.Once);
+        loggerMock.Verify(m => m.Log(LogLevel.Info, 5000, ref It.Ref<FormattableLogMessage>.IsAny, null), Times.Once);
+
+        loggerMock.Verify(m => m.Log(LogLevel.Warning, It.IsAny<LogEventId>(), ref It.Ref<FormattableLogMessage>.IsAny, It.IsAny<Exception>()), Times.Once);
+        loggerMock.Verify(m => m.Log(LogLevel.Warning, 3000, ref It.Ref<FormattableLogMessage>.IsAny, null), Times.Once);
+
+        loggerMock.Verify(m => m.Log(LogLevel.Error, It.IsAny<LogEventId>(), ref It.Ref<FormattableLogMessage>.IsAny, It.IsAny<Exception>()), Times.Once);
+        loggerMock.Verify(m => m.Log(LogLevel.Error, 1000, ref It.Ref<FormattableLogMessage>.IsAny, ex1), Times.Once);
+    }
 }

src/ConfigCat.Client.Tests/UtilsTests.cs

@@ -157,4 +157,26 @@ public void ModelHelper_SetEnum_Works(SettingType enumValue)
             Assert.ThrowsException<ArgumentOutOfRangeException>(() => ModelHelper.SetEnum(ref field, enumValue));
         }
     }
+
+    [DataTestMethod]
+    [DataRow(null, false, true, null)]
+    [DataRow("abc", false, true, "abc")]
+    [DataRow("abc", null, false, "abc")]
+    [DataRow("abc", new object?[0], false, "abc")]
+    [DataRow("abc{0}{1}{2}", new object?[] { 0.1, null, 23 }, false, "abc0.123")]
+    public void LazyString_Value_Works(string? valueOrFormat, object? args, bool expectedIsValueCreated, string? expectedValue)
+    {
+        var lazyString = args is false ? new LazyString(valueOrFormat) : new LazyString(valueOrFormat!, (object?[]?)args);
+
+        Assert.AreEqual(expectedIsValueCreated, lazyString.IsValueCreated);
+
+        var value = lazyString.Value;
+        Assert.AreEqual(expectedValue, value);
+
+        Assert.IsTrue(lazyString.IsValueCreated);
+
+        Assert.AreSame(value, lazyString.Value);
+
+        Assert.AreSame(expectedValue is not null ? value : string.Empty, lazyString.ToString());
+    }
 }

src/ConfigCatClient/ConfigCatClient.cs

@@ -85,7 +85,7 @@ internal ConfigCatClient(string sdkKey, ConfigCatClientOptions options)
         // hold a strong reference to the hooks object (see also SafeHooksWrapper).
         var hooksWrapper = new SafeHooksWrapper(this.hooks);
 
-        var logger = new LoggerWrapper(options.Logger ?? ConfigCatClientOptions.CreateDefaultLogger(), hooksWrapper);
+        var logger = new LoggerWrapper(options.Logger ?? ConfigCatClientOptions.CreateDefaultLogger(), options.LogFilter, hooksWrapper);
         var evaluator = new RolloutEvaluator(logger);
 
         this.evaluationServices = new EvaluationServices(evaluator, hooksWrapper, logger);
@@ -125,13 +125,14 @@ internal ConfigCatClient(string sdkKey, ConfigCatClientOptions options)
 
     // For test purposes only
     internal ConfigCatClient(IConfigService configService, IConfigCatLogger logger, IRolloutEvaluator evaluator,
-        OverrideBehaviour? overrideBehaviour = null, IOverrideDataSource? overrideDataSource = null, Hooks? hooks = null)
+        OverrideBehaviour? overrideBehaviour = null, IOverrideDataSource? overrideDataSource = null,
+        LogFilterCallback? logFilter = null, Hooks? hooks = null)
     {
         this.hooks = hooks ?? NullHooks.Instance;
         this.hooks.SetSender(this);
         var hooksWrapper = new SafeHooksWrapper(this.hooks);
 
-        this.evaluationServices = new EvaluationServices(evaluator, hooksWrapper, new LoggerWrapper(logger, hooks));
+        this.evaluationServices = new EvaluationServices(evaluator, hooksWrapper, new LoggerWrapper(logger, logFilter, hooks));
 
         this.configService = configService;
 

src/ConfigCatClient/ConfigService/ConfigServiceBase.cs

@@ -96,7 +96,7 @@ public virtual RefreshResult RefreshConfig()
         else
         {
             var logMessage = this.Logger.ConfigServiceCannotInitiateHttpCalls();
-            return RefreshResult.Failure(RefreshErrorCode.OfflineClient, logMessage.InvariantFormattedMessage);
+            return RefreshResult.Failure(RefreshErrorCode.OfflineClient, logMessage.ToLazyString());
         }
     }
 
@@ -133,7 +133,7 @@ public virtual async ValueTask<RefreshResult> RefreshConfigAsync(CancellationTok
         else
         {
             var logMessage = this.Logger.ConfigServiceCannotInitiateHttpCalls();
-            return RefreshResult.Failure(RefreshErrorCode.OfflineClient, logMessage.InvariantFormattedMessage);
+            return RefreshResult.Failure(RefreshErrorCode.OfflineClient, logMessage.ToLazyString());
         }
     }
 

src/ConfigCatClient/Configuration/ConfigCatClientOptions.cs

@@ -17,6 +17,12 @@ public class ConfigCatClientOptions : IProvidesHooks
 
     private Hooks hooks = new();
 
+    /// <summary>
+    /// An optional callback that can be used to filter log events beyond the minimum log level setting
+    /// (<see cref="IConfigCatLogger.LogLevel"/> and <see cref="ConfigCatClient.LogLevel"/>).
+    /// </summary>
+    public LogFilterCallback? LogFilter { get; set; }
+
     /// <summary>
     /// The logger implementation to use for performing logging.
     /// If not set, <see cref="ConsoleLogger"/> with <see cref="LogLevel.Warning"/> will be used by default.<br/>

src/ConfigCatClient/Evaluation/EvaluationDetails.cs

@@ -1,5 +1,6 @@
 using System;
 using ConfigCat.Client.Evaluation;
+using ConfigCat.Client.Utils;
 
 namespace ConfigCat.Client;
 
@@ -28,13 +29,13 @@ internal static EvaluationDetails<TValue> FromEvaluateResult<TValue>(string key,
     }
 
     internal static EvaluationDetails<TValue> FromDefaultValue<TValue>(string key, TValue defaultValue, DateTime? fetchTime, User? user,
-        string errorMessage, Exception? errorException = null, EvaluationErrorCode errorCode = EvaluationErrorCode.UnexpectedError)
+        LazyString errorMessage, Exception? errorException = null, EvaluationErrorCode errorCode = EvaluationErrorCode.UnexpectedError)
     {
         var instance = new EvaluationDetails<TValue>(key, defaultValue)
         {
             User = user,
             IsDefaultValue = true,
-            ErrorMessage = errorMessage,
+            errorMessage = errorMessage,
             ErrorException = errorException,
             ErrorCode = errorCode,
         };
@@ -47,6 +48,8 @@ internal static EvaluationDetails<TValue> FromDefaultValue<TValue>(string key, T
         return instance;
     }
 
+    private LazyString errorMessage;
+
     private protected EvaluationDetails(string key)
     {
         Key = key;
@@ -93,7 +96,11 @@ private protected EvaluationDetails(string key)
     /// <summary>
     /// Error message in case evaluation failed.
     /// </summary>
-    public string? ErrorMessage { get; set; }
+    public string? ErrorMessage
+    {
+        get => this.errorMessage.Value;
+        set => this.errorMessage = value;
+    }
 
     /// <summary>
     /// The <see cref="Exception"/> object related to the error in case evaluation failed (if any).

src/ConfigCatClient/Evaluation/EvaluationHelper.cs

@@ -17,15 +17,15 @@ public static EvaluationDetails<T> Evaluate<T>(this IRolloutEvaluator evaluator,
         {
             logMessage = logger.ConfigJsonIsNotPresent(key, nameof(defaultValue), defaultValue);
             return EvaluationDetails.FromDefaultValue(key, defaultValue, fetchTime: remoteConfig?.TimeStamp, user,
-                logMessage.InvariantFormattedMessage, errorCode: EvaluationErrorCode.ConfigJsonNotAvailable);
+                logMessage.ToLazyString(), errorCode: EvaluationErrorCode.ConfigJsonNotAvailable);
         }
 
         if (!settings.TryGetValue(key, out var setting))
         {
-            var availableKeys = new StringListFormatter(settings.Keys).ToString();
+            var availableKeys = new StringListFormatter(settings.Keys);
             logMessage = logger.SettingEvaluationFailedDueToMissingKey(key, nameof(defaultValue), defaultValue, availableKeys);
             return EvaluationDetails.FromDefaultValue(key, defaultValue, fetchTime: remoteConfig?.TimeStamp, user,
-                logMessage.InvariantFormattedMessage, errorCode: EvaluationErrorCode.SettingKeyMissing);
+                logMessage.ToLazyString(), errorCode: EvaluationErrorCode.SettingKeyMissing);
         }
 
         var evaluateContext = new EvaluateContext(key, setting, user, settings);

src/ConfigCatClient/FetchResult.cs

@@ -1,5 +1,8 @@
 using System;
+using System.Collections.Generic;
+using System.Diagnostics;
 using System.Diagnostics.CodeAnalysis;
+using ConfigCat.Client.Utils;
 
 namespace ConfigCat.Client;
 
@@ -17,12 +20,13 @@ public static FetchResult NotModified(ProjectConfig config)
         return new FetchResult(config, RefreshErrorCode.None, NotModifiedToken);
     }
 
-    public static FetchResult Failure(ProjectConfig config, RefreshErrorCode errorCode, string errorMessage, Exception? errorException = null)
+    public static FetchResult Failure(ProjectConfig config, RefreshErrorCode errorCode, LazyString errorMessage, Exception? errorException = null)
     {
-        return new FetchResult(config, errorCode, errorMessage, errorException);
+        Debug.Assert(!EqualityComparer<LazyString>.Default.Equals(errorMessage, default));
+        return new FetchResult(config, errorCode, errorMessage.IsValueCreated ? errorMessage.Value : (object)errorMessage, errorException);
     }
 
-    private readonly object? errorMessageOrToken;
+    private readonly object? errorMessageOrToken; // either null or a string or a boxed LazyString or NotModifiedToken
 
     private FetchResult(ProjectConfig config, RefreshErrorCode errorCode, object? errorMessageOrToken, Exception? errorException = null)
     {
@@ -35,10 +39,10 @@ private FetchResult(ProjectConfig config, RefreshErrorCode errorCode, object? er
     public bool IsSuccess => this.errorMessageOrToken is null;
     public bool IsNotModified => ReferenceEquals(this.errorMessageOrToken, NotModifiedToken);
     [MemberNotNullWhen(true, nameof(ErrorMessage))]
-    public bool IsFailure => this.errorMessageOrToken is string;
+    public bool IsFailure => !IsSuccess && !IsNotModified;
 
     public ProjectConfig Config { get; }
     public RefreshErrorCode ErrorCode { get; }
-    public string? ErrorMessage => this.errorMessageOrToken as string;
+    public object? ErrorMessage => !IsNotModified ? this.errorMessageOrToken : null;
     public Exception? ErrorException { get; }
 }