Repository.show() returns wrong file contents to GHPRI extension

[joyceerhl]

In the latest RemoteHub pre-release, https://insiders.vscode.dev/github/microsoft/vscode/pull/142606 turns up no diff on the first try, then an empty LHS on the second try.

[joyceerhl]

I cannot reproduce this in desktop, but am seeing some very fishy behavior in web:

This pull request only contains one commit, c496ed0cb34285e4e6f090443aff77d2de894ebe. The current main branch of vscode has HEAD sha 80fd8b36eae911fe31216eb9b095ab7da5378086. 8d9562 is a slightly older commit in main.

[joyceerhl]

That error message comes from: https://github.com/microsoft/vscode-pull-request-github/blob/dae6028f027a7500be09045b5f2b6294d7f0355a/src/view/gitContentProvider.ts#L54-L58 The message is a bit misleading since there is no 'local' repository when running in web.

There's two mysteries here:

1. Why is no Repository object returned sometimes? I see a reference in GHPRI to vscode.Uri.file, which is a bit suspect since that returns file:// URIs and RemoteHub has vscode-vfs:// URIs, but the getRepositoryForFile function seems to look at the uri.path so that should be fine... Possibly race condition with initializing the IGit API?
2. Why is GHPRI asking RemoteHub to getObjectDetails for 8d9562?

[joyceerhl]

Now I also see the LHS of the first diff coming back empty for other PRs like https://github.dev/dotnet/roslyn/pull/57667

[alexr00]

Possibly race condition with initializing the IGit API?

Yes, I'm pretty sure that's what this is. I have an issue for it so I'll try to fix it today: microsoft/vscode-pull-request-github#3242. This notification occurs when you refresh a tab with a PR in it and the diff editor tries to restore. Because there's a race, we don't have the required information yet to restore.

I don't think this message is related since the inputs I could see going into Repository.show when a PR in the tree is clicked on look correct.

I could repro the left hand being empty or wrong for many PRs.

[alexr00]

Why is GHPRI asking RemoteHub to getObjectDetails for 8d9562

When I test this scenario the commit in the error the message is the commit of the "into" branch, which is correct.

[alexr00]

Worth clarifying: when this happens it is not only the first diff, it is all diffs in the PR.

I've added the following log line:

