search

microsoft / vscode

Visual Studio Code
https://code.visualstudio.com
MIT License
162.2k stars 28.55k forks source link

Extension Verification is super slow in dev containers #174632

Open ncstate01 opened 1 year ago

ncstate01 commented 1 year ago

Type: Performance Issue

On the September 2022 release, I don't have any performance issues installing extensions in a docker container.

When running the latest VSCode I see the following process consuming RAM until I assume it has consumed all of the RAM allowed to docker, when the process either ends or crashes. Once that happens the extension will install and I can install subsequent extensions reasonably after that.

/usr/bin/qemu-x86_64 /vscode/vscode-server/bin/linux-x64/441438abd1ac652551dbe4d408dfcec8a499b8bf/node_modules/node-vsce-sign/bin/vsce-sign /vscode/vscode-server/bin/linux-x64/441438abd1ac652551dbe4d408dfcec8a499b8bf/node_modules/node-vsce-sign/bin/vsce-sign verify --package /root/.vscode-server/extensionsCache/golang.go-0.37.1 --signaturearchive /root/.vscode-server/extensionsCache/golang.go-0.37.1.sigzip

The amount of RAM this process is using at the time is 4309 MB. It will run all the way up to 8G or so before ending.

Again all else being equal, I can revert to the September 2022 release before the vsce-sign feature was added and get around this issue for now.

VS Code version: Code 1.75.1 (441438abd1ac652551dbe4d408dfcec8a499b8bf, 2023-02-08T21:34:01.965Z) OS version: Darwin arm64 22.3.0 Modes: Sandboxed: No Remote OS version: Linux x64 5.15.49-linuxkit

