Merge pull request microsoft#165599 from laurentlb/telemetry

Telemetry: log command execution time

Author: jrieken

src/vs/workbench/api/common/extHostCommands.ts

@@ -224,7 +224,6 @@ export class ExtHostCommands implements ExtHostCommandsShape {
 		if (!command) {
 			throw new Error('Unknown command');
 		}
-		this._reportTelemetry(command, id);
 		const { callback, thisArg, description } = command;
 		if (description) {
 			for (let i = 0; i < description.args.length; i++) {
@@ -236,6 +235,7 @@ export class ExtHostCommands implements ExtHostCommandsShape {
 			}
 		}
 
+		const start = Date.now();
 		try {
 			return await callback.apply(thisArg, args);
 		} catch (err) {
@@ -261,25 +261,31 @@ export class ExtHostCommands implements ExtHostCommandsShape {
 				}
 			};
 		}
+		finally {
+			this._reportTelemetry(command, id, Date.now() - start);
+		}
 	}
 
-	private _reportTelemetry(command: CommandHandler, id: string) {
+	private _reportTelemetry(command: CommandHandler, id: string, duration: number) {
 		if (!command.extension || command.extension.isBuiltin) {
 			return;
 		}
 		type ExtensionActionTelemetry = {
 			extensionId: string;
 			id: string;
+			duration: number;
 		};
 		type ExtensionActionTelemetryMeta = {
 			extensionId: { classification: 'SystemMetaData'; purpose: 'FeatureInsight'; comment: 'The id of the extension handling the command, informing which extensions provide most-used functionality.' };
 			id: { classification: 'SystemMetaData'; purpose: 'FeatureInsight'; comment: 'The id of the command, to understand which specific extension features are most popular.' };
+			duration: { classification: 'SystemMetaData'; purpose: 'FeatureInsight'; isMeasurement: true; comment: 'The duration of the command execution, to detect performance issues' };
 			owner: 'digitarald';
 			comment: 'Used to gain insight on the most popular commands used from extensions';
 		};
 		this.#telemetry.$publicLog2<ExtensionActionTelemetry, ExtensionActionTelemetryMeta>('Extension:ActionExecuted', {
 			extensionId: command.extension.identifier.value,
 			id: id,
+			duration: duration,
 		});
 	}