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

Extension incomplete after update #43813

Closed
egamma opened this Issue Feb 16, 2018 · 52 comments

Comments

Projects
None yet
@egamma
Copy link
Member

egamma commented Feb 16, 2018

pls see this issue Microsoft/vscode-tslint#324.

@egamma

This comment has been minimized.

Copy link
Member

egamma commented Feb 16, 2018

Another instance of a corrupt extension Microsoft/vscode-tslint#323 (comment).

I´m starting to think that we should have a checksum for an installed extension so that we can detect a corruption and recover from it.

@thorn0

This comment has been minimized.

Copy link

thorn0 commented Feb 16, 2018

@egamma wrote:

One more thing can you please attach the log for the shared process to #43813?

Here you are: shared.log

@sandy081

This comment has been minimized.

Copy link
Member

sandy081 commented Feb 20, 2018

@thorn0 From the logs I am guessing following:

  • You have deleted TS Lint extension from the disk
  • You installed TS Lint extension again freshly

After this, I think you have TS Lint extension working.

I would be interested to know how the extension got corrupted before above happened. We preserve logs for last 10 VS Code sessions, hoping that the corrupted extension might occurred during those 10 sessions. Can you please share the logs of the shared process from last available sessions. To get that

  • Open logs folder. Use command Open Logs Folder. This will open the logs folder for current session.
  • Go to its parent folder where you can see all sessions and you can get the logs of shared process from there.

Also, any idea if you restarted (quit and restart) VS Code while the update of TS Lint extension is happening?

@thorn0

This comment has been minimized.

Copy link

thorn0 commented Feb 20, 2018

That's what helped:

  1. I have uninstalled the extension
  2. But the corrupted folder still was there, so I deleted it myself
  3. I installed TS Lint extension again freshly

First I tried reinstalling the extension without the step 2, but it didn't help.

We preserve logs for last 10 VS Code sessions

Sorry, I open and close VS Code often enough, so there are only today's and yesterday's logs there.

any idea if you restarted (quit and restart) VS Code while the update of TS Lint extension is happening?

Probably. Extensions are updated automatically, so I don't pay much attention to their updating.
Also I had this issue: #43503

@sandy081

This comment has been minimized.

Copy link
Member

sandy081 commented Feb 20, 2018

Logs at the point of the corruption would have been helpful to know what happened. My suspect is that code would have been restarted while extension update is in progress.

@vscodebot vscodebot bot closed this Feb 27, 2018

@vscodebot

This comment has been minimized.

Copy link

vscodebot bot commented Feb 27, 2018

This issue has been closed automatically because it needs more information and has not had recent activity. See also our issue reporting guidelines.

Happy Coding!

@sandy081 sandy081 reopened this Feb 27, 2018

@sandy081 sandy081 added bug and removed needs more info labels Feb 27, 2018

@sandy081 sandy081 modified the milestones: February 2018, March 2018 Feb 27, 2018

@sandy081

This comment has been minimized.

Copy link
Member

sandy081 commented Feb 27, 2018

This will be fixed in the perspective of code got restarted while extension update is in progress.

@thorn0

This comment has been minimized.

Copy link

thorn0 commented Feb 27, 2018

Will it be something like along the lines of:

have a checksum for an installed extension so that we can detect a corruption and recover from it

?

@sandy081

This comment has been minimized.

Copy link
Member

sandy081 commented Feb 28, 2018

Hmm I suspect download was not an issue but extracting for which we do not have checksum. If there is an interruption or failure while extracting, I will not consider that as installed and remove it.

@sandy081

This comment has been minimized.

Copy link
Member

sandy081 commented Feb 28, 2018

I pushed following fix in #44471

  • Remove partially extracted extensions from the disk When there is a failure during extract or post extract

The other case that is left is when there is an abrupt shutdown of VS Code.

@ramya-rao-a

This comment has been minimized.

Copy link
Member

ramya-rao-a commented Feb 28, 2018

@sandy081 This has been happening multiple times in the Go extension as well. The extension fails to activate due to missing files. For some, uninstall -> install works. Others have to manually delete the extension from the extensions folder and then install.