System Info |Item|Value| |---|---| |CPUs|Apple M1 Pro (10 x 24)| |GPU Status|2d_canvas: enabled
canvas_oop_rasterization: disabled_off
direct_rendering_display_compositor: disabled_off_ok
gpu_compositing: enabled
metal: disabled_off
multiple_raster_threads: enabled_on
opengl: enabled_on
rasterization: enabled
raw_draw: disabled_off_ok
skia_renderer: enabled_on
video_decode: enabled
video_encode: enabled
vulkan: disabled_off
webgl: enabled
webgl2: enabled
webgpu: disabled_off| |Load (avg)|7, 5, 5| |Memory (System)|16.00GB (0.06GB free)| |Process Argv|--crash-reporter-id 9f85b6b8-ef23-4278-98f4-ac98ab00958a| |Screen Reader|no| |VM|0%| |Item|Value| |---|---| |Remote|Dev Container: sas-skeleton| |OS|Linux x64 5.15.49-linuxkit| |CPUs|unknown (5 x 0)| |Memory (System)|7.76GB (3.69GB free)| |VM|0%|
Process Info ``` CPU % Mem MB PID Process 3 147 44296 code main 1 66 44302 gpu-process 0 33 44305 utility-network-service 0 164 44307 window (prepare.sh — src [Dev Container: sas-skeleton]) 0 98 44371 shared-process 0 33 44375 ptyHost 0 33 44841 fileWatcher 0 0 45412 /bin/ps -ax -o pid=,ppid=,pcpu=,pmem=,command= 0 66 44765 extension-host 0 33 45051 docker exec -i -u root -e VSCODE_REMOTE_CONTAINERS_SESSION=8c034630-f947-40b0-b717-f01213789ca61676587884310 a48c257eba5f35f722c656f59b57ed4f7b0b78999b21350795fdf883feb54887 /bin/sh 0 16 45052 /Applications/Docker.app/Contents/Resources/bin/com.docker.cli exec -i -u root -e VSCODE_REMOTE_CONTAINERS_SESSION=8c034630-f947-40b0-b717-f01213789ca61676587884310 a48c257eba5f35f722c656f59b57ed4f7b0b78999b21350795fdf883feb54887 /bin/sh 0 33 45055 /Applications/Visual Studio Code.app/Contents/Frameworks/Code Helper (Plugin).app/Contents/MacOS/Code Helper (Plugin) --ms-enable-electron-run-as-node /Users/jischn/.vscode/extensions/ms-vscode-remote.remote-containers-0.275.1/dist/shutdown/shutdownMonitorProcess /var/folders/0c/vq4vb_051kz5pk335ktkwm940000gn/T/vscode-remote-containers-034b219395f8eeaa6a3c8083f8016dba9c80d861.sock dockerCompose Debug /Users/jischn/Library/Application Support/Code/logs/20230216T174939/window1/exthost/ms-vscode-remote.remote-containers 1676587884685 0 33 45071 docker exec -i -u root a48c257eba5f35f722c656f59b57ed4f7b0b78999b21350795fdf883feb54887 /bin/sh 0 16 45072 /Applications/Docker.app/Contents/Resources/bin/com.docker.cli exec -i -u root a48c257eba5f35f722c656f59b57ed4f7b0b78999b21350795fdf883feb54887 /bin/sh 0 33 45077 docker exec -i -u root -e SHELL=/usr/bin/zsh -e VSCODE_AGENT_FOLDER=/root/.vscode-server -w /root/.vscode-server/bin/441438abd1ac652551dbe4d408dfcec8a499b8bf a48c257eba5f35f722c656f59b57ed4f7b0b78999b21350795fdf883feb54887 /root/.vscode-server/bin/441438abd1ac652551dbe4d408dfcec8a499b8bf/bin/code-server --log debug --force-disable-user-env --server-data-dir /root/.vscode-server --use-host-proxy --telemetry-level all --accept-server-license-terms --host 127.0.0.1 --port 0 --connection-token-file /root/.vscode-server/data/Machine/.connection-token-441438abd1ac652551dbe4d408dfcec8a499b8bf --extensions-download-dir /root/.vscode-server/extensionsCache --install-extension golang.go --start-server --disable-websocket-compression 0 16 45078 /Applications/Docker.app/Contents/Resources/bin/com.docker.cli exec -i -u root -e SHELL=/usr/bin/zsh -e VSCODE_AGENT_FOLDER=/root/.vscode-server -w /root/.vscode-server/bin/441438abd1ac652551dbe4d408dfcec8a499b8bf a48c257eba5f35f722c656f59b57ed4f7b0b78999b21350795fdf883feb54887 /root/.vscode-server/bin/441438abd1ac652551dbe4d408dfcec8a499b8bf/bin/code-server --log debug --force-disable-user-env --server-data-dir /root/.vscode-server --use-host-proxy --telemetry-level all --accept-server-license-terms --host 127.0.0.1 --port 0 --connection-token-file /root/.vscode-server/data/Machine/.connection-token-441438abd1ac652551dbe4d408dfcec8a499b8bf --extensions-download-dir /root/.vscode-server/extensionsCache --install-extension golang.go --start-server --disable-websocket-compression 0 33 45091 docker exec -i -u root -e VSCODE_REMOTE_CONTAINERS_SESSION=8c034630-f947-40b0-b717-f01213789ca61676587884310 a48c257eba5f35f722c656f59b57ed4f7b0b78999b21350795fdf883feb54887 /root/.vscode-server/bin/441438abd1ac652551dbe4d408dfcec8a499b8bf/node -e \012\011\011\011\011const net = require('net');\012\011\011\011\011const fs = require('fs');\012\011\011\011\011process.stdin.pause();\012\011\011\011\011const client = net.createConnection({ host: '127.0.0.1', port: 33877 }, () => {\012\011\011\011\011\011console.error('Connection established');\012\011\011\011\011\011client.pipe(process.stdout);\012\011\011\011\011\011process.stdin.pipe(client);\012\011\011\011\011});\012\011\011\011\011client.on('close', function (hadError) {\012\011\011\011\011\011console.error(hadError ? 'Remote close with error' : 'Remote close');\012\011\011\011\011\011process.exit(hadError ? 1 : 0);\012\011\011\011\011});\012\011\011\011\011client.on('error', function (err) {\012\011\011\011\011\011process.stderr.write(err && (err.stack || err.message) || String(err));\012\011\011\011\011});\012\011\011\011\011process.stdin.on('close', function (hadError) {\012\011\011\011\011\011console.error(hadError ? 'Remote stdin close with error' : 'Remote stdin close');\012\011\011\011\011\011process.exit(hadError ? 1 : 0);\012\011\011\011\011});\012\011\011\011\011process.on('uncaughtException', function (err) {\012\011\011\011\011\011fs.writeSync(process.stderr.fd, `Uncaught Exception: ${String(err && (err.stack || err.message) || err)}\n`);\012\011\011\011\011});\012\011\011\011 0 16 45093 /Applications/Docker.app/Contents/Resources/bin/com.docker.cli exec -i -u root -e VSCODE_REMOTE_CONTAINERS_SESSION=8c034630-f947-40b0-b717-f01213789ca61676587884310 a48c257eba5f35f722c656f59b57ed4f7b0b78999b21350795fdf883feb54887 /root/.vscode-server/bin/441438abd1ac652551dbe4d408dfcec8a499b8bf/node -e \012\011\011\011\011const net = require('net');\012\011\011\011\011const fs = require('fs');\012\011\011\011\011process.stdin.pause();\012\011\011\011\011const client = net.createConnection({ host: '127.0.0.1', port: 33877 }, () => {\012\011\011\011\011\011console.error('Connection established');\012\011\011\011\011\011client.pipe(process.stdout);\012\011\011\011\011\011process.stdin.pipe(client);\012\011\011\011\011});\012\011\011\011\011client.on('close', function (hadError) {\012\011\011\011\011\011console.error(hadError ? 'Remote close with error' : 'Remote close');\012\011\011\011\011\011process.exit(hadError ? 1 : 0);\012\011\011\011\011});\012\011\011\011\011client.on('error', function (err) {\012\011\011\011\011\011process.stderr.write(err && (err.stack || err.message) || String(err));\012\011\011\011\011});\012\011\011\011\011process.stdin.on('close', function (hadError) {\012\011\011\011\011\011console.error(hadError ? 'Remote stdin close with error' : 'Remote stdin close');\012\011\011\011\011\011process.exit(hadError ? 1 : 0);\012\011\011\011\011});\012\011\011\011\011process.on('uncaughtException', function (err) {\012\011\011\011\011\011fs.writeSync(process.stderr.fd, `Uncaught Exception: ${String(err && (err.stack || err.message) || err)}\n`);\012\011\011\011\011});\012\011\011\011 0 33 45096 docker exec -i -u root -e VSCODE_REMOTE_CONTAINERS_SESSION=8c034630-f947-40b0-b717-f01213789ca61676587884310 a48c257eba5f35f722c656f59b57ed4f7b0b78999b21350795fdf883feb54887 /root/.vscode-server/bin/441438abd1ac652551dbe4d408dfcec8a499b8bf/node -e \012\011\011\011\011const net = require('net');\012\011\011\011\011const fs = require('fs');\012\011\011\011\011process.stdin.pause();\012\011\011\011\011const client = net.createConnection({ host: '127.0.0.1', port: 33877 }, () => {\012\011\011\011\011\011console.error('Connection established');\012\011\011\011\011\011client.pipe(process.stdout);\012\011\011\011\011\011process.stdin.pipe(client);\012\011\011\011\011});\012\011\011\011\011client.on('close', function (hadError) {\012\011\011\011\011\011console.error(hadError ? 'Remote close with error' : 'Remote close');\012\011\011\011\011\011process.exit(hadError ? 1 : 0);\012\011\011\011\011});\012\011\011\011\011client.on('error', function (err) {\012\011\011\011\011\011process.stderr.write(err && (err.stack || err.message) || String(err));\012\011\011\011\011});\012\011\011\011\011process.stdin.on('close', function (hadError) {\012\011\011\011\011\011console.error(hadError ? 'Remote stdin close with error' : 'Remote stdin close');\012\011\011\011\011\011process.exit(hadError ? 1 : 0);\012\011\011\011\011});\012\011\011\011\011process.on('uncaughtException', function (err) {\012\011\011\011\011\011fs.writeSync(process.stderr.fd, `Uncaught Exception: ${String(err && (err.stack || err.message) || err)}\n`);\012\011\011\011\011});\012\011\011\011 0 16 45097 /Applications/Docker.app/Contents/Resources/bin/com.docker.cli exec -i -u root -e VSCODE_REMOTE_CONTAINERS_SESSION=8c034630-f947-40b0-b717-f01213789ca61676587884310 a48c257eba5f35f722c656f59b57ed4f7b0b78999b21350795fdf883feb54887 /root/.vscode-server/bin/441438abd1ac652551dbe4d408dfcec8a499b8bf/node -e \012\011\011\011\011const net = require('net');\012\011\011\011\011const fs = require('fs');\012\011\011\011\011process.stdin.pause();\012\011\011\011\011const client = net.createConnection({ host: '127.0.0.1', port: 33877 }, () => {\012\011\011\011\011\011console.error('Connection established');\012\011\011\011\011\011client.pipe(process.stdout);\012\011\011\011\011\011process.stdin.pipe(client);\012\011\011\011\011});\012\011\011\011\011client.on('close', function (hadError) {\012\011\011\011\011\011console.error(hadError ? 'Remote close with error' : 'Remote close');\012\011\011\011\011\011process.exit(hadError ? 1 : 0);\012\011\011\011\011});\012\011\011\011\011client.on('error', function (err) {\012\011\011\011\011\011process.stderr.write(err && (err.stack || err.message) || String(err));\012\011\011\011\011});\012\011\011\011\011process.stdin.on('close', function (hadError) {\012\011\011\011\011\011console.error(hadError ? 'Remote stdin close with error' : 'Remote stdin close');\012\011\011\011\011\011process.exit(hadError ? 1 : 0);\012\011\011\011\011});\012\011\011\011\011process.on('uncaughtException', function (err) {\012\011\011\011\011\011fs.writeSync(process.stderr.fd, `Uncaught Exception: ${String(err && (err.stack || err.message) || err)}\n`);\012\011\011\011\011});\012\011\011\011 2 98 45133 issue-reporter Remote: Dev Container: sas-skeleton CPU % Mem MB PID Process 0 606 407 remote agent 0 262 517 ptyHost 19 5341 936 /usr/bin/qemu-x86_64 /vscode/vscode-server/bin/linux-x64/441438abd1ac652551dbe4d408dfcec8a499b8bf/node_modules/node-vsce-sign/bin/vsce-sign /vscode/vscode-server/bin/linux-x64/441438abd1ac652551dbe4d408dfcec8a499b8bf/node_modules/node-vsce-sign/bin/vsce-sign verify --package /root/.vscode-server/extensionsCache/golang.go-0.37.1 --signaturearchive /root/.vscode-server/extensionsCache/golang.go-0.37.1.sigzip 0 246 1027 fileWatcher 0 590 1040 extension-host 0 0 4604 /usr/bin/qemu-x86_64 /bin/sh /bin/sh -c /usr/bin/ps -ax -o pid=,ppid=,pcpu=,pmem=,command= 0 16 4607 /usr/bin/ps -ax -o pid=,ppid=,pcpu=,pmem=,command= ```
Workspace Info ``` | Remote: Dev Container: sas-skeleton| Folder (src): 124 files| File types: go(14) json(9) properties(7) yaml(7) md(4) lock(4) bin(3) | gradle(3) Jenkinsfile(3) env(2) | Conf files: devcontainer.json(1) dockerfile(1); ```
Extensions (6) Extension|Author (truncated)|Version ---|---|--- remote-containers|ms-|0.275.1 remote-ssh|ms-|0.96.0 remote-ssh-edit|ms-|0.84.0 remote-wsl|ms-|0.75.3 vscode-remote-extensionpack|ms-|0.23.0 remote-explorer|ms-|0.2.0
A/B Experiments ``` vsliv368:30146709 vsreu685:30147344 python383cf:30185419 vspor879:30202332 vspor708:30202333 vspor363:30204092 vslsvsres303:30308271 pythonvspyl392:30443607 vserr242:30382549 pythontb:30283811 vsjup518:30340749 pythonptprofiler:30281270 vshan820:30294714 vstes263:30335439 vscoreces:30445986 pythondataviewer:30285071 vscod805:30301674 binariesv615:30325510 bridge0708:30335490 bridge0723:30353136 cmake_vspar411:30581797 vsaa593cf:30376535 pythonvs932:30410667 cppdebug:30492333 vsclangdf:30486550 c4g48928:30535728 dsvsc012:30540252 azure-dev_surveyone:30548225 pyindex848:30662994 nodejswelcome1:30587005 2e4cg342:30602488 pyind779cf:30662993 89544117:30613380 pythonsymbol12cf:30657549 ```
ncstate01 commented 1 year ago

