From ae8c3e4fc4deaf51edc808168c257d801757e508 Mon Sep 17 00:00:00 2001 From: GeWuYou <95328647+GeWuYou@users.noreply.github.com> Date: Thu, 5 Mar 2026 16:03:02 +0800 Subject: [PATCH] =?UTF-8?q?feat(logging):=20=E6=89=A9=E5=B1=95ILogAppender?= =?UTF-8?q?=E6=8E=A5=E5=8F=A3=E5=B9=B6=E5=AE=9E=E7=8E=B0=E6=97=B6=E9=97=B4?= =?UTF-8?q?=E6=8F=90=E4=BE=9B=E8=80=85=E6=B3=A8=E5=85=A5?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit - 将ILogAppender接口继承IDisposable以支持资源释放 - 添加ITimeProvider和SystemTimeProvider接口及实现类 - 创建FakeTimeProvider用于测试时间控制 - 修改SamplingFilter支持时间提供者注入和最大日志记录器数量限制 - 为SamplingFilter添加过期状态清理功能 - 修改StatisticsAppender使用时间提供者并实现IDisposable - 更新相关单元测试以使用FakeTimeProvider进行精确时间控制 - 在测试类中为模拟追加器添加Dispose方法实现 --- .../logging/ILogAppender.cs | 2 +- .../time/ITimeProvider.cs | 12 +++ .../logging/AsyncLogAppenderTests.cs | 12 +++ .../logging/CompositeLoggerTests.cs | 4 + .../logging/SamplingFilterTests.cs | 84 ++++++++++++++++--- .../logging/StatisticsAppenderTests.cs | 16 ++-- .../time/FakeTimeProvider.cs | 41 +++++++++ .../logging/appenders/StatisticsAppender.cs | 34 ++++++-- .../logging/filters/SamplingFilter.cs | 77 +++++++++++++++-- GFramework.Core/time/SystemTimeProvider.cs | 14 ++++ 10 files changed, 265 insertions(+), 31 deletions(-) create mode 100644 GFramework.Core.Abstractions/time/ITimeProvider.cs create mode 100644 GFramework.Core.Tests/time/FakeTimeProvider.cs create mode 100644 GFramework.Core/time/SystemTimeProvider.cs diff --git a/GFramework.Core.Abstractions/logging/ILogAppender.cs b/GFramework.Core.Abstractions/logging/ILogAppender.cs index a667d17..e47c4dd 100644 --- a/GFramework.Core.Abstractions/logging/ILogAppender.cs +++ b/GFramework.Core.Abstractions/logging/ILogAppender.cs @@ -3,7 +3,7 @@ namespace GFramework.Core.Abstractions.logging; /// /// 日志输出器接口,负责将日志条目写入特定目标 /// -public interface ILogAppender +public interface ILogAppender : IDisposable { /// /// 追加日志条目 diff --git a/GFramework.Core.Abstractions/time/ITimeProvider.cs b/GFramework.Core.Abstractions/time/ITimeProvider.cs new file mode 100644 index 0000000..5d9c6ac --- /dev/null +++ b/GFramework.Core.Abstractions/time/ITimeProvider.cs @@ -0,0 +1,12 @@ +namespace GFramework.Core.Abstractions.time; + +/// +/// 时间提供者接口,用于抽象时间获取以支持测试 +/// +public interface ITimeProvider +{ + /// + /// 获取当前 UTC 时间 + /// + DateTime UtcNow { get; } +} \ No newline at end of file diff --git a/GFramework.Core.Tests/logging/AsyncLogAppenderTests.cs b/GFramework.Core.Tests/logging/AsyncLogAppenderTests.cs index eb5bd3d..e048c7d 100644 --- a/GFramework.Core.Tests/logging/AsyncLogAppenderTests.cs +++ b/GFramework.Core.Tests/logging/AsyncLogAppenderTests.cs @@ -184,6 +184,10 @@ public class AsyncLogAppenderTests public void Flush() { } + + public void Dispose() + { + } } private class SlowAppender : ILogAppender @@ -203,6 +207,10 @@ public class AsyncLogAppenderTests public void Flush() { } + + public void Dispose() + { + } } private class ThrowingAppender : ILogAppender @@ -215,5 +223,9 @@ public class AsyncLogAppenderTests public void Flush() { } + + public void Dispose() + { + } } } \ No newline at end of file diff --git a/GFramework.Core.Tests/logging/CompositeLoggerTests.cs b/GFramework.Core.Tests/logging/CompositeLoggerTests.cs index cbf355c..a8fc24b 100644 --- a/GFramework.Core.Tests/logging/CompositeLoggerTests.cs +++ b/GFramework.Core.Tests/logging/CompositeLoggerTests.cs @@ -160,6 +160,10 @@ public class CompositeLoggerTests { FlushCalled = true; } + + public void Dispose() + { + } } private class TestDisposableAppender : ILogAppender, IDisposable diff --git a/GFramework.Core.Tests/logging/SamplingFilterTests.cs b/GFramework.Core.Tests/logging/SamplingFilterTests.cs index 64370c3..562f586 100644 --- a/GFramework.Core.Tests/logging/SamplingFilterTests.cs +++ b/GFramework.Core.Tests/logging/SamplingFilterTests.cs @@ -1,5 +1,6 @@ using GFramework.Core.Abstractions.logging; using GFramework.Core.logging.filters; +using GFramework.Core.Tests.time; using NUnit.Framework; namespace GFramework.Core.Tests.logging; @@ -10,9 +11,10 @@ public class SamplingFilterTests [Test] public void SamplingFilter_Should_Sample_Logs_By_Rate() { - var filter = new SamplingFilter(sampleRate: 3, timeWindow: TimeSpan.FromMinutes(1)); + var timeProvider = new FakeTimeProvider(); + var filter = new SamplingFilter(sampleRate: 3, timeWindow: TimeSpan.FromMinutes(1), timeProvider: timeProvider); var entry = new LogEntry( - DateTime.UtcNow, + timeProvider.UtcNow, LogLevel.Info, "TestLogger", "Test message", @@ -34,9 +36,11 @@ public class SamplingFilterTests [Test] public void SamplingFilter_Should_Reset_After_Time_Window() { - var filter = new SamplingFilter(sampleRate: 2, timeWindow: TimeSpan.FromMilliseconds(100)); + var timeProvider = new FakeTimeProvider(); + var filter = new SamplingFilter(sampleRate: 2, timeWindow: TimeSpan.FromMilliseconds(100), + timeProvider: timeProvider); var entry = new LogEntry( - DateTime.UtcNow, + timeProvider.UtcNow, LogLevel.Info, "TestLogger", "Test message", @@ -48,8 +52,8 @@ public class SamplingFilterTests Assert.That(filter.ShouldLog(entry), Is.True); // 1st Assert.That(filter.ShouldLog(entry), Is.False); // 2nd - // 等待时间窗口过期 - Thread.Sleep(150); + // 前进时间超过窗口 + timeProvider.Advance(TimeSpan.FromMilliseconds(150)); // 新窗口应该重置计数 Assert.That(filter.ShouldLog(entry), Is.True); // 1st in new window @@ -59,10 +63,11 @@ public class SamplingFilterTests [Test] public void SamplingFilter_Should_Maintain_Separate_State_Per_Logger() { - var filter = new SamplingFilter(sampleRate: 2, timeWindow: TimeSpan.FromMinutes(1)); + var timeProvider = new FakeTimeProvider(); + var filter = new SamplingFilter(sampleRate: 2, timeWindow: TimeSpan.FromMinutes(1), timeProvider: timeProvider); - var entry1 = new LogEntry(DateTime.UtcNow, LogLevel.Info, "Logger1", "Message", null, null); - var entry2 = new LogEntry(DateTime.UtcNow, LogLevel.Info, "Logger2", "Message", null, null); + var entry1 = new LogEntry(timeProvider.UtcNow, LogLevel.Info, "Logger1", "Message", null, null); + var entry2 = new LogEntry(timeProvider.UtcNow, LogLevel.Info, "Logger2", "Message", null, null); // Logger1 的第一条 Assert.That(filter.ShouldLog(entry1), Is.True); @@ -77,6 +82,47 @@ public class SamplingFilterTests Assert.That(filter.ShouldLog(entry2), Is.False); } + [Test] + public void SamplingFilter_Should_Use_Shared_State_When_Max_Loggers_Exceeded() + { + var timeProvider = new FakeTimeProvider(); + var filter = new SamplingFilter(sampleRate: 2, timeWindow: TimeSpan.FromMinutes(1), maxLoggers: 2, + timeProvider: timeProvider); + + var entry1 = new LogEntry(timeProvider.UtcNow, LogLevel.Info, "Logger1", "Message", null, null); + var entry2 = new LogEntry(timeProvider.UtcNow, LogLevel.Info, "Logger2", "Message", null, null); + var entry3 = new LogEntry(timeProvider.UtcNow, LogLevel.Info, "Logger3", "Message", null, null); + + // Logger1 和 Logger2 各自独立 + Assert.That(filter.ShouldLog(entry1), Is.True); // Logger1: 1st + Assert.That(filter.ShouldLog(entry2), Is.True); // Logger2: 1st + + // Logger3 超过限制,使用共享状态 + Assert.That(filter.ShouldLog(entry3), Is.True); // Shared: 1st + Assert.That(filter.ShouldLog(entry3), Is.False); // Shared: 2nd + } + + [Test] + public void SamplingFilter_Should_Cleanup_Stale_States() + { + var timeProvider = new FakeTimeProvider(); + var filter = new SamplingFilter(sampleRate: 2, timeWindow: TimeSpan.FromMinutes(1), timeProvider: timeProvider); + + var entry = new LogEntry(timeProvider.UtcNow, LogLevel.Info, "TestLogger", "Message", null, null); + + // 使用过滤器 + filter.ShouldLog(entry); + + // 前进时间 + timeProvider.Advance(TimeSpan.FromHours(2)); + + // 清理过期状态 + filter.CleanupStaleStates(TimeSpan.FromHours(1)); + + // 验证状态已被清理(通过再次使用应该重新开始计数) + Assert.That(filter.ShouldLog(entry), Is.True); // 应该是新的第一条 + } + [Test] public void SamplingFilter_Should_Throw_When_SampleRate_Is_Invalid() { @@ -102,11 +148,27 @@ public class SamplingFilterTests }); } + [Test] + public void SamplingFilter_Should_Throw_When_MaxLoggers_Is_Invalid() + { + Assert.Throws(() => + { + new SamplingFilter(sampleRate: 2, timeWindow: TimeSpan.FromMinutes(1), maxLoggers: 0); + }); + + Assert.Throws(() => + { + new SamplingFilter(sampleRate: 2, timeWindow: TimeSpan.FromMinutes(1), maxLoggers: -1); + }); + } + [Test] public void SamplingFilter_Should_Be_Thread_Safe() { - var filter = new SamplingFilter(sampleRate: 10, timeWindow: TimeSpan.FromMinutes(1)); - var entry = new LogEntry(DateTime.UtcNow, LogLevel.Info, "TestLogger", "Message", null, null); + var timeProvider = new FakeTimeProvider(); + var filter = new SamplingFilter(sampleRate: 10, timeWindow: TimeSpan.FromMinutes(1), + timeProvider: timeProvider); + var entry = new LogEntry(timeProvider.UtcNow, LogLevel.Info, "TestLogger", "Message", null, null); var passedCount = 0; var tasks = new List(); diff --git a/GFramework.Core.Tests/logging/StatisticsAppenderTests.cs b/GFramework.Core.Tests/logging/StatisticsAppenderTests.cs index 902f8cd..b6c1961 100644 --- a/GFramework.Core.Tests/logging/StatisticsAppenderTests.cs +++ b/GFramework.Core.Tests/logging/StatisticsAppenderTests.cs @@ -1,5 +1,6 @@ using GFramework.Core.Abstractions.logging; using GFramework.Core.logging.appenders; +using GFramework.Core.Tests.time; using NUnit.Framework; namespace GFramework.Core.Tests.logging; @@ -10,14 +11,17 @@ public class StatisticsAppenderTests [SetUp] public void SetUp() { - _appender = new StatisticsAppender(); + _timeProvider = new FakeTimeProvider(); + _appender = new StatisticsAppender(_timeProvider); } [TearDown] public void TearDown() { + _appender.Dispose(); } + private FakeTimeProvider _timeProvider = null!; private StatisticsAppender _appender = null!; [Test] @@ -86,9 +90,9 @@ public class StatisticsAppenderTests public void StatisticsAppender_Should_Track_Uptime() { var startTime = _appender.StartTime; - Thread.Sleep(100); + _timeProvider.Advance(TimeSpan.FromSeconds(100)); - Assert.That(_appender.Uptime, Is.GreaterThanOrEqualTo(TimeSpan.FromMilliseconds(100))); + Assert.That(_appender.Uptime, Is.EqualTo(TimeSpan.FromSeconds(100))); Assert.That(_appender.StartTime, Is.EqualTo(startTime)); } @@ -102,7 +106,7 @@ public class StatisticsAppenderTests Assert.That(_appender.ErrorCount, Is.EqualTo(1)); var oldStartTime = _appender.StartTime; - Thread.Sleep(10); + _timeProvider.Advance(TimeSpan.FromSeconds(10)); _appender.Reset(); Assert.That(_appender.TotalCount, Is.EqualTo(0)); @@ -172,10 +176,10 @@ public class StatisticsAppenderTests Assert.DoesNotThrow(() => _appender.Flush()); } - private static LogEntry CreateLogEntry(LogLevel level, string loggerName, string message) + private LogEntry CreateLogEntry(LogLevel level, string loggerName, string message) { return new LogEntry( - DateTime.UtcNow, + _timeProvider.UtcNow, level, loggerName, message, diff --git a/GFramework.Core.Tests/time/FakeTimeProvider.cs b/GFramework.Core.Tests/time/FakeTimeProvider.cs new file mode 100644 index 0000000..791fac7 --- /dev/null +++ b/GFramework.Core.Tests/time/FakeTimeProvider.cs @@ -0,0 +1,41 @@ +using GFramework.Core.Abstractions.time; + +namespace GFramework.Core.Tests.time; + +/// +/// 可控制的时间提供者,用于测试 +/// +public sealed class FakeTimeProvider : ITimeProvider +{ + private DateTime _currentTime; + + /// + /// 创建可控制的时间提供者 + /// + /// 初始时间,默认为 2024-01-01 00:00:00 UTC + public FakeTimeProvider(DateTime? initialTime = null) + { + _currentTime = initialTime ?? new DateTime(2024, 1, 1, 0, 0, 0, DateTimeKind.Utc); + } + + /// + /// 获取当前时间 + /// + public DateTime UtcNow => _currentTime; + + /// + /// 前进指定的时间 + /// + public void Advance(TimeSpan duration) + { + _currentTime = _currentTime.Add(duration); + } + + /// + /// 设置当前时间 + /// + public void SetTime(DateTime time) + { + _currentTime = time; + } +} \ No newline at end of file diff --git a/GFramework.Core/logging/appenders/StatisticsAppender.cs b/GFramework.Core/logging/appenders/StatisticsAppender.cs index 664c497..e23167a 100644 --- a/GFramework.Core/logging/appenders/StatisticsAppender.cs +++ b/GFramework.Core/logging/appenders/StatisticsAppender.cs @@ -1,6 +1,8 @@ using System.Collections.Concurrent; using System.Text; using GFramework.Core.Abstractions.logging; +using GFramework.Core.Abstractions.time; +using GFramework.Core.time; namespace GFramework.Core.logging.appenders; @@ -12,10 +14,21 @@ public sealed class StatisticsAppender : ILogAppender { private readonly ConcurrentDictionary _levelCounts = new(); private readonly ConcurrentDictionary _loggerCounts = new(); + private readonly ITimeProvider _timeProvider; private long _errorCount; - private DateTime _startTime = DateTime.UtcNow; + private long _startTimeTicks; private long _totalCount; + /// + /// 创建日志统计 Appender + /// + /// 时间提供者,默认使用系统时间 + public StatisticsAppender(ITimeProvider? timeProvider = null) + { + _timeProvider = timeProvider ?? new SystemTimeProvider(); + _startTimeTicks = _timeProvider.UtcNow.Ticks; + } + /// /// 获取总日志数量 /// @@ -29,12 +42,12 @@ public sealed class StatisticsAppender : ILogAppender /// /// 获取统计开始时间 /// - public DateTime StartTime => _startTime; + public DateTime StartTime => new(Interlocked.Read(ref _startTimeTicks), DateTimeKind.Utc); /// /// 获取运行时长 /// - public TimeSpan Uptime => DateTime.UtcNow - _startTime; + public TimeSpan Uptime => _timeProvider.UtcNow - StartTime; /// /// 获取错误率(错误数 / 总数) @@ -77,6 +90,14 @@ public sealed class StatisticsAppender : ILogAppender // 统计 Appender 不需要刷新 } + /// + /// 释放资源 + /// + public void Dispose() + { + // 无需释放资源 + } + /// /// 获取指定级别的日志数量 /// @@ -118,7 +139,7 @@ public sealed class StatisticsAppender : ILogAppender Interlocked.Exchange(ref _errorCount, 0); _levelCounts.Clear(); _loggerCounts.Clear(); - _startTime = DateTime.UtcNow; + Interlocked.Exchange(ref _startTimeTicks, _timeProvider.UtcNow.Ticks); } /// @@ -127,8 +148,11 @@ public sealed class StatisticsAppender : ILogAppender public string GenerateReport() { var report = new StringBuilder(); + var startTime = StartTime; + var now = _timeProvider.UtcNow; + report.AppendLine("=== 日志统计报告 ==="); - report.AppendLine($"统计时间: {_startTime:yyyy-MM-dd HH:mm:ss} - {DateTime.UtcNow:yyyy-MM-dd HH:mm:ss}"); + report.AppendLine($"统计时间: {startTime:yyyy-MM-dd HH:mm:ss} - {now:yyyy-MM-dd HH:mm:ss}"); report.AppendLine($"运行时长: {Uptime}"); report.AppendLine($"总日志数: {TotalCount}"); report.AppendLine($"错误日志数: {ErrorCount}"); diff --git a/GFramework.Core/logging/filters/SamplingFilter.cs b/GFramework.Core/logging/filters/SamplingFilter.cs index 23da89e..b20de4b 100644 --- a/GFramework.Core/logging/filters/SamplingFilter.cs +++ b/GFramework.Core/logging/filters/SamplingFilter.cs @@ -1,5 +1,7 @@ using System.Collections.Concurrent; using GFramework.Core.Abstractions.logging; +using GFramework.Core.Abstractions.time; +using GFramework.Core.time; namespace GFramework.Core.logging.filters; @@ -9,8 +11,11 @@ namespace GFramework.Core.logging.filters; /// public sealed class SamplingFilter : ILogFilter { + private const int DefaultMaxLoggers = 1000; + private readonly int _maxLoggers; private readonly int _sampleRate; private readonly ConcurrentDictionary _samplingStates = new(); + private readonly ITimeProvider _timeProvider; private readonly TimeSpan _timeWindow; /// @@ -18,7 +23,13 @@ public sealed class SamplingFilter : ILogFilter /// /// 采样率(每 N 条日志保留 1 条) /// 时间窗口(在此时间内应用采样) - public SamplingFilter(int sampleRate, TimeSpan timeWindow) + /// 最大日志记录器数量,超过后使用共享状态 + /// 时间提供者,默认使用系统时间 + public SamplingFilter( + int sampleRate, + TimeSpan timeWindow, + int maxLoggers = DefaultMaxLoggers, + ITimeProvider? timeProvider = null) { if (sampleRate <= 0) throw new ArgumentException("Sample rate must be greater than 0", nameof(sampleRate)); @@ -26,8 +37,13 @@ public sealed class SamplingFilter : ILogFilter if (timeWindow <= TimeSpan.Zero) throw new ArgumentException("Time window must be greater than zero", nameof(timeWindow)); + if (maxLoggers <= 0) + throw new ArgumentException("Max loggers must be greater than 0", nameof(maxLoggers)); + _sampleRate = sampleRate; _timeWindow = timeWindow; + _maxLoggers = maxLoggers; + _timeProvider = timeProvider ?? new SystemTimeProvider(); } /// @@ -35,32 +51,71 @@ public sealed class SamplingFilter : ILogFilter /// public bool ShouldLog(LogEntry entry) { - // 为每个日志记录器维护独立的采样状态 - var key = entry.LoggerName; - var state = _samplingStates.GetOrAdd(key, _ => new SamplingState()); + // 如果超过最大日志记录器数量,使用共享状态 + var key = _samplingStates.Count >= _maxLoggers ? "*" : entry.LoggerName; + + var state = _samplingStates.GetOrAdd(key, _ => new SamplingState(_timeProvider)); return state.ShouldLog(_sampleRate, _timeWindow); } + /// + /// 清理过期的采样状态 + /// + public void CleanupStaleStates(TimeSpan staleThreshold) + { + var now = _timeProvider.UtcNow; + var keysToRemove = new List(); + + foreach (var kvp in _samplingStates) + { + if (kvp.Key == "*") continue; // 不清理共享状态 + + if (kvp.Value.IsStale(now, staleThreshold)) + { + keysToRemove.Add(kvp.Key); + } + } + + foreach (var key in keysToRemove) + { + _samplingStates.TryRemove(key, out _); + } + } + /// /// 采样状态 /// private sealed class SamplingState { private readonly object _lock = new(); + private readonly ITimeProvider _timeProvider; private long _count; - private DateTime _windowStart = DateTime.UtcNow; + private long _lastAccessTicks; + private long _windowStartTicks; + + public SamplingState(ITimeProvider timeProvider) + { + _timeProvider = timeProvider; + var now = timeProvider.UtcNow.Ticks; + _windowStartTicks = now; + _lastAccessTicks = now; + } public bool ShouldLog(int sampleRate, TimeSpan timeWindow) { lock (_lock) { - var now = DateTime.UtcNow; + var now = _timeProvider.UtcNow; + var nowTicks = now.Ticks; + Interlocked.Exchange(ref _lastAccessTicks, nowTicks); + + var windowStart = new DateTime(Interlocked.Read(ref _windowStartTicks), DateTimeKind.Utc); // 检查是否需要重置时间窗口 - if (now - _windowStart >= timeWindow) + if (now - windowStart >= timeWindow) { - _windowStart = now; + Interlocked.Exchange(ref _windowStartTicks, nowTicks); _count = 0; } @@ -70,5 +125,11 @@ public sealed class SamplingFilter : ILogFilter return _count % sampleRate == 1; } } + + public bool IsStale(DateTime now, TimeSpan staleThreshold) + { + var lastAccess = new DateTime(Interlocked.Read(ref _lastAccessTicks), DateTimeKind.Utc); + return now - lastAccess > staleThreshold; + } } } \ No newline at end of file diff --git a/GFramework.Core/time/SystemTimeProvider.cs b/GFramework.Core/time/SystemTimeProvider.cs new file mode 100644 index 0000000..17d37fa --- /dev/null +++ b/GFramework.Core/time/SystemTimeProvider.cs @@ -0,0 +1,14 @@ +using GFramework.Core.Abstractions.time; + +namespace GFramework.Core.time; + +/// +/// 系统时间提供者,返回真实的系统时间 +/// +public sealed class SystemTimeProvider : ITimeProvider +{ + /// + /// 获取当前 UTC 时间 + /// + public DateTime UtcNow => DateTime.UtcNow; +} \ No newline at end of file