git diff being insanely slow

[shodanium]

• I was not able to find an open or closed issue matching what I'm seeing

Setup

• Which version of Git for Windows are you using? Is it 32-bit or 64-bit?

C:\>git --version --build-options
git version 2.21.0.windows.1
cpu: x86_64
built from commit: 2481c4cbe949856f270a3ee80c802f5dd89381aa
sizeof-long: 4
sizeof-size_t: 8

• Which version of Windows are you running? Vista, 7, 8, 10? Is it 32-bit or 64-bit?

$ cmd.exe /c ver
Microsoft Windows [Version 10.0.16299.1029]

• What options did you set as part of the installation? Or did you choose the
  defaults?

# One of the following:
> type "C:\Program Files\Git\etc\install-options.txt"
> type "C:\Program Files (x86)\Git\etc\install-options.txt"
> type "%USERPROFILE%\AppData\Local\Programs\Git\etc\install-options.txt"
C:\>type "C:\bin\Git\etc\install-options.txt"
Editor Option: Notepad++
Custom Editor Path:
Path Option: CmdTools
SSH Option: OpenSSH
CURL Option: OpenSSL
CRLF Option: CRLFCommitAsIs
Bash Terminal Option: MinTTY
Performance Tweaks FSCache: Enabled
Use Credential Manager: Enabled
Enable Symlinks: Enabled

• Any other interesting things about your environment that might be related
  to the issue you're seeing?

The environment is IMO rather bland. The issue is not related to antivirus (Windows Defender etc are all disabled).

Details

• Which terminal/shell are you running Git from? e.g Bash/CMD/PowerShell/other

cmd.exe and FAR, same situation in both cases

• What commands did you run to trigger this issue? If you can provide a
  Minimal, Complete, and Verifiable example
  this will help us understand the issue.

git diff

• What did you expect to occur after running these commands?

I expect a diff in less than 1 second (less than 0.1 second actually).

• What actually happened instead?

I get a diff but in 15-20 seconds. Immediately running "git diff" again would actually complete in 0.1 seconds or less. However, after a trivial amount of work in a different window (say, edit a source file a little and save it), git diff would be insanely slow again.

Z:\work\...\generator>timeit git diff
command took 0:0:15.74 (15.74s total)

Z:\work\...\generator>timeit c:\bin\git\bin\git.exe diff
command took 0:0:19.75 (19.75s total)

Z:\work\...\generator>timeit c:\bin\git\bin\git.exe diff
command took 0:0:16.21 (16.21s total)

Neither CPU nor disk activity is reported by Task Manager during that slowdown. 0-1% CPU usage, 0-1% disk activity. I would assume that "git diff" does NOT do any network activity, huh.

GIT_TRACE output exists, but is is less than useful:
Z:\work...\generator>timeit git diff
15:18:56.996500 exec-cmd.c:236 trace: resolved executable dir:
C:/Bin/Git/mingw64/bin
15:18:56.997001 git.c:419 trace: built-in: git diff
15:18:56.999006 run-command.c:643 trace: run_command: unset
GIT_PAGER_IN_USE; LESS=FRX LV=-c less
command took 0:0:15.51 (15.51s total)

ProcMon output indicates that git manages to scan the FS real quick, and
then just sits doing nothing (waiting for 4 threads, that in turn are
sitting doing nothing, to complete???) for about 15 seconds. The following is from ProcMon and the last column is TID:

3:00:35.4799875 PM	git.exe	7316	QueryOpen	Z:\work\...\structure.pp	SUCCESS	CreationTime: 3/12/2019 5:52:24 PM, LastAccessTime: 3/26/2019 1:52:27 PM, LastWriteTime: 3/26/2019 1:52:27 PM, ChangeTime: 3/26/2019 1:52:27 PM, AllocationSize: 4,096, EndOfFile: 2,593, FileAttributes: ANCI	12068
3:00:51.2974759 PM	git.exe	7316	Thread Exit		SUCCESS	Thread ID: 11572, User Time: 0.0000000, Kernel Time: 0.0000000	11572
3:00:51.2975934 PM	git.exe	7316	Thread Exit		SUCCESS	Thread ID: 8756, User Time: 0.0000000, Kernel Time: 0.0000000	8756
3:00:51.2976240 PM	git.exe	7316	Thread Exit		SUCCESS	Thread ID: 13400, User Time: 0.0000000, Kernel Time: 0.0000000	13400
3:00:51.2976519 PM	git.exe	7316	Thread Exit		SUCCESS	Thread ID: 10932, User Time: 0.0000000, Kernel Time: 0.0000000	10932
3:00:51.2976537 PM	git.exe	7316	RegCloseKey	HKCU\Software\Classes\Local Settings\Software\Microsoft	SUCCESS		12068
3:00:51.2976681 PM	git.exe	7316	RegCloseKey	HKCU\Software\Classes\Local Settings	SUCCESS		12068
3:00:51.2976963 PM	git.exe	7316	RegCloseKey	HKLM\SOFTWARE\Microsoft\Ole	SUCCESS		12068
3:00:51.2977062 PM	git.exe	7316	RegCloseKey	HKLM	SUCCESS		12068
3:00:51.2978077 PM	git.exe	7316	RegOpenKey	HKLM\Software\Microsoft\Windows NT\CurrentVersion\GRE_Initialize	SUCCESS	Desired Access: Read	12068
3:00:51.2978293 PM	git.exe	7316	RegQueryValue	HKLM\SOFTWARE\Microsoft\Windows NT\CurrentVersion\GRE_Initialize\DisableMetaFiles	NAME NOT FOUND	Length: 20	12068
3:00:51.2978444 PM	git.exe	7316	RegCloseKey	HKLM\SOFTWARE\Microsoft\Windows NT\CurrentVersion\GRE_Initialize	SUCCESS		12068
3:00:51.2979467 PM	git.exe	7316	Thread Exit		SUCCESS	Thread ID: 12068, User Time: 0.0000000, Kernel Time: 0.0781250	12068
3:00:51.2993663 PM	git.exe	7316	QueryNameInformationFile	C:\Bin\Git\mingw64\bin\libintl-8.dll	SUCCESS	Name: \Bin\Git\mingw64\bin\libintl-8.dll	12068

