Vscode: Insiders failed to launch for test run using vscode-test ("Could not delete obsolete instance handle" - sock file missing?)

[DanTup]

I don't have repro steps for this (nor do I know how common it is), but it seems like this came up in #81652 but the issue was closed by the bot and it doesn't seem like it was addressed.

I'm running tests on GitHub Actions - this one using macOS. I use vscode-test to run the tests like this:

const res = await vstest.runTests({
    extensionDevelopmentPath: cwd,
    extensionTestsEnv: { ...testEnv, ...env },
    extensionTestsPath: path.join(cwd, "out", "src", "test", testFolder),
    launchArgs: [
        path.isAbsolute(workspaceFolder)
            ? workspaceFolder
            : path.join(cwd, "src", "test", "test_projects", workspaceFolder),
        "--user-data-dir",
        path.join(cwd, ".dart_code_test_data_dir"),
    ],
    version: process.env.CODE_VERSION,
});

This is called multiple times with different testFolder and workspaceFolder params. One test run was fine, but then I got this error (which then repeated for every subsequent invocation in the same way):

2019-12-05T09:17:37.8141490Z   test environment
2019-12-05T09:17:37.8146740Z 
2019-12-05T09:17:37.8147990Z     ✓ has opened the correct folder
2019-12-05T09:17:37.8150710Z 
2019-12-05T09:17:37.8151900Z   3 passing (6s)
2019-12-05T09:17:37.8152370Z 
2019-12-05T09:17:37.8158840Z Test run is complete! Calling VS Code callback with (null, 0)
2019-12-05T09:17:37.8173710Z 
2019-12-05T09:17:40.8880150Z Exit code:   0
2019-12-05T09:17:40.8880790Z Done
2019-12-05T09:17:40.8881040Z 
2019-12-05T09:17:40.8881520Z ############################################################
2019-12-05T09:17:40.8881740Z 
2019-12-05T09:17:40.8881870Z 
2019-12-05T09:17:40.8882050Z 
2019-12-05T09:17:40.8882550Z Running not_activated/dart_create tests folder in workspace empty
2019-12-05T09:17:40.8884650Z Attempting to download VS Code attempt #1
2019-12-05T09:17:41.1385550Z Found .vscode-test/vscode-1.40.2. Skipping download.
2019-12-05T09:17:41.1386330Z Running tests with pre-downloaded VS Code
2019-12-05T09:17:41.6285570Z Found .vscode-test/vscode-insiders matching latest Insiders release. Skipping download.
2019-12-05T09:17:42.0750980Z [main 2019-12-05T09:17:42.070Z] Could not delete obsolete instance handle Error: ENOENT: no such file or directory, unlink '/Users/runner/runners/2.162.0/work/Dart-Code/Dart-Code/.dart_code_test_data_dir/1.41.0-insider-main.sock'
2019-12-05T09:17:42.0751790Z     at Object.unlinkSync (original-fs.js:976:3)
2019-12-05T09:17:42.0752680Z     at Object.doStartup (/Users/runner/runners/2.162.0/work/Dart-Code/Dart-Code/.vscode-test/vscode-insiders/Visual Studio Code - Insiders.app/Contents/Resources/app/out/vs/code/electron-main/main.js:551:165)
2019-12-05T09:17:42.0752980Z     at processTicksAndRejections (internal/process/task_queues.js:89:5) {
2019-12-05T09:17:42.0753490Z   errno: -2,
2019-12-05T09:17:42.0754000Z   syscall: 'unlink',
2019-12-05T09:17:42.0754680Z   code: 'ENOENT',
2019-12-05T09:17:42.0755420Z   path: '/Users/runner/runners/2.162.0/work/Dart-Code/Dart-Code/.dart_code_test_data_dir/1.41.0-insider-main.sock'
2019-12-05T09:17:42.0755680Z }
2019-12-05T09:17:42.0755760Z 
2019-12-05T09:17:42.0757390Z [main 2019-12-05T09:17:42.075Z] Error: ENOENT: no such file or directory, unlink '/Users/runner/runners/2.162.0/work/Dart-Code/Dart-Code/.dart_code_test_data_dir/1.41.0-insider-main.sock'
2019-12-05T09:17:42.0758040Z     at Object.unlinkSync (original-fs.js:976:3)
2019-12-05T09:17:42.0758900Z     at Object.doStartup (/Users/runner/runners/2.162.0/work/Dart-Code/Dart-Code/.vscode-test/vscode-insiders/Visual Studio Code - Insiders.app/Contents/Resources/app/out/vs/code/electron-main/main.js:551:165)
2019-12-05T09:17:42.0759230Z     at processTicksAndRejections (internal/process/task_queues.js:89:5)
2019-12-05T09:17:42.0759320Z 
2019-12-05T09:17:42.0884930Z Exit code:   1
2019-12-05T09:17:42.0886770Z Done
2019-12-05T09:17:42.0886940Z 
2019-12-05T09:17:42.0894300Z Failed
2019-12-05T09:17:42.0894790Z ############################################################
2019-12-05T09:17:42.0918950Z 

