dohertj2/lmxopcua
1
0
Fork 0
Code Issues 2 Pull Requests 1 Actions Packages Projects Releases Wiki Activity

review(Driver.FOCAS.Cli): FlushLogging() in finally + fix misleading detach comment

Browse Source 
Re-review at 7286d320. -006 (Low): FlushLogging() in all command finally blocks + tests.
-007: rewrite the inaccurate handler-detach comment (cleanup is via await using disposal).
This commit is contained in:
Joseph Doherty
2026-06-19 12:08:45 -04:00
parent b50fd6c34a
commit 754c5a3684
6 changed files with 191 additions and 25 deletions
Download Patch File Download Diff File Expand all files Collapse all files
code-reviews/Driver.FOCAS.Cli/findings.md
+82 -2
View File
@@ -4,8 +4,8 @@
|---|---|
| Module | `src/Drivers/Cli/ZB.MOM.WW.OtOpcUa.Driver.FOCAS.Cli` |
| Reviewer | Claude Code |
| Review date | 2026-05-22 |
| Commit reviewed | `76d35d1` |
| Review date | 2026-06-19 |
| Commit reviewed | `7286d320` |
| Status | Reviewed |
| Open findings | 0 |
@@ -229,3 +229,83 @@ promises, restoring parity between the docs and the shipped behaviour. Regressio
shortlist again; the existing well-known shortlist `[Theory]` was extended with
the same five entries to enforce the exact `0x... (Name)` rendering. Suite now
47 green (was 42).
## Re-review 2026-06-19 (commit 7286d320)
All five prior findings (001–005) remain Resolved. The test suite now has 52 tests
(48 pre-existing + 4 added in this re-review). Two new findings were identified.
#### Checklist coverage (re-review)
| # | Category | Result |
|---|---|---|
| 1 | Correctness & logic bugs | No new issues found |
| 2 | OtOpcUa conventions | No new issues found |
| 3 | Concurrency & thread safety | No new issues found |
| 4 | Error handling & resilience | No new issues found |
| 5 | Security | No new issues found |
| 6 | Performance & resource management | No new issues found |
| 7 | Design-document adherence | No new issues found |
| 8 | Code organization & conventions | Driver.FOCAS.Cli-006, Driver.FOCAS.Cli-007 |
| 9 | Testing coverage | No new issues found |
| 10 | Documentation & comments | Driver.FOCAS.Cli-007 |
### Driver.FOCAS.Cli-006
| Field | Value |
|---|---|
| Severity | Low |
| Category | Code organization & conventions |
| Location | `Commands/ProbeCommand.cs`, `Commands/ReadCommand.cs`, `Commands/WriteCommand.cs`, `Commands/SubscribeCommand.cs` |
| Status | Resolved |
**Description:** `DriverCommandBase.ConfigureLogging` was extended between review
commits to document that callers must call `FlushLogging()` in a `finally` block
to ensure buffered Serilog output is flushed before process exit. Every sibling
driver CLI (Modbus, AbCip, AbLegacy, TwinCAT) honours this contract, but all four
FOCAS CLI commands were missing the call. With the Console sink (Serilog 6.0.0)
there is no actual data loss today because `System.Console.Out` auto-flushes;
however the gap is a maintenance hazard: if a file sink or an async sink is ever
added to the logger configuration, the omission becomes data-losing. The
inconsistency with sibling CLIs also makes the codebase misleading for reviewers.
**Recommendation:** Add `try/finally` wrappers in ProbeCommand, ReadCommand, and
WriteCommand (which had no finally blocks since the -004 cleanup) and extend
SubscribeCommand's existing finally block, calling `FlushLogging()` in each.
Add a convention test (parallel to `CommandDisposalConventionsTests`) that
scans source files and asserts the call is present, preventing silent regressions.
**Resolution:** Resolved 2026-06-19 — added `try/finally` wrappers with
`FlushLogging()` to `ProbeCommand`, `ReadCommand`, and `WriteCommand`; extended
SubscribeCommand's existing `finally` block with the same call. Added
`FlushLoggingConventionsTests` with a `[Theory]` over all four command files so
the call cannot be silently dropped in future refactors. Suite now 52 green (was 48).
### Driver.FOCAS.Cli-007
| Field | Value |
|---|---|
| Severity | Low |
| Category | Documentation & comments |
| Location | `Commands/SubscribeCommand.cs:113-120` |
| Status | Resolved |
**Description:** The comment in the `SubscribeCommand.finally` block (added by
the -002 resolution) said "detach the OnDataChange handler before unsubscribe +
disposal" — but no `-=` operator call exists in the block. The comment's claim
was factually incorrect: handler cleanup is achieved by driver disposal (via
`await using`), which tears down the `PollGroupEngine` and prevents further
`OnDataChange` events; not by explicit unsubscription from the event. A
parenthetical note at the end of the original comment partially explained the
real mechanism, but the leading sentence was still misleading for future readers.
**Recommendation:** Reword the comment to accurately describe what the code does:
`UnsubscribeAsync` stops the poll-group ticker (a subscription lifecycle step);
the anonymous handler is never explicitly removed via `-=`; driver disposal via
`await using` is the real cleanup.
**Resolution:** Resolved 2026-06-19 — rewrote the comment to correctly describe
the two-step teardown: `UnsubscribeAsync` halts the poll ticker (subscription
lifecycle), then `await using` disposes the driver and tears down
`PollGroupEngine` (real cleanup). Removed the incorrect claim about `-=`
detachment. No behavioral change; documentation only.
src/Drivers/Cli/ZB.MOM.WW.OtOpcUa.Driver.FOCAS.Cli/Commands/ProbeCommand.cs
+20 -10
View File
@@ -43,16 +43,26 @@ public sealed class ProbeCommand : FocasCommandBase
// already invokes ShutdownAsync, so a redundant explicit ShutdownAsync(CancellationToken.None)
// in a finally block ran shutdown twice. The await-using on the next line is enough.
await using var driver = new FocasDriver(options, DriverInstanceId);
await driver.InitializeAsync("{}", ct);
var snapshot = await driver.ReadAsync(["__probe"], ct);
var health = driver.GetHealth();
try
{
await driver.InitializeAsync("{}", ct);
var snapshot = await driver.ReadAsync(["__probe"], ct);
var health = driver.GetHealth();
await console.Output.WriteLineAsync($"CNC: {CncHost}:{CncPort}");
await console.Output.WriteLineAsync($"Series: {Series}");
await console.Output.WriteLineAsync($"Health: {health.State}");
if (health.LastError is { } err)
await console.Output.WriteLineAsync($"Last error: {err}");
await console.Output.WriteLineAsync();
await console.Output.WriteLineAsync(SnapshotFormatter.Format(Address, snapshot[0]));
await console.Output.WriteLineAsync($"CNC: {CncHost}:{CncPort}");
await console.Output.WriteLineAsync($"Series: {Series}");
await console.Output.WriteLineAsync($"Health: {health.State}");
if (health.LastError is { } err)
await console.Output.WriteLineAsync($"Last error: {err}");
await console.Output.WriteLineAsync();
await console.Output.WriteLineAsync(SnapshotFormatter.Format(Address, snapshot[0]));
}
finally
{
// Driver.FOCAS.Cli-006: flush Serilog before process exit so buffered log output
// emitted during driver shutdown is not silently dropped (matching DriverCommandBase
// docs and every sibling CLI — Modbus / AbCip / AbLegacy / TwinCAT).
FlushLogging();
}
}
}
src/Drivers/Cli/ZB.MOM.WW.OtOpcUa.Driver.FOCAS.Cli/Commands/ReadCommand.cs
+13 -3
View File
@@ -44,9 +44,19 @@ public sealed class ReadCommand : FocasCommandBase
// already invokes ShutdownAsync, so a redundant explicit ShutdownAsync(CancellationToken.None)
// in a finally block ran shutdown twice. The await-using on the next line is enough.
await using var driver = new FocasDriver(options, DriverInstanceId);
await driver.InitializeAsync("{}", ct);
var snapshot = await driver.ReadAsync([tagName], ct);
await console.Output.WriteLineAsync(SnapshotFormatter.Format(Address, snapshot[0]));
try
{
await driver.InitializeAsync("{}", ct);
var snapshot = await driver.ReadAsync([tagName], ct);
await console.Output.WriteLineAsync(SnapshotFormatter.Format(Address, snapshot[0]));
}
finally
{
// Driver.FOCAS.Cli-006: flush Serilog before process exit so buffered log output
// emitted during driver shutdown is not silently dropped (matching DriverCommandBase
// docs and every sibling CLI — Modbus / AbCip / AbLegacy / TwinCAT).
FlushLogging();
}
}
/// <summary>Constructs a tag name from address and data type.</summary>
src/Drivers/Cli/ZB.MOM.WW.OtOpcUa.Driver.FOCAS.Cli/Commands/SubscribeCommand.cs
+10 -7
View File
@@ -110,16 +110,19 @@ public sealed class SubscribeCommand : FocasCommandBase
{
if (handle is not null)
{
// Driver.FOCAS.Cli-002: detach the OnDataChange handler before unsubscribe +
// disposal for symmetry with the handle teardown, so a future refactor that
// reuses the driver after the subscribe verb returns wouldn't leak a
// dangling subscription.
// (Single anonymous handler instance is captured implicitly by `await using`
// disposing the driver immediately afterwards; the unsubscribe + dispose
// sequence is what really cleans up here.)
// Driver.FOCAS.Cli-002: stop the subscription before disposal — UnsubscribeAsync
// halts the poll-group ticker so no further OnDataChange events fire. The
// anonymous handler is never explicitly removed via -=; instead, driver disposal
// (via `await using` immediately after this finally) tears down the PollGroupEngine,
// which is the real cleanup. The unsubscribe here is a best-effort subscription
// lifecycle step so the CNC-side session is cleanly released before teardown.
try { await driver.UnsubscribeAsync(handle, CancellationToken.None); }
catch { /* teardown best-effort */ }
}
// Driver.FOCAS.Cli-006: flush Serilog before process exit so buffered log output
// emitted during driver shutdown is not silently dropped (matching DriverCommandBase
// docs and every sibling CLI — Modbus / AbCip / AbLegacy / TwinCAT).
FlushLogging();
}
}
}
src/Drivers/Cli/ZB.MOM.WW.OtOpcUa.Driver.FOCAS.Cli/Commands/WriteCommand.cs
+13 -3
View File
@@ -54,9 +54,19 @@ public sealed class WriteCommand : FocasCommandBase
// already invokes ShutdownAsync, so a redundant explicit ShutdownAsync(CancellationToken.None)
// in a finally block ran shutdown twice. The await-using on the next line is enough.
await using var driver = new FocasDriver(options, DriverInstanceId);
await driver.InitializeAsync("{}", ct);
var results = await driver.WriteAsync([new WriteRequest(tagName, parsed)], ct);
await console.Output.WriteLineAsync(SnapshotFormatter.FormatWrite(Address, results[0]));
try
{
await driver.InitializeAsync("{}", ct);
var results = await driver.WriteAsync([new WriteRequest(tagName, parsed)], ct);
await console.Output.WriteLineAsync(SnapshotFormatter.FormatWrite(Address, results[0]));
}
finally
{
// Driver.FOCAS.Cli-006: flush Serilog before process exit so buffered log output
// emitted during driver shutdown is not silently dropped (matching DriverCommandBase
// docs and every sibling CLI — Modbus / AbCip / AbLegacy / TwinCAT).
FlushLogging();
}
}
/// <summary>Parse <c>--value</c> per <see cref="FocasDataType"/>, invariant culture throughout.</summary>
tests/Drivers/Cli/ZB.MOM.WW.OtOpcUa.Driver.FOCAS.Cli.Tests/FlushLoggingConventionsTests.cs
+53
View File
@@ -0,0 +1,53 @@
using Shouldly;
using Xunit;
namespace ZB.MOM.WW.OtOpcUa.Driver.FOCAS.Cli.Tests;
/// <summary>
/// Driver.FOCAS.Cli-006: every FOCAS CLI command must call
/// <c>FlushLogging()</c> in a <c>finally</c> block so buffered Serilog output
/// emitted during driver shutdown is not silently dropped when the process exits.
/// <c>DriverCommandBase</c> documents this requirement and every sibling CLI
/// (Modbus / S7 / AbCip / AbLegacy / TwinCAT) honours it; the FOCAS CLI was
/// the only one missing the call.
/// </summary>
[Trait("Category", "Unit")]
public sealed class FlushLoggingConventionsTests
{
private static readonly string CommandsDir = LocateCommandsDir();
/// <summary>
/// Verifies that a FOCAS CLI command source file contains a <c>FlushLogging()</c>
/// call, matching the pattern used by every other driver CLI in the repo.
/// </summary>
/// <param name="commandFile">The command source file name to inspect.</param>
[Theory]
[InlineData("ProbeCommand.cs")]
[InlineData("ReadCommand.cs")]
[InlineData("WriteCommand.cs")]
[InlineData("SubscribeCommand.cs")]
public void Command_calls_FlushLogging_in_finally_block(string commandFile)
{
var path = Path.Combine(CommandsDir, commandFile);
File.Exists(path).ShouldBeTrue($"Expected {path} to exist.");
var source = File.ReadAllText(path);
// DriverCommandBase.ConfigureLogging XML doc says:
// "Call FlushLogging in a finally block to ensure buffered output is flushed
// before the process exits."
// Every other driver CLI (Modbus, AbCip, AbLegacy, TwinCAT) calls FlushLogging()
// from a finally block. The FOCAS CLI must do the same so buffered Serilog output
// during driver shutdown is not lost when the process exits abruptly.
source.ShouldContain("FlushLogging()");
}
private static string LocateCommandsDir()
{
var dir = new DirectoryInfo(AppContext.BaseDirectory);
while (dir is not null && !File.Exists(Path.Combine(dir.FullName, "ZB.MOM.WW.OtOpcUa.slnx")))
dir = dir.Parent;
dir.ShouldNotBeNull("Could not find solution root (ZB.MOM.WW.OtOpcUa.slnx).");
return Path.Combine(
dir!.FullName, "src", "Drivers", "Cli", "ZB.MOM.WW.OtOpcUa.Driver.FOCAS.Cli", "Commands");
}
}