mirror of
https://github.com/GeWuYou/GFramework.git
synced 2026-05-07 17:21:16 +08:00
fix(core): 修复 AsyncLogAppender 刷新竞态
- 修复 AsyncLogAppender 在队列已被后台线程提前清空时 Flush 仍可能超时失败的问题 - 新增 AsyncLogAppender 已处理队列场景的稳定回归测试并重新验证 GFramework.Core.Tests - 更新 analyzer-warning-reduction 的 tracking 与 trace 记录 PR267 failed-test follow-up
This commit is contained in:
GeWuYou
parent
685897f2de
commit
a9f86348ff
@ -120,6 +120,30 @@ public class AsyncLogAppenderTests
|
||||
Assert.That(observedResults, Has.All.True);
|
||||
}
|
||||
|
||||
[Test]
|
||||
public void Flush_WhenEntriesAlreadyProcessed_Should_Still_ReportSuccess()
|
||||
{
|
||||
using var appendCompleted = new ManualResetEventSlim();
|
||||
var innerAppender = new SignalingAppender(appendCompleted);
|
||||
using var asyncAppender = new AsyncLogAppender(innerAppender, bufferSize: 10);
|
||||
var observedResults = new List<bool>();
|
||||
|
||||
asyncAppender.Append(new LogEntry(DateTime.UtcNow, LogLevel.Info, "TestLogger", "Already processed", null, null));
|
||||
Assert.That(appendCompleted.Wait(TimeSpan.FromSeconds(1)), Is.True);
|
||||
|
||||
asyncAppender.OnFlushCompleted += (_, eventArgs) => observedResults.Add(eventArgs.Success);
|
||||
|
||||
var result = asyncAppender.Flush(TimeSpan.FromSeconds(1));
|
||||
|
||||
Assert.Multiple(() =>
|
||||
{
|
||||
Assert.That(result, Is.True);
|
||||
Assert.That(observedResults, Has.Count.EqualTo(1));
|
||||
Assert.That(observedResults, Has.All.True);
|
||||
Assert.That(innerAppender.FlushCount, Is.EqualTo(1));
|
||||
});
|
||||
}
|
||||
|
||||
[Test]
|
||||
public void Dispose_ShouldProcessRemainingEntries()
|
||||
{
|
||||
@ -308,6 +332,32 @@ public class AsyncLogAppenderTests
|
||||
}
|
||||
}
|
||||
|
||||
private sealed class SignalingAppender : ILogAppender
|
||||
{
|
||||
private readonly ManualResetEventSlim _appendCompleted;
|
||||
|
||||
public SignalingAppender(ManualResetEventSlim appendCompleted)
|
||||
{
|
||||
_appendCompleted = appendCompleted;
|
||||
}
|
||||
|
||||
public int FlushCount { get; private set; }
|
||||
|
||||
public void Append(LogEntry entry)
|
||||
{
|
||||
_appendCompleted.Set();
|
||||
}
|
||||
|
||||
public void Flush()
|
||||
{
|
||||
FlushCount++;
|
||||
}
|
||||
|
||||
public void Dispose()
|
||||
{
|
||||
}
|
||||
}
|
||||
|
||||
private class ThrowingAppender : ILogAppender
|
||||
{
|
||||
public void Append(LogEntry entry)
|
||||
|
||||
@ -23,6 +23,7 @@ public sealed class AsyncLogAppender : ILogAppender
|
||||
private readonly Action<Exception>? _processingErrorHandler;
|
||||
private readonly Task _processingTask;
|
||||
private bool _disposed;
|
||||
private int _isProcessingEntry;
|
||||
private volatile bool _flushRequested;
|
||||
|
||||
/// <summary>
|
||||
@ -140,6 +141,7 @@ public sealed class AsyncLogAppender : ILogAppender
|
||||
|
||||
// 请求刷新
|
||||
_flushRequested = true;
|
||||
TrySignalFlushCompletion();
|
||||
|
||||
try
|
||||
{
|
||||
@ -166,6 +168,7 @@ public sealed class AsyncLogAppender : ILogAppender
|
||||
{
|
||||
try
|
||||
{
|
||||
Volatile.Write(ref _isProcessingEntry, 1);
|
||||
_innerAppender.Append(entry);
|
||||
}
|
||||
catch (Exception ex)
|
||||
@ -173,18 +176,12 @@ public sealed class AsyncLogAppender : ILogAppender
|
||||
// 后台消费失败只通过显式回调暴露，避免测试宿主将 stderr 误判为测试告警。
|
||||
ReportProcessingError(ex);
|
||||
}
|
||||
|
||||
// 检查是否有刷新请求且通道已空
|
||||
if (_flushRequested && _channel.Reader.Count == 0)
|
||||
finally
|
||||
{
|
||||
_innerAppender.Flush();
|
||||
|
||||
// 发出完成信号
|
||||
if (_flushSemaphore.CurrentCount == 0)
|
||||
{
|
||||
_flushSemaphore.Release();
|
||||
}
|
||||
Volatile.Write(ref _isProcessingEntry, 0);
|
||||
}
|
||||
|
||||
TrySignalFlushCompletion();
|
||||
}
|
||||
}
|
||||
catch (OperationCanceledException)
|
||||
@ -209,6 +206,29 @@ public sealed class AsyncLogAppender : ILogAppender
|
||||
}
|
||||
}
|
||||
|
||||
/// <summary>
|
||||
/// 在后台消费者已经处理完当前条目且队列为空时完成挂起的 Flush 请求。
|
||||
/// </summary>
|
||||
private void TrySignalFlushCompletion()
|
||||
{
|
||||
if (!_flushRequested)
|
||||
{
|
||||
return;
|
||||
}
|
||||
|
||||
if (Volatile.Read(ref _isProcessingEntry) != 0 || _channel.Reader.Count != 0)
|
||||
{
|
||||
return;
|
||||
}
|
||||
|
||||
_innerAppender.Flush();
|
||||
|
||||
if (_flushSemaphore.CurrentCount == 0)
|
||||
{
|
||||
_flushSemaphore.Release();
|
||||
}
|
||||
}
|
||||
|
||||
/// <summary>
|
||||
/// 上报后台处理异常，同时隔离观察者自身抛出的错误，避免终止处理循环。
|
||||
/// 取消相关异常表示关闭流程中的预期控制流，不应被视为后台处理失败。
|
||||
|
||||
@ -7,12 +7,12 @@
|
||||
|
||||
## 当前恢复点
|
||||
|
||||
- 恢复点编号：`ANALYZER-WARNING-REDUCTION-RP-014`
|
||||
- 当前阶段：`Phase 14`
|
||||
- 恢复点编号：`ANALYZER-WARNING-REDUCTION-RP-015`
|
||||
- 当前阶段：`Phase 15`
|
||||
- 当前焦点：
|
||||
- 当前分支 PR #267 的 latest CodeRabbit unresolved threads、outside-diff comment 与 nitpick comment 已完成本地复核
|
||||
- 本轮优先收口仍然成立的 follow-up：`AsyncLogAppender` 接口路径重复触发 `OnFlushCompleted`、事件/XML 契约缺口、
|
||||
`PhaseChanged` 迁移文档说明与 `ai-plan` 基线表述歧义
|
||||
- 当前分支 PR #267 的失败测试已通过 `$gframework-pr-review` 与本地整包测试完成复核
|
||||
- 已确认并修复 `AsyncLogAppender.Flush()` 在“后台线程先清空队列”场景下可能超时返回 `false` 的竞态
|
||||
- 已补上稳定回归测试，避免只在整包 `GFramework.Core.Tests` 里偶发暴露的刷新完成信号问题再次回归
|
||||
- 下一轮默认恢复到 `MA0016` 或 `MA0002` 低风险批次；`MA0015` 与 `MA0077` 继续作为尾项顺手吸收
|
||||
- `GFramework.Godot` 的 `Timing.cs` 已同步适配新事件签名，但当前 worktree 的 Godot restore 资产仍受 Windows fallback package folder 干扰，独立 build 需在修复资产后补跑
|
||||
- 后续继续按 warning 类型和数量批处理，而不是回退到按单文件切片推进
|
||||
@ -32,6 +32,8 @@
|
||||
并同步更新 `GFramework.Godot` 订阅点、定向测试与 `docs/zh-CN` 示例
|
||||
- 已完成当前 PR #267 review follow-up：修复 `AsyncLogAppender` 的 `ILogAppender.Flush()` 双重完成通知，并补齐
|
||||
`PhaseChanged` / `CoroutineExceptionEventArgs` XML 文档、`PhaseChanged` 迁移说明和 `ai-plan` 基线注释
|
||||
- 已完成当前 PR #267 failed-test follow-up：修复 `AsyncLogAppender.Flush()` 在队列已被后台线程提前清空时仍可能
|
||||
等待满默认超时并返回 `false` 的竞态，并通过整包 `GFramework.Core.Tests` 重新验证
|
||||
- 当前 `GFramework.Core` `net8.0` warnings-only 基线已降到 `9` 条；剩余 warning 集中在
|
||||
`MA0016` 集合抽象接口、`MA0002` comparer 重载，以及 `MA0015` / `MA0077` 两个低数量尾项
|
||||
|
||||
@ -62,6 +64,8 @@
|
||||
非标准签名；`GFramework.Core` `net8.0` warnings-only 基线由 `15` 降至 `9`
|
||||
- `RP-014` 使用 `gframework-pr-review` 复核当前分支 PR #267 的 latest head review threads、outside-diff comment 与
|
||||
nitpick comment 后，确认 8 条高信号项中仍成立的是 1 个行为 bug 与 7 个文档/测试/跟踪缺口，并按最小改动收口
|
||||
- `RP-015` 使用 `$gframework-pr-review` 复核 PR #267 的 CTRF 失败测试评论后，确认 `AsyncLogAppender` 仍存在
|
||||
“队列已空但 Flush 仍超时失败”的竞态；该问题在本地整包 `GFramework.Core.Tests` 中可复现，现已修复并补上稳定回归测试
|
||||
- 当前工作树分支 `fix/analyzer-warning-reduction-batch` 已在 `ai-plan/public/README.md` 建立 topic 映射
|
||||
|
||||
## 当前风险
|
||||
@ -149,6 +153,11 @@
|
||||
- 结果：`9 Warning(s)`，`0 Error(s)`；`AsyncLogAppender` 行为修复与 XML / 文档补充未引入新的 `GFramework.Core` `net8.0` 构建错误
|
||||
- `dotnet test GFramework.Core.Tests/GFramework.Core.Tests.csproj -c Release --no-restore --filter "FullyQualifiedName~CoroutineSchedulerTests.Scheduler_Should_Raise_OnCoroutineException_With_EventArgs|FullyQualifiedName~AsyncLogAppenderTests.Flush_Should_Raise_OnFlushCompleted_With_Sender_And_Result|FullyQualifiedName~AsyncLogAppenderTests.ILogAppender_Flush_Should_Raise_OnFlushCompleted_Only_Once|FullyQualifiedName~ArchitectureLifecycleBehaviorTests.InitializeAsync_Should_Raise_PhaseChanged_With_Sender_And_EventArgs" -m:1 -p:RestoreFallbackFolders="" -nologo`
|
||||
- 结果：`4 Passed`，`0 Failed`
|
||||
- `RP-015` 的验证结果：
|
||||
- `dotnet test GFramework.Core.Tests/GFramework.Core.Tests.csproj -c Release --no-restore --disable-build-servers --filter "FullyQualifiedName~AsyncLogAppenderTests"`
|
||||
- 结果：`15 Passed`，`0 Failed`
|
||||
- `dotnet test GFramework.Core.Tests/GFramework.Core.Tests.csproj -c Release --no-restore --disable-build-servers`
|
||||
- 结果：`1607 Passed`，`0 Failed`
|
||||
- active 跟踪文件只保留当前恢复点、活跃事实、风险与下一步，不再重复保存已完成阶段的长篇历史
|
||||
|
||||
## 下一步
|
||||
|
||||
@ -1,5 +1,40 @@
|
||||
# Analyzer Warning Reduction 追踪
|
||||
|
||||
## 2026-04-21 — RP-015
|
||||
|
||||
### 阶段：PR #267 failed-test follow-up 收口（RP-015）
|
||||
|
||||
- 触发背景：
|
||||
- 用户指出“测试好像挂了”，按 `$gframework-pr-review` 重新抓取当前分支 PR #267 的 review / checks / CTRF 评论
|
||||
- PR 评论里同时存在一次 `2143 passed / 0 failed` 与一次 `1 failed` 的 CTRF 报告；失败用例为
|
||||
`AsyncLogAppenderTests.ILogAppender_Flush_Should_Raise_OnFlushCompleted_Only_Once`
|
||||
- 复核过程：
|
||||
- 先跑定向单测时该用例可以单独通过，因此继续核对 PR head commit 与本地整包测试，避免把旧评论误判成当前状态
|
||||
- 在 `dotnet test GFramework.Core.Tests/GFramework.Core.Tests.csproj -c Release --no-restore --disable-build-servers`
|
||||
下成功复现相同失败，确认问题仍存在于当前代码，而不是单纯的 PR 评论残留
|
||||
- 同时发现当前沙箱内如果用 shell 循环反复启动 `dotnet test`，会触发 `MSBuild` named pipe `Permission denied`
|
||||
的环境噪音；后续验证改为单次命令并显式加 `--disable-build-servers`
|
||||
- 根因结论：
|
||||
- `AsyncLogAppender.Flush()` 只依赖后台消费循环在处理完某个条目后检查 `_flushRequested`
|
||||
- 当调用方执行 `Flush()` 前，后台线程已经把最后一个条目消费完并离开检查点时，`Flush()` 会一直等到默认超时，
|
||||
最终通过 `OnFlushCompleted` 发出一次 `Success=false` 的错误完成通知
|
||||
- 实施修复：
|
||||
- 为 `AsyncLogAppender` 增加“当前是否仍有条目在途处理”的状态跟踪
|
||||
- 抽出 `TrySignalFlushCompletion()`，让 `Flush()` 在请求发出后先做一次即时完成判定；后台循环在每次处理结束后也复用
|
||||
这条判定路径
|
||||
- 在 `AsyncLogAppenderTests` 中新增 `Flush_WhenEntriesAlreadyProcessed_Should_Still_ReportSuccess`，稳定覆盖
|
||||
“调用 Flush 前队列已被后台线程清空”的场景
|
||||
- 验证结果：
|
||||
- `dotnet test GFramework.Core.Tests/GFramework.Core.Tests.csproj -c Release --no-restore --disable-build-servers --filter "FullyQualifiedName~AsyncLogAppenderTests"`
|
||||
- 结果：`15 Passed`，`0 Failed`
|
||||
- `dotnet test GFramework.Core.Tests/GFramework.Core.Tests.csproj -c Release --no-restore --disable-build-servers`
|
||||
- 结果：`1607 Passed`，`0 Failed`
|
||||
- 当前结论：
|
||||
- PR #267 的 failed-test 信号不是纯粹的历史评论噪音，而是当前实现里仍存在的时序竞态
|
||||
- 修复后该竞态已被稳定回归测试覆盖，当前 `GFramework.Core.Tests` 整包通过
|
||||
- 下一步建议：
|
||||
- 若继续 analyzer warning reduction 主题，恢复到 `MA0016` / `MA0002` 低风险批次
|
||||
|
||||
## 2026-04-21 — RP-014
|
||||
|
||||
### 阶段：PR #267 review follow-up 收口（RP-014）
|
||||
|
||||
Loading…
x
Reference in New Issue
Block a user