JsonParseError: Parsing --target-org intermittent error on running sf commands

[erocheleau]

Note
Before you submit your issue, make sure that:

• You're using the latest version of Salesforce CLI.
• You've searched both open and closed issues for related posts.
• You've used the doctor command to diagnose common issues.
• You understand that GitHub Issues don't adhere to any agreement or SLA.
  • If you require immediate assistance, use official channels such as Salesforce Customer Support.

Summary

I am using the @salesforce/cli installed through npm.
I am using it through a nodejs application (automated tests with playwright, and using the node exec command in the test setup phase)
Everything is running smoothly on windows (using wsl2) and on CI (using ubuntu runners).
But on a Macbook with a M2 chip (dunno if it matters), I am experiencing very flaky commands.
More specifically, when running
sf data record get --sobject Case --where "where clause" --target-org random_alias --json
I am randomly getting this error:

    {
      code: 1,
      context: 'DataSoqlQueryCommand',
      commandName: 'DataSoqlQueryCommand',
      message: 'Parsing --target-org \n' +
        '\tUnexpected end of JSON input\n' +
        'See more help with --help',
      name: 'JsonParseError',
      status: 1,
      stack: 'JsonParseError: Parsing --target-org \n' +
        '\tUnexpected end of JSON input\n' +
        'See more help with --help\n' +
        '    at JsonParseError.create (/Users/username/.nvm/versions/node/v18.17.1/lib/node_modules/@salesforce/cli/node_modules/@salesforce/kit/lib/errors.js:51:20)\n' +
        '    at parseJson (/Users/username/.nvm/versions/node/v18.17.1/lib/node_modules/@salesforce/cli/node_modules/@salesforce/kit/lib/json.js:28:39)\n' +
        '    at parseJsonMap (/Users/username/.nvm/versions/node/v18.17.1/lib/node_modules/@salesforce/cli/node_modules/@salesforce/kit/lib/json.js:67:18)\n' +
        '    at AuthInfoConfig.read (/Users/username/.nvm/versions/node/v18.17.1/lib/node_modules/@salesforce/cli/node_modules/@salesforce/core/lib/config/configFile.js:150:52)\n' +
        '    at async AuthInfoConfig.init (/Users/username/.nvm/versions/node/v18.17.1/lib/node_modules/@salesforce/cli/node_modules/@salesforce/core/lib/config/configFile.js:338:9)\n' +
        '    at async AuthInfoConfig.create (/Users/username/.nvm/versions/node/v18.17.1/lib/node_modules/@salesforce/cli/node_modules/@salesforce/kit/lib/creatable.js:57:9)\n' +
        '    at async OrgAccessor.read (/Users/username/.nvm/versions/node/v18.17.1/lib/node_modules/@salesforce/cli/node_modules/@salesforce/core/lib/stateAggregator/accessors/orgAccessor.js:39:28)\n' +
        '    at async AuthInfo.init (/Users/username/.nvm/versions/node/v18.17.1/lib/node_modules/@salesforce/cli/node_modules/@salesforce/core/lib/org/authInfo.js:581:13)\n' +
        '    at async AuthInfo.create (/Users/username/.nvm/versions/node/v18.17.1/lib/node_modules/@salesforce/cli/node_modules/@salesforce/kit/lib/creatable.js:57:9)\n' +
        '    at async Org.init (/Users/username/.nvm/versions/node/v18.17.1/lib/node_modules/@salesforce/cli/node_modules/@salesforce/core/lib/org/org.js:777:27)',
      exitCode: 1,
      warnings: []
    }

I am getting the same error:

message: 'Parsing --target-org \n' +
        '\tUnexpected end of JSON input\n' +
        'See more help with --help',
      name: 'JsonParseError',

When running also
sf data get record --target-org random_alias --sobject Case --where "where clause" --json
And also:
sf org open -p "path/to/record" --urlonly --target-org random_alias --json

Expected result

I expect these commands to not fail?

Actual result

These commands randomly fail

System Information