@dtivel Perhaps this is something you'd be able to look into.

Cheers

ncstate01 commented 1 year ago

A few more observations.

I tried using a vanilla Alpine dev container and I did not see this issue with that container.

Also, if I kill -9 the vsce-sign pid from a bash terminal in the docker container then it releases the log jam and I can quickly install extensions again. So, there are some workarounds to this issue for now. I'm not sure at what point the "vsce-sign verify" will not act like an optional process.

dtivel commented 1 year ago

Thanks for the report, @ncstate01. Can you point me to a specific Docker container image that can I use to repro this?

ncstate01 commented 1 year ago

@dtivel I'm not able to create a test case for you. I've tried to recreate the problem in a separate folder using off-the-shelf containers, but I haven't had any luck yet.

I tried using alpine and using centos 7 which is the base for our layered image here at work.

.devcontainer/devcontainer.json { "name": "Foo", "build":{ "dockerfile": "Dockerfile" } }

.devcontainer/Dockerfile FROM --platform=linux/x86_64 centos:7

This forces an x84 centos image to be pulled which I noticed forces docker to run the processes under qemu-x86_64 as it does in my other image. I can't share the other image because it is for company development.

Now, I'm not sure how to help you recreate the problem. Using the same image, but an older VSCode works ok. So the problem follows VSCode, but the container seems to play a part and I wonder if qemu also plays a part.

