loading ms-python extension in offline mode too slow

[ailifeng]

OS/Web Information

• Web Browser: Chrome, Firefox
• Local OS: Ubuntu
• Remote OS: Ubuntu
• Remote Architecture: Docker Container, No internet
• code-server --version: 3.11.1

Steps to Reproduce

Expected

My docker container doesn't have Internet. The code-server can start properly. I expect loading ms-python extension (which has been installed offline) can complete in 20 seconds in version 3.11.1.

Actual

While activating the ms-python extension, it takes more than 2 minutes.

My script to start code-server is below:

/usr/lib/code-server/lib/node /usr/lib/code-server --auth none --bind-addr localhost:8089 --log trace --extensions-dir ./vscode-data/extensions

Logs

Screenshot

Notes

This issue can be reproduced in VS Code: Yes/No

[jsjoeio]

Does this happen on VS Code, Codespaces or vscode.dev?

[ailifeng]

Does this happen on VS Code, Codespaces or vscode.dev?

It happen on my company' s internal cluster and my code-server is deployed on docker without internet access. The log file shows the extension host started loadCommonJSModule (testing-editor-contributions/dist/extension.js) from 10:16:32.480 and completed loading Python extension at 10:18:35.109 (2 minutes).

[jsjoeio]

Hmmm...it's very hard to tell if this is specific to code-server on not without you testing on Codespaces or vscode.dev. I'm really not sure what we would have down that could have slowed down the extension in offline mode 🤔 It feels like this is something that's specific to the extension and should be raised in their repo, no?

[ailifeng]

Hmmm...it's very hard to tell if this is specific to code-server on not without you testing on Codespaces or vscode.dev. I'm really not sure what we would have down that could have slowed down the extension in offline mode 🤔 It feels like this is something that's specific to the extension and should be raised in their repo, no?

I also tested in VM Ubuntu to turn off Internet, in order to reproduce the slowness issue. It took 10 seconds to load the extension without internet. With internet, it took 2 seconds. From Chrome, I can see the code-server sent Http Post to "extension.coder.com".

In my company' s docker environment, I can see in the "extension host" process, there were two connections in "sync_sent" status. The two connection destinations are public IPs. Can I change configuration in code-server, for disallow the Python extension to connect to public IPs?

[jsjoeio]

Can I change configuration in code-server, for disallow the Python extension to connect to public IPs?

I don't believe so but @code-asher would know forsure

[code-asher]

I think I have seen this before where the extension marketplace is being queried for some reason. We will need to dig into it to find out what is going on.

[ailifeng]

I collected more detailed log today. Below are my observations:

• there are two "resolveProxy unconfigured" errors.
• Around the two errors, there were long time of no output in the log. One is 30 seconds(17:09:05.553 to 17:09:41.562), and the other one is 1.5 minutes(2021-11-19 17:09:41.563 to 17:11:12.869)

Below is the full log for loading python extension.