Is this something VS Code can recover better from? It's particularly bad on GitHub Actions where it's not possible to re-run individual steps (so I have to re-run a whole 1-hour run to retry this) - though I appreciate that's hardly VS Code's fault :-)

[DanTup]

Actually, I'm seeing this reliably. Most of my bots only run one set of tests, but the one that runs multiple is seeing this on Insiders on macOS all the time.

Anything I can do to get more info that might help understand what's happening?

[octref]

@dbaeumer I see some old issues where you know more about the socket files created. Do you have any pointers why this might happen?

[dbaeumer]

@octref for communication between various processes we use socket files under Linux / MacOS. The one mentioned here is for the main process. May be @bpasero knows about it.

I was on issues for the extension host and LSP server.

The problem looks like someone tries to delete a non existing socket file (ENOENT). May be we are simply missing code to handle this correctly

[bpasero]

I can answer if I know the source process and the target process. We have different IPC mechanisms in place depending on that.

[octref]

@DonJayamanne Did the problem in #81652 go away or did you find a solution?

[DonJayamanne]

Unfortunately this didn't go away for me.

[octref]

I don't think this is specific to vscode-test, but launching VS Code in general. @joaomoreno you are assigned for the other issue as well, do you have any insights?

[bpasero]

@DonJayamanne @DanTup would be good if you can try to reproduce this running out of sources, then we can possibly add some logging code

[DanTup]

I'm not sure how to make this run from source on GH Actions, but here's a repo that repros the issue on GH Actions:

https://github.com/DanTup/vscode-sock-issue-86382
https://github.com/DanTup/vscode-sock-issue-86382/runs/372401580#step:7:44
https://github.com/DanTup/vscode-sock-issue-86382/blob/1b26fc751d575aa81103da1d5b79eacd84f7a862/src/test/test_all.ts#L33

[joaomoreno]

This comes from https://github.com/microsoft/vscode/blob/3d5b61c8435f651a3788062978ea344abdf865e5/src/vs/code/electron-main/main.ts#L245

Which means that Code (1) wasn't able to connect to an existing socket file and (2) wasn't able to delete the socket file. So it can't proceed. Deleting the socket file is the recover action. If that fails we can't do anything else.

Do these tests run concurrently? If so, you must prevent that and run them serially, or run them all with separate user data dirs.

[DanTup]

@joaomoreno they do not run currently. I included a link to the code that runs the tests:

https://github.com/DanTup/vscode-sock-issue-86382/blob/1b26fc751d575aa81103da1d5b79eacd84f7a862/src/test/test_all.ts#L33

runTests is a function defined just above those lines, which just calls runTests of vscode-test and awaits it.

[joaomoreno]

Does it work if you sleep between runTests?

[DanTup]

It doesn't appear to. I added:

await new Promise((resolve) => setTimeout(resolve, 5000));

And still have the same failure:

https://github.com/DanTup/vscode-sock-issue-86382/runs/393328115#step:7:54

[joaomoreno]

Can you check whether that directory exists at the time the error occurs?

/Users/runner/runners/2.163.1/work/vscode-sock-issue-86382/vscode-sock-issue-86382/.test_data_dir

