feat(asic): add standing optical read functionality with diagnostic logging, improved rollover handling, and updated test coverage ver 3.9.3161.0

enhance optical lifecycle logging and safeguard manual testing operations

TBF/Properties/AssemblyInfo.cs

@@ -32,5 +32,5 @@ using System.Runtime.InteropServices;
 //      Build Number
 //      Revision
 //
-[assembly: AssemblyVersion("3.9.3159.0")]
-[assembly: AssemblyFileVersion("3.9.3159.0")]
+[assembly: AssemblyVersion("3.9.3161.0")]
+[assembly: AssemblyFileVersion("3.9.3161.0")]

TBF/Rig/RegisterReaders/AllyReader/AllyMeterReader.cs

@@ -356,6 +356,7 @@ namespace TBF.Rig.RegisterReaders.AllyReader
 
         public void Start()
         {
+            LogOpticalLifecycle("MEASUREMENT_START_REQUEST", false);
             lock (opticalSync)
             {
                 measurementStartFailed = false;
@@ -427,6 +428,7 @@ namespace TBF.Rig.RegisterReaders.AllyReader
 
         private void StartDataStreamProcessing(bool requireVolumeConversion)
         {
+            LogOpticalLifecycle("CAPTURE_START_REQUEST", false);
             LastOpticalError = string.Empty;
             log.InfoFormat(
                 "ALLY_OPTO start requested: COM{0}, {1} Bd, 8N1, meter size={2}, debug={3}",
@@ -496,8 +498,15 @@ namespace TBF.Rig.RegisterReaders.AllyReader
 
         public void StopDataStreamProcessing()
         {
+            LogOpticalLifecycle("CAPTURE_STOP_REQUEST", false);
             lock (opticalSync)
             {
+                if (operationActive && measurementSampleCount == 0)
+                {
+                    log.Warn("ALLY_OPTO_NO_MEASUREMENT_DATA: reader=" + Name +
+                        ";batch=" + Sequences.ProcessData.BatchNr + ";" + OpticalTrace.Context +
+                        ";capture ended without metrology samples; opening COM does not enable meter LED output.");
+                }
                 FinalizeOpticalCapture("stream-stop");
                 streamEnabled = false;
                 if (opticalPort == null)
@@ -1385,6 +1394,7 @@ namespace TBF.Rig.RegisterReaders.AllyReader
         /// </summary>
         public void StopOpticalVerificationStream(int timeoutMs)
         {
+            LogOpticalLifecycle("METER_OUTPUT_STOP_REQUEST", opticalVerificationOutputActive);
             try
             {
                 lock (opticalSync)
@@ -1393,7 +1403,11 @@ namespace TBF.Rig.RegisterReaders.AllyReader
                 }
 
                 if (opticalVerificationOutputActive)
+                {
+                    LogOpticalLifecycle("METER_OUTPUT_STOP_SEND", true);
                     ExecuteCommand(service => service.StopOpticalVerificationOutput(timeoutMs));
+                    LogOpticalLifecycle("METER_OUTPUT_STOP_ACK", true);
+                }
             }
             finally
             {
@@ -1412,6 +1426,7 @@ namespace TBF.Rig.RegisterReaders.AllyReader
         /// </summary>
         public void StopExternallyStartedOpticalVerificationStream(int timeoutMs)
         {
+            LogOpticalLifecycle("EXTERNAL_METER_OUTPUT_STOP_REQUEST", true);
             try
             {
                 lock (opticalSync)
@@ -1419,7 +1434,9 @@ namespace TBF.Rig.RegisterReaders.AllyReader
                     operationActive = false;
                 }
 
+                LogOpticalLifecycle("EXTERNAL_METER_OUTPUT_STOP_SEND", true);
                 ExecuteCommand(service => service.StopOpticalVerificationOutput(timeoutMs));
+                LogOpticalLifecycle("EXTERNAL_METER_OUTPUT_STOP_ACK", true);
             }
             finally
             {
@@ -1429,6 +1446,36 @@ namespace TBF.Rig.RegisterReaders.AllyReader
             }
         }
 
+        // Diagnostic only: no changes to port ownership, command order or measurement selection.
+        // Capture the complete caller chain because GUI events and deferred cleanup can otherwise
+        // look identical to a procedure's explicit LED-off step in the command log.
+        [System.Runtime.CompilerServices.MethodImpl(System.Runtime.CompilerServices.MethodImplOptions.NoInlining)]
+        private void LogOpticalLifecycle(string action, bool changesMeterOutput)
+        {
+            try
+            {
+                string callChain = new System.Diagnostics.StackTrace(1, true).ToString()
+                    .Replace("\r", string.Empty).Replace("\n", " <- ");
+                string message = "ALLY_OPTO_LIFECYCLE: action=" + action +
+                    ";reader=" + Name + ";instance=" +
+                    System.Runtime.CompilerServices.RuntimeHelpers.GetHashCode(this) +
+                    ";batch=" + Sequences.ProcessData.BatchNr + ";" + OpticalTrace.Context +
+                    ";thread=" + Thread.CurrentThread.ManagedThreadId +
+                    ";operationActive=" + operationActive + ";captureActive=" + streamEnabled +
+                    ";outputActive=" + opticalVerificationOutputActive +
+                    ";outputMode=" + activeOpticalOutputMode + ";samples=" + measurementSampleCount +
+                    ";opticalCharacters=" + opticalCharactersReceived +
+                    ";opticalCOM=" + (allyCfg == null ? 0 : allyCfg.OptoComPortNr) +
+                    ";changesMeterOutput=" + changesMeterOutput + ";callerChain=" + callChain;
+                log.Info(message);
+                allyLog.Info(message);
+            }
+            catch (Exception)
+            {
+                // A diagnostic failure must never prevent cleanup or a measurement transition.
+            }
+        }
+
         private static string ToHex(string text)
         {
             return BitConverter.ToString(Encoding.ASCII.GetBytes(text ?? string.Empty)).Replace("-", " ");

TBF/Rig/RegisterReaders/AllyReader/AllyReaderCfgCtrl.cs

@@ -80,7 +80,7 @@ namespace TBF.Rig.RegisterReaders.AllyReader
             config.CommandComPortNr = int.Parse(rfidPortNrTextBox.Text); config.CommandBaudRate = int.Parse(headPortNrTextBox.Text);
             return CfgUpdateFlags.RestartRqrd | logsCfgCtrl.UpdateCfg();
         }
-        public void Closing() { manualTestControl.StopOpticalStream(); }
+        public void Closing() { manualTestControl.StopManualTesting(); }
         private void Redraw()
         {
             if (config == null) return;

TBF/Rig/RegisterReaders/AllyReader/AllyReaderManualTestCtrl.cs

@@ -31,6 +31,13 @@ namespace TBF.Rig.RegisterReaders.AllyReader
         public void StopOpticalStream()
         {
             opticalPollTimer.Stop();
+            if (ManualCommunicationGuard.TestRunning)
+            {
+                log4net.LogManager.GetLogger(typeof(AllyReaderManualTestCtrl)).Warn(
+                    "ALLY_MANUAL_STOP_SKIPPED: test is running; GUI cleanup must not switch LED off or release reader COM ports.");
+                manualStreamReader = null;
+                return;
+            }
             AllyMeterReader reader = manualStreamReader ?? FindReader();
             if (reader != null)
             {
@@ -73,6 +80,8 @@ namespace TBF.Rig.RegisterReaders.AllyReader
             opticalPollTimer.Stop();
             if (ManualCommunicationGuard.TestRunning)
             {
+                log4net.LogManager.GetLogger(typeof(AllyReaderManualTestCtrl)).Info(
+                    "ALLY_MANUAL_CLEANUP_SKIPPED: test is running; only GUI timer stopped, meter output and COM ownership unchanged.");
                 manualStreamReader = null;
                 return; // Never send LED-off or release another operation's connection.
             }

TBF/Rig/RegisterReaders/AsicReader/AsicReader.cs

@@ -67,6 +67,18 @@ namespace TBF.Rig.RegisterReaders.AsicReader
             OpticalTrace.Calculation(method, startVolume, endVolume, startTime, endTime);
         }
 
+        protected override void StandingTelegramCaptured(string raw, DiagnosticLedState7Data data, bool start)
+        {
+            string endpoint = start ? "START" : "END";
+            log4net.LogManager.GetLogger("AnsiIPerlOptical").Info("ASIC_STANDING_SELECTED_" + endpoint + " | COM" + OptoComPortNr + " | " + raw);
+            opticalDiagnosticWriter.Write(asicCfg, ProcessData.BatchNr, Position, SerialNr,
+                start ? 0 : 1, true, raw, System.Text.Encoding.ASCII.GetBytes(raw), data,
+                data.RawVolume, data.AsicTimestamp, OpticalTrace.Context + ";standingEndpoint=" + endpoint,
+                DateTime.Now, "SELECTED_STANDING_" + endpoint);
+            OpticalTrace.Selected(start, start ? 0 : 1, data.RawVolume, data.AsicTimestamp,
+                "standing-direct-read;raw-counter;buffer=false");
+        }
+
         private readonly AsicReaderCfg asicCfg;
         private AsicOpticalBatchWorker experimentalWorker;
         protected override void CloseOptoSerialPort()
@@ -74,8 +86,8 @@ namespace TBF.Rig.RegisterReaders.AsicReader
             try { FinishExperimentalOpticalInput(); }
             finally { base.CloseOptoSerialPort(); }
         }
-        protected override bool ClearOpticalOnOpen => asicCfg == null || !asicCfg.EnableOpticalExperiments || asicCfg.ClearOpticalInputOnOpen;
-        protected override bool ExperimentalSelectionEnabled => asicCfg != null && asicCfg.EnableOpticalExperiments &&
+        protected override bool ClearOpticalOnOpen => StandingOpticalReadActive || asicCfg == null || !asicCfg.EnableOpticalExperiments || asicCfg.ClearOpticalInputOnOpen;
+        protected override bool ExperimentalSelectionEnabled => !StandingOpticalReadActive && asicCfg != null && asicCfg.EnableOpticalExperiments &&
             (asicCfg.EnableOpticalBatchSelection || asicCfg.OnlyNewOpticalMeterSecond);
         protected override bool ReadExperimentalOpticalInput()
         {

TBF/Rig/RegisterReaders/AsicReader/AsicReaderMeasurementCfgCtrl.cs

@@ -62,8 +62,13 @@ namespace TBF.Rig.RegisterReaders.AsicReader
             if (experimentsCheckBox.Checked && config != null &&
                 (!config.EnableDetailedLogPerWM || string.Equals(config.RawOpticalDataFormat, "Disabled", StringComparison.OrdinalIgnoreCase)))
             {
-                message += Environment.NewLine + "Optical experiments require per-WM logging and RAW enabled in Logs.";
-                return CfgUpdateFlags.Error;
+                string culture = CultureInfo.CurrentUICulture.TwoLetterISOLanguageName;
+                message += Environment.NewLine + (culture == "sk"
+                    ? "Pre diagnostiku optických experimentov odporúčame detailné logovanie pre WM a RAW v záložke Logs. Nastavenia merania je možné uložiť aj bez nich."
+                    : culture == "cs"
+                    ? "Pro diagnostiku optických experimentů doporučujeme podrobné logování pro WM a RAW v záložce Logs. Nastavení měření lze uložit i bez nich."
+                    : "Per-WM logging and RAW in Logs are recommended for optical experiment diagnostics. Measurement settings can be saved without them.");
+                return CfgUpdateFlags.Warning;
             }
             if (config == null)
             {

TBF/Rig/TestMethods/iPerlCommunication/iPerlHead/IperlAsicHead.cs

@@ -2080,7 +2080,16 @@ namespace TBF.Rig.TestMethods.iPerlCommunication.iPerlHead
         }
         
         
+        protected bool StandingOpticalReadActive { get; private set; }
+
         public async Task<double> DataEntry_EndVolumeAsync(int timeoutMs = DefaultDataEntryVolumeTimeoutMs)
+        {
+            StandingOpticalReadActive = true;
+            try { return await ReadStandingEndVolumeAsync(timeoutMs).ConfigureAwait(false); }
+            finally { StandingOpticalReadActive = false; }
+        }
+
+        private async Task<double> ReadStandingEndVolumeAsync(int timeoutMs)
         {
             
             if (!IsOptoPortOpen)
@@ -2115,6 +2124,7 @@ namespace TBF.Rig.TestMethods.iPerlCommunication.iPerlHead
                                 DiagnosticLedState7Data data =
                                     (DiagnosticLedState7Data)parser.ParseLine(readOptoDataWithTimeout, false);
                                 volumeLtr = data.RawVolume;
+                                NotifyStandingTelegram(readOptoDataWithTimeout, data, false);
                                 break;
                             }
                             catch (Exception ex)
@@ -2138,16 +2148,18 @@ namespace TBF.Rig.TestMethods.iPerlCommunication.iPerlHead
                     endWMState = volumeLtr;
                     if (!Double.IsNaN(beginWMState) && !Double.IsNaN(endWMState))
                     {
-                        //Solve roll over
-                        if (endWMState < beginWMState)
+                        double signedDelta = StandingVolumeDelta(beginWMState, endWMState);
+                        log.Info($"ASIC_STANDING_VOLUME start={beginWMState:R}; rawEnd={endWMState:R}; signedDelta={signedDelta:R}; direction={InitFlowDir}");
+                        if ((InitFlowDir == Counting.Positive && signedDelta < 0) ||
+                            (InitFlowDir == Counting.Negative && signedDelta > 0))
                         {
-                            log.Debug($"Solve roll over! endWMState: {endWMState} < beginWMState: {beginWMState}");
-                            const double VOL_RANGE_LITERS = 16777216.0 * 0.00025; // 4,194.304 l
-                            endWMState += VOL_RANGE_LITERS;
-                            volumeLtr = endWMState;
-                            ReadPulses();
-                            log.Debug($"Solve roll over! Upgraded endWMState: {endWMState}, beginWMState: {beginWMState}");
+                            log.Error("ASIC Standing volume direction does not match configuration; result rejected (not a rollover).");
+                            endWMState = Double.NaN;
+                            return Double.NaN;
                         }
+                        endWMState = beginWMState + Math.Abs(signedDelta);
+                        volumeLtr = endWMState;
+                        ReadPulses();
                     }
                     return endWMState;
                 }
@@ -2159,7 +2171,33 @@ namespace TBF.Rig.TestMethods.iPerlCommunication.iPerlHead
         }
 
 
+        // Two endpoint reads cannot identify multiple wraps. Use the nearest signed
+        // 24-bit displacement; intervals >= half the counter range are unsupported.
+        internal static double StandingVolumeDelta(double start, double end)
+        {
+            const double range = 16777216.0 * 0.00025;
+            double delta = end - start;
+            if (delta > range / 2) delta -= range;
+            else if (delta < -range / 2) delta += range;
+            return delta;
+        }
+
+        protected virtual void StandingTelegramCaptured(string raw, DiagnosticLedState7Data data, bool start) { }
+
+        private void NotifyStandingTelegram(string raw, DiagnosticLedState7Data data, bool start)
+        {
+            try { StandingTelegramCaptured(raw, data, start); }
+            catch (Exception ex) { log.Warn("ASIC Standing diagnostic logging failed.", ex); }
+        }
+
         public async Task<double> DataEntry_BeginVolumeAsync(int timeoutMs = DefaultDataEntryVolumeTimeoutMs)
+        {
+            StandingOpticalReadActive = true;
+            try { return await ReadStandingBeginVolumeAsync(timeoutMs).ConfigureAwait(false); }
+            finally { StandingOpticalReadActive = false; }
+        }
+
+        private async Task<double> ReadStandingBeginVolumeAsync(int timeoutMs)
         {
             if (ConfigStruct == null)
             {
@@ -2192,6 +2230,7 @@ namespace TBF.Rig.TestMethods.iPerlCommunication.iPerlHead
                                 DiagnosticLedState7Data data =
                                     (DiagnosticLedState7Data)parser.ParseLine(readOptoDataWithTimeout, false);
                                 volumeLtr0 = data.RawVolume;
+                                NotifyStandingTelegram(readOptoDataWithTimeout, data, true);
                                 break;
                             }
                             catch (Exception ex)

TBFTests/Rig/RegisterReaders/AsicReader/AsicFlyingDrainTests.cs

@@ -12,6 +12,37 @@ namespace TBFTests.Rig.RegisterReaders.AsicReader
     [DoNotParallelize]
     public class AsicFlyingDrainTests
     {
+        [DataTestMethod]
+        [DataRow(3451.52225, 3430.41175, -21.1105)]
+        [DataRow(3416.28225, 3395.1585, -21.12375)]
+        [DataRow(100.0, 121.0, 21.0)]
+        [DataRow(4190.0, 5.0, 9.304)]
+        [DataRow(5.0, 4190.0, -9.304)]
+        [DataRow(100.0, 100.0, 0.0)]
+        public void StandingDisplacementDistinguishesReverseCountingFromRollover(double start, double end, double expected)
+        {
+            Assert.AreEqual(expected,
+                TBF.Rig.TestMethods.iPerlCommunication.iPerlHead.IperlAsicHead.StandingVolumeDelta(start, end), 0.00000001);
+        }
+
+        [TestMethod]
+        public void StandingDisablesExperimentalSelectionWithoutChangingFlyingSettings()
+        {
+            var cfg = new AsicReaderCfg { EnableOpticalExperiments = true, EnableOpticalBatchSelection = true, ClearOpticalInputOnOpen = false };
+            var reader = new TBF.Rig.RegisterReaders.AsicReader.AsicReader(cfg);
+            var selection = reader.GetType().GetProperty("ExperimentalSelectionEnabled", BindingFlags.Instance | BindingFlags.NonPublic);
+            var clear = reader.GetType().GetProperty("ClearOpticalOnOpen", BindingFlags.Instance | BindingFlags.NonPublic);
+            var active = typeof(TBF.Rig.TestMethods.iPerlCommunication.iPerlHead.IperlAsicHead)
+                .GetProperty("StandingOpticalReadActive", BindingFlags.Instance | BindingFlags.NonPublic);
+            Assert.IsTrue((bool)selection.GetValue(reader));
+            active.SetValue(reader, true);
+            Assert.IsFalse((bool)selection.GetValue(reader));
+            Assert.IsTrue((bool)clear.GetValue(reader));
+            active.SetValue(reader, false);
+            Assert.IsTrue((bool)selection.GetValue(reader));
+            Assert.IsFalse((bool)clear.GetValue(reader));
+        }
+
         private static string ExperimentalLine(uint ticks, uint volume)
         {
             string body = "FFCC09\t2020\tFFFA\t" + volume.ToString("X6") +
@@ -349,7 +380,7 @@ namespace TBFTests.Rig.RegisterReaders.AsicReader
                         batching.Checked = true;
                         Assert.IsTrue(size.Enabled);
                         size.Value = 20;
-                        Assert.AreEqual(Common.CfgUpdateFlags.Error, ui.VerifyCfg(ref message));
+                        Assert.AreEqual(Common.CfgUpdateFlags.Warning, ui.VerifyCfg(ref message));
                         cfg.EnableDetailedLogPerWM = true;
                         Assert.AreEqual(Common.CfgUpdateFlags.None, ui.VerifyCfg(ref message));
                         Assert.AreEqual(Common.CfgUpdateFlags.RestartRqrd, ui.UpdateCfg());