[Info] GitContentFileSystemProvider> Getting repository (vscode-vfs://github%2B7b2276223a312c22726566223a7b2274797065223a332c226964223a22313432363036227d7d/microsoft/vscode) content for commit ec9df1d972f05f960a2f4660e6feca1ebf20d39a and path /microsoft/vscode/src/vs/workbench/api/browser/mainThreadAuthentication.ts

right before calling repository.show. This lets us confirm:

• That we actually have a repository
• The commit. This should be the commit from the base branch that the PR compares against, ie., the parent of the first commit in the PR.
• The file in question.

All the arguments for this look correct to me.

I am kicking off a new pre-release build of GHPRI with this logging + the fix for microsoft/vscode-pull-request-github#3242.

[joyceerhl]

If I sign out of GitHub for all extensions and then reload the page, I'm still seeing the LHS open completely empty and the error about not being able to find an open repository locally, with GHPRI v0.37.2022021409. When that happens, this is what the GHPRI log says:

[Info] TemporaryState> Error in initialization: Unable to delete nonexistent file 'vscode-userdata:/User/globalStorage/github.vscode-pull-request-github/temp'
[Info] Looking for git repository
[Info] Found 0 repositories during activation
[Info] Git repository found, initializing review manager and pr tree view.
[Info] Registering git provider
[Info] GitContentFileSystemProvider> Waiting for repositories.
[Info] GitContentFileSystemProvider> Timed out while waiting for repositories.
[Info] Repository vscode-vfs://github%2B7b2276223a312c22726566223a7b2274797065223a332c226964223a223537363637227d7d/dotnet/roslyn has been opened
[Info] Review> Validate state in progress
[Info] Review> Validating state...
[Info] Found GitHub remote
[Info] Review> current branch metadataOnlyEmitXmlDocs is associated with pull request #57667
[Info] Review> Resolving pull request
[Info] Review> Queuing additional validate state
[Info] Review> Queuing additional validate state
[Info] Found GitHub remote
[Info] Found GitHub remote
[Info] Found GitHub remote
[Info] Found GitHub remote
[Info] Review> Fetching pull request data
[Info] Review> register comments provider
[Info] Review> display pull request status bar indicator and refresh pull request tree view.
[Info] Review> using focus mode = true.
[Info] Review> state validation silent = true.
[Info] Review> PR show should show = https://github.com/dotnet/roslyn/pull/57667.
[Info] Review> Validating state...
[Info] Found GitHub remote
[Info] Trying to use globalState for mentionable users.
[Info] Using globalState mentionable users for 1.
[Info] Review> Validating state...
[Info] Found GitHub remote
[Info] Trying to use globalState for mentionable users.
[Info] Using globalState mentionable users for 1.
[Info] Repo state for vscode-vfs://github%2B7b2276223a312c22726566223a7b2274797065223a332c226964223a223537363637227d7d/dotnet/roslyn changed.
[Info] Repo vscode-vfs://github%2B7b2276223a312c22726566223a7b2274797065223a332c226964223a223537363637227d7d/dotnet/roslyn has already been setup.

Then when I reload the page again, I am already signed in, now I see a diff view with no changes, but only for the first file that is opened in the diff editor. All subsequent changed files do have the right contents, and additionally closing and reopening the first diff results in the right contents being shown...

[Info] TemporaryState> Error in initialization: Unable to delete nonexistent file 'vscode-userdata:/User/globalStorage/github.vscode-pull-request-github/temp'
[Info] Looking for git repository
[Info] Found 0 repositories during activation
[Info] Git repository found, initializing review manager and pr tree view.
[Info] Registering git provider
[Info] Review> Validate state in progress
[Info] Review> Validating state...
[Info] Found GitHub remote
[Info] Review> current branch metadataOnlyEmitXmlDocs is associated with pull request #57667
[Info] Review> Resolving pull request
[Info] Review> Fetching pull request data
[Info] Review> register comments provider
[Info] Review> display pull request status bar indicator and refresh pull request tree view.
[Info] Review> using focus mode = true.
[Info] Review> state validation silent = true.
[Info] Review> PR show should show = https://github.com/dotnet/roslyn/pull/57667.
[Info] Repo state for vscode-vfs://github%2B7b2276223a312c22726566223a7b2274797065223a332c226964223a223537363637227d7d/dotnet/roslyn changed.
[Info] Repo vscode-vfs://github%2B7b2276223a312c22726566223a7b2274797065223a332c226964223a223537363637227d7d/dotnet/roslyn has already been setup.
[Info] GitContentFileSystemProvider> Getting repository (vscode-vfs://github%2B7b2276223a312c22726566223a7b2274797065223a332c226964223a223537363637227d7d/dotnet/roslyn) content for commit aad378eca3bdbf9dc369c015b0668a778b0dd2e4 and path /dotnet/roslyn/src/Compilers/CSharp/Portable/Compilation/CSharpCompilation.cs

and (truncated for length) RemoteHub logs are:

[2022-02-14 17:41:50:680] [  122] IGit.getObjectDetails(aad378eca3bdbf9dc369c015b0668a778b0dd2e4, src/Compilers/CSharp/Portable/Compilation/CSharpCompilation.cs)
[2022-02-14 17:41:50:681] [  124] GitHub.createFileTree(github://github%2B7b2276223a312c22726566223a7b2274797065223a332c226964223a223537363637227d7d/dotnet/roslyn:aad378eca3bdbf9dc369c015b0668a778b0dd2e4)
[2022-02-14 17:41:50:681] [  125] FileTree.load(aad378eca3bdbf9dc369c015b0668a778b0dd2e4:undefined)
[2022-02-14 17:41:50:682] [  124] GitHub.createFileTree(github://github%2B7b2276223a312c22726566223a7b2274797065223a332c226964223a223537363637227d7d/dotnet/roslyn:aad378eca3bdbf9dc369c015b0668a778b0dd2e4) took 0 ms
[2022-02-14 17:41:50:682] [  123] GitHub.getFileTree(github://github%2B7b2276223a312c22726566223a7b2274797065223a332c226964223a223537363637227d7d/dotnet/roslyn:aad378eca3bdbf9dc369c015b0668a778b0dd2e4): vscode-vfs://github%2B7b2276223a312c22726566223a7b2274797065223a332c226964223a223537363637227d7d/dotnet/roslyn took 0 ms
[2022-02-14 17:41:50:740] [  126] [GITHUB] GET /repos/{owner}/{repo}/git/trees/{tree_sha} took 58 ms
[2022-02-14 17:41:50:741] [  125] FileTree.load(aad378eca3bdbf9dc369c015b0668a778b0dd2e4:undefined): Tree=aad378eca3bdbf9dc369c015b0668a778b0dd2e4; Tree query took 59 ms • Waiting for permissions...
[2022-02-14 17:41:50:741] [  125] FileTree.load(aad378eca3bdbf9dc369c015b0668a778b0dd2e4:undefined) Permissions query took 0 ms • Filling trie...
[2022-02-14 17:41:50:741] [  125] FileTree.load(aad378eca3bdbf9dc369c015b0668a778b0dd2e4:undefined) took 59 ms (Filling trie took 0 ms) • Tree=aad378eca3bdbf9dc369c015b0668a778b0dd2e4
[2022-02-14 17:41:50:741] [  127] FileTree.load(aad378eca3bdbf9dc369c015b0668a778b0dd2e4:src)
[2022-02-14 17:41:50:743] [  121] [GITHUB] POST /graphql query getRemoteBranchTips took 291 ms
[2022-02-14 17:41:50:743] [  120] GitHub.fetch(vscode-vfs://github%2B7b2276223a312c22726566223a7b2274797065223a332c226964223a223537363637227d7d/dotnet/roslyn, force=undefined, to=undefined) took 296 ms • Up to date
[2022-02-14 17:41:50:743] [  129] VirtualProviderService.updateMetadata(vscode-vfs://github%2B7b2276223a312c22726566223a7b2274797065223a332c226964223a223537363637227d7d/dotnet/roslyn) — c4591e910af9c444c8f8baa4bdf5523ae5625ab5
[2022-02-14 17:41:50:743] [  130] MementoStorage.store(metadata/vscode-vfs://github%2B7b2276223a312c22726566223a7b2274797065223a332c226964223a223537363637227d7d/dotnet/roslyn): scopedKey=5ec3b4c1/metadata/vscode-vfs://github%2B7b2276223a312c22726566223a7b2274797065223a332c226964223a223537363637227d7d/dotnet/roslyn
[2022-02-14 17:41:50:937] [  130] MementoStorage.store(metadata/vscode-vfs://github%2B7b2276223a312c22726566223a7b2274797065223a332c226964223a223537363637227d7d/dotnet/roslyn): scopedKey=5ec3b4c1/metadata/vscode-vfs://github%2B7b2276223a312c22726566223a7b2274797065223a332c226964223a223537363637227d7d/dotnet/roslyn took 193 ms
[2022-02-14 17:41:50:937] [  129] VirtualProviderService.updateMetadata(vscode-vfs://github%2B7b2276223a312c22726566223a7b2274797065223a332c226964223a223537363637227d7d/dotnet/roslyn) took 194 ms
[2022-02-14 17:41:50:957] VirtualProviderService.onMetadataChanged(vscode-vfs://github%2B7b2276223a312c22726566223a7b2274797065223a332c226964223a223537363637227d7d/dotnet/roslyn, reason=undefined): Firing onDidChangeRepository...
[2022-02-14 17:41:50:957] [  131] (A) Writer(3|WorkspaceRepositories) • WorkspaceRepositories.addOrUpdate
[2022-02-14 17:41:50:957] [  132] RichNavIndexProvider.createIndexMetadata(vscode-vfs://github%2B7b2276223a312c22726566223a7b2274797065223a332c226964223a223537363637227d7d/dotnet/roslyn)
[2022-02-14 17:41:50:959] [  131] (L) Writer(3|WorkspaceRepositories) waited for 2 ms • WorkspaceRepositories.addOrUpdate
[2022-02-14 17:41:50:959] [  133] MementoStorage.get(workspaceRepositories): scopedKey=workspaceRepositories
[2022-02-14 17:41:50:961] [  133] MementoStorage.get(workspaceRepositories): scopedKey=workspaceRepositories took 1 ms
[2022-02-14 17:41:50:965] [  132] RichNavIndexProvider.createIndexMetadata(vscode-vfs://github%2B7b2276223a312c22726566223a7b2274797065223a332c226964223a223537363637227d7d/dotnet/roslyn) Getting metadata took 7 ms • Getting snapshot...
[2022-02-14 17:41:50:965] [  134] GitHub.ensureAuthenticated
[2022-02-14 17:41:50:965] [  134] GitHub.ensureAuthenticated took 0 ms
[2022-02-14 17:41:50:971] [  132] RichNavIndexProvider.createIndexMetadata(vscode-vfs://github%2B7b2276223a312c22726566223a7b2274797065223a332c226964223a223537363637227d7d/dotnet/roslyn) Getting snapshot took 6 ms • Getting mode config...
[2022-02-14 17:41:50:972] [  132] RichNavIndexProvider.createIndexMetadata(vscode-vfs://github%2B7b2276223a312c22726566223a7b2274797065223a332c226964223a223537363637227d7d/dotnet/roslyn) took 14 ms (Getting mode config took 0 ms)
[2022-02-14 17:41:50:977] [  135] (A) Reader(5|vscode-vfs://github%2B7b2276223a312c22726566223a7b2274797065223a332c226964223a223537363637227d7d/dotnet/roslyn) • ChangeStore.getChangesByType(vscode-vfs://github%2B7b2276223a312c22726566223a7b2274797065223a332c226964223a223537363637227d7d/dotnet/roslyn)
[2022-02-14 17:41:51:004] [  135] (L) Reader(5|vscode-vfs://github%2B7b2276223a312c22726566223a7b2274797065223a332c226964223a223537363637227d7d/dotnet/roslyn) waited for 26 ms • ChangeStore.getChangesByType(vscode-vfs://github%2B7b2276223a312c22726566223a7b2274797065223a332c226964223a223537363637227d7d/dotnet/roslyn)
[2022-02-14 17:41:51:004] [  136] (A) Reader(6|vscode-vfs://github%2B7b2276223a312c22726566223a7b2274797065223a332c226964223a223537363637227d7d/dotnet/roslyn) • ChangeStore.getChanges(vscode-vfs://github%2B7b2276223a312c22726566223a7b2274797065223a332c226964223a223537363637227d7d/dotnet/roslyn)
[2022-02-14 17:41:51:005] [  135] (U) Reader(5|vscode-vfs://github%2B7b2276223a312c22726566223a7b2274797065223a332c226964223a223537363637227d7d/dotnet/roslyn) locked for 1 ms • ChangeStore.getChangesByType(vscode-vfs://github%2B7b2276223a312c22726566223a7b2274797065223a332c226964223a223537363637227d7d/dotnet/roslyn)
[2022-02-14 17:41:51:005] [  136] (L) Reader(6|vscode-vfs://github%2B7b2276223a312c22726566223a7b2274797065223a332c226964223a223537363637227d7d/dotnet/roslyn) waited for 0 ms • ChangeStore.getChanges(vscode-vfs://github%2B7b2276223a312c22726566223a7b2274797065223a332c226964223a223537363637227d7d/dotnet/roslyn)
[2022-02-14 17:41:51:007] [  136] (U) Reader(6|vscode-vfs://github%2B7b2276223a312c22726566223a7b2274797065223a332c226964223a223537363637227d7d/dotnet/roslyn) locked for 2 ms • ChangeStore.getChanges(vscode-vfs://github%2B7b2276223a312c22726566223a7b2274797065223a332c226964223a223537363637227d7d/dotnet/roslyn)
[2022-02-14 17:41:51:008] [  137] MementoStorage.store(workspaceRepositories): scopedKey=workspaceRepositories
[2022-02-14 17:41:51:092] [  128] [GITHUB] GET /repos/{owner}/{repo}/git/trees/{tree_sha} took 349 ms
[2022-02-14 17:41:51:092] [  127] FileTree.load(aad378eca3bdbf9dc369c015b0668a778b0dd2e4:src): Tree=d49d0920f5cf9c733677a9b678e60debf2e9719b; Tree query took 350 ms • Waiting for permissions...
[2022-02-14 17:41:51:092] [  127] FileTree.load(aad378eca3bdbf9dc369c015b0668a778b0dd2e4:src) Permissions query took 0 ms • Filling trie...
[2022-02-14 17:41:51:092] [  127] FileTree.load(aad378eca3bdbf9dc369c015b0668a778b0dd2e4:src) took 350 ms (Filling trie took 0 ms) • Tree=d49d0920f5cf9c733677a9b678e60debf2e9719b
[2022-02-14 17:41:51:092] [  138] FileTree.load(aad378eca3bdbf9dc369c015b0668a778b0dd2e4:src/Compilers)

[joyceerhl]

I was able to repro in vscode.dev and insiders.vscode.dev earlier today, but the repro is flaky and I can't repro anymore in insiders.vscode.dev. I still cannot repro this at all in the extension development host. I have added some debug logging in RemoteHub to continue to gather information.

[alexr00]

@alexdima has also run into this with pressing "." on https://github.com/microsoft/vscode/pull/145293/files. I was also able to repro with those steps. Interestingly, the first diff actually opens ok there, but subsequent diffs do not.

[bpasero]

I very often see no diff when I click on a change in a PR in github.dev, but it seems quite random only for some files of the PR, not all.

[joyceerhl]

Closing as duplicate of #177 which should be resolved in the latest pre-release of RemoteHub.