Browse Source

Add DBUSDEBUG input trail and unwrap DBus exceptions

The Linux DBus failure (org.freedesktop.DBus.Error.ServiceUnknown) arrives as an
unobserved AggregateException rethrown by the finalizer thread, so it is
temporally divorced from the mouse/keyboard gesture that made Avalonia issue the
DBus call (AT-SPI, portals, clipboard, IME). To pin the trigger, add an
ILSPY_LOG=DBUSDEBUG category: InputDiagnostics logs every pointer/key/focus event
into a rolling ring buffer, and the unobserved-task handler dumps that trail next
to the fully unwrapped exception. The unwrapper flattens the aggregate, walks
each inner chain, and reflects DBusException.ErrorName/ErrorMessage (Tmds.DBus is
a transitive dependency we can't reference directly) -- detail the bare
ToString() buries. The exception dialog and clipboard report carry the unwrapped
chain too, so the DBus error name shows even without the category enabled.
pull/3755/head
Siegfried Pammer 1 month ago
parent
commit
9274b58cd9
  1. 97
      ILSpy.Tests/Diagnostics/InputDiagnosticsTests.cs
  2. 8
      ILSpy/AppEnv/AppLog.cs
  3. 34
      ILSpy/AppEnv/GlobalExceptionHandler.cs
  4. 245
      ILSpy/AppEnv/InputDiagnostics.cs
  5. 4
      ILSpy/Views/MainWindow.axaml.cs

97
ILSpy.Tests/Diagnostics/InputDiagnosticsTests.cs

@ -0,0 +1,97 @@ @@ -0,0 +1,97 @@
// Copyright (c) 2026 AlphaSierraPapa for the SharpDevelop Team
//
// Permission is hereby granted, free of charge, to any person obtaining a copy of this
// software and associated documentation files (the "Software"), to deal in the Software
// without restriction, including without limitation the rights to use, copy, modify, merge,
// publish, distribute, sublicense, and/or sell copies of the Software, and to permit persons
// to whom the Software is furnished to do so, subject to the following conditions:
//
// The above copyright notice and this permission notice shall be included in all copies or
// substantial portions of the Software.
//
// THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR IMPLIED,
// INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, FITNESS FOR A PARTICULAR
// PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE
// FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR
// OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER
// DEALINGS IN THE SOFTWARE.
using System;
using Avalonia.Controls;
using Avalonia.Headless;
using Avalonia.Headless.NUnit;
using Avalonia.Input;
using Avalonia.Threading;
using AwesomeAssertions;
using ILSpy.AppEnv;
using NUnit.Framework;
namespace ICSharpCode.ILSpy.Tests.Diagnostics;
[TestFixture]
public class InputDiagnosticsTests
{
// Stands in for Tmds.DBus.Protocol.DBusException (a transitive dependency we don't reference):
// InputDiagnostics matches it by type Name and reflects ErrorName/ErrorMessage off it.
sealed class DBusException : Exception
{
public DBusException(string errorName, string errorMessage) : base(errorName + ": " + errorMessage)
{
ErrorName = errorName;
ErrorMessage = errorMessage;
}
public string ErrorName { get; }
public string ErrorMessage { get; }
}
[Test]
public void DescribeException_Unwraps_Aggregate_And_Reflects_DBus_ErrorName()
{
var dbus = new DBusException("org.freedesktop.DBus.Error.ServiceUnknown", "The name is not activatable");
var aggregate = new AggregateException("A Task's exception(s) were not observed",
new InvalidOperationException("outer", dbus));
InputDiagnostics.ContainsDBusException(aggregate).Should().BeTrue();
var report = InputDiagnostics.DescribeException(aggregate);
report.Should().Contain("InvalidOperationException");
report.Should().Contain("DBusException");
report.Should().Contain("ErrorName = org.freedesktop.DBus.Error.ServiceUnknown",
"the reflected DBus ErrorName is the detail a bare ToString() buries");
report.Should().Contain("ErrorMessage = The name is not activatable");
}
[Test]
public void ContainsDBusException_Is_False_For_Ordinary_Exceptions()
{
InputDiagnostics.ContainsDBusException(new InvalidOperationException("nope")).Should().BeFalse();
InputDiagnostics.ContainsDBusException(null).Should().BeFalse();
}
[AvaloniaTest]
public void Attach_Records_Keyboard_Interactions_When_DBusDebug_Enabled()
{
AppLog.Enable(AppLog.Category.DBusDebug);
InputDiagnostics.Record("--- test marker ---");
var window = new Window { Width = 200, Height = 200 };
var box = new TextBox();
window.Content = box;
InputDiagnostics.Attach(window);
window.Show();
Dispatcher.UIThread.RunJobs();
box.Focus();
Dispatcher.UIThread.RunJobs();
window.KeyPress(Key.A, RawInputModifiers.None, PhysicalKey.A, keySymbol: "a");
Dispatcher.UIThread.RunJobs();
InputDiagnostics.DumpRecent().Should().Contain("KeyDown A",
"every keyboard interaction must land on the DBUSDEBUG input trail");
}
}

8
ILSpy/AppEnv/AppLog.cs

@ -59,6 +59,14 @@ namespace ILSpy.AppEnv @@ -59,6 +59,14 @@ namespace ILSpy.AppEnv
/// <summary>Dock chrome activity — view-recycling cache, layout save/load, drag/drop transitions.</summary>
public const string Docking = "Docking";
/// <summary>
/// Mouse/keyboard interaction trail plus unwrapped DBus exception reports, for
/// correlating an unobserved <c>Tmds.DBus</c> error (which surfaces asynchronously on
/// the finalizer thread) with the interaction that triggered the DBus call. Off by
/// default; opt in with <c>ILSPY_LOG=DBUSDEBUG</c> (matched case-insensitively).
/// </summary>
public const string DBusDebug = "DBusDebug";
}
static readonly Stopwatch sw = Stopwatch.StartNew();