Next time it happens, I'll direct them here and ask them to share the logs of the shared process

cc @octref who has seen this in the vetur extension as well

@octref

This comment has been minimized.

Copy link
Member

octref commented Feb 28, 2018

@ramya-rao-a Yeah I opened #44709...

@sandy081

For some, uninstall -> install works. Others have to manually delete the extension from the extensions folder and then install.

That's the same case with Vetur. Do you have any theory as to why in some cases, uninstall -> install works, whereas for some people they had to remove the extension folders manually?

The other case that is left is when there is an abrupt shutdown of VS Code.

Maybe a fix for that could be making the shutdown or upgrade process start until all extension upgrades are done. It would be a common case where people are not using Code for a few days, got updates for both Code and extensions, and did the Code upgrade while extensions were installing.

I actually get this easily reproduced. Go to Vim's extension folder and in package.json, mark the version lower, reload VS Code so auto upgrade happens, Cmd + Q to shutdown while extension was installing.

Remove partially extracted extensions from the disk When there is a failure during extract or post extract

I think it does not cover the case where the extraction completed without error but some files become missing. Are we 100% sure we are not hitting any bugs in yauzl?
Another point was a majority of these reports coming in Vetur were from Windows users. One possibility is Windows Defender is doing something...

@ramya-rao-a

This comment has been minimized.

Copy link
Member

ramya-rao-a commented Feb 28, 2018

@octref For Go there is a good mix of Windows, linux and Mac. So I don't think this is a Windows specific

@sandy081

This comment has been minimized.

Copy link
Member

sandy081 commented Mar 1, 2018

That's the same case with Vetur. Do you have any theory as to why in some cases, uninstall -> install works, whereas for some people they had to remove the extension folders manually?

This is because, Internally, during uninstall we just tag the extension as uninstalled and remove this tag if user installs it immediately. If user wants to remove and install the extension completely I have introduced a new command Developer: Reinstall Extension. This will remove it completely from the disk and installs it freshly. See #44838

I think it does not cover the case

Yes, it does not cover shutdown case while update is happening. One suggestion from Alex is to extract it to some temp folder and move it when the extraction is complete. But this will also have a time frame where VS Code could quit while moving.

Are we 100% sure we are not hitting any bugs in yauzl?

I am not sure.

@octref

This comment has been minimized.

Copy link
Member

octref commented Mar 1, 2018

Developer: Reinstall Extension

Thanks for the addition. I'll point people to using it until a checksum becomes available.

@thorn0

This comment has been minimized.

Copy link

thorn0 commented Mar 2, 2018

Internally, during uninstall we just tag the extension as uninstalled and remove this tag if user installs it immediately.

Is the extension removed some time later if the user doesn't re-install it immediately? Sounds like a really questionable design decision any way.

@roblourens

This comment has been minimized.

Copy link
Member

roblourens commented Mar 30, 2018

@sandy081 I think there's still an issue here. I don't know how this is happening, but it's quite easy to reproduce.

I click the install button on an extension, them immediately press cmd+q. Then I see some files in the . folder and some in the destination folder.

We should just be calling fs.rename, so something weird is up. I tried it from the command line, pressing ctrl+c while installing, but don't see an issue there.

The shared process logs don't show anything useful. I think they are missing the last log message or two.

$ l ~/.vscode-insiders/extensions/.ms-vscode.csharp-1.14.0
drwxr-xr-x  3 roblou  staff  96 Mar 30 14:59 node_modules

$ l ~/.vscode-insiders/extensions/ms-vscode.csharp-1.14.0
-rw-r--r--  1 roblou  staff  49152 Mar 30 14:59 CHANGELOG.md

image

image

image

image

@roblourens roblourens reopened this Mar 30, 2018

sandy081 added a commit that referenced this issue Apr 2, 2018

@sandy081

This comment has been minimized.

Copy link
Member

sandy081 commented Apr 2, 2018

@roblourens Yes you are right. I expected operation fs.rename (which is also used for updating VS Code) to be atomic which proved to be not. Thanks for your testing.

