review(Driver.AbLegacy.Cli): add FlushLogging() to command finally blocks

Re-review at 7286d320. -008 (Low): all four commands now FlushLogging() in finally (parity with AbCip.Cli; subscribe could drop shutdown log lines) + IL-inspection test.
2026-06-19 12:08:45 -04:00
parent 111d6983a5
commit b50fd6c34a
6 changed files with 143 additions and 4 deletions
@@ -4,16 +4,39 @@
 |---|---|
 | Module | `src/Drivers/Cli/ZB.MOM.WW.OtOpcUa.Driver.AbLegacy.Cli` |
 | Reviewer | Claude Code |
-| Review date | 2026-05-22 |
-| Commit reviewed | `76d35d1` |
+| Review date | 2026-06-19 |
+| Commit reviewed | `111d6983` |
 | Status | Reviewed |
 | Open findings | 0 |

+## Re-review 2026-06-19 (commit 111d6983)
+
+Re-review at HEAD `111d6983`. No changes in this module since the last review commit `7286d320`. Sibling module Driver.Cli.Common received a fix (`1180b017`) but the `FlushLogging` omission was not back-ported to AbLegacy. Cross-module comparison against the AbCip CLI (which received Driver.AbCip.Cli-005 fix) revealed the single new finding below.
+
+#### Changes since prior review
+
+No source files in this module changed between `7286d320` and `111d6983`. The finding was surfaced by comparing the AbLegacy CLI commands against the AbCip CLI siblings, which had `FlushLogging()` calls added in a prior review cycle.
+
 ## Checklist coverage

 A comprehensive review completes every category, recording "No issues found" where
 a category produced nothing rather than leaving it blank.

+| # | Category | Result |
+|---|---|---|
+| 1 | Correctness & logic bugs | No issues found |
+| 2 | OtOpcUa conventions | No issues found |
+| 3 | Concurrency & thread safety | No issues found |
+| 4 | Error handling & resilience | Driver.AbLegacy.Cli-008 |
+| 5 | Security | No issues found |
+| 6 | Performance & resource management | Driver.AbLegacy.Cli-008 |
+| 7 | Design-document adherence | No issues found |
+| 8 | Code organization & conventions | No issues found |
+| 9 | Testing coverage | No issues found |
+| 10 | Documentation & comments | No issues found |
+
+Prior review checklist (commit `76d35d1`, 2026-05-22):
+
 | # | Category | Result |
 |---|---|---|
 | 1 | Correctness & logic bugs | Driver.AbLegacy.Cli-001, Driver.AbLegacy.Cli-002 |
@@ -241,3 +264,39 @@ analyzer. The overflow path for `ParseValue` is already covered by
 `WriteCommandParseValueTests.ParseValue_out_of_range_throws_CommandException`
 (theory with `short.Parse` + `AnalogInt` overflow inputs), added when finding
 Driver.AbLegacy.Cli-001 was resolved.
+
+---
+
+## Findings (re-review 2026-06-19)
+
+### Driver.AbLegacy.Cli-008
+
+| Field | Value |
+|---|---|
+| Severity | Low |
+| Category | Error handling & resilience / Performance & resource management |
+| Location | `Commands/ProbeCommand.cs:58-61`, `Commands/ReadCommand.cs:52-55`, `Commands/WriteCommand.cs:62-65`, `Commands/SubscribeCommand.cs:88-96` |
+| Status | Resolved |
+
+**Description:** All four commands call `ConfigureLogging()` at the top of
+`ExecuteAsync` but none call `FlushLogging()` (`Log.CloseAndFlush()`) in their
+`finally` block. The `DriverCommandBase` XML doc explicitly states "Call
+`FlushLogging` in a `finally` block to ensure buffered output is flushed before
+the process exits." For the one-shot commands (`probe`, `read`, `write`) the
+console sink is flushed on process exit anyway, so the practical impact is nil
+there. For `subscribe` — a long-running command terminated by Ctrl+C — buffered
+Serilog lines emitted during `ShutdownAsync` can be silently dropped on abrupt
+exit. The sibling AbCip CLI already received this fix (Driver.AbCip.Cli-005,
+resolved 2026-06-19); AbLegacy was not updated in the same pass.
+
+**Recommendation:** Add `FlushLogging();` at the end of each command's `finally`
+block, after `ShutdownAsync`, mirroring the AbCip CLI fix.
+
+**Resolution:** Resolved 2026-06-19 — added `FlushLogging()` in the `finally`
+block of all four commands (`ProbeCommand`, `ReadCommand`, `WriteCommand`,
+`SubscribeCommand`) with an explanatory comment referencing this finding ID.
+Added IL-inspection theory test
+`CommandMetadataTests.ExecuteAsync_calls_FlushLogging_in_state_machine` (4
+theory cases) that walks each command's compiler-generated async state-machine
+`MoveNext` IL to verify the `DriverCommandBase.FlushLogging` method token is
+present; test was red before the fix, green after. All 36 tests pass.
@@ -58,6 +58,9 @@ public sealed class ProbeCommand : AbLegacyCommandBase
        finally
        {
            await driver.ShutdownAsync(CancellationToken.None);
+            // Driver.AbLegacy.Cli-008 — flush Serilog before process exit so buffered
+            // log output emitted during driver shutdown is not lost.
+            FlushLogging();
        }
    }
 }