34
ILSpy/AppEnv/GlobalExceptionHandler.cs

@ -66,9 +66,24 @@ namespace ILSpy.AppEnv @@ -66,9 +66,24 @@ namespace ILSpy.AppEnv
static void OnUnobservedTask(object? sender, UnobservedTaskExceptionEventArgs e)
{
e.SetObserved();
// The Linux DBus failures arrive here: a fire-and-forget Tmds.DBus call faults and the
// AggregateException is rethrown by the finalizer. Log the unwrapped chain plus the
// recent input trail so the triggering gesture can be read off (ILSPY_LOG=DBUSDEBUG).
LogDBusDiagnostics(e.Exception);
Report(e.Exception);
}
static void LogDBusDiagnostics(Exception exception)
{
if (!AppLog.IsEnabled(AppLog.Category.DBusDebug))
return;
AppLog.Write(AppLog.Category.DBusDebug,
"UNOBSERVED TASK EXCEPTION (finalizer thread)" + Environment.NewLine
+ InputDiagnostics.DescribeException(exception) + Environment.NewLine
+ "Recent input trail (newest last):" + Environment.NewLine
+ InputDiagnostics.DumpRecent());
}
static void OnDispatcherUnhandled(object sender, DispatcherUnhandledExceptionEventArgs e)
{
Report(e.Exception);
@ -153,13 +168,21 @@ namespace ILSpy.AppEnv @@ -153,13 +168,21 @@ namespace ILSpy.AppEnv
static (Control root, TextBox details) BuildContent(Exception exception, Window window, string clipboardText)
{
// For DBus failures the bare ToString() hides the ServiceUnknown/ErrorName detail inside
// nested aggregates; append the fully unwrapped chain so the dialog carries it too.
var detailText = exception.ToString();
if (InputDiagnostics.ContainsDBusException(exception))
detailText += Environment.NewLine + Environment.NewLine
+ "--- unwrapped DBus chain ---" + Environment.NewLine
+ InputDiagnostics.DescribeException(exception);
var details = new TextBox {
IsReadOnly = true,
AcceptsReturn = true,
TextWrapping = TextWrapping.NoWrap,
FontFamily = new FontFamily("Consolas, Menlo, Monospace"),
FontSize = 12,
Text = exception.ToString(),
Text = detailText,
};
var summary = new TextBlock {
@ -197,7 +220,14 @@ namespace ILSpy.AppEnv @@ -197,7 +220,14 @@ namespace ILSpy.AppEnv
}
static string FormatForClipboard(Exception exception)
=> exception.GetType().FullName + ": " + exception.Message + Environment.NewLine + exception;
{
var text = exception.GetType().FullName + ": " + exception.Message + Environment.NewLine + exception;
if (InputDiagnostics.ContainsDBusException(exception))
text += Environment.NewLine + Environment.NewLine
+ "--- unwrapped DBus chain ---" + Environment.NewLine
+ InputDiagnostics.DescribeException(exception);
return text;
}
static void CopyToClipboard(Window window, string text)
{

245
ILSpy/AppEnv/InputDiagnostics.cs

@ -0,0 +1,245 @@ @@ -0,0 +1,245 @@
// Copyright (c) 2026 AlphaSierraPapa for the SharpDevelop Team
//
// Permission is hereby granted, free of charge, to any person obtaining a copy of this
// software and associated documentation files (the "Software"), to deal in the Software
// without restriction, including without limitation the rights to use, copy, modify, merge,
// publish, distribute, sublicense, and/or sell copies of the Software, and to permit persons
// to whom the Software is furnished to do so, subject to the following conditions:
//
// The above copyright notice and this permission notice shall be included in all copies or
// substantial portions of the Software.
//
// THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR IMPLIED,
// INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, FITNESS FOR A PARTICULAR
// PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE
// FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR
// OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER
// DEALINGS IN THE SOFTWARE.
using System;
using System.Collections.Generic;
using System.Reflection;
using System.Text;
using Avalonia;
using Avalonia.Input;
using Avalonia.Interactivity;
namespace ILSpy.AppEnv
{
/// <summary>
/// Diagnostics for chasing the asynchronous DBus failure on Linux: an unobserved
/// <c>Tmds.DBus.Protocol.DBusException</c> (e.g. <c>org.freedesktop.DBus.Error.ServiceUnknown</c>)
/// surfaces on the finalizer thread, temporally disconnected from the mouse/keyboard interaction
/// that made Avalonia issue the DBus call (AT-SPI accessibility, portals, clipboard, IME, …).
/// <para>
/// <see cref="Attach"/> records every input event into a rolling ring buffer (and the
/// <see cref="AppLog.Category.DBusDebug"/> log), so when the exception finally fires we can dump
/// the recent interaction trail next to the unwrapped exception and read off the trigger.
/// </para>
/// Everything here is gated on <see cref="AppLog.Category.DBusDebug"/> (opt in with
/// <c>ILSPY_LOG=DBUSDEBUG</c>); with the category off, <see cref="Attach"/> installs no handlers
/// and the app pays nothing.
/// </summary>
public static class InputDiagnostics
{
const int RingCapacity = 256;
const long MoveThrottleMs = 50;
static readonly object ringLock = new();
static readonly Queue<string> ring = new(RingCapacity + 1);
static long lastMoveTick;
/// <summary>
/// Installs tunnel/bubble handlers for every mouse and keyboard routed event on
/// <paramref name="root"/> (typically the main window). No-op unless the
/// <see cref="AppLog.Category.DBusDebug"/> category is enabled at the time of the call, so it
/// is a launch-time flag: set <c>ILSPY_LOG=DBUSDEBUG</c> before starting the process.
/// </summary>
public static void Attach(InputElement root)
{
ArgumentNullException.ThrowIfNull(root);
if (!AppLog.IsEnabled(AppLog.Category.DBusDebug))
return;
// Tunnel + handledEventsToo for the gesture events so we log them on the way DOWN,
// before any control handles them (and possibly triggers the DBus call) -- the log line
// then reliably precedes the DBus error in time. Focus/enter/exit have no tunnel route,
// so register those on Bubble.
root.AddHandler(InputElement.KeyDownEvent, OnKeyDown, RoutingStrategies.Tunnel, handledEventsToo: true);
root.AddHandler(InputElement.KeyUpEvent, OnKeyUp, RoutingStrategies.Tunnel, handledEventsToo: true);
root.AddHandler(InputElement.TextInputEvent, OnTextInput, RoutingStrategies.Tunnel, handledEventsToo: true);
root.AddHandler(InputElement.PointerPressedEvent, OnPointerPressed, RoutingStrategies.Tunnel, handledEventsToo: true);
root.AddHandler(InputElement.PointerReleasedEvent, OnPointerReleased, RoutingStrategies.Tunnel, handledEventsToo: true);
root.AddHandler(InputElement.PointerMovedEvent, OnPointerMoved, RoutingStrategies.Tunnel, handledEventsToo: true);
root.AddHandler(InputElement.PointerWheelChangedEvent, OnPointerWheel, RoutingStrategies.Tunnel, handledEventsToo: true);
root.AddHandler(InputElement.PointerEnteredEvent, OnPointerEntered, RoutingStrategies.Bubble, handledEventsToo: true);
root.AddHandler(InputElement.PointerExitedEvent, OnPointerExited, RoutingStrategies.Bubble, handledEventsToo: true);
root.AddHandler(InputElement.GotFocusEvent, OnGotFocus, RoutingStrategies.Bubble, handledEventsToo: true);
root.AddHandler(InputElement.LostFocusEvent, OnLostFocus, RoutingStrategies.Bubble, handledEventsToo: true);
Record($"input diagnostics attached to {Src(root)}");
}
/// <summary>
/// Appends one timestamped line to the ring buffer and writes it under
/// <see cref="AppLog.Category.DBusDebug"/>. Public so non-input subsystems can drop markers
/// onto the same trail when chasing the DBus issue.
/// </summary>
public static void Record(string message)
{
var line = $"[{DateTime.Now:HH:mm:ss.fff}] {message}";
lock (ringLock)
{
ring.Enqueue(line);
while (ring.Count > RingCapacity)
ring.Dequeue();
}
AppLog.Write(AppLog.Category.DBusDebug, message);
}
/// <summary>Newest-last snapshot of the recent interaction trail, one event per line.</summary>
public static string DumpRecent()
{
lock (ringLock)
{
return ring.Count == 0 ? "(no input recorded)" : string.Join(Environment.NewLine, ring);
}
}
#region Input handlers
static void OnKeyDown(object? sender, KeyEventArgs e)
=> Record($"KeyDown {e.Key} mods={e.KeyModifiers} src={Src(e.Source)} handled={e.Handled}");
static void OnKeyUp(object? sender, KeyEventArgs e)
=> Record($"KeyUp {e.Key} mods={e.KeyModifiers} src={Src(e.Source)}");
static void OnTextInput(object? sender, TextInputEventArgs e)
=> Record($"TextInput '{e.Text}' src={Src(e.Source)}");
static void OnPointerPressed(object? sender, PointerPressedEventArgs e)
{
var point = e.GetCurrentPoint(sender as Visual);
Record($"PtrPressed {point.Properties.PointerUpdateKind} @{Pos(point.Position)} clicks={e.ClickCount} src={Src(e.Source)}");
}
static void OnPointerReleased(object? sender, PointerReleasedEventArgs e)
{
var point = e.GetCurrentPoint(sender as Visual);
Record($"PtrReleased {point.Properties.PointerUpdateKind} @{Pos(point.Position)} src={Src(e.Source)}");
}
static void OnPointerMoved(object? sender, PointerEventArgs e)
{
// Moves can fire hundreds of times a second; throttle so the trail stays readable while
// still bracketing the moment a DBus call fired.
var now = Environment.TickCount64;
if (now - lastMoveTick < MoveThrottleMs)
return;
lastMoveTick = now;
Record($"PtrMoved @{Pos(e.GetPosition(sender as Visual))} src={Src(e.Source)}");
}
static void OnPointerWheel(object? sender, PointerWheelEventArgs e)
=> Record($"PtrWheel delta={e.Delta} src={Src(e.Source)}");
static void OnPointerEntered(object? sender, PointerEventArgs e)
=> Record($"PtrEntered src={Src(e.Source)}");
static void OnPointerExited(object? sender, PointerEventArgs e)
=> Record($"PtrExited src={Src(e.Source)}");
static void OnGotFocus(object? sender, RoutedEventArgs e)
=> Record($"GotFocus src={Src(e.Source)}");
static void OnLostFocus(object? sender, RoutedEventArgs e)
=> Record($"LostFocus src={Src(e.Source)}");
#endregion
static string Src(object? source)
{
if (source is StyledElement element)
return string.IsNullOrEmpty(element.Name) ? element.GetType().Name : $"{element.GetType().Name}#{element.Name}";
return source?.GetType().Name ?? "null";
}
static string Pos(Point p) => $"{p.X:0},{p.Y:0}";
#region DBus exception unwrapping
/// <summary>
/// True if <paramref name="exception"/> (flattened, including inner exceptions) carries a
/// <c>Tmds.DBus.Protocol.DBusException</c>.
/// </summary>
public static bool ContainsDBusException(Exception? exception)
{
foreach (var root in Roots(exception))
for (var ex = root; ex != null; ex = ex.InnerException)
if (IsDBusException(ex))
return true;
return false;
}
/// <summary>
/// Fully unwraps <paramref name="exception"/> -- flattens any <see cref="AggregateException"/>,
/// walks every inner-exception chain, and for each <c>DBusException</c> reflects the
/// <c>ErrorName</c> / <c>ErrorMessage</c> the bare <c>ToString()</c> hides -- into a readable
/// multi-line report. We reflect because Tmds.DBus is a transitive dependency we don't
/// reference directly.
/// </summary>
public static string DescribeException(Exception? exception)
{
if (exception == null)
return "(null exception)";
var sb = new StringBuilder();
sb.AppendLine($"{exception.GetType().FullName}: {exception.Message}");
var roots = Roots(exception);
for (int i = 0; i < roots.Count; i++)
{
sb.AppendLine($"--- branch {i + 1}/{roots.Count} ---");
int depth = 0;
for (var ex = roots[i]; ex != null; ex = ex.InnerException, depth++)
{
var indent = new string(' ', 2 + depth * 2);
sb.AppendLine($"{indent}{ex.GetType().FullName}: {ex.Message}");
AppendDBusDetails(sb, ex, indent + " ");
}
if (roots[i].StackTrace is { Length: > 0 } stack)
{
sb.AppendLine(" stack:");
sb.AppendLine(stack);
}
}
return sb.ToString();
}
static void AppendDBusDetails(StringBuilder sb, Exception ex, string indent)
{
if (!IsDBusException(ex))
return;
var type = ex.GetType();
foreach (var property in new[] { "ErrorName", "ErrorMessage" })
{
var value = type.GetProperty(property, BindingFlags.Public | BindingFlags.Instance)?.GetValue(ex);
if (value != null)
sb.AppendLine($"{indent}{property} = {value}");
}
}
static bool IsDBusException(Exception ex)
=> ex.GetType().FullName == "Tmds.DBus.Protocol.DBusException"
|| ex.GetType().Name == "DBusException";
static IReadOnlyList<Exception> Roots(Exception? exception)
{
if (exception is AggregateException aggregate)
return aggregate.Flatten().InnerExceptions;
return exception == null ? Array.Empty<Exception>() : new[] { exception };
}
#endregion
}
}

4
ILSpy/Views/MainWindow.axaml.cs

@ -55,6 +55,10 @@ namespace ILSpy.Views @@ -55,6 +55,10 @@ namespace ILSpy.Views
AppLog.Mark("MainWindow XAML inflation about to start (DataContext set)");
InitializeComponent();
AppLog.Mark("MainWindow XAML inflation done");
// Records every mouse/keyboard interaction under ILSPY_LOG=DBUSDEBUG so an unobserved
// DBus error (which surfaces later on the finalizer thread) can be traced back to the
// gesture that triggered the DBus call. No-op unless that category is enabled.
InputDiagnostics.Attach(this);
ILSpy.MainMenu.Attach(this);
ApplySessionSettings(settingsService.SessionSettings);
Opened += async (_, _) => {

Loading…
Cancel
Save