UI freezes when updating submodule status

[gerhardol]

Current behaviour

When the submodule status are updated for the drop down (or side panel in master), the UI can freeze and stop to respond.

Note: There are several issues reported that are related to this already. However, most are quite generic and have been partly fixed (or a workaround applied). This issue is a fresh start to describe a (the core?) problem.

Expected behaviour

The UI responding.

Steps to reproduce

This is described for master, can be reproduced in a similar way for 3.0, but master (3.1) (even better with #6349, now merged to master) has better visual clues (status in left panel). In 3.0 the submodule structure and status is calculated immediately, in 3.1 the structure is calculated immediately but the status is evaluated when commit-count reports that submodules are dirty or changed.

The more submodules there is in a repo, the easier it is to reproduce. I find it easier to reproduce if I add GE as a submodule to itself 4 times. It can be reproduced with fewer and more reliably occurs with more clones, but the freeze is annoying...
The following add a clone to an existing local directory, repeat four times:

$ git submodule add ../gitextensions subtest/x001

To create many:

for i in `seq 1 100`; do git submodule add ../gitextensions subtest/x$i; done

• Enable submodule status (require commit status) (GE 3.0 do not require commit status, submodule status queried instantly).

• Change revision or make a submodule dirty (to initiate the submodule status when commit status sees changes)
  $ touch GitExtensionsDoc/t.t

• Show the Git Command log

View the Diff tab (to get GE to create Git commands).
View artificial commits
Reload (F5)

Watch the command log to emit updates every second (instead of many per second). If no freeze when the status markers appears (use #6349, now merged), refresh again until the problem appear.

To see that the "slow log update" is actually a problem:
When Commit button changes from gray to yellow switch between Worktree and Index artificial commits until the UI freezes.
Note: It is easier to recreate by selecting commits, but the command cache requires that you scroll to get new commits at each try.

Screenshots

One recording, first try experiences the problem, the second not

ge_subm.txt

Did this work in previous version of GitExtensions

Working fine in 2.51

To recreate the same scenario in GE2.51:
Wait 15 s (the menu structure/status is evaluated at Browse activation, throttled)
Activate Browse, select the submodule menu

Note that the menu is sluggish and the background work due to all submodule calculations is quite high as the structure and status is often recreated.

Environment

• Git Extensions 3.1.0
• Build 6c6885e
• Git 2.21.0.windows.1
• Microsoft Windows NT 10.0.17763.0
• .NET Framework 4.7.3324.0
• DPI 96dpi (no scaling)

[gerhardol]

The command log shows a lot more calls of "git rev-parse --git-common-dir" than required, called when making a copy of a GitModule that should not be necessary.

When the problem occurs, the git-rev-parse commands are emitted about one every second.
See log at
2019-03-09T22:50:01.8937308+01:00

[gerhardol]

I am testing with a workaround to eliminate git-rev-parse calls. This reduces the risk, I could not reproduce with 4 "extra" clones, but 8 is more prone to recreate the problem

[amaiorano]

I'm glad you created this issue to help track the perf issue. What I'd like to know is what exactly is the issue here? Is the revision graph waiting on git commands to complete, but these are blocked while submodule update also executes a bunch of commands? Are these commands that require a repo lock? I mentioned this before, but maybe it's worth considering a priority queue for git commands - even if just 2 levels: higher for "UI" (commands that block UI), lower for background.

[gerhardol]

What I'd like to know is what exactly is the issue here?

The diff tab (and commit) should probably get the output async, at least cancel if selection changes.
The core problem is that execution stops, one Git command each second. Exhaustion?
The threads are blocked on WaitSynchronouslyCore, GitUI.ThreadHelper.JoinableTaskFactory.Run()
I am not sure if the Git commands are started or not.
The --no-optional-locks option is set (and git-diff) should not lock the repo).

maybe it's worth considering a priority queue for git commands

Currently we start Git commands (which is the primary I/O) immediately, no queue or throttling.
Some kind of thread prioritization could help. I tried to start a discussion for thread priorities in #6000

To complete #5769 would eliminate the problem in most scenarios by reducing git-diff to where needed. But the "all modules are changed" should be handled too (and someone may request that status is set also when not the topmodule is selected).

[gerhardol]

@sharwell @jbialobr Any hints on the problem?

[jbialobr]

The problem is here

gitextensions/GitCommands/Submodules/SubmoduleStatusProvider.cs

Line 154 in 5c0d503

private async Task GetSubmoduleStatusAsync(bool updateStatus, SubmoduleInfo info, CancellationToken cancelToken)

It is an async method, but instead of using async GitModule api it uses a background task to perform a sync operations with blocking on I/O (reading from git.exe). Generally await TaskScheduler.Default; should be only used for time expensive operations but non blocking - we don't want them executing on the main thread and block the UI. Every time we want to execute a git command asynchronously we should go for the async api instead of delegating the work to the background thread.

[amaiorano]

Generally await TaskScheduler.Default; should be only used for time expensive operations but non blocking - we don't want them executing on the main thread and block the UI.

Just for my own education, how does executing a blocking operation (I/O) on a background thread block the UI thread?

[jbialobr]

It is because when the main thread executes a git command it indirectly uses threads from the thread pool
(GetOutputAsync -> CopyToAsync -> https://referencesource.microsoft.com/#mscorlib/system/io/stream.cs,08ee62b6d544c8fe,references -> ConfigureAwait(false)). This way the main thread to complete, has to compete with other background tasks for the thread pool resources. So it stands in a line and waits for a thread which could read data from the git process.

[vbjay]

A custom task scheduler that maybe round robins a few threads might help. We could play with the number. We can use a taskfactory to make the needed tasks to use our scheduler.

…

On Tue, Mar 12, 2019, 1:05 AM Janusz Białobrzewski ***@***.***> wrote: It is because when the main thread executes a git command it indirectly uses threads from the thread pool (GetOutputAsync -> CopyToAsync -> https://referencesource.microsoft.com/#mscorlib/system/io/stream.cs,08ee62b6d544c8fe,references -> ConfigureAwait(false)). This way the main thread to complete, has to compete with other background tasks for the thread pool resources. So it stands in a line and waits for a thread which could read data from the git process. — You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub <#6357 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/ADdhsWQAL05EEjtl5CPLDNN3dcG_vzr2ks5vVzWNgaJpZM4bm7Tb> .

[amaiorano]

It is because when the main thread executes a git command it indirectly uses threads from the thread pool

That makes sense, but what's escaping me is where exactly is the main thread executing git commands? You said that the problem is that GetSubmoduleStatusAsync executes IO on a background thread. Sorry if I'm not seeing it, and thanks for explaining, @jbialobr.

[jbialobr]

When refreshing repo, one is FileStatusList.SetDiffs, another is GetCurrentCheckout. But it can be anything. The scenario is that when for any reason submodules are updating using too many background threads, the main thread remains responsive. Then you click on anything that requires a trip to git.exe and if that trip is synchronous you get hung.

[amaiorano]

When refreshing repo, one is FileStatusList.SetDiffs, another is GetCurrentCheckout. But it can be anything. The scenario is that when for any reason submodules are updating using too many background threads, the main thread remains responsive. Then you click on anything that requires a trip to git.exe and if that trip is synchronous you get hung.

Ah, okay, I understand now. So we have to be careful to only using async IO so that we don't block worker threads in the pool. Is this something that can be easily addressed for the SubmoduleStatusProvider?

[jbialobr]

Ah, okay, I understand now. So we have to be careful to only using async IO so that we don't block worker threads in the pool.

Exactly.

Is this something that can be easily addressed for the SubmoduleStatusProvider?

The easiest way is to either introduce an async equivalent for each sync method used by SubmoduleStatusProvider or replace the sync version with an async one and where possible use the async version and where not possible wrap in JTF.Run. Perhaps the solution could be also a mix of both.

[ideaalab]

Im having this problem, and my project only have 1 submodule.
Only the commit history view (I dont know how its really called) is blocked. In my case it shows all black.
But if I click on any place there, a commit is selected. And if i right click the contextual menu is shown.
I can still commit, create branches, stack, etc... Only im going blind.

[gerhardol]

Im having this problem, and my project only have 1 submodule.

It seems like something different. If you have a space in the path this will occur for instance (already corrected in master, you can test).
Open another issue if this something else.

[jbialobr]

A custom task scheduler that maybe round robins a few threads might help.
We could play with the number. We can use a taskfactory to make the needed
tasks to use our scheduler.

@vbjay The more I think about this, the more I am leaning to your proposal. Uncontrolled use of the default thread pool interferes with the async/await mechanizm causing bad lags in UI responsiveness.
What helped in #6372 was limiting the number of background threads to 1 and I wondered to what number I could increase the numer of threads to not degrade the responsiveness. But it would be the same as your proposal, but done manually while your proposal is on the system level.

[vbjay]

@jbialobr Yep. DRY code is better. Define a taskfactory that uses the right taskscheduler to create the tasks. That way, if we need to use our taskscheduler for git commands and maybe the threadpool for others, we can just not use out taksfactory for some. We control the threading with the scheduler, and taskfactory. They aren't hard to make.

//--------------------------------------------------------------------------
// 
//  Copyright (c) Microsoft Corporation.  All rights reserved. 
// 
//  File: StaTaskScheduler.cs
//
//--------------------------------------------------------------------------

using System.Collections.Concurrent;
using System.Collections.Generic;
using System.Linq;

namespace System.Threading.Tasks.Schedulers
{
    /// <summary>Provides a scheduler that uses STA threads.</summary>
    public sealed class StaTaskScheduler : TaskScheduler, IDisposable
    {
        /// <summary>Stores the queued tasks to be executed by our pool of STA threads.</summary>
        private BlockingCollection<Task> _tasks;
        /// <summary>The STA threads used by the scheduler.</summary>
        private readonly List<Thread> _threads;

        /// <summary>Initializes a new instance of the StaTaskScheduler class with the specified concurrency level.</summary>
        /// <param name="numberOfThreads">The number of threads that should be created and used by this scheduler.</param>
        public StaTaskScheduler(int numberOfThreads)
        {
            // Validate arguments
            if (numberOfThreads < 1) throw new ArgumentOutOfRangeException("concurrencyLevel");

            // Initialize the tasks collection
            _tasks = new BlockingCollection<Task>();

            // Create the threads to be used by this scheduler
            _threads = Enumerable.Range(0, numberOfThreads).Select(i =>
                       {
                           var thread = new Thread(() =>
                           {
                               // Continually get the next task and try to execute it.
                               // This will continue until the scheduler is disposed and no more tasks remain.
                               foreach (var t in _tasks.GetConsumingEnumerable())
                               {
                                   TryExecuteTask(t);
                               }
                           });
                           thread.IsBackground = true;
                           thread.SetApartmentState(ApartmentState.STA);
                           return thread;
                       }).ToList();

            // Start all of the threads
            _threads.ForEach(t => t.Start());
        }

        /// <summary>Queues a Task to be executed by this scheduler.</summary>
        /// <param name="task">The task to be executed.</param>
        protected override void QueueTask(Task task)
        {
            // Push it into the blocking collection of tasks
            _tasks.Add(task);
        }

        /// <summary>Provides a list of the scheduled tasks for the debugger to consume.</summary>
        /// <returns>An enumerable of all tasks currently scheduled.</returns>
        protected override IEnumerable<Task> GetScheduledTasks()
        {
            // Serialize the contents of the blocking collection of tasks for the debugger
            return _tasks.ToArray();
        }

        /// <summary>Determines whether a Task may be inlined.</summary>
        /// <param name="task">The task to be executed.</param>
        /// <param name="taskWasPreviouslyQueued">Whether the task was previously queued.</param>
        /// <returns>true if the task was successfully inlined; otherwise, false.</returns>
        protected override bool TryExecuteTaskInline(Task task, bool taskWasPreviouslyQueued)
        {
            // Try to inline if the current thread is STA
            return
                Thread.CurrentThread.GetApartmentState() == ApartmentState.STA &&
                TryExecuteTask(task);
        }

        /// <summary>Gets the maximum concurrency level supported by this scheduler.</summary>
        public override int MaximumConcurrencyLevel
        {
            get { return _threads.Count; }
        }

        /// <summary>
        /// Cleans up the scheduler by indicating that no more tasks will be queued.
        /// This method blocks until all threads successfully shutdown.
        /// </summary>
        public void Dispose()
        {
            if (_tasks != null)
            {
                // Indicate that no new tasks will be coming in
                _tasks.CompleteAdding();

                // Wait for all threads to finish processing tasks
                foreach (var thread in _threads) thread.Join();

                // Cleanup
                _tasks.Dispose();
                _tasks = null;
            }
        }
    }
}

[sharwell]

A custom task scheduler that maybe round robins a few threads might help.
We could play with the number. We can use a taskfactory to make the needed
tasks to use our scheduler.

This might be a workaround, but it's really not the correct approach. We should not be blocking threads for IO, regardless of whether those threads are UI threads, Thread Pool threads, or other dedicated threads.

The worst offender right now is GetOutput, which I'll describe over in #6319.

[jbialobr]

This might be a workaround, but it's really not the correct approach. We should not be blocking threads for IO, regardless of whether those threads are UI threads, Thread Pool threads, or other dedicated threads.

In #6372 I encountered a situation when no background thread was blocking for IO (all the calls were async) yet there was a big lag in processing async IO - see the time column in the attached screenshots. There was no thread that could process pending async IO continuations. Running these same commands in sequence was 10 times faster than in parallel.

[ideaalab]

It seems like something different. If you have a space in the path this will occur for instance (already corrected in master, you can test).

Thanks @gerhardol is it possible to download the builded master anywhere? Otherwise i will have to wait to the next release.

[RussKie]

is it possible to download the builded master anywhere?

https://ci.appveyor.com/api/buildjobs/wy4tfeggjx1xhfxs/artifacts/Setup%2FGitExtensions-Portable-3.1.0.5505.zip

[pmiossec]

The link is on the main page : https://github.com/gitextensions/gitextensions/blob/master/README.md#download

Or more specifically https://ci.appveyor.com/project/gitextensions/gitextensions/branch/master/artifacts

[ideaalab]

Thanks both... Ive tried but the exe gives an error when launching. Something about an URL...
I will wait until the next stable release.

[mstv]

error when launching. Something about an URL...

reproducible on some machines --> #6381