Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

v2win/v2net: UICatalog full benchmark suite crashes in Dialogs scenario #3941

Open
TheTonttu opened this issue Mar 1, 2025 · 12 comments · May be fixed by #3946
Open

v2win/v2net: UICatalog full benchmark suite crashes in Dialogs scenario #3941

TheTonttu opened this issue Mar 1, 2025 · 12 comments · May be fixed by #3946
Labels

Comments

@TheTonttu
Copy link
Contributor

Describe the bug

When running the full benchmark suite with either the v2win or v2net driver the Dialogs scenario crashes. Running the Dialogs scenario alone does not crash most of the time but it is also prone to crash.

The Dialogs scenario seems to be stuck for a while before crashing. Sometimes instead of crashing it is just stuck there at least longer than my patience persists.

To Reproduce

Choose one of the commands and run it in Release build:

UICatalog.exe --driver v2win --benchmark
UICatalog.exe --driver v2net --benchmark

Expected behavior

The benchmark suite finishes without crashes.

Screenshots

Running the full benchmark suite with both v2 drivers in VS the debug output shows a StackOverflowException when the benchmark crashes after message flood. Of course no stack trace is available when stack overflows.

Image

After flooding for a while...

Image

Memory is flooded rapidly at the time it happens.

Image

Desktop

  • OS: Windows 10 22H2 (build 19045.5487)
  • CLI: Windows Terminal v1.21.10351.0 /w cmd
  • Terminal.GUI branch: v2_develop
@tznind
Copy link
Collaborator

tznind commented Mar 1, 2025

I can't seem to get trace logs out @tig , I've tried with -dl trace and -dl verbose neither of which seems to result in VRB logs being generated.

I do get the normal logs though... also tried capital V for verbose but no joy 😕

@tig
Copy link
Collaborator

tig commented Mar 1, 2025

I can't seem to get trace logs out @tig , I've tried with -dl trace and -dl verbose neither of which seems to result in VRB logs being generated.

