Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Auth failure in Win10/Cygwin environment, Cygwin bash shell #509

Closed
2 of 9 tasks
bakoontz2 opened this issue Oct 29, 2021 · 18 comments
Closed
2 of 9 tasks

Auth failure in Win10/Cygwin environment, Cygwin bash shell #509

bakoontz2 opened this issue Oct 29, 2021 · 18 comments
Labels
auth-issue An issue authenticating to a host

Comments

@bakoontz2
Copy link

bakoontz2 commented Oct 29, 2021

GCM 2.0.567

From a terminal, run git-credential-manager-core --version and paste the output.

2.0.567+3047faf390

Which Git host provider are you trying to connect to?

  • Azure DevOps
  • Azure DevOps Server (TFS/on-prem)
  • GitHub
  • GitHub Enterprise
  • Bitbucket
  • Other - please describe

Can you access the remote repository directly in the browser using the remote URL? Yes

From a terminal, run git remote -v to see your remote URL.

$ git remote -v
origin  https://github.com/<redacted>.git (fetch)
origin  https://github.com/<redacted>.git (push)
  • Yes
  • No, I get a permission error
  • No, for a different reason - please describe

Expected behavior

I am authenticated and my Git operation completes successfully.

Actual behavior

Authentication fails; falls back to username/PAT authentication (which is successful). New git credential observed in WCM; subsequent authentication attempts fail with fallback to username/PAT authentication (which is successful).

Logs

Set the environment variables GCM_TRACE=1 and GIT_TRACE=1 and re-run your Git command. Review and redact any private information and attach the log.

***Initial authentication attempt***
08:55:25.778101 ...pplicationBase.cs:75 trace: [RunAsync] Tracing of secrets is enabled. Trace output may contain sensitive information.
08:55:25.807023 ...\Application.cs:95   trace: [RunInternalAsync] Version: 2.0.567.18224
08:55:25.807023 ...\Application.cs:96   trace: [RunInternalAsync] Runtime: .NET Framework 4.0.30319.42000
08:55:25.807023 ...\Application.cs:97   trace: [RunInternalAsync] Platform: Windows (x86-64)
08:55:25.807023 ...\Application.cs:98   trace: [RunInternalAsync] OSVersion: 10.0 (build 17763)
08:55:25.807023 ...\Application.cs:99   trace: [RunInternalAsync] AppPath: C:\cygwin64\usr\libexec\git-core\git-credential-manager-core.exe
08:55:25.807023 ...\Application.cs:100  trace: [RunInternalAsync] Arguments: get
08:55:25.887808 ...GitCommandBase.cs:33 trace: [ExecuteAsync] Start 'get' command...
08:55:25.898778 ...GitCommandBase.cs:47 trace: [ExecuteAsync] Detecting host provider for input:
08:55:25.899814 ...GitCommandBase.cs:48 trace: [ExecuteAsync]   protocol=https
08:55:25.899814 ...GitCommandBase.cs:48 trace: [ExecuteAsync]   host=github.com
08:55:26.147796 ...viderRegistry.cs:147 trace: [GetProviderAsync] Performing auto-detection of host provider.
08:55:26.248527 ...viderRegistry.cs:152 trace: [GetProviderAsync] Auto-detect probe timeout is 2 ms.
08:55:26.250522 ...viderRegistry.cs:160 trace: [GetProviderAsync] Checking against 3 host providers registered with priority 'Normal'.
08:55:26.252518 ...GitCommandBase.cs:50 trace: [ExecuteAsync] Host provider 'GitHub' was selected.
08:55:26.255510 ...\HostProvider.cs:126 trace: [GetCredentialAsync] Looking for existing credential in store with service=https://github.com account=...
08:55:26.520918 ...\HostProvider.cs:131 trace: [GetCredentialAsync] No existing credentials found.
08:55:26.521915 ...\HostProvider.cs:134 trace: [GetCredentialAsync] Creating new credential...
08:55:26.649141 ...bHostProvider.cs:242 trace: [GetSupportedAuthenticationModesAsync] Supported authentication modes override present: Pat
08:55:26.767963 ...enticationBase.cs:42 trace: [InvokeHelperAsync] Starting helper process: C:\cygwin64\usr\libexec\git-core\GitHub.UI.exe prompt --pat
08:55:31.072548 ...\GitHubRestApi.cs:95 trace: [GetUserInfoAsync] HTTP: GET https://api.github.com/user
08:55:31.086480 ...pClientFactory.cs:58 trace: [CreateClient] Creating new HTTP client instance...
08:55:32.068624 ...GitHubRestApi.cs:102 trace: [GetUserInfoAsync] HTTP: Response 200 [OK]
08:55:32.212237 ...\HostProvider.cs:136 trace: [GetCredentialAsync] Credential created.
08:55:32.212237 ...GitCommandBase.cs:54 trace: [ExecuteAsync] End 'get' command...
08:55:40.965463 ...pplicationBase.cs:75 trace: [RunAsync] Tracing of secrets is enabled. Trace output may contain sensitive information.
08:55:40.981420 ...\Application.cs:95   trace: [RunInternalAsync] Version: 2.0.567.18224
08:55:40.981420 ...\Application.cs:96   trace: [RunInternalAsync] Runtime: .NET Framework 4.0.30319.42000
08:55:40.981420 ...\Application.cs:97   trace: [RunInternalAsync] Platform: Windows (x86-64)
08:55:40.981420 ...\Application.cs:98   trace: [RunInternalAsync] OSVersion: 10.0 (build 17763)
08:55:40.981420 ...\Application.cs:99   trace: [RunInternalAsync] AppPath: C:\cygwin64\usr\libexec\git-core\git-credential-manager-core.exe
08:55:40.981420 ...\Application.cs:100  trace: [RunInternalAsync] Arguments: store
08:55:41.043258 ...GitCommandBase.cs:33 trace: [ExecuteAsync] Start 'store' command...
08:55:41.054227 ...GitCommandBase.cs:47 trace: [ExecuteAsync] Detecting host provider for input:
08:55:41.056221 ...GitCommandBase.cs:48 trace: [ExecuteAsync]   protocol=https
08:55:41.056221 ...GitCommandBase.cs:48 trace: [ExecuteAsync]   host=github.com
08:55:41.056221 ...GitCommandBase.cs:48 trace: [ExecuteAsync]   username=<redacted>
08:55:41.056221 ...GitCommandBase.cs:48 trace: [ExecuteAsync]   password=<redacted>
08:55:41.274710 ...viderRegistry.cs:147 trace: [GetProviderAsync] Performing auto-detection of host provider.
08:55:41.397193 ...viderRegistry.cs:152 trace: [GetProviderAsync] Auto-detect probe timeout is 2 ms.
08:55:41.399190 ...viderRegistry.cs:160 trace: [GetProviderAsync] Checking against 3 host providers registered with priority 'Normal'.
08:55:41.401183 ...GitCommandBase.cs:50 trace: [ExecuteAsync] Host provider 'GitHub' was selected.
08:55:41.402182 ...\HostProvider.cs:160 trace: [StoreCredentialAsync] Storing credential with service=https://github.com account=<redacted>...
08:55:41.665200 ...\HostProvider.cs:162 trace: [StoreCredentialAsync] Credential was successfully stored.
08:55:41.665200 ...GitCommandBase.cs:54 trace: [ExecuteAsync] End 'store' command...
***Subsequent authentication attempt***
08:58:04.772064 ...pplicationBase.cs:75 trace: [RunAsync] Tracing of secrets is enabled. Trace output may contain sensitive information.
08:58:04.788023 ...\Application.cs:95   trace: [RunInternalAsync] Version: 2.0.567.18224
08:58:04.788023 ...\Application.cs:96   trace: [RunInternalAsync] Runtime: .NET Framework 4.0.30319.42000
08:58:04.788023 ...\Application.cs:97   trace: [RunInternalAsync] Platform: Windows (x86-64)
08:58:04.788023 ...\Application.cs:98   trace: [RunInternalAsync] OSVersion: 10.0 (build 17763)
08:58:04.788023 ...\Application.cs:99   trace: [RunInternalAsync] AppPath: C:\cygwin64\usr\libexec\git-core\git-credential-manager-core.exe
08:58:04.788023 ...\Application.cs:100  trace: [RunInternalAsync] Arguments: get
08:58:04.851851 ...GitCommandBase.cs:33 trace: [ExecuteAsync] Start 'get' command...
08:58:04.864817 ...GitCommandBase.cs:47 trace: [ExecuteAsync] Detecting host provider for input:
08:58:04.866812 ...GitCommandBase.cs:48 trace: [ExecuteAsync]   protocol=https
08:58:04.866812 ...GitCommandBase.cs:48 trace: [ExecuteAsync]   host=github.com
08:58:05.092208 ...viderRegistry.cs:147 trace: [GetProviderAsync] Performing auto-detection of host provider.
08:58:05.213933 ...viderRegistry.cs:152 trace: [GetProviderAsync] Auto-detect probe timeout is 2 ms.
08:58:05.215928 ...viderRegistry.cs:160 trace: [GetProviderAsync] Checking against 3 host providers registered with priority 'Normal'.
08:58:05.216926 ...GitCommandBase.cs:50 trace: [ExecuteAsync] Host provider 'GitHub' was selected.
08:58:05.220915 ...\HostProvider.cs:126 trace: [GetCredentialAsync] Looking for existing credential in store with service=https://github.com account=...
08:58:05.425640 ...\HostProvider.cs:140 trace: [GetCredentialAsync] Existing credential found.
08:58:05.426634 ...GitCommandBase.cs:54 trace: [ExecuteAsync] End 'get' command...
08:58:16.376125 ...pplicationBase.cs:75 trace: [RunAsync] Tracing of secrets is enabled. Trace output may contain sensitive information.
08:58:16.392116 ...\Application.cs:95   trace: [RunInternalAsync] Version: 2.0.567.18224
08:58:16.392116 ...\Application.cs:96   trace: [RunInternalAsync] Runtime: .NET Framework 4.0.30319.42000
08:58:16.392116 ...\Application.cs:97   trace: [RunInternalAsync] Platform: Windows (x86-64)
08:58:16.392116 ...\Application.cs:98   trace: [RunInternalAsync] OSVersion: 10.0 (build 17763)
08:58:16.392116 ...\Application.cs:99   trace: [RunInternalAsync] AppPath: C:\cygwin64\usr\libexec\git-core\git-credential-manager-core.exe
08:58:16.392116 ...\Application.cs:100  trace: [RunInternalAsync] Arguments: store
08:58:16.452955 ...GitCommandBase.cs:33 trace: [ExecuteAsync] Start 'store' command...
08:58:16.464885 ...GitCommandBase.cs:47 trace: [ExecuteAsync] Detecting host provider for input:
08:58:16.466911 ...GitCommandBase.cs:48 trace: [ExecuteAsync]   protocol=https
08:58:16.466911 ...GitCommandBase.cs:48 trace: [ExecuteAsync]   host=github.com
08:58:16.466911 ...GitCommandBase.cs:48 trace: [ExecuteAsync]   username=<redacted>
08:58:16.466911 ...GitCommandBase.cs:48 trace: [ExecuteAsync]   password=<redacted>
08:58:16.719000 ...viderRegistry.cs:147 trace: [GetProviderAsync] Performing auto-detection of host provider.
08:58:16.839199 ...viderRegistry.cs:152 trace: [GetProviderAsync] Auto-detect probe timeout is 2 ms.
08:58:16.841220 ...viderRegistry.cs:160 trace: [GetProviderAsync] Checking against 3 host providers registered with priority 'Normal'.
08:58:16.843215 ...GitCommandBase.cs:50 trace: [ExecuteAsync] Host provider 'GitHub' was selected.
08:58:16.844187 ...\HostProvider.cs:160 trace: [StoreCredentialAsync] Storing credential with service=https://github.com account=<redacted>...
08:58:17.100741 ...\HostProvider.cs:162 trace: [StoreCredentialAsync] Credential was successfully stored.
08:58:17.100741 ...GitCommandBase.cs:54 trace: [ExecuteAsync] End 'store' command...
@bakoontz2 bakoontz2 added the auth-issue An issue authenticating to a host label Oct 29, 2021
@mjcheetham
Copy link
Collaborator

