fix: wait to read until file is unlocked (#1116)

* fix: wait to read until file is unlocked

* test: failing ut

* test: nut for concurrency

* refactor: retry decorator for polling

* test: run entire nut

* refactor: back to original retries

* test: use normal naming convention

* test: remove ut init hook

* test: include for nut

* ci: remove test folder to avoid a plugin running sfdx-core's NUTs

* ci: fix on windows, too

---------

Co-authored-by: mshanemc <[email protected]>

.github/workflows/test.yml

@@ -14,6 +14,10 @@ jobs:
   windows-unit-tests:
     needs: linux-unit-tests
     uses: salesforcecli/github-workflows/.github/workflows/unitTestsWindows.yml@main
+  nuts:
+    needs: linux-unit-tests
+    uses: salesforcecli/github-workflows/.github/workflows/nut.yml@main
+
   xNuts:
     needs: linux-unit-tests
     uses: salesforcecli/github-workflows/.github/workflows/externalNut.yml@main
@@ -40,6 +44,8 @@ jobs:
       command: 'yarn test:nuts'
       os: ${{ matrix.os }}
       useCache: false
+      # remove the test folder for sfdx-core
+      preBuildCommands: 'shx rm -rf test'
       preSwapCommands: 'yarn upgrade @jsforce/jsforce-node@latest; npx yarn-deduplicate; yarn install'
       preExternalBuildCommands: 'shx rm -rf node_modules/@salesforce/core/node_modules/@jsforce/jsforce-node shx rm -rf node_modules/@salesforce/sf-plugins-core/node_modules/@salesforce/core node_modules/@salesforce/cli-plugins-testkit/node_modules/@salesforce/core node_modules/@salesforce/source-tracking/node_modules/@salesforce/core node_modules/@salesforce/source-deploy-retrieve/node_modules/@salesforce/core node_modules/@salesforce/apex-node/node_modules/@salesforce/core'
     secrets: inherit

.mocharc.json

@@ -1,5 +1,5 @@
 {
-  "require": "test/init.js, ts-node/register, source-map-support/register",
+  "require": "ts-node/register, source-map-support/register",
   "watch-extensions": "ts",
   "watch-files": ["src", "test"],
   "recursive": true,

.sfdevrc.json

@@ -1,6 +1,6 @@
 {
   "test": {
-    "testsPath": "test/**/*Test.ts"
+    "testsPath": "test/unit/**/*.test.ts"
   },
   "wireit": {
     "compile": {

package.json

@@ -35,6 +35,7 @@
     "prepack": "sf-prepack",
     "prepare": "sf-install",
     "test": "wireit",
+    "test:nuts": "mocha \"test/**/*.nut.ts\" --timeout 500000",
     "test:only": "wireit",
     "test:perf": "ts-node test/perf/logger/main.test.ts"
   },
@@ -146,7 +147,7 @@
       "output": []
     },
     "test:only": {
-      "command": "nyc mocha \"test/**/*Test.ts\"",
+      "command": "nyc mocha \"test/unit/**/*.test.ts\"",
       "env": {
         "FORCE_COLOR": "2"
       },

src/config/configFile.ts

@@ -14,7 +14,7 @@ import { Global } from '../global';
 import { Logger } from '../logger/logger';
 import { SfError } from '../sfError';
 import { resolveProjectPath, resolveProjectPathSync } from '../util/internal';
-import { lockInit, lockInitSync } from '../util/fileLocking';
+import { lockInit, lockInitSync, pollUntilUnlock, pollUntilUnlockSync } from '../util/fileLocking';
 import { BaseConfigStore } from './configStore';
 import { ConfigContents } from './configStackTypes';
 import { stateFromContents } from './lwwMap';
@@ -167,7 +167,7 @@ export class ConfigFile<
             !this.hasRead ? 'hasRead is false' : 'force parameter is true'
           }`
         );
-
+        await pollUntilUnlock(this.getPath());
         const obj = parseJsonMap<P>(await fs.promises.readFile(this.getPath(), 'utf8'), this.getPath());
         this.setContentsFromFileContents(obj, (await fs.promises.stat(this.getPath(), { bigint: true })).mtimeNs);
       }
@@ -203,6 +203,7 @@ export class ConfigFile<
       // Only need to read config files once.  They are kept up to date
       // internally and updated persistently via write().
       if (!this.hasRead || force) {
+        pollUntilUnlockSync(this.getPath());
         this.logger.debug(`Reading config file: ${this.getPath()}`);
         const obj = parseJsonMap<P>(fs.readFileSync(this.getPath(), 'utf8'));
         this.setContentsFromFileContents(obj, fs.statSync(this.getPath(), { bigint: true }).mtimeNs);

src/util/fileLocking.ts

@@ -6,7 +6,9 @@
  */
 import * as fs from 'node:fs';
 import { dirname } from 'node:path';
-import { lock, lockSync } from 'proper-lockfile';
+import { lock, lockSync, check, checkSync } from 'proper-lockfile';
+import { Duration } from '@salesforce/kit';
+import { retryDecorator } from 'ts-retry-promise';
 import { SfError } from '../sfError';
 import { Logger } from '../logger/logger';
 import { lockOptions, lockRetryOptions } from './lockRetryOptions';
@@ -95,3 +97,37 @@ export const lockInitSync = (filePath: string): LockInitSyncResponse => {
     unlock,
   };
 };
+
+/**
+ * Poll until the file is unlocked.
+ *
+ * @param filePath file path to check
+ */
+export const pollUntilUnlock = async (filePath: string): Promise<void> => {
+  try {
+    await retryDecorator(check, {
+      timeout: Duration.minutes(1).milliseconds,
+      delay: 10,
+      until: (locked) => locked === false,
+      // don't retry errors (typically enoent or access on the lockfile, therefore not locked)
+      retryIf: () => false,
+    })(filePath, lockRetryOptions);
+  } catch (e) {
+    // intentionally swallow the error, same reason as above
+  }
+};
+
+export const pollUntilUnlockSync = (filePath: string): void => {
+  // Set a counter to ensure that the while loop does not run indefinitely
+  let counter = 0;
+  let locked = true;
+  while (locked && counter < 100) {
+    try {
+      locked = checkSync(filePath, lockOptions);
+      counter++;
+    } catch {
+      // Likely a file not found error, which means the file is not locked
+      locked = false;
+    }
+  }
+};

test/nut/concurrencyConfig.ts

@@ -0,0 +1,31 @@
+/*
+ * Copyright (c) 2023, salesforce.com, inc.
+ * All rights reserved.
+ * Licensed under the BSD 3-Clause license.
+ * For full license text, see LICENSE.txt file in the repo root or https://opensource.org/licenses/BSD-3-Clause
+ */
+import { tmpdir } from 'node:os';
+import { ConfigFile } from '../../src';
+
+export const FILENAME = 'concurrency.json';
+
+export class TestConfig extends ConfigFile<ConfigFile.Options> {
+  public static getOptions(
+    filename: string,
+    isGlobal: boolean,
+    isState?: boolean,
+    filePath?: string
+  ): ConfigFile.Options {
+    return {
+      rootFolder: tmpdir(),
+      filename,
+      isGlobal,
+      isState,
+      filePath,
+    };
+  }
+
+  public static getFileName() {
+    return FILENAME;
+  }
+}

test/nut/concurrencyReadWrite.ts

@@ -0,0 +1,22 @@
+/*
+ * Copyright (c) 2023, salesforce.com, inc.
+ * All rights reserved.
+ * Licensed under the BSD 3-Clause license.
+ * For full license text, see LICENSE.txt file in the repo root or https://opensource.org/licenses/BSD-3-Clause
+ */
+import { join } from 'node:path';
+import { expect } from 'chai'; // Add this line to import the expect function
+import { TestConfig } from './concurrencyConfig';
+
+const sharedLocation = join('sfdx-core-ut', 'test', 'configFile');
+
+/** ex: `yarn ts-node test/nut/concurrencyReadWrite.ts 1` */
+(async function (i: number = parseInt(process.argv[2], 10)) {
+  const config = new TestConfig(TestConfig.getOptions('test', true, true, sharedLocation));
+  config.set('x', i);
+  await config.write();
+  const readConfig = await config.read(true, true);
+  expect(readConfig.x).to.be.a('number');
+})().catch((err) => {
+  throw err;
+});

test/unit/config/configFileConcurrency.test.ts → test/nut/configFileConcurrency.nut.ts

@@ -7,33 +7,15 @@
 import { join } from 'node:path';
 import { tmpdir } from 'node:os';
 import { rm } from 'node:fs/promises';
+import { exec } from 'node:child_process';
+import { promisify } from 'node:util';
 import { expect } from 'chai';
 import { sleep } from '@salesforce/kit';
-import { ConfigFile } from '../../../src';
+import { TestConfig, FILENAME } from './concurrencyConfig';
 
-const FILENAME = 'concurrency.json';
-const sharedLocation = join('sfdx-core-ut', 'test', 'configFile');
+const execProm = promisify(exec);
 
-class TestConfig extends ConfigFile<ConfigFile.Options> {
-  public static getOptions(
-    filename: string,
-    isGlobal: boolean,
-    isState?: boolean,
-    filePath?: string
-  ): ConfigFile.Options {
-    return {
-      rootFolder: tmpdir(),
-      filename,
-      isGlobal,
-      isState,
-      filePath,
-    };
-  }
-
-  public static getFileName() {
-    return FILENAME;
-  }
-}
+const sharedLocation = join('sfdx-core-ut', 'test', 'configFile');
 
 /* file and node - clock timestamps aren't precise enough to run in a UT.
  *  the goal of this and the `sleep` is to put a bit of space between operations
@@ -190,4 +172,15 @@ describe('concurrency', () => {
       expect(config4.get('x')).to.be.greaterThanOrEqual(7).and.lessThanOrEqual(9);
     }
   });
+
+  it('safe reads on parallel writes', async () => {
+    const configOriginal = new TestConfig(TestConfig.getOptions('test', true, true, sharedLocation));
+    configOriginal.set('x', 0);
+    await configOriginal.write();
+    await sleep(SLEEP_FUDGE_MS);
+
+    await Promise.all(
+      Array.from({ length: 50 }).map((_, i) => execProm(`yarn ts-node test/nut/concurrencyReadWrite.ts ${i}`))
+    );
+  });
 });

test/tsconfig.json

@@ -1,6 +1,6 @@
 {
   "extends": "@salesforce/dev-config/tsconfig-test-strict",
-  "include": ["unit/**/*.ts", "perf/**/*.ts"],
+  "include": ["nut/**/*.ts", "unit/**/*.ts", "perf/**/*.ts"],
   "compilerOptions": {
     "noEmit": true,
     "skipLibCheck": true,

test/unit/config/ttlConfigTest.ts → test/unit/config/ttlConfig.test.ts

@@ -51,7 +51,7 @@ describe('TTLConfig', () => {
     it('should return the latest entry', async () => {
       const config = await TestConfig.create();
       config.set('1', { one: 'one' });
-      await sleep(1000);
+      await sleep(200);
       config.set('2', { two: 'two' });
       const latest = config.getLatestEntry();
       expect(latest).to.deep.equal(['2', config.get('2')]);
@@ -68,7 +68,7 @@ describe('TTLConfig', () => {
     it('should return the key of the latest entry', async () => {
       const config = await TestConfig.create();
       config.set('1', { one: 'one' });
-      await sleep(1000);
+      await sleep(200);
       config.set('2', { two: 'two' });
       const latest = config.getLatestKey();
       expect(latest).to.equal('2');

test/unit/loggerTest.ts → test/unit/logger/logger.test.ts

@@ -10,8 +10,8 @@
 
 import { expect, config as chaiConfig } from 'chai';
 import { isString } from '@salesforce/ts-types';
-import { Logger, LoggerLevel, computeLevel } from '../../src/logger/logger';
-import { shouldThrowSync, TestContext } from '../../src/testSetup';
+import { Logger, LoggerLevel, computeLevel } from '../../../src/logger/logger';
+import { shouldThrowSync, TestContext } from '../../../src/testSetup';
 
 // NOTE: These tests still use 'await' which is how it use to work and were left to make
 // sure we didn't regress the way they were used.

test/unit/sfErrorTest.ts → test/unit/sfError.test.ts

@@ -79,15 +79,15 @@ describe('SfError', () => {
     it('returned `name:message` when no cause', () => {
       const err = new SfError('test');
       expect(inspect(err)).to.include('SfError: test');
-      expect(inspect(err)).to.include('sfErrorTest.ts');
+      expect(inspect(err)).to.include('sfError.test.ts');
       // there's always 1 cause from the `cause:` property, even if undefined
       expect(inspect(err)?.match(causeRegex)).to.have.lengthOf(1);
     });
     it('1 cause', () => {
       const nestedError = new Error('nested');
       const err = new SfError('test', undefined, undefined, nestedError);
       expect(inspect(err)).to.include('SfError: test');
-      expect(inspect(err)).to.include('sfErrorTest.ts');
+      expect(inspect(err)).to.include('sfError.test.ts');
       expect(inspect(err)).to.include('nested');
       expect(inspect(err)?.match(causeRegex)).to.have.lengthOf(1);
       expect(inspect(err)?.match(nestedCauseRegex)).to.be.null;
@@ -97,7 +97,7 @@ describe('SfError', () => {
       const nestedError2 = new Error('nested2', { cause: nestedError });
       const err = new SfError('test', undefined, undefined, nestedError2);
       expect(inspect(err)).to.include('SfError: test');
-      expect(inspect(err)).to.include('sfErrorTest.ts');
+      expect(inspect(err)).to.include('sfError.test.ts');
       expect(inspect(err)).to.include('nested');
       expect(inspect(err)).to.include('nested2');
       expect(inspect(err)?.match(causeRegex)).to.have.lengthOf(1);