WSL is used where it shouldn't, causing 30s idle

[JeroenBos]

The problem

Since 3.2.2 or 3.2.3 I observe a regression, namely that squashing commits, or in general rebasing, takes very long in the presence of a post-checkout bash script hook. There is some sort of timeout going on where you have to wait for pretty much exactly 30 seconds.

Release version

3.2.3 (x64)

Operating system

Windows 10

Steps to reproduce the behavior

• Assume a linear git history.
• Create a file ./.git/hooks/post-checkout with the contents #!/bin/bash (nothing else)
• Drag the latest commit over the second latest commit (to initiate a squash).
• Click "Squash 2 commits"

Observe that the "Squash in progress" dialog takes 30 seconds.

Log files

2023-05-11T13:31:15.125Z - info: [main] Using toast activator CLSID {27D44D0C-A542-5B90-BCDB-AC3126048BA2}
2023-05-11T13:31:15.393Z - info: [ui] [AppStore] loading 24 repositories from store
2023-05-11T13:31:15.394Z - info: [ui] [AppStore] found account: JeroenBos (Jeroen Bos)
2023-05-11T13:31:15.408Z - info: [ui] [BranchPruner] Last prune took place 3 hours ago - skipping
2023-05-11T13:31:15.817Z - warn: [ui] Error refreshing account 'JeroenBos'
Error: Cannot update an account which doesn't have a token: JeroenBos
    at it (C:\Users\Windows\AppData\Local\GitHubDesktop\app-3.2.3\webpack:\app\src\lib\fatal-error.ts:3:9)
    at C:\Users\Windows\AppData\Local\GitHubDesktop\app-3.2.3\webpack:\app\src\lib\stores\accounts-store.ts:214:12
    at ir.tryUpdateAccount (C:\Users\Windows\AppData\Local\GitHubDesktop\app-3.2.3\webpack:\app\src\lib\stores\accounts-store.ts:134:20)
    at C:\Users\Windows\AppData\Local\GitHubDesktop\app-3.2.3\webpack:\app\src\lib\stores\accounts-store.ts:114:37
    at Array.map (<anonymous>)
    at ir.refresh (C:\Users\Windows\AppData\Local\GitHubDesktop\app-3.2.3\webpack:\app\src\lib\stores\accounts-store.ts:114:21)
    at ir.loadInitialState (C:\Users\Windows\AppData\Local\GitHubDesktop\app-3.2.3\webpack:\app\src\lib\stores\app-store.ts:2110:24)
2023-05-11T13:31:15.879Z - warn: [ui] fetchAll: 'repos/JeroenBos/JBNA/issues?state=open' returned a 404
2023-05-11T13:31:15.890Z - info: [ui] [fetchProtectedBranches] unable to list protected branches
Error: Not Found
    at Bt (C:\Users\Windows\AppData\Local\GitHubDesktop\app-3.2.3\webpack:\app\src\lib\http.ts:178:11)
    at En.fetchProtectedBranches (C:\Users\Windows\AppData\Local\GitHubDesktop\app-3.2.3\webpack:\app\src\lib\api.ts:1548:7)
    at ir.updateBranchProtectionsFromAPI (C:\Users\Windows\AppData\Local\GitHubDesktop\app-3.2.3\webpack:\app\src\lib\stores\app-store.ts:3962:11)
2023-05-11T13:31:15.912Z - info: [ui] launching: 3.2.3 (Windows 10.0.19044)
2023-05-11T13:31:15.920Z - info: [ui] execPath: 'C:\Users\Windows\AppData\Local\GitHubDesktop\app-3.2.3\GitHubDesktop.exe'
2023-05-11T13:31:16.011Z - warn: [ui] Alive channel request failed: Error: Not Found
2023-05-11T13:31:16.042Z - warn: [ui] fetchRepository: 'JeroenBos/JBNA' returned a 404
2023-05-11T13:31:16.066Z - warn: [ui] Alive channel request failed: Error: Not Found
2023-05-11T13:31:16.078Z - warn: [ui] fetchAll: 'repos/JeroenBos/JBNA/pulls?state=open' returned a 404
2023-05-11T13:31:16.090Z - warn: [ui] Alive channel request failed: Error: Not Found
2023-05-11T13:31:16.118Z - warn: [ui] Alive channel request failed: Error: Not Found
2023-05-11T13:31:20.437Z - info: [ui] [Timing] Action 'create commit' for 'JeroenBos/JBNA' took 0.001s
2023-05-11T13:31:20.693Z - info: [ui] [squash] starting rebase for format at e46e133de43ab86759506eec3b3ff635e5c24ef0
2023-05-11T13:31:20.694Z - info: [ui] [squash] to restore the previous state if this completed rebase is unsatisfactory:
2023-05-11T13:31:20.694Z - info: [ui] [squash] - git checkout format
2023-05-11T13:31:20.694Z - info: [ui] [squash] - git reset e46e133de43ab86759506eec3b3ff635e5c24ef0 --hard
2023-05-11T13:31:22.833Z - error: [ui] `git -c credential.helper= fetch --progress --prune --recurse-submodules=on-demand origin` exited with an unexpected code: 128.
stderr:
git@github.com: Permission denied (publickey).
fatal: Could not read from remote repository.

Please make sure you have the correct access rights
and the repository exists.