Hello @bakoontz2,

Authentication fails; falls back to username/PAT authentication (which is successful). New git credential observed in WCM; subsequent authentication attempts fail with fallback to username/PAT authentication (which is successful).

From the trace logs you've included (thanks by the way!) I cannot see where the subsequent failure occurs. The logs show the following:

  1. Git requests a credential for github.com, and you are prompted to enter a PAT:
08:55:25.887808 ...GitCommandBase.cs:33 trace: [ExecuteAsync] Start 'get' command...
08:55:25.898778 ...GitCommandBase.cs:47 trace: [ExecuteAsync] Detecting host provider for input:
08:55:25.899814 ...GitCommandBase.cs:48 trace: [ExecuteAsync]   protocol=https
08:55:25.899814 ...GitCommandBase.cs:48 trace: [ExecuteAsync]   host=github.com
[..]
08:55:26.252518 ...GitCommandBase.cs:50 trace: [ExecuteAsync] Host provider 'GitHub' was selected.
08:55:26.255510 ...\HostProvider.cs:126 trace: [GetCredentialAsync] Looking for existing credential in store with service=https://github.com account=...
08:55:26.520918 ...\HostProvider.cs:131 trace: [GetCredentialAsync] No existing credentials found.
08:55:26.521915 ...\HostProvider.cs:134 trace: [GetCredentialAsync] Creating new credential...
08:55:26.649141 ...bHostProvider.cs:242 trace: [GetSupportedAuthenticationModesAsync] Supported authentication modes override present: Pat
08:55:26.767963 ...enticationBase.cs:42 trace: [InvokeHelperAsync] Starting helper process: C:\cygwin64\usr\libexec\git-core\GitHub.UI.exe prompt --pat
[..]
08:55:32.212237 ...GitCommandBase.cs:54 trace: [ExecuteAsync] End 'get' command...
  1. Git uses the credential successfully, and asks GCM to store it (which is successful):
08:55:41.043258 ...GitCommandBase.cs:33 trace: [ExecuteAsync] Start 'store' command...
08:55:41.054227 ...GitCommandBase.cs:47 trace: [ExecuteAsync] Detecting host provider for input:
08:55:41.056221 ...GitCommandBase.cs:48 trace: [ExecuteAsync]   protocol=https
08:55:41.056221 ...GitCommandBase.cs:48 trace: [ExecuteAsync]   host=github.com
08:55:41.056221 ...GitCommandBase.cs:48 trace: [ExecuteAsync]   username=<redacted>
08:55:41.056221 ...GitCommandBase.cs:48 trace: [ExecuteAsync]   password=<redacted>
[..]
08:55:41.401183 ...GitCommandBase.cs:50 trace: [ExecuteAsync] Host provider 'GitHub' was selected.
08:55:41.402182 ...\HostProvider.cs:160 trace: [StoreCredentialAsync] Storing credential with service=https://github.com account=<redacted>...
08:55:41.665200 ...\HostProvider.cs:162 trace: [StoreCredentialAsync] Credential was successfully stored.
08:55:41.665200 ...GitCommandBase.cs:54 trace: [ExecuteAsync] End 'store' command...
  1. A second credential request from Git comes in for github.com, and GCM finds that stored credential:
08:58:04.851851 ...GitCommandBase.cs:33 trace: [ExecuteAsync] Start 'get' command...
08:58:04.864817 ...GitCommandBase.cs:47 trace: [ExecuteAsync] Detecting host provider for input:
08:58:04.866812 ...GitCommandBase.cs:48 trace: [ExecuteAsync]   protocol=https
08:58:04.866812 ...GitCommandBase.cs:48 trace: [ExecuteAsync]   host=github.com
[..]
08:58:05.216926 ...GitCommandBase.cs:50 trace: [ExecuteAsync] Host provider 'GitHub' was selected.
08:58:05.220915 ...\HostProvider.cs:126 trace: [GetCredentialAsync] Looking for existing credential in store with service=https://github.com account=...
08:58:05.425640 ...\HostProvider.cs:140 trace: [GetCredentialAsync] Existing credential found.
08:58:05.426634 ...GitCommandBase.cs:54 trace: [ExecuteAsync] End 'get' command...
  1. Git also successfully uses that credential again, and asks us to ensure it is still stored:
08:58:16.452955 ...GitCommandBase.cs:33 trace: [ExecuteAsync] Start 'store' command...
08:58:16.464885 ...GitCommandBase.cs:47 trace: [ExecuteAsync] Detecting host provider for input:
08:58:16.466911 ...GitCommandBase.cs:48 trace: [ExecuteAsync]   protocol=https
08:58:16.466911 ...GitCommandBase.cs:48 trace: [ExecuteAsync]   host=github.com
08:58:16.466911 ...GitCommandBase.cs:48 trace: [ExecuteAsync]   username=<redacted>
08:58:16.466911 ...GitCommandBase.cs:48 trace: [ExecuteAsync]   password=<redacted>
[..]
08:58:16.843215 ...GitCommandBase.cs:50 trace: [ExecuteAsync] Host provider 'GitHub' was selected.
08:58:16.844187 ...\HostProvider.cs:160 trace: [StoreCredentialAsync] Storing credential with service=https://github.com account=<redacted>...
08:58:17.100741 ...\HostProvider.cs:162 trace: [StoreCredentialAsync] Credential was successfully stored.
08:58:17.100741 ...GitCommandBase.cs:54 trace: [ExecuteAsync] End 'store' command...

One thing of note that I see is that this is for github.com (not a GitHub Enterprise Server or GitHub AE) and you have a setting set to force the use of PATs, rather than allowing OAuth tokens:

08:55:26.649141 ...bHostProvider.cs:242 trace: [GetSupportedAuthenticationModesAsync] Supported authentication modes override present: Pat

Is this intentional?

@bakoontz2
Copy link
Author

Good catch! Let me see what's up with that, might be the problem.

@mjcheetham
Copy link
Collaborator

You'll probably want to look for the Git configuration entry credential.githubAuthModes or an environment variable GCM_GITHUB_AUTHMODES.

@bakoontz2
Copy link
Author

bakoontz2 commented Nov 2, 2021

OK, apparently that setting was copied over inadvertently from someone else's config. I've removed it, as the docs indicate the appropriate authentication mode should be detected (oauth in this case). And yes, this is not a github enterprise account, corrected my initial comment.