• If the problem was occurring with a specific repository, can you provide the
  URL to that repository to help us with testing?

Nope, private work repo. Seeing this issue with different repos though.

Also, all my attempts to post to mailing list failed for some reason.

[dscho]

GIT_TRACE output exists, but is is less than useful

Probably GIT_TRACE_PERFORMANCE will be more helpful.

On a hunch, I would say that maybe git -P diff would be faster? If so, then you are probably observing the startup cost of the MSYS2 runtime that is a consequence of the pager (less.exe) being an MSYS2 program.

Nope, private work repo. Seeing this issue with different repos though.

As a rule of thumb, if your work repository is private, don't even mention it, but try to reproduce the problem in a minimal (or toy) repository.

For example, if you see the same issue in a repository that you just created via

git init test-dir
cd test-dir
echo Hello >world.txt
git add world.txt
git commit -m initial
echo world >world.txt
git diff

then it would be a good idea to mention that.

Also, all my attempts to post to mailing list failed for some reason.

Probably your mailer insists on adding an HTML part, which the Git mailing list flatly rejects.

[shodanium]

Probably GIT_TRACE_PERFORMANCE will be more helpful.

On a hunch, I would say that maybe git -P diff would be faster?

Thank you. I will try all that the next time the issue manifests. In the meantime, got back from traveling, and back to a somewhat better Internet connection(s) => and suddenly, the issue seems to be gone! At least, it did not manifest in the last several days. Also, I think it did not happen while working on the flight, with network off.

So on a counter-hunch, this looks veeery much like running "git diff" does, rather unexpectedly to my taste, some (shady) network-related requests. Which are only occasionally slow on my "regular" connections (I occasionally see this problem on "regular" connections too), but were always very slow while traveling, but were getting cached for a very small while.

Any pointers as to how I can debug those the next time? :)

Re repos, also duly noted, and next time I will try other repos. I strongly suspect that using pretty much any repo would trigger the problem, just did not have enough time (and bandwidth!) to fiddle more, clone a moderately big one, and/or create a trivial one.

[shodanium]

Oh, there and was another bit that I just remembered. Just in case, maybe this could help to narrow it down.

"git status" either did not have the issue at all, or very very rarely.

"git diff" and "git log" had. Even immediately after a quick enough "git status" they would be slow.

Network activity from MSYS in some cases, perchance?

[dscho]

Any pointers as to how I can debug those the next time? :)

Yes. The culprit is most likely in the startup of the MSYS2 runtime (which less.exe uses to emulate a POSIX system). I also got the hunch that the MSYS2 runtime tries to contact the domain controller upon startup, for some information that we actually do not need at all...

"git status" either did not have the issue at all, or very very rarely.

git status does not run the pager. Hence no MSYS2 runtime involved.

[shodanium]

The issue manifested a couple times again today, and git -P seemed to help.

Pinging the domain controller is definitely very possible as all the manifestations only seem to happen when I'm on a VPN connection to work.

Anything that can be done about MSYS2 startup in this particular case? :)

[jordanbrowneb]

Wanted to bump this issue. Our office is experiencing the same intermittent slowdowns with git diff. Any thoughts on a workaround?

[PhilipOakley]

@jordanbrowneb I'm not sure anyone is working on this.

Can you give more details of your setup and testing? Can you make the issue repeatable? do all PCs suffer, or just some?

What is the same/different about those that suffer from those that don't? VPNs and Proxies?

Do you have timing statistics, does it depend on the file that is being diff'd. Have all the machines been 'g'cd, and repacked?

Has any network sniffing been done to see if there are indications there?

Better clues are needed from those that are at the scene of the crime ;-)

@shodanium - any news from your systems?

[shodanium]

Yes, git -P helps.

[dscho]

It could be potentially helpful to have a ProcMon dump of such a slow run.

[dscho]

Closing this as stale.