search

microsoft / vscode-remote-release

Visual Studio Code Remote Development: Open any folder in WSL, in a Docker container, or on a remote machine using SSH and take advantage of VS Code's full feature set.
https://aka.ms/vscode-remote
Other
3.69k stars 296 forks source link

Devcontainer extensions very slow to install #9980

Closed rjra100 closed 1 week ago

rjra100 commented 5 months ago

Type: Bug

Since (I think) VSCode 1.90.0, installation of extensions into our containers appears to be painfully slow. Believe it's probably related to https://github.com/microsoft/vscode-remote-release/issues/9628, and specifically I'm suspicious of the change referenced here.

With default settings (extension signature verification enabled), I have the log attached as withverification.txt. For the first 90s or so, I didn't see any indication outside of the container log that anything was happening at all. After that, the extensions appear as "Installing" in the extensions pane, but it takes another 8 minutes or so to complete installing extensions, and at least in the run attached, a bunch of them apparently failed to install at all due to timing out. For each extension, there's a log line along the lines of 

[290511 ms] [18:52:32] Extension signature verification result for ms-vscode.live-server: Success. Executed: true. Duration: 90792ms.

indicating that verification took roughly 90s. That seems unnecessarily slow...

Since the issue seems so similar, I experimented with the solution suggested in the other issue for Mac silicon, and disabled signature verification (set "extensions.verifySignature": false). This gave me the log attached as withoutverification.txt. Now, while it's still annoyingly slow, it does at least complete successfully, taking about 3 minutes to do so. Again, for the first 90s or so, I didn't see much indication that anything was happening at all; after that I got a scrolling indicator in the extensions pane, but the extensions themselves didn't show up until the process completed (at which point they all appeared at once, fully installed).

