address comments

Signed-off-by: Ash Wu <[email protected]>

packages/build-tools/src/common/__tests__/xcpretty.test.ts

@@ -0,0 +1,94 @@
+import { EventEmitter } from 'events';
+
+import spawnAsync from '@expo/spawn-async';
+import { ExpoRunFormatter } from '@expo/xcpretty';
+import fg from 'fast-glob';
+
+import { createMockLogger } from '../../__tests__/utils/logger';
+import { Sentry } from '../../sentry';
+import { XcodeBuildLogger } from '../xcpretty';
+
+jest.mock('@expo/spawn-async');
+jest.mock('@expo/xcpretty');
+jest.mock('fast-glob');
+jest.mock('../../sentry', () => ({
+  Sentry: {
+    setup: jest.fn(),
+    capture: jest.fn(),
+    flush: jest.fn(),
+  },
+}));
+
+describe(XcodeBuildLogger, () => {
+  let stdout: EventEmitter;
+  let formatter: { pipe: jest.Mock; getBuildSummary: jest.Mock };
+
+  beforeEach(() => {
+    jest.clearAllMocks();
+
+    stdout = new EventEmitter();
+    const spawnPromise = Object.assign(new Promise(() => {}), {
+      child: { stdout, kill: jest.fn() },
+    });
+    jest.mocked(spawnAsync).mockReturnValue(spawnPromise as any);
+
+    formatter = {
+      pipe: jest.fn(),
+      getBuildSummary: jest.fn().mockReturnValue('summary'),
+    };
+    jest.mocked(ExpoRunFormatter.create).mockReturnValue(formatter as any);
+
+    jest.mocked(fg).mockResolvedValue(['build.log'] as any);
+  });
+
+  async function startWatchingAsync(logger: ReturnType<typeof createMockLogger>): Promise<void> {
+    const buildLogger = new XcodeBuildLogger(logger, '/project');
+    await buildLogger.watchLogFiles('/logs');
+  }
+
+  it('logs formatted lines', async () => {
+    const logger = createMockLogger();
+    await startWatchingAsync(logger);
+
+    formatter.pipe.mockReturnValue(['line1', 'line2']);
+    stdout.emit('data', 'raw xcodebuild output');
+
+    expect(formatter.pipe).toHaveBeenCalledWith('raw xcodebuild output');
+    expect(logger.info).toHaveBeenCalledWith('line1');
+    expect(logger.info).toHaveBeenCalledWith('line2');
+    expect(Sentry.capture).not.toHaveBeenCalled();
+  });
+
+  it('falls back to raw logs when the formatter throws', async () => {
+    const logger = createMockLogger();
+    await startWatchingAsync(logger);
+
+    formatter.pipe.mockImplementation(() => {
+      throw new RangeError('Invalid array length');
+    });
+    stdout.emit('data', 'offending output');
+
+    expect(logger.info).toHaveBeenCalledWith('offending output');
+  });
+
+  it('reports the formatter error to Sentry only once', async () => {
+    const logger = createMockLogger();
+    await startWatchingAsync(logger);
+
+    const error = new RangeError('Invalid array length');
+    formatter.pipe.mockImplementation(() => {
+      throw error;
+    });
+    stdout.emit('data', 'offending output');
+    stdout.emit('data', 'more offending output');
+
+    expect(logger.info).toHaveBeenCalledWith('offending output');
+    expect(logger.info).toHaveBeenCalledWith('more offending output');
+    expect(Sentry.capture).toHaveBeenCalledTimes(1);
+    expect(Sentry.capture).toHaveBeenCalledWith(
+      'xcpretty formatter failed to parse xcodebuild logs',
+      error,
+      { extras: { data: 'offending output' } }
+    );
+  });
+});

packages/build-tools/src/common/xcpretty.ts

@@ -6,11 +6,14 @@ import fg from 'fast-glob';
 import fs from 'fs-extra';
 import path from 'path';
 
