[eas-cli] Print a JSON error on stdout when a --json command fails

CHANGELOG.md

@@ -6,12 +6,16 @@ This is the log of notable changes to EAS CLI and related packages.
 
 ### 🛠 Breaking changes
 
+- [eas-cli] Write the reason a command failed to stderr, next to the `command failed.` line, instead of to stdout. A program that reads the reason from stdout must read stderr instead. ([#4592](https://github.com/expo/eas-cli/pull/4592) by [@vonovak](https://github.com/vonovak))
+
 ### 🎉 New features
 
+- [eas-cli] Print `{"error": {"message", "requestId"?}}` on stdout when a command run with `--json` fails, and keep all other output off stdout from the start of the command. ([#4593](https://github.com/expo/eas-cli/pull/4593) by [@vonovak](https://github.com/vonovak))
 - [build-tools] Let the MCP server read text and image files from sandboxes. ([#4555](https://github.com/expo/eas-cli/pull/4555) by [@AHGIJMKLKKZNPJKQR](https://github.com/AHGIJMKLKKZNPJKQR))
 
 ### 🐛 Bug fixes
 
+- [eas-cli] Print the notice about eas-cli in project dependencies only when stderr is a terminal, so programs that read stderr get the command's error. ([#4591](https://github.com/expo/eas-cli/pull/4591) by [@vonovak](https://github.com/vonovak))
 - [build-tools] Look up ffmpeg on PATH instead of running it. ([#4582](https://github.com/expo/eas-cli/pull/4582) by [@gwdp](https://github.com/gwdp))
 - [build-tools] Install ffmpeg for Appium simulator sessions. ([#4577](https://github.com/expo/eas-cli/pull/4577) by [@gwdp](https://github.com/gwdp))
 

packages/eas-cli/src/__tests__/log-test.ts

@@ -0,0 +1,17 @@
+import Log from '../log';
+
+describe(Log.errorToStderr, () => {
+  afterEach(() => {
+    jest.restoreAllMocks();
+  });
+
+  it('writes to stderr, not stdout', () => {
+    const stdout = jest.spyOn(console, 'log').mockImplementation(() => {});
+    const stderr = jest.spyOn(console, 'error').mockImplementation(() => {});
+
+    Log.errorToStderr('EAS project not configured.');
+
+    expect(stderr).toHaveBeenCalledWith(expect.stringContaining('EAS project not configured.'));
+    expect(stdout).not.toHaveBeenCalled();
+  });
+});

packages/eas-cli/src/commandUtils/EasCommand.ts

@@ -1,4 +1,4 @@
-import { Command } from '@oclif/core';
+import { Command, Errors } from '@oclif/core';
 import { CombinedError } from '@urql/core';
 import chalk from 'chalk';
 import { GraphQLError } from 'graphql/error';
@@ -30,6 +30,7 @@ import Log, { link } from '../log';
 import Sentry from '../sentry';
 import SessionManager from '../user/SessionManager';
 import { getActorDisplayName } from '../user/User';
+import { enableJsonOutput, printJsonErrorOutput } from '../utils/json';
 import { Client } from '../vcs/vcs';
 
 export type ContextInput<
@@ -248,9 +249,24 @@ export default abstract class EasCommand extends Command {
       action: `eas ${this.id}`,
     });
 
+    // Before the context is resolved, so its messages and errors stay off stdout too.
+    if (this.jsonOutputRequested()) {
+      enableJsonOutput();
+    }
+
     return await this.runAsync();
   }
 
+  /** Mirrors oclif's `jsonEnabled`, for commands that declare their own `json` flag. */
+  private jsonOutputRequested(): boolean {
+    if (!this.ctor.flags?.json) {
+      return false;
+    }
+    const jsonIndex = this.argv.indexOf('--json');
+    const passThroughIndex = this.argv.indexOf('--');
+    return jsonIndex !== -1 && (passThroughIndex === -1 || jsonIndex < passThroughIndex);
+  }
+
   // eslint-disable-next-line async-protect/async-suffix
   override async finally(err: Error): Promise<any> {
     await this.analytics.flushAsync();
@@ -261,8 +277,14 @@ export default abstract class EasCommand extends Command {
   protected override catch(err: Error): Promise<any> {
     const commandId = this.id ?? 'unknown';
     let baseMessage = `${commandId} command failed.`;
-    if (err instanceof EasCommandError) {
-      Log.error(err.message);
+    let message = err.message;
+    let requestId: string | undefined;
+    if (err instanceof Errors.ExitError) {
+      // Errors.exit(1) carries no reason; the code that called it printed the reason already.
+      Log.errorToStderr(err.message);
+      message = baseMessage;
+    } else if (err instanceof EasCommandError) {
+      Log.errorToStderr(err.message);
     } else if (err instanceof CombinedError && err?.graphQLErrors) {
       const cleanGQLErrorsMessage = err?.graphQLErrors
         .map((graphQLError: GraphQLError) => {
@@ -299,10 +321,15 @@ export default abstract class EasCommand extends Command {
       const cleanMessage = err.networkError
         ? `${cleanGQLErrorsMessage}\n${err.networkError.message}`
         : cleanGQLErrorsMessage;
-      Log.error(cleanMessage);
+      Log.errorToStderr(cleanMessage);
       baseMessage = BASE_GRAPHQL_ERROR_MESSAGE;
+      message = cleanMessage;
+      requestId = err.graphQLErrors[0]?.extensions?.requestId as string | undefined;
     } else {
-      Log.error(err.message);
+      Log.errorToStderr(err.message);
+    }
+    if (this.jsonOutputRequested()) {
+      printJsonErrorOutput({ message, requestId });
     }
     Log.debug(err);
     Sentry.withScope(scope => {

packages/eas-cli/src/commandUtils/__tests__/EasCommand-test.ts

@@ -24,6 +24,7 @@ jest.mock('../../analytics/AnalyticsManager', () => {
   };
 });
 jest.mock('../../log');
+jest.mock('../../utils/json');
 
 const mockRequestId = uuidv4();
 
@@ -199,7 +200,7 @@ describe('EasCommand', () => {
       it('logs the message', async () => {
         const TestEasCommand = createTestEasCommand();
         const Log = jest.requireMock('../../log').default;
-        const logErrorSpy = jest.spyOn(Log, 'error');
+        const logErrorSpy = jest.spyOn(Log, 'errorToStderr');
         const logDebugSpy = jest.spyOn(Log, 'debug');
         const runAsyncMock = jest.spyOn(TestEasCommand.prototype, 'runAsync');
         const error = new Error('Unexpected, internal error message');
@@ -217,7 +218,7 @@ describe('EasCommand', () => {
       it('logs the cleaned message if needed', async () => {
         const TestEasCommand = createTestEasCommand();
         const Log = jest.requireMock('../../log').default;
-        const logErrorSpy = jest.spyOn(Log, 'error');
+        const logErrorSpy = jest.spyOn(Log, 'errorToStderr');
         const logDebugSpy = jest.spyOn(Log, 'debug');
         const runAsyncMock = jest.spyOn(TestEasCommand.prototype, 'runAsync');
         const { CombinedError } = require('@urql/core');
@@ -237,7 +238,7 @@ describe('EasCommand', () => {
       it('logs the cleaned message with request ID if present', async () => {
         const TestEasCommand = createTestEasCommand();
         const Log = jest.requireMock('../../log').default;
-        const logErrorSpy = jest.spyOn(Log, 'error');
+        const logErrorSpy = jest.spyOn(Log, 'errorToStderr');
         const logDebugSpy = jest.spyOn(Log, 'debug');
         const runAsyncMock = jest.spyOn(TestEasCommand.prototype, 'runAsync');
         const { CombinedError } = require('@urql/core');
@@ -272,7 +273,7 @@ describe('EasCommand', () => {
       it('logs the cleaned messages with request IDs if multiple GraphQL errors present', async () => {
         const TestEasCommand = createTestEasCommand();
         const Log = jest.requireMock('../../log').default;
-        const logErrorSpy = jest.spyOn(Log, 'error');
+        const logErrorSpy = jest.spyOn(Log, 'errorToStderr');
         const logDebugSpy = jest.spyOn(Log, 'debug');
         const runAsyncMock = jest.spyOn(TestEasCommand.prototype, 'runAsync');
         const { CombinedError } = require('@urql/core');
@@ -310,6 +311,112 @@ describe('EasCommand', () => {
         expect(logDebugSpy).toBeCalledWith(error);
       });
 
+      describe('with --json', () => {
+        const createJsonTestEasCommand = (): any => {
+          const TestEasCommand = createTestEasCommand();
+          const { Flags } = require('@oclif/core');
+          TestEasCommand.flags = { json: Flags.boolean() };
+          return TestEasCommand;
+        };
+
+        it('enables JSON output before the command runs', async () => {
+          const TestEasCommand = createJsonTestEasCommand();
+          const { enableJsonOutput } = jest.requireMock('../../utils/json');
+          let enabledBeforeRun = false;
+          jest.spyOn(TestEasCommand.prototype, 'runAsync').mockImplementation(async () => {
+            enabledBeforeRun = enableJsonOutput.mock.calls.length > 0;
+          });
+
+          await TestEasCommand.run(['--json'], mockConfig);
+
+          expect(enabledBeforeRun).toBe(true);
+        });
+
+        it('prints the error message', async () => {
+          const TestEasCommand = createJsonTestEasCommand();
+          const { printJsonErrorOutput } = jest.requireMock('../../utils/json');
+          const { EasCommandError } = require('../errors');
+          jest.spyOn(TestEasCommand.prototype, 'runAsync').mockImplementation(() => {
+            throw new EasCommandError('EAS project not configured.');
+          });
+
+          await expect(TestEasCommand.run(['--json'], mockConfig)).rejects.toThrow();
+
+          expect(printJsonErrorOutput).toHaveBeenCalledWith({
+            message: 'EAS project not configured.',
+            requestId: undefined,
+          });
+        });
+
+        it('prints the command failure, not EEXIT, for Errors.exit', async () => {
+          const TestEasCommand = createJsonTestEasCommand();
+          const { printJsonErrorOutput } = jest.requireMock('../../utils/json');
+          const { Errors } = require('@oclif/core');
+          jest.spyOn(TestEasCommand.prototype, 'runAsync').mockImplementation(() => {
+            Errors.exit(1);
+          });
+
+          await expect(TestEasCommand.run(['--json'], mockConfig)).rejects.toThrow();
+
+          expect(printJsonErrorOutput).toHaveBeenCalledWith({
+            message: `${TestEasCommand.id} command failed.`,
+            requestId: undefined,
+          });
+        });
+
+        it('prints the GraphQL request ID, not the server error code', async () => {
+          const TestEasCommand = createJsonTestEasCommand();
+          const { printJsonErrorOutput } = jest.requireMock('../../utils/json');
+          const { CombinedError } = require('@urql/core');
+          const { GraphQLError } = require('graphql/error');
+          jest.spyOn(TestEasCommand.prototype, 'runAsync').mockImplementation(() => {
+            throw new CombinedError({
+              graphQLErrors: [
+                new GraphQLError('Entity not authorized', null, null, null, null, null, {
+                  errorCode: 'UNAUTHORIZED_ERROR',
+                  requestId: mockRequestId,
+                }),
+              ],
+            });
+          });
+
+          await expect(TestEasCommand.run(['--json'], mockConfig)).rejects.toThrow();
+
+          expect(printJsonErrorOutput).toHaveBeenCalledWith(
+            expect.objectContaining({ requestId: mockRequestId })
+          );
+          expect(printJsonErrorOutput.mock.calls[0][0]).not.toHaveProperty('code');
+        });
+
+        it.each([
+          ['without --json', []],
+          ['with --json after --', ['--', '--json']],
+        ])('prints no JSON error %s', async (_, argv) => {
+          const TestEasCommand = createJsonTestEasCommand();
+          const { enableJsonOutput, printJsonErrorOutput } = jest.requireMock('../../utils/json');
+          jest.spyOn(TestEasCommand.prototype, 'runAsync').mockImplementation(() => {
+            throw new Error('foo');
+          });
+
+          await expect(TestEasCommand.run(argv, mockConfig)).rejects.toThrow();
+
+          expect(enableJsonOutput).not.toHaveBeenCalled();
+          expect(printJsonErrorOutput).not.toHaveBeenCalled();
+        });
+
+        it('prints no JSON error when the command has no json flag', async () => {
+          const TestEasCommand = createTestEasCommand();
+          const { printJsonErrorOutput } = jest.requireMock('../../utils/json');
+          jest.spyOn(TestEasCommand.prototype, 'runAsync').mockImplementation(() => {
+            throw new Error('foo');
+          });
+
+          await expect(TestEasCommand.run(['--json'], mockConfig)).rejects.toThrow();
+
+          expect(printJsonErrorOutput).not.toHaveBeenCalled();
+        });
+      });
+
       it('re-throws the error with default base message', async () => {
         const TestEasCommand = createTestEasCommand();
         const runAsyncMock = jest.spyOn(TestEasCommand.prototype, 'runAsync');

packages/eas-cli/src/commandUtils/context/contextUtils/__tests__/findProjectDirAndVerifyProjectSetupAsync-test.ts

@@ -11,8 +11,16 @@ jest.mock('fs');
 
 jest.mock('../../../../prompts');
 
+const originalStderrIsTTY = process.stderr.isTTY;
+
 beforeEach(() => {
   jest.resetAllMocks();
+  // The dependency notice prints once per process and only to a terminal, so keep it unspent.
+  process.stderr.isTTY = false;
+});
+
+afterAll(() => {
+  process.stderr.isTTY = originalStderrIsTTY;
 });
 
 describe(findProjectRootAsync, () => {
@@ -115,3 +123,32 @@ describe(findProjectDirAndVerifyProjectSetupAsync, () => {
     await expect(findProjectDirAndVerifyProjectSetupAsync({ cwd: '/app' })).resolves.not.toThrow();
   });
 });
+
+describe('eas-cli dependency notice', () => {
+  beforeEach(() => {
+    vol.reset();
+    vol.fromJSON(
+      {
+        './eas.json': JSON.stringify({}),
+        './package.json': JSON.stringify({ devDependencies: { 'eas-cli': '*' } }),
+      },
+      '/app'
+    );
+  });
+
+  afterEach(() => {
+    jest.restoreAllMocks();
+  });
+
+  it('prints the notice only when stderr is a terminal', async () => {
+    const warn = jest.spyOn(console, 'warn').mockImplementation(() => {});
+
+    process.stderr.isTTY = false;
+    await findProjectDirAndVerifyProjectSetupAsync({ cwd: '/app' });
+    expect(warn).not.toHaveBeenCalled();
+
+    process.stderr.isTTY = true;
+    await findProjectDirAndVerifyProjectSetupAsync({ cwd: '/app' });
+    expect(warn).toHaveBeenCalledWith(expect.stringContaining('in your project dependencies'));
+  });
+});

packages/eas-cli/src/commandUtils/context/contextUtils/findProjectDirAndVerifyProjectSetupAsync.ts

@@ -127,7 +127,8 @@ export async function findProjectDirAndVerifyProjectSetupAsync({
 } = {}): Promise<string> {
   const projectDir = await findProjectRootAsync({ cwd });
   await applyCliConfigAsync(projectDir);
-  if (!ranEnsureEasCliIsNotInDependencies) {
+  // The notice is advice for a person. Programs that run eas-cli read stderr for its errors.
+  if (!ranEnsureEasCliIsNotInDependencies && process.stderr.isTTY) {
     ranEnsureEasCliIsNotInDependencies = true;
     await ensureEasCliIsNotInDependenciesAsync(projectDir);
   }

packages/eas-cli/src/commandUtils/flags.ts

@@ -8,7 +8,7 @@ export function isNonInteractiveByDefault(): boolean {
 export const EasNonInteractiveAndJsonFlags = {
   json: Flags.boolean({
     description:
-      'Enable JSON output, non-JSON messages will be printed to stderr. Implies --non-interactive.',
+      'Enable JSON output, non-JSON messages will be printed to stderr. On failure, prints {"error": {"message", "requestId"?}}. Implies --non-interactive.',
   }),
   'non-interactive': Flags.boolean({
     description: 'Run the command in non-interactive mode.',
@@ -87,7 +87,8 @@ export const EASNonInteractiveFlag = {
 
 export const EasJsonOnlyFlag = {
   json: Flags.boolean({
-    description: 'Enable JSON output, non-JSON messages will be printed to stderr.',
+    description:
+      'Enable JSON output, non-JSON messages will be printed to stderr. On failure, prints {"error": {"message", "requestId"?}}.',
   }),
 };
 

packages/eas-cli/src/log.ts

@@ -39,6 +39,16 @@ export default class Log {
     Log.consoleLog(...Log.withTextColor(args, chalk.red));
   }
 
+  /**
+   * Print the reason a command failed. It goes to stderr, next to oclif's "command failed." line,
+   * so a program that runs eas-cli finds it there.
+   */
+  public static errorToStderr(...args: any[]): void {
+    Log.updateIsLastLineNewLine(args);
+    // eslint-disable-next-line no-console
+    console.error(...Log.withTextColor(args, chalk.red));
+  }
+
   public static warn(...args: any[]): void {
     Log.consoleLog(...Log.withTextColor(args, chalk.yellow));
   }

packages/eas-cli/src/utils/__tests__/json-test.ts

@@ -0,0 +1,36 @@
+describe('printJsonErrorOutput', () => {
+  const originalStdoutWrite = process.stdout.write;
+  const originalStderrWrite = process.stderr.write;
+
+  afterEach(() => {
+    jest.restoreAllMocks();
+    process.stdout.write = originalStdoutWrite;
+    process.stderr.write = originalStderrWrite;
+  });
+
+  it('prints one error object on stdout, without ANSI codes, once per process', () => {
+    const stdout = jest.fn(() => true);
+    const stderr = jest.fn(() => true);
+    process.stdout.write = stdout as any;
+    process.stderr.write = stderr as any;
+    // Jest's console does not write through process.stdout, so record which stream was live.
+    const printed: { text: string; toStdout: boolean }[] = [];
+    jest.spyOn(console, 'log').mockImplementation((text: string) => {
+      printed.push({ text, toStdout: process.stdout.write === stdout });
+    });
+
+    jest.isolateModules(() => {
+      const { printJsonErrorOutput } = require('../json');
+      printJsonErrorOutput({
+        message: '\u001b[31mEAS project not configured.\u001b[39m',
+      });
+      printJsonErrorOutput({ message: 'update:republish command failed.' });
+    });
+
+    expect(printed).toHaveLength(1);
+    expect(printed[0].toStdout).toBe(true);
+    expect(JSON.parse(printed[0].text)).toEqual({
+      error: { message: 'EAS project not configured.' },
+    });
+  });
+});