$ git config --global -l
credential.helper=manager-core
user.name=<redacted>
user.email=<redacted>

I can see in the log below where the credential is found (line 17), but I'm still being presented with a username/password prompt (lines 28-31).

  1 10:39:25.600864 ...pplicationBase.cs:75 trace: [RunAsync] Tracing of secrets is enabled. Trace output may contain se    nsitive information.
  2 10:39:25.653863 ...\Application.cs:95   trace: [RunInternalAsync] Version: 2.0.567.18224
  3 10:39:25.653863 ...\Application.cs:96   trace: [RunInternalAsync] Runtime: .NET Framework 4.0.30319.42000
  4 10:39:25.654863 ...\Application.cs:97   trace: [RunInternalAsync] Platform: Windows (x86-64)
  5 10:39:25.654863 ...\Application.cs:98   trace: [RunInternalAsync] OSVersion: 10.0 (build 17763)
  6 10:39:25.654863 ...\Application.cs:99   trace: [RunInternalAsync] AppPath: C:\cygwin64\usr\libexec\git-core\git-cred    ential-manager-core.exe
  7 10:39:25.654863 ...\Application.cs:100  trace: [RunInternalAsync] Arguments: get
  8 10:39:25.740861 ...GitCommandBase.cs:33 trace: [ExecuteAsync] Start 'get' command...
  9 10:39:25.754863 ...GitCommandBase.cs:47 trace: [ExecuteAsync] Detecting host provider for input:
 10 10:39:25.755864 ...GitCommandBase.cs:48 trace: [ExecuteAsync]   protocol=https
 11 10:39:25.755864 ...GitCommandBase.cs:48 trace: [ExecuteAsync]   host=github.com
 12 10:39:26.554004 ...viderRegistry.cs:147 trace: [GetProviderAsync] Performing auto-detection of host provider.
 13 10:39:26.971876 ...viderRegistry.cs:152 trace: [GetProviderAsync] Auto-detect probe timeout is 2 ms.
 14 10:39:26.974879 ...viderRegistry.cs:160 trace: [GetProviderAsync] Checking against 3 host providers registered with     priority 'Normal'.
 15 10:39:26.976874 ...GitCommandBase.cs:50 trace: [ExecuteAsync] Host provider 'GitHub' was selected.
 16 10:39:26.981873 ...\HostProvider.cs:126 trace: [GetCredentialAsync] Looking for existing credential in store with se    rvice=https://github.com account=...
 17 10:39:27.816872 ...\HostProvider.cs:140 trace: [GetCredentialAsync] Existing credential found.
 18 10:39:27.817874 ...GitCommandBase.cs:54 trace: [ExecuteAsync] End 'get' command...
 19 10:39:42.364027 ...pplicationBase.cs:75 trace: [RunAsync] Tracing of secrets is enabled. Trace output may contain se    nsitive information.
 20 10:39:42.410026 ...\Application.cs:95   trace: [RunInternalAsync] Version: 2.0.567.18224
 21 10:39:42.410026 ...\Application.cs:96   trace: [RunInternalAsync] Runtime: .NET Framework 4.0.30319.42000
 22 10:39:42.410026 ...\Application.cs:97   trace: [RunInternalAsync] Platform: Windows (x86-64)
 23 10:39:42.410026 ...\Application.cs:98   trace: [RunInternalAsync] OSVersion: 10.0 (build 17763)
 24 10:39:42.410026 ...\Application.cs:99   trace: [RunInternalAsync] AppPath: C:\cygwin64\usr\libexec\git-core\git-cred    ential-manager-core.exe
 25 10:39:42.410026 ...\Application.cs:100  trace: [RunInternalAsync] Arguments: store
 26 10:39:42.565024 ...GitCommandBase.cs:33 trace: [ExecuteAsync] Start 'store' command...
 27 10:39:42.834027 ...GitCommandBase.cs:47 trace: [ExecuteAsync] Detecting host provider for input:
 28 10:39:42.835028 ...GitCommandBase.cs:48 trace: [ExecuteAsync]   protocol=https
 29 10:39:42.836025 ...GitCommandBase.cs:48 trace: [ExecuteAsync]   host=github.com
 30 10:39:42.836025 ...GitCommandBase.cs:48 trace: [ExecuteAsync] username=<redacted>
 31 10:39:42.836025 ...GitCommandBase.cs:48 trace: [ExecuteAsync] password=<redacted>
 32 10:39:44.062022 ...viderRegistry.cs:147 trace: [GetProviderAsync] Performing auto-detection of host provider.
 33 10:39:44.506643 ...viderRegistry.cs:152 trace: [GetProviderAsync] Auto-detect probe timeout is 2 ms.
 34 10:39:44.510642 ...viderRegistry.cs:160 trace: [GetProviderAsync] Checking against 3 host providers registered with     priority 'Normal'.
 35 10:39:44.512643 ...GitCommandBase.cs:50 trace: [ExecuteAsync] Host provider 'GitHub' was selected.
 36 10:39:44.513640 ...\HostProvider.cs:160 trace: [StoreCredentialAsync] Storing credential with service=https://github    .com account=<redacted>
 37 10:39:45.325637 ...\HostProvider.cs:162 trace: [StoreCredentialAsync] Credential was successfully stored.
 38 10:39:45.325637 ...GitCommandBase.cs:54 trace: [ExecuteAsync] End 'store' command...

@mjcheetham
Copy link
Collaborator

but I'm still being presented with a username/password prompt (lines 28-31).

Hmm.. strange. Can you please try again, and as well as GCM_TRACE=1 can you also set GIT_TRACE=1 too (to see what Git is doing in between the get and store)?

Also a few questions/things to try and help diagnose the problem further:

  1. Can you run git credential-manager-core diagnose and include the resulting log file (contains lots of information, possibly including secrets and environment variables, please redact!)
  2. When you get a username/password prompt, what does it look like? Is it a command-line prompt or GUI window?
  3. Does this reproduce outside of Cygwin, for example in cmd.exe?
  4. Has this only started happening recently? If so, what version of Git for Windows/GCM did this start happening in?

Thanks!

@bakoontz2
Copy link
Author

  1. See below for logs. This was displayed on stdout:
$ git credential-manager-core diagnose
Running diagnostics...

 [ OK ] Environment
 [ OK ] File system
 [ OK ] Networking
 [ OK ] Git
 [ OK ] Credential storage
 [ OK ] Microsoft authentication (AAD/MSA)
 [ OK ] GitHub API

Diagnostic summary: 7 passed, 0 skipped, 0 failed.
Log files:
  C:\Users\<redacted>\Repos\CIFS_Parent\gcm-diagnose.log

Caution: Log files may include sensitive information - redact before sharing.
  1. Command-line prompt.
  2. I usually don't use cmd.exe, but I tried by appending the bin/ directory to %PATH% and doing a 'git push'. I was prompted with a UI, selected "Token" and pasted in my PAT. The I was presented with a command-line Username prompt.
  3. This laptop I'm working on was completely wiped and reimaged. Previously, I used GCM-Windows and it worked well. When I went to re-install, I saw that GCM-Windows had been deprecated, so wanting to Do the Right Thing, I installed GCM-Core instead. GCM-Windows has never been installed on this new image. Right now, as a workaround, I'm using the "store" CM.

gcm-diagnose.log

 1 Diagnose log at 2021-11-03T15:05:05Z
 2 
 3 Executable: C:\cygwin64\usr\libexec\git-core\git-credential-manager-core.exe
 4 Version: 2.0.567+3047faf390
 5 
 6 ------------
 7 Diagnostic: Environment
 8 Skipped: False
 9 Success: True