# full log
[2021-11-19 17:09:05.275] [exthost] [info] ExtensionService#_doActivateExtension ms-python.python {"startup":false,"extensionId":{"value":"ms-python.python","_lower":"ms-python.python"},"activationEvent":"onLanguage:python"}
[2021-11-19 17:09:05.275] [exthost] [info] ExtensionService#loadCommonJSModule file:///vscode-data/extensions/ms-python.python-2021.8.1159798656/out/client/extension
[2021-11-19 17:09:05.505] [exthost] [trace] ExtensionService#loadExtensionContext ms-python.python
[2021-11-19 17:09:05.513] [exthost] [trace] ExtHostSCM#$provideOriginalResource 0 file:///home/cdsw/1.py
[2021-11-19 17:09:05.513] [exthost] [trace] [vscode.merge-conflict] INVOKE provider 'm'
[2021-11-19 17:09:05.514] [exthost] [trace] ExtHostCommands#executeCommand setContext
[2021-11-19 17:09:05.514] [exthost] [trace] [vscode.merge-conflict] provider DONE after 1ms
[2021-11-19 17:09:05.536] [exthost] [trace] ExtensionService#_callActivateOptional ms-python.python
[2021-11-19 17:09:05.553] [exthost] [debug] ProxyResolver#resolveProxy unconfigured https://default.exp-tas.com/vscode/ab DIRECT 
Error: Error for stack trace
	at resolveProxy (/usr/lib/code-server/lib/vscode/node_modules/vscode-proxy-agent/out/index.js:105:69)
	at /usr/lib/code-server/lib/vscode/node_modules/vscode-proxy-agent/out/index.js:293:77
	at new Promise (<anonymous>)
	at _PacProxyAgent.resolveP [as resolver] (/usr/lib/code-server/lib/vscode/node_modules/vscode-proxy-agent/out/index.js:293:54)
	at _PacProxyAgent.<anonymous> (/usr/lib/code-server/lib/vscode/node_modules/vscode-proxy-agent/out/agent.js:71:37)
	at Generator.next (<anonymous>)
	at /usr/lib/code-server/lib/vscode/node_modules/vscode-proxy-agent/out/agent.js:8:71
	at new Promise (<anonymous>)
	at __awaiter (/usr/lib/code-server/lib/vscode/node_modules/vscode-proxy-agent/out/agent.js:4:12)
	at _PacProxyAgent.callback (/usr/lib/code-server/lib/vscode/node_modules/vscode-proxy-agent/out/agent.js:53:16)
	at _PacProxyAgent.addRequest (/usr/lib/code-server/lib/vscode/node_modules/vscode-proxy-agent/node_modules/agent-base/dist/src/index.js:184:38)
	at new ClientRequest (_http_client.js:305:16)
	at request (https.js:374:10)
	at Object.patched [as request] (/usr/lib/code-server/lib/vscode/node_modules/vscode-proxy-agent/out/index.js:297:24)
	at g._performRequest (/vscode-data/extensions/ms-python.python-2021.8.1159798656/out/client/extension.js:29:23600)
	at new g (/vscode-data/extensions/ms-python.python-2021.8.1159798656/out/client/extension.js:29:19921)
	at Object.value [as request] (/vscode-data/extensions/ms-python.python-2021.8.1159798656/out/client/extension.js:29:20480)
	at /vscode-data/extensions/ms-python.python-2021.8.1159798656/out/client/extension.js:78:342012
	at new Promise (<anonymous>)
	at e.exports (/vscode-data/extensions/ms-python.python-2021.8.1159798656/out/client/extension.js:78:339974)
	at e.exports (/vscode-data/extensions/ms-python.python-2021.8.1159798656/out/client/extension.js:78:335351)
	at processTicksAndRejections (internal/process/task_queues.js:95:5)
	at async i.fetch (/vscode-data/extensions/ms-python.python-2021.8.1159798656/out/client/extension.js:78:331495)
	at async i.getFeatures (/vscode-data/extensions/ms-python.python-2021.8.1159798656/out/client/extension.js:78:332722)
	at async /vscode-data/extensions/ms-python.python-2021.8.1159798656/out/client/extension.js:78:353862
	at async Promise.all (index 0)
	at async s.getFeaturesAsync (/vscode-data/extensions/ms-python.python-2021.8.1159798656/out/client/extension.js:78:353898)
	at async t.PollingService.onTick (/vscode-data/extensions/ms-python.python-2021.8.1159798656/out/client/extension.js:78:352183)
[2021-11-19 17:09:41.562] [exthost] [trace] [vscode.merge-conflict] INVOKE provider 'm' 
[2021-11-19 17:09:41.563] [exthost] [trace] ExtHostCommands#executeCommand setContext
[2021-11-19 17:09:41.563] [exthost] [trace] [vscode.merge-conflict] provider DONE after 1ms
[2021-11-19 17:11:12.869] [exthost] [debug] ProxyResolver#resolveProxy unconfigured https://dc.services.visualstudio.com/api/profiles/AIF-d9b70cd4-b9f9-4d70-929b-a071c400b217/appId DIRECT 
Error: Error for stack trace
	at resolveProxy (/usr/lib/code-server/lib/vscode/node_modules/vscode-proxy-agent/out/index.js:105:69)
	at /usr/lib/code-server/lib/vscode/node_modules/vscode-proxy-agent/out/index.js:293:77
	at new Promise (<anonymous>)
	at _PacProxyAgent.resolveP [as resolver] (/usr/lib/code-server/lib/vscode/node_modules/vscode-proxy-agent/out/index.js:293:54)
	at _PacProxyAgent.<anonymous> (/usr/lib/code-server/lib/vscode/node_modules/vscode-proxy-agent/out/agent.js:71:37)
	at Generator.next (<anonymous>)
	at /usr/lib/code-server/lib/vscode/node_modules/vscode-proxy-agent/out/agent.js:8:71
	at new Promise (<anonymous>)
	at __awaiter (/usr/lib/code-server/lib/vscode/node_modules/vscode-proxy-agent/out/agent.js:4:12)
	at _PacProxyAgent.callback (/usr/lib/code-server/lib/vscode/node_modules/vscode-proxy-agent/out/agent.js:53:16)
	at _PacProxyAgent.addRequest (/usr/lib/code-server/lib/vscode/node_modules/vscode-proxy-agent/node_modules/agent-base/dist/src/index.js:184:38)
	at new ClientRequest (_http_client.js:305:16)
	at request (https.js:374:10)
	at Object.patched [as request] (/usr/lib/code-server/lib/vscode/node_modules/vscode-proxy-agent/out/index.js:297:24)
	at Function.e.makeRequest (/vscode-data/extensions/ms-python.python-2021.8.1159798656/out/client/extension.js:9:695228)
	at Timeout.s [as _onTimeout] (/vscode-data/extensions/ms-python.python-2021.8.1159798656/out/client/extension.js:9:696850)
	at listOnTimeout (internal/timers.js:557:17)
	at processTimers (internal/timers.js:500:7)
