search

git-ecosystem / git-credential-manager

Secure, cross-platform Git credential storage with authentication to GitHub, Azure Repos, and other popular Git hosting services.
Other
5.97k stars 1.62k forks source link

extremely slow: 6 seconds every git operation minimum - checking for sslCAInfo and cookieFile #1620

Open MaurGi opened 1 month ago

MaurGi commented 1 month ago

Version

2.5.0+d34930736e131ad80e5690e5634ced1808aff3e2

Operating system

Other - please describe below

OS version or distribution

wsl --version: WSL version: 2.1.5.0 Kernel version: 5.15.146.1-2 WSLg version: 1.0.60 MSRDC version: 1.2.5105 Direct3D version: 1.611.1-81528511 DXCore version: 10.0.25131.1002-220531-1700.rs-onecore-base2-hyp Windows version: 10.0.22631.3593

Git hosting provider(s)

Azure DevOps

Other hosting provider

No response

(Azure DevOps only) What format is your remote URL?

https://dev.azure.com/{org}

Can you access the remote repository directly in the browser?

Yes, I can access the repository

Expected behavior

git fetch and pull with no changes should be around one second. they are taking 5 to 6 seconds every time

Actual behavior

$ time git fetch                                                          
git fetch  0.05s user 0.01s system 1% cpu 5.732 total
$ time git fetch
git fetch  0.06s user 0.00s system 1% cpu 5.760 total
$ time git fetch
git fetch  0.06s user 0.00s system 1% cpu 5.720 total

Logs

