From 077cf3244083e7c302bb1afb2ca22ec0ab751b3a Mon Sep 17 00:00:00 2001 From: Evan Bacon Date: Wed, 17 Mar 2021 13:38:21 -0700 Subject: [PATCH] Added debug simctl logger (#3293) * Added simctl logger * Update SimControlLogs.ts --- packages/xdl/src/SimControlLogs.ts | 259 +++++++++++++++++++++++++++++ packages/xdl/src/Simulator.ts | 31 +++- 2 files changed, 286 insertions(+), 4 deletions(-) create mode 100644 packages/xdl/src/SimControlLogs.ts diff --git a/packages/xdl/src/SimControlLogs.ts b/packages/xdl/src/SimControlLogs.ts new file mode 100644 index 0000000000..abc7250192 --- /dev/null +++ b/packages/xdl/src/SimControlLogs.ts @@ -0,0 +1,259 @@ +import chalk from 'chalk'; +import { ChildProcessWithoutNullStreams, spawn } from 'child_process'; +import path from 'path'; +import wrapAnsi from 'wrap-ansi'; + +import * as SimControl from './SimControl'; +import { Logger } from './xdl'; + +const forks: Record = {}; + +type SimLog = { + /** + * 258753568922927108 + */ + traceID: number; + /** + * + * "Connection 1: done", + */ + eventMessage: string; + /** + * "logEvent" | "activityCreateEvent", + */ + eventType: 'logEvent' | 'activityCreateEvent'; + source: null | { + /** + * 'RCTDefaultLogFunction_block_invoke' | '__TCC_CRASHING_DUE_TO_PRIVACY_VIOLATION__' + */ + symbol: string; + line: number; + /** + * 'TCC' | 'Security' | 'CFNetwork' | 'libnetwork.dylib' | 'myapp' + * + * TCC is apple sys, it means "Transparency, Consent, and Control" + */ + image: string; + /** + * 'RCTLog.mm' | '' + */ + file: string; + }; + /** + * "Connection %llu: done" + */ + formatString: string; + /** + * 0 + */ + activityIdentifier: number; + subsystem: + | '' + | 'com.apple.network' + | 'com.facebook.react.log' + | 'com.apple.TCC' + | 'com.apple.CoreTelephony' + | 'com.apple.WebKit' + | 'com.apple.runningboard'; + category: '' | 'access' | 'connection'; + /** + * "2021-03-15 15:36:28.004331-0700" + */ + timestamp: string; + /** + * 706567072091713 + */ + machTimestamp: number; + /** + * "Default" + */ + messageType: 'Default' | 'Error'; + /** + * 15192 + */ + processID: number; +}; + +function parseMessageJson(data: Buffer) { + const stringData = data.toString(); + try { + return JSON.parse(stringData) as SimLog; + } catch (e) { + Logger.global.debug('Failed to parse simctl JSON message:\n' + stringData); + } + return null; +} + +// There are a lot of networking logs in RN that aren't relevant to the user. +function isNetworkLog(simLog: SimLog): boolean { + return ( + simLog.subsystem === 'com.apple.network' || + simLog.category === 'connection' || + simLog.source?.image === 'CFNetwork' + ); +} + +function isReactLog(simLog: SimLog): boolean { + return simLog.subsystem === 'com.facebook.react.log' && simLog.source?.file === 'RCTLog.mm'; +} + +// It's not clear what these are but they aren't very useful. +// (The connection to service on pid 0 named com.apple.commcenter.coretelephony.xpc was invalidated) +// We can add them later if need. +function isCoreTelephonyLog(simLog: SimLog): boolean { + // [CoreTelephony] Updating selectors failed with: Error Domain=NSCocoaErrorDomain Code=4099 + // "The connection to service on pid 0 named com.apple.commcenter.coretelephony.xpc was invalidated." UserInfo={NSDebugDescription=The connection to service on pid 0 named com.apple.commcenter.coretelephony.xpc was invalidated.} + return simLog.subsystem === 'com.apple.CoreTelephony'; +} + +// https://stackoverflow.com/a/65313219/4047926 +function isWebKitLog(simLog: SimLog): boolean { + // [WebKit] 0x1143ca500 - ProcessAssertion: Failed to acquire RBS Background assertion 'WebProcess Background Assertion' for process with PID 27084, error: Error Domain=RBSAssertionErrorDomain Code=3 "Target is not running or required target + // entitlement is missing" UserInfo={RBSAssertionAttribute=, NSLocalizedFailureReason=Target is not running or required target entitlement is missing} + return simLog.subsystem === 'com.apple.WebKit'; +} + +// Similar to WebKit logs +function isRunningBoardServicesLog(simLog: SimLog): boolean { + // [RunningBoardServices] Error acquiring assertion: , NSLocalizedFailureReason=Target is not running or required target entitlement is missing}> + return simLog.subsystem === 'com.apple.runningboard'; +} + +function formatMessage(simLog: SimLog): string { + // TODO: Maybe change "TCC" to "Consent" or "System". + const category = chalk.gray(`[${simLog.source?.image ?? simLog.subsystem}]`); + const message = simLog.eventMessage; + return wrapAnsi(category + ' ' + message, process.stdout.columns || 80); +} + +// The primary purpose of this module is to surface logs related to fatal app crashes. +// Everything else should come through the native React logger. +export function streamLogs({ pid, udid }: { pid: string; udid: string }): void { + // Prevent adding a duplicate listener. + // This only works because our current usage of SimControlLogs only allows for one possible `pid` to be used. + // If in the future, you can attach logs to two different apps from the same process, then this will need to be changed. + if (forks[udid]) { + return; + } + + // xcrun simctl spawn booted log stream --process --style json + const childProcess = spawn('xcrun', [ + 'simctl', + 'spawn', + udid, + 'log', + 'stream', + '--process', + pid, + // ndjson provides a better format than json. + '--style', + 'ndjson', + // Provide the source so we can filter logs better + '--source', + // log, activity, trace -- activity was related to layouts, trace didn't work, so that leaves log. + // Passing nothing combines all three, but we don't use activity. + '--type', + 'log', + // backtrace doesn't seem very useful in basic cases. + // TODO: Maybe we can format as a stack trace for native errors. + '--no-backtrace', + ]); + + childProcess.stdout.on('data', (data: Buffer) => { + const simLog = parseMessageJson(data); + if (!simLog) { + return; + } + + let hasLogged = false; + + if (simLog.messageType === 'Error') { + if ( + // Hide all networking errors which are mostly useless. + !isNetworkLog(simLog) && + // Showing React errors will result in duplicate messages. + !isReactLog(simLog) && + !isCoreTelephonyLog(simLog) && + !isWebKitLog(simLog) && + !isRunningBoardServicesLog(simLog) + ) { + hasLogged = true; + // Sim: This app has crashed because it attempted to access privacy-sensitive data without a usage description. The app's Info.plist must contain an NSCameraUsageDescription key with a string value explaining to the user how the app uses this data. + Logger.global.error(formatMessage(simLog)); + } + } else { + // If the source has a file (i.e. not a system log). + if (simLog.source?.file) { + hasLogged = true; + Logger.global.info(formatMessage(simLog)); + } + } + + if (!hasLogged) { + Logger.global.debug(formatMessage(simLog)); + } else { + // console.log('DATA:', simLog); + } + }); + + childProcess.on('error', ({ message }) => { + Logger.global.debug('[simctl error]:', message); + }); + + forks[udid] = childProcess; + // Ensure the process is removed. + ensureExitHooksInstalled(); +} + +export async function detachStream(udid: string) { + if (forks[udid]) { + await killProcess(forks[udid]); + delete forks[udid]; + } +} + +let hasInstalledExitHooks = false; + +function ensureExitHooksInstalled(): void { + if (hasInstalledExitHooks) return; + hasInstalledExitHooks = true; + + const killSignals: ['SIGINT', 'SIGTERM'] = ['SIGINT', 'SIGTERM']; + for (const signal of killSignals) { + process.on(signal, async () => { + await Promise.all(Object.keys(forks).map(udid => detachStream(udid))); + }); + } +} + +async function killProcess(childProcess: ChildProcessWithoutNullStreams): Promise { + if (childProcess) { + return new Promise(resolve => { + childProcess.on('close', resolve); + childProcess.kill(); + }); + } +} + +/** + * + * @param udid + * @param bundleIdentifier + * @returns Image name like `Exponent` and `null` when the app is not installed on the provided simulator. + */ +export async function getImageNameFromBundleIdentifierAsync( + udid: string, + bundleIdentifier: string +): Promise { + const containerPath = await SimControl.getContainerPathAsync(udid, bundleIdentifier); + + if (containerPath) { + return getImageNameFromContainerPath(containerPath); + } + return null; +} + +export function getImageNameFromContainerPath(binaryPath: string): string { + return path.basename(binaryPath).split('.')[0]; +} diff --git a/packages/xdl/src/Simulator.ts b/packages/xdl/src/Simulator.ts index 794e9b60f2..33f00fa8c0 100644 --- a/packages/xdl/src/Simulator.ts +++ b/packages/xdl/src/Simulator.ts @@ -15,6 +15,7 @@ import Logger from './Logger'; import NotificationCode from './NotificationCode'; import * as Prompts from './Prompts'; import * as SimControl from './SimControl'; +import * as SimControlLogs from './SimControlLogs'; import * as UrlUtils from './UrlUtils'; import UserSettings from './UserSettings'; import * as Versions from './Versions'; @@ -551,7 +552,7 @@ async function openUrlInSimulatorSafeAsync({ devClient?: boolean; exp?: ExpoConfig; projectRoot: string; -}): Promise<{ success: true } | { success: false; msg: string }> { +}): Promise<{ success: true; bundleIdentifier: string } | { success: false; msg: string }> { if (!(await isSimulatorInstalledAsync())) { return { success: false, @@ -569,9 +570,10 @@ async function openUrlInSimulatorSafeAsync({ }; } + let bundleIdentifier = 'host.exp.Exponent'; try { if (devClient) { - const bundleIdentifier = await configureBundleIdentifierAsync(projectRoot, exp); + bundleIdentifier = await configureBundleIdentifierAsync(projectRoot, exp); await assertDevClientInstalledAsync(simulator, bundleIdentifier); } else if (!isDetached) { await ensureExpoClientInstalledAsync(simulator, sdkVersion); @@ -611,6 +613,7 @@ async function openUrlInSimulatorSafeAsync({ return { success: true, + bundleIdentifier, }; } @@ -689,7 +692,10 @@ export async function openProjectAsync({ projectRoot: string; shouldPrompt?: boolean; devClient?: boolean; -}): Promise<{ success: true; url: string } | { success: false; error: string }> { +}): Promise< + | { success: true; url: string; udid: string; bundleIdentifier: string } + | { success: false; error: string } +> { const projectUrl = await UrlUtils.constructDeepLinkAsync(projectRoot, { hostType: 'localhost', }); @@ -720,8 +726,25 @@ export async function openProjectAsync({ }); if (result.success) { + if (devClient) { + const imageName = await SimControlLogs.getImageNameFromBundleIdentifierAsync( + device.udid, + result.bundleIdentifier + ); + if (imageName) { + // Attach simulator log observer + SimControlLogs.streamLogs({ pid: imageName, udid: device.udid }); + } + } + await activateSimulatorWindowAsync(); - return { success: true, url: projectUrl }; + + return { + success: true, + url: projectUrl, + udid: device.udid, + bundleIdentifier: result.bundleIdentifier, + }; } return { success: result.success, error: result.msg }; }