feat(ios): structured app logs that follow relaunches

Devices stream com.apple.os_trace_relay and simulators use log stream, both selected by executable name, so logs survive closing and reopening the app. --log picks the scope: JS output by default, the app's native logs without debug entries with debug, everything with trace or all. Without a new enough ios-device-lib, devices fall back to the syslog relay.

Debug builds ask the runtime for chunk markers through logChunkMarkers in the app's package.json, and the CLI stitches split messages back together per process and thread.

Author: rigor789

docs/man_pages/project/testing/run-ios.md

@@ -33,6 +33,7 @@ Start an emulator with specified device identifier and sdk | `$ ns run ios [--de
 * `--emulator` - If set, runs the app in all available and configured ios simulators. It will start a simulator if none are already running.
 * `--sdk` - Specifies the target simulator's sdk.
 * `--justlaunch` - If set, does not print the application output in the console.
+* `--log <Level>` - Also controls how much of the application output is printed. By default only its JavaScript output is shown. `debug` adds everything else the app logs - its native code and the system frameworks it uses, like Xcode's console - and `trace` adds debug level entries as well.
 * `--clean` - If set, forces the complete rebuild of the native application.
 * `--no-watch` - If set, changes in your code will not be reflected during the execution of this command.
 * `--release` - If set, produces a release build by running webpack in production mode and native build in release mode. Otherwise, produces a debug build.

lib/common/constants.ts

@@ -62,9 +62,12 @@ export class EmulatorDiscoveryNames {
 }
 
 export const DEVICE_LOG_EVENT_NAME = "deviceLogData";
+export const DEVICE_LOG_ENTRY_EVENT_NAME = "deviceLogEntry";
 export const IOS_LOG_PREDICATE = 'senderImagePath contains "NativeScript"';
-export const IOS_APP_CRASH_LOG_REG_EXP = /Fatal JavaScript exception \- application has been terminated/;
-export const FAIL_LIVESYNC_LOG_REGEX = /Failed to refresh the application with RefreshRequest./;
+export const IOS_APP_CRASH_LOG_REG_EXP =
+	/Fatal JavaScript exception \- application has been terminated/;
+export const FAIL_LIVESYNC_LOG_REGEX =
+	/Failed to refresh the application with RefreshRequest./;
 
 export const TARGET_FRAMEWORK_IDENTIFIERS = {
 	Cordova: "Cordova",

lib/common/definitions/mobile.d.ts

@@ -154,6 +154,27 @@ declare global {
 		/**
 		 * Describes log stream options
 		 */
+		/**
+		 * A structured unified logging (os_log) entry.
+		 */
+		interface IiOSLogEntry {
+			/**
+			 * Together with the thread, tells apart messages logged at the same time.
+			 */
+			pid?: number;
+			thread?: number;
+			/**
+			 * Path of the executable of the process that logged the entry.
+			 */
+			process: string;
+			/**
+			 * Path of the binary (executable, framework or library) that logged the entry.
+			 */
+			image: string;
+			level: string;
+			message: string;
+		}
+
 		interface IiOSLogStreamOptions {
 			/**
 			 * This is the --predicate option which will be passed to `log stream` command
@@ -213,6 +234,21 @@ declare global {
 			 */
 			logData(line: string, platform: string, deviceIdentifier: string): void;
 
+			/**
+			 * Logs a structured iOS log entry, when it belongs to the application
+			 * whose logs are shown on the device.
+			 */
+			logEntry(
+				entry: IiOSLogEntry,
+				platform: string,
+				deviceIdentifier: string,
+			): void;
+
+			/**
+			 * Returns the project name set for the device, if any.
+			 */
+			getProjectNameForDevice(deviceIdentifier: string): string;
+
 			/**
 			 * Sets the level of logging that will be used.
 			 * @param {string} level The level of logs - could be INFO or FULL.
@@ -1331,6 +1367,15 @@ declare global {
 
 		startDeviceLog(deviceIdentifier: string): void;
 
+		/**
+		 * Streams structured logs of the process with the given executable name.
+		 * Returns false when the installed ios-device-lib cannot stream them.
+		 */
+		startDeviceLogStream(
+			deviceIdentifier: string,
+			processName: string,
+		): boolean;
+
 		apps(
 			deviceIdentifiers: string[],
 			errorHandler?: DeviceOperationErrorHandler,

lib/common/mobile/device-log-emitter.ts

@@ -2,34 +2,71 @@ import { DeviceLogProviderBase } from "./device-log-provider-base";
 import { DEVICE_LOG_EVENT_NAME } from "../constants";
 import { injector } from "../yok";
 import * as _ from "lodash";
+import { getIOSLogEntryText, getIOSLogScope } from "./ios/ios-log-entry";
 
 export class DeviceLogEmitter extends DeviceLogProviderBase {
 	constructor(
 		protected $logFilter: Mobile.ILogFilter,
 		$logger: ILogger,
 		private $loggingLevels: Mobile.ILoggingLevels,
-		protected $logSourceMapService: Mobile.ILogSourceMapService
+		protected $logSourceMapService: Mobile.ILogSourceMapService,
 	) {
 		super($logFilter, $logger, $logSourceMapService);
 	}
 
 	public logData(
 		line: string,
 		platform: string,
-		deviceIdentifier: string
+		deviceIdentifier: string,
 	): void {
 		this.setDefaultLogLevelForDevice(deviceIdentifier);
 
 		const loggingOptions = this.getDeviceLogOptionsForDevice(
-			deviceIdentifier
+			deviceIdentifier,
 		) || { logLevel: this.$loggingLevels.info, projectDir: null };
 		let data = this.$logFilter.filterData(platform, line, loggingOptions);
 		data = this.$logSourceMapService.replaceWithOriginalFileLocations(
 			platform,
 			data,
-			loggingOptions
+			loggingOptions,
 		);
 
+		this.emitData(data, platform, deviceIdentifier);
+	}
+
+	public logEntry(
+		entry: Mobile.IiOSLogEntry,
+		platform: string,
+		deviceIdentifier: string,
+	): void {
+		const loggingOptions = this.getDeviceLogOptionsForDevice(deviceIdentifier);
+		const text = getIOSLogEntryText(entry, {
+			processName: loggingOptions && loggingOptions.projectName,
+			...getIOSLogScope(
+				this.$logger.getLevel(),
+				loggingOptions?.logLevel?.toUpperCase() === this.$loggingLevels.full,
+			),
+		});
+		if (text) {
+			this.stitchIOSLogEntry(entry, text, deviceIdentifier, (message) =>
+				this.emitData(
+					this.$logSourceMapService.replaceWithOriginalFileLocations(
+						platform,
+						message + "\n",
+						loggingOptions,
+					),
+					platform,
+					deviceIdentifier,
+				),
+			);
+		}
+	}
+
+	private emitData(
+		data: string,
+		platform: string,
+		deviceIdentifier: string,
+	): void {
 		if (data) {
 			this.emit("data", deviceIdentifier, data);
 			this.emit(DEVICE_LOG_EVENT_NAME, data, deviceIdentifier, platform);
@@ -42,17 +79,16 @@ export class DeviceLogEmitter extends DeviceLogProviderBase {
 				deviceIdentifier,
 				(deviceLogOptions: Mobile.IDeviceLogOptions) =>
 					deviceLogOptions.logLevel,
-				logLevel.toUpperCase()
+				logLevel.toUpperCase(),
 			);
 		} else {
 			this.$logFilter.loggingLevel = logLevel.toUpperCase();
 
 			_.keys(this.devicesLogOptions).forEach((deviceId) => {
 				this.devicesLogOptions[deviceId] =
 					this.devicesLogOptions[deviceId] || <Mobile.IDeviceLogOptions>{};
-				this.devicesLogOptions[
-					deviceId
-				].logLevel = this.$logFilter.loggingLevel;
+				this.devicesLogOptions[deviceId].logLevel =
+					this.$logFilter.loggingLevel;
 			});
 		}
 	}

lib/common/mobile/device-log-provider-base.ts

@@ -1,27 +1,29 @@
 import { EventEmitter } from "events";
 import { getPropertyName } from "../helpers";
 import { IDictionary } from "../declarations";
+import { IOSLogChunkStitcher, isIOSRuntimeLogEntry } from "./ios/ios-log-entry";
 
 export abstract class DeviceLogProviderBase
 	extends EventEmitter
 	implements Mobile.IDeviceLogProvider
 {
 	protected devicesLogOptions: IDictionary<Mobile.IDeviceLogOptions> = {};
+	private iOSLogChunkStitcher = new IOSLogChunkStitcher();
 
 	constructor(
 		protected $logFilter: Mobile.ILogFilter,
 		protected $logger: ILogger,
-		protected $logSourceMapService: Mobile.ILogSourceMapService
+		protected $logSourceMapService: Mobile.ILogSourceMapService,
 	) {
 		super();
 	}
 
 	public async setSourceFileLocation(
-		pathToOriginalFile: string
+		pathToOriginalFile: string,
 	): Promise<void> {
 		try {
 			await this.$logSourceMapService.setSourceMapConsumerForFile(
-				pathToOriginalFile
+				pathToOriginalFile,
 			);
 		} catch (err) {
 			this.$logger.trace("Error while trying to set source map file", err);
@@ -31,23 +33,47 @@ export abstract class DeviceLogProviderBase
 	public abstract logData(
 		lineText: string,
 		platform: string,
-		deviceIdentifier: string
+		deviceIdentifier: string,
+	): void;
+
+	public abstract logEntry(
+		entry: Mobile.IiOSLogEntry,
+		platform: string,
+		deviceIdentifier: string,
 	): void;
 
 	public abstract setLogLevel(
 		logLevel: string,
-		deviceIdentifier?: string
+		deviceIdentifier?: string,
 	): void;
 
+	protected stitchIOSLogEntry(
+		entry: Mobile.IiOSLogEntry,
+		text: string,
+		deviceIdentifier: string,
+		emit: (text: string) => void,
+	): void {
+		if (!isIOSRuntimeLogEntry(entry)) {
+			emit(text);
+			return;
+		}
+
+		this.iOSLogChunkStitcher.add(
+			`${deviceIdentifier}:${entry.pid}:${entry.thread}`,
+			text,
+			emit,
+		);
+	}
+
 	public setApplicationPidForDevice(
 		deviceIdentifier: string,
-		pid: string
+		pid: string,
 	): void {
 		this.setDeviceLogOptionsProperty(
 			deviceIdentifier,
 			(deviceLogOptions: Mobile.IDeviceLogOptions) =>
 				deviceLogOptions.applicationPid,
-			pid
+			pid,
 		);
 	}
 
@@ -56,31 +82,31 @@ export abstract class DeviceLogProviderBase
 			deviceIdentifier,
 			(deviceLogOptions: Mobile.IDeviceLogOptions) =>
 				deviceLogOptions.applicationId,
-			appId
+			appId,
 		);
 	}
 
 	public setProjectNameForDevice(
 		deviceIdentifier: string,
-		projectName: string
+		projectName: string,
 	): void {
 		this.setDeviceLogOptionsProperty(
 			deviceIdentifier,
 			(deviceLogOptions: Mobile.IDeviceLogOptions) =>
 				deviceLogOptions.projectName,
-			projectName
+			projectName,
 		);
 	}
 
 	public setProjectDirForDevice(
 		deviceIdentifier: string,
-		projectDir: string
+		projectDir: string,
 	): void {
 		this.setDeviceLogOptionsProperty(
 			deviceIdentifier,
 			(deviceLogOptions: Mobile.IDeviceLogOptions) =>
 				deviceLogOptions.projectDir,
-			projectDir
+			projectDir,
 		);
 	}
 
@@ -99,6 +125,13 @@ export abstract class DeviceLogProviderBase
 		);
 	}
 
+	public getProjectNameForDevice(deviceIdentifier: string): string {
+		return (
+			this.devicesLogOptions[deviceIdentifier] &&
+			this.devicesLogOptions[deviceIdentifier].projectName
+		);
+	}
+
 	getApplicationIdForDevice(deviceIdentifier: string) {
 		return (
 			this.devicesLogOptions[deviceIdentifier] &&
@@ -107,7 +140,7 @@ export abstract class DeviceLogProviderBase
 	}
 
 	protected getDeviceLogOptionsForDevice(
-		deviceIdentifier: string
+		deviceIdentifier: string,
 	): Mobile.IDeviceLogOptions {
 		const loggingOptions = this.devicesLogOptions[deviceIdentifier];
 		if (!loggingOptions) {
@@ -120,7 +153,7 @@ export abstract class DeviceLogProviderBase
 	protected setDeviceLogOptionsProperty(
 		deviceIdentifier: string,
 		propNameFunction: Function,
-		propertyValue: string | boolean
+		propertyValue: string | boolean,
 	): void {
 		const propertyName = getPropertyName(propNameFunction);