$ time WSLENV=$WSLENV:GCM_TRACE:GIT_TRACE GCM_TRACE=1 GIT_TRACE=1 git fetch
17:42:55.640533 git.c:455               trace: built-in: git fetch
17:42:55.641105 run-command.c:668       trace: run_command: GIT_DIR=.git git remote-https origin https://dev.azure.com/msazure/CloudNativeCompute/_git/aks-region-config
17:42:55.642257 git.c:742               trace: exec: git-remote-https origin https://dev.azure.com/msazure/CloudNativeCompute/_git/aks-region-config
17:42:55.642327 run-command.c:668       trace: run_command: git-remote-https origin https://dev.azure.com/msazure/CloudNativeCompute/_git/aks-region-config
17:42:55.700910 run-command.c:668       trace: run_command: '/mnt/c/Program\ Files/Git/mingw64/bin/git-credential-manager.exe get'
10:42:55.872236 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:42:55.933477 git.c:465               trace: built-in: git config --null --list
10:42:56.021713 ...\Application.cs:106  trace: [RunInternalAsync] Version: 2.5.0.0
10:42:56.021713 ...\Application.cs:107  trace: [RunInternalAsync] Runtime: .NET Framework 4.8.9241.0
10:42:56.021713 ...\Application.cs:108  trace: [RunInternalAsync] Platform: Windows (x86-64)
10:42:56.021713 ...\Application.cs:109  trace: [RunInternalAsync] OSVersion: 10.0 (build 22631)
10:42:56.021713 ...\Application.cs:110  trace: [RunInternalAsync] AppPath: C:\Program Files\Git\mingw64\bin\git-credential-manager.exe
10:42:56.021713 ...\Application.cs:111  trace: [RunInternalAsync] InstallDir: C:\Program Files\Git\mingw64\bin\
10:42:56.021713 ...\Application.cs:112  trace: [RunInternalAsync] Arguments: get
10:42:56.061773 ...GitCommandBase.cs:32 trace: [ExecuteAsync] Start 'get' command...
10:42:56.071164 ...GitCommandBase.cs:46 trace: [ExecuteAsync] Detecting host provider for input:
10:42:56.072837 ...GitCommandBase.cs:47 trace: [ExecuteAsync]   protocol=https
10:42:56.072837 ...GitCommandBase.cs:47 trace: [ExecuteAsync]   host=dev.azure.com
10:42:56.072898 ...GitCommandBase.cs:47 trace: [ExecuteAsync]   path=msazure/CloudNativeCompute/_git/aks-region-config
10:42:56.077196 ...viderRegistry.cs:149 trace: [GetProviderAsync] Performing auto-detection of host provider.
10:42:56.077196 ...viderRegistry.cs:162 trace: [GetProviderAsync] Auto-detect probe timeout is 2 ms.
10:42:56.078315 ...viderRegistry.cs:170 trace: [GetProviderAsync] Checking against 4 host providers registered with priority 'Normal'.
10:42:56.079424 ...GitCommandBase.cs:49 trace: [ExecuteAsync] Host provider 'Azure Repos' was selected.
10:42:56.084940 ...sHostProvider.cs:272 trace: [GetAzureAccessTokenAsync] Determining Microsoft Authentication authority for Azure DevOps organization 'msazure'...
10:42:56.086594 ...AuthorityCache.cs:57 trace: [GetAuthority] Looking up cached authority for organization 'msazure'...
10:42:56.114710 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:42:56.137614 git.c:465               trace: built-in: git version
10:42:56.171520 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:42:56.231503 git.c:465               trace: built-in: git config --null --global credential.azrepos:org/msazure.azureAuthority
10:42:56.236016 ...sHostProvider.cs:290 trace: [GetAzureAccessTokenAsync] Authority was found in cache.
10:42:56.236016 ...sHostProvider.cs:294 trace: [GetAzureAccessTokenAsync] Authority is 'https://login.microsoftonline.com/72f988bf-86f1-41af-91ab-2d7cd011db47'.
10:42:56.236016 ...sHostProvider.cs:316 trace: [GetAzureAccessTokenAsync] Looking up user for organization 'msazure'...
10:42:56.236016 ...BindingManager.cs:94 trace: [GetBinding] Looking up organization binding for 'msazure'...
10:42:56.343385 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:42:56.401875 git.c:465               trace: built-in: git config --null --global credential.azrepos:org/msazure.username
10:42:56.405876 ...sHostProvider.cs:320 trace: [GetAzureAccessTokenAsync] User is 'maurgi@microsoft.com'.
10:42:56.405876 ...sHostProvider.cs:323 trace: [GetAzureAccessTokenAsync] Getting Azure AD access token...
10:42:56.413970 ...uthentication.cs:132 trace: [GetTokenForUserAsync] OS broker is available and enabled.
10:42:56.414969 ...uthentication.cs:138 trace: [GetTokenForUserAsync] MSA passthrough is enabled.
10:42:56.424982 ...uthentication.cs:493 trace: [CreatePublicClientApplicationAsync] Using progress parent window for MSAL authentication dialogs.
10:42:56.449956 ...uthentication.cs:562 trace: [RegisterTokenCacheAsync] Configuring MSAL token cache...
10:42:56.481736 ...uthentication.cs:617 trace: [RegisterTokenCacheAsync] Token cache configured.
10:42:56.483737 ...uthentication.cs:410 trace: [GetAccessTokenSilentlyAsync] Attempting to acquire token silently for user 'maurgi@microsoft.com'...
10:42:56.758777 ...pClientFactory.cs:60 trace: [CreateClient] Creating new HTTP client instance...
10:42:56.775563 ...pClientFactory.cs:80 trace: [CreateClient] Git's SSL/TLS backend is: OpenSsl
10:42:56.810160 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:42:56.865553 git.c:465               trace: built-in: git config --null --type=path http.https://dev.azure.com/msazure/CloudNativeCompute/_git/aks-region-config.sslCAInfo
10:42:56.898822 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:42:56.953312 git.c:465               trace: built-in: git config --null --type=path http.dev.azure.com/msazure/CloudNativeCompute/_git/aks-region-config.sslCAInfo
10:42:56.988381 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:42:57.046204 git.c:465               trace: built-in: git config --null --type=path http.https://dev.azure.com/msazure/CloudNativeCompute/_git.sslCAInfo
10:42:57.079589 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:42:57.136656 git.c:465               trace: built-in: git config --null --type=path http.dev.azure.com/msazure/CloudNativeCompute/_git.sslCAInfo
10:42:57.169437 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:42:57.226694 git.c:465               trace: built-in: git config --null --type=path http.https://dev.azure.com/msazure/CloudNativeCompute.sslCAInfo
10:42:57.258580 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:42:57.315282 git.c:465               trace: built-in: git config --null --type=path http.dev.azure.com/msazure/CloudNativeCompute.sslCAInfo
10:42:57.348316 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:42:57.406116 git.c:465               trace: built-in: git config --null --type=path http.https://dev.azure.com/msazure.sslCAInfo
10:42:57.440363 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:42:57.496946 git.c:465               trace: built-in: git config --null --type=path http.dev.azure.com/msazure.sslCAInfo
10:42:57.528571 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:42:57.583375 git.c:465               trace: built-in: git config --null --type=path http.https://dev.azure.com.sslCAInfo
10:42:57.615584 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:42:57.669731 git.c:465               trace: built-in: git config --null --type=path http.dev.azure.com.sslCAInfo
10:42:57.707146 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:42:57.760439 git.c:465               trace: built-in: git config --null --type=path http.https://azure.com.sslCAInfo
10:42:57.792746 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:42:57.840539 git.c:465               trace: built-in: git config --null --type=path http.azure.com.sslCAInfo
10:42:57.872708 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:42:57.921833 git.c:465               trace: built-in: git config --null --type=path http.sslCAInfo
10:42:57.953489 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:42:58.011152 git.c:465               trace: built-in: git config --null --type=path http.https://dev.azure.com/msazure/CloudNativeCompute/_git/aks-region-config.sslCAInfo
10:42:58.042353 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:42:58.098705 git.c:465               trace: built-in: git config --null --type=path http.dev.azure.com/msazure/CloudNativeCompute/_git/aks-region-config.sslCAInfo
10:42:58.129050 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:42:58.187777 git.c:465               trace: built-in: git config --null --type=path http.https://dev.azure.com/msazure/CloudNativeCompute/_git.sslCAInfo
10:42:58.218706 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:42:58.281029 git.c:465               trace: built-in: git config --null --type=path http.dev.azure.com/msazure/CloudNativeCompute/_git.sslCAInfo
10:42:58.313817 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:42:58.372840 git.c:465               trace: built-in: git config --null --type=path http.https://dev.azure.com/msazure/CloudNativeCompute.sslCAInfo
10:42:58.408790 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:42:58.465214 git.c:465               trace: built-in: git config --null --type=path http.dev.azure.com/msazure/CloudNativeCompute.sslCAInfo
10:42:58.498360 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:42:58.554652 git.c:465               trace: built-in: git config --null --type=path http.https://dev.azure.com/msazure.sslCAInfo
10:42:58.585942 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:42:58.636254 git.c:465               trace: built-in: git config --null --type=path http.dev.azure.com/msazure.sslCAInfo
10:42:58.667048 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:42:58.728365 git.c:465               trace: built-in: git config --null --type=path http.https://dev.azure.com.sslCAInfo
10:42:58.759200 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:42:58.815065 git.c:465               trace: built-in: git config --null --type=path http.dev.azure.com.sslCAInfo
10:42:58.847130 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:42:58.899863 git.c:465               trace: built-in: git config --null --type=path http.https://azure.com.sslCAInfo
10:42:58.932993 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:42:58.987810 git.c:465               trace: built-in: git config --null --type=path http.azure.com.sslCAInfo
10:42:59.019607 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:42:59.071962 git.c:465               trace: built-in: git config --null --type=path http.sslCAInfo
10:42:59.075956 ...ClientFactory.cs:113 trace: [CreateClient] Custom certificate verification has been enabled with certificate bundle at C:/Program Files/Git/mingw64/etc/ssl/certs/ca-bundle.crt
10:42:59.104197 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:42:59.153545 git.c:465               trace: built-in: git config --null --type=path http.https://dev.azure.com/msazure/CloudNativeCompute/_git/aks-region-config.cookieFile
10:42:59.184859 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:42:59.236764 git.c:465               trace: built-in: git config --null --type=path http.dev.azure.com/msazure/CloudNativeCompute/_git/aks-region-config.cookieFile
10:42:59.271281 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:42:59.328321 git.c:465               trace: built-in: git config --null --type=path http.https://dev.azure.com/msazure/CloudNativeCompute/_git.cookieFile
10:42:59.360703 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:42:59.419174 git.c:465               trace: built-in: git config --null --type=path http.dev.azure.com/msazure/CloudNativeCompute/_git.cookieFile
10:42:59.451128 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:42:59.508742 git.c:465               trace: built-in: git config --null --type=path http.https://dev.azure.com/msazure/CloudNativeCompute.cookieFile
10:42:59.540065 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:42:59.598455 git.c:465               trace: built-in: git config --null --type=path http.dev.azure.com/msazure/CloudNativeCompute.cookieFile
10:42:59.630236 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:42:59.680474 git.c:465               trace: built-in: git config --null --type=path http.https://dev.azure.com/msazure.cookieFile
10:42:59.711875 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:42:59.774479 git.c:465               trace: built-in: git config --null --type=path http.dev.azure.com/msazure.cookieFile
10:42:59.807077 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:42:59.864751 git.c:465               trace: built-in: git config --null --type=path http.https://dev.azure.com.cookieFile
10:42:59.897618 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:42:59.954314 git.c:465               trace: built-in: git config --null --type=path http.dev.azure.com.cookieFile
10:42:59.986352 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:43:00.048046 git.c:465               trace: built-in: git config --null --type=path http.https://azure.com.cookieFile
10:43:00.082049 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:43:00.142852 git.c:465               trace: built-in: git config --null --type=path http.azure.com.cookieFile
10:43:00.175964 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:43:00.232961 git.c:465               trace: built-in: git config --null --type=path http.cookieFile
10:43:00.653728 ...sHostProvider.cs:331 trace: [GetAzureAccessTokenAsync] Acquired Azure access token. Account='maurgi@microsoft.com' Token='********'
10:43:00.654728 ...\GetCommand.cs:39    trace: [ExecuteInternalAsync] Writing credentials to output:
10:43:00.654728 ...\GetCommand.cs:40    trace: [ExecuteInternalAsync]   protocol=https
10:43:00.654728 ...\GetCommand.cs:40    trace: [ExecuteInternalAsync]   host=dev.azure.com
10:43:00.654728 ...\GetCommand.cs:40    trace: [ExecuteInternalAsync]   path=msazure/CloudNativeCompute/_git/aks-region-config
10:43:00.654728 ...\GetCommand.cs:40    trace: [ExecuteInternalAsync]   username=maurgi@microsoft.com
10:43:00.654728 ...\GetCommand.cs:40    trace: [ExecuteInternalAsync]   password=********
10:43:00.654728 ...GitCommandBase.cs:53 trace: [ExecuteAsync] End 'get' command...
17:43:00.723861 run-command.c:668       trace: run_command: '/mnt/c/Program\ Files/Git/mingw64/bin/git-credential-manager.exe store'
10:43:00.865837 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:43:00.921663 git.c:465               trace: built-in: git config --null --list
10:43:01.013658 ...\Application.cs:106  trace: [RunInternalAsync] Version: 2.5.0.0
10:43:01.013658 ...\Application.cs:107  trace: [RunInternalAsync] Runtime: .NET Framework 4.8.9241.0
10:43:01.013658 ...\Application.cs:108  trace: [RunInternalAsync] Platform: Windows (x86-64)
10:43:01.013658 ...\Application.cs:109  trace: [RunInternalAsync] OSVersion: 10.0 (build 22631)
10:43:01.013658 ...\Application.cs:110  trace: [RunInternalAsync] AppPath: C:\Program Files\Git\mingw64\bin\git-credential-manager.exe
10:43:01.013658 ...\Application.cs:111  trace: [RunInternalAsync] InstallDir: C:\Program Files\Git\mingw64\bin\
10:43:01.013658 ...\Application.cs:112  trace: [RunInternalAsync] Arguments: store
10:43:01.056404 ...GitCommandBase.cs:32 trace: [ExecuteAsync] Start 'store' command...
10:43:01.066317 ...GitCommandBase.cs:46 trace: [ExecuteAsync] Detecting host provider for input:
10:43:01.067787 ...GitCommandBase.cs:47 trace: [ExecuteAsync]   protocol=https
10:43:01.067787 ...GitCommandBase.cs:47 trace: [ExecuteAsync]   host=dev.azure.com
10:43:01.067787 ...GitCommandBase.cs:47 trace: [ExecuteAsync]   path=msazure/CloudNativeCompute/_git/aks-region-config
10:43:01.067787 ...GitCommandBase.cs:47 trace: [ExecuteAsync]   username=maurgi@microsoft.com
10:43:01.067787 ...GitCommandBase.cs:47 trace: [ExecuteAsync]   password=********
10:43:01.072343 ...viderRegistry.cs:149 trace: [GetProviderAsync] Performing auto-detection of host provider.
10:43:01.072343 ...viderRegistry.cs:162 trace: [GetProviderAsync] Auto-detect probe timeout is 2 ms.
10:43:01.073346 ...viderRegistry.cs:170 trace: [GetProviderAsync] Checking against 4 host providers registered with priority 'Normal'.
10:43:01.074737 ...GitCommandBase.cs:49 trace: [ExecuteAsync] Host provider 'Azure Repos' was selected.
10:43:01.077292 ...sHostProvider.cs:155 trace: [StoreCredentialAsync] Signing user maurgi@microsoft.com in to organization 'msazure'...
10:43:01.077292 ...BindingManager.cs:94 trace: [GetBinding] Looking up organization binding for 'msazure'...
10:43:01.187097 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:43:01.204029 git.c:465               trace: built-in: git version
10:43:01.237405 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:43:01.295132 git.c:465               trace: built-in: git config --null --global credential.azrepos:org/msazure.username
10:43:01.300150 ...indingManager.cs:140 trace: [Bind] Binding user 'maurgi@microsoft.com' to organization 'msazure' in global configuration...
10:43:01.327500 exec-cmd.c:243          trace: resolved executable dir: C:/Program Files/Git/mingw64/bin
10:43:01.384150 git.c:465               trace: built-in: git config --global credential.azrepos:org/msazure.username maurgi@microsoft.com
10:43:01.390151 ...indingManager.cs:155 trace: [Unbind] Unbinding organization 'msazure' in local repository...
10:43:01.467541 ...indingManager.cs:162 trace: [Unbind] Cannot set local configuration binding - not inside a repository!
10:43:01.467541 ...GitCommandBase.cs:53 trace: [ExecuteAsync] End 'store' command...
17:43:01.478959 run-command.c:668       trace: run_command: git rev-list --objects --stdin --not --all --quiet --alternate-refs
17:43:01.485771 run-command.c:1597      run_processes_parallel: preparing to run up to 1 tasks
17:43:01.485837 run-command.c:1629      run_processes_parallel: done
17:43:01.485880 run-command.c:668       trace: run_command: git maintenance run --auto --no-quiet
17:43:01.487382 git.c:455               trace: built-in: git maintenance run --auto --no-quiet
WSLENV=$WSLENV:GCM_TRACE:GIT_TRACE GCM_TRACE=1 GIT_TRACE=1 git fetch  0.04s user 0.02s system 1% cpu 5.849 total
MaurGi commented 1 month ago

any help here? why is it looking at all those paths every time and not reusing the creds?

mjcheetham commented 1 month ago

why is it looking at all those paths every time and not reusing the creds?

The cookie files are read via repeated calls to git config so we can take advantage of the path expansion and complicated conditional config inclusion handling that is possible.

MaurGi commented 1 month ago

this happens on my machine - my team members do not experience the same - different configs with Mac and Linux as well

MaurGi commented 3 weeks ago

any way to avoid this loop @mjcheetham ?