ncstate01 commented 1 year ago

I found that we had an ARM based image too. When I configure things to pull that image. The vcse-sign step is super fast an I don't have any issues. So the issue could be related to running the vcse-sign in an amd64/x86_64 image on Mac ARM CPUs, but there still seems to be something particular to our image in addition to those other variables.

I'm not sure where you want to go with this one. It seems I have a few options to get around this issue and those options may help others.

[1078087 ms] [10:36:20] [127.0.0.1][eaee4e5d][ExtensionHostConnection] <556> Launched Extension Host Process.
[1078295 ms] [10:36:20] Extension signature verification: golang.go. Verification status: Verified.
[1079371 ms] [10:36:21] Extracted extension to /root/.vscode-server/extensions/.608b4541-b34e-42e4-8e1f-571d524abf1b: golang.go
[1079426 ms] [10:36:21] Renamed to /root/.vscode-server/extensions/golang.go-0.37.1
[1079432 ms] [10:36:21] Extracting completed. golang.go
[1079488 ms] [10:36:21] Extension installed successfully: golang.go
[1079551 ms] Extension 'golang.go' v0.37.1 was successfully installed.
dtivel commented 1 year ago

Thank you for the additional information, @ncstate01. I really appreciate it. Let me see if I can repro this with the information you've provided.