In case it's relevant, I should perhaps point out that we've got /home/${USER}/.vscode-server/extensions mapped to a docker volume in the docker-compose.yml, so that the extensions only need installing once on initial creation of a devcontainer (rebuilding the container will reuse the extensions from that volume, unless it's explicitly deleted). I don't particularly see why that should slow down the initial installation, but I can try without the volume if necessary.

Extension version: 0.369.0 VS Code version: Code 1.90.1 (611f9bfce64f25108829dd295f54a6894e87339d, 2024-06-11T21:01:24.262Z) OS version: Windows_NT x64 10.0.19045 Modes: Remote OS version: Linux x64 5.15.146.1-microsoft-standard-WSL2

System Info |Item|Value| |---|---| |CPUs|Intel(R) Core(TM) i9-10980XE CPU @ 3.00GHz (36 x 3000)| |GPU Status|2d_canvas: enabled
canvas_oop_rasterization: enabled_on
direct_rendering_display_compositor: disabled_off_ok
gpu_compositing: enabled
multiple_raster_threads: enabled_on
opengl: enabled_on
rasterization: enabled
raw_draw: disabled_off_ok
skia_graphite: disabled_off
video_decode: enabled
video_encode: enabled
vulkan: disabled_off
webgl: enabled
webgl2: enabled
webgpu: enabled| |Load (avg)|undefined| |Memory (System)|127.80GB (83.80GB free)| |Process Argv|| |Screen Reader|no| |VM|0%| |Item|Value| |---|---| |Remote|WSL: Ubuntu-22.04| |OS|Linux x64 5.15.146.1-microsoft-standard-WSL2| |CPUs|Intel(R) Core(TM) i9-10980XE CPU @ 3.00GHz (36 x 0)| |Memory (System)|62.69GB (57.77GB free)| |VM|0%| |Item|Value| |---|---| |Remote|Dev Container: portal_ws-dev| |OS|Linux x64 5.15.146.1-microsoft-standard-WSL2| |CPUs|Intel(R) Core(TM) i9-10980XE CPU @ 3.00GHz (36 x 0)| |Memory (System)|62.69GB (57.77GB free)| |VM|0%| |Item|Value| |---|---| |Remote|Dev Container: qmi-dev| |OS|Linux x64 5.15.146.1-microsoft-standard-WSL2| |CPUs|Intel(R) Core(TM) i9-10980XE CPU @ 3.00GHz (36 x 0)| |Memory (System)|62.69GB (57.77GB free)| |VM|0%|
sandy081 commented 5 months ago

Thanks for the logs. I suspect you might be have network issues in the remote dev container. Can you please try following and let us know the results

Thanks

rjra100 commented 5 months ago

(With signature validation turned back on, and the extensions volume disabled; installing ms-vscode.cpptools) Installing from the UI, wall time from clicking "install" to completed installation was 39s (including approx 10s lag before anything shows up in the log - I speculate that this may be extension host startup time or suchlike; installations of later extensions have no noticeable delay here). Log: from_extensions_pane.log With remote.downloadExtensionsLocally, wall time from clicking "install" to completed installation was 24s (including approx 19s lag before anything shows up in the log). Log: from_extension_pane_downloadlocal.log Installing via devcontainer.json (without downloadExtensionsLocally), a single extension actually doesn't seem so bad. There's an approx ~12s gap between the last log entry before extension installation and the "Installing extension" log (pretty consistent with the UI's behaviour), and signature validation took a mere 2s. Log: from_devcontainer_json.log Setting downloadExtensionsLocally and running again appeared to make very little difference.

However, with a few more extensions, things seem to scale poorly. Installing C/C++, CMake Test Adapter, and CMake Tools (which in turn drag in CMake, Test Adapter Converter, and Test Explorer UI), suddenly the signature verification takes 15s per extension, and total extension installation time is almost 2 minutes. Log: from_devcontainer_json_3_exts.log. Adding Gitlens as well, it was back up to 90s. Pretty much the same behaviour with downloadExtensionsLocally: from_devcontainer_json_3_exts_downloadlocal.log

Installing the same extensions via the UI, the signature verifications seem shorter, but I notice:

Here's a log of installing CMake Tools, then CMake Test Adapter, then C/C++, for example. Now it's CMake Tools and CMake that take 6s (each) to verify, and C/C++ takes a mere 1s. from_extensions_pane_3_exts.log

Is the signature verification tool perhaps processing all the extensions that are being installed at any given time and doing some sort of quadratic scaling? And why does it seem to be slower on the first extension(s) installed?

sandy081 commented 5 months ago

@rjra100 Thanks for the information. It would be great if you share the logs from the Output Channel instead from the Terminal. You can get the Server log for example by running the command: F1 > Open View... > Server

Installing via devcontainer.json (without downloadExtensionsLocally), a single extension actually doesn't seem so bad. There's an approx ~12s gap between the last log entry before extension installation and the "Installing extension" log (pretty consistent with the UI's behaviour), and signature validation took a mere 2s. Log: from_devcontainer_json.log Setting downloadExtensionsLocally and running again appeared to make very little difference.

When installing via devcontainer.json , downloadExtensionsLocally setting has no effect as the extension will be downloaded and installed on server during start up. This setting makes sense only when you install extension from UI. Hence you have seen no impact of this setting in this case.

@chrmarti Is there something we can do here if user has this setting set? Generally users set this setting because to overcome network connectivity issues on the remote. Is it possible for dev containers to respect this setting and disable installing extensions on start up and postpone it after start up - Filed a separate issue for this - https://github.com/microsoft/vscode-remote-release/issues/9994

Installing the same extensions via the UI, the signature verifications seem shorter, but I notice:

Have you tried using setting downloadExtensionsLocally here?

rjra100 commented 5 months ago

Server logs downloading the same 3 extensions via the UI: UI_3_exts.log and with downloadExtensionsLocally: UI_3_exts_downloadlocal.log End to end times here are meaningless because there are gaps between one extension finishing and my clicking the download button for the next. Downloading locally is indeed much faster, though that could be because it doesn't appear to be doing the signature verification at all in this case (indeed, it felt fast enough that it could be using a cached copy on the host which I haven't found to delete). So https://github.com/microsoft/vscode-remote-release/issues/9994 might be a workaround, but I still feel that there's some new problem with the installation on the container side. While we do have a complicated proxy setup, it's not that my container's networking isn't working at all, because the installation does complete eventually. But it's definitely much slower than it used to be.

Incidentally, I think there's a race condition in the installation itself when one extension pulls in others as dependencies as in these cases. I've raised that as a separate issue.

sandy081 commented 5 months ago

Downloading locally is indeed much faster, though that could be because it doesn't appear to be doing the signature verification at all in this case (indeed, it felt fast enough that it could be using a cached copy on the host which I haven't found to delete

Signature verification is done locally in this case. Yes, we do cache the VSIXs both on client and server and the location where we do is CachedExtensionVSIXs folder in User Data folder.

but I still feel that there's some new problem with the installation on the container side.

Why do you think so? Is there any analysis you have behind this assumption?

rjra100 commented 5 months ago

Signature verification is done locally in this case. Yes, we do cache the VSIXs both on client and server and the location where we do is CachedExtensionVSIXs folder in User Data folder.

Thought so. However, afraid I'm still struggling to find this: I don't see those particular extensions cached in either %APPDATA%\Roaming\Code\CachedExtensionVSIXs (Windows host) or, for that matter, ~/.vscode-server/data/CachedExtensionVSIXs/ (WSL layer). Strange. Even had a look with procmon, and it is looking in the APPDATA path, but no downloads are actually appearing there.

Why do you think so? Is there any analysis you have behind this assumption?

My impression was that previously it wasn't particularly slow (extensions reliably installed after building a new container), while recently we've had to explicitly disable extensions.verifySignature to keep it usable. However, since you ask, I've just tried installing my full list of extensions in 1.89 and 1.88, and while they're all very slow to install everything, neither seem significantly slower than 1.90; this evening I'm not even getting errors in 1.90 like rejected promise not handled within 1 second: Extract: ENOENT: no such file or directory, open '/home/ralexander72/.vscode-server/extensionsCache/ms-vscode.test-adapter-converter-0.1.9' (as I did in my original log). Suppose something DevContainers-extension-related could have changed, but possibly not.

Sorry: as I mentioned, we've normally got the extensions installed in a volume; most of the time we're doing rebuilds of existing containers, so maybe it's just that the occasional new container build is surprisingly slow (compared to not having to install anything!). I'll back down on the "there's something new", though it certainly seems strangely slow compared to the "local" download. If there is any way to speed it up anyway, that'd be great, and I'll keep an eye on https://github.com/microsoft/vscode-remote-release/issues/9994.

rubensa commented 4 months ago

@rjra100 I think the cache path in WSL layer would be ~/.config/Code/CachedExtensionVSIXs/ (vs. ~/.vscode-server/data/CachedExtensionVSIXs/) as that's the one under Linux.

rubensa commented 4 months ago

I'm experiencing similar problems.

I also have a Docker volume to "share" the extensions cache.

In my devcontainer.json I have something like:

  "mounts": [
    // VSCode server extensions cache
    "source=vscode-server-extensions-cache,target=/vscode/vscode-server/extensionsCache,type=volume"
  ],

If I have multiple extensions added to devcontainer.json like:

      // An array of extension IDs that specify the extensions that should be installed inside the container when it is created.
      "extensions": [
        /////////
        // GIT //
        /////////
        // Git Graph (https://github.com/mhutchie/vscode-git-graph)
        "mhutchie.git-graph",
        // GitLens — Git supercharged (https://github.com/gitkraken/vscode-gitlens)
        "eamodio.gitlens",
        ///////////////////
        // DOCUMENTATION //
        ///////////////////
        // Draw.io Integration (https://github.com/hediet/vscode-drawio)
        "hediet.vscode-drawio",
        // LTeX – LanguageTool grammar/spell checking (https://github.com/valentjn/vscode-ltex)
        "valentjn.vscode-ltex",
        // GitHub Markdown Preview (https://github.com/mjbvz/vscode-github-markdown-preview)
        "bierner.github-markdown-preview",
        // Markdown Checkboxes (https://github.com/mjbvz/vscode-markdown-checkboxes)
        "bierner.markdown-checkbox",
        // Markdown Emoji (https://github.com/mjbvz/vscode-markdown-emoji)
        "bierner.markdown-emoji",
        // Markdown Footnotes (https://github.com/mjbvz/vscode-markdown-footnotes)
        "bierner.markdown-footnotes",
        // Markdown Preview Github Styling (https://github.com/mjbvz/vscode-github-markdown-preview-style)
        "bierner.markdown-preview-github-styles",
        // Markdown Preview Mermaid Support (https://github.com/mjbvz/vscode-markdown-mermaid)
        "bierner.markdown-mermaid",
        // Markdown yaml Preamble (https://github.com/mjbvz/vscode-markdown-yaml-preamble)
        "bierner.markdown-yaml-preamble",
        // markdownlint (https://github.com/DavidAnson/vscode-markdownlint)
        "DavidAnson.vscode-markdownlint",
        // Markdown Table (https://github.com/takumisoft68/vscode-markdown-table)
        "takumii.markdowntable",
        // SVG (https://github.com/lishu/vscode-svg2)
        "jock.svg",
        // HTMLHint (https://github.com/htmlhint/vscode-htmlhint)
        "htmlhint.vscode-htmlhint",
        // Auto Close Tag (https://github.com/formulahendry/vscode-auto-close-tag)
        "formulahendry.auto-close-tag"
      ],

some times (mostly on container rebuild but not always) I get the ENOENT: no such file or directory error message.

But the problems seems to disappear if I set:

      "settings": {
        "extensions.verifySignature": false,

This might be related.

vs-code-engineering[bot] commented 2 weeks ago

Hey @sandy081, this issue might need further attention.

@rjra100, you can help us out by closing this issue if the problem no longer exists, or adding more information.

vs-code-engineering[bot] commented 1 week ago

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!