perf(cli): Add CPU profiling support

packages/cli/bin/ui5.cjs

@@ -94,8 +94,19 @@ const ui5 = {
 	},
 
 	async invokeCLI(pkg) {
+		let profile;
+		if (process.env.UI5_CLI_PROFILE) {
+			profile = await import("../lib/utils/profile.js");
+			await profile.start();
+		}
 		const {default: cli} = await import("../lib/cli/cli.js");
-		await cli(pkg);
+		const argv = await cli(pkg);
+
+		// Stop profiling after CLI finished execution
+		// Except for "serve" command, which continues running and only stops on sigint (see profile.js)
+		if (profile && argv._[0] !== "serve") {
+			await profile.stop();
+		}
 	},
 
 	async main() {

packages/cli/lib/cli/cli.js

@@ -68,7 +68,5 @@ export default async (pkg) => {
 	// Format terminal output to full available width
 	cli.wrap(cli.terminalWidth());
 
-	// yargs registers a get method on the argv property.
-	// The property needs to be accessed to initialize everything.
-	cli.argv;
+	return cli.parse();
 };

packages/cli/lib/utils/profile.js

@@ -0,0 +1,83 @@
+/* eslint-disable no-console */
+import {writeFileSync} from "node:fs";
+import {Session} from "node:inspector/promises";
+
+let session;
+let processSignals;
+
+export async function start() {
+	if (session) {
+		return;
+	}
+	session = new Session();
+	session.connect();
+	await session.post("Profiler.enable");
+	await session.post("Profiler.start");
+	console.log(`Recording CPU profile...`);
+	processSignals = registerSigHooks();
+}
+
+async function writeProfile(profile) {
+	const formatter = new Intl.DateTimeFormat("en-GB", {
+		year: "numeric",
+		month: "2-digit",
+		day: "2-digit",
+		hour: "2-digit",
+		minute: "2-digit",
+		second: "2-digit",
+	});
+	const dateParts = Object.create(null);
+	const parts = formatter.formatToParts(new Date());
+	parts.forEach((p) => {
+		dateParts[p.type] = p.value;
+	});
+
+	const fileName = `./ui5_${dateParts.year}-${dateParts.month}-${dateParts.day}_` +
+		`${dateParts.hour}-${dateParts.minute}-${dateParts.second}.cpuprofile`;
+	console.log(`\nSaving CPU profile to ${fileName}...`);
+	writeFileSync(fileName, JSON.stringify(profile));
+}
+
+export async function stop() {
+	if (!session) {
+		return;
+	}
+	const {profile} = await session.post("Profiler.stop");
+	session = null;
+	if (profile) {
+		await writeProfile(profile);
+	}
+	if (processSignals) {
+		deregisterSigHooks(processSignals);
+		processSignals = null;
+	}
+}
+
+function registerSigHooks() {
+	function createListener(exitCode) {
+		return function() {
+			// Gracefully end profiling, then exit
+			stop().then(() => {
+				process.exit(exitCode);
+			});
+		};
+	}
+
+	const processSignals = {
+		"SIGHUP": createListener(128 + 1),
+		"SIGINT": createListener(128 + 2),
+		"SIGTERM": createListener(128 + 15),
+		"SIGBREAK": createListener(128 + 21)
+	};
+
+	for (const signal of Object.keys(processSignals)) {
+		process.on(signal, processSignals[signal]);
+	}
+	return processSignals;
+}
+
+function deregisterSigHooks(signals) {
+	for (const signal of Object.keys(signals)) {
+		process.removeListener(signal, signals[signal]);
+	}
+}

packages/cli/test/lib/cli/cli.js

@@ -11,18 +11,16 @@ test.beforeEach(async (t) => {
 		notify: t.context.updateNotifierNotify
 	}).named("updateNotifier");
 
-	t.context.argvGetter = sinon.stub();
+	t.context.yargsHideBin = sinon.stub().named("hideBin").returns([]);
+
 	t.context.yargsInstance = {
 		parserConfiguration: sinon.stub(),
 		version: sinon.stub(),
 		scriptName: sinon.stub(),
 		command: sinon.stub(),
 		terminalWidth: sinon.stub().returns(123),
 		wrap: sinon.stub(),
-		get argv() {
-			t.context.argvGetter();
-			return undefined;
-		}
+		parse: sinon.stub().resolves({_: []})
 	};
 
 	t.context.yargs = sinon.stub().returns(t.context.yargsInstance).named("yargs");
@@ -54,10 +52,9 @@ test.beforeEach(async (t) => {
 	t.context.cli = await esmock.p("../../../lib/cli/cli.js", {
 		"update-notifier": t.context.updateNotifier,
 		"yargs": t.context.yargs,
-		// TODO: Somehow esmock is unable to mock this import
-		// "yargs/helpers": {
-		// 	hideBin: t.context.yargsHideBin
-		// },
+		"yargs/helpers": {
+			hideBin: t.context.yargsHideBin
+		},
 		"../../../lib/cli/version.js": {
 			setVersion: t.context.setVersion
 		},
@@ -76,7 +73,7 @@ test.afterEach.always((t) => {
 
 test.serial("CLI", async (t) => {
 	const {
-		cli, updateNotifier, updateNotifierNotify, argvGetter, yargsInstance, yargs,
+		cli, updateNotifier, updateNotifierNotify, yargsInstance, yargs,
 		setVersion, cliBase
 	} = t.context;
 
@@ -131,8 +128,8 @@ test.serial("CLI", async (t) => {
 	t.is(yargsInstance.wrap.callCount, 1);
 	t.deepEqual(yargsInstance.wrap.getCall(0).args, [123]);
 
-	t.is(argvGetter.callCount, 1);
-	t.deepEqual(argvGetter.getCall(0).args, []);
+	t.is(yargsInstance.parse.callCount, 1);
+	t.deepEqual(yargsInstance.parse.getCall(0).args, []);
 
 	sinon.assert.callOrder(
 		updateNotifier,
@@ -146,7 +143,7 @@ test.serial("CLI", async (t) => {
 		yargsInstance.command,
 		yargsInstance.terminalWidth,
 		yargsInstance.wrap,
-		argvGetter
+		yargsInstance.parse
 	);
 });
 

packages/cli/test/lib/utils/profile.js

@@ -0,0 +1,169 @@
+import test from "ava";
+import sinon from "sinon";
+import esmock from "esmock";
+
+function createSessionStubs() {
+	const connectStub = sinon.stub();
+	const postStub = sinon.stub().callsFake(async (method) => {
+		if (method === "Profiler.stop") {
+			return {profile: {foo: "bar"}};
+		}
+		return {};
+	});
+	class Session {
+		connect() {
+			return connectStub();
+		}
+		post(method) {
+			return postStub(method);
+		}
+	}
+	return {Session, connectStub, postStub};
+}
+
+test.afterEach.always(() => {
+	sinon.restore();
+});
+
+test.serial("start() enables and starts profiler and registers signals", async (t) => {
+	const {Session, connectStub, postStub} = createSessionStubs();
+	const writeFileSyncStub = sinon.stub();
+
+	const installed = new Map();
+	const onStub = sinon.stub(process, "on").callsFake((signal, handler) => {
+		installed.set(signal, handler);
+		return process;
+	});
+	const removeListenerStub = sinon.stub(process, "removeListener");
+
+	const {start, stop} = await esmock("../../../lib/utils/profile.js", {
+		"node:inspector/promises": {Session},
+		"node:fs": {writeFileSync: writeFileSyncStub}
+	});
+
+	await start();
+
+	t.true(connectStub.calledOnce, "session.connect called once");
+	t.true(postStub.calledWith("Profiler.enable"), "Profiler.enable posted");
+	t.true(postStub.calledWith("Profiler.start"), "Profiler.start posted");
+
+	// Four signals should be registered
+	t.true(onStub.calledWith("SIGHUP"));
+	t.true(onStub.calledWith("SIGINT"));
+	t.true(onStub.calledWith("SIGTERM"));
+	t.true(onStub.calledWith("SIGBREAK"));
+
+	// Cleanup to reset internal state
+	await stop();
+
+	// stop should deregister the same handlers
+	t.true(removeListenerStub.calledWith("SIGHUP", installed.get("SIGHUP")));
+	t.true(removeListenerStub.calledWith("SIGINT", installed.get("SIGINT")));
+	t.true(removeListenerStub.calledWith("SIGTERM", installed.get("SIGTERM")));
+	t.true(removeListenerStub.calledWith("SIGBREAK", installed.get("SIGBREAK")));
+});
+
+test.serial("start() is idempotent", async (t) => {
+	const {Session, connectStub} = createSessionStubs();
+	const writeFileSyncStub = sinon.stub();
+
+	sinon.stub(process, "on").returns(process);
+	sinon.stub(process, "removeListener");
+
+	const {start, stop} = await esmock("../../../lib/utils/profile.js", {
+		"node:inspector/promises": {Session},
+		"node:fs": {writeFileSync: writeFileSyncStub}
+	});
+
+	await start();
+	await start();
+	t.true(connectStub.calledOnce, "connect should be called only once");
+
+	await stop();
+});
+
+test.serial("stop() writes profile and deregisters signals", async (t) => {
+	const {Session, postStub} = createSessionStubs();
+	const writeFileSyncStub = sinon.stub();
+
+	const installed = new Map();
+	sinon.stub(process, "on").callsFake((signal, handler) => {
+		installed.set(signal, handler);
+		return process;
+	});
+	const removeListenerStub = sinon.stub(process, "removeListener");
+
+	const {start, stop} = await esmock("../../../lib/utils/profile.js", {
+		"node:inspector/promises": {Session},
+		"node:fs": {writeFileSync: writeFileSyncStub}
+	});
+
+	await start();
+	t.true(postStub.calledWith("Profiler.start"));
+
+	await stop();
+
+	t.true(writeFileSyncStub.calledOnce, "profile written once");
+	const [fileName, content] = writeFileSyncStub.firstCall.args;
+	t.regex(fileName, /^\.\/ui5_\d{4}-\d{2}-\d{2}_\d{2}-\d{2}-\d{2}\.cpuprofile$/, "filename matches pattern");
+	t.deepEqual(JSON.parse(content), {foo: "bar"}, "written profile content matches");
+
+	t.true(removeListenerStub.calledWith("SIGHUP", installed.get("SIGHUP")));
+	t.true(removeListenerStub.calledWith("SIGINT", installed.get("SIGINT")));
+	t.true(removeListenerStub.calledWith("SIGTERM", installed.get("SIGTERM")));
+	t.true(removeListenerStub.calledWith("SIGBREAK", installed.get("SIGBREAK")));
+});
+
+test.serial("stop() without start is a no-op", async (t) => {
+	const writeFileSyncStub = sinon.stub();
+
+	const removeListenerStub = sinon.stub(process, "removeListener");
+
+	const {stop} = await esmock("../../../lib/utils/profile.js", {
+		"node:inspector/promises": {Session: class {}},
+		"node:fs": {writeFileSync: writeFileSyncStub}
+	});
+
+	await stop();
+
+	t.true(removeListenerStub.notCalled, "no signal deregistration happened");
+	t.true(writeFileSyncStub.notCalled, "no write happened");
+});
+
+test.serial("signal handler stops profiling and exits", async (t) => {
+	const {Session, postStub} = createSessionStubs();
+	const writeFileSyncStub = sinon.stub();
+
+	const installed = new Map();
+	sinon.stub(process, "on").callsFake((signal, handler) => {
+		installed.set(signal, handler);
+		return process;
+	});
+	const removeListenerStub = sinon.stub(process, "removeListener");
+	const exitStub = sinon.stub(process, "exit");
+
+	const {start} = await esmock("../../../lib/utils/profile.js", {
+		"node:inspector/promises": {Session},
+		"node:fs": {writeFileSync: writeFileSyncStub}
+	});
+
+	await start();
+
+	t.true(typeof installed.get("SIGINT") === "function", "SIGINT handler registered");
+
+	// Trigger the signal handler
+	installed.get("SIGINT")();
+
+	// Allow the Promise chain in the handler (stop().then(...)) to run
+	await new Promise((resolve) => setImmediate(resolve));
+
+	t.true(postStub.calledWith("Profiler.stop"), "Profiler.stop posted via handler");
+	t.true(writeFileSyncStub.calledOnce, "profile written by handler");
+	t.true(exitStub.calledWith(128 + 2), "process.exit called with SIGINT code");
+
+	// Signals should be deregistered during stop
+	t.true(removeListenerStub.calledWith("SIGHUP", installed.get("SIGHUP")));
+	t.true(removeListenerStub.calledWith("SIGINT", installed.get("SIGINT")));
+	t.true(removeListenerStub.calledWith("SIGTERM", installed.get("SIGTERM")));
+	t.true(removeListenerStub.calledWith("SIGBREAK", installed.get("SIGBREAK")));
+});