microsoft/vscode-cmake-tools

EBUSY error from "C:\DumpStack.log.tmp"

leolcao opened this issue · 14 comments

leolcao commented

Brief Issue Summary

cmakes-tools make vscode extension host crash

Expected:

No crash to restart the extension host

Apparent Behavior:

  1. Remove the cmake-tools extension 1.4.1
  2. Restart vs code
  3. Re-install cmake-tools 1.4.1
  4. Unpredictable crash in any time during work
  5. Uninstall cmake-tools 1.4.1 again and restart VS Code, no crash(rarely) even in long time work

CMake Tools Log

N/A.

Developer Tools Log

events.js:200
      throw er; // Unhandled 'error' event
      ^

Error: EBUSY: resource busy or locked, lstat 'C:\DumpStack.log.tmp'
Emitted 'error' event on FSWatcher instance at:
    at FSWatcher._handleError (c:\Users\<user>\.vscode\extensions\ms-vscode.cmake-tools-1.4.1\node_modules\chokidar\index.js:629:1)
    at ReaddirpStream.NodeFsHandler._boundHandleError (c:\Users\<user>\.vscode\extensions\ms-vscode.cmake-tools-1.4.1\node_modules\chokidar\lib\nodefs-handler.js:302:1)
    at ReaddirpStream.emit (events.js:223:5)
    at emitErrorNT (internal/streams/destroy.js:92:8)
    at emitErrorAndCloseNT (internal/streams/destroy.js:60:3)
    at processTicksAndRejections (internal/process/task_queues.js:81:21) {
  errno: -4082,
  code: 'EBUSY',
  syscall: 'lstat',
  path: 'C:\\DumpStack.log.tmp',
  vslsStack: []
}

Platform and Versions

  • Operating System: Windows 10 x64 10.0.19041.508
  • CMake Version: MSYS2 MinGW CMake 3.17.3
  • VSCode Version: 1.49.0
  • CMake Tools Extension Version: 1.4.1
  • Compiler/Toolchain: MSVC 2017/2019, MSYS2 MinGW GCC/Clang

Other Notes/Information

leolcao commented

I figure it out by myself according to : https://answers.microsoft.com/en-us/windows/forum/all/dumpstacklog-file/eba04d25-bac2-4173-b9d5-b1a8fc47f64e

But, it still will make VSCode extension host crash with new messages:

c:\Users\leo.cao\.vscode\extensions\ms-vscode.cmake-tools-1.4.1\dist\main.js:1355
            throw e;
            ^

TypeError: message must be set
    at new V (c:\Users\<user>\AppData\Local\Programs\Microsoft VS Code\resources\app\out\vs\workbench\services\extensions\node\extensionHostProcess.js:508:651)
    at new V (c:\Users\<user>\AppData\Local\Programs\Microsoft VS Code\resources\app\out\vs\workbench\services\extensions\node\extensionHostProcess.js:497:187)
    at CMakeOutputConsumer._parseDiags (c:\Users\<user>\.vscode\extensions\ms-vscode.cmake-tools-1.4.1\src\diagnostics\cmake.ts:96:24)
    at CMakeOutputConsumer.error (c:\Users\<user>\.vscode\extensions\ms-vscode.cmake-tools-1.4.1\src\diagnostics\cmake.ts:75:10)
    at c:\Users\<user>\.vscode\extensions\ms-vscode.cmake-tools-1.4.1\src\proc.ts:198:32
    at RollbarController.invoke (c:\Users\<user>\.vscode\extensions\ms-vscode.cmake-tools-1.4.1\src\rollbar.ts:127:14)
    at Socket.<anonymous> (c:\Users\<user>\.vscode\extensions\ms-vscode.cmake-tools-1.4.1\src\proc.ts:192:19)
    at Socket.emit (events.js:223:5)
    at addChunk (_stream_readable.js:309:12)
    at readableAddChunk (_stream_readable.js:290:11)
    at Socket.Readable.push (_stream_readable.js:224:10)
    at Pipe.onStreamRead (internal/stream_base_commons.js:181:23) {
  vslsStack: [
    CallSite {}, CallSite {},
    CallSite {}, CallSite {},
    CallSite {}, CallSite {},
    CallSite {}, CallSite {},
    CallSite {}, CallSite {},
    CallSite {}, CallSite {}
  ]
}
asorgejr commented

