Skip to content

Commit e16928a

Browse files
evgenyfedorov2evgenyfedorov2
evgenyfedorov2
authored andcommitted
Add more list pools
1 parent 5e49d69 commit e16928a

File tree

4 files changed

+138
-121
lines changed

4 files changed

+138
-121
lines changed

src/Libraries/Microsoft.AspNetCore.Diagnostics.Middleware/Buffering/IncomingRequestLogBuffer.cs

+1-1
Original file line numberDiff line numberDiff line change
@@ -109,7 +109,7 @@ public void Flush()
109109
_activeBuffer = _standbyBuffer;
110110
tempBuffer.Clear();
111111
_standbyBuffer = tempBuffer;
112-
Interlocked.Exchange(ref _activeBufferSize, 0);
112+
_ = Interlocked.Exchange(ref _activeBufferSize, 0);
113113
}
114114

115115
// Process records in batches

src/Libraries/Microsoft.Extensions.Telemetry/Buffering/GlobalBuffer.cs

+1-1
Original file line numberDiff line numberDiff line change
@@ -128,7 +128,7 @@ public void Flush()
128128
_activeBuffer = _standbyBuffer;
129129
tempBuffer.Clear();
130130
_standbyBuffer = tempBuffer;
131-
Interlocked.Exchange(ref _activeBufferSize, 0);
131+
_ = Interlocked.Exchange(ref _activeBufferSize, 0);
132132
}
133133

134134
// Process records in batches

src/Libraries/Microsoft.Extensions.Telemetry/Buffering/LogBufferingFilterRuleSelector.cs

+28-10
Original file line numberDiff line numberDiff line change
@@ -11,6 +11,8 @@
1111
using System.Collections.Generic;
1212
using System.Linq;
1313
using Microsoft.Extensions.Logging;
14+
using Microsoft.Extensions.ObjectPool;
15+
using Microsoft.Shared.Pools;
1416

1517
namespace Microsoft.Extensions.Diagnostics.Buffering;
1618

@@ -19,28 +21,44 @@ namespace Microsoft.Extensions.Diagnostics.Buffering;
1921
/// </summary>
2022
internal sealed class LogBufferingFilterRuleSelector
2123
{
24+
private static readonly ObjectPool<List<LogBufferingFilterRule>> _cachedRulePool =
25+
PoolFactory.CreateListPool<LogBufferingFilterRule>();
26+
27+
private static readonly ObjectPool<List<LogBufferingFilterRule>> _rulePool =
28+
PoolFactory.CreateListPool<LogBufferingFilterRule>();
29+
2230
private static readonly IEqualityComparer<KeyValuePair<string, object?>> _stringifyComparer = new StringifyComprarer();
2331
private readonly ConcurrentDictionary<(LogLevel, EventId), List<LogBufferingFilterRule>> _ruleCache = new();
2432

2533
public static LogBufferingFilterRule[] SelectByCategory(IList<LogBufferingFilterRule> rules, string category)
2634
{
27-
List<LogBufferingFilterRule> result = [];
28-
29-
// Skip rules with inapplicable category
30-
// because GlobalBuffers are created for each category
31-
foreach (LogBufferingFilterRule rule in rules)
35+
List<LogBufferingFilterRule> rulesOfCategory = _rulePool.Get();
36+
try
3237
{
33-
if (IsMatch(rule, category))
38+
// Select rules with applicable category only
39+
foreach (LogBufferingFilterRule rule in rules)
3440
{
35-
result.Add(rule);
41+
if (IsMatch(rule, category))
42+
{
43+
rulesOfCategory.Add(rule);
44+
}
3645
}
37-
}
3846

39-
return result.ToArray();
47+
return rulesOfCategory.ToArray();
48+
}
49+
finally
50+
{
51+
_rulePool.Return(rulesOfCategory);
52+
}
4053
}
4154

4255
public void InvalidateCache()
4356
{
57+
foreach (((LogLevel, EventId) key, List<LogBufferingFilterRule> value) in _ruleCache)
58+
{
59+
_cachedRulePool.Return(value);
60+
}
61+
4462
_ruleCache.Clear();
4563
}
4664

