feat(profiling): generate chrome compatible timeline data (#5686)

Author: rigor789

lib/bootstrap.ts

@@ -155,6 +155,10 @@ injector.require(
 	"./services/android-device-debug-service"
 );
 
+injector.require(
+	"timelineProfilerService",
+	"./services/timeline-profiler-service"
+);
 injector.require("userSettingsService", "./services/user-settings-service");
 injector.requirePublic(
 	"analyticsSettingsService",

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

@@ -6,11 +6,14 @@ import * as chalk from "chalk";
 import { LoggerConfigData } from "../../constants";
 import { IOptions } from "../../declarations";
 
+import { ITimelineProfilerService } from "../../services/timeline-profiler-service";
+
 export class DeviceLogProvider extends DeviceLogProviderBase {
 	constructor(
 		protected $logFilter: Mobile.ILogFilter,
 		protected $logger: ILogger,
 		protected $logSourceMapService: Mobile.ILogSourceMapService,
+		protected $timelineProfilerService: ITimelineProfilerService,
 		protected $options: IOptions
 	) {
 		super($logFilter, $logger, $logSourceMapService);
@@ -29,7 +32,9 @@ export class DeviceLogProvider extends DeviceLogProviderBase {
 			data,
 			loggingOptions
 		);
+
 		if (data) {
+			this.$timelineProfilerService.processLogData(data, deviceIdentifier);
 			this.logDataCore(data, deviceIdentifier);
 			this.emit(DEVICE_LOG_EVENT_NAME, lineText, deviceIdentifier, platform);
 		}

lib/common/test/unit-tests/mobile/device-log-provider.ts

@@ -76,6 +76,10 @@ const createTestInjector = (): IInjector => {
 		},
 	});
 
+	testInjector.register("timelineProfilerService", {
+		processLogData() {},
+	});
+
 	const logger = testInjector.resolve<CommonLoggerStub>("logger");
 	logger.info = (...args: any[]): void => {
 		args = args.filter((arg) => Object.keys(arg).indexOf("skipNewLine") === -1);

lib/nativescript-cli.ts

@@ -22,7 +22,7 @@ installUncaughtExceptionListener(
 );
 
 const logger: ILogger = injector.resolve("logger");
-const originalProcessOn = process.on;
+export const originalProcessOn = process.on.bind(process);
 
 process.on = (event: string, listener: any): any => {
 	if (event === "SIGINT") {
@@ -33,7 +33,7 @@ process.on = (event: string, listener: any): any => {
 		const stackTrace = new Error(msg).stack || "";
 		logger.trace(stackTrace.replace(`Error: ${msg}`, msg));
 	} else {
-		return originalProcessOn.apply(process, [event, listener]);
+		return originalProcessOn(event, listener);
 	}
 };
 

lib/services/timeline-profiler-service.ts

@@ -0,0 +1,122 @@
+import { IFileSystem } from "../common/declarations";
+import { cache } from "../common/decorators";
+import { injector } from "../common/yok";
+import { IProjectConfigService } from "../definitions/project";
+import * as path from "path";
+import { originalProcessOn } from "../nativescript-cli";
+
+export interface ITimelineProfilerService {
+	processLogData(data: string, deviceIdentifier: string): void;
+}
+
+const TIMELINE_LOG_RE = /Timeline:\s*(\d*.?\d*ms:\s*)?([^\:]*\:)?(.*)\((\d*.?\d*)ms\.?\s*-\s*(\d*.\d*)ms\.?\)/;
+
+enum ChromeTraceEventPhase {
+	BEGIN = "B",
+	END = "E",
+	INSTANT = "i",
+	COMPLETE = "X",
+}
+
+interface ChromeTraceEvent {
+	ts: number;
+	pid: number;
+	tid: number;
+	/** event phase */
+	ph?: ChromeTraceEventPhase | string;
+	[otherData: string]: any;
+}
+
+interface DeviceTimeline {
+	startPoint: number;
+	timeline: ChromeTraceEvent[];
+}
+
+export class TimelineProfilerService implements ITimelineProfilerService {
+	private timelines: Map<string, DeviceTimeline> = new Map();
+	private attachedExitHandler: boolean = false;
+	constructor(
+		private $projectConfigService: IProjectConfigService,
+		private $fs: IFileSystem,
+		private $logger: ILogger
+	) {}
+
+	private attachExitHanlder() {
+		if (!this.attachedExitHandler) {
+			this.$logger.info('attached "SIGINT" handler to write timeline data.');
+			originalProcessOn("SIGINT", this.writeTimelines.bind(this));
+			this.attachedExitHandler = true;
+		}
+	}
+
+	public processLogData(data: string, deviceIdentifier: string) {
+		if (!this.isEnabled()) {
+			return;
+		}
+		this.attachExitHanlder();
+
+		if (!this.timelines.has(deviceIdentifier)) {
+			this.timelines.set(deviceIdentifier, {
+				startPoint: null,
+				timeline: [],
+			});
+		}
+
+		const deviceTimeline = this.timelines.get(deviceIdentifier);
+
+		data.split("\n").forEach((line) => {
+			const trace = this.toTrace(line.trim());
+			if (trace) {
+				deviceTimeline.startPoint ??= trace.from;
+				deviceTimeline.timeline.push(trace);
+			}
+		});
+	}
+
+	@cache()
+	private isEnabled() {
+		return this.$projectConfigService.getValue("profiling") === "timeline";
+	}
+
+	private toTrace(text: string): ChromeTraceEvent | undefined {
+		const result = text.match(TIMELINE_LOG_RE);
+		if (!result) {
+			return;
+		}
+
+		const trace = {
+			domain: result[2]?.trim().replace(":", ""),
+			name: result[3].trim(),
+			from: parseFloat(result[4]),
+			to: parseFloat(result[5]),
+		};
+
+		return {
+			pid: 1,
+			tid: 1,
+			ts: trace.from * 1000,
+			dur: (trace.to - trace.from) * 1000,
+			name: trace.name,
+			cat: trace.domain ?? "default",
+			ph: ChromeTraceEventPhase.COMPLETE,
+		};
+	}
+
+	private writeTimelines() {
+		this.$logger.info("\n\nWriting timeline data to json...");
+		this.timelines.forEach((deviceTimeline, deviceIdentifier) => {
+			const deviceTimelineFileName = `timeline-${deviceIdentifier}.json`;
+			this.$fs.writeJson(
+				path.resolve(process.cwd(), deviceTimelineFileName),
+				deviceTimeline.timeline
+			);
+			this.$logger.info(
+				`Timeline data for device ${deviceIdentifier} written to ${deviceTimelineFileName}`
+			);
+		});
+
+		process.exit();
+	}
+}
+
+injector.register("timelineProfilerService", TimelineProfilerService);

test/ios-project-service.ts

@@ -129,6 +129,7 @@ function createTestInjector(
 	testInjector.register("messages", Messages);
 	testInjector.register("mobileHelper", MobileHelper);
 	testInjector.register("deviceLogProvider", DeviceLogProvider);
+	testInjector.register("timelineProfilerService", {});
 	testInjector.register("logFilter", LogFilter);
 	testInjector.register("loggingLevels", LoggingLevels);
 	testInjector.register("utils", Utils);