{
  "cliVersion": "@salesforce/cli/2.5.7",
  "architecture": "darwin-arm64",
  "nodeVersion": "node-v18.17.1",
  "osVersion": "Darwin 22.6.0",
  "shell": "zsh",
  "rootPath": "/Users/username/.nvm/versions/node/v18.17.1/lib/node_modules/@salesforce/cli",
  "pluginVersions": [
    "@oclif/plugin-autocomplete 2.3.6 (core)",
    "@oclif/plugin-commands 2.2.22 (core)",
    "@oclif/plugin-help 5.2.17 (core)",
    "@oclif/plugin-not-found 2.3.37 (core)",
    "@oclif/plugin-plugins 3.2.6 (core)",
    "@oclif/plugin-search 0.0.22 (core)",
    "@oclif/plugin-update 3.1.32 (core)",
    "@oclif/plugin-version 1.3.8 (core)",
    "@oclif/plugin-warn-if-update-available 2.0.48 (core)",
    "@oclif/plugin-which 2.2.30 (core)",
    "@salesforce/cli 2.5.7 (core)",
    "apex 2.3.10 (core)",
    "auth 2.8.12 (core)",
    "data 2.5.6 (core)",
    "deploy-retrieve 1.17.5 (core)",
    "info 2.6.39 (core)",
    "limits 2.3.30 (core)",
    "login 1.2.26 (core)",
    "org 2.10.0 (core)",
    "packaging 1.22.1 (user)",
    "schema 2.3.23 (core)",
    "settings 1.4.25 (core)",
    "sobject 0.2.4 (core)",
    "source 2.10.31 (core)",
    "telemetry 2.3.0 (core)",
    "templates 55.5.10 (core)",
    "trust 2.6.1 (core)",
    "user 2.3.28 (core)"
  ]
}

Additional information

[github-actions]

Thank you for filing this issue. We appreciate your feedback and will review the issue as soon as possible. Remember, however, that GitHub isn't a mechanism for receiving support under any agreement or SLA. If you require immediate assistance, contact Salesforce Customer Support.

[erocheleau]

If I set some retries in the test run, the same commands that fail eventually work.

I thought it may have been a problem with having multiple concurrent workers trying to read the same file maybe? So I lowered the number of workers to 1, but it still doesn't work after that.