Fix is

    private static ILogger CreateLogger ()
    {
        // Configure Serilog to write logs to a file
+        _logLevelSwitch.MinimumLevel = Enum.Parse<LogEventLevel> (_options.DebugLogLevel);
        Log.Logger = new LoggerConfiguration ()

I do get the normal logs though... also tried capital V for verbose but no joy 😕

System.CommandLine is case sensitive.

Also Trace is not a valid LogEventLevel.

/// <summary>
/// Specifies the meaning and relative importance of a log event.
/// </summary>
public enum LogEventLevel
{
    /// <summary>
    /// Anything and everything you might want to know about
    /// a running block of code.
    /// </summary>
    Verbose,

    /// <summary>
    /// Internal system events that aren't necessarily
    /// observable from the outside.
    /// </summary>
    Debug,

    /// <summary>
    /// The lifeblood of operational intelligence - things
    /// happen.
    /// </summary>
    Information,

    /// <summary>
    /// Service is degraded or endangered.
    /// </summary>
    Warning,

    /// <summary>
    /// Functionality is unavailable, invariants are broken
    /// or data is lost.
    /// </summary>
    Error,

    /// <summary>
    /// If you have a pager, it goes off when one of these
    /// occurs.
    /// </summary>
    Fatal
}

@tig
Copy link
Collaborator

tig commented Mar 1, 2025

(I just edited the above).

@tig
Copy link
Collaborator

tig commented Mar 1, 2025

Grok says:

When Serilog integrates with ILogger, it maps LogLevel to LogEventLevel:
LogLevel.Trace → LogEventLevel.Verbose
LogLevel.Debug → LogEventLevel.Debug
LogLevel.Information → LogEventLevel.Information
LogLevel.Warning → LogEventLevel.Warning
LogLevel.Error → LogEventLevel.Error
LogLevel.Critical → LogEventLevel.Fatal
LogLevel.None → No equivalent (disables logging).

Which naming should we use? We should be consistent.

@tznind
Copy link
Collaborator

tznind commented Mar 1, 2025

Ah this is because UICatalog is implementing Serilog while the Terminal.Gui logger is ILogger (from core microsoft).

Since the calls in core library are LogLevel we should probably use that for the command line but that means changing it into the Serilog level for the actual logger.

@tznind
Copy link
Collaborator

tznind commented Mar 1, 2025

I am struggling to understand this stack overflow, it seems to be tied up in the RaiseAccepting logic. But it does not seem to repro when using the UI directly and trying to press the coresponding buttons.

Its like the Accepting is looking at the super view to compute IsDefault which is then running a new iteration and... unclear.

I wonder if this is why we have sporadic test failures in CI, there is All_Scenarios_Benchmark and a stack overflow might cause the behaviour we see.

>	System.Private.CoreLib.dll!System.Text.Rune.ToString() Line 492	C#
 	Terminal.Gui.dll!Terminal.Gui.TextFormatter.RemoveHotKeySpecifier(string text, int hotPos, System.Text.Rune hotKeySpecifier) Line 2136	C#
 	Terminal.Gui.dll!Terminal.Gui.TextFormatter.GetLines() Line 607	C#
 	Terminal.Gui.dll!Terminal.Gui.TextFormatter.FormatAndGetSize(System.Drawing.Size? constrainSize) Line 507	C#
 	Terminal.Gui.dll!Terminal.Gui.DimAuto.Calculate(int location, int superviewContentSize, Terminal.Gui.View us, Terminal.Gui.Dimension dimension) Line 48	C#
 	Terminal.Gui.dll!Terminal.Gui.PosAlign.AlignAndUpdateGroup(int groupId, System.Collections.Generic.IList<Terminal.Gui.View> views, Terminal.Gui.Dimension dimension, int size) Line 166	C#
 	Terminal.Gui.dll!Terminal.Gui.PosAlign.Calculate(int superviewDimension, Terminal.Gui.Dim dim, Terminal.Gui.View us, Terminal.Gui.Dimension dimension) Line 123	C#
 	Terminal.Gui.dll!Terminal.Gui.View.SetRelativeLayout(System.Drawing.Size superviewContentSize) Line 490	C#
 	Terminal.Gui.dll!Terminal.Gui.DimAuto.Calculate(int location, int superviewContentSize, Terminal.Gui.View us, Terminal.Gui.Dimension dimension) Line 308	C#
 	Terminal.Gui.dll!Terminal.Gui.View.SetRelativeLayout(System.Drawing.Size superviewContentSize) Line 506	C#
 	Terminal.Gui.dll!Terminal.Gui.View.Layout(System.Drawing.Size contentSize) Line 417	C#
 	Terminal.Gui.dll!Terminal.Gui.View.Layout(System.Collections.Generic.IEnumerable<Terminal.Gui.View> views, System.Drawing.Size contentSize) Line 393	C#
 	Terminal.Gui.dll!Terminal.Gui.Application.LayoutAndDraw(bool forceDraw) Line 415	C#
 	Terminal.Gui.dll!Terminal.Gui.MainLoop<System.ConsoleKeyInfo>.IterationImpl() Line 134	C#
 	Terminal.Gui.dll!Terminal.Gui.MainLoop<System.ConsoleKeyInfo>.Iteration() Line 103	C#
 	Terminal.Gui.dll!Terminal.Gui.MainLoopCoordinator<System.ConsoleKeyInfo>.RunIteration() Line 137	C#
 	Terminal.Gui.dll!Terminal.Gui.ApplicationV2.Run(Terminal.Gui.Toplevel view, System.Func<System.Exception, bool> errorHandler) Line 177	C#
 	Terminal.Gui.dll!Terminal.Gui.Application.Run(Terminal.Gui.Toplevel view, System.Func<System.Exception, bool> errorHandler) Line 376	C#
 	UICatalog.dll!UICatalog.Scenarios.Dialogs.Main.AnonymousMethod__1(object s, Terminal.Gui.CommandEventArgs e) Line 200	C#
 	Terminal.Gui.dll!Terminal.Gui.View.RaiseAccepting(Terminal.Gui.ICommandContext ctx) Line 85	C#
 	Terminal.Gui.dll!Terminal.Gui.View.InvokeCommand<Terminal.Gui.KeyBinding>(Terminal.Gui.Command command, Terminal.Gui.KeyBinding binding) Line 332	C#
 	Terminal.Gui.dll!Terminal.Gui.View.RaiseAccepting(Terminal.Gui.ICommandContext ctx) Line 107	C#
 	Terminal.Gui.dll!Terminal.Gui.View.InvokeCommand<Terminal.Gui.KeyBinding>(Terminal.Gui.Command command, Terminal.Gui.KeyBinding binding) Line 332	C#
 	Terminal.Gui.dll!Terminal.Gui.View.RaiseAccepting(Terminal.Gui.ICommandContext ctx) Line 98	C#
 	Terminal.Gui.dll!Terminal.Gui.View.InvokeCommand<Terminal.Gui.KeyBinding>(Terminal.Gui.Command command, Terminal.Gui.KeyBinding binding) Line 332	C#
 	Terminal.Gui.dll!Terminal.Gui.View.RaiseAccepting(Terminal.Gui.ICommandContext ctx) Line 107	C#
 	Terminal.Gui.dll!Terminal.Gui.View.InvokeCommand<Terminal.Gui.KeyBinding>(Terminal.Gui.Command command, Terminal.Gui.KeyBinding binding) Line 332	C#
 	Terminal.Gui.dll!Terminal.Gui.View.InvokeCommands<Terminal.Gui.KeyBinding>(Terminal.Gui.Command[] commands, Terminal.Gui.KeyBinding binding) Line 303	C#
 	Terminal.Gui.dll!Terminal.Gui.View.DoInvokeCommands(Terminal.Gui.Key key) Line 644	C#
 	Terminal.Gui.dll!Terminal.Gui.View.InvokeCommands(Terminal.Gui.Key key) Line 529	C#
 	Terminal.Gui.dll!Terminal.Gui.View.NewKeyDownEvent(Terminal.Gui.Key key) Line 300	C#
 	Terminal.Gui.dll!Terminal.Gui.View.NewKeyDownEvent(Terminal.Gui.Key key) Line 286	C#
 	Terminal.Gui.dll!Terminal.Gui.View.NewKeyDownEvent(Terminal.Gui.Key key) Line 286	C#
 	Terminal.Gui.dll!Terminal.Gui.Application.RaiseKeyDownEvent(Terminal.Gui.Key key) Line 40	C#
 	UICatalog.dll!UICatalog.Scenario.OnApplicationNotifyNewRunState.AnonymousMethod__30_0() Line 248	C#
 	Terminal.Gui.dll!Terminal.Gui.TimedEvents.RunTimers() Line 153	C#
 	Terminal.Gui.dll!Terminal.Gui.TimedEvents.LockAndRunTimers() Line 113	C#
 	Terminal.Gui.dll!Terminal.Gui.MainLoop<System.ConsoleKeyInfo>.IterationImpl() Line 146	C#
 	[The 24 frame(s) above this were repeated 224 times]	
 	UICatalog.dll!UICatalog.Scenarios.Dialogs.Main.AnonymousMethod__1(object s, Terminal.Gui.CommandEventArgs e) Line 200	C#
 	Terminal.Gui.dll!Terminal.Gui.View.RaiseAccepting(Terminal.Gui.ICommandContext ctx) Line 85	C#
 	Terminal.Gui.dll!Terminal.Gui.View.InvokeCommand<Terminal.Gui.KeyBinding>(Terminal.Gui.Command command, Terminal.Gui.KeyBinding binding) Line 332	C#
 	Terminal.Gui.dll!Terminal.Gui.View.RaiseAccepting(Terminal.Gui.ICommandContext ctx) Line 107	C#
 	Terminal.Gui.dll!Terminal.Gui.View.InvokeCommand<Terminal.Gui.KeyBinding>(Terminal.Gui.Command command, Terminal.Gui.KeyBinding binding) Line 332	C#
 	Terminal.Gui.dll!Terminal.Gui.View.RaiseAccepting(Terminal.Gui.ICommandContext ctx) Line 98	C#
 	Terminal.Gui.dll!Terminal.Gui.View.InvokeCommand<Terminal.Gui.KeyBinding>(Terminal.Gui.Command command, Terminal.Gui.KeyBinding binding) Line 332	C#
 	Terminal.Gui.dll!Terminal.Gui.View.RaiseAccepting(Terminal.Gui.ICommandContext ctx) Line 107	C#
 	Terminal.Gui.dll!Terminal.Gui.View.InvokeCommand<Terminal.Gui.KeyBinding>(Terminal.Gui.Command command, Terminal.Gui.KeyBinding binding) Line 332	C#
 	Terminal.Gui.dll!Terminal.Gui.View.InvokeCommands<Terminal.Gui.KeyBinding>(Terminal.Gui.Command[] commands, Terminal.Gui.KeyBinding binding) Line 303	C#
 	Terminal.Gui.dll!Terminal.Gui.View.DoInvokeCommands(Terminal.Gui.Key key) Line 644	C#
 	Terminal.Gui.dll!Terminal.Gui.View.InvokeCommands(Terminal.Gui.Key key) Line 529	C#
 	Terminal.Gui.dll!Terminal.Gui.View.NewKeyDownEvent(Terminal.Gui.Key key) Line 300	C#
 	Terminal.Gui.dll!Terminal.Gui.View.NewKeyDownEvent(Terminal.Gui.Key key) Line 286	C#
 	Terminal.Gui.dll!Terminal.Gui.View.NewKeyDownEvent(Terminal.Gui.Key key) Line 286	C#
 	Terminal.Gui.dll!Terminal.Gui.Application.RaiseKeyDownEvent(Terminal.Gui.Key key) Line 40	C#
 	UICatalog.dll!UICatalog.Scenario.OnApplicationNotifyNewRunState.AnonymousMethod__30_0() Line 248	C#
 	Terminal.Gui.dll!Terminal.Gui.TimedEvents.RunTimers() Line 153	C#
 	Terminal.Gui.dll!Terminal.Gui.TimedEvents.LockAndRunTimers() Line 113	C#
 	Terminal.Gui.dll!Terminal.Gui.MainLoop<System.ConsoleKeyInfo>.IterationImpl() Line 146	C#
 	Terminal.Gui.dll!Terminal.Gui.MainLoop<System.ConsoleKeyInfo>.Iteration() Line 103	C#
 	Terminal.Gui.dll!Terminal.Gui.MainLoopCoordinator<System.ConsoleKeyInfo>.RunIteration() Line 137	C#
 	Terminal.Gui.dll!Terminal.Gui.ApplicationV2.Run(Terminal.Gui.Toplevel view, System.Func<System.Exception, bool> errorHandler) Line 177	C#
 	Terminal.Gui.dll!Terminal.Gui.Application.Run(Terminal.Gui.Toplevel view, System.Func<System.Exception, bool> errorHandler) Line 376	C#
 	UICatalog.dll!UICatalog.Scenarios.Dialogs.Main() Line 208	C#
 	UICatalog.dll!UICatalog.UICatalogApp.RunScenario(UICatalog.Scenario scenario, bool benchmark) Line 495	C#
 	UICatalog.dll!UICatalog.UICatalogApp.BenchmarkAllScenarios() Line 520	C#
 	UICatalog.dll!UICatalog.UICatalogApp.UICatalogMain(UICatalog.UICatalogApp.Options options) Line 429	C#
 	UICatalog.dll!UICatalog.UICatalogApp.Main(string[] args) Line 232	C#

@tig
Copy link
Collaborator

tig commented Mar 1, 2025

Issue is probably in here:

  /// <summary>
  ///     Called when the user is accepting the state of the View and the <see cref="Command.Accept"/> has been invoked. Calls <see cref="OnAccepting"/> which can be cancelled; if not cancelled raises <see cref="Accepting"/>.
  ///     event. The default <see cref="Command.Accept"/> handler calls this method.
  /// </summary>
  /// <remarks>
  /// <para>
  ///     The <see cref="Accepting"/> event should be raised after the state of the View has changed (after <see cref="Selecting"/> is raised).
  /// </para>
  /// <para>
  ///    If the Accepting event is not handled, <see cref="Command.Accept"/> will be invoked on the SuperView, enabling default Accept behavior.
  /// </para>
  /// <para>
  ///    If a peer-View raises the Accepting event and the event is not cancelled, the <see cref="Command.Accept"/> will be invoked on the
  ///    first Button in the SuperView that has <see cref="Button.IsDefault"/> set to <see langword="true"/>.
  /// </para>
  /// </remarks>
  /// <returns>
  ///     <see langword="null"/> if no event was raised; input processing should continue.
  ///     <see langword="false"/> if the event was raised and was not handled (or cancelled); input processing should continue.
  ///     <see langword="true"/> if the event was raised and handled (or cancelled); input processing should stop.
  /// </returns>
  protected bool? RaiseAccepting (ICommandContext? ctx)
  {
      CommandEventArgs args = new () { Context = ctx };

      // Best practice is to invoke the virtual method first.
      // This allows derived classes to handle the event and potentially cancel it.
      args.Cancel = OnAccepting (args) || args.Cancel;

      if (!args.Cancel)
      {
          // If the event is not canceled by the virtual method, raise the event to notify any external subscribers.
          Accepting?.Invoke (this, args);
      }

      // Accept is a special case where if the event is not canceled, the event is
      //  - Invoked on any peer-View with IsDefault == true
      //  - bubbled up the SuperView hierarchy.
      if (!args.Cancel)
      {
          // If there's an IsDefault peer view in Subviews, try it
          var isDefaultView = SuperView?.Subviews.FirstOrDefault (v => v is Button { IsDefault: true });

          if (isDefaultView != this && isDefaultView is Button { IsDefault: true } button)
          {
              bool? handled = isDefaultView.InvokeCommand<KeyBinding> (Command.Accept, new ([Command.Accept], null, this));
              if (handled == true)
              {
                  return true;
              }
          }

          if (SuperView is { })
          {
              return SuperView?.InvokeCommand<KeyBinding> (Command.Accept, new ([Command.Accept], null, this)) is true;
          }
      }

      return Accepting is null ? null : args.Cancel;
  }

@tznind
Copy link
Collaborator

tznind commented Mar 1, 2025

I think the Enter key is being raised over and over.

I have a hypothesis.

There is a TimedEvent in the stack. If the timed event raises Enter which calls Run. Then run does an iteration and finds the same timed event and triggers another Run.

Because you never get out of the timed event callback it never gets removed or it's run time changed.

Solution would be to prevent double entry into the same timed event callback

@tig
Copy link
Collaborator

tig commented Mar 1, 2025

This?

private void OnApplicationNotifyNewRunState (object? sender, RunStateEventArgs e)
{
    SubscribeAllSubviews (Application.Top!);

    _currentDemoKey = 0;
    _demoKeys = GetDemoKeyStrokes ();

    Application.AddTimeout (
                            new TimeSpan (0, 0, 0, 0, BENCHMARK_KEY_PACING),
                            () =>
                            {
                                if (_currentDemoKey >= _demoKeys.Count)
                                {
                                    return false;
                                }

                                Application.RaiseKeyDownEvent (_demoKeys [_currentDemoKey++]);

                                return true;
                            });

    return;

    // Get a list of all subviews under Application.Top (and their subviews, etc.)
    // and subscribe to their DrawComplete event
    void SubscribeAllSubviews (View view)
    {
        view.DrawComplete += (s, a) => BenchmarkResults.DrawCompleteCount++;
        view.SubviewsLaidOut += (s, a) => BenchmarkResults.LaidOutCount++;
        foreach (View subview in view.Subviews)
        {
            SubscribeAllSubviews (subview);
        }
    }
}

@tig
Copy link
Collaborator

tig commented Mar 1, 2025

Yep.

-private const int BENCHMARK_KEY_PACING = 1; // Must be non-zero
 +private const int BENCHMARK_KEY_PACING = 100; // Must be non-zero

After

\UICatalog\bin\Debug\net8.0\UICatalog.exe --driver v2win --benchmark Dialogs                                                                                          {
  "Scenario": "Dialogs",
  "Duration": "00:00:02.8324626",
  "IterationCount": 0,
  "ClearedContentCount": 17,
  "RefreshedCount": 0,
  "UpdatedCount": 0,
  "DrawCompleteCount": 398,
  "LaidOutCount": 34
}

@tig
Copy link
Collaborator

tig commented Mar 1, 2025

10 works too.

But I need to make this more rebust because that's stoopid. Not sure how.

@tig tig linked a pull request Mar 2, 2025 that will close this issue
9 tasks
@tznind
Copy link
Collaborator

tznind commented Mar 2, 2025

Not sure I understand how this is triggering infinite loop... the callback has ++ on keys counter - so even if the timeout code ran over and over, it should run out of keys 🤔

Ah right, it's because the dialog is a popup which is a new run state. And when it closes its probably also a new run state maybe.

This code needs to check to see if the run state being entered is a Scenario maybe? And that it is the first time entering that Scenario.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants