Vscode: No window opens when previously having an empty window open and then starting with --extensionDevelopmentPath

[caleteeter]

• VSCode Version:1.46.0-insider
• OS Version: Windows 10 2004 (OS Build 19041.264)

Steps to Reproduce:

1. Install package dependencies, run: npm run test
2. The vscode (stable) instance is downloaded to .vscode-test and the test hangs at: command prompt with: [main 2020-06-05T21:45:22.670Z] update#setState idle

This failed on my extension and I tested with the helloworld-sample tests as well. Same result.

I have waited for up to 10 mins, it will eventually just exit. When running the tests from the Task Launcher (not command line) it works fine.

Does this issue occur when all extensions are disabled?: Yes/No Yes

[caleteeter]

Update: I have found that if you start a vscode instance while this is waiting for tests to run, it will use the instance. So I guess what is happening, the vscode instance that is downloaded is not launched in all cases.

[apupier]

I'm hitting the same kind of behavior with 1.46.0.
Impacted projects:

• https://github.com/camel-tooling/vscode-camelk
• https://github.com/camel-tooling/camel-lsp-client-vscode

it works fine locally (Fedora 31) and on Travis CI (Ubuntu Xenial) and when launching from VS Code UI launcher. On our Jenkins CI, which is using RHEL 7, we are facing the same problem mentioned here. It is hanging for a very long time (at least 3 hours, I killed it after)

UPDATE: it is working with RHEL 8 on Jenkins CI

Any ideas how to investigate this issue?

[luispDesktop]

Hitting the same issues on our side. Only versions hitting this are 1.46 and above
Would be really appreciated if we could get an update here please?

[shamiwillms]

Is there a plan for when this can get fixed? This is hitting my team too!

[aletsdelarosa]

Hello,
Is hitting our pipelines in Azure Dev Ops. We are using VSCode stable in Windows. Using 1.47.0 and above

[bpasero]

Can people that see this do the following change to runTests.ts to get verbose output and post it here:

await runTests({ extensionDevelopmentPath, extensionTestsPath, launchArgs: ['--verbose'] });

[dbaeumer]

I was seeing the same. What fixed it for me was to use a fresh userData and extensions dir. I start my tests like this

async function go() {
    try {
        const extensionDevelopmentPath = path.resolve(__dirname, '..');
        const extensionTestsPath = __dirname;
        const testDir = path.join(os.tmpdir(), uuid.v4());
        fs.mkdirSync(testDir, { recursive: true });
        const userDataDir = path.join(testDir, 'userData');
        fs.mkdirSync(userDataDir);
        const extensionDir = path.join(testDir, 'extensions');
        fs.mkdirSync(extensionDir);
        const workspaceFolder = path.join(testDir, 'workspace');
        fs.mkdirSync(workspaceFolder);
        /**
         * Basic usage
         */
        await runTests({
            version: '1.44.0',
            extensionDevelopmentPath,
            extensionTestsPath,
            launchArgs: [
                '--user-data-dir', userDataDir,
                '--extensions-dir', extensionDir,
                workspaceFolder
            ]
        });
        rimraf(testDir);
    } catch (err) {
        console.error('Failed to run tests');
        process.exitCode = 1;
    }
}

[ChristophNiehoff]

@bpasero I hope this helps.
jenkins-vscode-log.txt

From there the log hangs and every 5min I get the additional lines:

[File Watcher (node.js)] [CHANGED] /home/jenkins-slave/.config/Code/logs/20200721T142407/sharedprocess.log
[File Watcher (node.js)] >> normalized [CHANGED] /home/jenkins-slave/.config/Code/logs/20200721T142407/sharedprocess.log
[File Watcher (node.js)] [CHANGED] /home/jenkins-slave/.config/Code/logs/20200721T142407/sharedprocess.log
[File Watcher (node.js)] >> normalized [CHANGED] /home/jenkins-slave/.config/Code/logs/20200721T142407/sharedprocess.log

[bpasero]

@ChristophNiehoff unfortunately I cannot find anything suspicious in that output, at least no error is showing up when I scan through the output.