I am experiencing this issue as well, same platform and versions (cmake-tools v1.4.2). Crashes are so frequent that it is unusable on larger project builds.

leolcao commented

The second issue about "message must be set" has been fixed in the 1.4.2 version.

For the beginning issue, I think it may not because of cmake tools itself, it should be the npm packages stuff related, because now I get another issue for the 'resource busy or locked' from 'c:\hiberfil.sys'. I haven't find the root cause, I just disabled all of extensions, and to check which extension has some conflicts with cmake tools.
BTW, I really hope vs code can provide the workspace based configuration to only enable allowed extensions.

bobbrow commented

@leolcao The presence of the node_modules folder in the released version of the extension is a mistake. PR #1456 should make sure this doesn't happen again. It looks like you deleted your message about that though.

leolcao commented

@bobbrow, thanks for your attention. Yes, I deleted my message few days ago, because that was not the right solution for this issue.
So, before the new version, what is the workaround to solve this issue?

Today, I try to delete whole node_modules, but cmake tools won't work anymore, which it depends on node_modules/vscode-nls.

BTW, can you explain something about the root cause of this issue? Why chokidar try to touch those files? c:\DumpStack.log.tmp, c:\hiberfil.sys, ...

I wanted to figure out its root cause by myself, but it could be nice if you can give me some tips.

leolcao commented

I found the root cause of this issue finally. @bobbrow, I think your PR is not relevant for this issue although the 'node_modules' is meaningless in production.

let me summary my finding:

VS Code Version: 1.49.2
CMake Tools Version: 1.4.2
Issue: In Windows 10 x64 10.0.19041.264, it will make the VS extension host crash unpredictably and frequently, sometime after 10 minutes, sometime immediately after restart the extension host. The log message from VS Code Developer Tools:

events.js:200
      throw er; // Unhandled 'error' event
      ^

Error: EBUSY: resource busy or locked, lstat 'C:\hiberfil.sys'
Emitted 'error' event on FSWatcher instance at:
    at FSWatcher._handleError (c:\Users\<user>\.vscode\extensions\ms-vscode.cmake-tools-1.4.2\node_modules\chokidar\index.js:631:1)
    at ReaddirpStream.NodeFsHandler._boundHandleError (c:\Users\<user>\.vscode\extensions\ms-vscode.cmake-tools-1.4.2\node_modules\chokidar\lib\nodefs-handler.js:319:1)
    at ReaddirpStream.emit (events.js:223:5)
    at emitErrorNT (internal/streams/destroy.js:92:8)
    at emitErrorAndCloseNT (internal/streams/destroy.js:60:3)
    at processTicksAndRejections (internal/process/task_queues.js:81:21) {
  errno: -4082,
  code: 'EBUSY',
  syscall: 'lstat',
  path: 'C:\\hiberfil.sys',
  vslsStack: []
}

Note: If only enable few of extensions, such as:

  • CMake(twxs.cmake v0.0.17)
  • CMake Tools(ms-vscode.cmake-tools v1.4.2)
  • C/C++(ms-vscode.cpptools v1.0.1)

It will not cause extension host crash, although it still throw above error log watched in Developer Tools, the VS Code Extension Host stay in running. After enabling more and more extensions, it will make the extension host crash, but not sure about which extension affects this.

Root cause:
In the constructor function in variant.ts, it use folder.uri.path to get the full file path from variant files.