+import { Sentry } from '../sentry';
+
 const CHECK_FILE_INTERVAL_MS = 1000;
 
 export class XcodeBuildLogger {
   private loggerError?: Error;
   private flushing: boolean = false;
+  private reportedFormatterError: boolean = false;
   private logReaderPromise?: SpawnPromise<SpawnResult>;
   private logsPath?: string;
 
@@ -60,9 +63,21 @@ export class XcodeBuildLogger {
       this.logReaderPromise = spawnAsync('tail', ['-n', '+0', '-f', logsPath], { stdio: 'pipe' });
       assert(this.logReaderPromise.child.stdout, 'stdout is not available');
       this.logReaderPromise.child.stdout.on('data', (data: string) => {
-        const lines = formatter.pipe(data.toString());
-        for (const line of lines) {
-          this.logger.info(line);
+        try {
+          const lines = formatter.pipe(data.toString());
+          for (const line of lines) {
+            this.logger.info(line);
+          }
+        } catch (err: any) {
+          // The formatter can throw on unexpected xcodebuild output. Fall back to
+          // raw logs instead of crashing the process with an uncaught exception.
+          if (!this.reportedFormatterError) {
+            this.reportedFormatterError = true;
+            Sentry.capture('xcpretty formatter failed to parse xcodebuild logs', err, {
+              extras: { data: data.toString().slice(-2000) },
+            });
+          }
+          this.logger.info(data.toString());
         }
       });
       await this.logReaderPromise;

packages/build-tools/src/ios/fastlane.ts

@@ -10,8 +10,8 @@ import type { Credentials } from './credentials/manager';
 import { createFastfileForResigningBuild } from './fastfile';
 import { createGymfileForArchiveBuild, createGymfileForSimulatorBuild } from './gymfile';
 import { isTVOS } from './tvos';
-import { XcodeBuildLogger } from './xcpretty';
 import { COMMON_FASTLANE_ENV } from '../common/fastlane';
+import { XcodeBuildLogger } from '../common/xcpretty';
 import { BuildContext, SkipNativeBuildError } from '../context';
 
 export async function runFastlaneGym<TJob extends Ios.Job>(

packages/build-tools/src/steps/utils/ios/fastlane.ts

@@ -3,8 +3,8 @@ import { BuildStepEnv } from '@expo/steps';
 import spawn, { SpawnResult } from '@expo/turtle-spawn';
 import path from 'path';
 
-import { XcodeBuildLogger } from './xcpretty';
 import { COMMON_FASTLANE_ENV } from '../../../common/fastlane';
+import { XcodeBuildLogger } from '../../../common/xcpretty';
 
 export async function runFastlaneGym({
   workingDir,

packages/build-tools/src/steps/utils/ios/xcpretty.ts

@@ -1,91 +0,0 @@
-import { bunyan } from '@expo/logger';
-import spawnAsync, { SpawnPromise, SpawnResult } from '@expo/spawn-async';
-import { ExpoRunFormatter } from '@expo/xcpretty';
-import assert from 'assert';
-import fg from 'fast-glob';
-import fs from 'fs-extra';
-import path from 'path';
-
-const CHECK_FILE_INTERVAL_MS = 1000;
-
-export class XcodeBuildLogger {
-  private loggerError?: Error;
-  private flushing: boolean = false;
-  private logReaderPromise?: SpawnPromise<SpawnResult>;
-  private logsPath?: string;
-
-  constructor(
-    private readonly logger: bunyan,
-    private readonly projectRoot: string
-  ) {}
-
-  public async watchLogFiles(logsDirectory: string): Promise<void> {
-    while (!this.flushing) {
-      const logsFilename = await this.getBuildLogFilename(logsDirectory);
-      if (logsFilename) {
-        this.logsPath = path.join(logsDirectory, logsFilename);
-        void this.startBuildLogger(this.logsPath);
-        return;
-      }
-      await new Promise(res => setTimeout(res, CHECK_FILE_INTERVAL_MS));
-    }
-  }
-
-  public async flush(): Promise<void> {
-    this.flushing = true;
-    if (this.loggerError) {
-      throw this.loggerError;
-    }
-    if (this.logReaderPromise) {
-      this.logReaderPromise.child.kill('SIGINT');
-      try {
-        await this.logReaderPromise;
-      } catch {}
-    }
-    if (this.logsPath) {
-      await this.findBundlerErrors(this.logsPath);
-    }
-  }
-  private async getBuildLogFilename(logsDirectory: string): Promise<string | undefined> {
-    const paths = await fg('*.log', { cwd: logsDirectory });
-    return paths.length >= 1 ? paths[0] : undefined;
-  }
-
-  private async startBuildLogger(logsPath: string): Promise<void> {
-    try {
-      const formatter = ExpoRunFormatter.create(this.projectRoot, {
-        // TODO: Can provide xcode project name for better parsing
-        isDebug: false,
-      });
-      this.logReaderPromise = spawnAsync('tail', ['-n', '+0', '-f', logsPath], { stdio: 'pipe' });
-      assert(this.logReaderPromise.child.stdout, 'stdout is not available');
-      this.logReaderPromise.child.stdout.on('data', (data: string) => {
-        const lines = formatter.pipe(data.toString());
-        for (const line of lines) {
-          this.logger.info(line);
-        }
-      });
-      await this.logReaderPromise;
-
-      this.logger.info(formatter.getBuildSummary());
-    } catch (err: any) {
-      if (!this.flushing) {
-        this.loggerError = err;
-      }
-    }
-  }
-
-  private async findBundlerErrors(logsPath: string): Promise<void> {
-    try {
-      const logFile = await fs.readFile(logsPath, 'utf-8');
-      const match = logFile.match(
-        /Welcome to Metro!\s* Fast - Scalable - Integrated\s*([\s\S]*)Run CLI with --verbose flag for more details.\nCommand PhaseScriptExecution failed with a nonzero exit code/
-      );
-      if (match) {
-        this.logger.info(match[1]);
-      }
-    } catch (err) {
-      this.logger.error({ err }, 'Failed to read Xcode logs');
-    }
-  }
-}

yarn.lock

@@ -789,15 +789,6 @@ __metadata:
   languageName: node
   linkType: hard
 
-"@babel/code-frame@npm:7.10.4, @babel/code-frame@npm:^7.0.0, @babel/code-frame@npm:^7.10.4, @babel/code-frame@npm:~7.10.4":
-  version: 7.10.4
-  resolution: "@babel/code-frame@npm:7.10.4"
-  dependencies:
-    "@babel/highlight": "npm:^7.10.4"
-  checksum: 10c0/69e0f52986a1f40231d891224f420436629b6678711b68c088e97b7bdba1607aeb5eb9cfb070275c433f0bf43c37c134845db80d1cdbf5ac88a69b0bdcce9402
-  languageName: node
-  linkType: hard
-
 "@babel/code-frame@npm:7.23.5, @babel/code-frame@npm:^7.23.5":
   version: 7.23.5
   resolution: "@babel/code-frame@npm:7.23.5"
@@ -808,6 +799,15 @@ __metadata:
   languageName: node
   linkType: hard
 
+"@babel/code-frame@npm:^7.0.0, @babel/code-frame@npm:^7.10.4, @babel/code-frame@npm:~7.10.4":
+  version: 7.10.4
+  resolution: "@babel/code-frame@npm:7.10.4"
+  dependencies:
+    "@babel/highlight": "npm:^7.10.4"
+  checksum: 10c0/69e0f52986a1f40231d891224f420436629b6678711b68c088e97b7bdba1607aeb5eb9cfb070275c433f0bf43c37c134845db80d1cdbf5ac88a69b0bdcce9402
+  languageName: node
+  linkType: hard
+
 "@babel/code-frame@npm:^7.12.13":
   version: 7.12.13
   resolution: "@babel/code-frame@npm:7.12.13"
@@ -3614,16 +3614,15 @@ __metadata:
   linkType: soft
 
 "@expo/xcpretty@npm:^4.3.1":
-  version: 4.3.2
-  resolution: "@expo/xcpretty@npm:4.3.2"
+  version: 4.4.4
+  resolution: "@expo/xcpretty@npm:4.4.4"
   dependencies:
-    "@babel/code-frame": "npm:7.10.4"
+    "@babel/code-frame": "npm:^7.20.0"
     chalk: "npm:^4.1.0"
-    find-up: "npm:^5.0.0"
     js-yaml: "npm:^4.1.0"
   bin:
     excpretty: build/cli.js
-  checksum: 10c0/e524817b2e42fb8c8914fca7e8f7c2f723f4f6d338a57b7ae97cd3e76da8108af63a22d4c7dc2e96a192a248a242f6e0f8056f0ca53bc4fb5cd2e5ae428e0891
+  checksum: 10c0/cd555ad49438dee2cc3f2950ecbef3048f7169bbdadc8db169cfcddaad13668fee6377c010624ed4079dc439c46d6023d2551da403a2070deec000bc864e8dd8
   languageName: node
   linkType: hard
 
@@ -12119,16 +12118,6 @@ __metadata:
   languageName: node
   linkType: hard
 
-"find-up@npm:^5.0.0":
-  version: 5.0.0
-  resolution: "find-up@npm:5.0.0"
-  dependencies:
-    locate-path: "npm:^6.0.0"
-    path-exists: "npm:^4.0.0"
-  checksum: 10c0/062c5a83a9c02f53cdd6d175a37ecf8f87ea5bbff1fdfb828f04bfa021441bc7583e8ebc0872a4c1baab96221fb8a8a275a19809fb93fbc40bd69ec35634069a
-  languageName: node
-  linkType: hard
-
 "find-yarn-workspace-root@npm:^2.0.0":
   version: 2.0.0
   resolution: "find-yarn-workspace-root@npm:2.0.0"
@@ -15375,15 +15364,6 @@ __metadata:
   languageName: node
   linkType: hard
 
-"locate-path@npm:^6.0.0":
-  version: 6.0.0
-  resolution: "locate-path@npm:6.0.0"
-  dependencies:
-    p-locate: "npm:^5.0.0"
-  checksum: 10c0/d3972ab70dfe58ce620e64265f90162d247e87159b6126b01314dd67be43d50e96a50b517bce2d9452a79409c7614054c277b5232377de50416564a77ac7aad3
-  languageName: node
-  linkType: hard
-
 "lodash.clonedeep@npm:^4.5.0":
   version: 4.5.0
   resolution: "lodash.clonedeep@npm:4.5.0"
@@ -17349,7 +17329,7 @@ __metadata:
   languageName: node
   linkType: hard
 
-"p-limit@npm:3.1.0, p-limit@npm:^3.0.1, p-limit@npm:^3.0.2, p-limit@npm:^3.1.0":
+"p-limit@npm:3.1.0, p-limit@npm:^3.0.1, p-limit@npm:^3.1.0":
   version: 3.1.0
   resolution: "p-limit@npm:3.1.0"
   dependencies:
@@ -17394,15 +17374,6 @@ __metadata:
   languageName: node
   linkType: hard
 
-"p-locate@npm:^5.0.0":
-  version: 5.0.0
-  resolution: "p-locate@npm:5.0.0"
-  dependencies:
-    p-limit: "npm:^3.0.2"
-  checksum: 10c0/2290d627ab7903b8b70d11d384fee714b797f6040d9278932754a6860845c4d3190603a0772a663c8cb5a7b21d1b16acb3a6487ebcafa9773094edc3dfe6009a
-  languageName: node
-  linkType: hard
-
 "p-map-series@npm:2.1.0":
   version: 2.1.0
   resolution: "p-map-series@npm:2.1.0"