-
Notifications
You must be signed in to change notification settings - Fork 788
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.
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
Allow custom filtering logic for FakeLogger #5848
base: main
Are you sure you want to change the base?
Changes from all commits
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
Original file line number | Diff line number | Diff line change | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|
|
@@ -3,7 +3,8 @@ | |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
using System; | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
using System.Collections.Generic; | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
using Microsoft.Extensions.Logging; | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
using System.Diagnostics.CodeAnalysis; | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
using Microsoft.Shared.DiagnosticIds; | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
#pragma warning disable CA2227 // Collection properties should be read only | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
@@ -34,6 +35,17 @@ public class FakeLogCollectorOptions | |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
/// </remarks> | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
public ISet<LogLevel> FilteredLevels { get; set; } = new HashSet<LogLevel>(); | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
/// <summary> | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
/// Gets or sets custom filters used to filter out records to be collected. | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more.
Suggested change
|
||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
/// </summary> | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
/// <value>Default is an empty array.</value> | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
/// <remarks> | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
/// Defaults to an empty array, which doesn't filter any records. | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
/// If not empty, only records for which the filter function returns <see langword="true" /> will be collected by the fake logger. | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. I think this is the point of the disconnect for me: "only records for which the filter function returns <see langword="true" /> will be collected by the fake logger.". I recommend inverting the meaning here, which will invert the logic in the collector implementation too. |
||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
/// </remarks> | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
[Experimental(DiagnosticIds.Experiments.Telemetry)] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
public IEnumerable<Func<FakeLogRecord, bool>> CustomFilters { get; set; } = Array.Empty<Func<FakeLogRecord, bool>>(); | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. This setter will allow setting the property to null. Is this desirable? There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Since Nullable is enabled, attempt to setting it to null issues a warning. It is true that by supplying null the logic ends up crashing in runtime, which is awkward, however this seems to be the case for e.g. TimeProvider prop as well. How about defining it as nullable, defaulting to null and having a null check at the place of usage? There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more.
"Nullable" only provides annotations which only work at compile-time. That is, those may result in warnings, however, they don't block the user code from assigning null (which results in NRE at runtime and may crash the app).
It's definitely an option to expect a developer to implement null-checks, but since the API is annotated the good developer won't do that (because they trust us) and a mediocre developer won't do that (because they are mediocre). Either way, the likelihood of a user receiving an NRE is pretty high because our code isn't living up to the annotation and not handling nulls. Null handling either implies throwing if null is assigned or setting (or just returning) an empty array (like we're doing for the init state). Which implementation better depends on usecases you're trying to address. There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Yes, that's want I meant, let's define the contract as nullable with null as default and handle the null gracefully on our side. This way the user will never reach NRE.
Comment on lines
+38
to
+47
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more.
Suggested change
Suggested change
|
||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
/// <summary> | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
/// Gets or sets a value indicating whether to collect records that are logged when the associated log level is currently disabled. | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
/// </summary> | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Original file line number | Diff line number | Diff line change | ||||
---|---|---|---|---|---|---|
|
@@ -6,8 +6,6 @@ | |||||
using System.Globalization; | ||||||
using System.Linq; | ||||||
using System.Threading; | ||||||
using Microsoft.Extensions.Logging; | ||||||
using Microsoft.Extensions.Logging.Testing; | ||||||
using Microsoft.Extensions.Time.Testing; | ||||||
using Xunit; | ||||||
|
||||||
|
@@ -283,4 +281,59 @@ public void Scopes() | |||||
Assert.Equal(42, (int)logger.LatestRecord.Scopes[0]!); | ||||||
Assert.Equal("Hello World", (string)logger.LatestRecord.Scopes[1]!); | ||||||
} | ||||||
|
||||||
[Fact] | ||||||
public void FilterByCustomFilter() | ||||||
{ | ||||||
const string NotIgnoredMessage1 = "Not ignored message 1"; | ||||||
const string NotIgnoredMessage2 = "Not ignored message 2"; | ||||||
const string IgnoredMessage = "Ignored message"; | ||||||
|
||||||
// Given | ||||||
var options = new FakeLogCollectorOptions | ||||||
{ | ||||||
CustomFilters = [ | ||||||
r => !r.Message.Equals(IgnoredMessage, StringComparison.Ordinal), | ||||||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. If you're using Ordinal comparison, then more idiomatic to write as follows:
Suggested change
|
||||||
], | ||||||
}; | ||||||
|
||||||
var collector = FakeLogCollector.Create(options); | ||||||
var logger = new FakeLogger(collector); | ||||||
|
||||||
// When | ||||||
logger.LogInformation(NotIgnoredMessage1); | ||||||
logger.LogInformation(IgnoredMessage); | ||||||
logger.LogError(IgnoredMessage); | ||||||
logger.LogCritical(IgnoredMessage); | ||||||
logger.LogError(NotIgnoredMessage2); | ||||||
|
||||||
var records = logger.Collector.GetSnapshot(); | ||||||
|
||||||
// Then | ||||||
Assert.Equal(2, records.Count); | ||||||
Assert.Equal(2, logger.Collector.Count); | ||||||
|
||||||
var firstLogRecordFromSnapshot = records[0]; | ||||||
|
||||||
Assert.Equal(NotIgnoredMessage1, firstLogRecordFromSnapshot.Message); | ||||||
Assert.Equal(LogLevel.Information, firstLogRecordFromSnapshot.Level); | ||||||
Assert.Null(firstLogRecordFromSnapshot.Exception); | ||||||
Assert.Null(firstLogRecordFromSnapshot.Category); | ||||||
Assert.True(firstLogRecordFromSnapshot.LevelEnabled); | ||||||
Assert.Empty(firstLogRecordFromSnapshot.Scopes); | ||||||
Assert.Equal(0, firstLogRecordFromSnapshot.Id.Id); | ||||||
Assert.EndsWith($"info] {NotIgnoredMessage1}", firstLogRecordFromSnapshot.ToString()); | ||||||
|
||||||
var secondLogRecordFromSnapshot = records[1]; | ||||||
Assert.Equal(NotIgnoredMessage2, secondLogRecordFromSnapshot.Message); | ||||||
Assert.Equal(LogLevel.Error, secondLogRecordFromSnapshot.Level); | ||||||
Assert.Null(secondLogRecordFromSnapshot.Exception); | ||||||
Assert.Null(secondLogRecordFromSnapshot.Category); | ||||||
Assert.Empty(secondLogRecordFromSnapshot.Scopes); | ||||||
Assert.True(secondLogRecordFromSnapshot.LevelEnabled); | ||||||
Assert.Equal(0, secondLogRecordFromSnapshot.Id.Id); | ||||||
Assert.EndsWith($"error] {NotIgnoredMessage2}", secondLogRecordFromSnapshot.ToString()); | ||||||
|
||||||
Assert.Equivalent(secondLogRecordFromSnapshot, logger.LatestRecord); | ||||||
} | ||||||
} |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Would this work?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
This looks sus - if any record hasn't been filtered (i.e.,
!filter(record)
) then exit because "record was filtered out by a custom filter". Don't you think?There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
ad Linq/foreach: 👍 will switch to Linq
ad !filter(): Do I understand correctly you would find a reversed semantic better? Currently the predicate evaluates whether the record should be allowed to pass through each filter, that is: "if the record fails to pass any of the filters, it is filtered out", when reversed, the predicate would evaluate whether the record should be caught by each filter, that is: "if the record is caught by any of the filters, it is filtered out" - both seem ok to me, but since the usage will more likely be to "filter this and that out", the reversed semantic might work better
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
It's may worth checking perf switching to linq. If this is a hot path, then non-linq version may behave better. ¯\_(ツ)_/¯
To me the current implementation looks confusing to me (which means it'll likely confuse others)...
I sense the predicate's logic is inverse - i.e., "is the record caught by the filter => false", whereas perhaps it should be "is the record handled/filtered by the filter => true". This will remove the inversion in the iterator, i.e.,
if (_options.CustomFilters.Any(filter)) return true
.WDYT?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
My idea under the issue was that only those records will be collected that are allowed by the filter, i.e. those that the filter returns
true
for (and if not filter is specified, then all records are allowed). This is following the logic of the other filtering here above: e.g., ifFilteredLevels
contains items, then only those records that have the level contained there will be allowed.So, what's currently in the PR is IMO correct.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
The inverse was proposed in this comment: #5848 (comment)
I think both versions are possible, but I suggested going with the original proposal as that seems to be more widely used (e.g.:
.Where
in LINQ,.filter
in javascript,stream.filter
in Java) and also consistent with the behavior of the other filters in the same options type as mentioned by @Piedone.There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
In any case, this API proposal needs to pass through API review first anyway, so both options can be mentioned during the process and considered there?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I guess indeed. My concern is really only about keeping it consistent with the other filter options here, what the current implementation is.