Performance degradation in 3.0+

[DmitriyYukhanov]

Hey guys,

Current behaviour

I've recently updated to 3.0.2 from older 2.* version and noticed this: after opening new repository or submodule, GitExt freezes for 4-6 seconds (differs from time to time but never saw less than 4 secs).
Video:
http://codestage.net/dump/share/2019.02/Untitled%20Project.mp4

Same for fresh submodule with only 1 commit - same 4-6 secs delay.

It was responsive nearly immediately prior to 3.0.

Expected behaviour

I expect it to be instantly responsive, as it was prior to 3.0

Steps to reproduce

Update to 3.0+, open any repo on latest Windows 10

Screenshots

Hope tiny video works better here:
http://codestage.net/dump/share/2019.02/Untitled%20Project.mp4

Did this work in previous version of GitExtensions

It was fine in 2.** I had before updating to 3.0

Environment

• GitExtensions version: 3.0.2.5232 (actually all current 3.0 releases from GitHub)
• GIT version: 2.20.0.windows.1
• OS version: 10.0.17763.0
• .NET version: 4.7.3324.0

Diagnostics

I found this particular command a bit beefy:

> File name:   C:\Program Files\Git\bin\git.exe
> Arguments:   --no-optional-locks status --porcelain=2 -z --untracked-files --ignore-submodules=none
> Working dir: D:\Work\Current\***\***\
> Process ID:  31396
> Started at:  2019-02-18T18:47:07.0292477+03:00
> UI Thread?:  False
> Duration:    4017,943 ms
> Exit code:   0
> Call stack: 
>    в GitCommands.Logging.CommandLog.LogProcessStart(String fileName, String arguments, String workDir)
>    в GitCommands.Executable.ProcessWrapper..ctor(String fileName, String arguments, String workDir, Boolean createWindow, Boolean redirectInput, Boolean redirectOutput, Encoding outputEncoding)
>    в GitCommands.Executable.Start(ArgumentString arguments, Boolean createWindow, Boolean redirectInput, Boolean redirectOutput, Encoding outputEncoding)
>    в GitCommands.ExecutableExtensions.<GetOutputAsync>d__3.MoveNext()
>    в System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.Start[TStateMachine](TStateMachine& stateMachine)
>    в GitCommands.ExecutableExtensions.GetOutputAsync(IExecutable executable, ArgumentString arguments, Byte[] input, Encoding outputEncoding, CommandCache cache, Boolean stripAnsiEscapeCodes)
>    в GitCommands.ExecutableExtensions.<>c__DisplayClass2_0.<GetOutput>b__0()
>    в Microsoft.VisualStudio.Threading.JoinableTaskFactory.ExecuteJob[T](Func`1 asyncMethod, JoinableTask job)
>    в Microsoft.VisualStudio.Threading.JoinableTaskFactory.RunAsync[T](Func`1 asyncMethod, Boolean synchronouslyBlocking, JoinableTaskCreationOptions creationOptions)
>    в Microsoft.VisualStudio.Threading.JoinableTaskFactory.Run[T](Func`1 asyncMethod, JoinableTaskCreationOptions creationOptions)
>    в GitCommands.ExecutableExtensions.GetOutput(IExecutable executable, ArgumentString arguments, Byte[] input, Encoding outputEncoding, CommandCache cache, Boolean stripAnsiEscapeCodes)
>    в GitCommands.GitModule.RunGitCmd(ArgumentString arguments, Encoding outputEncoding, Byte[] stdInput)
>    в GitUI.CommandsDialogs.BrowseDialog.GitStatusMonitor.<>c__DisplayClass35_0.<<Update>b__0>d.MoveNext()
>    в System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
>    в System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
>    в System.Runtime.CompilerServices.AsyncMethodBuilderCore.MoveNextRunner.Run()
>    в System.Threading.QueueUserWorkItemCallback.System.Threading.IThreadPoolWorkItem.ExecuteWorkItem()
>    в System.Threading.ThreadPoolWorkQueue.Dispatch()
> 

Sometimes it runs very fast, sometimes it gets 5 secs to execute.

[vbjay]

https://github.com/gitextensions/gitextensions/wiki/Diagnosing-problems

[DmitriyYukhanov]

Thanks, @vbjay
As you could already noticed, I posted suspicious command from the Command Log in the initial report.

Here is some more information from Diagnostics part.

I tried once again and found this right after opening a repo in a fresh GitExt instance:

Count of refs:

8 heads
10 remotes

Counts of stashes: 0

Counts of objects:

$ git count-objects -vH
count: 0
size: 0 bytes
in-pack: 18031
packs: 1
size-pack: 170.11 MiB
prune-packable: 0
garbage: 0
size-garbage: 0 bytes

Count of remotes: 1

Size on disk:

$ du -h -d 1 .git
44K .git/hooks
5,0K .git/info
11G .git/lfs
242K .git/logs
569M .git/modules
171M .git/objects
4,0K .git/refs
12G .git

Should I record PerfView session too?

[DmitriyYukhanov]

Here are interesting parts of PerfView trace:

GitExt itself (opened repo and closed):

Console recorded (perhaps wrapped git process?)

Some git processes:

[gerhardol]

git-status runs in the background, updates the commit count.
This should have minor impact on the GUI performance. Also in GE2 the command started earlier and affected the log retrieval more. But please try without commit count, if only to reduce the noise this command can create.

There has been some reports of slowdowns like this and some tweaks in GE3, no conclusion of the problem though.

[vbjay]

Ignoring lfs you have a GB .git folder. That can most certainly be a part of it.

…

On Mon, Feb 18, 2019, 12:17 PM Gerhard Olsson ***@***.***> wrote: git-status runs in the background, updates the commit count. This should have minor impact on the GUI performance. Also in GE2 the command started earlier and affected the log retrieval more. But please try without commit count, if only to reduce the noise this command can create. There has been some reports of slowdowns like this and some tweaks in GE3, no conclusion of the problem though. — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#6267 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/ADdhsdKpEjS7lPhxEvpGk_RC5LHFuUqTks5vOuASgaJpZM4bBKRG> .

[DmitriyYukhanov]

Thanks @gerhardol and @vbjay
I found option which generated this huge delay:
Show submodule status in browse menu

When I disable it - everything is loaded and initialized blazingly fast. When I turn it back - I get UI freeze back.

This option is very important though, would be glad to have it enabled without delays =\

@vbjay Git-LFS is enabled for that repository (see 11G .git/lfs in my prev comment), not sure what you meant by ignoring it.

P.S. looks like this delay happens only when I open big repos and their submodules, nothing is freezing when I open small repos.

P.P.S GitExt 2.51.05 opens that repo with default settings without delay, it started to happen after update to 3.0

[vbjay]

Ignoring the 11GB you still have a 1GB .git folder. Now if it has a submodule or few then that is not surprising and reasonable.

…

On Mon, Feb 18, 2019, 2:04 PM Dmitriy [focus] Yukhanov < ***@***.***> wrote: Thanks @gerhardol <https://github.com/gerhardol> and @vbjay <https://github.com/vbjay> I found option which generated this huge delay: Show submodule status in browse menu [image: image] <https://user-images.githubusercontent.com/883587/52971467-a1a60a80-33c8-11e9-8f07-752448f1a0da.png> When I disable it - everything is loaded and initialized blazingly fast. When I turn it back - I get UI freeze back. This option is very important though, would be glad to have it enabled without delays =\ @vbjay <https://github.com/vbjay> Git-LFS is enabled for that repository (see 11G .git/lfs in my prev comment), not sure what you meant by ignoring it. P.S. looks like this delay happens only when I open big repos and their submodules, nothing is freezing when I open small repos. — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#6267 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/ADdhsQK31nIFnpCw_hfMvCkzAAD9-f6-ks5vOvlAgaJpZM4bBKRG> .

[DmitriyYukhanov]

Ah, yes it has about 10 submodules @vbjay

[gerhardol]

The submodule status is (supposed) to be collected in the background, the UI is not dependent on the status. There were a number of threading updates in 3.0 (to ba able to main the program) and there is some regression in this area.

Submodule status performance enhancements are tracked in #5769
There are some changes in master already, if there are no changes in submodules, the status will not be attempted. If this meets your usage pattern, please try the master builds.
I expect that #5569 is merged soon too, then the submodules are available in the left panel too.

[RussKie]

We do have some threading issues in submodules interrogation code paths, that are yet to be resolved.

[DmitriyYukhanov]

Thanks for quick replies guys, it's not a show stopper for me so I'll just keep updating to new official releases until it'll get in there.
And now, when I'm sure it's already on track, I'm closing this issue.

Cheers!

[gerhardol]

Please try the latest master with submodule updates (including in the left bar).
https://ci.appveyor.com/project/gitextensions/gitextensions/branch/master/artifacts

[DmitriyYukhanov]

Thanks @gerhardol but it does crashes on start for me:

[DmitriyYukhanov]

Also I do confirm this issue is fixed in the new version, yey! (I can proceed to use it when I close crash report dialog with X)

[RussKie]

but it does crashes on start for me

This error is tracked under #6093

[gerhardol]

@DmitriyYukhanov
Another note: In master (to be 3.1), the query for submodule status is only done if there are changes. I have seen occasional slowdowns also with master, but for some reason it it is not not consistent.

[DmitriyYukhanov]

@gerhardol thanks for this information!
I'll keep an eye and will report here anything related (no slowdowns on current repo for me anymore so far)

[RussKie]

There is also a certain perf degradation caused by the commit info panel (#6319).
Hopefully we can resolve most of these for the 3.1.0 release.

[gerhardol]

Some more about the slowdown in 3.x, not related to the sidepanel. When submodules start to update, the UI freezes if there are many submodules and you click around when the commit status finishes. (You can see when the Commit button changes from gray to something other than green,) There are many threads trying to find module.FilesEncoding which will require "git-rev-parse --git-common-dir".
Not sure if this a thread exhaustion or if the submodule provider is locking the UI thread.
Creation of GitModule could be improved, caching the git-rev-parse call or cache separately and provide when creating the GitModule.

[RussKie]

Gerhard could you please raise it as a new issue with your findings for us to investigate.

…

On Thu, Mar 7, 2019, 10:47 AM Gerhard Olsson ***@***.*** wrote: Some more about the slowdown in 3.x, not related to the sidepanel. When submodules start to update, the UI freezes if there are many submodules and you click around when the commit status finishes. (You can see when the Commit button changes from gray to something other than green,) There are many threads trying to find module.FilesEncoding which will require "git-rev-parse --git-common-dir". Not sure if this a thread exhaustion or if the submodule provider is locking the UI thread. Creation of GitModule could be improved, caching the git-rev-parse call or cache separately and provide when creating the GitModule. — You are receiving this because you commented. Reply to this email directly, view it on GitHub <#6267 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AEMyXqj-GQoV-8oQTph_bXYwCaITYjNjks5vUFN5gaJpZM4bBKRG> .

[gerhardol]

Opened #6357 for an alternative description of this problem