const base_path = folder.uri.path;
    for (const filename of ['cmake-variants.yaml',
                            'cmake-variants.json',
                            '.vscode/cmake-variants.yaml',
                            '.vscode/cmake-variants.json']) {
      this._variantFileWatcher.add(path.join(base_path, filename));

So, after path.join(base_path, filename), each file path will be like: \d:\<relative path to>\cmake-variants.yaml, this will make chokidar try to state c:\d:\<relative path to>\cmake-variants.yaml, then adding the 'c:' finally into the watch list.

Then, if any file changed, like: 'c:\hiberfil.sys' or 'c:\DumpStack.log.tmp', chokidar will trigger the error because chokidar has not permission to use them.

Check the issue from chokidar github repo: paulmillr/chokidar#1037

Solution:
According to https://code.visualstudio.com/api/references/vscode-api#Uri, it should change const base_path = folder.uri.path; to const base_path = folder.uri.fsPath;

Actually, in the _reloadVariantsFile function of variant.ts, it already use the folder.uri.fsPath.

Troubleshooting way:

  • Reading source codes according to log message
  • Searching in related package's source codes
  • Inserting log statements in the installed code: %userprofile%\.vscode\extensions\ms-vscode.cmake-tools-1.4.2\dist\main.js.

Workaround before new version
Open installed cmake tools extension file: %userprofile%\.vscode\extensions\ms-vscode.cmake-tools-1.4.2\dist\main.js,
change the line 21775: const base_path = folder.uri.path; to const base_path = this.folder.uri.fsPath;

New Result from workaround:
Enable the same VS Code extensions(almost 110 extensions) as in before the workaround, chokidar will only add the workspace folder into watching list, so will not touch the c:\ directory. After long time watching(~ 1 hours), there is no any crash.

@bobbrow This fix is very simple, I think you can do that by yourself, Or, If let me to create a PR, which branch can be used to create a feature branch? and does the 'develop' branch is target for PR?

bobbrow commented

Thank you for your very detailed analysis! If you have time to create a pull request to fix this, we will be happy to review and accept it. Use the 'develop' branch as the target for the PR.

leolcao commented

@bobbrow just created a PR #1462

RReverser commented

Looks like I'm experiencing this too. Wasn't sure until now why extension host crashes several times per day, but seems to be coming from CMake:

image

bobbrow commented

We now publish builds of the extension with each commit to the repository. If you would like to help validate the fix for this, you can download the latest cmake-tools.vsix here: https://github.com/microsoft/vscode-cmake-tools/actions/runs/331832244

Unzip the download and then invoke the "Install from VSIX" command in VS Code to install it.

RReverser commented

Thanks. I think for now I'll keep CMake disabled, because another issue I've been experiencing is that it starts "Initializing" task and notification even on projects without CMakeLists.txt in the root dir. This has been quite annoying too, but not sure if it count as an issue.

bobbrow commented

The extension will initialize if a CMakeLists.txt exists somewhere in the folder, but it shouldn't do much unless you've set the cmake.sourceDirectory setting. If you have any extra details you can share about your workspace, that could help us investigate and I'd move this to a new issue. We're not trying to be annoying. 😉

RReverser commented

Fair enough :) I think I most commonly observed this on either Rust or even Node.js projects where one of the dependencies (or dependency of a dependency 😅) in some nested dir might have been a CMake project, but one that I obviously don't care about, since it's not the root project I'm working on. Yet, CMake was popping up with "do you want to initialize this project?" dialogue every time.

Hopefully this helps, but I'll try to re-enable the extension and see if I have a more concrete example.

leolcao commented

Since last time I did the quick fix like this:

Workaround before new version
Open installed cmake tools extension file: %userprofile%\.vscode\extensions\ms-vscode.cmake-tools-1.4.2\dist\main.js,
change the line 21775: const base_path = folder.uri.path; to const base_path = this.folder.uri.fsPath;

I already used CMake Tools in my production project since last time, and it is quite stable and not found any crash yet.

BTW, my job depends on VS Code totally, but the extensions are not so stable, so I use some strategies, like disable the extensions auto update function. For cmake tools, I usually set

"cmake.configureOnOpen": false

in the vscode user settings to let CMake tools not disturbing me.