Parallel node-gyp builds failing due to concurrent file access (Windows only)

[MRayermannMSFT]

Hi! I'm looking for help solving an issue we're starting to see more often on Windows, when npm install builds our native node modules.

The issue is that because npm install runs native module builds in parallel, and each needs exclusive access to some files, they end up failing due to not being able to get that exclusive access. We believe we're seeing this issue more often because we recently standardized on using node-addon-api for all five of our native modules. Thus, we have five parallel builds, all trying to access a lot of the same files. I've provided a series of example errors below (if someone wants full logs, I can provide those as well).

To be clear, I don't think this is necessarialy node-gyp's fault, however it may be part of the solution. For now, I am here to see if anyone in the node-gyp community has any ideas/thoughts/suggestions on how to proceed next. So far here's some ideas I've had:

1. Use --install-strategy=nested to de-deduplicate node-addon-api, thus reducing (maybe even eliminating) the chance of conflicting file access. Our project is ultimately bundled, so this will probably work out ok, but there are likely going to be other complications. Would be nice if we could only de-deduplicate node-addon-api.
2. Combine some of the five native modules, thus reducing the total number. This won't fix the problem, but it'll reduce the chance of it happening.
3. Solicit npm to not do parallel native node module installs.
4. Add a retry mechanism to node-gyp.
5. Prebuild the binaries for as many of our native node_modules as we can, thus avoiding having to rebuild them for the main project.
6. Write our own build-time code to de-deduplicate node-addon-api.
7. Use --ignore-scripts, and then use npm rebuild for any package which has an installScript: true in package-lock. Currently using this.
8. Use --foreground-scripts. Need to test this.

Details

The specified task executable "CL.exe" could not be run. System.IO.IOException: The process cannot access the file 'PATH_TO_NODE_MODULES\node-addon-api\Release\obj\nothing\nothing.tlog\CL.command.1.tlog' because it is being used by another process. [PATH_TO_NODE_MODULES\node-addon-api\nothing.vcxproj]
 at System.IO.__Error.WinIOError(Int32 errorCode, String maybeFullPath) [PATH_TO_NODE_MODULES\node-addon-api\nothing.vcxproj]
 at System.IO.FileStream.Init(String path, FileMode mode, FileAccess access, Int32 rights, Boolean useRights, FileShare share, Int32 bufferSize, FileOptions options, SECURITY_ATTRIBUTES secAttrs, String msgPath, Boolean bFromProxy, Boolean useLongPath, Boolean checkHost) [PATH_TO_NODE_MODULES\node-addon-api\nothing.vcxproj]
 at System.IO.FileStream..ctor(String path, FileMode mode, FileAccess access, FileShare share, Int32 bufferSize, FileOptions options, String msgPath, Boolean bFromProxy, Boolean useLongPath, Boolean checkHost) [PATH_TO_NODE_MODULES\node-addon-api\nothing.vcxproj]
 at System.IO.StreamReader..ctor(String path, Encoding encoding, Boolean detectEncodingFromByteOrderMarks, Int32 bufferSize, Boolean checkHost) [PATH_TO_NODE_MODULES\node-addon-api\nothing.vcxproj]
 at System.IO.StreamReader..ctor(String path) [PATH_TO_NODE_MODULES\node-addon-api\nothing.vcxproj]
 at System.IO.File.OpenText(String path) [PATH_TO_NODE_MODULES\node-addon-api\nothing.vcxproj]
 at Microsoft.Build.CPPTasks.TrackedVCToolTask.MapSourcesToCommandLines() [PATH_TO_NODE_MODULES\node-addon-api\nothing.vcxproj]
 at Microsoft.Build.CPPTasks.TrackedVCToolTask.GenerateSourcesOutOfDateDueToCommandLine() [PATH_TO_NODE_MODULES\node-addon-api\nothing.vcxproj]
 at Microsoft.Build.CPPTasks.CL.ComputeOutOfDateSources() [PATH_TO_NODE_MODULES\node-addon-api\nothing.vcxproj]
 at Microsoft.Build.CPPTasks.TrackedVCToolTask.SkipTaskExecution() [PATH_TO_NODE_MODULES\node-addon-api\nothing.vcxproj]
 at Microsoft.Build.Utilities.ToolTask.Execute() [PATH_TO_NODE_MODULES\node-addon-api\nothing.vcxproj]

