Merge pull request #3515 from github/koesie10/tee-logger-file-handle

Use file handle in TeeLogger

Author: koesie10

extensions/ql-vscode/src/common/logging/tee-logger.ts

@@ -1,7 +1,10 @@
-import { appendFile, ensureFile } from "fs-extra";
+import { ensureFile } from "fs-extra";
+import { open } from "node:fs/promises";
+import type { FileHandle } from "node:fs/promises";
 import { isAbsolute } from "path";
 import { getErrorMessage } from "../helpers-pure";
 import type { Logger, LogOptions } from "./logger";
+import type { Disposable } from "../disposable-object";
 
 /**
  * An implementation of {@link Logger} that sends the output both to another {@link Logger}
@@ -10,9 +13,10 @@ import type { Logger, LogOptions } from "./logger";
  * The first time a message is written, an additional banner is written to the underlying logger
  * pointing the user to the "side log" file.
  */
-export class TeeLogger implements Logger {
+export class TeeLogger implements Logger, Disposable {
   private emittedRedirectMessage = false;
   private error = false;
+  private fileHandle: FileHandle | undefined = undefined;
 
   public constructor(
     private readonly logger: Logger,
@@ -37,11 +41,15 @@ export class TeeLogger implements Logger {
 
     if (!this.error) {
       try {
+        if (!this.fileHandle) {
+          await ensureFile(this.location);
+
+          this.fileHandle = await open(this.location, "a");
+        }
+
         const trailingNewline = options.trailingNewline ?? true;
-        await ensureFile(this.location);
 
-        await appendFile(
-          this.location,
+        await this.fileHandle.appendFile(
           message + (trailingNewline ? "\n" : ""),
           {
             encoding: "utf8",
@@ -50,6 +58,14 @@ export class TeeLogger implements Logger {
       } catch (e) {
         // Write an error message to the primary log, and stop trying to write to the side log.
         this.error = true;
+        try {
+          await this.fileHandle?.close();
+        } catch (e) {
+          void this.logger.log(
+            `Failed to close file handle: ${getErrorMessage(e)}`,
+          );
+        }
+        this.fileHandle = undefined;
         const errorMessage = getErrorMessage(e);
         await this.logger.log(
           `Error writing to additional log file: ${errorMessage}`,
@@ -65,4 +81,15 @@ export class TeeLogger implements Logger {
   show(preserveFocus?: boolean): void {
     this.logger.show(preserveFocus);
   }
+
+  dispose(): void {
+    try {
+      void this.fileHandle?.close();
+    } catch (e) {
+      void this.logger.log(
+        `Failed to close file handle: ${getErrorMessage(e)}`,
+      );
+    }
+    this.fileHandle = undefined;
+  }
 }

extensions/ql-vscode/src/language-support/contextual/query-resolver.ts

@@ -92,11 +92,12 @@ export async function runContextualQuery(
   void extLogger.log(
     `Running contextual query ${query}; results will be stored in ${queryRun.outputDir.querySaveDir}`,
   );
-  const results = await queryRun.evaluate(
-    progress,
-    token,
-    new TeeLogger(qs.logger, queryRun.outputDir.logPath),
-  );
-  await cleanup?.();
-  return results;
+  const teeLogger = new TeeLogger(qs.logger, queryRun.outputDir.logPath);
+
+  try {
+    return await queryRun.evaluate(progress, token, teeLogger);
+  } finally {
+    await cleanup?.();
+    teeLogger.dispose();
+  }
 }

extensions/ql-vscode/src/local-queries/local-query-run.ts

@@ -25,6 +25,7 @@ import { redactableError } from "../common/errors";
 import type { LocalQueries } from "./local-queries";
 import { tryGetQueryMetadata } from "../codeql-cli/query-metadata";
 import { telemetryListener } from "../common/vscode/telemetry";
+import type { Disposable } from "../common/disposable-object";
 
 function formatResultMessage(result: CoreQueryResults): string {
   switch (result.resultType) {
@@ -61,7 +62,11 @@ export class LocalQueryRun {
     private readonly localQueries: LocalQueries,
     private readonly queryInfo: LocalQueryInfo,
     private readonly dbItem: DatabaseItem,
-    public readonly logger: Logger, // Public so that other clients, like the debug adapter, know where to send log output
+    /**
+     * The logger is only available while the query is running and will be disposed of when the
+     * query completes.
+     */
+    public readonly logger: Logger & Disposable, // Public so that other clients, like the debug adapter, know where to send log output
     private readonly queryHistoryManager: QueryHistoryManager,
     private readonly cliServer: CodeQLCliServer,
   ) {}
@@ -92,6 +97,8 @@ export class LocalQueryRun {
     // Note we must update the query history view after showing results as the
     // display and sorting might depend on the number of results
     await this.queryHistoryManager.refreshTreeView();
+
+    this.logger.dispose();
   }
 
   /**
@@ -110,6 +117,8 @@ export class LocalQueryRun {
     err.message = `Error running query: ${err.message}`;
     this.queryInfo.failureReason = err.message;
     await this.queryHistoryManager.refreshTreeView();
+
+    this.logger.dispose();
   }
 
   /**

extensions/ql-vscode/src/local-queries/run-query.ts

@@ -47,21 +47,27 @@ export async function runQuery({
     undefined,
   );
 
-  const completedQuery = await queryRun.evaluate(
-    progress,
-    token,
-    new TeeLogger(queryRunner.logger, queryRun.outputDir.logPath),
+  const teeLogger = new TeeLogger(
+    queryRunner.logger,
+    queryRun.outputDir.logPath,
   );
 
-  if (completedQuery.resultType !== QueryResultType.SUCCESS) {
-    void showAndLogExceptionWithTelemetry(
-      extLogger,
-      telemetryListener,
-      redactableError`Failed to run ${basename(queryPath)} query: ${
-        completedQuery.message ?? "No message"
-      }`,
-    );
-    return;
+  try {
+    const completedQuery = await queryRun.evaluate(progress, token, teeLogger);
+
+    if (completedQuery.resultType !== QueryResultType.SUCCESS) {
+      void showAndLogExceptionWithTelemetry(
+        extLogger,
+        telemetryListener,
+        redactableError`Failed to run ${basename(queryPath)} query: ${
+          completedQuery.message ?? "No message"
+        }`,
+      );
+      return;
+    }
+
+    return completedQuery;
+  } finally {
+    teeLogger.dispose();
   }
-  return completedQuery;
 }

extensions/ql-vscode/test/common/logging/output-channel-logger.test.ts

@@ -5,6 +5,7 @@ import { dirSync } from "tmp";
 import type { BaseLogger, Logger } from "../../../src/common/logging";
 import { TeeLogger } from "../../../src/common/logging";
 import { OutputChannelLogger } from "../../../src/common/logging/vscode";
+import type { Disposable } from "../../../src/common/disposable-object";
 
 jest.setTimeout(999999);
 
@@ -66,6 +67,8 @@ describe("OutputChannelLogger tests", function () {
 
     // should have created 1 side log
     expect(readdirSync(tempFolders.storagePath.name)).toEqual(["hucairz"]);
+
+    hucairz.dispose();
   });
 
   it("should create a side log", async () => {
@@ -86,12 +89,15 @@ describe("OutputChannelLogger tests", function () {
     expect(
       readFileSync(join(tempFolders.storagePath.name, "second"), "utf8"),
     ).toBe("yyy\n");
+
+    first.dispose();
+    second.dispose();
   });
 
   function createSideLogger(
     logger: Logger,
     additionalLogLocation: string,
-  ): BaseLogger {
+  ): BaseLogger & Disposable {
     return new TeeLogger(
       logger,
       join(tempFolders.storagePath.name, additionalLogLocation),