dtivel commented 1 year ago

@ncstate01. I think I can reproduce this on an M1 with linux/x86_64 centos:7. The trouble is getting a dump of vsce-sign. When I attach with gdb, I get ptrace: Function not implemented, which looks similar to https://github.com/docker/for-mac/issues/5191. There are some suggestions in that issue I'll try next.

ncstate01 commented 1 year ago

@dtivel I'm glad you were able to find a way to reproduce this. I wasn't sure we'd find a way with available docker images.

I'm sure users will hit this issue, but since I found my company is making an arm64-based image I haven't seen this issue. I only have problems with our intel-based image.

karmicdude commented 1 year ago

the same issue on M2 max without docker container

karmicdude 31899 98.2 0.0 410124896 944 ?? R Wed10PM 1850:33.98 /private/var/folders/9j/l5md3vy534b29t6q03gnsnbh0000gn/T/AppTranslocation/F0C38A48-08A3-4B7A-8031-E04FD95397F3/d/Visual Studio Code.app/Contents/Resources/app/node_modules.asar.unpacked/node-vsce-sign/bin/vsce-sign verify --package /Users/karmicdude/Library/Application Support/Code/CachedExtensionVSIXs/golang.go-0.38.0 --signaturearchive /Users/karmicdude/Library/Application Support/Code/CachedExtensionVSIXs/golang.go-0.38.0.sigzip