[DanTup]

That's the folder passed to VS Code's --user-data-dir flag so it will be created by the first test run (as far as I know, VS Code does not delete it).

If you fork the repo, it should all be set up to run using GitHub Actions when you commit, so it may be easier for you to debug there directly.

[joaomoreno]

Unfortunately I cannot afford to spend a day investigating an obscure user CI issue, surely you can understand. I'm more than happy to give you a general direction on where to look.

In any case, I would still write some code that checks for that folder's existence once runTests throws.

[DanTup]

Unfortunately I cannot afford to spend a day investigating an obscure user CI issue

That's disappointing. This is not an obscure user CI issue, it's a tiny trivial repro I built specifically to shows the issue in VS Code or vscode-test. There is almost zero code written by me above. vscode-test is invoked twice and the second time, VS Code fails to start up with an error. The repro really couldn't be any simpler - I even set it up on GH Actions so it was trivial for you to repro (there was a suggestion above about running from source which I don't know how to do) and to avoid any issues with it being someone elses CI system.

And FWIW, I've spent significant time (easily in the order of a large number of weeks) building repro cases for VS Code bugs. My GitHub account has 28 repositories containing 'vscode' where I've built full extension repros, and there are countless issues where I've provided code samples in issues.

[joaomoreno]

Bringing @octref in. Is it possible to runTests always from a different user data dir?

[DanTup]

Yep, the script above already passes user-data-dir so it's possible for us to pass a different one each time:

https://github.com/DanTup/vscode-sock-issue-86382/blob/1b26fc751d575aa81103da1d5b79eacd84f7a862/src/test/test_all.ts#L18-L19

That works and will do me. It feels a bit like side-stepping the issue without understanding it though - for ex. if VS Code isn't shutting down properly, it may be a bug that could affect users too?

[joaomoreno]

It could be. It would be handy to know why exactly the file cna be deleted. Are permissions broken? Does the parent folder no longer exist? That's why I asked to check the directory above.

Great to know the user-data-dir works around it.

[vscodebot[bot]]

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!

[connor4312]

Rob mentioned he's running into this when running from js-debug, see the linked issue for details. I postulated it might be related to our forceful killTree function that causes some bad/missing teardown behavior in VS Code.

[roblourens]

For me this is easy to repro. I can investigate more if someone can point me towards where these socket files are created and if you know why their path lengths might be limited. Seems like the path length is limited to 103 characters.

mkdir -p /tmp/aaaaaaaa/bbbbbbbbbbbbb/cccccccccccccccc/dddddddddddddddd/eeeeeeeeeeeeeee/fffffffffffffffff/gggggggggggggggggg/hhhhhhhhhhhhhhhhh/iiiiiiiiiiiiiii
code-insiders --user-data-dir /tmp/aaaaaaaa/bbbbbbbbbbbbb/cccccccccccccccc/dddddddddddddddd/eeeeeeeeeeeeeee/fffffffffffffffff/gggggggggggggggggg/hhhhhhhhhhhhhhhhh/iiiiiiiiiiiiiii # works
# same command again with --verbose, produces the error

ls -l /tmp/aaaaaaaa/bbbbbbbbbbbbb/cccccccccccccccc/dddddddddddddddd/eeeeeeeeeeeeeee/fffffffffffffffff/ggggggg

srwxr-xr-x  1 roblou  wheel  0 Mar  2 20:40 /tmp/aaaaaaaa/bbbbbbbbbbbbb/cccccccccccccccc/dddddddddddddddd/eeeeeeeeeeeeeee/fffffffffffffffff/ggggggg

[roblourens]

103 is exactly right: https://nodejs.org/api/net.html#net_identifying_paths_for_ipc_connections

[roblourens]

Here is my suggested fix https://github.com/microsoft/vscode/pull/91931

[joaomoreno]

Added comment to the PR: https://github.com/microsoft/vscode/pull/91931#pullrequestreview-387201695

Given that this is one instance and it's even a CI and not an actual use case, please just use a shorter user data dir. Is that possible?

[roblourens]

Will do this instead

How about I check the length and log a warning if it's too long but leave the logic alone