Does it help to pass a different user-data-dir as Dirk suggested?

[eamodio]

I am seeing the same thing, but when run with the --verbose it seemed to work. It also worked fine for me using the --disable-extensions flag

await runTests({ extensionDevelopmentPath, extensionTestsPath, launchArgs: ['--disable-extension'] });

I wonder if it has something to do with the eslint popup dialog.

[dbaeumer]

@eamodio could be, but I saw the behavior already weeks ago. Do you see the dialog in the test instance when it hangs?

[eamodio]

I think it was a red-herring, it didn't show up on the hang, but it did on the successful run.

[dbaeumer]

And the LiveShare devs see this in the Azure Pipeline which always is a fresh machine with no extensions installed. So unless they install ESLint in their test setup it can actually not happen.

[ChristophNiehoff]

@bpasero I tried adding a new user-data-dir as well as a new extensions-dir, but unfortunately this did not change the behavior...

[luispDesktop]

We are on the same boat as @ChristophNiehoff

[aletsdelarosa]

And the LiveShare devs see this in the Azure Pipeline which always is a fresh machine with no extensions installed. So unless they install ESLint in their test setup it can actually not happen.

I added launchArgs: ['--verbose'] and running with VSCode 1.47.3 and our Azure pipeline is working now

[IntelOrca]

After hitting the same issue, I found that setting "window.restoreWindows": "none" in my user preferences fixes the issue.

[MarioCadenas]

Having the same problem, has anyone find a solution to this?

[bpasero]

I think this is not a problem with VSCode but the CI the tests are running with. To proof that, I have created https://github.com/bpasero/test-ts-pipeline which is a simple "Hello World" VSCode extension generated with the latest yo code generator. It configures a GitHub workflow to run tests on Windows, macOS and Linux:

https://github.com/bpasero/test-ts-pipeline/blob/master/.github/workflows/main.yml

All three platforms run successfully:

https://github.com/bpasero/test-ts-pipeline/runs/1182568572

If someone can provide a similar setup where the run fails consistently, we can continue to investigate.

[IntelOrca]

@bpasero we found the problem only appears when you start a normal instance of vscode and then close that prior to running command line tests.

[bpasero]

@IntelOrca can you please provide exact steps for me to reproduce exactly that scenario with all the detail you can provide for me to reproduce exactly?

[MarioCadenas]

having the same version on package.json engines and runTests vscode version worked for me

// package.json
  "engines": {
    "vscode": "^1.44.0"
  }

and

// runTest.js
    // ...
    await runTests({
      version: '1.44.0',
      extensionDevelopmentPath,
      extensionTestsPath,
      launchArgs: ['--disable-extensions'],
    });

[IntelOrca]

My steps are:

yo code
npm install
npm run compile
npm run test

...tests work.
Now launch vscode from start menu, then close it.

npm run test

Warning: 'sandbox' is not in the list of known options, but still passed to Electron/Chromium.

[main 2020-09-30T08:37:04.912Z] update#setState idle

Gets stuck here.
Adding the following option to my vscode settings fixes it:

    "window.restoreWindows": "none",

installed vscode version details:
Version: 1.49.2 (user setup)
Commit: e5e9e69aed6e1984f7499b7af85b3d05f9a6883a
Date: 2020-09-24T16:29:41.983Z
Electron: 9.2.1
Chrome: 83.0.4103.122
Node.js: 12.14.1
V8: 8.3.110.13-electron.0
OS: Windows_NT x64 10.0.19041

[bpasero]

@IntelOrca tried your steps, works fine for me. Could it be that VSCode is still running after you close it? Does it reproduce with stock settings?

[IntelOrca]

I checked task manager and there are no code processes running after closing the instance of vscode. It does reproduce with no settings file. My colleague also has the same issue so I don't think it is specific to my installation.

[bpasero]

@IntelOrca can you follow https://github.com/microsoft/vscode/issues/99492#issuecomment-661743191 and print the output here from the run that does not work?

[IntelOrca]

> [email protected] pretest C:\git\vscode-test-bug\test-99492
> npm run compile && npm run lint