process periodically eat up 80% of the CPU and only after force killing it for a while does the problem disappear.

abhibeckert commented 1 year ago

I'm having this issue too - it's using gigabytes of memory (and climbing, maybe a leak?) and has been running for 10 minutes now with no sign of finishing.

ryboe commented 1 year ago

In #179827 @ariedl discovered that setting "extensions.verifySignature": false worked around the issue.

For devcontainer, set "customizations.vscode.settings.extensions.verifySignature": false.

sandy081 commented 7 months ago

Can you (those who subscribed) please verify if this issue still exists?

LouisStAmour commented 6 months ago

Still occurring.

Stable logs

Insiders logs

As noted in Insiders logs, I have set NODE_OPTIONS to --use-openssl-ca and I'm using a local proxy via host.docker.internal. Deleting everything docker including the vscode volume does not help.

esba1ley commented 5 months ago

I can confirm this is still an issue, but a less-secure work-around is to disable extension signature checking in your .devcontainer/devcontainer.json file, under 

{
    "customizations": {
        "vscode":{ 
            "settings": {  
                "extensions.verifySignature": false 
            }
        }
    }
}

This at least is working for me. My organization is eagerly awaiting a VS Code update that fixes this.

My software version configuration where I have experienced the extension verification problem and used the above work-around successfully:

Hardware: MacBook Air, Apple Silicon (M2) Operating System: MacOS 14.4 VS Code Version: 1.87.2 (Universal) Docker Desktop Version: 4.28.0 Docker Engine Version: 25.0.3

AndreuCodina commented 5 months ago

"extensions.verifySignature": false doesn't work for me. It's stuck on "Installing".

Hardware: MacBook Pro M1 Operating System: MacOS 14.3.1 VS Code Version: 1.87.2 Docker Desktop Version: 4.28.0 Docker Engine Version: 25.0.3

Dockerfile: FROM --platform=linux/amd64 python:3.11-bullseye

tbistr commented 5 months ago

This issue reproduces in my environment, and I may have found some useful information.

I found that "extensions.verifySignature": false is effective only in customizations.vscode.settings in devcontainer.json. .vscode/settings.json and user's setting are not effectable. I think this is related to the load timing of settings.

Next, I found that once devcontainer built, extensions.verifySignature is not necessary for reopening container. This may useful for git management.

System info HW: M3 Macbook Air OS: 14.4.1 VSCode: 1.87.2 Docker desktop: 4.28.0 Dockerfile: `FROM --platform=amd64 mcr.microsoft.com/devcontainers/python:1-3.12-bullseye` Installing extensions: `ms-python.python` and some local heredity.
sueszli commented 3 months ago

update may 2024: this solution worked flawlessly for me and my colleagues 👇

https://github.com/microsoft/vscode-remote-release/issues/8169#issuecomment-1543987445