Create decorator that logs execution time of the method

Author: K-dizzled

.vscode/settings.json

@@ -12,12 +12,15 @@
         "**/CVS": true,
         "**/.DS_Store": true,
         "**/Thumbs.db": true,
-        "out": false,
-        "**/*_cp_aux.v": true
+        "out": false
     },
     "search.exclude": {
         "out": true // set this to false to include "out" folder in search results
     },
     // Turn off tsc task auto detection since we have the necessary tasks as npm scripts
-    "typescript.tsc.autoDetect": "off"
+    "typescript.tsc.autoDetect": "off",
+    "coq-lsp.check_only_on_request": false,
+    "eslint.options": {
+        "experimentalDecorators": true
+    }
 }

set_gitignore.sh

@@ -1,15 +1,19 @@
 import { OutputChannel, window } from "vscode";
 
+import { EventLogger } from "../logging/eventLogger";
+
 import { CoqLspClient, CoqLspClientInterface } from "./coqLspClient";
 import { CoqLspClientConfig, CoqLspConfig } from "./coqLspConfig";
 
 export async function createCoqLspClient(
     coqLspServerPath: string,
-    logOutputChannel?: OutputChannel
+    logOutputChannel?: OutputChannel,
+    eventLogger?: EventLogger
 ): Promise<CoqLspClientInterface> {
     return createAbstractCoqLspClient(
         CoqLspConfig.createClientConfig(coqLspServerPath),
-        logOutputChannel
+        logOutputChannel,
+        eventLogger
     );
 }
 
@@ -28,12 +32,14 @@ async function createAbstractCoqLspClient(
     coqLspClientConfig: CoqLspClientConfig,
     logOutputChannel: OutputChannel = window.createOutputChannel(
         "CoqPilot: coq-lsp events"
-    )
+    ),
+    eventLogger?: EventLogger
 ): Promise<CoqLspClientInterface> {
     const coqLspServerConfig = CoqLspConfig.createServerConfig();
     return await CoqLspClient.create(
         coqLspServerConfig,
         coqLspClientConfig,
-        logOutputChannel
+        logOutputChannel,
+        eventLogger
     );
 }

src/coqLsp/coqLspBuilders.ts

@@ -19,6 +19,7 @@ import {
     VersionedTextDocumentIdentifier,
 } from "vscode-languageclient";
 
+import { EventLogger } from "../logging/eventLogger";
 import { Uri } from "../utils/uri";
 
 import { CoqLspClientConfig, CoqLspServerConfig } from "./coqLspConfig";
@@ -33,6 +34,7 @@ import {
     GoalRequest,
     PpString,
 } from "./coqLspTypes";