Details

node-gyp\src\win_delay_load_hook.cc(1,1): error C1083: Cannot open compiler generated file: 'PATH_TO_NODE_MODULES\node-addon-api\Release\obj\nothing\win_delay_load_hook.obj': Permission denied [PATH_TO_NODE_MODULES\node-addon-api\nothing.vcxproj]

Details

npm error LINK : fatal error LNK1181: cannot open input file 'Release\obj\nothing\\node-addon-api\nothing.obj' [PATH_TO_NODE_MODULES\node-addon-api\nothing.vcxproj]

Details

The specified task executable "CL.exe" could not be run. System.IO.IOException: The process cannot access the file 'PATH_TO_NODE_MODULES\node-addon-api\Release\obj\nothing\nothing.tlog\CL.write.1.tlog' because it is being used by another process. [PATH_TO_NODE_MODULES\node-addon-api\nothing.vcxproj]
 at System.IO.__Error.WinIOError(Int32 errorCode, String maybeFullPath) [PATH_TO_NODE_MODULES\node-addon-api\nothing.vcxproj]
 at System.IO.FileStream.Init(String path, FileMode mode, FileAccess access, Int32 rights, Boolean useRights, FileShare share, Int32 bufferSize, FileOptions options, SECURITY_ATTRIBUTES secAttrs, String msgPath, Boolean bFromProxy, Boolean useLongPath, Boolean checkHost) [PATH_TO_NODE_MODULES\node-addon-api\nothing.vcxproj]
 at System.IO.FileStream..ctor(String path, FileMode mode, FileAccess access, FileShare share, Int32 bufferSize, FileOptions options, String msgPath, Boolean bFromProxy, Boolean useLongPath, Boolean checkHost) [PATH_TO_NODE_MODULES\node-addon-api\nothing.vcxproj]
 at System.IO.StreamWriter.CreateFile(String path, Boolean append, Boolean checkHost) [PATH_TO_NODE_MODULES\node-addon-api\nothing.vcxproj]
 at System.IO.StreamWriter..ctor(String path, Boolean append, Encoding encoding, Int32 bufferSize, Boolean checkHost) [PATH_TO_NODE_MODULES\node-addon-api\nothing.vcxproj]
 at System.IO.File.InternalWriteAllText(String path, String contents, Encoding encoding, Boolean checkHost) [PATH_TO_NODE_MODULES\node-addon-api\nothing.vcxproj]
 at System.IO.File.WriteAllText(String path, String contents, Encoding encoding) [PATH_TO_NODE_MODULES\node-addon-api\nothing.vcxproj]
 at Microsoft.Build.Utilities.CanonicalTrackedOutputFiles.SaveTlog(DependencyFilter includeInTLog) [PATH_TO_NODE_MODULES\node-addon-api\nothing.vcxproj]
 at Microsoft.Build.CPPTasks.CL.PostExecuteTool(Int32 exitCode) [PATH_TO_NODE_MODULES\node-addon-api\nothing.vcxproj]
 at Microsoft.Build.CPPTasks.TrackedVCToolTask.ExecuteTool(String pathToTool, String responseFileCommands, String commandLineCommands) [PATH_TO_NODE_MODULES\node-addon-api\nothing.vcxproj]
 at Microsoft.Build.CPPTasks.CL.ExecuteTool(String pathToTool, String responseFileCommands, String commandLineCommands) [PATH_TO_NODE_MODULES\node-addon-api\nothing.vcxproj]
 at Microsoft.Build.Utilities.ToolTask.Execute() [PATH_TO_NODE_MODULES\node-addon-api\nothing.vcxproj]

Details

npm error LINK : fatal error LNK1181: cannot open input file 'Release\obj\nothing\win_delay_load_hook.obj' [PATH_TO_NODE_MODULES\node-addon-api\nothing.vcxproj]

Details