> [email protected] compile C:\git\vscode-test-bug\test-99492
> tsc -p ./


> [email protected] lint C:\git\vscode-test-bug\test-99492
> eslint src --ext ts


> [email protected] test C:\git\vscode-test-bug\test-99492
> node ./out/test/runTest.js

Found .vscode-test/vscode-1.49.2. Skipping download.


Warning: 'sandbox' is not in the list of known options, but still passed to Electron/Chromium.

[main 2020-09-30T09:41:10.168Z] Starting VS Code

[main 2020-09-30T09:41:10.168Z] from: c:\git\vscode-test-bug\test-99492\.vscode-test\vscode-1.49.2\resources\app

[main 2020-09-30T09:41:10.168Z] args: {
  _: [],
  diff: false,
  add: false,
  goto: false,
  'new-window': false,
  'reuse-window': false,
  wait: false,
  help: false,
  'list-extensions': false,
  'show-versions': false,
  version: false,
  verbose: true,
  status: false,
  'prof-startup': false,
  'disable-extensions': false,
  'disable-gpu': false,
  telemetry: false,
  extensionDevelopmentPath: [ 'C:\\git\\vscode-test-bug\\test-99492' ],
  extensionTestsPath: 'C:\\git\\vscode-test-bug\\test-99492\\out\\test\\suite\\index',
  logExtensionHostCommunication: false,
  'skip-release-notes': false,
  'disable-restore-windows': false,
  'disable-telemetry': false,
  'disable-updates': false,
  'disable-crash-reporter': false,
  'crash-reporter-id': '5ac96a46-7df0-4a68-a409-fc14676af576',
  'disable-user-env-probe': false,
  'skip-add-to-recently-opened': false,
  'unity-launch': false,
  'open-url': false,
  'file-write': false,
  'file-chmod': false,
  'driver-verbose': false,
  force: false,
  'do-not-sync': false,
  trace: false,
  'force-user-env': false,
  'open-devtools': false,
  'no-proxy-server': false,
  nolazy: false,
  'force-renderer-accessibility': false,
  'ignore-certificate-errors': false,
  'allow-insecure-localhost': false
}

[main 2020-09-30T09:41:10.169Z] Resolving machine identifier...
[main 2020-09-30T09:41:10.169Z] Resolved machine identifier: 9fc7150a1202de7c35403986210eaff37fa7df8967d80483eab96f9badfb2307

[main 2020-09-30T09:41:10.188Z] [storage :memory:] open(:memory:, retryOnBusy: true)

[main 2020-09-30T09:41:10.188Z] lifecycle (main): phase changed (value: 2)

[main 2020-09-30T09:41:10.189Z] windowsManager#open

[main 2020-09-30T09:41:10.190Z] lifecycle (main): phase changed (value: 3)

[main 2020-09-30T09:41:10.190Z] update#setState idle

[main 2020-09-30T09:41:10.230Z] getShellEnvironment: running on Windows, skipping

[main 2020-09-30T09:41:10.231Z] [storage :memory:] Trace (event): SELECT * FROM ItemTable
[main 2020-09-30T09:41:10.231Z] [storage :memory:] getItems(): 0 rows

[main 2020-09-30T09:41:10.341Z] [storage :memory:] updateItems(): insert(Map(4) {__$__isNewStorageMarker => true, telemetry.instanceId => aa81e588-9756-43d1-aea1-b38b55505b9d, telemetry.firstSessionDate => Wed, 30 Sep 2020 09:41:10 GMT, telemetry.currentSessionDate => Wed, 30 Sep 2020 09:41:10 GMT}), delete(Set(0) {})

[main 2020-09-30T09:41:10.342Z] [storage :memory:] Trace (event): BEGIN TRANSACTION

[main 2020-09-30T09:41:10.342Z] [storage :memory:] Trace (event): INSERT INTO ItemTable VALUES ('__$__isNewStorageMarker','true'),('telemetry.instanceId','aa81e588-9756-43d1-aea1-b38b55505b9d'),('telemetry.firstSessionDate','Wed, 30 Sep 2020 09:41:10 GMT'),('telemetry.currentSessionDate','Wed, 30 Sep 2020 09:41:10 GMT')