10 Exception: None
11 Log:
12 OSType: Windows
13 OSVersion: 10.0 (build 17763)
14 Reading environment variables... OK
15  Variables:
16 HOMEPATH=\Users\<redacted>
17 DriverData=C:\Windows\System32\Drivers\DriverData
18 COMPUTERNAME=<redacted>
19 UATDATA=C:\Windows\CCM\UATData\<redacted>
20 EXECIGNORE=*.dll
21 CommonProgramFiles(x86)=C:\Program Files (x86)\Common Files
22 OneDrive=C:\Users\<redacted>\OneDrive - <redacted>, Inc
23 USERDNSDOMAIN=<redacted>
24 GCM_TRACE=C:\Users\<redacted>\git.log
25 PERL_MB_OPT=--install_base "/home/<redacted>/perl5"
26 HOME=C:\cygwin64\home\<redacted>
27 LC_CTYPE=en_US.UTF-8
28 PROCESSOR_IDENTIFIER=Intel64 Family 6 Model 78 Stepping 3, GenuineIntel
29 PATHEXT=.COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC
30 GCM_TRACE_SECRETS=1
31 EDITOR=/usr/bin/vim
32 GIT_EXEC_PATH=/usr/libexec/git-core
33 PWD=/cygdrive/c/Users/<redacted>/Repos/CIFS_Parent
34 HISTFILESIZE=100000
35 LOCALAPPDATA=C:\Users\<redacted>\AppData\Local
36 HISTCONTROL=ignoredups:erasedups
37 TERM=xterm
38 HISTSIZE=100000
39 CATALINA_BASE=/cygdrive/c/apache-tomcat
40 SYSTEMDRIVE=C:
41 ProgramData=C:\ProgramData
42 JAVA_HOME=/cygdrive/c/jdk-8.0.312.7-hotspot
43 TERM_PROGRAM_VERSION=3.5.1
44 ProgramFiles(x86)=C:\Program Files (x86)
45 PROCESSOR_REVISION=4e03
46 PERL_LOCAL_LIB_ROOT=/home/<redacted>/perl5
47 TZ=America/Chicago
48 TERM_PROGRAM=mintty
49 PROCESSOR_LEVEL=6
50 NUMBER_OF_PROCESSORS=4
51 SHLVL=1
52 SVN_EDITOR=/usr/bin/vim
53 PSModulePath=C:\Program Files\WindowsPowerShell\Modules;C:\Windows\system32\WindowsPowerShell\v1.0\Modules
54 PUBLIC=C:\Users\Public
55 HOSTNAME=<redacted>
56 USERDOMAIN_ROAMINGPROFILE=<redacted>
57 PERL_MM_OPT=INSTALL_BASE=/home/<redacted>/perl5
58 VISUAL=/usr/bin/vim
59 CATALINA_HOME=/cygdrive/c/apache-tomcat
60 PROGRAMFILES=C:\Program Files (x86)
61 INFOPATH=/usr/local/info:/usr/share/info:/usr/info
62 ProgramW6432=C:\Program Files
63 PATH=C:\cygwin64\usr\libexec\git-core;C:\cygwin64\home\<redacted>\perl5\bin;C:\MongoDB\Server\3.6\bin;C:\cygwin64\usr\local\src\apache-maven-3.8.3\bin;C:\OpenShift\;C:\jdk-8.0.312.7-hotspot\bin;C:\ant\bin;C:\cygwin64\usr\local\bin;C:\cygwin64\bin;C:\jdk-8.0.312.7-hotspot\bin;C:\Program Files\Teradata\Client\16.10\bin;C:\Program Files (x86)\Teradata\Client\16.10\bin;C:\Windows\system32;C:\Windows;C:\Windows\System32\Wbem;C:\Windows\System32\WindowsPowerShell\v1.0;C:\Windows\System32\OpenSSH;C:\Program Files (x86)\Webex\Plugins;C:\Program Files (x86)\Sennheiser\SoftphoneSDK;C:\Windows\SysWOW64;C:\Windows\SysWOW64\Wbem;C:\Windows\SysWOW64\WindowsPowerShell\v1.0;C:\Windows\idmu\common;%C;C:\cygwin64\Windows%\idmu\common;C:\Program Files\Docker\Docker\resources\bin;C:\ProgramData\DockerDesktop\version-bin;C:\Users\<redacted>\AppData\Local\Microsoft\WindowsApps;C:\Program Files\nodejs;C:\Program Files\Cloud Foundry
64 TEMP=C:\cygwin64\tmp
65 PROFILEREAD=true
66 FPS_BROWSER_APP_PROFILE_STRING=Internet Explorer
67 USERDOMAIN=<redacted>
68 GIT_TRACE=C:\Users\<redacted>\git.log
69 PRINTER=BADGE-PRINT-Q on SECUREPRINT
70 TMP=C:\cygwin64\tmp
71 SHELL=/bin/bash
72 PERL5LIB=/home/<redacted>/perl5/lib/perl5
73 S3_URL=<redacted>
74 COMSPEC=C:\Windows\system32\cmd.exe
75 LOGONSERVER=<redacted>
76 USERPROFILE=C:\Users\<redacted>
77 FPS_BROWSER_USER_PROFILE_STRING=Default
78 CommonProgramW6432=C:\Program Files\Common Files
79 COMMONPROGRAMFILES=C:\Program Files (x86)\Common Files
80 WINDIR=C:\Windows
81 _=/usr/bin/git
82 MINTTY_SHORTCUT=/cygdrive/c/Users/<redacted>/AppData/Roaming/Microsoft/Internet Explorer/Quick Launch/User Pinned/TaskBar/Cygwin64 Terminal.lnk
83 APPDATA=C:\Users\<redacted>\AppData\Roaming
84 HOMEDRIVE=C:
85 OLDPWD=/cygdrive/c/Users/<redacted>/Downloads
86 OneDriveCommercial=C:\Users\<redacted>\OneDrive - <redacted>, Inc
87 ANT_HOME=/cygdrive/c/ant
88 SESSIONNAME=Console
89 VBOX_MSI_INSTALL_PATH=C:\Program Files\Oracle\VirtualBox\
90 USERNAME=<redacted>
91 PROCESSOR_ARCHITEW6432=AMD64
92 ORIGINAL_PATH=/cygdrive/c/jdk-8.0.312.7-hotspot/bin:/cygdrive/c/Program Files/Teradata/Client/16.10/bin:/cygdrive/c/Program Files (x86)/Teradata/Client/16.10/bin:/cygdrive/c/Windows/system32:/cygdrive/c/Windows:/cygdrive/c/Windows/System32/Wbem:/cygdrive/c/Windows/System32/WindowsPowerShell/v1.0:/cygdrive/c/Windows/System32/OpenSSH:/cygdrive/c/Program Files (x86)/Webex/Plugins:/cygdrive/c/Program Files (x86)/Sennheiser/SoftphoneSDK:/cygdrive/c/Windows/SysWOW64:/cygdrive/c/Windows/SysWOW64/Wbem:/cygdrive/c/Windows/SysWOW64/WindowsPowerShell/v1.0:/cygdrive/c/Windows/idmu/common:%C:/Windows%/idmu/common:/cygdrive/c/Program Files/Docker/Docker/resources/bin:/cygdrive/c/ProgramData/DockerDesktop/version-bin:/cygdrive/c/Users/<redacted>/AppData/Local/Microsoft/WindowsApps
93 PROCESSOR_ARCHITECTURE=x86
94 PS1=\[\e]0;<redacted>\a\]\n\[\e[32m\]\u@\h\[\e[33m\]>\[\e[0m\] 
95 OS=Windows_NT
96 USER=<redacted>
97 SYSTEMROOT=C:\Windows
98 ALLUSERSPROFILE=C:\ProgramData
99 
100 
101 ------------
102 Diagnostic: File system
103 Skipped: False
104 Success: True
105 Exception: None
106 Log:
107 Temporary directory is 'C:\cygwin64\tmp\'...
108 Checking basic file I/O...
109 Writing to temporary file 'C:\cygwin64\tmp\90a849708c2cb0cd3b2fc6dc'... OK
110 Reading from temporary file 'C:\cygwin64\tmp\90a849708c2cb0cd3b2fc6dc'... OK
111 Deleting temporary file 'C:\cygwin64\tmp\90a849708c2cb0cd3b2fc6dc'... OK
112 Testing IFileSystem instance...
113 UserHomePath: C:\Users\<redacted>
114 UserDataDirectoryPath: C:\Users\<redacted>\.gcm
115 GetCurrentDirectory(): C:\Users\<redacted>\Repos\CIFS_Parent
116 
117 ------------
118 Diagnostic: Networking
119 Skipped: False
120 Success: True
121 Exception: None
122 Log:
123 Checking basic networking and HTTP stack...
124 Creating HTTP client... OK
125 IsNetworkAvailable: True
126 Sending HEAD request to http://example.com... OK
127 Sending HEAD request to https://example.com... OK
128 Acquiring free TCP port... OK
129 Testing local HTTP loopback connections...
130 Creating new HTTP listener for http://localhost:62242/... OK
131 Waiting for loopback connection... OK
132 Writing response... OK
133 Waiting for response data... OK
134 Loopback connection data OK
135 Testing with IHttpClientFactory created HTTP client...
136 Creating HTTP client... OK
137 IsNetworkAvailable: True
138 Sending HEAD request to http://example.com... OK
139 Sending HEAD request to https://example.com... OK
140 Acquiring free TCP port... OK
141 Testing local HTTP loopback connections...
142 Creating new HTTP listener for http://localhost:62247/... OK
143 Waiting for loopback connection... OK
144 Writing response... OK
145 Waiting for response data... OK
146 Loopback connection data OK
147 
148 ------------
149 Diagnostic: Git
150 Skipped: False
151 Success: True
152 Exception: None
153 Log:
154 Getting Git version... OK
155 Git version is '2.33.0'
156 Locating current repository... OK
157 Git repository at '/cygdrive/c/Users/<redacted>/Repos/CIFS_Parent/.git'
158 Listing all Git configuration... OK
159 Git configuration:
160 file:/home/<redacted>/.gitconfig	credential.helper=manager-core
161 file:/home/<redacted>/.gitconfig	user.name=<redacted>
162 file:/home/<redacted>/.gitconfig	user.email=<redacted>
163 file:.git/config	core.repositoryformatversion=0
164 file:.git/config	core.filemode=true
165 file:.git/config	core.bare=false
166 file:.git/config	core.logallrefupdates=true
167 file:.git/config	core.ignorecase=true
168 file:.git/config	remote.origin.url=<redacted>
169 file:.git/config	remote.origin.fetch=+refs/heads/*:refs/remotes/origin/*
170 file:.git/config	branch.master.remote=origin
171 file:.git/config	branch.master.merge=refs/heads/master
172 
173 
174 ------------
175 Diagnostic: Credential storage
176 Skipped: False
177 Success: True
178 Exception: None
179 Log:
180 ICredentialStore instance is of type: CredentialStore
181 Writing test credential... OK
182 Reading test credential... OK
183 Deleting test credential... OK
184 
185 ------------
186 Diagnostic: Microsoft authentication (AAD/MSA)
187 Skipped: False
188 Success: True
189 Exception: None
190 Log:
191 Broker not supported.
192 Flow type is: Auto
193 Gathering MSAL token cache data... OK
194 CacheDirectory: C:\Users\<redacted>\AppData\Local\.IdentityService
195 CacheFileName: msal.cache
196 CacheFilePath: C:\Users\<redacted>\AppData\Local\.IdentityService\msal.cache
197 Creating cache helper... OK
198 Verifying MSAL token cache persistence... OK
199 
200 ------------
201 Diagnostic: GitHub API
202 Skipped: False
203 Success: True
204 Exception: None
205 Log:
206 Using 'https://github.com/' as API target.
207 Querying '/meta' endpoint... OK
208 

git.log

 1 # Initial authentication request
 2 
 3 10:16:38.065333 git.c:455               trace: built-in: git push
 4 10:16:38.068678 run-command.c:666       trace: run_command: GIT_DIR=.git git remote-https origin https://github.com/<redacted>/<redacted>.git
 5 10:16:38.131919 git.c:743               trace: exec: git-remote-https origin https://github.com/<redacted>/<redacted>.git
 6 10:16:38.132589 run-command.c:666       trace: run_command: git-remote-https origin https://github.com/<redacted>/<redacted>.git
 7 10:16:38.577572 run-command.c:666       trace: run_command: 'git credential-manager-core get'
 8 10:16:38.778665 git.c:743               trace: exec: git-credential-manager-core get
 9 10:16:38.781940 run-command.c:666       trace: run_command: git-credential-manager-core get
10 10:16:39.071031 git.c:455               trace: built-in: git version
11 10:16:39.138130 git.c:455               trace: built-in: git config --null credential.msauthUseBroker
12 10:16:39.162844 ...pplicationBase.cs:75 trace: [RunAsync] Tracing of secrets is enabled. Trace output may contain sensitive information.
13 10:16:39.179801 ...\Application.cs:95   trace: [RunInternalAsync] Version: 2.0.567.18224
14 10:16:39.179801 ...\Application.cs:96   trace: [RunInternalAsync] Runtime: .NET Framework 4.0.30319.42000
15 10:16:39.179801 ...\Application.cs:97   trace: [RunInternalAsync] Platform: Windows (x86-64)
16 10:16:39.179801 ...\Application.cs:98   trace: [RunInternalAsync] OSVersion: 10.0 (build 17763)
17 10:16:39.180803 ...\Application.cs:99   trace: [RunInternalAsync] AppPath: C:\cygwin64\usr\libexec\git-core\git-credential-manager-core.exe
18 10:16:39.180803 ...\Application.cs:100  trace: [RunInternalAsync] Arguments: get
19 10:16:39.251695 ...GitCommandBase.cs:33 trace: [ExecuteAsync] Start 'get' command...
20 10:16:39.264695 ...GitCommandBase.cs:47 trace: [ExecuteAsync] Detecting host provider for input:
21 10:16:39.265697 ...GitCommandBase.cs:48 trace: [ExecuteAsync] 	protocol=https
22 10:16:39.265697 ...GitCommandBase.cs:48 trace: [ExecuteAsync] 	host=github.com
23 10:16:39.548557 ...viderRegistry.cs:147 trace: [GetProviderAsync] Performing auto-detection of host provider.
24 10:16:39.688961 ...viderRegistry.cs:152 trace: [GetProviderAsync] Auto-detect probe timeout is 2 ms.
25 10:16:39.690996 ...viderRegistry.cs:160 trace: [GetProviderAsync] Checking against 3 host providers registered with priority 'Normal'.
26 10:16:39.692995 ...GitCommandBase.cs:50 trace: [ExecuteAsync] Host provider 'GitHub' was selected.
27 10:16:39.695993 ...\HostProvider.cs:126 trace: [GetCredentialAsync] Looking for existing credential in store with service=https://github.com account=...
28 10:16:39.982162 ...\HostProvider.cs:140 trace: [GetCredentialAsync] Existing credential found.
29 10:16:39.983134 ...GitCommandBase.cs:54 trace: [ExecuteAsync] End 'get' command...
30 10:16:39.893424 git.c:455               trace: built-in: git config --null --list
31 10:16:39.970003 git.c:455               trace: built-in: git config --null credential.credentialStore
32 10:16:49.701322 run-command.c:666       trace: run_command: 'git credential-manager-core store'
33 10:16:49.896788 git.c:743               trace: exec: git-credential-manager-core store
34 10:16:49.897647 run-command.c:666       trace: run_command: git-credential-manager-core store
35 10:16:50.193101 git.c:455               trace: built-in: git version
36 10:16:50.262163 git.c:455               trace: built-in: git config --null credential.msauthUseBroker
37 10:16:50.295307 ...pplicationBase.cs:75 trace: [RunAsync] Tracing of secrets is enabled. Trace output may contain sensitive information.
38 10:16:50.313268 ...\Application.cs:95   trace: [RunInternalAsync] Version: 2.0.567.18224
39 10:16:50.313268 ...\Application.cs:96   trace: [RunInternalAsync] Runtime: .NET Framework 4.0.30319.42000
40 10:16:50.313268 ...\Application.cs:97   trace: [RunInternalAsync] Platform: Windows (x86-64)
41 10:16:50.313268 ...\Application.cs:98   trace: [RunInternalAsync] OSVersion: 10.0 (build 17763)
42 10:16:50.313268 ...\Application.cs:99   trace: [RunInternalAsync] AppPath: C:\cygwin64\usr\libexec\git-core\git-credential-manager-core.exe
43 10:16:50.313268 ...\Application.cs:100  trace: [RunInternalAsync] Arguments: store
44 10:16:50.383264 ...GitCommandBase.cs:33 trace: [ExecuteAsync] Start 'store' command...
45 10:16:50.397266 ...GitCommandBase.cs:47 trace: [ExecuteAsync] Detecting host provider for input:
46 10:16:50.398269 ...GitCommandBase.cs:48 trace: [ExecuteAsync] 	protocol=https
47 10:16:50.398269 ...GitCommandBase.cs:48 trace: [ExecuteAsync] 	host=github.com
48 10:16:50.398269 ...GitCommandBase.cs:48 trace: [ExecuteAsync] 	username=<redacted>
49 10:16:50.399265 ...GitCommandBase.cs:48 trace: [ExecuteAsync] 	password=<redacted>
50 10:16:50.680972 ...viderRegistry.cs:147 trace: [GetProviderAsync] Performing auto-detection of host provider.
51 10:16:50.817827 ...viderRegistry.cs:152 trace: [GetProviderAsync] Auto-detect probe timeout is 2 ms.
52 10:16:50.819825 ...viderRegistry.cs:160 trace: [GetProviderAsync] Checking against 3 host providers registered with priority 'Normal'.
53 10:16:50.821823 ...GitCommandBase.cs:50 trace: [ExecuteAsync] Host provider 'GitHub' was selected.
54 10:16:50.822823 ...\HostProvider.cs:160 trace: [StoreCredentialAsync] Storing credential with service=https://github.com account=<redacted>...
55 10:16:51.118508 ...\HostProvider.cs:162 trace: [StoreCredentialAsync] Credential was successfully stored.
56 10:16:51.118508 ...GitCommandBase.cs:54 trace: [ExecuteAsync] End 'store' command...
57 01 git.c:455               trace: built-in: git config --null --list
58 10:16:51.103339 git.c:455               trace: built-in: git config --null credential.credentialStore
59 10:16:51.191298 run-command.c:666       trace: run_command: git send-pack --stateless-rpc --helper-status --thin --progress https://github.com/<redacted>/<redacted>.git/ --stdin
60 10:16:51.301436 git.c:455               trace: built-in: git send-pack --stateless-rpc --helper-status --thin --progress https://github.com/<redacted>/<redacted>.git/ --stdin
61 10:16:51.316976 run-command.c:666       trace: run_command: git pack-objects --all-progress-implied --revs --stdout --thin --delta-base-offset --progress
62 10:16:51.384252 git.c:455               trace: built-in: git pack-objects --all-progress-implied --revs --stdout --thin --delta-base-offset --progress
63 
64 # Subsequent authentication request
65 10:17:28.128292 git.c:455               trace: built-in: git commit -a
66 10:17:28.161615 run-command.c:666       trace: run_command: GIT_INDEX_FILE=/cygdrive/c/Users/<redacted>/Repos/CIFS_Parent/.git/index.lock /usr/bin/vim /cygdrive/c/Users/<redacted>/Repos/CIFS_Parent/.git/COMMIT_EDITMSG
67 10:17:31.765885 run-command.c:666       trace: run_command: git maintenance run --auto --no-quiet
68 10:17:31.838022 git.c:455               trace: built-in: git maintenance run --auto --no-quiet
69 10:17:34.112414 git.c:455               trace: built-in: git push
70 10:17:34.115608 run-command.c:666       trace: run_command: GIT_DIR=.git git remote-https origin https://github.com/<redacted>/<redacted>.git
71 10:17:34.178650 git.c:743               trace: exec: git-remote-https origin https://github.com/<redacted>/<redacted>.git
72 10:17:34.179336 run-command.c:666       trace: run_command: git-remote-https origin https://github.com/<redacted>/<redacted>.git
73 10:17:34.677692 run-command.c:666       trace: run_command: 'git credential-manager-core get'
74 10:17:34.862543 git.c:743               trace: exec: git-credential-manager-core get
75 10:17:34.863235 run-command.c:666       trace: run_command: git-credential-manager-core get
76 10:17:35.162008 git.c:455               trace: built-in: git version
77 10:17:35.240630 git.c:455               trace: built-in: git config --null credential.msauthUseBroker
78 10:17:35.266013 ...pplicationBase.cs:75 trace: [RunAsync] Tracing of secrets is enabled. Trace output may contain sensitive information.
79 10:17:35.286976 ...\Application.cs:95   trace: [RunInternalAsync] Version: 2.0.567.18224
80 10:17:35.286976 ...\Application.cs:96   trace: [RunInternalAsync] Runtime: .NET Framework 4.0.30319.42000
81 10:17:35.286976 ...\Application.cs:97   trace: [RunInternalAsync] Platform: Windows (x86-64)
82 10:17:35.287976 ...\Application.cs:98   trace: [RunInternalAsync] OSVersion: 10.0 (build 17763)
83 10:17:35.287976 ...\Application.cs:99   trace: [RunInternalAsync] AppPath: C:\cygwin64\usr\libexec\git-core\git-credential-manager-core.exe
84 10:17:35.287976 ...\Application.cs:100  trace: [RunInternalAsync] Arguments: get
85 10:17:35.352013 ...GitCommandBase.cs:33 trace: [ExecuteAsync] Start 'get' command...
86 10:17:35.364982 ...GitCommandBase.cs:47 trace: [ExecuteAsync] Detecting host provider for input:
87 10:17:35.365982 ...GitCommandBase.cs:48 trace: [ExecuteAsync] 	protocol=https
88 10:17:35.365982 ...GitCommandBase.cs:48 trace: [ExecuteAsync] 	host=github.com
89 10:17:35.661037 ...viderRegistry.cs:147 trace: [GetProviderAsync] Performing auto-detection of host provider.
90 10:17:35.790049 ...viderRegistry.cs:152 trace: [GetProviderAsync] Auto-detect probe timeout is 2 ms.
91 10:17:35.793046 ...viderRegistry.cs:160 trace: [GetProviderAsync] Checking against 3 host providers registered with priority 'Normal'.
92 10:17:35.794073 ...GitCommandBase.cs:50 trace: [ExecuteAsync] Host provider 'GitHub' was selected.
93 10:17:35.797077 ...\HostProvider.cs:126 trace: [GetCredentialAsync] Looking for existing credential in store with service=https://github.com account=...
94 10:17:36.083122 ...\HostProvider.cs:140 trace: [GetCredentialAsync] Existing credential found.
95 10:17:36.084121 ...GitCommandBase.cs:54 trace: [ExecuteAsync] End 'get' command...
96 10:17:36.003908 git.c:455               trace: built-in: git config --null --list
97 10:17:36.070901 git.c:455               trace: built-in: git config --null credential.credentialStore
98 10:17:43.472913 run-command.c:666       trace: run_command: 'git credential-manager-core store'
99 10:17:43.682006 git.c:743               trace: exec: git-credential-manager-core store
100 10:17:43.682996 run-command.c:666       trace: run_command: git-credential-manager-core store
101 10:17:43.980279 git.c:455               trace: built-in: git version
102 10:17:44.044890 git.c:455               trace: built-in: git config --null credential.msauthUseBroker
103 10:17:44.073819 ...pplicationBase.cs:75 trace: [RunAsync] Tracing of secrets is enabled. Trace output may contain sensitive information.
104 10:17:44.090823 ...\Application.cs:95   trace: [RunInternalAsync] Version: 2.0.567.18224
105 10:17:44.090823 ...\Application.cs:96   trace: [RunInternalAsync] Runtime: .NET Framework 4.0.30319.42000
106 10:17:44.090823 ...\Application.cs:97   trace: [RunInternalAsync] Platform: Windows (x86-64)
107 10:17:44.090823 ...\Application.cs:98   trace: [RunInternalAsync] OSVersion: 10.0 (build 17763)
108 10:17:44.090823 ...\Application.cs:99   trace: [RunInternalAsync] AppPath: C:\cygwin64\usr\libexec\git-core\git-credential-manager-core.exe
109 10:17:44.090823 ...\Application.cs:100  trace: [RunInternalAsync] Arguments: store
110 10:17:44.164818 ...GitCommandBase.cs:33 trace: [ExecuteAsync] Start 'store' command...
111 10:17:44.177819 ...GitCommandBase.cs:47 trace: [ExecuteAsync] Detecting host provider for input:
112 10:17:44.178821 ...GitCommandBase.cs:48 trace: [ExecuteAsync] 	protocol=https
113 10:17:44.178821 ...GitCommandBase.cs:48 trace: [ExecuteAsync] 	host=github.com
114 10:17:44.178821 ...GitCommandBase.cs:48 trace: [ExecuteAsync] 	username=<redacted>
115 10:17:44.178821 ...GitCommandBase.cs:48 trace: [ExecuteAsync] 	password=<redacted>
116 10:17:44.474040 ...viderRegistry.cs:147 trace: [GetProviderAsync] Performing auto-detection of host provider.
117 10:17:44.612209 ...viderRegistry.cs:152 trace: [GetProviderAsync] Auto-detect probe timeout is 2 ms.
118 10:17:44.614239 ...viderRegistry.cs:160 trace: [GetProviderAsync] Checking against 3 host providers registered with priority 'Normal'.
119 10:17:44.616206 ...GitCommandBase.cs:50 trace: [ExecuteAsync] Host provider 'GitHub' was selected.
120 10:17:44.617208 ...\HostProvider.cs:160 trace: [StoreCredentialAsync] Storing credential with service=https://github.com account=<redacted>...
121 10:17:44.917863 ...\HostProvider.cs:162 trace: [StoreCredentialAsync] Credential was successfully stored.
122 10:17:44.917863 ...GitCommandBase.cs:54 trace: [ExecuteAsync] End 'store' command...
123 72 git.c:455               trace: built-in: git config --null --list
124 10:17:44.903292 git.c:455               trace: built-in: git config --null credential.credentialStore
125 10:17:44.989116 run-command.c:666       trace: run_command: git send-pack --stateless-rpc --helper-status --thin --progress https://github.com/<redacted>/<redacted>.git/ --stdin
126 10:17:45.098710 git.c:455               trace: built-in: git send-pack --stateless-rpc --helper-status --thin --progress https://github.com/<redacted>/<redacted>.git/ --stdin
127 10:17:45.113721 run-command.c:666       trace: run_command: git pack-objects --all-progress-implied --revs --stdout --thin --delta-base-offset --progress
128 10:17:45.182969 git.c:455               trace: built-in: git pack-objects --all-progress-implied --revs --stdout --thin --delta-base-offset --progress

@dscho
Copy link
Collaborator

dscho commented Nov 4, 2021

2. The I was presented with a command-line Username prompt.

Just to understand correctly: this user name prompt, is it in the terminal window, or is it a GUI window?

@mjcheetham
Copy link
Collaborator

mjcheetham commented Nov 4, 2021

Can you include a screenshot and the exact wording of the prompt please? Might help narrow down where it's coming from.

Can I also ask what method you used to install GCM Core? Was it via extracting the gcmcore-win-x86-<version>.zip file in to your /usr/libexec/git-core?

@dscho
Copy link
Collaborator

dscho commented Nov 4, 2021

I debugged a bit further and can confirm that this is a Cygwin-only issue. In fact, it looks as if a getc() call that wants to read git-credential-manager-core.exe's output falsely reports EOF even before the credential helper started outputting.

So I just had a hunch that this might be a regression in Cygwin v3.3.1, and it looks as if indeed, this still works as intended when I replace /bin/cygwin1.dll by https://cygwin.com/snapshots/x86_64/cygwin1-20210913.dll.xz.

@bakoontz2 could you replace your cygwin1.dll and see whether it works around the problem for you, too?

@bakoontz2
Copy link
Author

@dscho @mjcheetham You all are geniuses. That fixed the problem.

I feel badly I put you all through this to debug a Cygwin issue. I wish I had been able to catch this before taking up your time. Much appreciated!

I will close this out and take this up with the cygwin folks.

@dscho
Copy link
Collaborator

dscho commented Nov 4, 2021

I feel badly I put you all through this to debug a Cygwin issue

Oh, don't feel bad about this! I need to make sure that Cygwin's runtime works well anyway, as part of my work on Git for Windows (which uses a fork of that runtime to drive its Bash, Perl, SSH, etc).

I will close this out and take this up with the cygwin folks.

Would you mind leaving a link here once you do?

@gstrauss
Copy link

gstrauss commented Nov 4, 2021

Would you mind leaving a link here once you do?

cygwin email list thread starts here: https://cygwin.com/pipermail/cygwin/2021-November/249777.html
(no resolution yet)

@bakoontz2
Copy link
Author

bakoontz2 commented Nov 5, 2021 via email

@dscho
Copy link
Collaborator

dscho commented Nov 5, 2021

Reporting back that in https://cygwin.com/pipermail/cygwin/2021-November/249790.html a workaround was found: export CYGWIN=pipe_byte

@bakoontz2
Copy link
Author

bakoontz2 commented Nov 5, 2021

And confirmed as working. Thanks for looking into this!

@bakoontz2
Copy link
Author

Update from Cygwin list:

https://cygwin.com/pipermail/cygwin/2021-November/249818.html

Fix the issue that pipe reader falsely detects EOF if the output of
the C# program is redirected to the pipe.
Addresses: https://cygwin.com/pipermail/cygwin/2021-November/249777.html

@dscho
Copy link
Collaborator

dscho commented Nov 8, 2021

It's already in Cygwin v3.3.2.

@jpmat296
Copy link

Thanks I confirm export CYGWIN=pipe_byte is no more required with cygwin 3.3.2-1.

dscho added a commit to dscho/msys2-runtime that referenced this issue May 16, 2023
…rtup."

When Git for Windows upgraded its MSYS2 runtime from v3.3.* to v3.4.* at
long last, the t3701-add-interactive test of Git's test suite started to
hang consistently, timing out.

The culprit is a `git add -p` call that wants to read from a diff
filter. This diff filter is `cat.exe`, i.e. nothing special, but that
diff filter gets input that is larger than the pipe buffer, and
therefore must not block. Yet that is exactly what it does.

This was a regression that introduced by upgrading from MSYS2 runtime
v3.3.*. After a tedious, multi-day bisection session, the commit
introducing that regression was identified as 9078882 (Cygwin: pipe:
Restore blocking mode for cygwin process at startup., 2021-11-17), which
we hereby revert.

So what bug does this reversion reintroduce?

The commit seems to have been in response to
https://inbox.sourceware.org/cygwin/CAEv6GOB8PXHgHoz7hdJy6Bia2GWEmUDnTd252gTGinz2vuv=hA@mail.gmail.com/
which reported a bug when a C# program writes 0-byte content to a Cygwin
pipe. (Irony of ironies, this report originated from Git's realm, over
at git-ecosystem/git-credential-manager#509.)

The analysis revealed, back in December '21, that a `CYGWIN=pipe_byte`
would work around the bug, too, but that did not fix the regression in
Git's test suite.

That leaves us with the somewhat unsatisfying conclusion that we _might_
reintroduce a regression when Git Credential Manager tries to talk to an
_MSYS_ `git.exe`. But since we do not need that in Git for Windows, and
since we need to have CI builds that do not time out after 6h causing
failures, it is better to revert that commit, and in the hopefully
unlikely event that this causes _other_ problems in Git for Windows'
ecosystem, we will simply have to revisit this issue in more depth.

This fixes git-for-windows/git#4422.

Signed-off-by: Johannes Schindelin <[email protected]>
dscho added a commit to dscho/msys2-runtime that referenced this issue Jun 16, 2023
…rtup."

When Git for Windows upgraded its MSYS2 runtime from v3.3.* to v3.4.* at
long last, the t3701-add-interactive test of Git's test suite started to
hang consistently, timing out.

The culprit is a `git add -p` call that wants to read from a diff
filter. This diff filter is `cat.exe`, i.e. nothing special, but that
diff filter gets input that is larger than the pipe buffer, and
therefore must not block. Yet that is exactly what it does.

This was a regression that introduced by upgrading from MSYS2 runtime
v3.3.*. After a tedious, multi-day bisection session, the commit
introducing that regression was identified as 9078882 (Cygwin: pipe:
Restore blocking mode for cygwin process at startup., 2021-11-17), which
we hereby revert.

So what bug does this reversion reintroduce?

The commit seems to have been in response to
https://inbox.sourceware.org/cygwin/CAEv6GOB8PXHgHoz7hdJy6Bia2GWEmUDnTd252gTGinz2vuv=hA@mail.gmail.com/
which reported a bug when a C# program writes 0-byte content to a Cygwin
pipe. (Irony of ironies, this report originated from Git's realm, over
at git-ecosystem/git-credential-manager#509.)

The analysis revealed, back in December '21, that a `CYGWIN=pipe_byte`
would work around the bug, too, but that did not fix the regression in
Git's test suite.

That leaves us with the somewhat unsatisfying conclusion that we _might_
reintroduce a regression when Git Credential Manager tries to talk to an
_MSYS_ `git.exe`. But since we do not need that in Git for Windows, and
since we need to have CI builds that do not time out after 6h causing
failures, it is better to revert that commit, and in the hopefully
unlikely event that this causes _other_ problems in Git for Windows'
ecosystem, we will simply have to revisit this issue in more depth.

This fixes git-for-windows/git#4422.

Signed-off-by: Johannes Schindelin <[email protected]>
dscho added a commit to dscho/msys2-runtime that referenced this issue Jun 19, 2023
…rtup."

When Git for Windows upgraded its MSYS2 runtime from v3.3.* to v3.4.* at
long last, the t3701-add-interactive test of Git's test suite started to
hang consistently, timing out.

The culprit is a `git add -p` call that wants to read from a diff
filter. This diff filter is `cat.exe`, i.e. nothing special, but that
diff filter gets input that is larger than the pipe buffer, and
therefore must not block. Yet that is exactly what it does.

This was a regression that introduced by upgrading from MSYS2 runtime
v3.3.*. After a tedious, multi-day bisection session, the commit
introducing that regression was identified as 9078882 (Cygwin: pipe:
Restore blocking mode for cygwin process at startup., 2021-11-17), which
we hereby revert.

So what bug does this reversion reintroduce?

The commit seems to have been in response to
https://inbox.sourceware.org/cygwin/CAEv6GOB8PXHgHoz7hdJy6Bia2GWEmUDnTd252gTGinz2vuv=hA@mail.gmail.com/
which reported a bug when a C# program writes 0-byte content to a Cygwin
pipe. (Irony of ironies, this report originated from Git's realm, over
at git-ecosystem/git-credential-manager#509.)

The analysis revealed, back in December '21, that a `CYGWIN=pipe_byte`
would work around the bug, too, but that did not fix the regression in
Git's test suite.

That leaves us with the somewhat unsatisfying conclusion that we _might_
reintroduce a regression when Git Credential Manager tries to talk to an
_MSYS_ `git.exe`. But since we do not need that in Git for Windows, and
since we need to have CI builds that do not time out after 6h causing
failures, it is better to revert that commit, and in the hopefully
unlikely event that this causes _other_ problems in Git for Windows'
ecosystem, we will simply have to revisit this issue in more depth.

This fixes git-for-windows/git#4422.

Signed-off-by: Johannes Schindelin <[email protected]>
dscho added a commit to dscho/msys2-runtime that referenced this issue Sep 6, 2023
…rtup."

When Git for Windows upgraded its MSYS2 runtime from v3.3.* to v3.4.* at
long last, the t3701-add-interactive test of Git's test suite started to
hang consistently, timing out.

The culprit is a `git add -p` call that wants to read from a diff
filter. This diff filter is `cat.exe`, i.e. nothing special, but that
diff filter gets input that is larger than the pipe buffer, and
therefore must not block. Yet that is exactly what it does.

This was a regression that introduced by upgrading from MSYS2 runtime
v3.3.*. After a tedious, multi-day bisection session, the commit
introducing that regression was identified as 9078882 (Cygwin: pipe:
Restore blocking mode for cygwin process at startup., 2021-11-17), which
we hereby revert.

So what bug does this reversion reintroduce?

The commit seems to have been in response to
https://inbox.sourceware.org/cygwin/CAEv6GOB8PXHgHoz7hdJy6Bia2GWEmUDnTd252gTGinz2vuv=hA@mail.gmail.com/
which reported a bug when a C# program writes 0-byte content to a Cygwin
pipe. (Irony of ironies, this report originated from Git's realm, over
at git-ecosystem/git-credential-manager#509.)

The analysis revealed, back in December '21, that a `CYGWIN=pipe_byte`
would work around the bug, too, but that did not fix the regression in
Git's test suite.

That leaves us with the somewhat unsatisfying conclusion that we _might_
reintroduce a regression when Git Credential Manager tries to talk to an
_MSYS_ `git.exe`. But since we do not need that in Git for Windows, and
since we need to have CI builds that do not time out after 6h causing
failures, it is better to revert that commit, and in the hopefully
unlikely event that this causes _other_ problems in Git for Windows'
ecosystem, we will simply have to revisit this issue in more depth.

This fixes git-for-windows/git#4422.

Signed-off-by: Johannes Schindelin <[email protected]>
dscho added a commit to dscho/msys2-runtime that referenced this issue Nov 29, 2023
…rtup."

When Git for Windows upgraded its MSYS2 runtime from v3.3.* to v3.4.* at
long last, the t3701-add-interactive test of Git's test suite started to
hang consistently, timing out.

The culprit is a `git add -p` call that wants to read from a diff
filter. This diff filter is `cat.exe`, i.e. nothing special, but that
diff filter gets input that is larger than the pipe buffer, and
therefore must not block. Yet that is exactly what it does.

This was a regression that introduced by upgrading from MSYS2 runtime
v3.3.*. After a tedious, multi-day bisection session, the commit
introducing that regression was identified as 9078882 (Cygwin: pipe:
Restore blocking mode for cygwin process at startup., 2021-11-17), which
we hereby revert.

So what bug does this reversion reintroduce?

The commit seems to have been in response to
https://inbox.sourceware.org/cygwin/CAEv6GOB8PXHgHoz7hdJy6Bia2GWEmUDnTd252gTGinz2vuv=hA@mail.gmail.com/
which reported a bug when a C# program writes 0-byte content to a Cygwin
pipe. (Irony of ironies, this report originated from Git's realm, over
at git-ecosystem/git-credential-manager#509.)

The analysis revealed, back in December '21, that a `CYGWIN=pipe_byte`
would work around the bug, too, but that did not fix the regression in
Git's test suite.

That leaves us with the somewhat unsatisfying conclusion that we _might_
reintroduce a regression when Git Credential Manager tries to talk to an
_MSYS_ `git.exe`. But since we do not need that in Git for Windows, and
since we need to have CI builds that do not time out after 6h causing
failures, it is better to revert that commit, and in the hopefully
unlikely event that this causes _other_ problems in Git for Windows'
ecosystem, we will simply have to revisit this issue in more depth.

This fixes git-for-windows/git#4422.

Signed-off-by: Johannes Schindelin <[email protected]>
dscho added a commit to dscho/Cygwin-msys2-fork that referenced this issue Dec 2, 2023
…rtup."

When Git for Windows upgraded its MSYS2 runtime from v3.3.* to v3.4.* at
long last, the t3701-add-interactive test of Git's test suite started to
hang consistently, timing out.

The culprit is a `git add -p` call that wants to read from a diff
filter. This diff filter is `cat.exe`, i.e. nothing special, but that
diff filter gets input that is larger than the pipe buffer, and
therefore must not block. Yet that is exactly what it does.

This was a regression that introduced by upgrading from MSYS2 runtime
v3.3.*. After a tedious, multi-day bisection session, the commit
introducing that regression was identified as 9078882 (Cygwin: pipe:
Restore blocking mode for cygwin process at startup., 2021-11-17), which
we hereby revert.

So what bug does this reversion reintroduce?

The commit seems to have been in response to
https://inbox.sourceware.org/cygwin/CAEv6GOB8PXHgHoz7hdJy6Bia2GWEmUDnTd252gTGinz2vuv=hA@mail.gmail.com/
which reported a bug when a C# program writes 0-byte content to a Cygwin
pipe. (Irony of ironies, this report originated from Git's realm, over
at git-ecosystem/git-credential-manager#509.)

The analysis revealed, back in December '21, that a `CYGWIN=pipe_byte`
would work around the bug, too, but that did not fix the regression in
Git's test suite.

That leaves us with the somewhat unsatisfying conclusion that we _might_
reintroduce a regression when Git Credential Manager tries to talk to an
_MSYS_ `git.exe`. But since we do not need that in Git for Windows, and
since we need to have CI builds that do not time out after 6h causing
failures, it is better to revert that commit, and in the hopefully
unlikely event that this causes _other_ problems in Git for Windows'
ecosystem, we will simply have to revisit this issue in more depth.

This fixes git-for-windows/git#4422.

Signed-off-by: Johannes Schindelin <[email protected]>
dscho added a commit to dscho/msys2-runtime that referenced this issue Aug 30, 2024
…rtup."

When Git for Windows upgraded its MSYS2 runtime from v3.3.* to v3.4.* at
long last, the t3701-add-interactive test of Git's test suite started to
hang consistently, timing out.

The culprit is a `git add -p` call that wants to read from a diff
filter. This diff filter is `cat.exe`, i.e. nothing special, but that
diff filter gets input that is larger than the pipe buffer, and
therefore must not block. Yet that is exactly what it does.

This was a regression that introduced by upgrading from MSYS2 runtime
v3.3.*. After a tedious, multi-day bisection session, the commit
introducing that regression was identified as 9078882 (Cygwin: pipe:
Restore blocking mode for cygwin process at startup., 2021-11-17), which
we hereby revert.

So what bug does this reversion reintroduce?

The commit seems to have been in response to
https://inbox.sourceware.org/cygwin/CAEv6GOB8PXHgHoz7hdJy6Bia2GWEmUDnTd252gTGinz2vuv=hA@mail.gmail.com/
which reported a bug when a C# program writes 0-byte content to a Cygwin
pipe. (Irony of ironies, this report originated from Git's realm, over
at git-ecosystem/git-credential-manager#509.)

The analysis revealed, back in December '21, that a `CYGWIN=pipe_byte`
would work around the bug, too, but that did not fix the regression in
Git's test suite.

That leaves us with the somewhat unsatisfying conclusion that we _might_
reintroduce a regression when Git Credential Manager tries to talk to an
_MSYS_ `git.exe`. But since we do not need that in Git for Windows, and
since we need to have CI builds that do not time out after 6h causing
failures, it is better to revert that commit, and in the hopefully
unlikely event that this causes _other_ problems in Git for Windows'
ecosystem, we will simply have to revisit this issue in more depth.

This fixes git-for-windows/git#4422.

Signed-off-by: Johannes Schindelin <[email protected]>
dscho added a commit to dscho/msys2-runtime that referenced this issue Sep 5, 2024
…rtup."

When Git for Windows upgraded its MSYS2 runtime from v3.3.* to v3.4.* at
long last, the t3701-add-interactive test of Git's test suite started to
hang consistently, timing out.

The culprit is a `git add -p` call that wants to read from a diff
filter. This diff filter is `cat.exe`, i.e. nothing special, but that
diff filter gets input that is larger than the pipe buffer, and
therefore must not block. Yet that is exactly what it does.

This was a regression that introduced by upgrading from MSYS2 runtime
v3.3.*. After a tedious, multi-day bisection session, the commit
introducing that regression was identified as 9078882 (Cygwin: pipe:
Restore blocking mode for cygwin process at startup., 2021-11-17), which
we hereby revert.

So what bug does this reversion reintroduce?

The commit seems to have been in response to
https://inbox.sourceware.org/cygwin/CAEv6GOB8PXHgHoz7hdJy6Bia2GWEmUDnTd252gTGinz2vuv=hA@mail.gmail.com/
which reported a bug when a C# program writes 0-byte content to a Cygwin
pipe. (Irony of ironies, this report originated from Git's realm, over
at git-ecosystem/git-credential-manager#509.)

The analysis revealed, back in December '21, that a `CYGWIN=pipe_byte`
would work around the bug, too, but that did not fix the regression in
Git's test suite.

That leaves us with the somewhat unsatisfying conclusion that we _might_
reintroduce a regression when Git Credential Manager tries to talk to an
_MSYS_ `git.exe`. But since we do not need that in Git for Windows, and
since we need to have CI builds that do not time out after 6h causing
failures, it is better to revert that commit, and in the hopefully
unlikely event that this causes _other_ problems in Git for Windows'
ecosystem, we will simply have to revisit this issue in more depth.

This fixes git-for-windows/git#4422.

Signed-off-by: Johannes Schindelin <[email protected]>
dscho added a commit to dscho/msys2-runtime that referenced this issue Sep 18, 2024
…rtup."

When Git for Windows upgraded its MSYS2 runtime from v3.3.* to v3.4.* at
long last, the t3701-add-interactive test of Git's test suite started to
hang consistently, timing out.

The culprit is a `git add -p` call that wants to read from a diff
filter. This diff filter is `cat.exe`, i.e. nothing special, but that
diff filter gets input that is larger than the pipe buffer, and
therefore must not block. Yet that is exactly what it does.

This was a regression that introduced by upgrading from MSYS2 runtime
v3.3.*. After a tedious, multi-day bisection session, the commit
introducing that regression was identified as 9078882 (Cygwin: pipe:
Restore blocking mode for cygwin process at startup., 2021-11-17), which
we hereby revert.

So what bug does this reversion reintroduce?

The commit seems to have been in response to
https://inbox.sourceware.org/cygwin/CAEv6GOB8PXHgHoz7hdJy6Bia2GWEmUDnTd252gTGinz2vuv=hA@mail.gmail.com/
which reported a bug when a C# program writes 0-byte content to a Cygwin
pipe. (Irony of ironies, this report originated from Git's realm, over
at git-ecosystem/git-credential-manager#509.)

The analysis revealed, back in December '21, that a `CYGWIN=pipe_byte`
would work around the bug, too, but that did not fix the regression in
Git's test suite.

That leaves us with the somewhat unsatisfying conclusion that we _might_
reintroduce a regression when Git Credential Manager tries to talk to an
_MSYS_ `git.exe`. But since we do not need that in Git for Windows, and
since we need to have CI builds that do not time out after 6h causing
failures, it is better to revert that commit, and in the hopefully
unlikely event that this causes _other_ problems in Git for Windows'
ecosystem, we will simply have to revisit this issue in more depth.

This fixes git-for-windows/git#4422.

Signed-off-by: Johannes Schindelin <[email protected]>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
auth-issue An issue authenticating to a host
Projects
None yet
Development

No branches or pull requests

5 participants