npm error C:\Program Files\Microsoft Visual Studio\2022\Enterprise\MSBuild\Microsoft\VC\v170\Microsoft.CppBuild.targets(386,5): error MSB3374: The last access/last write time on file "Release\obj\nothing\nothing.tlog\unsuccessfulbuild" cannot be set. Could not find file 'PATH_TO_NODE_MODULES\node-addon-api\Release\obj\nothing\nothing.tlog\unsuccessfulbuild'. [PATH_TO_NODE_MODULES\node-addon-api\nothing.vcxproj]

Details

npm error FileTracker : error FTK1011: could not create the new file tracking log file: PATH_TO_NODE_MODULES\node-addon-api\Release\obj\nothing\nothing.tlog\CL.write.1.tlog. The file exists. [PATH_TO_NODE_MODULES\node-addon-api\nothing.vcxproj]

[lukekarrys]

@MRayermannMSFT I think 3 is likely the best option since npm is in charge of how and when those scripts get run.

There is also a hack/workaround that uses the npm flag --foreground-scripts which forces npm scripts to run sequentially: npm/cli#3034 (comment). Can you try and see if this flag does the same to native module builds?

[MRayermannMSFT]

There is also a hack/workaround that uses the npm flag --foreground-scripts which forces npm scripts to run sequentially:

Oh nice! I had actually just implemented a workaround using --ignore-scripts, where we use that flag, and then we use npm rebuild for any package which has an installScript: true in package-lock. I'll give --foreground-scripts a try as well though.

[tmm1]

Does this manifest as follows?

node-addon-api\Release\obj\node_addon_api_except\node_add.508A2FFA.tlog\node_addon_api_except.lastbuildstate' because it is being used by another process.

Does the --foreground-scripts workaround help?

EDIT: Missed the detailed logs above. I can confirm --foreground-scripts runs in serial and works around the issue.

[tmm1]

An alternative to --foreground-scripts is to use a simple retry loop around npm ci. However, this requires a taskkill /im vctip.exe /f within the loop to work (or the patch from #3112)

[lukekarrys]

I think with #3112 landing and any other fix being outside of what node-gyp is likely responsible for, I'm going to close this issue. Please let me know if this should be reopened if there's anything here I'm missing.

[MRayermannMSFT]

Thanks for making an effort at fixing this! I know it's a bit of a power user scenario. Will let you know if it comes up again.

[tmm1]

@MRayermannMSFT I'm curious if you noticed any difference after #3112?

I had a hard time upgrading to the latest node-gyp, but figured it out in #3172

 $nodePath = Split-Path -Parent (Get-Command node).Path
 npm install --global --prefix $nodePath\\node_modules\\npm node-gyp@latest

However I still see some errors like:

npm error C:\Program Files (x86)\Microsoft Visual Studio\2019\Enterprise\MSBuild\Microsoft\VC\v160\Microsoft.CppBuild.targets(382,5): error MSB3491: Could not write lines to file "Release\obj\node_addon_api_except\node_add.A3690B4C.tlog\node_addon_api_except.lastbuildstate". The process cannot access the file 'D:\a_work\1\s\vscode\node_modules@vscode\node-addon-api\Release\obj\node_addon_api_except\node_add.A3690B4C.tlog\node_addon_api_except.lastbuildstate' because it is being used by another process. [D:\a_work\1\s\vscode\node_modules@vscode\node-addon-api\node_addon_api_except.vcxproj]

as well as warnings:

npm warn cleanup 'D:\a\_work\1\s\vscode\node_modules\node-pty',
npm warn cleanup [Error: EBUSY: resource busy or locked, rmdir 'D:\a_work\1\s\vscode\node_modules\node-pty'] {

These go away by adding --foreground-scripts, but that makes execution unbearably slow.

[tmm1]

Yea my logs clearly show /nodeReuse:false added, but the errors continue.

It seems that flag will stop lingering processes, but currently tlog files are always generated and node-gyp running in parallel will cause failures. See dotnet/msbuild#10814

[MRayermannMSFT]

I'm curious if you noticed any difference after #3112?

Unfortunately I no longer work on the project that was haivng these issues. However, I do see that the project is still using the strategy of "Use --ignore-scripts, and then use npm rebuild for any package which has an installScript: true in package-lock". Guess they haven't gotten around to trying out the fixes made in April.