From 5421042605e59ba5ef45d01a29505f67035e3f1f Mon Sep 17 00:00:00 2001 From: Claude Date: Mon, 3 Aug 2026 11:47:14 -0600 Subject: [PATCH 1/2] feat(devices): surface Core's background failures in the app log Core 1.4.0 made two previously invisible failure classes observable and the desktop subscribed to neither, so they still vanished silently: - IDevice.ErrorOccurred (daqifi-core#378) - faults on a device's read loop, parse, subscriber dispatch, or per-frame stream decode. A stream that could not be read and a stream that could not be decoded both presented to the user as a device that had simply stopped sending. - DaqifiDevice.SendFailed (daqifi-core#413) - sending is fire-and-forget, so a SCPI command could fail to reach the device with no error, no log, and no user-visible signal, leaving the app's idea of device state silently diverging from the device's. Neither Core device the desktop builds is given an ILogger (the serial one is constructed bare, the WiFi one via DeviceConnectionOptions with Logger unset), so Core's own warnings for both went to a null sink. These events are currently the only way either failure can be seen at all. Both are wired in ConnectionManager where ConnectionLost is already attached, and detached at the same two teardown sites. Subscribe/unsubscribe now go through a single mirrored pair of methods so a newly wired event cannot be attached at connect and forgotten at teardown (the leak fixed in #795). Severity: default Warning; Error is reserved for DeviceErrorSource.Unknown. Every source Core actually raises describes the link or the device, not the app - a read that failed because the cable came out, a frame the device garbled, a reconnect that ran out of attempts against a powered-off unit - and routing those to Error would file a Sentry event on every unplug, which is how #775, #779 and #801 buried real bugs. Unknown is unreachable from any Core 1.4.0 path, so one arriving means Core hit a failure it could not classify: expected volume zero, high signal, the same call already made for SerialPortConnectFailure.Unknown in #801. A source value this build does not recognise means the desktop is behind Core, not that the device misbehaved, and stays a Warning. Core's SuppressedCount is reported in the message rather than adding a second throttle on top of Core's. Send-failure logging reports the SCPI verb only. Core's SetNetworkWifiPassword embeds the user's WiFi password in the command payload, and DAQiFiAppLog.log must never contain it. The desktop wrapper re-exposes both Core events on IDevice from a new partial file, forwarding with itself as sender so a log line can name the device the way the user sees it. The Core subscription is attached on the first desktop subscriber and released on the last, and the attached instance is remembered so the release cannot miss it across a reconnect. Observability only - no retry or recovery behavior; auto-reconnect is #804. Closes #805 Co-Authored-By: Claude Opus 5 --- ...ConnectionManagerBackgroundFailureTests.cs | 359 ++++++++++++++++++ ...AbstractStreamingDeviceDiagnosticsTests.cs | 138 +++++++ Daqifi.Desktop/ConnectionManager.cs | 226 ++++++++++- .../AbstractStreamingDevice.Diagnostics.cs | 161 ++++++++ Daqifi.Desktop/Device/IDevice.cs | 36 +- 5 files changed, 902 insertions(+), 18 deletions(-) create mode 100644 Daqifi.Desktop.Test/ConnectionManagerBackgroundFailureTests.cs create mode 100644 Daqifi.Desktop.Test/Device/AbstractStreamingDeviceDiagnosticsTests.cs create mode 100644 Daqifi.Desktop/Device/AbstractStreamingDevice.Diagnostics.cs diff --git a/Daqifi.Desktop.Test/ConnectionManagerBackgroundFailureTests.cs b/Daqifi.Desktop.Test/ConnectionManagerBackgroundFailureTests.cs new file mode 100644 index 00000000..ccb0d6e9 --- /dev/null +++ b/Daqifi.Desktop.Test/ConnectionManagerBackgroundFailureTests.cs @@ -0,0 +1,359 @@ +using System.Reflection; +using Daqifi.Core.Communication.Messages; +using Daqifi.Core.Communication.Producers; +using Daqifi.Desktop.Common.Loggers; +using Daqifi.Desktop.Device; +using Moq; +using CoreDeviceErrorEventArgs = Daqifi.Core.Device.DeviceErrorEventArgs; +using CoreSendFailedEventArgs = Daqifi.Core.Communication.Producers.MessageSendFailedEventArgs; +using DeviceErrorSource = Daqifi.Core.Device.DeviceErrorSource; + +namespace Daqifi.Desktop.Test; + +/// +/// Tests for 's routing of Core 1.4.0's background-failure events +/// (issue #805). Core made two previously invisible failure classes observable — faults on a +/// device's read/decode threads (ErrorOccurred) and fire-and-forget writes that never +/// reached the device (SendFailed) — and the desktop subscribed to neither. +/// +/// Every case asserts the log level actually used, via an injected , and +/// checks BOTH and +/// , because both reach Sentry — the exception overload via +/// CaptureException, the message-only one via a synthesized AppLogErrorException. +/// Asserting "did not throw" would be true of every arm and is exactly how routing regressions +/// #775, #779 and #801 stayed green while environmental conditions were filed as app bugs. +/// +/// +/// Each test builds its own through the internal test constructor +/// rather than touching : the singleton is process-wide, +/// and MSTest parallelizes test classes, so a shared sink would collect other classes' logging. +/// +/// +[TestClass] +public class ConnectionManagerBackgroundFailureTests +{ + private const string DISPLAY_NAME = "Nyquist-1 (SN-805)"; + + // A password-carrying SCPI command is the reason send-failure logging reports the verb only. + private const string WIFI_PASSWORD = "hunter2-not-in-the-log"; + + #region ErrorOccurred severity mapping + [TestMethod] + [DataRow(DeviceErrorSource.MessageConsumer)] + [DataRow(DeviceErrorSource.StreamDecode)] + [DataRow(DeviceErrorSource.Reconnect)] + public void ErrorOccurred_WithEnvironmentalSource_LogsWarningAndNotError(DeviceErrorSource source) + { + // Every source Core 1.4.0 actually raises describes the link or the device, not the app: a + // read that failed because the cable came out, a frame the device garbled, a reconnect that + // ran out of attempts against a powered-off unit. Routing these to Error would file a Sentry + // event every time a user unplugs something and bury the real bugs (#775, #779, #801). + var logger = new Mock(); + var device = CreateDevice(); + _ = CreateSubscribedManager(logger, device); + var error = new IOException("The device is not connected."); + + device.Raise(d => d.ErrorOccurred += null, device.Object, new CoreDeviceErrorEventArgs(source, error)); + + logger.Verify(l => l.Warning(error, It.IsAny()), Times.Once); + logger.Verify(l => l.Error(It.IsAny(), It.IsAny()), Times.Never); + logger.Verify(l => l.Error(It.IsAny()), Times.Never); + } + + [TestMethod] + public void ErrorOccurred_WithUnknownSource_LogsError() + { + // The guard in the other direction. No Core 1.4.0 path raises Unknown, so one arriving means + // Core caught a failure it could not classify — expected volume zero, high signal. Same call + // already made for SerialPortConnectFailure.Unknown in #801. + var logger = new Mock(); + var device = CreateDevice(); + _ = CreateSubscribedManager(logger, device); + var error = new InvalidOperationException("Something Core could not classify."); + + device.Raise( + d => d.ErrorOccurred += null, + device.Object, + new CoreDeviceErrorEventArgs(DeviceErrorSource.Unknown, error)); + + // Via the exception-carrying overload specifically: Error(string) would synthesize its own + // exception and strand the real stack trace out of Sentry. + logger.Verify(l => l.Error(error, It.IsAny()), Times.Once); + logger.Verify(l => l.Error(It.IsAny()), Times.Never); + logger.Verify(l => l.Warning(It.IsAny(), It.IsAny()), Times.Never); + } + + [TestMethod] + public void ErrorOccurred_WithSourceThisBuildDoesNotRecognise_LogsWarningAndNotError() + { + // A source value the desktop has never heard of means this build is behind Core, not that + // the device misbehaved — so it must not be blanket-escalated into Sentry when a Core bump + // introduces a chatty new source. + var logger = new Mock(); + var device = CreateDevice(); + _ = CreateSubscribedManager(logger, device); + var error = new IOException("From a source added after this build."); + + device.Raise( + d => d.ErrorOccurred += null, + device.Object, + new CoreDeviceErrorEventArgs((DeviceErrorSource)999, error)); + + logger.Verify(l => l.Warning(error, It.IsAny()), Times.Once); + logger.Verify(l => l.Error(It.IsAny(), It.IsAny()), Times.Never); + logger.Verify(l => l.Error(It.IsAny()), Times.Never); + } + + [TestMethod] + public void IsAppBug_ClassifiesExactlyTheSourcesCoreDeclares() + { + // Tripwire for a Core bump: if daqifi-core adds or removes a DeviceErrorSource, this fails + // by name rather than letting the new source silently inherit the default arm. + var expected = new Dictionary + { + [DeviceErrorSource.Unknown] = true, + [DeviceErrorSource.MessageConsumer] = false, + [DeviceErrorSource.StreamDecode] = false, + [DeviceErrorSource.Reconnect] = false + }; + + CollectionAssert.AreEquivalent( + expected.Keys.ToList(), + Enum.GetValues().ToList(), + "Core's DeviceErrorSource set changed; revisit the Warning/Error mapping before updating this list."); + + foreach (var (source, isAppBug) in expected) + { + Assert.AreEqual(isAppBug, ConnectionManager.IsAppBug(source), $"Unexpected classification for {source}."); + } + } + + [TestMethod] + public void ErrorOccurred_ReportsCoresSuppressedCountRatherThanThrottlingAgain() + { + // Core already collapses repeats per (source, exception type) and hands over how many it + // swallowed. A large count is the signal that a failure is systematic rather than a one-off, + // so it belongs in the message — and the desktop must not add a second throttle on top. + var logger = new Mock(); + var device = CreateDevice(); + _ = CreateSubscribedManager(logger, device); + var error = new IOException("Read failed."); + + device.Raise( + d => d.ErrorOccurred += null, + device.Object, + new CoreDeviceErrorEventArgs(DeviceErrorSource.StreamDecode, error, suppressedCount: 417)); + + logger.Verify( + l => l.Warning(error, It.Is(m => m.Contains("417", StringComparison.Ordinal))), + Times.Once); + } + + [TestMethod] + public void ErrorOccurred_NamesTheDeviceAndTheSource() + { + // "Why am I getting no samples" is only answerable if the report says which device and which + // stage failed; a bare exception message would leave both unknown with several devices open. + var logger = new Mock(); + var device = CreateDevice(); + _ = CreateSubscribedManager(logger, device); + var error = new IOException("Read failed."); + + device.Raise( + d => d.ErrorOccurred += null, + device.Object, + new CoreDeviceErrorEventArgs(DeviceErrorSource.MessageConsumer, error)); + + logger.Verify( + l => l.Warning( + error, + It.Is(m => + m.Contains(DISPLAY_NAME, StringComparison.Ordinal) + && m.Contains(nameof(DeviceErrorSource.MessageConsumer), StringComparison.Ordinal))), + Times.Once); + } + #endregion + + #region SendFailed + [TestMethod] + [DataRow(true)] + [DataRow(false)] + public void SendFailed_LogsWarningAndNotError(bool isTimeout) + { + // A write fails because the port closed, the device went away, or the device stopped + // draining its receive buffer. All three are conditions of the link, never app bugs, so + // neither the timeout nor the hard-failure variant may reach Sentry. + var logger = new Mock(); + var device = CreateDevice(); + _ = CreateSubscribedManager(logger, device); + Exception error = isTimeout + ? new TimeoutException("The write timed out.") + : new IOException("The port is closed."); + + device.Raise( + d => d.SendFailed += null, + device.Object, + new CoreSendFailedEventArgs(new ScpiMessage("SYSTem:STReam:ENable 1"), error)); + + logger.Verify(l => l.Warning(error, It.IsAny()), Times.Once); + logger.Verify(l => l.Error(It.IsAny(), It.IsAny()), Times.Never); + logger.Verify(l => l.Error(It.IsAny()), Times.Never); + } + + [TestMethod] + public void SendFailed_NamesTheDeviceAndTheLostCommand() + { + // The point of the event is knowing which command the device never got — without the verb + // the log says only that "something" failed to send. + var logger = new Mock(); + var device = CreateDevice(); + _ = CreateSubscribedManager(logger, device); + var error = new IOException("The port is closed."); + + device.Raise( + d => d.SendFailed += null, + device.Object, + new CoreSendFailedEventArgs(new ScpiMessage("SYSTem:STReam:ENable 1"), error)); + + logger.Verify( + l => l.Warning( + error, + It.Is(m => + m.Contains(DISPLAY_NAME, StringComparison.Ordinal) + && m.Contains("SYSTem:STReam:ENable", StringComparison.Ordinal))), + Times.Once); + } + + [TestMethod] + public void SendFailed_DoesNotWriteTheCommandArgumentsToTheLog() + { + // Core's SetNetworkWifiPassword puts the user's WiFi password in the message payload. A + // failed send of that command must still be diagnosable without DAQiFiAppLog.log ending up + // with the plaintext password in it, so only the SCPI verb is logged. + var logger = new Mock(); + var device = CreateDevice(); + _ = CreateSubscribedManager(logger, device); + var error = new IOException("The port is closed."); + var passwordCommand = ScpiMessageProducer.SetNetworkWifiPassword(WIFI_PASSWORD); + + Assert.IsTrue( + passwordCommand.Data.Contains(WIFI_PASSWORD, StringComparison.Ordinal), + "Precondition: Core still embeds the password in the command payload."); + + device.Raise( + d => d.SendFailed += null, + device.Object, + new CoreSendFailedEventArgs(passwordCommand, error)); + + logger.Verify( + l => l.Warning(error, It.Is(m => !m.Contains(WIFI_PASSWORD, StringComparison.Ordinal))), + Times.Once); + } + #endregion + + #region Subscribe / unsubscribe lifetime + [TestMethod] + public async Task Connect_SubscribesToBackgroundFailureEvents() + { + // Wired at the same point ConnectionLost is, so a connected device's background failures are + // observed for the whole time it is connected and no earlier (the Core device behind these + // events does not exist until Connect succeeds). + var logger = new Mock(); + var device = CreateDevice(); + device.Setup(d => d.Connect()).Returns(true); + var manager = new ConnectionManager(logger.Object); + + await manager.Connect(device.Object); + + var error = new IOException("Read failed."); + device.Raise( + d => d.ErrorOccurred += null, + device.Object, + new CoreDeviceErrorEventArgs(DeviceErrorSource.MessageConsumer, error)); + + logger.Verify(l => l.Warning(error, It.IsAny()), Times.Once); + } + + [TestMethod] + public void Disconnect_UnsubscribesFromBackgroundFailureEvents() + { + // The leak shape fixed in #795: an event attached at connect and never detached keeps a + // disconnected device reporting into a handler that no longer represents anything. + var logger = new Mock(); + var device = CreateDevice(); + var manager = CreateSubscribedManager(logger, device); + + manager.Disconnect(device.Object); + logger.Invocations.Clear(); + RaiseBothFailureEvents(device); + + VerifyNothingWasReported(logger); + } + + [TestMethod] + public void Reboot_UnsubscribesFromBackgroundFailureEvents() + { + // Reboot is the second teardown path ConnectionLost is detached from, and it is the easier + // one to forget: it drops the device from ConnectedDevices without going through Disconnect. + var logger = new Mock(); + var device = CreateDevice(); + var manager = CreateSubscribedManager(logger, device); + + manager.Reboot(device.Object); + logger.Invocations.Clear(); + RaiseBothFailureEvents(device); + + VerifyNothingWasReported(logger); + } + #endregion + + #region Helpers + private static void RaiseBothFailureEvents(Mock device) + { + device.Raise( + d => d.ErrorOccurred += null, + device.Object, + new CoreDeviceErrorEventArgs(DeviceErrorSource.MessageConsumer, new IOException("Read failed."))); + device.Raise( + d => d.SendFailed += null, + device.Object, + new CoreSendFailedEventArgs(new ScpiMessage("SYSTem:STReam:ENable 1"), new IOException("Write failed."))); + } + + private static void VerifyNothingWasReported(Mock logger) + { + logger.Verify(l => l.Warning(It.IsAny(), It.IsAny()), Times.Never); + logger.Verify(l => l.Warning(It.IsAny()), Times.Never); + logger.Verify(l => l.Error(It.IsAny(), It.IsAny()), Times.Never); + logger.Verify(l => l.Error(It.IsAny()), Times.Never); + } + + /// + /// Builds a connection manager with the given sink and attaches it to + /// through the same private wiring uses, without paying + /// that method's post-connect settle delay in every test. The connect path itself is covered by + /// . + /// + private static ConnectionManager CreateSubscribedManager(Mock logger, Mock device) + { + var manager = new ConnectionManager(logger.Object); + var subscribe = typeof(ConnectionManager).GetMethod( + "SubscribeDeviceEvents", + BindingFlags.Instance | BindingFlags.NonPublic); + Assert.IsNotNull(subscribe, "SubscribeDeviceEvents not found."); + subscribe.Invoke(manager, [device.Object]); + return manager; + } + + private static Mock CreateDevice() + { + var device = new Mock(); + device.SetupGet(d => d.ConnectionType).Returns(ConnectionType.Usb); + device.SetupGet(d => d.Name).Returns("Device-805"); + device.SetupGet(d => d.DeviceDisplayName).Returns(DISPLAY_NAME); + device.SetupGet(d => d.DeviceSerialNo).Returns(string.Empty); + device.SetupGet(d => d.MacAddress).Returns(string.Empty); + return device; + } + #endregion +} diff --git a/Daqifi.Desktop.Test/Device/AbstractStreamingDeviceDiagnosticsTests.cs b/Daqifi.Desktop.Test/Device/AbstractStreamingDeviceDiagnosticsTests.cs new file mode 100644 index 00000000..47e66be8 --- /dev/null +++ b/Daqifi.Desktop.Test/Device/AbstractStreamingDeviceDiagnosticsTests.cs @@ -0,0 +1,138 @@ +using System.Reflection; +using Daqifi.Core.Communication.Messages; +using Daqifi.Desktop.Device; +using CoreDeviceErrorEventArgs = Daqifi.Core.Device.DeviceErrorEventArgs; +using CoreStreamingDevice = Daqifi.Core.Device.DaqifiStreamingDevice; +using DeviceErrorSource = Daqifi.Core.Device.DeviceErrorSource; + +namespace Daqifi.Desktop.Test.Device; + +/// +/// Tests for the desktop wrapper's re-exposure of Core's background-failure events (issue #805). +/// ConnectionManager routes these to the app log, but only if the wrapper actually attaches +/// to the Core device when someone subscribes and detaches when the last one leaves — the half of +/// the wiring a mocked IStreamingDevice cannot prove. +/// +[TestClass] +public class AbstractStreamingDeviceDiagnosticsTests +{ + [TestMethod] + public void ErrorOccurred_ForwardsCoreFailuresWithTheDesktopDeviceAsSender() + { + // The sender must be the desktop wrapper, not the Core device: a log line has to name the + // device the way the user sees it, and only the wrapper knows DeviceDisplayName. + using var device = new DiagnosticsTestDevice(); + object? capturedSender = null; + CoreDeviceErrorEventArgs? capturedArgs = null; + device.ErrorOccurred += (sender, e) => + { + capturedSender = sender; + capturedArgs = e; + }; + var error = new IOException("Read failed."); + + device.RaiseCoreDeviceError(DeviceErrorSource.MessageConsumer, error); + + Assert.AreSame(device, capturedSender, "Handlers should see the desktop device, not the Core one."); + Assert.IsNotNull(capturedArgs); + Assert.AreEqual(DeviceErrorSource.MessageConsumer, capturedArgs.Source); + Assert.AreSame(error, capturedArgs.Error); + Assert.IsTrue(IsAttachedToCore(device)); + } + + [TestMethod] + public void ErrorOccurred_AfterUnsubscribe_DeliversNothing() + { + // The no-leak half: once the last subscriber detaches, the wrapper must release its own + // subscription on the Core device rather than keeping a disconnected device reporting into + // handlers nobody is listening with (the #795 shape). + using var device = new DiagnosticsTestDevice(); + var deliveries = 0; + void Handler(object? sender, CoreDeviceErrorEventArgs e) => deliveries++; + + device.ErrorOccurred += Handler; + device.ErrorOccurred -= Handler; + + // A different exception type so Core's per-(source, type) throttle cannot be what silences + // this raise — the test must fail for the right reason. + device.RaiseCoreDeviceError(DeviceErrorSource.StreamDecode, new InvalidOperationException("Decode failed.")); + + Assert.AreEqual(0, deliveries, "An unsubscribed handler must not keep receiving Core failures."); + Assert.IsFalse(IsAttachedToCore(device), + "The wrapper should have released its Core subscription once no subscriber was left."); + } + + [TestMethod] + public void ErrorOccurred_WithTwoSubscribers_KeepsDeliveringAfterOneDetaches() + { + // One Core subscription is shared by every desktop subscriber, so releasing it must wait for + // the last one — otherwise one component unsubscribing silences everybody else. + using var device = new DiagnosticsTestDevice(); + var first = 0; + var second = 0; + void FirstHandler(object? sender, CoreDeviceErrorEventArgs e) => first++; + void SecondHandler(object? sender, CoreDeviceErrorEventArgs e) => second++; + + device.ErrorOccurred += FirstHandler; + device.ErrorOccurred += SecondHandler; + device.ErrorOccurred -= FirstHandler; + + device.RaiseCoreDeviceError(DeviceErrorSource.MessageConsumer, new IOException("Read failed.")); + + Assert.AreEqual(0, first); + Assert.AreEqual(1, second, "The remaining subscriber must still receive Core failures."); + Assert.IsTrue(IsAttachedToCore(device)); + } + + /// + /// True while the wrapper holds a live forwarding subscription on its Core device. Read from the + /// private field because Core's ErrorOccurred is a non-virtual field-like event, so + /// nothing outside DaqifiDevice can inspect its invocation list. + /// + private static bool IsAttachedToCore(AbstractStreamingDevice device) + { + var field = typeof(AbstractStreamingDevice).GetField( + "_diagnosticsSource", + BindingFlags.Instance | BindingFlags.NonPublic); + Assert.IsNotNull(field, "_diagnosticsSource not found."); + return field.GetValue(device) != null; + } + + /// + /// A wrapper backed by a Core device that can raise ErrorOccurred on demand, standing in + /// for the read/decode threads that raise it in production. + /// + private sealed class DiagnosticsTestDevice : AbstractStreamingDevice, IDisposable + { + private readonly ErrorRaisingCoreDevice _coreDevice = new(); + + public DiagnosticsTestDevice() + { + CoreDevice = _coreDevice; + } + + public override ConnectionType ConnectionType => ConnectionType.Usb; + + public void RaiseCoreDeviceError(DeviceErrorSource source, Exception error) => + _coreDevice.RaiseError(source, error); + + public override bool Connect() => true; + + public override bool Disconnect() => true; + + public override bool Write(string command) => true; + + protected override void SendMessage(IOutboundMessage message) + { + } + + // The Core device built in the constructor is owned by this fixture; disposing it keeps the + // suite from leaking one per test (CA1001). + public void Dispose() => _coreDevice.Dispose(); + } + + private sealed class ErrorRaisingCoreDevice() : CoreStreamingDevice("DiagnosticsTestDevice") + { + public void RaiseError(DeviceErrorSource source, Exception error) => RaiseDeviceError(source, error); + } +} diff --git a/Daqifi.Desktop/ConnectionManager.cs b/Daqifi.Desktop/ConnectionManager.cs index 7fe461a8..3a252733 100644 --- a/Daqifi.Desktop/ConnectionManager.cs +++ b/Daqifi.Desktop/ConnectionManager.cs @@ -4,6 +4,9 @@ using Daqifi.Desktop.Logger; using System.Diagnostics.CodeAnalysis; using CommunityToolkit.Mvvm.ComponentModel; +using CoreDeviceErrorEventArgs = Daqifi.Core.Device.DeviceErrorEventArgs; +using CoreSendFailedEventArgs = Daqifi.Core.Communication.Producers.MessageSendFailedEventArgs; +using DeviceErrorSource = Daqifi.Core.Device.DeviceErrorSource; using DeviceIdentity = Daqifi.Core.Device.DeviceIdentity; namespace Daqifi.Desktop; @@ -28,6 +31,12 @@ namespace Daqifi.Desktop; /// The firmware-update carve-out: a device being flashed drops its transport as an expected part /// of the flash, and Core owns reconnecting it, so this class must not tear it down (issue #738). /// +/// +/// Log severity for Core's background-failure events ( and +/// ). Whether a device failure is an app bug worth capturing to +/// Sentry or an environmental condition worth only a local Warning is app policy, not Core's — +/// see (issue #805). +/// /// /// /// Spontaneous transport drops arrive via and are handled by @@ -38,6 +47,14 @@ namespace Daqifi.Desktop; /// public partial class ConnectionManager : ObservableObject { + #region Constants + /// + /// Longest SCPI verb written to the log when a send fails. Real verbs are far shorter; the cap + /// only exists so a malformed payload cannot turn one failure into a wall of log. + /// + private const int MAX_LOGGED_COMMAND_LENGTH = 64; + #endregion + #region Properties [ObservableProperty] private DAQiFiConnectionStatus _connectionStatus = DAQiFiConnectionStatus.Disconnected; @@ -169,8 +186,28 @@ private ConnectionManager() ConnectedDevices = new List(); } + /// + /// Test-only constructor. is a process-wide singleton, so asserting the + /// severity a background-failure report is logged at (issue #805) against the shared instance + /// would have every other test class's logging land in the same mock. Tests build their own + /// instance with their own sink instead. + /// + /// The logging sink this instance reports through. + internal ConnectionManager(IAppLogger appLogger) : this() + { + AppLogger = appLogger; + } + public static ConnectionManager Instance => instance; + /// + /// Logging sink for this connection manager. Defaults to the process-wide + /// ; typed as and + /// settable only through the test constructor so the log level of a report can be asserted + /// rather than merely that nothing threw. + /// + internal IAppLogger AppLogger { get; init; } = Common.Loggers.AppLogger.Instance; + #endregion public async Task Connect(IStreamingDevice device) @@ -186,7 +223,7 @@ public async Task Connect(IStreamingDevice device) // Core's reconnect calls the Core device's Connect() directly, so this gate can't block it. if (IsFirmwareUpdateInProgress && device.ConnectionType == ConnectionType.Usb) { - AppLogger.Instance.Warning( + AppLogger.Warning( $"Refusing to connect USB device {device.Name} while a firmware update is in progress " + "(the device reconnects itself after the flash)."); ConnectionStatus = DAQiFiConnectionStatus.Error; @@ -248,7 +285,7 @@ public async Task Connect(IStreamingDevice device) { // Exception-aware overload: keeps the stack trace in DAQiFiAppLog.log (where a // leaked-handle report is diagnosed from) without escalating to Sentry. - AppLogger.Instance.Warning( + AppLogger.Warning( ex, $"Failed to dispose a rejected duplicate device ({device.Name})."); } ConnectionStatus = postConnectDuplicateResult.ExistingDevice != null ? DAQiFiConnectionStatus.AlreadyConnected : DAQiFiConnectionStatus.Error; @@ -256,23 +293,23 @@ public async Task Connect(IStreamingDevice device) } ConnectedDevices.Add(device); - device.ConnectionLost += OnDeviceConnectionLost; + SubscribeDeviceEvents(device); await Task.Delay(1000); OnPropertyChanged(nameof(ConnectedDevices)); ConnectionStatus = DAQiFiConnectionStatus.Connected; var connectionType = device.ConnectionType == ConnectionType.Usb ? "usb" : "wifi"; - AppLogger.Instance.SetDeviceContext( + AppLogger.SetDeviceContext( device.DevicePartNumber, device.DeviceSerialNo, device.DeviceVersion, connectionType, device.DataChannels?.Count(c => c.IsActive) ?? 0); - AppLogger.Instance.AddBreadcrumb("device", $"Device connected: {device.Name} (S/N: {device.DeviceSerialNo}) via {connectionType}"); + AppLogger.AddBreadcrumb("device", $"Device connected: {device.Name} (S/N: {device.DeviceSerialNo}) via {connectionType}"); } catch (Exception ex) { - AppLogger.Instance.Error(ex, "Failed to Connect in Connection"); + AppLogger.Error(ex, "Failed to Connect in Connection"); ConnectionStatus = DAQiFiConnectionStatus.Error; } } @@ -282,7 +319,7 @@ public void Disconnect(IStreamingDevice device) var connectionType = device.ConnectionType == ConnectionType.Usb ? "usb" : "wifi"; try { - device.ConnectionLost -= OnDeviceConnectionLost; + UnsubscribeDeviceEvents(device); device.Disconnect(); // Release any transport/port handle the device owns; SerialStreamingDevice.Dispose is // idempotent with the cleanup Disconnect already performed. @@ -290,17 +327,17 @@ public void Disconnect(IStreamingDevice device) ConnectedDevices.Remove(device); OnPropertyChanged(nameof(ConnectedDevices)); - AppLogger.Instance.AddBreadcrumb("device", $"Device disconnected: {device.Name} (S/N: {device.DeviceSerialNo}) via {connectionType}"); + AppLogger.AddBreadcrumb("device", $"Device disconnected: {device.Name} (S/N: {device.DeviceSerialNo}) via {connectionType}"); if (ConnectedDevices.Count == 0) { - AppLogger.Instance.ClearDeviceContext(); + AppLogger.ClearDeviceContext(); } else { var remaining = ConnectedDevices[^1]; var remainingType = remaining.ConnectionType == ConnectionType.Usb ? "usb" : "wifi"; - AppLogger.Instance.SetDeviceContext( + AppLogger.SetDeviceContext( remaining.DevicePartNumber, remaining.DeviceSerialNo, remaining.DeviceVersion, @@ -310,8 +347,8 @@ public void Disconnect(IStreamingDevice device) } catch (Exception ex) { - AppLogger.Instance.AddBreadcrumb("device", $"Device disconnect failed: {device.Name} (S/N: {device.DeviceSerialNo}) via {connectionType}", Common.Loggers.BreadcrumbLevel.Error); - AppLogger.Instance.Error(ex, "Failed in Disconnect"); + AppLogger.AddBreadcrumb("device", $"Device disconnect failed: {device.Name} (S/N: {device.DeviceSerialNo}) via {connectionType}", Common.Loggers.BreadcrumbLevel.Error); + AppLogger.Error(ex, "Failed in Disconnect"); } } @@ -319,14 +356,14 @@ public void Reboot(IStreamingDevice device) { try { - device.ConnectionLost -= OnDeviceConnectionLost; + UnsubscribeDeviceEvents(device); device.Reboot(); ConnectedDevices.Remove(device); OnPropertyChanged(nameof(ConnectedDevices)); } catch (Exception ex) { - AppLogger.Instance.Error(ex, "Failed in Reboot"); + AppLogger.Error(ex, "Failed in Reboot"); } } @@ -343,6 +380,163 @@ public void UpdateStatusString() }; } + #region Device Event Wiring + /// + /// Attaches every per-device event this class listens to. Kept as a single method with an exact + /// mirror in so a newly wired event cannot be attached at + /// connect and forgotten at teardown — the leak shape fixed in issue #795. Runs once the device + /// has connected and been accepted into , which is also when the + /// Core device behind these events exists. + /// + private void SubscribeDeviceEvents(IStreamingDevice device) + { + device.ConnectionLost += OnDeviceConnectionLost; + device.ErrorOccurred += OnDeviceErrorOccurred; + device.SendFailed += OnDeviceSendFailed; + } + + /// + /// Detaches everything attached. Called from both teardown + /// paths ( and ) before the + /// device's own teardown runs, while the underlying Core device is still alive to detach from. + /// + private void UnsubscribeDeviceEvents(IStreamingDevice device) + { + device.ConnectionLost -= OnDeviceConnectionLost; + device.ErrorOccurred -= OnDeviceErrorOccurred; + device.SendFailed -= OnDeviceSendFailed; + } + + /// + /// Reports a failure Core caught on one of a device's background threads (issue #805). Before + /// Core 1.4.0 these had nowhere to go, so a read loop that could not read and a decoder that + /// could not decode both presented to the user as a device that had simply stopped sending. + /// + /// + /// Observability only: Core does not tear the connection down for these, and neither does this + /// handler. A genuinely dead link arrives separately as , + /// which is where teardown and the user-facing notification live; automatic recovery is issue + /// #804. No dispatcher hop either — nothing here touches bound state, and Core raises from a + /// background thread. + /// + private void OnDeviceErrorOccurred(object? sender, CoreDeviceErrorEventArgs e) + { + // Core already collapses repeats per (source, exception type) and reports how many it + // swallowed, so this reports the count instead of adding a second throttle on top. + var suppressed = e.SuppressedCount > 0 + ? $"; {e.SuppressedCount} further like failure(s) suppressed by Core's throttle" + : string.Empty; + var message = + $"Device {DescribeDevice(sender)} reported a background failure from {e.Source} " + + $"({e.Error.GetType().Name}: {e.Error.Message}){suppressed}."; + + if (IsAppBug(e.Source)) + { + AppLogger.Error(e.Error, message); + return; + } + + AppLogger.Warning(e.Error, message); + } + + /// + /// Decides whether a background device failure is an app bug (log at Error, which captures to + /// Sentry) or an environmental condition (log at Warning, which does not). + /// + /// + /// + /// Routing environmental conditions to Error has burned this app three times (#775, #779, #801): + /// the noise buries real bugs and the volume tracks how often users unplug things. So every + /// source Core actually raises today is a Warning: + /// + /// + /// + /// MessageConsumer — a failed transport read, parse, or subscriber dispatch. The + /// dominant cause by far is a link that is dying or gone, which Core independently escalates to + /// ConnectionStatus.Lost; every unplug would otherwise file a Sentry event. Core does not + /// separate the subscriber-dispatch subcase (which would be an app bug), so that one is + /// knowingly under-reported here rather than paying for it with a flood — it is still written to + /// DAQiFiAppLog.log with its stack trace. + /// + /// + /// StreamDecode — one malformed streaming frame. Core drops the frame and the stream + /// survives, so this is firmware or link noise, not an app fault. + /// + /// + /// Reconnect — Core exhausted its reconnect attempts. Terminal, but the cause is a device + /// that is unplugged, powered off, or off the network. The user already gets the + /// teardown and its dialog. + /// + /// + /// + /// Unknown is the exception, and it is deliberately the same call made for + /// SerialPortConnectFailure.Unknown in #801: no Core 1.4.0 path raises it, so seeing one + /// means Core hit a failure it could not classify — expected volume zero, and worth a look. + /// A source value this build does not recognise is a different thing (the desktop is behind + /// Core, not the device misbehaving) and stays a Warning. + /// + /// + internal static bool IsAppBug(DeviceErrorSource source) => source switch + { + DeviceErrorSource.Unknown => true, + DeviceErrorSource.MessageConsumer => false, + DeviceErrorSource.StreamDecode => false, + DeviceErrorSource.Reconnect => false, + _ => false + }; + + /// + /// Reports a command that never reached the device (issue #805). Sending is fire-and-forget, so + /// before Core 1.4.0 a failed write was indistinguishable from a delivered one and the app's + /// idea of device state could silently diverge from the device's. + /// + /// + /// Always a Warning: a write fails because the port closed, the device went away, or the device + /// stopped draining its receive buffer (IsTimeout) — all conditions of the link, not app + /// bugs. The distinction is still logged because "busy device" and "gone device" are diagnosed + /// differently. + /// + private void OnDeviceSendFailed(object? sender, CoreSendFailedEventArgs e) + { + var outcome = e.IsTimeout + ? "timed out on the way to" + : "failed to reach"; + AppLogger.Warning( + e.Error, + $"Command '{DescribeCommand(e.Message.Data)}' {outcome} device {DescribeDevice(sender)} " + + $"and was not delivered ({e.Error.GetType().Name}: {e.Error.Message})."); + } + + /// + /// Names the device a background failure came from, the way the user sees it in the UI. + /// + private static string DescribeDevice(object? sender) => + sender is IStreamingDevice device ? device.DeviceDisplayName : "(unknown)"; + + /// + /// Reduces a SCPI command to its verb — everything before the first space — for logging. + /// + /// + /// Arguments are dropped deliberately: SYSTem:COMMunicate:LAN:PASs "..." carries the user's + /// WiFi password in plaintext, and DAQiFiAppLog.log must never contain it. The verb alone + /// answers the question a send failure raises — which command was lost. + /// + private static string DescribeCommand(string? data) + { + if (string.IsNullOrWhiteSpace(data)) + { + return "(empty)"; + } + + var trimmed = data.Trim(); + var firstSpace = trimmed.IndexOf(' '); + var verb = firstSpace < 0 ? trimmed : trimmed[..firstSpace]; + + // A malformed or oversized payload must not turn one failure into a wall of log. + return verb.Length <= MAX_LOGGED_COMMAND_LENGTH ? verb : verb[..MAX_LOGGED_COMMAND_LENGTH] + "..."; + } + #endregion + /// /// Handles a device's event — Core detected a /// spontaneous transport drop (reboot, unplug, WiFi/TCP timeout, HID disconnect) that this @@ -457,7 +651,7 @@ private DuplicateDeviceCheckResult CheckForDuplicateDevice(IStreamingDevice newD // With no discriminator at all there is nothing to compare against, so duplicates are undetectable. if (candidateIdentity.IsEmpty) { - AppLogger.Instance.Information( + AppLogger.Information( $"Device {newDevice.Name} has no serial number or MAC address - cannot check for duplicates"); return new DuplicateDeviceCheckResult { IsDuplicate = false }; } @@ -470,7 +664,7 @@ private DuplicateDeviceCheckResult CheckForDuplicateDevice(IStreamingDevice newD var newDeviceInterface = newDevice.ConnectionType == ConnectionType.Usb ? "USB" : "WiFi"; var existingDeviceInterface = existingDevice.ConnectionType == ConnectionType.Usb ? "USB" : "WiFi"; - AppLogger.Instance.Information( + AppLogger.Information( $"Duplicate device detected ({candidateIdentity}): Device already connected via " + $"{existingDeviceInterface}, attempted to add via {newDeviceInterface}"); diff --git a/Daqifi.Desktop/Device/AbstractStreamingDevice.Diagnostics.cs b/Daqifi.Desktop/Device/AbstractStreamingDevice.Diagnostics.cs new file mode 100644 index 00000000..4dad58f5 --- /dev/null +++ b/Daqifi.Desktop/Device/AbstractStreamingDevice.Diagnostics.cs @@ -0,0 +1,161 @@ +using CoreDeviceErrorEventArgs = Daqifi.Core.Device.DeviceErrorEventArgs; +using CoreSendFailedEventArgs = Daqifi.Core.Communication.Producers.MessageSendFailedEventArgs; +using CoreStreamingDevice = Daqifi.Core.Device.DaqifiStreamingDevice; + +namespace Daqifi.Desktop.Device; + +/// +/// Re-exposes Core's background-failure events (ErrorOccurred, SendFailed) on the +/// desktop wrapper so ConnectionManager can route them to the app log with the right +/// severity (issue #805). Before Core 1.4.0 these failures had nowhere to go at all: a read-loop +/// fault or a producer write that never reached the device was indistinguishable from silence. +/// +/// +/// +/// Forwarding rather than passing the Core event object straight through is deliberate: handlers +/// receive this as the sender, so a log line can name the device the way the user sees it +/// () instead of the Core-internal object. +/// +/// +/// The Core subscription is attached on the first desktop subscriber and released on the last, and +/// the attached instance is remembered so the release always targets the same Core device even if +/// CoreDevice has since been replaced by a reconnect. This late binding is what lets the +/// wiring live entirely in this file: CoreDevice does not exist until Connect() +/// creates it, and the wrapper's existing SubscribeCoreDeviceEvents runs before any desktop +/// subscriber has appeared. +/// +/// +public abstract partial class AbstractStreamingDevice +{ + #region Private Fields + /// + /// Guards the handler lists and the attach/detach pair below. Core raises both events from + /// background threads while ConnectionManager subscribes and unsubscribes from the UI + /// thread, so the bookkeeping cannot be left to unsynchronized delegate assignment. + /// + private readonly object _diagnosticsSync = new(); + + /// + /// The Core device this wrapper's forwarding handlers are currently attached to, or null when + /// nothing is attached. Held separately from CoreDevice so detaching cannot miss the + /// instance it attached to. + /// + private CoreStreamingDevice? _diagnosticsSource; + + private EventHandler? _errorOccurred; + private EventHandler? _sendFailed; + #endregion + + #region Events + /// + public event EventHandler? ErrorOccurred + { + add + { + if (value == null) { return; } + + lock (_diagnosticsSync) + { + AttachDiagnostics(); + _errorOccurred += value; + } + } + remove + { + if (value == null) { return; } + + lock (_diagnosticsSync) + { + _errorOccurred -= value; + DetachDiagnosticsIfUnobserved(); + } + } + } + + /// + public event EventHandler? SendFailed + { + add + { + if (value == null) { return; } + + lock (_diagnosticsSync) + { + AttachDiagnostics(); + _sendFailed += value; + } + } + remove + { + if (value == null) { return; } + + lock (_diagnosticsSync) + { + _sendFailed -= value; + DetachDiagnosticsIfUnobserved(); + } + } + } + #endregion + + #region Private Methods + /// + /// Attaches this wrapper's forwarding handlers to the current Core device, moving them off any + /// previously attached instance first. A no-op while the device is disconnected + /// (CoreDevice is null) — there is no background pipeline to report failures yet. + /// + private void AttachDiagnostics() + { + var coreDevice = CoreDevice; + if (ReferenceEquals(_diagnosticsSource, coreDevice)) + { + return; + } + + DetachDiagnostics(); + + if (coreDevice == null) + { + return; + } + + coreDevice.ErrorOccurred += OnCoreErrorOccurred; + coreDevice.SendFailed += OnCoreSendFailed; + _diagnosticsSource = coreDevice; + } + + /// + /// Releases the Core subscription once no desktop subscriber is left, so a disconnected + /// device's Core instance is not kept reporting into handlers nobody is listening with. + /// + private void DetachDiagnosticsIfUnobserved() + { + if (_errorOccurred == null && _sendFailed == null) + { + DetachDiagnostics(); + } + } + + private void DetachDiagnostics() + { + if (_diagnosticsSource == null) + { + return; + } + + _diagnosticsSource.ErrorOccurred -= OnCoreErrorOccurred; + _diagnosticsSource.SendFailed -= OnCoreSendFailed; + _diagnosticsSource = null; + } + + private void OnCoreErrorOccurred(object? sender, CoreDeviceErrorEventArgs e) + { + _errorOccurred?.Invoke(this, e); + } + + private void OnCoreSendFailed(object? sender, CoreSendFailedEventArgs e) + { + _sendFailed?.Invoke(this, e); + } + #endregion +} diff --git a/Daqifi.Desktop/Device/IDevice.cs b/Daqifi.Desktop/Device/IDevice.cs index bc7139f5..fdc92d66 100644 --- a/Daqifi.Desktop/Device/IDevice.cs +++ b/Daqifi.Desktop/Device/IDevice.cs @@ -1,4 +1,6 @@ -using System.ComponentModel; +using System.ComponentModel; +using CoreDeviceErrorEventArgs = Daqifi.Core.Device.DeviceErrorEventArgs; +using CoreSendFailedEventArgs = Daqifi.Core.Communication.Producers.MessageSendFailedEventArgs; namespace Daqifi.Desktop.Device; @@ -33,4 +35,34 @@ public interface IDevice : INotifyPropertyChanged /// this fires. /// event EventHandler? ConnectionLost; -} \ No newline at end of file + + /// + /// Raised when Core reports a failure on one of the device's background threads — a read + /// from the transport stream, a parse, a dispatch to a subscriber, or the decode of a + /// single streaming frame (issue #805; daqifi-core#378). Purely observational: Core does + /// not tear the connection down, change status, or stop the stream because of it, and a + /// genuinely dead link still arrives separately as . + /// + /// + /// Core throttles raises per (source, exception type) and reports how many like failures it + /// collapsed in SuppressedCount, so subscribers must not add a throttle of their own. + /// Raised on a Core background thread, so handlers must be thread-safe and cheap. + /// Subscriptions are only meaningful while the device is connected: subscribe after a + /// successful and unsubscribe before , exactly + /// as is handled in ConnectionManager. + /// + event EventHandler? ErrorOccurred; + + /// + /// Raised when a message queued for this device fails to write to it (issue #805; + /// daqifi-core#413). Sending is fire-and-forget, so before this event a SCPI command could + /// fail to reach the device with no error and no log, leaving the app's idea of device state + /// silently diverging from the device's. + /// + /// + /// Purely observational — the producer keeps draining its remaining queue. Raised on the + /// producer's background thread, and subject to the same subscribe-after-connect / + /// unsubscribe-before-disconnect lifetime as . + /// + event EventHandler? SendFailed; +} From 8f64b975c54b05a43c267ea18c7bae9385915a11 Mon Sep 17 00:00:00 2001 From: Claude Date: Mon, 3 Aug 2026 12:00:47 -0600 Subject: [PATCH 2/2] fix(tests): name the send-failure fixture argument for what it is Qodo rule violation: a `string` constant named WIFI_PASSWORD read as a stored credential. It never was one - it is a synthetic marker fed to SetNetworkWifiPassword purely so the test can assert those argument bytes never reach the log. Renamed to SENTINEL_COMMAND_ARGUMENT and documented why SecureString does not apply: nothing secret is being protected, and Core's SetNetworkWifiPassword takes a plain string. Co-Authored-By: Claude Opus 5 --- .../ConnectionManagerBackgroundFailureTests.cs | 15 +++++++++------ 1 file changed, 9 insertions(+), 6 deletions(-) diff --git a/Daqifi.Desktop.Test/ConnectionManagerBackgroundFailureTests.cs b/Daqifi.Desktop.Test/ConnectionManagerBackgroundFailureTests.cs index ccb0d6e9..455b57e5 100644 --- a/Daqifi.Desktop.Test/ConnectionManagerBackgroundFailureTests.cs +++ b/Daqifi.Desktop.Test/ConnectionManagerBackgroundFailureTests.cs @@ -34,8 +34,11 @@ public class ConnectionManagerBackgroundFailureTests { private const string DISPLAY_NAME = "Nyquist-1 (SN-805)"; - // A password-carrying SCPI command is the reason send-failure logging reports the verb only. - private const string WIFI_PASSWORD = "hunter2-not-in-the-log"; + // A synthetic marker string, not a credential: it is passed where a password-carrying SCPI + // command takes its argument, purely so the test can assert the argument bytes never reach the + // log. SecureString would be meaningless here — nothing secret is being protected, and Core's + // SetNetworkWifiPassword takes a plain string anyway. + private const string SENTINEL_COMMAND_ARGUMENT = "sentinel-argument-not-in-the-log"; #region ErrorOccurred severity mapping [TestMethod] @@ -234,19 +237,19 @@ public void SendFailed_DoesNotWriteTheCommandArgumentsToTheLog() var device = CreateDevice(); _ = CreateSubscribedManager(logger, device); var error = new IOException("The port is closed."); - var passwordCommand = ScpiMessageProducer.SetNetworkWifiPassword(WIFI_PASSWORD); + var secretBearingCommand = ScpiMessageProducer.SetNetworkWifiPassword(SENTINEL_COMMAND_ARGUMENT); Assert.IsTrue( - passwordCommand.Data.Contains(WIFI_PASSWORD, StringComparison.Ordinal), + secretBearingCommand.Data.Contains(SENTINEL_COMMAND_ARGUMENT, StringComparison.Ordinal), "Precondition: Core still embeds the password in the command payload."); device.Raise( d => d.SendFailed += null, device.Object, - new CoreSendFailedEventArgs(passwordCommand, error)); + new CoreSendFailedEventArgs(secretBearingCommand, error)); logger.Verify( - l => l.Warning(error, It.Is(m => !m.Contains(WIFI_PASSWORD, StringComparison.Ordinal))), + l => l.Warning(error, It.Is(m => !m.Contains(SENTINEL_COMMAND_ARGUMENT, StringComparison.Ordinal))), Times.Once); } #endregion