Compare commits

..
Author SHA1 Message Date
Brent Vatne 72b8a78145 [worker] Apply log masking to uploaded Xcode build logs
Pass the job's log masks to the Xcode build log upload and mask the file
line by line while streaming it, including values written in the escaped
form Xcode uses for build settings.
2026-10-20 16:31:19 -07:00
Brent Vatne 56646b7436 [eas-cli] Show simulator session errors in simulator:get (#4694)
Look up why a failed simulator session failed in both simulator:start and
simulator:get. For unknown errors, read the failed step's cause from the job
run log, using only the masked log message, with the download bounded by size
and time. Strip terminal control characters before printing.
2026-10-20 14:00:29 -07:00
Brent Vatne f775b10549 [eas-cli] Show why a simulator session failed to start (#4693)
* [eas-cli] Show why a simulator session failed to start

simulator:start only printed the session status when a session errored
before it was ready. The reason is already on the session's job run, so
fetch turtleJobRun.errors and print each message (and docs link) on its
own line.

* [eas-cli] Read simulator job run errors only on failure, and from logs for unknown errors

Fetch job run errors with a separate query when a session fails instead of
on every poll of the shared session query. When the job run only reports an
unknown error, print the failed step errors from its logs. Also show the
errors when a session fails after it is ready.

* [eas-cli] Show only structured job run errors in simulator:start

Drop the job run log fallback from this change, which printed unmasked
err.message lines, read logs for stopped sessions and had no timeout or size
limit. The bounded, masked log fallback lands in the simulator:get follow-up.

* [eas-cli] Bound and quiet the simulator job run errors lookup

Give the lookup a 10s deadline and the session's Ctrl+C signal, and cancel
its request by unsubscribing from urql, so it can't hold up stopping the
session. Don't retry it or print the transient-error message, since it's
best-effort. Cap each error message at 500 characters.
2026-10-20 13:51:21 -07:00
Brent Vatne c756c5d0b5 [worker] Mask secrets in every field of uploaded log records (#4698)
* [worker] Mask secrets in logged errors

The upload transform masked only each record's msg, so a serialized err
(message, stack and other fields) was uploaded with secrets intact. That
includes unknown build phase failures, which log { err } with an empty msg.
Mask the strings inside err on a copy, since bunyan shares the record with
other streams.

* [worker] Mask secrets in every field of uploaded log records

Mask all fields except bunyan's metadata, not only err: other fields such as
error, data and the job dump also carried secrets. Round-trip each value
through JSON first so a toJSON method can't bring back the original, mask keys
and numbers, and replace values nested too deeply instead of uploading them
unmasked.
2026-10-20 13:51:17 -07:00
Brent VatneandClaude Opus 5.5 9f674b1d19 [eas-build-job][build-tools] Check Android launch inputs before the session starts (#4696)
* [build-tools] Check Android launch inputs before the emulator boots

Agent-device sessions checked Android launch inputs only when launching,
after the emulator booted and the build installed. Check NUL characters
and the command length at the start of the step, as on iOS, leaving room
for the launch component that is only known after install.

* Add changeset for early Android launch input checks

* [eas-build-job] Share the Android launch input checks

Move the Android shell quoting and the early launch input checks into
@expo/eas-build-job, so www can check launch inputs when a session is
created, for every session type.

* [eas-build-job] Check only the known part of the Android launch command early

Co-Authored-By: Claude Opus 5.5 (1M context) <[email protected]>

---------

Co-authored-by: Claude Opus 5.5 (1M context) <[email protected]>
2026-10-20 13:40:44 -07:00
Expo CI 6f33a4d2a4 bump STAGING and PRODUCTION to 25.3.0 in cli-versions.json 2026-10-20 19:22:35 +00:00
28 changed files with 1885 additions and 56 deletions

No files matched your search

@@ -0,0 +1,6 @@
---
'@expo/eas-build-job': minor
'@expo/build-tools': patch
---
Export `validateAndroidLaunchOptions` and `quoteAndroidShellCommand` from `@expo/eas-build-job`, so Android launch arguments can be checked for NUL characters and length before a simulator session starts, and check them before the emulator boots in agent-device sessions.
@@ -0,0 +1,5 @@
---
'eas-cli': patch
---
Show why a simulator session failed in `eas simulator:get`, and add an `errors` array to its `--json` output. For an unknown error, `simulator:start` and `simulator:get` now show the failed step's error from the session logs.
@@ -0,0 +1,5 @@
---
'eas-cli': patch
---
Show why a simulator session failed in `eas simulator:start`, such as an unknown `--device` name, instead of only the session status.
+5
View File
@@ -0,0 +1,5 @@
---
'@expo/worker': patch
---
Mask secrets in every field of uploaded job log records, such as logged errors, not only in log messages.
@@ -0,0 +1,5 @@
---
'@expo/worker': patch
---
Apply the job log's secret masking to uploaded Xcode build logs.
+2 -2
View File
@@ -1,4 +1,4 @@
{
"STAGING": "25.2.0",
"PRODUCTION": "25.2.0"
"STAGING": "25.3.0",
"PRODUCTION": "25.3.0"
}
@@ -687,6 +687,18 @@ describe(createStartAgentDeviceSessionBuildFunction, () => {
expect(runAgentDeviceRemoteSessionAsync).not.toHaveBeenCalled();
});
it.each([
['NUL argument', { launch_args: ['a\u0000b'] }],
['command length', { launch_args: ['--es', 'quotes', "'".repeat(20_000)] }],
['NUL URL', { open_url: 'example:\u0000screen' }],
])('rejects Android launch %s before startup work', async (_name, inputs) => {
const step = runStep(BuildRuntimePlatform.LINUX, { build_id: 'build-id', ...inputs });
await expect(step).rejects.toMatchObject({ errorCode: 'EAS_LAUNCH_APPLICATION_INVALID_INPUT' });
expect(startAndroidEmulatorAsync).not.toHaveBeenCalled();
expect(downloadBuildAsync).not.toHaveBeenCalled();
expect(runAgentDeviceRemoteSessionAsync).not.toHaveBeenCalled();
});
it('keeps Android launch inputs on its existing direct path', async () => {
const launchArgs = ['a'.repeat(9000)];
await runStep(BuildRuntimePlatform.LINUX, { build_id: 'build-id', launch_args: launchArgs });
@@ -1,4 +1,4 @@
import { UserError } from '@expo/eas-build-job';
import { UserError, quoteAndroidShellCommand } from '@expo/eas-build-job';
import { bunyan } from '@expo/logger';
import {
BuildFunction,
@@ -11,8 +11,6 @@ import spawn from '@expo/turtle-spawn';
const IOS_URL_SCHEME_APPROVAL_DOMAIN = 'com.apple.launchservices.schemeapproval';
const IOS_URL_SCHEME_APPROVAL_KEY_PREFIX = 'com.apple.CoreSimulator.CoreSimulatorBridge-->';
// adb closes the connection for longer shell commands (about 65.5 KB with adb 37 on API 35).
const ANDROID_SHELL_COMMAND_MAX_BYTES = 65_000;
export function createLaunchApplicationFunction(): BuildFunction {
return new BuildFunction({
@@ -135,33 +133,11 @@ export async function launchApplicationAsync({
}
}
// `adb shell` joins its arguments with spaces and the device shell parses the result again, so
// each argument is quoted to reach the command as one literal word.
async function spawnAndroidShellCommandAsync(
command: string[],
{ env, logger }: { env: BuildStepEnv; logger: bunyan }
): Promise<void> {
if (command.some(argument => argument.includes('\0'))) {
throw new UserError(
'EAS_LAUNCH_APPLICATION_INVALID_INPUT',
'Android "launch_args" and "open_url" cannot contain NUL characters.'
);
}
const quotedCommand = command.map(quoteAndroidShellArgument);
if (Buffer.byteLength(quotedCommand.join(' ')) > ANDROID_SHELL_COMMAND_MAX_BYTES) {
throw new UserError(
'EAS_LAUNCH_APPLICATION_INVALID_INPUT',
`The Android launch command is longer than ${ANDROID_SHELL_COMMAND_MAX_BYTES} bytes after shell quoting. Shorten "launch_args" or "open_url".`
);
}
await spawn('adb', ['shell', ...quotedCommand], { env, logger });
}
function quoteAndroidShellArgument(argument: string): string {
if (/^[\w@%+=:,./-]+$/.test(argument)) {
return argument;
}
return `'${argument.replaceAll("'", `'\\''`)}'`;
await spawn('adb', ['shell', ...quoteAndroidShellCommand(command)], { env, logger });
}
async function preapproveIosUrlSchemeAsync({
@@ -1,4 +1,4 @@
import { UserError } from '@expo/eas-build-job';
import { UserError, validateAndroidLaunchOptions } from '@expo/eas-build-job';
import {
BuildFunction,
BuildRuntimePlatform,
@@ -164,6 +164,8 @@ export function createStartAgentDeviceSessionBuildFunction(ctx: CustomBuildConte
}
if (isIos) {
validateServeSimLaunchOptions({ launchArgs, openUrl });
} else {
validateAndroidLaunchOptions({ launchArgs, openUrl });
}
const deviceIdentifier = inputs.device_identifier.value as string | undefined;
const capture = parseNetworkCaptureInputs(
@@ -1,4 +1,9 @@
import { DeviceRunSessionEvent, parseDeviceRunSessionEvents } from '../deviceRunSession';
import {
DeviceRunSessionEvent,
parseDeviceRunSessionEvents,
quoteAndroidShellCommand,
validateAndroidLaunchOptions,
} from '../deviceRunSession';
describe('parseDeviceRunSessionEvents', () => {
it('parses, deduplicates, and sorts events from the dedicated event log', () => {
@@ -33,6 +38,56 @@ describe('parseDeviceRunSessionEvents', () => {
});
});
describe(quoteAndroidShellCommand, () => {
it('quotes only arguments the device shell would split or expand', () => {
expect(
quoteAndroidShellCommand(['am', 'start', '--es', 'text', 'hello world', "it's", '', '-n'])
).toEqual(['am', 'start', '--es', 'text', "'hello world'", "'it'\\''s'", "''", '-n']);
});
it('rejects NUL characters', () => {
expect(() => quoteAndroidShellCommand(['am', 'start', 'a\0b'])).toThrow(
expect.objectContaining({ errorCode: 'EAS_LAUNCH_APPLICATION_INVALID_INPUT' })
);
});
});
describe(validateAndroidLaunchOptions, () => {
it('rejects only commands that are too long without the launch component', () => {
const fixedLength = 'am start --es key -n'.length;
const launchArgs = (valueLength: number) => ['--es', 'key', 'a'.repeat(valueLength)];
expect(() =>
validateAndroidLaunchOptions({ launchArgs: launchArgs(65_000 - fixedLength) })
).not.toThrow();
expect(() =>
validateAndroidLaunchOptions({ launchArgs: launchArgs(65_000 - fixedLength + 1) })
).toThrow(expect.objectContaining({ errorCode: 'EAS_LAUNCH_APPLICATION_INVALID_INPUT' }));
});
it('counts bytes, not characters', () => {
// "é" is two bytes in UTF-8 and is quoted, which adds two more.
const fixedLength = "am start --es key '' -n".length;
const launchArgs = (extraLength: number) => [
'--es',
'key',
'a'.repeat(extraLength) + 'é'.repeat(32_488),
];
expect(fixedLength + 1 + 2 * 32_488).toBe(65_000);
expect(() => validateAndroidLaunchOptions({ launchArgs: launchArgs(1) })).not.toThrow();
expect(() => validateAndroidLaunchOptions({ launchArgs: launchArgs(2) })).toThrow(
expect.objectContaining({ errorCode: 'EAS_LAUNCH_APPLICATION_INVALID_INPUT' })
);
});
it('checks the URL to open', () => {
expect(() => validateAndroidLaunchOptions({ openUrl: 'exp://example.test/a\0b' })).toThrow(
expect.objectContaining({ errorCode: 'EAS_LAUNCH_APPLICATION_INVALID_INPUT' })
);
});
});
function createEvent(overrides: Partial<DeviceRunSessionEvent> = {}): string {
return JSON.stringify(createEventValue(overrides));
}
@@ -1,5 +1,7 @@
import { z } from 'zod';
import { UserError } from './errors';
/**
* Canonical record format for the activity events emitted during a remote device run (simulator)
* session. Producers (e.g. the worker and agent-device) write these as NDJSON to the
@@ -46,3 +48,54 @@ export function parseDeviceRunSessionEvents(eventLog: string): DeviceRunSessionE
(left, right) => new Date(left.ts).getTime() - new Date(right.ts).getTime()
);
}
// adb closes the connection for longer shell commands (about 65.5 KB with adb 37 on API 35).
export const ANDROID_SHELL_COMMAND_MAX_BYTES = 65_000;
/**
* Check Android launch inputs before a session starts. The launch component is only known once the
* build is installed, so this rejects only commands that are too long without it; the launch itself
* checks the exact command.
*/
export function validateAndroidLaunchOptions({
launchArgs = [],
openUrl,
}: {
launchArgs?: string[];
openUrl?: string;
}): void {
quoteAndroidShellCommand(['am', 'start', ...launchArgs, '-n']);
if (openUrl) {
quoteAndroidShellCommand(['am', 'start', '-a', 'android.intent.action.VIEW', '-d', openUrl]);
}
}
/**
* `adb shell` joins its arguments with spaces and the device shell parses the result again, so
* each argument is quoted to reach the command as one literal word.
*/
export function quoteAndroidShellCommand(command: string[]): string[] {
if (command.some(argument => argument.includes('\0'))) {
throw new UserError(
'EAS_LAUNCH_APPLICATION_INVALID_INPUT',
'Android "launch_args" and "open_url" cannot contain NUL characters.'
);
}
const quotedCommand = command.map(quoteAndroidShellArgument);
if (
new TextEncoder().encode(quotedCommand.join(' ')).byteLength > ANDROID_SHELL_COMMAND_MAX_BYTES
) {
throw new UserError(
'EAS_LAUNCH_APPLICATION_INVALID_INPUT',
`The Android launch command is longer than ${ANDROID_SHELL_COMMAND_MAX_BYTES} bytes after shell quoting. Shorten "launch_args" or "open_url".`
);
}
return quotedCommand;
}
function quoteAndroidShellArgument(argument: string): string {
if (/^[\w@%+=:,./-]+$/.test(argument)) {
return argument;
}
return `'${argument.replaceAll("'", `'\\''`)}'`;
}
@@ -40,6 +40,7 @@ jest.mock('../../../utils/json');
type DeviceRunSessionById = DeviceRunSessionByIdQuery['deviceRunSessions']['byId'];
const mockByIdAsync = jest.mocked(DeviceRunSessionQuery.byIdAsync);
const mockJobRunErrorsByIdAsync = jest.mocked(DeviceRunSessionQuery.jobRunErrorsByIdAsync);
const mockEnableJsonOutput = jest.mocked(enableJsonOutput);
const mockLoadSimulatorEnvironmentVariablesAsync = jest.mocked(loadSimulatorEnvAsync);
const mockPrintJsonOnlyOutput = jest.mocked(printJsonOnlyOutput);
@@ -108,6 +109,7 @@ describe(SimulatorGet, () => {
beforeEach(() => {
jest.clearAllMocks();
mockLoadSimulatorEnvironmentVariablesAsync.mockResolvedValue();
mockJobRunErrorsByIdAsync.mockResolvedValue(null);
});
function createCommand(argv: string[]): {
@@ -162,6 +164,79 @@ describe(SimulatorGet, () => {
previewApiUrl: null,
},
artifacts: session.artifacts,
errors: [],
});
expect(mockJobRunErrorsByIdAsync).not.toHaveBeenCalled();
});
describe('errored sessions', () => {
const jobRunErrors = {
id: 'job-123',
errors: [
{
errorCode: 'EAS_IOS_SIMULATOR_NOT_FOUND',
message: 'No available iOS Simulator is named "iPhone 16 Pro".',
docsUrl: null,
},
],
logFileUrls: [],
};
it('includes the job run errors in JSON output', async () => {
mockByIdAsync.mockResolvedValue(
makeDeviceRunSession({ status: DeviceRunSessionStatus.Errored, remoteConfig: null })
);
mockJobRunErrorsByIdAsync.mockResolvedValue(jobRunErrors);
const { command } = createCommand(['--id', 'session-123', '--json']);
await command.runAsync();
expect(mockJobRunErrorsByIdAsync).toHaveBeenCalledWith(graphqlClient, 'session-123', {
signal: expect.any(AbortSignal),
});
expect(mockPrintJsonOnlyOutput).toHaveBeenCalledWith(
expect.objectContaining({
errors: [
{
errorCode: 'EAS_IOS_SIMULATOR_NOT_FOUND',
message: 'No available iOS Simulator is named "iPhone 16 Pro".',
docsUrl: null,
},
],
})
);
});
it('prints the job run errors when only the job run errored', async () => {
mockByIdAsync.mockResolvedValue(
makeDeviceRunSession({
status: DeviceRunSessionStatus.Stopped,
remoteConfig: null,
turtleJobRun: { id: 'job-123', status: JobRunStatus.Errored },
})
);
mockJobRunErrorsByIdAsync.mockResolvedValue(jobRunErrors);
const { command } = createCommand(['--id', 'session-123']);
await command.runAsync();
expect(Log.gray).toHaveBeenCalledWith('Session errors:');
expect(Log.error).toHaveBeenCalledWith(
' No available iOS Simulator is named "iPhone 16 Pro".'
);
});
it('prints no errors section when the job run errors cannot be fetched', async () => {
mockByIdAsync.mockResolvedValue(
makeDeviceRunSession({ status: DeviceRunSessionStatus.Errored, remoteConfig: null })
);
mockJobRunErrorsByIdAsync.mockRejectedValue(new Error('graphql boom'));
const { command } = createCommand(['--id', 'session-123']);
await command.runAsync();
expect(Log.gray).not.toHaveBeenCalledWith('Session errors:');
expect(Log.error).not.toHaveBeenCalled();
});
});
@@ -6,6 +6,7 @@ import { GraphQLError } from 'graphql';
import { SimulatorEvent, isAnalyticsOptedOutAsync } from '../../../analytics/AnalyticsManager';
import { getAgentTelemetryContext } from '../../../analytics/agent';
import { ExpoGraphqlClient } from '../../../commandUtils/context/contextUtils/createGraphqlClient';
import fetch from '../../../fetch';
import {
AppPlatform,
CreateDeviceRunSessionMutation,
@@ -44,6 +45,7 @@ jest.mock('../../../analytics/AnalyticsManager', () => ({
jest.mock('../../../analytics/agent');
jest.mock('../../../graphql/mutations/DeviceRunSessionMutation');
jest.mock('../../../graphql/queries/DeviceRunSessionAvailabilityQuery');
jest.mock('../../../fetch');
jest.mock('../../../graphql/queries/DeviceRunSessionQuery');
jest.mock('../../../log', () => ({
__esModule: true,
@@ -57,6 +59,7 @@ jest.mock('../../../log', () => ({
withTick: jest.fn(),
},
link: jest.fn((url: string) => url),
learnMore: jest.fn((url: string) => `Learn more: ${url}`),
}));
jest.mock('../../../simulator/env', () => ({
...jest.requireActual('../../../simulator/env'),
@@ -105,6 +108,8 @@ const mockEnsureDeviceRunSessionStoppedAsync = jest.mocked(
);
const mockAvailabilityByAppIdAsync = jest.mocked(DeviceRunSessionAvailabilityQuery.byAppIdAsync);
const mockByIdAsync = jest.mocked(DeviceRunSessionQuery.byIdAsync);
const mockJobRunErrorsByIdAsync = jest.mocked(DeviceRunSessionQuery.jobRunErrorsByIdAsync);
const mockFetch = jest.mocked(fetch);
const mockLoadSimulatorEnvAsync = jest.mocked(loadSimulatorEnvAsync);
const mockLogEvent = jest.fn();
const mockFlushAsync = jest.fn(async () => {});
@@ -191,6 +196,7 @@ describe(Simulator, () => {
jest.restoreAllMocks();
jest.clearAllMocks();
delete process.env[EAS_SIMULATOR_SESSION_ID];
mockJobRunErrorsByIdAsync.mockResolvedValue(null);
mockAvailabilityByAppIdAsync.mockResolvedValue({ accountName: 'testuser', available: true });
mockCreateDeviceRunSessionAsync.mockResolvedValue(makeCreatedDeviceRunSession());
mockEnsureDeviceRunSessionStoppedAsync.mockResolvedValue({
@@ -1990,6 +1996,292 @@ describe(Simulator, () => {
);
});
describe('job run errors', () => {
const erroredSessionMessage =
'Simulator session session-123 errored before the agent-device session was ready. https://expo.dev/accounts/testuser/projects/testapp/simulator-sessions/session-123';
const logFileUrl = 'https://logs.example.com/job-123';
const unknownError = {
errorCode: 'UNKNOWN_ERROR',
message: 'Unknown error. See logs for more information.',
docsUrl: null,
};
// Shaped like the worker's bunyan output: the failing call logs at error level with `err`,
// then the step runner logs an end-step marker with result "fail".
function failedStepLogLines(
stepId: string,
displayName: string,
messages: string[]
): Record<string, unknown>[] {
return [
{
level: 30,
buildStepId: stepId,
buildStepDisplayName: displayName,
marker: 'start-step',
msg: `Executing build step "${displayName}"`,
},
...messages.map(msg => ({
level: 50,
buildStepId: stepId,
buildStepDisplayName: displayName,
msg,
err: { message: msg },
})),
{
level: 50,
buildStepId: stepId,
buildStepDisplayName: displayName,
marker: 'end-step',
result: 'fail',
msg: `Build step "${displayName}" failed`,
},
];
}
function mockLogFile(logLines: Record<string, unknown>[]): void {
mockFetch.mockResolvedValue({
text: async () => logLines.map(line => JSON.stringify(line)).join('\n'),
} as unknown as Awaited<ReturnType<typeof fetch>>);
}
beforeEach(() => {
mockByIdAsync.mockResolvedValue(
makeDeviceRunSession({ status: DeviceRunSessionStatus.Errored, remoteConfig: null })
);
});
it('keeps the message unchanged without reading logs when the job run has no errors', async () => {
mockJobRunErrorsByIdAsync.mockResolvedValue({
id: 'job-123',
errors: [],
logFileUrls: [logFileUrl],
});
const { command } = createCommand(['--platform', 'ios', '--non-interactive']);
await expect(command.runAsync()).rejects.toThrow(
expect.objectContaining({ message: erroredSessionMessage })
);
expect(mockFetch).not.toHaveBeenCalled();
});
it('lists each job run error on its own line with its docs link', async () => {
mockJobRunErrorsByIdAsync.mockResolvedValue({
id: 'job-123',
errors: [
{
errorCode: 'EAS_IOS_SIMULATOR_NOT_FOUND',
message: 'No available iOS Simulator is named "iPhone 16 Pro".',
docsUrl: null,
},
{
errorCode: 'EAS_SIMULATOR_BUILD_NOT_INSTALLABLE',
message: 'The build cannot be installed on a simulator.',
docsUrl: 'https://docs.expo.dev/simulator',
},
],
logFileUrls: [logFileUrl],
});
const { command } = createCommand(['--platform', 'ios', '--non-interactive']);
await expect(command.runAsync()).rejects.toThrow(
expect.objectContaining({
message: `${erroredSessionMessage}\nNo available iOS Simulator is named "iPhone 16 Pro".\nThe build cannot be installed on a simulator. Learn more: https://docs.expo.dev/simulator`,
})
);
expect(mockFetch).not.toHaveBeenCalled();
});
it('reads the failed step error from the job run logs for an unknown error', async () => {
mockJobRunErrorsByIdAsync.mockResolvedValue({
id: 'job-123',
errors: [unknownError],
logFileUrls: [logFileUrl],
});
mockLogFile([
{
level: 50,
buildStepId: 'step-001',
buildStepDisplayName: 'Install application',
msg: 'Retrying install',
err: { message: 'Retrying install' },
},
{
level: 30,
buildStepId: 'step-001',
marker: 'end-step',
result: 'success',
msg: 'Finished',
},
...failedStepLogLines('step-002', 'Launch application', [
'adb shell am start exited with non-zero code: 1',
]),
{
level: 20,
buildStepId: 'step-002',
msg: 'Getting value for output parameter "x" failed.',
err: { message: 'not set' },
},
{
level: 40,
msg: 'Could not stop the emulator during remote session teardown.',
err: { message: 'teardown' },
},
]);
const { command } = createCommand(['--platform', 'ios', '--non-interactive']);
await expect(command.runAsync()).rejects.toThrow(
expect.objectContaining({
message: `${erroredSessionMessage}\nLaunch application: adb shell am start exited with non-zero code: 1`,
})
);
expect(mockFetch).toHaveBeenCalledWith(
logFileUrl,
expect.objectContaining({ size: 20 * 1024 * 1024, signal: expect.any(AbortSignal) })
);
});
it('prints the masked log message instead of the unmasked err.message', async () => {
mockJobRunErrorsByIdAsync.mockResolvedValue({
id: 'job-123',
errors: [unknownError],
logFileUrls: [logFileUrl],
});
mockLogFile([
{
level: 50,
buildStepId: 'step-001',
buildStepDisplayName: 'Run script',
msg: 'curl -H "Authorization: ********" exited with non-zero code: 22',
err: { message: 'curl -H "Authorization: secret-token" exited with non-zero code: 22' },
},
{
level: 50,
buildStepId: 'step-001',
marker: 'end-step',
result: 'fail',
msg: 'Build step "Run script" failed',
},
]);
const { command } = createCommand(['--platform', 'ios', '--non-interactive']);
await expect(command.runAsync()).rejects.toThrow(
expect.objectContaining({
message: `${erroredSessionMessage}\nRun script: curl -H "Authorization: ********" exited with non-zero code: 22`,
})
);
});
it('shows the first failed step, then only the error line of later failed steps', async () => {
mockJobRunErrorsByIdAsync.mockResolvedValue({
id: 'job-123',
errors: [unknownError],
logFileUrls: [logFileUrl],
});
mockLogFile([
...failedStepLogLines('step-001', 'Boot', ['A', 'B']),
...failedStepLogLines('step-002', 'Finish recordings', ['C', 'D']),
]);
const { command } = createCommand(['--platform', 'ios', '--non-interactive']);
await expect(command.runAsync()).rejects.toThrow(
expect.objectContaining({
message: `${erroredSessionMessage}\nBoot: B\nFinish recordings: D`,
})
);
});
it('truncates very long log errors', async () => {
mockJobRunErrorsByIdAsync.mockResolvedValue({
id: 'job-123',
errors: [unknownError],
logFileUrls: [logFileUrl],
});
mockLogFile(failedStepLogLines('step-001', 'Boot', ['x'.repeat(2000)]));
const { command } = createCommand(['--platform', 'ios', '--non-interactive']);
await expect(command.runAsync()).rejects.toThrow(
expect.objectContaining({
message: `${erroredSessionMessage}\n${`Boot: ${'x'.repeat(2000)}`.slice(0, 500)}…`,
})
);
});
it('keeps the job run error when no step failed, ignoring errors that steps ignored', async () => {
mockJobRunErrorsByIdAsync.mockResolvedValue({
id: 'job-123',
errors: [
{
errorCode: 'UNKNOWN_ERROR',
message:
'Unknown error. See logs of the Complete job build phase for more information.',
docsUrl: null,
},
],
logFileUrls: [logFileUrl],
});
mockLogFile([
{
level: 50,
buildStepId: 'step-001',
buildStepDisplayName: 'Upload artifact',
msg: 'Failed to upload screen-recording. Ignoring error.',
err: { message: 'upload failed' },
},
{
level: 30,
buildStepId: 'step-001',
marker: 'end-step',
result: 'success',
msg: 'Finished',
},
{ level: 50, phase: 'COMPLETE_JOB', msg: '', err: { message: 'upload outputs failed' } },
]);
const { command } = createCommand(['--platform', 'ios', '--non-interactive']);
await expect(command.runAsync()).rejects.toThrow(
expect.objectContaining({
message: `${erroredSessionMessage}\nUnknown error. See logs of the Complete job build phase for more information.`,
})
);
});
it('falls back to the unknown error message when the job run logs cannot be read', async () => {
mockJobRunErrorsByIdAsync.mockResolvedValue({
id: 'job-123',
errors: [unknownError],
logFileUrls: [logFileUrl],
});
mockFetch.mockRejectedValue(new Error('Request failed: 503 (Service Unavailable)'));
const { command } = createCommand(['--platform', 'ios', '--non-interactive']);
await expect(command.runAsync()).rejects.toThrow(
expect.objectContaining({
message: `${erroredSessionMessage}\nUnknown error. See logs for more information.`,
})
);
});
it('keeps the message unchanged when the job run errors cannot be fetched', async () => {
mockJobRunErrorsByIdAsync.mockRejectedValue(new Error('graphql boom'));
const { command } = createCommand(['--platform', 'ios', '--non-interactive']);
await expect(command.runAsync()).rejects.toThrow(
expect.objectContaining({ message: erroredSessionMessage })
);
expect(mockEnsureDeviceRunSessionStoppedAsync).toHaveBeenCalled();
});
});
it('keeps polling until the remote config appears', async () => {
mockByIdAsync
.mockResolvedValueOnce(makeDeviceRunSession({ remoteConfig: null }))
@@ -2289,6 +2581,31 @@ describe(Simulator, () => {
await expect(command.runAsync()).rejects.toThrow('Simulator session session-123 errored.');
});
it('includes the job run error when the session errors while it is running', async () => {
mockByIdAsync
.mockResolvedValueOnce(makeDeviceRunSession())
.mockResolvedValueOnce(makeDeviceRunSession({ status: DeviceRunSessionStatus.Errored }));
mockJobRunErrorsByIdAsync.mockResolvedValue({
id: 'job-123',
errors: [
{
errorCode: 'EAS_SIMULATOR_SESSION_CRASHED',
message: 'The simulator stopped responding.',
docsUrl: null,
},
],
logFileUrls: [],
});
const { command } = createCommand(['--platform', 'ios']);
await expect(command.runAsync()).rejects.toThrow(
expect.objectContaining({
message: 'Simulator session session-123 errored.\nThe simulator stopped responding.',
})
);
});
it('keeps waiting while the session is still in progress', async () => {
mockByIdAsync
.mockResolvedValueOnce(makeDeviceRunSession())
+24 -1
View File
@@ -6,7 +6,11 @@ import {
EasNonInteractiveAndJsonFlags,
resolveNonInteractiveAndJsonFlags,
} from '../../commandUtils/flags';
import { DeviceRunSessionByIdQuery, DeviceRunSessionStatus } from '../../graphql/generated';
import {
DeviceRunSessionByIdQuery,
DeviceRunSessionStatus,
JobRunStatus,
} from '../../graphql/generated';
import { DeviceRunSessionQuery } from '../../graphql/queries/DeviceRunSessionQuery';
import Log, { link } from '../../log';
import { ora } from '../../ora';
@@ -15,6 +19,11 @@ import {
SIMULATOR_DOTENV_FILE_NAME,
loadSimulatorEnvAsync,
} from '../../simulator/env';
import {
SimulatorSessionError,
fetchSimulatorSessionErrorsAsync,
formatSimulatorSessionError,
} from '../../simulator/jobRunErrors';
import {
deviceRunSessionTypeToFlagValue,
formatRemoteSessionInstructions,
@@ -87,6 +96,11 @@ export default class SimulatorGet extends EasCommand {
session.app.slug,
session.id
);
const errors: SimulatorSessionError[] =
session.status === DeviceRunSessionStatus.Errored ||
session.turtleJobRun?.status === JobRunStatus.Errored
? await fetchSimulatorSessionErrorsAsync(graphqlClient, session.id)
: [];
if (jsonFlag) {
printJsonOnlyOutput({
@@ -109,6 +123,7 @@ export default class SimulatorGet extends EasCommand {
)
: session.remoteConfig,
artifacts: session.artifacts,
errors,
});
return;
}
@@ -116,6 +131,14 @@ export default class SimulatorGet extends EasCommand {
Log.newLine();
Log.log(formatSessionFields(session, deviceRunSessionUrl));
if (errors.length > 0) {
Log.newLine();
Log.gray('Session errors:');
for (const error of errors) {
Log.error(` ${formatSimulatorSessionError(error)}`);
}
}
if (session.status === DeviceRunSessionStatus.InProgress) {
Log.newLine();
if (session.remoteConfig) {
@@ -41,6 +41,10 @@ import {
writeSimulatorEnvAsync,
} from '../../simulator/env';
import { resolveExpoGoSdkVersionAsync } from '../../simulator/expoGo';
import {
fetchSimulatorSessionErrorsAsync,
formatSimulatorSessionError,
} from '../../simulator/jobRunErrors';
import {
simulatorRequestFailureReason,
simulatorRequestProperties,
@@ -461,7 +465,7 @@ export default class Simulator extends EasCommand {
session.status === DeviceRunSessionStatus.Stopped
) {
throw new Error(
`Simulator session ${deviceRunSessionId} ${session.status.toLowerCase()} before the ${flags.type} session was ready. ${link(deviceRunSessionUrl)}`
`Simulator session ${deviceRunSessionId} ${session.status.toLowerCase()} before the ${flags.type} session was ready. ${link(deviceRunSessionUrl)}${await formatJobRunErrorsAsync(graphqlClient, deviceRunSessionId, sessionInterrupt.signal)}`
);
}
@@ -472,7 +476,7 @@ export default class Simulator extends EasCommand {
jobRunStatus === JobRunStatus.Finished
) {
throw new Error(
`Turtle job run for simulator session ${deviceRunSessionId} ${jobRunStatus.toLowerCase()} before the ${flags.type} session was ready. ${link(deviceRunSessionUrl)}`
`Turtle job run for simulator session ${deviceRunSessionId} ${jobRunStatus.toLowerCase()} before the ${flags.type} session was ready. ${link(deviceRunSessionUrl)}${await formatJobRunErrorsAsync(graphqlClient, deviceRunSessionId, sessionInterrupt.signal)}`
);
}
@@ -634,6 +638,18 @@ export default class Simulator extends EasCommand {
}
}
// Returns the reasons the session's job run failed, one per line, or an empty string when none are available.
async function formatJobRunErrorsAsync(
graphqlClient: ExpoGraphqlClient,
deviceRunSessionId: string,
signal: AbortSignal
): Promise<string> {
const errors = await fetchSimulatorSessionErrorsAsync(graphqlClient, deviceRunSessionId, {
signal,
});
return errors.map(error => `\n${formatSimulatorSessionError(error)}`).join('');
}
async function resolvePlatformAsync(
platform: PlatformFlagValue | undefined,
nonInteractive: boolean
@@ -715,7 +731,9 @@ async function waitForSessionEndOrInterruptAsync({
jobRunStatus === JobRunStatus.Errored
) {
spinner.fail(`Simulator session errored. ${link(deviceRunSessionUrl)}`);
throw new Error(`Simulator session ${deviceRunSessionId} errored.`);
throw new Error(
`Simulator session ${deviceRunSessionId} errored.${await formatJobRunErrorsAsync(graphqlClient, deviceRunSessionId, signal)}`
);
}
if (
session.status === DeviceRunSessionStatus.Stopped ||
+7
View File
@@ -16018,6 +16018,13 @@ export type DeviceRunSessionEventsByIdQueryVariables = Exact<{
export type DeviceRunSessionEventsByIdQuery = { __typename?: 'RootQuery', deviceRunSessions: { __typename?: 'DeviceRunSessionQuery', byId: { __typename?: 'DeviceRunSession', id: string, status: DeviceRunSessionStatus, artifacts: Array<{ __typename?: 'DeviceRunSessionArtifact', id: string, downloadUrl: string, metadata?: any | null }> } } };
export type DeviceRunSessionJobRunErrorsByIdQueryVariables = Exact<{
deviceRunSessionId: Scalars['ID']['input'];
}>;
export type DeviceRunSessionJobRunErrorsByIdQuery = { __typename?: 'RootQuery', deviceRunSessions: { __typename?: 'DeviceRunSessionQuery', byId: { __typename?: 'DeviceRunSession', id: string, turtleJobRun?: { __typename?: 'JobRun', id: string, logFileUrls: Array<string>, errors: Array<{ __typename?: 'JobRunError', errorCode: string, message: string, docsUrl?: string | null }> } | null } } };
export type DeviceRunSessionByIdQueryVariables = Exact<{
deviceRunSessionId: Scalars['ID']['input'];
}>;
@@ -1,3 +1,4 @@
import { OperationResult, OperationResultSource } from '@urql/core';
import gql from 'graphql-tag';
import { ExpoGraphqlClient } from '../../commandUtils/context/contextUtils/createGraphqlClient';
@@ -8,6 +9,8 @@ import {
DeviceRunSessionEventsByIdQuery,
DeviceRunSessionEventsByIdQueryVariables,
DeviceRunSessionFilterInput,
DeviceRunSessionJobRunErrorsByIdQuery,
DeviceRunSessionJobRunErrorsByIdQueryVariables,
DeviceRunSessionsByAppIdQuery,
DeviceRunSessionsByAppIdQueryVariables,
} from '../generated';
@@ -42,6 +45,52 @@ export const DeviceRunSessionQuery = {
);
return data.deviceRunSessions.byId;
},
/**
* Best-effort lookup of why the session's job run failed. It doesn't retry or print errors, and it
* rejects with `signal.reason` and cancels the request when `signal` aborts.
*/
async jobRunErrorsByIdAsync(
graphqlClient: ExpoGraphqlClient,
deviceRunSessionId: string,
{ signal }: { signal: AbortSignal }
): Promise<DeviceRunSessionJobRunErrorsByIdQuery['deviceRunSessions']['byId']['turtleJobRun']> {
const { data, error } = await firstResultUntilAbortedAsync(
graphqlClient.query<
DeviceRunSessionJobRunErrorsByIdQuery,
DeviceRunSessionJobRunErrorsByIdQueryVariables
>(
gql`
query DeviceRunSessionJobRunErrorsByIdQuery($deviceRunSessionId: ID!) {
deviceRunSessions {
byId(deviceRunSessionId: $deviceRunSessionId) {
id
turtleJobRun {
id
errors {
errorCode
message
docsUrl
}
logFileUrls
}
}
}
}
`,
{ deviceRunSessionId },
// Retries would keep a timer alive after the caller gives up.
{ requestPolicy: 'network-only', noRetry: true }
),
signal
);
if (error) {
throw error;
}
if (!data) {
throw new Error('Returned query result data is null!');
}
return data.deviceRunSessions.byId.turtleJobRun;
},
async byIdAsync(
graphqlClient: ExpoGraphqlClient,
deviceRunSessionId: string
@@ -224,3 +273,41 @@ export const DeviceRunSessionQuery = {
return data.app.byId.deviceRunSessionsPaginated;
},
};
// Like `toPromise()`, but unsubscribing on abort makes urql cancel the request.
async function firstResultUntilAbortedAsync<T extends OperationResult>(
source: OperationResultSource<T>,
signal: AbortSignal
): Promise<T> {
signal.throwIfAborted();
return await new Promise<T>((resolve, reject) => {
let subscription: { unsubscribe: () => void } | undefined;
let settled = false;
const settle = (finish: () => void): void => {
if (settled) {
return;
}
settled = true;
signal.removeEventListener('abort', onAbort);
subscription?.unsubscribe();
finish();
};
const onAbort = (): void => {
settle(() => {
reject(signal.reason);
});
};
signal.addEventListener('abort', onAbort, { once: true });
subscription = source.subscribe(result => {
if (!result.stale && !result.hasNext) {
settle(() => {
resolve(result);
});
}
});
// The result can arrive synchronously, before `subscription` is assigned.
if (settled) {
subscription.unsubscribe();
}
});
}
@@ -0,0 +1,142 @@
import http from 'http';
import { AddressInfo } from 'net';
import { createGraphqlClient } from '../../../commandUtils/context/contextUtils/createGraphqlClient';
import Log from '../../../log';
import { DeviceRunSessionQuery } from '../DeviceRunSessionQuery';
jest.mock('../../../api', () => ({
getExpoApiBaseUrl: () => process.env.DEVICE_RUN_SESSION_QUERY_TEST_URL,
}));
describe('DeviceRunSessionQuery.jobRunErrorsByIdAsync', () => {
let server: http.Server;
let requests: number;
let closedRequests: number;
async function startServerAsync(handler: http.RequestListener): Promise<void> {
requests = 0;
closedRequests = 0;
server = http.createServer((request, response) => {
requests += 1;
request.socket.on('close', () => {
closedRequests += 1;
});
handler(request, response);
});
await new Promise<void>(resolve => server.listen(0, '127.0.0.1', resolve));
const { port } = server.address() as AddressInfo;
process.env.DEVICE_RUN_SESSION_QUERY_TEST_URL = `http://127.0.0.1:${port}`;
}
function respondWithJson(body: unknown): http.RequestListener {
return (_request, response) => {
response.setHeader('content-type', 'application/json');
response.end(JSON.stringify(body));
};
}
afterEach(async () => {
jest.restoreAllMocks();
server.closeAllConnections();
await new Promise(resolve => server.close(resolve));
});
it('returns the job run errors', async () => {
const turtleJobRun = {
__typename: 'JobRun',
id: 'job-123',
logFileUrls: ['https://logs.example.com/job-123'],
errors: [
{
__typename: 'JobRunError',
errorCode: 'UNKNOWN_ERROR',
message: 'Unknown error.',
docsUrl: null,
},
],
};
await startServerAsync(
respondWithJson({
data: {
deviceRunSessions: {
__typename: 'DeviceRunSessionQuery',
byId: { __typename: 'DeviceRunSession', id: 'session-123', turtleJobRun },
},
},
})
);
const client = createGraphqlClient({ accessToken: 'token', sessionSecret: null });
await expect(
DeviceRunSessionQuery.jobRunErrorsByIdAsync(client, 'session-123', {
signal: new AbortController().signal,
})
).resolves.toEqual(turtleJobRun);
});
it('rejects without printing anything on a transient GraphQL error', async () => {
const logErrorSpy = jest.spyOn(Log, 'error').mockImplementation(() => {});
await startServerAsync(
respondWithJson({
data: null,
errors: [{ message: 'Try again', extensions: { isTransient: true } }],
})
);
const client = createGraphqlClient({ accessToken: 'token', sessionSecret: null });
await expect(
DeviceRunSessionQuery.jobRunErrorsByIdAsync(client, 'session-123', {
signal: new AbortController().signal,
})
).rejects.toThrow('Try again');
expect(logErrorSpy).not.toHaveBeenCalled();
expect(requests).toBe(1);
});
it('does not retry a network error', async () => {
await startServerAsync(request => {
request.socket.destroy();
});
const client = createGraphqlClient({ accessToken: 'token', sessionSecret: null });
await expect(
DeviceRunSessionQuery.jobRunErrorsByIdAsync(client, 'session-123', {
signal: new AbortController().signal,
})
).rejects.toThrow();
expect(requests).toBe(1);
});
it('rejects and cancels the request when the signal aborts', async () => {
const controller = new AbortController();
await startServerAsync(() => {
controller.abort(new Error('interrupted'));
});
const client = createGraphqlClient({ accessToken: 'token', sessionSecret: null });
await expect(
DeviceRunSessionQuery.jobRunErrorsByIdAsync(client, 'session-123', {
signal: controller.signal,
})
).rejects.toThrow('interrupted');
for (let attempt = 0; attempt < 50 && closedRequests === 0; attempt++) {
await new Promise(resolve => setTimeout(resolve, 20));
}
expect(closedRequests).toBe(1);
});
it('rejects without sending a request when the signal has already aborted', async () => {
await startServerAsync(() => {});
const client = createGraphqlClient({ accessToken: 'token', sessionSecret: null });
const controller = new AbortController();
controller.abort(new Error('interrupted'));
await expect(
DeviceRunSessionQuery.jobRunErrorsByIdAsync(client, 'session-123', {
signal: controller.signal,
})
).rejects.toThrow('interrupted');
expect(requests).toBe(0);
});
});
@@ -0,0 +1,479 @@
import http from 'http';
import { AddressInfo } from 'net';
import { ExpoGraphqlClient } from '../../commandUtils/context/contextUtils/createGraphqlClient';
import { DeviceRunSessionQuery } from '../../graphql/queries/DeviceRunSessionQuery';
import type LogType from '../../log';
import type * as JobRunErrors from '../jobRunErrors';
jest.mock('../../graphql/queries/DeviceRunSessionQuery');
jest.mock('../../log');
const mockJobRunErrorsByIdAsync = jest.mocked(DeviceRunSessionQuery.jobRunErrorsByIdAsync);
const graphqlClient = {} as ExpoGraphqlClient;
const unknownError = {
errorCode: 'UNKNOWN_ERROR',
message: 'Unknown error. See logs for more information.',
docsUrl: null,
};
// src/fetch.ts reads https_proxy when it loads, so load it only after clearing the proxy.
let jobRunErrors: typeof JobRunErrors;
let Log: typeof LogType;
beforeAll(() => {
delete process.env.https_proxy;
jest.isolateModules(() => {
jobRunErrors = jest.requireActual('../jobRunErrors');
Log = jest.requireMock('../../log').default;
});
});
// Lines 116-121 of a real failed Android session log, trimmed. The step's stderr has the precise
// cause at level 30; the level-50 error line only has the exit code.
const failedLaunchLog = [
{
level: 30,
buildStepId: 'install_build',
marker: 'end-step',
result: 'success',
msg: 'Finished build step "Install build" successfully',
},
{
level: 30,
buildStepId: 'install_build',
source: 'stderr',
msg: 'Error: Unable to find emulator skin, using default',
},
{
level: 30,
buildStepId: 'step-002',
buildStepDisplayName: 'Launch application',
marker: 'start-step',
msg: 'Executing build step "Launch application"',
},
{
level: 30,
buildStepId: 'step-002',
buildStepDisplayName: 'Launch application',
source: 'stdout',
msg: 'Starting: Intent { act=android.intent.action.MAIN pkg=world }',
},
{
level: 30,
buildStepId: 'step-002',
buildStepDisplayName: 'Launch application',
source: 'stderr',
msg: 'Error: Activity not started, unable to resolve Intent { act=android.intent.action.MAIN pkg=world }',
},
{
level: 50,
buildStepId: 'step-002',
buildStepDisplayName: 'Launch application',
msg: 'adb shell am start -n dev.brent.euxy/.MainActivity exited with non-zero code: 1',
err: {
message: 'adb shell am start -n dev.brent.euxy/.MainActivity exited with non-zero code: 1',
},
},
{
level: 50,
buildStepId: 'step-002',
buildStepDisplayName: 'Launch application',
marker: 'end-step',
result: 'fail',
msg: 'Build step "Launch application" failed',
},
];
describe('selectFailedStepErrors', () => {
it("shows the failed step's stderr cause before its error line", () => {
expect(jobRunErrors.selectFailedStepErrors(failedLaunchLog)).toEqual([
'Launch application: Error: Activity not started, unable to resolve Intent { act=android.intent.action.MAIN pkg=world }',
'Launch application: adb shell am start -n dev.brent.euxy/.MainActivity exited with non-zero code: 1',
]);
});
it('ignores stderr from steps that did not fail', () => {
const messages = jobRunErrors.selectFailedStepErrors(failedLaunchLog);
expect(messages.join('\n')).not.toContain('emulator skin');
});
it('never prints the unmasked err.message of a phase failure with an empty message', () => {
const phaseFailureLog = [
{ level: 30, phase: 'PREPARE_PROJECT', msg: 'Start phase: PREPARE_PROJECT' },
{
level: 50,
phase: 'PREPARE_PROJECT',
msg: '',
err: {
message: 'git clone https://[email protected]/acme/app failed',
stack: 'Error: git clone https://[email protected]/acme/app failed',
},
},
];
expect(jobRunErrors.selectFailedStepErrors(phaseFailureLog)).toEqual([]);
});
it('ignores errors outside of failed steps, such as errors a step ignored', () => {
expect(
jobRunErrors.selectFailedStepErrors([
{
level: 50,
buildStepId: 'step-001',
buildStepDisplayName: 'Upload artifact',
msg: 'Failed to upload screen-recording. Ignoring error.',
err: { message: 'upload failed' },
},
{
level: 30,
buildStepId: 'step-001',
marker: 'end-step',
result: 'success',
msg: 'Finished',
},
{
level: 50,
msg: 'simctl boot failed for ********',
err: { message: 'simctl boot failed for secret-udid' },
},
])
).toEqual([]);
});
it('keeps the stderr line that continues the cause', () => {
expect(
jobRunErrors.selectFailedStepErrors([
{
level: 30,
buildStepId: 'step-001',
buildStepDisplayName: 'Boot simulator',
source: 'stderr',
msg: 'An error was encountered processing the command (domain=com.apple.CoreSimulator.SimError, code=405):',
},
{
level: 30,
buildStepId: 'step-001',
buildStepDisplayName: 'Boot simulator',
source: 'stderr',
msg: 'Invalid device: iPhone 16 Pro',
},
{
level: 50,
buildStepId: 'step-001',
buildStepDisplayName: 'Boot simulator',
msg: 'xcrun simctl boot exited with non-zero code: 149',
err: { message: 'xcrun simctl boot exited with non-zero code: 149' },
},
{
level: 50,
buildStepId: 'step-001',
marker: 'end-step',
result: 'fail',
msg: 'Build step "Boot simulator" failed',
},
])
).toEqual([
'Boot simulator: An error was encountered processing the command (domain=com.apple.CoreSimulator.SimError, code=405):',
'Boot simulator: Invalid device: iPhone 16 Pro',
'Boot simulator: xcrun simctl boot exited with non-zero code: 149',
]);
});
it('keeps the cause of the first failed step when later steps also fail', () => {
expect(
jobRunErrors.selectFailedStepErrors([
...failedLaunchLog,
{
level: 30,
buildStepId: 'step-003',
buildStepDisplayName: 'Finish recordings',
source: 'stderr',
msg: 'Error: No devices are booted.',
},
{
level: 50,
buildStepId: 'step-003',
buildStepDisplayName: 'Finish recordings',
msg: 'xcrun simctl io recordVideo exited with non-zero code: 1',
err: { message: 'x' },
},
{
level: 50,
buildStepId: 'step-003',
marker: 'end-step',
result: 'fail',
msg: 'Build step "Finish recordings" failed',
},
])
).toEqual([
'Launch application: Error: Activity not started, unable to resolve Intent { act=android.intent.action.MAIN pkg=world }',
'Launch application: adb shell am start -n dev.brent.euxy/.MainActivity exited with non-zero code: 1',
'Finish recordings: xcrun simctl io recordVideo exited with non-zero code: 1',
]);
});
it('strips escape sequences and control characters from step names and messages', () => {
expect(
jobRunErrors.selectFailedStepErrors([
{
level: 50,
buildStepId: 'step-001',
buildStepDisplayName: 'Boot\u001b[2J simulator',
msg: '\u001b[31mxcrun simctl boot\u001b[0m exited\r\nwith code: 149\u0007',
err: { message: 'x' },
},
{
level: 50,
buildStepId: 'step-001',
marker: 'end-step',
result: 'fail',
msg: 'Build step "Boot simulator" failed',
},
])
).toEqual(['Boot simulator: xcrun simctl boot exited with code: 149']);
});
it('finds a colored stderr cause and skips error lines that are only escape sequences', () => {
expect(
jobRunErrors.selectFailedStepErrors([
{
level: 30,
buildStepId: 'step-001',
buildStepDisplayName: 'Launch application',
source: 'stderr',
msg: '\u001b[31mError\u001b[0m: Activity not started',
},
{
level: 50,
buildStepId: 'step-001',
buildStepDisplayName: 'Launch application',
msg: 'adb shell am start exited with non-zero code: 1',
err: { message: 'x' },
},
{
level: 50,
buildStepId: 'step-001',
buildStepDisplayName: 'Launch application',
msg: '\u001b[0m\u001b[K',
err: { message: 'x' },
},
{
level: 50,
buildStepId: 'step-001',
marker: 'end-step',
result: 'fail',
msg: 'Build step "Launch application" failed',
},
])
).toEqual([
'Launch application: Error: Activity not started',
'Launch application: adb shell am start exited with non-zero code: 1',
]);
});
});
describe('fetchSimulatorSessionErrorsAsync', () => {
let server: http.Server;
let closedRequests: number;
async function startServerAsync(handler: http.RequestListener): Promise<string> {
closedRequests = 0;
server = http.createServer((request, response) => {
request.socket.on('close', () => {
closedRequests += 1;
});
handler(request, response);
});
await new Promise<void>(resolve => server.listen(0, '127.0.0.1', resolve));
const { port } = server.address() as AddressInfo;
return `http://127.0.0.1:${port}/logs`;
}
beforeEach(() => {
jest.clearAllMocks();
});
async function waitForCloseAsync(): Promise<void> {
for (let attempt = 0; attempt < 50 && closedRequests === 0; attempt++) {
await new Promise(resolve => setTimeout(resolve, 20));
}
}
afterEach(async () => {
server.closeAllConnections();
await new Promise(resolve => server.close(resolve));
});
function mockJobRun(logFileUrl: string): void {
mockJobRunErrorsByIdAsync.mockResolvedValue({
id: 'job-123',
errors: [unknownError],
logFileUrls: [logFileUrl],
});
}
it('returns the failed step errors from the downloaded log', async () => {
mockJobRun(
await startServerAsync((_request, response) => {
response.end(failedLaunchLog.map(line => JSON.stringify(line)).join('\n'));
})
);
await expect(
jobRunErrors.fetchSimulatorSessionErrorsAsync(graphqlClient, 'session-123')
).resolves.toEqual([
{
errorCode: 'UNKNOWN_ERROR',
message: expect.stringContaining('Activity not started'),
docsUrl: null,
},
{
errorCode: 'UNKNOWN_ERROR',
message: expect.stringContaining('exited with non-zero code: 1'),
docsUrl: null,
},
]);
});
it('does not log the signed log URL when the download fails', async () => {
const logFileUrl = await startServerAsync((request, response) => {
request.socket.destroy();
response.end();
});
mockJobRun(`${logFileUrl}?X-Goog-Signature=secret-signature`);
await expect(
jobRunErrors.fetchSimulatorSessionErrorsAsync(graphqlClient, 'session-123')
).resolves.toEqual([unknownError]);
expect(JSON.stringify(jest.mocked(Log.debug).mock.calls)).not.toContain('secret-signature');
});
it('strips escape sequences and control characters from job run error messages', async () => {
server = http.createServer();
await new Promise<void>(resolve => server.listen(0, '127.0.0.1', resolve));
mockJobRunErrorsByIdAsync.mockResolvedValue({
id: 'job-123',
errors: [
{
errorCode: 'EAS_IOS_SIMULATOR_NOT_FOUND',
message: 'No available iOS Simulator is named "\u001b[2JiPhone\u001b]0;x\u0007\nFake"',
docsUrl: null,
},
],
logFileUrls: [],
});
await expect(
jobRunErrors.fetchSimulatorSessionErrorsAsync(graphqlClient, 'session-123')
).resolves.toEqual([
{
errorCode: 'EAS_IOS_SIMULATOR_NOT_FOUND',
message: 'No available iOS Simulator is named "iPhone Fake"',
docsUrl: null,
},
]);
});
it('falls back to the job run error when the log request fails', async () => {
mockJobRun(
await startServerAsync((_request, response) => {
response.statusCode = 404;
response.end(JSON.stringify({ level: 50, msg: 'not the cause', err: { message: 'x' } }));
})
);
await expect(
jobRunErrors.fetchSimulatorSessionErrorsAsync(graphqlClient, 'session-123')
).resolves.toEqual([unknownError]);
});
it('falls back and closes the connection when the log is too large', async () => {
mockJobRun(
await startServerAsync((_request, response) => {
const chunk = 'x'.repeat(64 * 1024);
const timer = setInterval(() => response.write(chunk), 5);
response.on('close', () => {
clearInterval(timer);
});
})
);
await expect(
jobRunErrors.fetchSimulatorSessionErrorsAsync(graphqlClient, 'session-123', {
maxLogSizeBytes: 256 * 1024,
})
).resolves.toEqual([unknownError]);
await waitForCloseAsync();
expect(closedRequests).toBe(1);
});
it('falls back and closes the connection when the log download stalls', async () => {
mockJobRun(
await startServerAsync((_request, response) => {
response.write('{"level":30,');
})
);
const startedAt = Date.now();
await expect(
jobRunErrors.fetchSimulatorSessionErrorsAsync(graphqlClient, 'session-123', {
logDownloadTimeoutMs: 200,
})
).resolves.toEqual([unknownError]);
expect(Date.now() - startedAt).toBeLessThan(2_000);
await waitForCloseAsync();
expect(closedRequests).toBe(1);
});
it('stops the log download when the signal aborts', async () => {
mockJobRun(
await startServerAsync((_request, response) => {
response.write('{"level":30,');
})
);
const controller = new AbortController();
setTimeout(() => {
controller.abort();
}, 100);
await expect(
jobRunErrors.fetchSimulatorSessionErrorsAsync(graphqlClient, 'session-123', {
signal: controller.signal,
})
).resolves.toEqual([unknownError]);
await waitForCloseAsync();
expect(closedRequests).toBe(1);
});
it('does not look up errors when the signal has already aborted', async () => {
server = http.createServer();
await new Promise<void>(resolve => server.listen(0, '127.0.0.1', resolve));
const controller = new AbortController();
controller.abort();
await expect(
jobRunErrors.fetchSimulatorSessionErrorsAsync(graphqlClient, 'session-123', {
signal: controller.signal,
})
).resolves.toEqual([]);
expect(mockJobRunErrorsByIdAsync).not.toHaveBeenCalled();
});
it('passes an abortable signal with a deadline to the errors query', async () => {
server = http.createServer();
await new Promise<void>(resolve => server.listen(0, '127.0.0.1', resolve));
mockJobRunErrorsByIdAsync.mockImplementation(
async (_client, _id, { signal }) =>
await new Promise((_resolve, reject) => {
signal.addEventListener('abort', () => {
reject(signal.reason);
});
})
);
await expect(
jobRunErrors.fetchSimulatorSessionErrorsAsync(graphqlClient, 'session-123', {
queryTimeoutMs: 100,
})
).resolves.toEqual([]);
});
});
@@ -0,0 +1,172 @@
import { stripVTControlCharacters } from 'util';
import { ExpoGraphqlClient } from '../commandUtils/context/contextUtils/createGraphqlClient';
import { parseLogLines } from '../commandUtils/logs/parseLogs';
import { RawLogLine } from '../commandUtils/logs/types';
import fetch from '../fetch';
import { DeviceRunSessionQuery } from '../graphql/queries/DeviceRunSessionQuery';
import Log, { learnMore } from '../log';
import { sanitizeTerminalText } from '../utils/terminalText';
export type SimulatorSessionError = {
errorCode: string;
message: string;
docsUrl?: string | null;
};
export type FetchSimulatorSessionErrorsOptions = {
/** Aborts the lookup, e.g. on Ctrl+C. */
signal?: AbortSignal;
queryTimeoutMs?: number;
logDownloadTimeoutMs?: number;
maxLogSizeBytes?: number;
};
// ErrorCode.UNKNOWN_ERROR and ErrorCode.UNKNOWN_CUSTOM_BUILD_ERROR from @expo/eas-build-job.
const UNKNOWN_ERROR_CODES = new Set(['UNKNOWN_ERROR', 'UNKNOWN_CUSTOM_BUILD_ERROR']);
const DEFAULT_QUERY_TIMEOUT_MS = 10_000;
const DEFAULT_LOG_DOWNLOAD_TIMEOUT_MS = 10_000;
const DEFAULT_MAX_LOG_SIZE_BYTES = 20 * 1024 * 1024;
const MAX_LOGGED_ERRORS = 4;
const MAX_LOGGED_ERROR_LENGTH = 500;
// Bunyan's "error" level.
const ERROR_LOG_LEVEL = 50;
const STDERR_CAUSE_PATTERN = /\b(error|exception|fatal)\b/i;
type JobRunLogLine = RawLogLine & { level?: number; source?: string };
// Returns why the session's job run failed, or an empty list when that is not available.
export async function fetchSimulatorSessionErrorsAsync(
graphqlClient: ExpoGraphqlClient,
deviceRunSessionId: string,
{
signal,
queryTimeoutMs = DEFAULT_QUERY_TIMEOUT_MS,
logDownloadTimeoutMs = DEFAULT_LOG_DOWNLOAD_TIMEOUT_MS,
maxLogSizeBytes = DEFAULT_MAX_LOG_SIZE_BYTES,
}: FetchSimulatorSessionErrorsOptions = {}
): Promise<SimulatorSessionError[]> {
if (signal?.aborted) {
return [];
}
let jobRun;
try {
jobRun = await DeviceRunSessionQuery.jobRunErrorsByIdAsync(graphqlClient, deviceRunSessionId, {
signal: withTimeout(signal, queryTimeoutMs),
});
} catch (err) {
Log.debug(`Failed to fetch simulator session errors: ${err}`);
return [];
}
const errors = jobRun?.errors ?? [];
// Uncategorized failures only say "Unknown error. See logs", so read the real cause from the job run logs.
const logFileUrl = jobRun?.logFileUrls[0];
if (
logFileUrl &&
errors.length > 0 &&
errors.every(error => UNKNOWN_ERROR_CODES.has(error.errorCode))
) {
const logErrors = await fetchJobRunLogErrorsAsync(logFileUrl, {
signal: withTimeout(signal, logDownloadTimeoutMs),
maxLogSizeBytes,
});
if (logErrors.length > 0) {
return logErrors.map(message => ({ errorCode: errors[0].errorCode, message, docsUrl: null }));
}
}
return errors.map(({ errorCode, message, docsUrl }) => ({
errorCode,
message: formatMessage(message),
docsUrl,
}));
}
export function formatSimulatorSessionError(error: SimulatorSessionError): string {
return `${error.message}${error.docsUrl ? ` ${learnMore(error.docsUrl)}` : ''}`;
}
function withTimeout(signal: AbortSignal | undefined, timeoutMs: number): AbortSignal {
const timeoutSignal = AbortSignal.timeout(timeoutMs);
return signal ? AbortSignal.any([signal, timeoutSignal]) : timeoutSignal;
}
async function fetchJobRunLogErrorsAsync(
logFileUrl: string,
{ signal, maxLogSizeBytes }: { signal: AbortSignal; maxLogSizeBytes: number }
): Promise<string[]> {
// node-fetch stops reading on its own only when the body ends, so abort to close the connection
// after an error, an oversized body or a timeout.
const controller = new AbortController();
try {
const response = await fetch(logFileUrl, {
size: maxLogSizeBytes,
signal: AbortSignal.any([signal, controller.signal]),
});
const { logLines } = parseLogLines(await response.text());
return selectFailedStepErrors(logLines);
} catch (err) {
// node-fetch's error messages include the signed log URL, so leave the message out.
Log.debug(
`Failed to read simulator session logs: ${err instanceof Error ? err.name : 'unknown error'}`
);
return [];
} finally {
controller.abort();
}
}
// Describes the steps that failed, the first one first: its last error line, preceded by the stderr
// line that names the cause and the line after it. Later failed steps only add their error line.
// Uses the log message rather than err.message because only the message has secrets masked.
export function selectFailedStepErrors(logLines: JobRunLogLine[]): string[] {
const failedStepIds = [
...new Set(
logLines
.filter(line => line.marker === 'end-step' && line.result === 'fail' && line.buildStepId)
.map(line => line.buildStepId as string)
),
];
const messages = failedStepIds.flatMap((stepId, index) => {
const lines = selectStepFailureLines(logLines.filter(line => line.buildStepId === stepId));
return (index === 0 ? lines : lines.slice(-1)).map(formatLogLine);
});
return [...new Set(messages)].slice(0, MAX_LOGGED_ERRORS);
}
function selectStepFailureLines(stepLines: JobRunLogLine[]): JobRunLogLine[] {
let selected: JobRunLogLine[] = [];
let stderrCause: JobRunLogLine[] = [];
for (const [index, line] of stepLines.entries()) {
const text = toPlainText(line.msg ?? '');
if (line.source === 'stderr') {
if (STDERR_CAUSE_PATTERN.test(text)) {
stderrCause = [line];
} else if (stderrCause.length === 1 && stepLines[index - 1] === stderrCause[0]) {
stderrCause.push(line);
}
} else if (line.err && (line.level ?? 0) >= ERROR_LOG_LEVEL && text) {
selected = [...stderrCause, line];
stderrCause = [];
}
}
return selected;
}
function formatLogLine(line: JobRunLogLine): string {
return formatMessage(
line.buildStepDisplayName ? `${line.buildStepDisplayName}: ${line.msg}` : String(line.msg)
);
}
// Log text comes from commands run in the session, so strip escape sequences and control
// characters that could clear the terminal or spoof output.
function toPlainText(message: string): string {
return sanitizeTerminalText(stripVTControlCharacters(message));
}
function formatMessage(message: string): string {
const text = toPlainText(message);
return text.length > MAX_LOGGED_ERROR_LENGTH
? `${text.slice(0, MAX_LOGGED_ERROR_LENGTH)}…`
: text;
}
@@ -39,6 +39,7 @@ describe(createBuildContext.name, () => {
buildId: 'build-id',
buildLogger,
addBuildLogMask: jest.fn(),
createLogMaskingStream: jest.fn(),
};
beforeEach(() => {
+192 -1
View File
@@ -1,4 +1,5 @@
import { TransformCallback, Writable } from 'node:stream';
import { Readable, Transform, TransformCallback, Writable } from 'node:stream';
import { pipeline } from 'node:stream/promises';
import { EnvironmentSecretType } from '@expo/eas-build-job';
import z from 'zod';
@@ -185,6 +186,100 @@ describe('logger', () => {
expect(logs.map(log => log.msg)).toEqual(['token: ***************, prefix: ***']);
});
describe('structured fields', () => {
async function logWithSecretAsync(
log: (
logger: Awaited<ReturnType<typeof createBuildLoggerWithSecretsFilter>>['logger']
) => void
): Promise<any[]> {
const { logger, outputStream } = await createBuildLoggerWithSecretsFilter({
environmentSecrets: [
{ name: 'TOKEN', value: 'secret-token', type: EnvironmentSecretType.STRING },
{ name: 'PIN', value: '123456789', type: EnvironmentSecretType.STRING },
],
});
const logs: any[] = [];
outputStream.pipe(
new Writable({
objectMode: true,
write(chunk: any, _encoding: BufferEncoding, callback: TransformCallback) {
logs.push(chunk);
callback(null, chunk);
},
})
);
log(logger);
await waitForStreamFlush();
// The upload streams send JSON.stringify(record).
for (const record of logs) {
expect(JSON.stringify(record)).not.toContain('secret-token');
expect(JSON.stringify(record)).not.toContain('123456789');
}
return logs;
}
it('masks errors, including when the message is empty', async () => {
const err = new Error('git clone https://[email protected]/acme/app failed');
const logs = await logWithSecretAsync(logger => {
logger.error({ err }, '');
logger.error({ err });
});
expect(logs).toHaveLength(2);
for (const log of logs) {
expect(log.err.message).toBe('git clone https://************@github.com/acme/app failed');
expect(log.err.stack).toContain(
'git clone https://************@github.com/acme/app failed'
);
}
expect(logs[0].msg).toBe('');
expect(logs[1].msg).toBe('git clone https://************@github.com/acme/app failed');
});
it('masks other fields, keys and numbers, and keeps metadata fields', async () => {
const job = { env: { TOKEN_COPY: 'secret-token', 'secret-token': 'key', PIN: 123456789 } };
const logs = await logWithSecretAsync(logger => {
logger.info({ job, source: 'stdout', buildStepId: 'step-1' }, 'Builder is ready');
});
expect(logs[0].job).toEqual({
env: { TOKEN_COPY: '************', '************': 'key', PIN: '*********' },
});
expect(logs[0].source).toBe('stdout');
expect(logs[0].buildStepId).toBe('step-1');
// The caller's object, which bunyan also hands to other streams, is not changed.
expect(job.env.TOKEN_COPY).toBe('secret-token');
});
it('masks what a toJSON method returns', async () => {
const logs = await logWithSecretAsync(logger => {
logger.error(
{
err: {
token: 'secret-token',
toJSON: () => ({ token: 'secret-token', at: new Date(0) }),
},
},
'failed'
);
});
expect(logs[0].err).toEqual({ token: '************', at: '1970-01-01T00:00:00.000Z' });
});
it('truncates deeply nested values instead of uploading them unmasked', async () => {
let nested: any = { token: 'secret-token' };
for (let index = 0; index < 30; index++) {
nested = { nested };
}
const logs = await logWithSecretAsync(logger => {
logger.error({ err: nested }, 'failed');
});
expect(JSON.stringify(logs[0].err)).toContain('[Truncated]');
});
});
it('adds logId to each log', async () => {
const { logger, outputStream } = await createBuildLoggerWithSecretsFilter({});
@@ -262,3 +357,99 @@ describe('logger', () => {
expect(outputStream.readableLength).toBe(0);
});
});
describe('createLogMaskingStream', () => {
async function maskAsync(stream: Transform, chunks: Buffer[]): Promise<Buffer> {
const output: Buffer[] = [];
await pipeline(
Readable.from(chunks),
stream,
new Writable({
write(chunk: Buffer, _encoding: BufferEncoding, callback: (error?: Error | null) => void) {
output.push(chunk);
callback();
},
})
);
return Buffer.concat(output);
}
it('masks secrets, secrets as Xcode prints them in build settings, and decoded secrets', async () => {
const { createLogMaskingStream } = await createBuildLoggerWithSecretsFilter({
environmentSecrets: [
{ name: 'API_KEY', value: 'ab cd=ef$gh', type: EnvironmentSecretType.STRING },
{
name: 'ANOTHER_SECRET_BASE64',
value: 'YW5vdGhlclNlY3JldA==',
type: EnvironmentSecretType.STRING,
},
],
});
const log = [
' export API_KEY\\=ab\\ cd\\=ef\\$gh',
'token is ab cd=ef$gh',
'decoded anotherSecret here',
'',
].join('\n');
const masked = await maskAsync(createLogMaskingStream(), [Buffer.from(log)]);
expect(masked.toString()).toBe(
[
` export API_KEY\\=${'*'.repeat(14)}`,
`token is ${'*'.repeat(11)}`,
`decoded ${'*'.repeat(13)} here`,
'',
].join('\n')
);
});
it('masks secrets split across chunks, including masks added after the logger was created', async () => {
const { createLogMaskingStream, addBuildLogMask } = await createBuildLoggerWithSecretsFilter(
{}
);
addBuildLogMask('leased-token');
const masked = await maskAsync(createLogMaskingStream(), [
Buffer.from('first line leased-'),
Buffer.from('token\nsecond '),
Buffer.from('leased-token without a newline'),
]);
expect(masked.toString()).toBe(
`first line ${'*'.repeat(12)}\nsecond ${'*'.repeat(12)} without a newline`
);
});
it('keeps everything except secrets byte for byte, including multibyte and invalid UTF-8', async () => {
const { createLogMaskingStream } = await createBuildLoggerWithSecretsFilter({
environmentSecrets: [
{ name: 'PASSWORD', value: 'pässwörd', type: EnvironmentSecretType.STRING },
],
});
const log = Buffer.concat([
Buffer.from('✓ Compiling café.swift\r\n'),
Buffer.from([0xff, 0xfe, 0x0a]),
Buffer.from('password: pässwörd\n'),
]);
// Split inside the multibyte characters.
const chunks = [
log.subarray(0, 1),
log.subarray(1, 20),
log.subarray(20, 40),
log.subarray(40),
];
const masked = await maskAsync(createLogMaskingStream(), chunks);
const passwordBytes = Buffer.byteLength('pässwörd');
expect(masked).toEqual(
Buffer.concat([
Buffer.from('✓ Compiling café.swift\r\n'),
Buffer.from([0xff, 0xfe, 0x0a]),
Buffer.from(`password: ${'*'.repeat(passwordBytes)}\n`),
])
);
expect(masked.length).toBe(log.length);
});
});
@@ -115,6 +115,7 @@ describe('BuildService Datadog setup', () => {
createBuildLoggerWithSecretsFilterMock.mockResolvedValue({
logger: buildLogger,
addBuildLogMask: jest.fn(),
createLogMaskingStream: jest.fn(),
cleanUp: jest.fn(async () => {}),
logBuffer: { getLogs: () => [], getPhaseLogs: () => [] } as any,
outputStream: {} as any,
@@ -0,0 +1,82 @@
import { RemoteLoggerStream, uploadWithSignedUrl } from '@expo/build-tools';
import fs from 'fs-extra';
import os from 'os';
import path from 'path';
import { Readable } from 'stream';
import zlib from 'zlib';
import config from '../config';
import { uploadXcodeBuildLogs } from '../ios/xcodeLogs';
import { createTextMaskingStream } from '../logger';
// These tests use real fs and directories in os.tmpdir(), since memfs read streams can't be closed.
jest.unmock('fs');
jest.unmock('node:fs');
const logger = { warn: jest.fn() } as any;
async function readAllAsync(stream: Readable): Promise<Buffer> {
const chunks: Buffer[] = [];
for await (const chunk of stream) {
chunks.push(Buffer.from(chunk));
}
return Buffer.concat(chunks);
}
describe(uploadXcodeBuildLogs, () => {
const originalGcs = { ...config.loggers.gcs };
let tmpDir: string;
beforeEach(async () => {
tmpDir = await fs.mkdtemp(path.join(os.tmpdir(), 'xcode-logs-test-'));
config.loggers.gcs.signedUploadUrlForXcodeBuildLogs = {
url: 'https://gcs.expo.test/xcode-logs',
headers: {},
};
});
afterEach(async () => {
Object.assign(config.loggers.gcs, originalGcs);
jest.mocked(uploadWithSignedUrl).mockReset();
await fs.remove(tmpDir);
});
it.each([
['no compression', null, (body: Buffer) => body],
['gzip', RemoteLoggerStream.CompressionMethod.GZIP, zlib.gunzipSync],
['brotli', RemoteLoggerStream.CompressionMethod.BR, zlib.brotliDecompressSync],
])('uploads the log with secrets masked (%s)', async (_name, compressionMethod, decompress) => {
config.loggers.gcs.compressionMethod = compressionMethod as any;
const logsPath = path.join(tmpDir, 'xcodebuild.log');
await fs.writeFile(logsPath, ' export API_KEY\\=ab\\ cd\\=ef\\$gh\n** BUILD SUCCEEDED **\n');
let uploaded: Buffer | undefined;
jest.mocked(uploadWithSignedUrl).mockImplementation(async ({ srcGeneratorAsync }) => {
uploaded = await readAllAsync((await srcGeneratorAsync()) as Readable);
return 'https://gcs.expo.test/xcode-logs';
});
await uploadXcodeBuildLogs(logger, logsPath, () =>
createTextMaskingStream(new Set(['ab cd=ef$gh']))
);
expect(decompress(uploaded!).toString()).toBe(
` export API_KEY\\=${'*'.repeat(14)}\n** BUILD SUCCEEDED **\n`
);
});
it.each([
['no compression', null],
['gzip', RemoteLoggerStream.CompressionMethod.GZIP],
])('fails the upload when the log cannot be read (%s)', async (_name, compressionMethod) => {
config.loggers.gcs.compressionMethod = compressionMethod as any;
jest.mocked(uploadWithSignedUrl).mockImplementation(async ({ srcGeneratorAsync }) => {
await readAllAsync((await srcGeneratorAsync()) as Readable);
return 'https://gcs.expo.test/xcode-logs';
});
// A directory can be stat'ed but not read.
await expect(
uploadXcodeBuildLogs(logger, tmpDir, () => createTextMaskingStream(new Set(['secret'])))
).rejects.toThrow('EISDIR');
});
});
+4 -1
View File
@@ -2,6 +2,7 @@ import { BuildContext, BuildContextOptions, LogBuffer, RuntimeSettings } from '@
import { Job, ManagedArtifactType, Metadata, Platform } from '@expo/eas-build-job';
import { bunyan } from '@expo/logger';
import assert from 'assert';
import { Transform } from 'stream';
import { GCSCacheManager } from './CacheManager';
import config from './config';
@@ -27,6 +28,7 @@ export async function createBuildContext<TJob extends Job>({
buildId,
buildLogger,
addBuildLogMask,
createLogMaskingStream,
}: {
job: TJob;
logBuffer: LogBuffer;
@@ -36,6 +38,7 @@ export async function createBuildContext<TJob extends Job>({
buildId: string;
buildLogger: bunyan;
addBuildLogMask: (secret: string) => void;
createLogMaskingStream: () => Transform;
}): Promise<BuildContext<TJob>> {
const childLogger = buildLogger.child({ buildId });
await RuntimeSettings.loadAsync({
@@ -51,7 +54,7 @@ export async function createBuildContext<TJob extends Job>({
switch (type) {
case ManagedArtifactType.XCODE_BUILD_LOGS: {
if (job.platform === Platform.IOS) {
await uploadXcodeBuildLogs(logger, paths[0]);
await uploadXcodeBuildLogs(logger, paths[0], createLogMaskingStream);
return { filename: null };
}
throw new Error('Uploading Xcode logs in non-iOS builds is not supported');
+14 -3
View File
@@ -3,14 +3,18 @@ import { bunyan } from '@expo/logger';
import fs from 'fs-extra';
import os from 'os';
import path from 'path';
import { Readable, pipeline } from 'stream';
import { Readable, Transform, pipeline } from 'stream';
import { promisify } from 'util';
import { v4 as uuid } from 'uuid';
import zlib from 'zlib';
import config from '../config';
export async function uploadXcodeBuildLogs(logger: bunyan, logsPath: string): Promise<void> {
export async function uploadXcodeBuildLogs(
logger: bunyan,
logsPath: string,
createLogMaskingStream: () => Transform
): Promise<void> {
if (!config.loggers.gcs.signedUploadUrlForXcodeBuildLogs) {
logger.warn('GCS Presigned URL for Xcode logs was not specified, skipping upload');
} else {
@@ -18,8 +22,15 @@ export async function uploadXcodeBuildLogs(logger: bunyan, logsPath: string): Pr
signedUrl: config.loggers.gcs.signedUploadUrlForXcodeBuildLogs,
srcGeneratorAsync: async () => {
const stat = await fs.stat(logsPath);
// Masking replaces each byte of a secret with one byte, so the size stays the same.
// pipeline passes read errors on to the masked stream, which fails the upload.
const maskedStream = pipeline(
fs.createReadStream(logsPath),
createLogMaskingStream(),
() => {}
);
const { stream } = await compress(
{ stream: fs.createReadStream(logsPath), length: stat.size },
{ stream: maskedStream, length: stat.size },
config.loggers.gcs.compressionMethod
);
return stream;
+111 -17
View File
@@ -59,30 +59,79 @@ export class WorkerLogBuffer extends Writable implements LogBuffer {
}
}
// Bunyan's own fields and fields that identify a log line, which never hold user data.
const UNMASKED_FIELDS = new Set([
'name',
'pid',
'level',
'time',
'v',
'phase',
'source',
'marker',
'result',
'buildStepId',
'buildStepInternalId',
]);
const MAX_MASKED_DEPTH = 20;
function createTransformStream(secretPatterns: ReadonlySet<string>): Transform {
return new Transform({
readableObjectMode: true,
writableObjectMode: true,
transform(_chunk: any, _encoding: BufferEncoding, callback: TransformCallback) {
let chunk = _chunk;
if (chunk && typeof chunk === 'object') {
// Remove hostname from logs since we don't need it.
const { hostname: _hostname, ...rest } = chunk;
chunk = {
...rest,
// Add logId to each log.
logId: uuidv7(),
};
if (!_chunk || typeof _chunk !== 'object') {
callback(null, _chunk);
return;
}
// Remove hostname from logs since we don't need it. Bunyan shares the record with other
// streams, so build a copy instead of changing it.
const { hostname: _hostname, ...rest } = _chunk;
const chunk: Record<string, unknown> = {};
for (const [key, value] of Object.entries(rest)) {
// Secrets can be in any field, such as a serialized error's message and stack.
chunk[key] =
secretPatterns.size === 0 || UNMASKED_FIELDS.has(key)
? value
: maskSecretsInValue(value, secretPatterns);
}
// Add logId to each log.
chunk.logId = uuidv7();
callback(null, chunk);
},
});
}
if (chunk && typeof chunk === 'object' && chunk.msg) {
callback(null, {
...chunk,
msg: maskSecrets(chunk.msg as string, secretPatterns),
});
} else {
callback(null, chunk);
}
// Characters that Xcode escapes with a backslash when it prints build settings.
const XCODE_ESCAPED_CHARACTERS = /[\t !"#$&'()*;<=>?[\\\]^`{|}~]/g;
/**
* Masks secrets in a text file's contents, line by line, including secrets written the way Xcode
* prints build settings. Masking works on bytes, so everything else stays unchanged.
*/
export function createTextMaskingStream(secretPatterns: ReadonlySet<string>): Transform {
const patterns = [
...new Set(
[...secretPatterns].flatMap(secret => [
secret,
secret.replace(XCODE_ESCAPED_CHARACTERS, '\\$&'),
])
),
].map(pattern => Buffer.from(pattern).toString('latin1'));
const maskLine = (line: string): string =>
patterns.some(pattern => line.includes(pattern)) ? maskSecrets(line, patterns) : line;
let partialLine = '';
return new Transform({
transform(chunk: Buffer, _encoding: BufferEncoding, callback: TransformCallback) {
const lines = (partialLine + chunk.toString('latin1')).split('\n');
partialLine = lines.pop() ?? '';
callback(
null,
lines.length > 0 ? Buffer.from(`${lines.map(maskLine).join('\n')}\n`, 'latin1') : undefined
);
},
flush(callback: TransformCallback) {
callback(null, partialLine ? Buffer.from(maskLine(partialLine), 'latin1') : undefined);
},
});
}
@@ -101,6 +150,48 @@ function maskSecrets(message: string, secrets: Iterable<string>): string {
return characters.join('');
}
function maskSecretsInValue(value: unknown, secrets: ReadonlySet<string>): unknown {
if (value === null || typeof value !== 'object') {
return maskSecretsInJsonValue(value, secrets, 0);
}
// Mask what the upload streams will serialize, so a toJSON method can't bring back the original.
let json: unknown;
try {
json = JSON.parse(JSON.stringify(value));
} catch {
return '[Unserializable]';
}
return maskSecretsInJsonValue(json, secrets, 0);
}
function maskSecretsInJsonValue(
value: unknown,
secrets: ReadonlySet<string>,
depth: number
): unknown {
if (typeof value === 'string') {
return maskSecrets(value, secrets);
}
if (typeof value === 'number') {
return secrets.has(String(value)) ? maskSecrets(String(value), secrets) : value;
}
if (value === null || typeof value !== 'object') {
return value;
}
if (depth >= MAX_MASKED_DEPTH) {
return '[Truncated]';
}
if (Array.isArray(value)) {
return value.map(item => maskSecretsInJsonValue(item, secrets, depth + 1));
}
return Object.fromEntries(
Object.entries(value).map(([key, item]) => [
maskSecrets(key, secrets),
maskSecretsInJsonValue(item, secrets, depth + 1),
])
);
}
function createDiscardStream(): Writable {
return new Writable({
objectMode: true,
@@ -113,6 +204,7 @@ function createDiscardStream(): Writable {
export async function createBuildLoggerWithSecretsFilter(secrets: Job['secrets']): Promise<{
logger: bunyan;
addBuildLogMask: (secret: string) => void;
createLogMaskingStream: () => Transform;
cleanUp: () => Promise<void>;
logBuffer: WorkerLogBuffer;
outputStream: Readable;
@@ -182,6 +274,8 @@ export async function createBuildLoggerWithSecretsFilter(secrets: Job['secrets']
return {
logger: buildLogger,
addBuildLogMask,
// Reads the masks when the stream is created, so it includes masks added during the job.
createLogMaskingStream: () => createTextMaskingStream(secretPatterns),
cleanUp: async () => {
await Promise.all([remoteLoggerStream?.cleanUp?.(), httpLogStream?.cleanUp?.()]);
},
+2
View File
@@ -275,6 +275,7 @@ export default class BuildService {
const {
logger: buildLogger,
addBuildLogMask,
createLogMaskingStream,
cleanUp,
logBuffer,
} = await createBuildLoggerWithSecretsFilter(job.secrets ?? {});
@@ -315,6 +316,7 @@ export default class BuildService {
buildId: this.buildId,
buildLogger,
addBuildLogMask,
createLogMaskingStream,
});
this.buildContext = ctx;