[main 2020-09-30T09:41:10.343Z] [storage :memory:] Trace (event): END TRANSACTION

[main 2020-09-30T09:41:13.433Z] Shared process: IPC ready

[main 2020-09-30T09:41:15.276Z] Shared process: init ready

[main 2020-09-30T09:41:15.515Z] [storage :memory:] updateItems(): insert(Map(3) {sync.previous.store => {"url":"https://vscode-sync.trafficmanager.net/","authenticationProviders":{"microsoft":{"scopes":["https://management.core.windows.net/.default","offline_access"]},"github":{"scopes":["user:email"]}}}, sync.storeUrl => https://vscode-sync.trafficmanager.net/, storage.serviceMachineId => e875f0f4-7a31-4649-8da9-5fef9ea46bd2}), delete(Set(0) {})

[main 2020-09-30T09:41:15.516Z] [storage :memory:] Trace (event): BEGIN TRANSACTION

[main 2020-09-30T09:41:15.516Z] [storage :memory:] Trace (event): INSERT INTO ItemTable VALUES ('sync.previous.store','{"url":"https://vscode-sync.trafficmanager.net/","authenticationProviders":{"microsoft":{"scopes":["https://management.core.windows.net/.default","offline_access"]},"github":{"scopes":["user:email"]}}}'),('sync.storeUrl','https://vscode-sync.trafficmanager.net/'),('storage.serviceMachineId','e875f0f4-7a31-4649-8da9-5fef9ea46bd2')

[main 2020-09-30T09:41:15.517Z] [storage :memory:] Trace (event): END TRANSACTION

[bpasero]

I cannot explain this, after the line [main 2020-09-30T09:41:10.189Z] windowsManager#open there should be more output from the window that opens, e.g. I get window#validateWindowState: validating window state on 1 display(s).

I can try to add more logging to understand why your execution does not result in a window to open.

[bpasero]

@IntelOrca and do you see the same when you switch to insiders, via:

await runTests({ extensionDevelopmentPath, extensionTestsPath, launchArgs: ['--verbose'], version: 'insiders' });

To reproduce I guess you would then first have to start a local installed Insiders.

[IntelOrca]

If the tests run insiders then it works as it won't conflict with my main release of vscode. However after running my main vscode insiders instance and then running the command line tests that use insiders, I get the same problem still.

[bpasero]

@IntelOrca thanks for trying, I added some more logging but we need to wait for another round of insider builds.

Something to test until then: when you CD into \.vscode-test\vscode-1.49.2 and simply run the downloaded VSCode from that folder, does it then bring up a window?

[IntelOrca]

Something to test until then: when you CD into .vscode-test\vscode-1.49.2 and simply run the downloaded VSCode from that folder, does it then bring up a window?

Yeah, I think it only has the problem when specifying the extension development and testing arguments.

[bpasero]

I just checked and our startup arguments are identical except for the paths. When you manually start that VSCode with the same arguments, does it then also fail? Speaking of --extensionDevelopmentPath and --extensionTestsPath

[IntelOrca]

Yep, just "Code - Insiders.exe" --extensionDevelopmentPath=C:\git\vscode-test-bug\test-99492 is enough to get it to hang. It also happens if I use the main instance executable as opposed to the one the tests downloaded.

[bpasero]

@IntelOrca how about using code and not the exe directly, any difference?

[bpasero]

@IntelOrca also, a new insiders build is out with my additional logging, so please try with this:

await runTests({ extensionDevelopmentPath, extensionTestsPath, launchArgs: ['--verbose'], version: 'insiders' });

and let me know the output.

[IntelOrca]

Here is latest logging:

> [email protected] pretest C:\git\vscode-test-bug\test-99492
> npm run compile && npm run lint


> [email protected] compile C:\git\vscode-test-bug\test-99492
> tsc -p ./


> [email protected] lint C:\git\vscode-test-bug\test-99492
> eslint src --ext ts


> [email protected] test C:\git\vscode-test-bug\test-99492
> node ./out/test/runTest.js

Found .vscode-test/vscode-insiders matching latest Insiders release. Skipping download.


Warning: 'sandbox' is not in the list of known options, but still passed to Electron/Chromium.

[main 2020-10-01T08:28:07.850Z] Starting VS Code

[main 2020-10-01T08:28:07.851Z] from: c:\git\vscode-test-bug\test-99492\.vscode-test\vscode-insiders\resources\app

[main 2020-10-01T08:28:07.851Z] args: {
  _: [],
  diff: false,
  add: false,
  goto: false,
  'new-window': false,
  'reuse-window': false,
  wait: false,
  help: false,
  'list-extensions': false,
  'show-versions': false,
  version: false,
  verbose: true,
  status: false,
  'prof-startup': false,
  'disable-extensions': false,
  'disable-gpu': false,
  telemetry: false,
  extensionDevelopmentPath: [ 'C:\\git\\vscode-test-bug\\test-99492' ],
  extensionTestsPath: 'C:\\git\\vscode-test-bug\\test-99492\\out\\test\\suite\\index',
  logExtensionHostCommunication: false,
  'skip-release-notes': false,
  'disable-restore-windows': false,
  'disable-telemetry': false,
  'disable-updates': false,
  'disable-crash-reporter': false,
  'crash-reporter-id': '8c659c00-8a27-4eb1-9852-8c403863a18f',
  'disable-user-env-probe': false,
  'skip-add-to-recently-opened': false,
  'unity-launch': false,
  'open-url': false,
  'file-write': false,
  'file-chmod': false,
  'driver-verbose': false,
  force: false,
  'do-not-sync': false,
  trace: false,
  'force-user-env': false,
  'open-devtools': false,
  'no-proxy-server': false,
  nolazy: false,
  'force-renderer-accessibility': false,
  'ignore-certificate-errors': false,
  'allow-insecure-localhost': false
}

[main 2020-10-01T08:28:07.852Z] Resolving machine identifier...
[main 2020-10-01T08:28:07.852Z] Resolved machine identifier: 60c996423c869f575fa4dd8886b167f8e6525788fbf5d7c1ffba8b0a0d0ed9ce

[main 2020-10-01T08:28:07.876Z] [storage :memory:] open(:memory:, retryOnBusy: true)

[main 2020-10-01T08:28:07.876Z] lifecycle (main): phase changed (value: 2)

[main 2020-10-01T08:28:07.877Z] windowsManager#open

[main 2020-10-01T08:28:07.878Z] windowsManager#open pathsToOpen [
  {
    backupPath: 'C:\\Users\\Ted\\AppData\\Roaming\\Code - Insiders\\Backups\\1601462256166',
    remoteAuthority: undefined
  }
]

[main 2020-10-01T08:28:07.878Z] windowsManager#open used window count 0 (workspacesToOpen: 0, foldersToOpen: 0, emptyToRestore: 0, emptyToOpen: 0)

[main 2020-10-01T08:28:07.879Z] lifecycle (main): phase changed (value: 3)

[main 2020-10-01T08:28:07.880Z] update#setState idle

[main 2020-10-01T08:28:07.928Z] getShellEnvironment: running on Windows, skipping

[main 2020-10-01T08:28:07.929Z] [storage :memory:] Trace (event): SELECT * FROM ItemTable
[main 2020-10-01T08:28:07.929Z] [storage :memory:] getItems(): 0 rows

[main 2020-10-01T08:28:08.034Z] [storage :memory:] updateItems(): insert(Map(4) {__$__isNewStorageMarker => true, telemetry.instanceId => c72b42f0-91af-4fff-8d8e-75609536e54f, telemetry.firstSessionDate => Thu, 01 Oct 2020 08:28:07 GMT, telemetry.currentSessionDate => Thu, 01 Oct 2020 08:28:07 GMT}), delete(Set(0) {})

[main 2020-10-01T08:28:08.035Z] [storage :memory:] Trace (event): BEGIN TRANSACTION

[main 2020-10-01T08:28:08.035Z] [storage :memory:] Trace (event): INSERT INTO ItemTable VALUES ('__$__isNewStorageMarker','true'),('telemetry.instanceId','c72b42f0-91af-4fff-8d8e-75609536e54f'),('telemetry.firstSessionDate','Thu, 01 Oct 2020 08:28:07 GMT'),('telemetry.currentSessionDate','Thu, 01 Oct 2020 08:28:07 GMT')

[main 2020-10-01T08:28:08.036Z] [storage :memory:] Trace (event): END TRANSACTION

[main 2020-10-01T08:28:11.177Z] Shared process: IPC ready

[main 2020-10-01T08:28:15.437Z] Shared process: init ready

[main 2020-10-01T08:28:15.671Z] [storage :memory:] updateItems(): insert(Map(3) {sync.previous.store => {"web":{"url":"https://vscode-sync.trafficmanager.net/","canSwitch":false},"url":"https://vscode-sync-insiders.trafficmanager.net/","stableUrl":"https://vscode-sync.trafficmanager.net/","insidersUrl":"https://vscode-sync-insiders.trafficmanager.net/","canSwitch":true,"authenticationProviders":{"microsoft":{"scopes":["https://management.core.windows.net/.default","offline_access"]},"github":{"scopes":["user:email"]}}}, sync.storeUrl => https://vscode-sync-insiders.trafficmanager.net/, storage.serviceMachineId => 83dc0d91-8ac6-4b0d-95ed-154d583db475}), delete(Set(0) {})

[main 2020-10-01T08:28:15.672Z] [storage :memory:] Trace (event): BEGIN TRANSACTION

[main 2020-10-01T08:28:15.672Z] [storage :memory:] Trace (event): INSERT INTO ItemTable VALUES ('sync.previous.store','{"web":{"url":"https://vscode-sync.trafficmanager.net/","canSwitch":false},"url":"https://vscode-sync-insiders.trafficmanager.net/","stableUrl":"https://vscode-sync.trafficmanager.net/","insidersUrl":"https://vscode-sync-insiders.trafficmanager.net/","canSwitch":true,"authenticationProviders":{"microsoft":{"scopes":["https://management.core.windows.net/.default","offline_access"]},"github":{"scopes":["user:email"]}}}'),('sync.storeUrl','https://vscode-sync-insiders.trafficmanager.net/'),('storage.serviceMachineId','83dc0d91-8ac6-4b0d-95ed-154d583db475')

[main 2020-10-01T08:28:15.672Z] [storage :memory:] Trace (event): END TRANSACTION

[main 2020-10-01T08:28:37.892Z] update#checkForUpdates, state =  idle

[main 2020-10-01T08:28:37.893Z] update#setState checking for updates
[main 2020-10-01T08:28:37.894Z] RequestService#request https://update.code.visualstudio.com/api/update/win32-archive/insider/228973889bc0e352f7cd11cc14755893f8d81864

[main 2020-10-01T08:28:38.880Z] update#setState idle

I don't think runnning code-insiders.cmd makes any difference. It is just a wrapper around running the same exe with same arguments.

[bpasero]

Thanks a lot, I can reproduce finally. It only happens when the last window that was opened is empty. I think a regression from https://github.com/microsoft/vscode/commit/7b681aa2fb49229e8a51443f782270937a175588

[bpasero]

Steps:

• run out of sources and leave have 1 empty window (File > Close Folder)
• exit
• run scripts/code.sh --extensionDevelopmentPath /Users/bpasero/Desktop/test-ts
• :bug: no window opens

[bpasero]

There was a weird extra check for extensionDevelopmentPath from the command line to decide wether to restore empty windows or those with untitled workspaces. I removed that check and hope this does not have negative impact. The consequence is that if you had untitled workspaces from a previous session, all these will also restore.

[IntelOrca]

Thanks @bpasero, I will give it a spin tomorrow. 🙂

[IntelOrca]

@bpasero, I can confirm today's insiders now fixes the issue