I reverted the rename approach which I think will make extension installation much more prone to partial/corrupted installation.

Better approach would be

  • Track the extensions installations in a file (like un-installations). Enter the extension being installed and remove it from the file when the extension is completely installed. Do not load extensions which are not installed completely. Also inform the user about this or auto clean up in the background?

  • Prompt user about extension installations in progress while restarting VS Code.

@sandy081 sandy081 modified the milestones: March 2018, April 2018 Apr 2, 2018

sandy081 added a commit that referenced this issue Apr 3, 2018

@sandy081 sandy081 modified the milestones: April 2018, March 2018 Apr 3, 2018

@sandy081

This comment has been minimized.

Copy link
Member

sandy081 commented Apr 3, 2018

@bpasero Helped in investigating deeper into this to understand why fs.rename is not atomic. In fact fs.rename is atomic and the issue that @roblourens reproduced here is not due to rename. It is because of the fallback code that extracts to the real folder if extraction to temp folder fails. This fallback case is being called when VS Code is shutdown because extraction gets cancelled. Hence both folders (temp and real) exist.

Fallback was needed for the windows defender issue during rename. So fix is to run the fallback only if the error is EPERM error in Windows.

Thanks @bpasero

@sandy081 sandy081 closed this in 515e2b5 Apr 3, 2018

sandy081 added a commit that referenced this issue Apr 3, 2018

@sandy081

This comment has been minimized.

Copy link
Member

sandy081 commented Apr 3, 2018

To verify:

  • Try to install an extension which is bit big in size. For eg: Python, c#, Java or live share.
  • Before the installation is finished, Quit VS Code
  • Make sure that in the extensions folder you do not have both temporary and real folder. For eg., if it is python then you should not have both .ms-python.python-* and ms-python.python-* folders.
  • If the installation was completed before you quit VS Code, then only the real folder should exist. Eg: ms-python.python-* and it should be extracted completely. You can verify the completeness by downloading the extension from Marketplace manually.
  • If the installation was not completed before you quit VS Code, then only the temp folder should exist and when you start VS Code extension should not be in installed list and you can be able to install it without issues.

Please try above steps during different timings during extension installation

@dbaeumer

This comment has been minimized.

Copy link
Member

dbaeumer commented Apr 3, 2018

Verified under Windows.

@aeschli

This comment has been minimized.

Copy link
Contributor

aeschli commented Apr 3, 2018

Verified on Linux (Ubuntu 16.04)

@sandy081

This comment has been minimized.

Copy link
Member

sandy081 commented Apr 3, 2018

@roblourens Can you please verify on Mac

@roblourens

This comment has been minimized.

Copy link
Member

roblourens commented Apr 3, 2018

Verified on Mac.

Is the fallback for if it still fails after the 5s retry period? And in this case the promise was just being canceled when the renderer process goes down?

@roblourens roblourens added the verified label Apr 3, 2018

@sandy081

This comment has been minimized.

Copy link
Member

sandy081 commented Apr 3, 2018

Yes fallback is for the case when the rename fails after trying for 5s.

@roblourens

This comment has been minimized.

Copy link
Member

roblourens commented Apr 3, 2018

Did you see a case where the rename still failed after trying for 5s, or is it a theoretical problem?

This solution still leaves a gap where the unzip to the final extension folder could be interrupted, which I think was basically the original problem.

You mentioned above that another sort of solution would be better and I agree with that. #43813 (comment)

@sandy081

This comment has been minimized.

Copy link
Member

sandy081 commented Apr 4, 2018

@roblourens Yes it is an hypothesis and it could cause user not able to install extensions at all.

Yes, there could be still some set of users (who has windows defenders holding onto files for more than 5s) can fall into this gap. But I think that will be very very minimal.

I have already pushed a fix to masters to remove the fallback and increase the retry time to 30s. I am also thinking to increase time to a minute. If there is a process that hangs onto extracted folder for such an amount of time, it is really an issue that the user should be known to. Because, it will be an issue while removing extensions too. So this will remove that very minimal set of users too.

I also agree other solution is bit consistent but was not trivial to implement in last minute. This can be thought about too in April.

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.