@@ -53,7 +71,7 @@ public void InvalidateCache()
5371
// 1. select rule candidates by log level and event id from the cache
5472
List<LogBufferingFilterRule> ruleCandidates = _ruleCache.GetOrAdd((logLevel, eventId), _ =>
5573
{
56-
List<LogBufferingFilterRule> candidates = new(rules.Count);
74+
List<LogBufferingFilterRule> candidates = _cachedRulePool.Get();
5775
foreach (LogBufferingFilterRule rule in rules)
5876
{
5977
if (IsMatch(rule, logLevel, eventId))

test/Libraries/Microsoft.Extensions.Telemetry.Tests/Logging/ExtendedLoggerTests.cs

+108-109
Original file line numberDiff line numberDiff line change
@@ -4,7 +4,6 @@
44
using System;
55
using System.Collections.Generic;
66
using System.Linq;
7-
using System.Threading.Tasks;
87
using Microsoft.Extensions.Compliance.Testing;
98
using Microsoft.Extensions.DependencyInjection;
109
using Microsoft.Extensions.Diagnostics.Enrichment;
@@ -14,12 +13,13 @@
1413
using Moq;
1514
using Xunit;
1615
#if NET9_0_OR_GREATER
16+
using System.Threading.Tasks;
1717
using Microsoft.Extensions.Diagnostics.Buffering;
1818
#endif
1919

2020
namespace Microsoft.Extensions.Logging.Test;
2121

22-
public class ExtendedLoggerTests
22+
public static class ExtendedLoggerTests
2323
{
2424
[Theory]
2525
[CombinatorialData]
@@ -156,113 +156,6 @@ public static void Sampling()
156156
Assert.Equal(0, provider.Logger!.Collector.Count);
157157
}
158158

159-
#if NET9_0_OR_GREATER
160-
[Fact]
161-
public static void GlobalBuffering_CanonicalUsecase()
162-
{
163-
using var provider = new Provider();
164-
using ILoggerFactory factory = Utils.CreateLoggerFactory(
165-
builder =>
166-
{
167-
builder.AddProvider(provider);
168-
builder.AddGlobalBuffer(LogLevel.Warning);
169-
});
170-
171-
ILogger logger = factory.CreateLogger("my category");
172-
logger.LogWarning("MSG0");
173-
logger.Log(LogLevel.Warning, new EventId(2, "ID2"), "some state", null, (_, _) => "MSG2");
174-
175-
// nothing is logged because the buffer not flushed yet
176-
Assert.Equal(0, provider.Logger!.Collector.Count);
177-
178-
// instead of this, users would get LogBuffer from DI and call Flush on it
179-
Utils.DisposingLoggerFactory dlf = (Utils.DisposingLoggerFactory)factory;
180-
GlobalLogBuffer buffer = dlf.ServiceProvider.GetRequiredService<GlobalLogBuffer>();
181-
182-
buffer.Flush();
183-
184-
// 2 log records emitted because the buffer has been flushed
185-
Assert.Equal(2, provider.Logger!.Collector.Count);
186-
}
187-
188-
[Fact]
189-
public static void GlobalBuffering_ParallelLogging()
190-
{
191-
using var provider = new Provider();
192-
using ILoggerFactory factory = Utils.CreateLoggerFactory(
193-
builder =>
194-
{
195-
builder.AddProvider(provider);
196-
builder.AddGlobalBuffer(LogLevel.Warning);
197-
});
198-
199-
ILogger logger = factory.CreateLogger("my category");
200-
201-
// 1000 threads logging at the same time
202-
Parallel.For(0, 1000, _ =>
203-
{
204-
logger.LogWarning("MSG0");
205-
logger.Log(LogLevel.Warning, new EventId(2, "ID2"), "some state", null, (_, _) => "MSG2");
206-
});
207-
208-
// nothing is logged because the buffer not flushed yet
209-
Assert.Equal(0, provider.Logger!.Collector.Count);
210-
211-
212-
Utils.DisposingLoggerFactory dlf = (Utils.DisposingLoggerFactory)factory;
213-
GlobalLogBuffer buffer = dlf.ServiceProvider.GetRequiredService<GlobalLogBuffer>();
214-
215-
buffer.Flush();
216-
217-
// 2000 log records emitted because the buffer has been flushed
218-
Assert.Equal(2000, provider.Logger!.Collector.Count);
219-
}
220-
221-
[Fact]
222-
public async Task GlobalBuffering_ParallelLoggingAndFlushing()
223-
{
224-
// Arrange
225-
using var provider = new Provider();
226-
using ILoggerFactory factory = Utils.CreateLoggerFactory(
227-
builder =>
228-
{
229-
builder.AddProvider(provider);
230-
builder.AddGlobalBuffer(options =>
231-
{
232-
options.AutoFlushDuration = TimeSpan.Zero;
233-
options.Rules.Add(new LogBufferingFilterRule(logLevel: LogLevel.Warning));
234-
});
235-
});
236-
237-
ILogger logger = factory.CreateLogger("my category");
238-
Utils.DisposingLoggerFactory dlf = (Utils.DisposingLoggerFactory)factory;
239-
GlobalLogBuffer buffer = dlf.ServiceProvider.GetRequiredService<GlobalLogBuffer>();
240-
241-
// Act - Run logging and flushing operations in parallel
242-
await Task.Run(() =>
243-
{
244-
Parallel.For(0, 100, i =>
245-
{
246-
logger.LogWarning("MSG0");
247-
logger.LogWarning("MSG1");
248-
logger.LogWarning("MSG2");
249-
logger.LogWarning("MSG3");
250-
logger.LogWarning("MSG4");
251-
logger.LogWarning("MSG5");
252-
logger.LogWarning("MSG6");
253-
logger.LogWarning("MSG7");
254-
logger.LogWarning("MSG8");
255-
logger.LogWarning("MSG9");
256-
buffer.Flush();
257-
});
258-
});
259-
260-
buffer.Flush();
261-
Assert.Equal(1000, provider.Logger!.Collector.Count);
262-
}
263-
264-
#endif
265-
266159
[Theory]
267160
[CombinatorialData]
268161
public static void BagAndJoiner(bool objectVersion)
@@ -1026,6 +919,112 @@ public static void LegacyLogging_OriginalFormatMustBeLastInTheListOfStatePropert
1026919
Assert.Equal("V4", property.Value);
1027920
}
1028921

922+
#if NET9_0_OR_GREATER
923+
[Fact]
924+
public static void GlobalBuffering_CanonicalUsecase()
925+
{
926+
using var provider = new Provider();
927+
using ILoggerFactory factory = Utils.CreateLoggerFactory(
928+
builder =>
929+
{
930+
builder.AddProvider(provider);
931+
builder.AddGlobalBuffer(LogLevel.Warning);
932+
});
933+
934+
ILogger logger = factory.CreateLogger("my category");
935+
logger.LogWarning("MSG0");
936+
logger.Log(LogLevel.Warning, new EventId(2, "ID2"), "some state", null, (_, _) => "MSG2");
937+
938+
// nothing is logged because the buffer not flushed yet
939+
Assert.Equal(0, provider.Logger!.Collector.Count);
940+
941+
// instead of this, users would get LogBuffer from DI and call Flush on it
942+
Utils.DisposingLoggerFactory dlf = (Utils.DisposingLoggerFactory)factory;
943+
GlobalLogBuffer buffer = dlf.ServiceProvider.GetRequiredService<GlobalLogBuffer>();
944+
945+
buffer.Flush();
946+
947+
// 2 log records emitted because the buffer has been flushed
948+
Assert.Equal(2, provider.Logger!.Collector.Count);
949+
}
950+
951+
[Fact]
952+
public static void GlobalBuffering_ParallelLogging()
953+
{
954+
using var provider = new Provider();
955+
using ILoggerFactory factory = Utils.CreateLoggerFactory(
956+
builder =>
957+
{
958+
builder.AddProvider(provider);
959+
builder.AddGlobalBuffer(LogLevel.Warning);
960+
});
961+
962+
ILogger logger = factory.CreateLogger("my category");
963+
964+
// 1000 threads logging at the same time
965+
Parallel.For(0, 1000, _ =>
966+
{
967+
logger.LogWarning("MSG0");
968+
logger.Log(LogLevel.Warning, new EventId(2, "ID2"), "some state", null, (_, _) => "MSG2");
969+
});
970+
971+
// nothing is logged because the buffer not flushed yet
972+
Assert.Equal(0, provider.Logger!.Collector.Count);
973+
974+
Utils.DisposingLoggerFactory dlf = (Utils.DisposingLoggerFactory)factory;
975+
GlobalLogBuffer buffer = dlf.ServiceProvider.GetRequiredService<GlobalLogBuffer>();
976+
977+
buffer.Flush();
978+
979+
// 2000 log records emitted because the buffer has been flushed
980+
Assert.Equal(2000, provider.Logger!.Collector.Count);
981+
}
982+
983+
[Fact]
984+
public static async Task GlobalBuffering_ParallelLoggingAndFlushing()
985+
{
986+
// Arrange
987+
using var provider = new Provider();
988+
using ILoggerFactory factory = Utils.CreateLoggerFactory(
989+
builder =>
990+
{
991+
builder.AddProvider(provider);
992+
builder.AddGlobalBuffer(options =>
993+
{
994+
options.AutoFlushDuration = TimeSpan.Zero;
995+
options.Rules.Add(new LogBufferingFilterRule(logLevel: LogLevel.Warning));
996+
});
997+
});
998+
999+
ILogger logger = factory.CreateLogger("my category");
1000+
Utils.DisposingLoggerFactory dlf = (Utils.DisposingLoggerFactory)factory;
1001+
GlobalLogBuffer buffer = dlf.ServiceProvider.GetRequiredService<GlobalLogBuffer>();
1002+
1003+
// Act - Run logging and flushing operations in parallel
1004+
await Task.Run(() =>
1005+
{
1006+
Parallel.For(0, 100, i =>
1007+
{
1008+
logger.LogWarning("MSG0");
1009+
logger.LogWarning("MSG1");
1010+
logger.LogWarning("MSG2");
1011+
logger.LogWarning("MSG3");
1012+
logger.LogWarning("MSG4");
1013+
logger.LogWarning("MSG5");
1014+
logger.LogWarning("MSG6");
1015+
logger.LogWarning("MSG7");
1016+
logger.LogWarning("MSG8");
1017+
logger.LogWarning("MSG9");
1018+
buffer.Flush();
1019+
});
1020+
});
1021+
1022+
buffer.Flush();
1023+
Assert.Equal(1000, provider.Logger!.Collector.Count);
1024+
}
1025+
1026+
#endif
1027+
10291028
private sealed class CustomLoggerProvider : ILoggerProvider
10301029
{
10311030
private readonly string _providerName;

0 commit comments

Comments
 (0)