(The error was parsed as 2: Authentication failed. Some common reasons include:

- You are not logged in to your account: see File > Options.
- You may need to log out and log back in to refresh your token.
- You do not have permission to access this repository.
- The repository is archived on GitHub. Check the repository settings to confirm you are still permitted to push commits.
- If you use SSH authentication, check that your key is added to the ssh-agent and associated with your account.
- If you use SSH authentication, ensure the host key verification passes for your repository hosting service.
- If you used username / password authentication, you might need to use a Personal Access Token instead of your account password. Check the documentation of your repository hosting service.)
2023-05-11T13:31:23.854Z - info: [ui] [fetchPushControl] unable to check if branch is potentially pushable
Error: Not Found
    at Bt (C:\Users\Windows\AppData\Local\GitHubDesktop\app-3.2.3\webpack:\app\src\lib\http.ts:178:11)
    at En.fetchPushControl (C:\Users\Windows\AppData\Local\GitHubDesktop\app-3.2.3\webpack:\app\src\lib\api.ts:1522:7)
    at ir.refreshBranchProtectionState (C:\Users\Windows\AppData\Local\GitHubDesktop\app-3.2.3\webpack:\app\src\lib\stores\app-store.ts:1148:39)
    at C:\Users\Windows\AppData\Local\GitHubDesktop\app-3.2.3\webpack:\app\src\lib\stores\app-store.ts:4852:32
    at ir.withPushPullFetch (C:\Users\Windows\AppData\Local\GitHubDesktop\app-3.2.3\webpack:\app\src\lib\stores\app-store.ts:4367:5)
    at ir.performFetch (C:\Users\Windows\AppData\Local\GitHubDesktop\app-3.2.3\webpack:\app\src\lib\stores\app-store.ts:4808:5)
    at Mo.performAndScheduleFetch (C:\Users\Windows\AppData\Local\GitHubDesktop\app-3.2.3\webpack:\app\src\lib\stores\helpers\background-fetcher.ts:102:7)
2023-05-11T13:31:39.742Z - info: [ui] [Timing] Action 'create commit' for 'JeroenBos/JBNA' took 0.000s
2023-05-11T13:32:10.462Z - info: [ui] Executing Squash: git -c sequence.editor=cat "C:\Users\Windows\AppData\Local\Temp\squashTodo-j9Zonk\squashTodo" > rebase -i 3f75247f48251bd436af366b06673a9a28e16ca1^ (took 30.677s)
2023-05-11T13:32:10.468Z - info: [ui] [squash] starting rebase for format at e46e133de43ab86759506eec3b3ff635e5c24ef0
2023-05-11T13:32:10.468Z - info: [ui] [squash] to restore the previous state if this completed rebase is unsatisfactory:
2023-05-11T13:32:10.468Z - info: [ui] [squash] - git checkout format
2023-05-11T13:32:10.468Z - info: [ui] [squash] - git reset e46e133de43ab86759506eec3b3ff635e5c24ef0 --hard

Screenshots

No response

Additional context

The timeout does not occur when

• there is no post checkout hook
• the hook does not start with #!/bin/bash (but e.g. with #!/bin/sh)

EDIT: I have it with normal commits too, not just rebases.

[steveward]

@JeroenBos thanks for the issue! Could you upload the log file from GitHub Desktop so that I could see if that shows anything interesting? To access the log files go to the file menu in GitHub Desktop and select Help > Show Logs. The log files are created daily -- please upload a log file as an attachment from a day where you experienced the issue.

[JeroenBos]

I edited my post and added minimal logs. As a description of what I did:
I did the squash operation twice:

• once with the contents of the hook being #!/bin/sh, which was pretty much instantaneous
• once with the contents of the hook being #!/bin/bash, which has the 30 second timeout (even with empty ~/.bashrc)

I see that the logs are about ssh, so I'll add some related information:

• I do have an ssh-agent running, with key loaded
• Other git commands or IDEs are using the ssh-agent without problem.

[JeroenBos]

I rebuilt an older version (3.2.0) from source, as I'm certain I didn't have the above behavior yet in that timeframe. I could still observe it with that version, so I concluce it has nothing to do with GitHub Desktop, and I'll have to look elsewhere for this puzzling behavior. Sorry for the inconvenience.

[JeroenBos]

Well, I am starting to think it is related to GitHub desktop.

A git commit command from shell works fine, no idling. A commit from GitHub Desktop idles, and I've figured out that it is related to WSL2.

Somehow the bash vs sh difference triggers WSL in GitHub desktop, but not in regular git usage.

I found out by disabling hyperv in BIOS, after which committing in GitHub desktop gave me the following error:

2023-05-16T10:46:54.318Z - error: [ui] `git commit -F -` exited with an unexpected code: 1.
stderr:
WSL2 is not supported with your current machine configuration.
Please enable the "Virtual Machine Platform" optional component and ensure virtualization is enabled in the BIOS.
For information please visit https://aka.ms/enablevirtualization
Error code: Bash/Service/CreateInstance/CreateVm/0x80370102

After uninstalling WSL (properly, as in including unticking the “Windows Subsystem for Linux” option in the Windows Features dialog box), this issue was resolved.

Now, I don't use WSL for anything. Admittedly I had installed it to try something, and ever since I've been having this issue with GitHub Desktop, but I didn't think of it. Merely installing WSL2 shouldn't affect GitHub Desktop imho.

[JeroenBos]

What I think is going on:

• we have in the logs:
  git -c credential.helper= fetch --progress --prune --recurse-submodules=on-demand origin

That hangs. Possibly that trying to execute something in WSL hangs (because it isn't running on my system), or maybe it is started and then it hangs on the message Enter passphrase for ~/.ssh/id_rsa: as WSL for sure can't find the ssh-agent (which is running on the Windows side). Either could explain the the 30s wait. The problem is that it shouldn't be using WSL for anything in the first place.