[rush] When rush performs phased operations, concurrent install autoinstallers may conflict and cause errors.

[LPegasus]

Summary

When rush performs phased operations, concurrent install autoinstallers may conflict and cause errors.

This happened randomly.

Repro steps

1. Create two projects with a autoinstaller command which registered in command-line.json.
2. Trigger this autoinstaller command of two projects simultaneously.

Expected result: install autoinstaller step should dedup.

Actual result: Random error. Sometimes, "xxx" module not found. Sometimes "pnpm" not found.

==[ SUCCESS: 3 operations ]====================================================

These operations completed successfully:
  app1 (build)         0.01 seconds
  app1 (type-check)    19.21 seconds
  app2 (build)         0.01 seconds

==[ FAILURE: 1 operation ]=====================================================

--[ FAILURE: app2 (type-check) ]-----------------------------[ 1.65 seconds ]--

/bin/sh: /*/rush-sample-repo/common/temp/pnpm-local/node_modules/.bin/pnpm: No such file or directory

ERROR: Process exited with code 127


Operations failed.

rush type-check (19.29 seconds)

==[ SUCCESS: 3 operations ]====================================================

These operations completed successfully:
  app1 (build)         0.01 seconds
  app1 (type-check)    19.89 seconds
  app2 (build)         0.01 seconds

==[ FAILURE: 1 operation ]=====================================================

--[ FAILURE: app2 (type-check) ]-----------------------------[ 9.26 seconds ]--

node:internal/modules/cjs/loader:1386
  throw err;
  ^

Error: Cannot find module '@ant-design/cssinjs'
Require stack:
- /*/rush-sample-repo/common/autoinstallers/tsc-wrapper/node_modules/.pnpm/antd@6.3.1_react-dom@19.2.4_react@19.2.4/node_modules/antd/lib/theme/internal.js
- /*/rush-sample-repo/common/autoinstallers/tsc-wrapper/node_modules/.pnpm/antd@6.3.1_react-dom@19.2.4_react@19.2.4/node_modules/antd/lib/affix/style/index.js
- /*/rush-sample-repo/common/autoinstallers/tsc-wrapper/node_modules/.pnpm/antd@6.3.1_react-dom@19.2.4_react@19.2.4/node_modules/antd/lib/affix/index.js
- /*/rush-sample-repo/common/autoinstallers/tsc-wrapper/node_modules/.pnpm/antd@6.3.1_react-dom@19.2.4_react@19.2.4/node_modules/antd/lib/index.js
  ...12 lines omitted...
  requireStack: [
    '/*/rush-sample-repo/common/autoinstallers/tsc-wrapper/node_modules/.pnpm/antd@6.3.1_react-dom@19.2.4_react@19.2.4/node_modules/antd/lib/theme/internal.js',
    '/*/rush-sample-repo/common/autoinstallers/tsc-wrapper/node_modules/.pnpm/antd@6.3.1_react-dom@19.2.4_react@19.2.4/node_modules/antd/lib/affix/style/index.js',
    '/*/rush-sample-repo/common/autoinstallers/tsc-wrapper/node_modules/.pnpm/antd@6.3.1_react-dom@19.2.4_react@19.2.4/node_modules/antd/lib/affix/index.js',
    '/*/rush-sample-repo/common/autoinstallers/tsc-wrapper/node_modules/.pnpm/antd@6.3.1_react-dom@19.2.4_react@19.2.4/node_modules/antd/lib/index.js',
    '/*/rush-sample-repo/common/autoinstallers/tsc-wrapper/index.js'
  ]
}

Node.js v22.21.1


Operations failed.

Details

I'll try to do some investigations later.

Standard questions

Please answer these questions to help us investigate your issue more quickly:

Question	Answer
@microsoft/rush globally installed version?	5.155.1
rushVersion from rush.json?	5.155.1
pnpmVersion, npmVersion, or yarnVersion from rush.json?	pnpm@8.8.0
(if pnpm) useWorkspaces from pnpm-config.json?	Yes
Operating system?	Mac / Linux
Would you consider contributing a PR?	Yes
Node.js version (node -v)?	v22.21.1

[dmichon-msft]

Rush's autoinstaller processing should be running at the very start of the command and should have nothing to do with the individual phases; could you clarify your repro with a demo repo?

[LPegasus]

Hi, @dmichon-msft. Here's the repro repo.

git clone github.com:LPegasus/rush-issue-5684.git
cd rush-issue-5684
rush install
rush fake

Can see two pnpm process lock file generated.

[octogonz]

We debugged this today. In a nutshell:

1. Process #1 locks the autoinstallers/fake-job folder and performs pnpm install there.

2. Process #2 tries to lock the autoinstallers/fake-job folder, and correctly waits for Step 1 to complete.

3. The install finishes, so process #1 now begins accessing the installed node_modules dependencies.

4. Simultaneously, process #2 finally acquires its lock, inspects rush-autoinstaller.flag (the LastInstallFlag) and decides it doesn't like it:

   rushstack/libraries/rush-lib/src/logic/Autoinstaller.ts

   Lines 117 to 133 in cf459dd

   	const lastInstallFlag: LastInstallFlag = new LastInstallFlag(lastInstallFlagPath, {
   	node: process.versions.node,
   	packageManager: this._rushConfiguration.packageManager,
   	packageManagerVersion: this._rushConfiguration.packageManagerToolVersion,
   	packageJson: packageJson,
   	rushJsonFolder: this._rushConfiguration.rushJsonFolder
   	});
   	// Example: ../common/autoinstallers/my-task/node_modules
   	const nodeModulesFolder: string = `${autoinstallerFullPath}/${RushConstants.nodeModulesFolderName}`;
   	const flagPath: string = `${nodeModulesFolder}/rush-autoinstaller.flag`;
   	const isLastInstallFlagDirty: boolean =
   	!(await lastInstallFlag.isValidAsync()) || !FileSystem.exists(flagPath);
   	if (isLastInstallFlagDirty || lock.dirtyWhenAcquired) {
   	if (FileSystem.exists(nodeModulesFolder)) {
   	this._logIfConsoleOutputIsNotRestricted('Deleting old files from ' + nodeModulesFolder);

   Thus if you look closely at the repro logs, we see Deleting old files from .../fake-job/node_modules.

5. Deleting the folder is what breaks process #1.

Next steps for this investigation

1. Determine why isLastInstallFlagDirty=true. Maybe one of the processes is getting a different Node.js runtime version for some reason?

2. Can Rush be improved? I think it would be super useful for the Deleting old files to include some console output explaining WHY. Or at the very least, maybe ---debug could dump the JSON objects being compared if they are different?

It took us nearly half an hour to track this down (particularly since race conditions aren't always easy to repro), so better diagnostics would be worthwhile.

@dmichon-msft

[LPegasus]

I've added some log

and shows two kind of error cases:

1. dirtyWhenAcquired=true
   
2. pnpm: No such file or directory
   

For case 1:

I found that when LockFile attempts to acquire a lock, other lock files still exist when call readdir, but when the for loop reads the files, if they have already been deleted by other processes, the problem in case 1 occurs. See https://github.com/microsoft/rushstack/blob/main/libraries/node-core-library/src/LockFile.ts#L325-L355
I'm wondering for this case, if the dirtyWhenAcquired could be changed to false cause other pnpm processes had been finished.

For case 2:

The running stack seems the same as case 1. The file not exists. But i'm wondering why the common/temp/pnpm-local/node_modules/.bin/pnpm is removed in this case. Any design context for this?