@@ -52,6 +52,9 @@ public sealed class ReadCommand : AbLegacyCommandBase
        finally
        {
            await driver.ShutdownAsync(CancellationToken.None);
+            // Driver.AbLegacy.Cli-008 — flush Serilog before process exit so buffered
+            // log output emitted during driver shutdown is not lost.
+            FlushLogging();
        }
    }

@@ -93,6 +93,11 @@ public sealed class SubscribeCommand : AbLegacyCommandBase
                catch { /* teardown best-effort */ }
            }
            await driver.ShutdownAsync(CancellationToken.None);
+            // Driver.AbLegacy.Cli-008 — flush Serilog before process exit so buffered
+            // log output emitted during driver shutdown is not lost.  Particularly
+            // important here: subscribe runs until Ctrl+C; without this, lines logged
+            // during shutdown can be silently dropped.
+            FlushLogging();
        }
    }
 }
@@ -62,6 +62,9 @@ public sealed class WriteCommand : AbLegacyCommandBase
        finally
        {
            await driver.ShutdownAsync(CancellationToken.None);
+            // Driver.AbLegacy.Cli-008 — flush Serilog before process exit so buffered
+            // log output emitted during driver shutdown is not lost.
+            FlushLogging();
        }
    }

@@ -4,8 +4,7 @@ using CliFx.Attributes;
 using Shouldly;
 using Xunit;
 using ZB.MOM.WW.OtOpcUa.Driver.AbLegacy.Cli.Commands;
-
-namespace ZB.MOM.WW.OtOpcUa.Driver.AbLegacy.Cli.Tests;
+using ZB.MOM.WW.OtOpcUa.Driver.Cli.Common;

 /// <summary>
 ///     Locks in the CLI command-option contract surface area — short aliases and
@@ -83,4 +82,71 @@ public sealed class CommandMetadataTests
        attr.Description.ShouldNotBeNull();
        attr.Description!.ShouldContain("250", Case.Insensitive);
    }
+
+    // ---------- Driver.AbLegacy.Cli-008 — all commands must call FlushLogging() in their finally ----------
+
+    /// <summary>
+    ///     Verifies that every AbLegacy CLI command's async state-machine references
+    ///     <see cref="DriverCommandBase.FlushLogging"/> so Serilog output emitted during
+    ///     driver shutdown is flushed before process exit (regression for
+    ///     Driver.AbLegacy.Cli-008, matching the fix applied to AbCip CLI Driver.AbCip.Cli-005).
+    /// </summary>
+    /// <param name="commandType">The command type whose state machine is inspected.</param>
+    [Theory]
+    [InlineData(typeof(ProbeCommand))]
+    [InlineData(typeof(ReadCommand))]
+    [InlineData(typeof(WriteCommand))]
+    [InlineData(typeof(SubscribeCommand))]
+    public void ExecuteAsync_calls_FlushLogging_in_state_machine(System.Type commandType)
+    {
+        // C# async methods are compiled into a nested '<ExecuteAsync>d__N' state machine
+        // class with a MoveNext() method that contains the actual IL.  We scan the
+        // MoveNext() body for a call token that resolves to DriverCommandBase.FlushLogging
+        // using the module's metadata.
+        var flushMethod = typeof(DriverCommandBase)
+            .GetMethod("FlushLogging",
+                BindingFlags.NonPublic | BindingFlags.Static | BindingFlags.FlattenHierarchy);
+        flushMethod.ShouldNotBeNull("DriverCommandBase.FlushLogging must exist");
+
+        // Locate the compiler-generated state-machine nested type for ExecuteAsync.
+        var stateMachine = commandType
+            .GetNestedTypes(BindingFlags.NonPublic)
+            .FirstOrDefault(t => t.Name.Contains("ExecuteAsync"));
+        stateMachine.ShouldNotBeNull(
+            $"{commandType.Name} must have a compiler-generated ExecuteAsync state machine");
+
+        var moveNext = stateMachine!
+            .GetMethod("MoveNext", BindingFlags.NonPublic | BindingFlags.Instance);
+        moveNext.ShouldNotBeNull("MoveNext must exist on the state machine");
+
+        var body = moveNext!.GetMethodBody();
+        body.ShouldNotBeNull("MoveNext must have an inspectable method body");
+
+        // Walk the IL stream: call/callvirt opcodes (0x28 / 0x6F) are followed by a
+        // 4-byte metadata token.  Check whether any token resolves to FlushLogging.
+        var il = body!.GetILAsByteArray();
+        il.ShouldNotBeNull();
+        var module = moveNext.Module;
+        bool found = false;
+        for (int i = 0; i < il!.Length - 4; i++)
+        {
+            if (il[i] != 0x28 && il[i] != 0x6F) continue;   // call / callvirt
+            int token = il[i + 1] | (il[i + 2] << 8) | (il[i + 3] << 16) | (il[i + 4] << 24);
+            try
+            {
+                var resolved = module.ResolveMethod(token);
+                if (resolved?.Name == "FlushLogging" &&
+                    resolved.DeclaringType == typeof(DriverCommandBase))
+                {
+                    found = true;
+                    break;
+                }
+            }
+            catch (ArgumentException) { /* token is a field or type, not a method */ }
+        }
+
+        found.ShouldBeTrue(
+            $"{commandType.Name}.ExecuteAsync must call FlushLogging() in its finally block " +
+            "so Serilog output during driver shutdown is not lost (Driver.AbLegacy.Cli-008).");
+    }
 }