diff --git a/Daqifi.Desktop.Test/ConnectionManagerBackgroundFailureTests.cs b/Daqifi.Desktop.Test/ConnectionManagerBackgroundFailureTests.cs new file mode 100644 index 00000000..455b57e5 --- /dev/null +++ b/Daqifi.Desktop.Test/ConnectionManagerBackgroundFailureTests.cs @@ -0,0 +1,362 @@ +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 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] + [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 secretBearingCommand = ScpiMessageProducer.SetNetworkWifiPassword(SENTINEL_COMMAND_ARGUMENT); + + Assert.IsTrue( + 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(secretBearingCommand, error)); + + logger.Verify( + l => l.Warning(error, It.Is(m => !m.Contains(SENTINEL_COMMAND_ARGUMENT, 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; +}