search

git-for-windows / git

A fork of Git containing Windows-specific patches.
http://gitforwindows.org/
Other
8.36k stars 2.53k forks source link

git diff being insanely slow #2151

Closed shodanium closed 3 years ago

shodanium commented 5 years ago

Setup

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
$ cmd.exe /c ver
Microsoft Windows [Version 10.0.16299.1029]
# 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

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

Details

cmd.exe and FAR, same situation in both cases

git diff

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

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

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 commented 5 years ago

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 commented 5 years ago

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 commented 5 years ago

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 commented 5 years ago

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 commented 5 years ago

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 commented 5 years ago

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

PhilipOakley commented 5 years ago

@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 commented 5 years ago

Yes, git -P helps.

dscho commented 5 years ago

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

dscho commented 3 years ago

Closing this as stale.