masarray · Oct 20, 2026
diff --git a/CHANGELOG.md b/CHANGELOG.md
@@ -1,5 +1,11 @@
 # Changelog
 
+## Control/report isolation trial — 2026-10-20
+
+- Reject non-RCB InformationReport shapes before persistent single-monitor fallback; control termination and LastApplError remain available to independent control subscribers.
+- Include monotonic service duration and post-response wait in each control wire-step detail. UTC marks local service start, not wire send. This separates SBOw/Operate service latency from asynchronous completion wait without changing timeout, checks, or command sequencing.
+- Synthetic regression coverage added; physical latency improvement is not yet established.
+
 All notable public changes to ARIEC61850 are recorded here. The project is still evolving toward stable semantic releases; entries are grouped by engineering milestone until a formal versioning policy is adopted.
 
 ## Unreleased — public wording, provenance and release assurance

diff --git a/src/AR.Iec61850/Control/Iec61850ControlObjectSession.cs b/src/AR.Iec61850/Control/Iec61850ControlObjectSession.cs
@@ -27,6 +27,10 @@ private sealed class AssociationControlState
     private CancellationTokenSource? _selectionLeaseCts;
     private bool _ownsLock;
     private bool _disposed;
+    private DateTimeOffset _serviceStartedUtc;
+    private TimeSpan _serviceElapsed;
+    private long _serviceCompletedTimestamp;
+
 
     internal Iec61850ControlObjectSession(
         IIec61850ControlTransport transport,
@@ -115,7 +119,7 @@ private async Task<Iec61850ControlActionResult> SelectCoreAsync(
         try
         {
             var context = CreateContext(request);
-            var read = await _transport.ReadAsync(Descriptor.References.Sbo, cancellationToken).ConfigureAwait(false);
+            var read = await MeasureServiceAsync(() => _transport.ReadAsync(Descriptor.References.Sbo, cancellationToken)).ConfigureAwait(false);
             if (!read.IsSuccess || !IsPositiveSboSelection(read.Value, Descriptor.References))
             {
                 ReleaseObject();
@@ -172,7 +176,7 @@ private async Task<Iec61850ControlActionResult> SelectWithValueCoreAsync(
                 context,
                 Descriptor.SelectWithValueSpecification,
                 _options.RequireExactNamedControlFields);
-            var write = await _transport.WriteControlAsync(Descriptor.References.SboWithValue, value, cancellationToken).ConfigureAwait(false);
+            var write = await MeasureServiceAsync(() => _transport.WriteControlAsync(Descriptor.References.SboWithValue, value, cancellationToken)).ConfigureAwait(false);
             if (!write.IsSuccess)
             {
                 var appError = await WaitForApplicationErrorAsync(_options.ApplicationErrorGracePeriod, cancellationToken, reports).ConfigureAwait(false);
@@ -289,7 +293,7 @@ private async Task<Iec61850ControlActionResult> OperateCoreAsync(
                 context,
                 Descriptor.OperSpecification,
                 _options.RequireExactNamedControlFields);
-            var write = await _transport.WriteControlAsync(Descriptor.References.Oper, operValue, linked.Token).ConfigureAwait(false);
+            var write = await MeasureServiceAsync(() => _transport.WriteControlAsync(Descriptor.References.Oper, operValue, linked.Token)).ConfigureAwait(false);
             if (!write.IsSuccess)
             {
                 var applicationError = await WaitForApplicationErrorAsync(_options.ApplicationErrorGracePeriod, cancellationToken, reports).ConfigureAwait(false);
@@ -432,7 +436,7 @@ private async Task<Iec61850ControlActionResult> CancelCoreAsync(CancellationToke
                 return Unsupported(Iec61850ControlAction.Cancel, "IED did not expose a decodable Cancel type specification.");
 
             var value = Iec61850ControlStructureBuilder.BuildCancel(context, Descriptor.CancelSpecification, _options.RequireExactNamedControlFields);
-            var write = await _transport.WriteControlAsync(Descriptor.References.Cancel, value, cancellationToken).ConfigureAwait(false);
+            var write = await MeasureServiceAsync(() => _transport.WriteControlAsync(Descriptor.References.Cancel, value, cancellationToken)).ConfigureAwait(false);
             return write.IsSuccess
                 ? Accepted(Iec61850ControlAction.Cancel, context, stopwatch.Elapsed, "Cancel accepted; local SBO ownership released.")
                 : FromWriteFailure(Iec61850ControlAction.Cancel, write, null, context, stopwatch.Elapsed);
@@ -691,7 +695,7 @@ private async Task BestEffortCancelAsync(CancellationToken cancellationToken)
                     context,
                     Descriptor.CancelSpecification,
                     _options.RequireExactNamedControlFields);
-                await _transport.WriteControlAsync(Descriptor.References.Cancel, value, cancellationToken).ConfigureAwait(false);
+                await MeasureServiceAsync(() => _transport.WriteControlAsync(Descriptor.References.Cancel, value, cancellationToken)).ConfigureAwait(false);
             }
         }
         catch
@@ -782,6 +786,20 @@ private Iec61850ControlActionResult FromApplicationRejection(
                 BuildWireStep(action, requestAccepted: true, clientMessage))
         };
 
+    // Serialized by _operationGate. These are local service boundaries, not
+    // packet capture timestamps; elapsed measurement uses the monotonic clock.
+    private async Task<T> MeasureServiceAsync<T>(Func<Task<T>> service)
+    {
+        _serviceStartedUtc = DateTimeOffset.UtcNow;
+        var started = Stopwatch.GetTimestamp();
+        try { return await service().ConfigureAwait(false); }
+        finally
+        {
+            _serviceElapsed = Stopwatch.GetElapsedTime(started);
+            _serviceCompletedTimestamp = Stopwatch.GetTimestamp();
+        }
+    }
+
     private Iec61850ControlWireStep BuildWireStep(
         Iec61850ControlAction action,
         bool requestAccepted,
@@ -803,7 +821,8 @@ private Iec61850ControlWireStep BuildWireStep(
             RequestAccepted = requestAccepted,
             RequestHex = _transport.LastRequestHex,
             ResponseHex = _transport.LastResponseHex,
-            Detail = detail
+            Detail = FormattableString.Invariant(
+                $"{detail} serviceStartedUtc={_serviceStartedUtc:O}; serviceMs={_serviceElapsed.TotalMilliseconds:0.###}; postResponseWaitMs={Stopwatch.GetElapsedTime(_serviceCompletedTimestamp).TotalMilliseconds:0.###}; timingScope=local-service-not-wire")
         };
     }
 

diff --git a/src/AR.Iec61850/Mms/MmsPersistentReportMonitor.cs b/src/AR.Iec61850/Mms/MmsPersistentReportMonitor.cs
@@ -637,6 +637,12 @@ private void RoutePersistentInformationReport(byte[] payload)
             return;
         }
 
+        // Control termination / LastApplError use the same MMS service but are
+        // not RCB reports. Never feed them to the single-monitor fallback.
+        // Their independent control subscribers already received the envelope.
+        if (!HasRcbReportHeader(decoded))
+            return;
+
         var header = MmsReportFrameMapper.DecodeHeader(decoded);
         var active = SnapshotPersistentReportMonitors();
         var target = SelectPersistentReportMonitor(active, header, out var evidence);
@@ -655,6 +661,11 @@ private void RoutePersistentInformationReport(byte[] payload)
             $"Routed InformationReport to {target.ReportControl.Reference} by {evidence}. RptID={RoutingTextOrDash(header.ReportId)}, DatSet={RoutingTextOrDash(header.DataSetReference)}.";
     }
 
+    internal static bool HasRcbReportHeader(MmsInformationReport report)
+        => report.IsSuccess && report.Items.Count >= 2 &&
+           report.Items[0].Value?.Kind is MmsDataKind.VisibleString or MmsDataKind.MmsString &&
+           report.Items[1].Value?.Kind == MmsDataKind.BitString;
+
     internal static MmsPersistentReportMonitorSession? SelectPersistentReportMonitor(
         IReadOnlyList<MmsPersistentReportMonitorSession> active,
         MmsReportHeader header,

diff --git a/tests/AR.Iec61850.Tests/Control/G1OrderedWireEvidenceTests.cs b/tests/AR.Iec61850.Tests/Control/G1OrderedWireEvidenceTests.cs
@@ -69,6 +69,14 @@ public async Task SboEnhanced_PositiveTermination_PreservesSboWThenOperateWireSt
         Assert.True(result.WireSteps[1].RequestAccepted);
         Assert.Contains("positive CommandTermination", result.WireSteps[1].Detail, StringComparison.OrdinalIgnoreCase);
 
+        foreach (var step in result.WireSteps)
+        {
+            Assert.Contains("serviceStartedUtc=", step.Detail);
+            Assert.Contains("serviceMs=", step.Detail);
+            Assert.Contains("postResponseWaitMs=", step.Detail);
+            Assert.Contains("timingScope=local-service-not-wire", step.Detail);
+        }
+
         Assert.Equal(2, transport.Writes.Count);
         Assert.EndsWith("$SBOw", transport.Writes[0].Reference.Item, StringComparison.Ordinal);
         Assert.EndsWith("$Oper", transport.Writes[1].Reference.Item, StringComparison.Ordinal);

diff --git a/tests/AR.Iec61850.Tests/Mms/MmsPersistentReportRoutingTests.cs b/tests/AR.Iec61850.Tests/Mms/MmsPersistentReportRoutingTests.cs
@@ -4,6 +4,53 @@ namespace AR.Iec61850.Tests.Mms;
 
 public sealed class MmsPersistentReportRoutingTests
 {
+    // Synthetic typed MMS evidence: no external packet capture or station data.
+    [Fact]
+    public void ControlInformationReportsCannotEnterSingleRcbFallback()
+    {
+        foreach (var value in new[]
+        {
+            MmsDataValue.Boolean(true),
+            MmsDataValue.Structure(new[] { MmsDataValue.VisibleString("LD0/CSWI1$CO$Pos$Oper"), MmsDataValue.Integer(0) })
+        })
+        {
+            var report = new MmsInformationReport
+            {
+                IsSuccess = true,
+                VariableReferences = new[] { "LD0/CSWI1$CO$Pos$Oper" },
+                Items = new[] { new MmsInformationReportItem { Value = value } }
+            };
+            Assert.False(MmsClientSession.HasRcbReportHeader(report));
+        }
+    }
+
+    [Fact]
+    public void RcbHeaderDoesNotRequireOptionalSequenceOrDatasetFields()
+    {
+        var report = new MmsInformationReport
+        {
+            IsSuccess = true,
+            Items = new[]
+            {
+                new MmsInformationReportItem { Value = MmsDataValue.VisibleString("RPT_A") },
+                new MmsInformationReportItem { Value = MmsDataValue.BitString(6, new byte[] { 0, 0 }) },
+                new MmsInformationReportItem { Value = MmsDataValue.BitString(7, new byte[] { 0x80 }) },
+                new MmsInformationReportItem { Value = MmsDataValue.Boolean(true) }
+            }
+        };
+        Assert.True(MmsClientSession.HasRcbReportHeader(report));
+        Assert.False(MmsClientSession.HasRcbReportHeader(new MmsInformationReport()));
+        Assert.False(MmsClientSession.HasRcbReportHeader(new MmsInformationReport
+        {
+            IsSuccess = true,
+            Items = new[]
+            {
+                new MmsInformationReportItem { Value = MmsDataValue.Boolean(true) },
+                new MmsInformationReportItem { Value = MmsDataValue.BitString(6, new byte[] { 0, 0 }) }
+            }
+        }));
+    }
+
     [Fact]
     public void Selector_RoutesByExactReportIdBeforeDataSetProjection()
     {