I tried looking at the code in the stack trace, it's this line that's always where the fail happens:

    /**
     * Read the config file and set the config contents. Returns the config contents of the config file. As an
     * optimization, files are only read once per process and updated in memory and via `write()`. To force
     * a read from the filesystem pass `force=true`.
     * **Throws** *{@link SfError}{ name: 'UnexpectedJsonFileFormat' }* There was a problem reading or parsing the file.
     *
     * @param [throwOnNotFound = false] Optionally indicate if a throw should occur on file read.
     * @param [force = false] Optionally force the file to be read from disk even when already read within the process.
     */
    async read(throwOnNotFound = false, force = false) {
        ...
        const obj = (0, kit_1.parseJsonMap)(await fs.promises.readFile(this.getPath(), 'utf8'), this.getPath());

I tried printing in the console what was causing the JSONParseError when it would happen but the output doesn't make sense to me to be able to debug it, it seems it's just trying to parse regular valid json...

[shetzel]

It's an issue with concurrency of config files. We have it on our radar to fix but it's not a small change and we'll need to do some planning for how to roll it out.

[mshanemc]

@erocheleau that warning indicates that the file isn't good json.

Like @shetzel said, it's probably getting corrupted at some point, probably during your authorization or scratch org creation process. Then when your data or open command goes to use it, it's bad.

If you've got any parallel work that might be touching that file, try to eliminate that.

[mshanemc]

@W-14085765@

[erocheleau]

@shetzel wow thank you for confirming this at least I know I'm not crazy and I pinpointed the issue correctly 😂

@mshanemc The parallel work is the point of what I'm trying to do, for example to run e2e tests with multiple workers in a CI pipeline, running queries to Salesforce using the CLI.

So IMO the concurrency is an issue that should be fixed. But I understand that it's not a small fix and I can work around it now that I know it's confirmed that this is the real cause of the issue.

It's funny that it worked without any issue on windows + wsl but on Mac it doesn't work even once.

Thanks the replies 👍

[mshanemc]

yeah, there's some ways to deal with that. We massively parallelize e2e tests on orgs by giving them their own isolated directories (see https://github.com/salesforcecli/cli-plugins-testkit).

It's funny that it worked without any issue on windows + wsl but on Mac it doesn't work even once.

one theory is that it relates to the keychain stuff on mac. You could experiment with SF_USE_GENERIC_UNIX_KEYCHAIN on mac to see if that helps.

[erocheleau]

To me it really looks like it's because most commands will constantly re-write the json config file for your scratch org instead of leaving it alone? (I could be totally wrong here) But I can log every time there is this error, and every time right now it's when trying to read this file:

/Users/<username>/.sfdx/<scratchorg>@example.com.json

Trying to print the content of the file on error returns completely empty. (it could be because the file cannot be opened to read too I guess because something else is still writing in it?)

'ERROR Reading config file: /Users/<username>/.sfdx/<scratchorg>@example.com.json\n' +
      'ERROR Reading config file:  <- file content.\n' +
      '{\n' +
      '  "code": 1,\n' +
      '  "context": "OrgOpenCommand",\n' +
      '  "commandName": "OrgOpenCommand",\n' +
      '  "message": "Parsing --target-org \\n\\tUnexpected end of JSON input\\nSee more help with --help",\n' +
      '  "name": "JsonParseError",\n' +
[...]

I added the <- file content after logging the content of the file read, to make sure it wasn't just an empty line break or something :)

I changed the code of the read method of configFile.js to

fileContent = await fs.promises.readFile(this.getPath(), 'utf8');
const obj = (0, kit_1.parseJsonMap)(fileContent, this.getPath());
[...]
catch(err) {
    console.log(`ERROR Reading config file: ${this.getPath()}`);
    console.log(`ERROR Reading config file: ${fileContent} <- file content.`);
}

And it completely prints as empty every time this error shows up. (I still have the error show up now with even just 1 working while running playwright tests.

[erocheleau]

async write(newContents) {
        if (newContents) {
            this.setContents(newContents);
        }
        try {
            await fs.promises.mkdir((0, path_1.dirname)(this.getPath()), { recursive: true });
        }
        catch (err) {
            throw sfError_1.SfError.wrap(err);
        }
        this.logger.info(`Writing to config file: ${this.getPath()}`);
        // await fs.promises.writeFile(this.getPath(), JSON.stringify(this.toObject(), null, 2));
        return this.getContents();
    }

It really seems to be tied to constantly re-writing the same config file, because if I comment out the line showcased here, I stop having issues altogether with the JSON parsing of the file...

Also from the node.fs documentation on this function:

• It is unsafe to use fsPromises.writeFile() multiple times on the same file
  * without waiting for the promise to be settled.
  *
  * Similarly to fsPromises.readFile - fsPromises.writeFile is a convenience
  * method that performs multiple write calls internally to write the buffer
  * passed to it. For performance sensitive code consider using fs.createWriteStream() or filehandle.createWriteStream().

I would assume this is exactly what is going on here, multiple calls to sfdx methods executed at the same time (by the test runners, even with 1 runner I am encountering this issue) would all try to call fsPromises.readFile and fsPromises.writeFile() at the same time.

It also looks like the content of the file is being re-written with the exact same content, not re-writing the same content could potentially help???, but I could be wrong it's hard to check what's going on during the execution of these commands.

Hopefully this information is helpful to try to resolve the issue? :)

[mshanemc]

@erocheleau we shipped a really large change to how configFiles work in today's nightly. Would you be able to try your replication with the nightly sf and see if it fixed it?

[erocheleau]

@mshanemc I completely missed this update but just saw the version description of 2.19.7 thank you so much!

I will try it right away!

[erocheleau]

I can confirm it seems to be working now!

[MarcTCruz]

@mshanemc
Last week I tried some "sf project deploy start --source-dir ... --json" in parallel and I've got the jsonParseError.

My sf version is usually up to date, last week it was at least @salesforce/cli/2.31.x, today it is @salesforce/cli/2.32.8.

So such errors still happens.

[mshanemc]

@MarcTCruz can you open a new issue with all the info about it. Can you also include what kind of org you're deploying to?

It may or may not be the same file causing the problem.