[2021-11-19 17:11:12.889] [exthost] [trace] ExtHostCommands#registerCommand python.viewOutput
[2021-11-19 17:11:12.890] [exthost] [trace] ExtHostCommands#registerCommand python.startPage.open
[2021-11-19 17:11:12.890] [exthost] [trace] ExtHostCommands#executeCommand setContext
[2021-11-19 17:11:12.890] [exthost] [trace] ExtHostCommands#registerCommand python.enableSourceMapSupport
[2021-11-19 17:11:12.895] [exthost] [trace] ExtHostCommands#registerCommand navigateToTestFile
[2021-11-19 17:11:12.895] [exthost] [trace] ExtHostCommands#registerCommand navigateToTestFunction
[2021-11-19 17:11:12.895] [exthost] [trace] ExtHostCommands#registerCommand navigateToTestSuite
[2021-11-19 17:11:12.896] [exthost] [trace] ExtHostCommands#registerCommand python.runTestNode
[2021-11-19 17:11:12.896] [exthost] [trace] ExtHostCommands#registerCommand python.debugTestNode
[2021-11-19 17:11:12.896] [exthost] [trace] ExtHostCommands#registerCommand python.openTestNodeInEditor
[2021-11-19 17:11:12.896] [exthost] [trace] ExtHostCommands#registerCommand python._loadLanguageServerExtension
[2021-11-19 17:11:12.899] [exthost] [trace] ExtHostCommands#registerCommand python.analysis.clearCache
[2021-11-19 17:11:17.305] [exthost] [trace] ExtHostCommands#registerCommand python.refactorExtractVariable
[2021-11-19 17:11:17.305] [exthost] [trace] ExtHostCommands#registerCommand python.refactorExtractMethod
[2021-11-19 17:11:17.305] [exthost] [trace] ExtHostCommands#registerCommand python.sortImports
[2021-11-19 17:11:17.305] [exthost] [trace] ExtHostCommands#registerCommand python.execInTerminal
[2021-11-19 17:11:17.305] [exthost] [trace] ExtHostCommands#registerCommand python.execInTerminal-icon
[2021-11-19 17:11:17.305] [exthost] [trace] ExtHostCommands#registerCommand python.execSelectionInTerminal
[2021-11-19 17:11:17.305] [exthost] [trace] ExtHostCommands#registerCommand python.execSelectionInDjangoShell
[2021-11-19 17:11:17.305] [exthost] [trace] ExtHostCommands#registerCommand python.setLinter
[2021-11-19 17:11:17.305] [exthost] [trace] ExtHostCommands#registerCommand python.enableLinting
[2021-11-19 17:11:17.305] [exthost] [trace] ExtHostCommands#registerCommand python.runLinting
[2021-11-19 17:11:17.307] [exthost] [trace] ExtHostCommands#registerCommand python.startREPL
[2021-11-19 17:11:17.307] [exthost] [trace] ExtHostCommands#registerCommand python.createTerminal
[2021-11-19 17:11:17.308] [exthost] [trace] ExtHostCommands#registerCommand python.clearPersistentStorage
[2021-11-19 17:11:17.309] [exthost] [trace] ExtHostCommands#registerCommand python.switchOffInsidersChannel
[2021-11-19 17:11:17.309] [exthost] [trace] ExtHostCommands#registerCommand python.switchToDailyChannel
[2021-11-19 17:11:17.309] [exthost] [trace] ExtHostCommands#registerCommand python.switchToWeeklyChannel
[2021-11-19 17:11:17.309] [exthost] [trace] ExtHostCommands#registerCommand python.reloadVSCode
[2021-11-19 17:11:17.309] [exthost] [trace] ExtHostCommands#registerCommand python.reportIssue
[2021-11-19 17:11:17.310] [exthost] [trace] ExtHostCommands#registerCommand python.revealTestItem
[2021-11-19 17:11:17.310] [exthost] [trace] ExtHostCommands#registerCommand python.setInterpreter
[2021-11-19 17:11:17.310] [exthost] [trace] ExtHostCommands#registerCommand python.clearWorkspaceInterpreter
[2021-11-19 17:11:17.310] [exthost] [trace] ExtHostCommands#registerCommand python.setShebangInterpreter
[2021-11-19 17:11:17.311] [exthost] [info] Extension 'ms-python.python' uses a document selector without scheme. Learn more about this: https://go.microsoft.com/fwlink/?linkid=872305
[2021-11-19 17:11:17.311] [exthost] [trace] ExtHostCommands#registerCommand python.interpreterPath
[2021-11-19 17:11:17.311] [exthost] [trace] ExtHostCommands#registerCommand python.SelectAndInsertDebugConfiguration
[2021-11-19 17:11:17.311] [exthost] [trace] ExtHostCommands#registerCommand python.pickLocalProcess
[2021-11-19 17:11:17.311] [exthost] [trace] ExtHostCommands#registerCommand python.launchTensorBoard
[2021-11-19 17:11:17.311] [exthost] [trace] ExtHostCommands#registerCommand python.refreshTensorBoard
[2021-11-19 17:11:18.636] [exthost] [trace] ExtHostCommands#registerCommand python.buildWorkspaceSymbols
[2021-11-19 17:11:18.638] [exthost] [trace] ExtHostCommands#registerCommand python.discoverTests
[2021-11-19 17:11:18.638] [exthost] [trace] ExtHostCommands#registerCommand python.configureTests
[2021-11-19 17:11:18.638] [exthost] [trace] ExtHostCommands#registerCommand python.runFailedTests
[2021-11-19 17:11:18.638] [exthost] [trace] ExtHostCommands#registerCommand python.runtests
[2021-11-19 17:11:18.638] [exthost] [trace] ExtHostCommands#registerCommand python.debugtests
[2021-11-19 17:11:18.638] [exthost] [trace] ExtHostCommands#registerCommand python.viewTestUI
[2021-11-19 17:11:18.638] [exthost] [trace] ExtHostCommands#registerCommand python.selectTestToRun
[2021-11-19 17:11:18.638] [exthost] [trace] ExtHostCommands#registerCommand python.selectTestToDebug
[2021-11-19 17:11:18.638] [exthost] [trace] ExtHostCommands#registerCommand python.runParametrizedTests
[2021-11-19 17:11:18.638] [exthost] [trace] ExtHostCommands#registerCommand python.stopTests
[2021-11-19 17:11:18.638] [exthost] [trace] ExtHostCommands#registerCommand python.viewTestOutput
[2021-11-19 17:11:18.638] [exthost] [trace] ExtHostCommands#registerCommand python.askToStopTestDiscovery
[2021-11-19 17:11:18.638] [exthost] [trace] ExtHostCommands#registerCommand python.askToStopTests
[2021-11-19 17:11:18.638] [exthost] [trace] ExtHostCommands#registerCommand python.selectAndRunTestMethod
[2021-11-19 17:11:18.638] [exthost] [trace] ExtHostCommands#registerCommand python.selectAndDebugTestMethod
[2021-11-19 17:11:18.638] [exthost] [trace] ExtHostCommands#registerCommand python.selectAndRunTestFile
[2021-11-19 17:11:18.638] [exthost] [trace] ExtHostCommands#registerCommand python.runCurrentTestFile
[2021-11-19 17:11:18.638] [exthost] [trace] ExtHostCommands#registerCommand python.discoveringTests
[2021-11-19 17:11:18.640] [exthost] [trace] ExtHostCommands#registerCommand python.goToPythonObject
[2021-11-19 17:11:18.655] [exthost] [trace] [ms-python.python] INVOKE provider 'u'
[2021-11-19 17:11:18.832] [exthost] [trace] [DiagnosticCollection] remove all (extension, owner) ms-python.python python

[lppsuixn]

same problem~

[ZeroVoid10]

Changing the Online Services Settings: Telemetry: Telemetry Level to off and some other settings which may need connect to internet may solve it when in the offline environment.

[code-asher]

I wanted to dig into this but just do not have the time. It might be better to report this upstream, it would need to be fixed there anyway.