+import { logExecutionTime } from "../logging/timeMeasureDecorator";
 
 export interface CoqLspClientInterface extends Disposable {
     getGoalsAtPoint(
@@ -66,14 +68,18 @@ export class CoqLspClient implements CoqLspClientInterface {
     private subscriptions: Disposable[] = [];
     private mutex = new Mutex();
 
-    private constructor(coqLspConnector: CoqLspConnector) {
+    private constructor(
+        coqLspConnector: CoqLspConnector,
+        public readonly eventLogger?: EventLogger
+    ) {
         this.client = coqLspConnector;
     }
 
     static async create(
         serverConfig: CoqLspServerConfig,
         clientConfig: CoqLspClientConfig,
-        logOutputChannel: OutputChannel
+        logOutputChannel: OutputChannel,
+        eventLogger?: EventLogger
     ): Promise<CoqLspClient> {
         const connector = new CoqLspConnector(
             serverConfig,
@@ -86,9 +92,10 @@ export class CoqLspClient implements CoqLspClientInterface {
                 clientConfig.coq_lsp_server_path
             );
         });
-        return new CoqLspClient(connector);
+        return new CoqLspClient(connector, eventLogger);
     }
 
+    @logExecutionTime
     async getGoalsAtPoint(
         position: Position,
         documentUri: Uri,
@@ -120,6 +127,7 @@ export class CoqLspClient implements CoqLspClientInterface {
         });
     }
 
+    @logExecutionTime
     async getFlecheDocument(uri: Uri): Promise<FlecheDocument> {
         return await this.mutex.runExclusive(async () => {
             return this.getFlecheDocumentUnsafe(uri);

src/coqLsp/coqLspClient.ts

@@ -7,7 +7,6 @@ import {
     workspace,
 } from "vscode";
 
-// import { createCoqLspClient } from "../coqLsp/coqLspBuilders";
 import { CoqLspStartupError } from "../coqLsp/coqLspTypes";
 
 import {
@@ -37,7 +36,6 @@ import {
     highlightTextInEditor,
     insertCompletion,
 } from "./documentEditor";
-import { suggestAddingAuxFilesToGitignore } from "./editGitignoreCommand";
 import {
     EditorMessages,
     showMessageToUser,
@@ -51,7 +49,6 @@ import {
     toVSCodeRange,
 } from "./positionRangeUtils";
 import { SettingsValidationError } from "./settingsValidationError";
-import { cleanAuxFiles, hideAuxFiles } from "./tmpFilesCleanup";
 
 export const pluginId = "coqpilot";
 export const pluginName = "CoqPilot";
@@ -64,9 +61,6 @@ export class CoqPilot {
         vscodeExtensionContext: ExtensionContext,
         globalExtensionState: GlobalExtensionState
     ) {
-        hideAuxFiles();
-        suggestAddingAuxFilesToGitignore();
-
         this.vscodeExtensionContext = vscodeExtensionContext;
         this.globalExtensionState = globalExtensionState;
 
@@ -332,7 +326,6 @@ export class CoqPilot {
     }
 
     dispose(): void {
-        cleanAuxFiles();
         this.globalExtensionState.dispose();
     }
 }

src/extension/coqPilot.ts

@@ -24,28 +24,34 @@ import { pluginId } from "./coqPilot";
 import VSCodeLogWriter from "./vscodeLogWriter";
 
 export class GlobalExtensionState {
-    public readonly eventLogger: EventLogger = new EventLogger();
     public readonly logWriter: VSCodeLogWriter = new VSCodeLogWriter(
         this.eventLogger,
         this.parseLoggingVerbosity(workspace.getConfiguration(pluginId))
     );
 
     private constructor(
         public readonly coqLspClient: CoqLspClientInterface,
-        public readonly logOutputChannel: OutputChannel
+        public readonly logOutputChannel: OutputChannel,
+        public readonly eventLogger: EventLogger
     ) {}
 
     static async create(): Promise<GlobalExtensionState> {
         const coqLspServerPath = parseCoqLspServerPath();
         const logOutputChannel = window.createOutputChannel(
             "CoqPilot: coq-lsp events"
         );
+        const eventLogger = new EventLogger();
         const coqLspClient = await createCoqLspClient(
             coqLspServerPath,
-            logOutputChannel
+            logOutputChannel,
+            eventLogger
         );
 
-        return new GlobalExtensionState(coqLspClient, logOutputChannel);
+        return new GlobalExtensionState(
+            coqLspClient,
+            logOutputChannel,
+            eventLogger
+        );
     }
 
     public readonly llmServicesLogsDir = path.join(

src/extension/editGitignoreCommand.ts

@@ -0,0 +1,59 @@
+import { Severity } from "./eventLogger";
+
+
+/**
+ * A decorator that logs the execution time of a method. 
+ * Execution time is logged in milliseconds with severity 
+ * `DEBUG` in the event logger. If the class does not have
+ * an event logger, the execution time is logged to the console.
+ * 
+ * (Note: typescript supports decorators only for class methods).
+ */
+export function logExecutionTime(
+    _target: any,
+    propertyKey: string,
+    descriptor: PropertyDescriptor
+) {
+    const originalMethod = descriptor.value;
+
+    descriptor.value = function (this: any, ...args: any[]) {
+        const start = performance.now();
+
+        const result = originalMethod.apply(this, args);
+
+        const logTime = (duration: number) => {
+            if (this.eventLogger) {
+                this.eventLogger.log(
+                    "function-execution-time",
+                    `${propertyKey} took ${duration.toFixed(2)}ms to execute`,
+                    undefined,
+                    Severity.DEBUG
+                );
+            } else {
+                console.log(
+                    `${propertyKey} took ${duration.toFixed(2)}ms to execute`
+                );
+            }
+        };
+
+        if (result && typeof result.then === "function") {
+            return result
+                .then((res: any) => {
+                    const duration = performance.now() - start;
+                    logTime(duration);
+                    return res;
+                })
+                .catch((err: any) => {
+                    const duration = performance.now() - start;
+                    logTime(duration);
+                    throw err;
+                });
+        } else {
+            const duration = performance.now() - start;
+            logTime(duration);
+            return result;
+        }
+    };
+
+    return descriptor;
+}