Expose per-query structured evaluator logs

Author: edoardopirovano

extensions/ql-vscode/CHANGELOG.md

@@ -15,6 +15,7 @@ No user facing changes.
 - Fix a bug where queries took a long time to run if there are no folders in the workspace. [#1157](https://github.com/github/vscode-codeql/pull/1157)
 - [BREAKING CHANGE] The `codeQL.runningQueries.customLogDirectory` setting is deprecated and no longer has any function. Instead, all query log files will be stored in the query history directory, next to the query results. [#1178](https://github.com/github/vscode-codeql/pull/1178)
 - Add a _Open query directory_ command for query items. This command opens the directory containing all artifacts for a query. [#1179](https://github.com/github/vscode-codeql/pull/1179)
+- Add options to display evaluator logs for a given query run. Some information that was previously found in the query server output may now be found here. [#1186](https://github.com/github/vscode-codeql/pull/1186)
 
 ## 1.5.11 - 10 February 2022
 

extensions/ql-vscode/package.json

@@ -522,6 +522,14 @@
         "command": "codeQLQueryHistory.openQueryDirectory",
         "title": "Open query directory"
       },
+      {
+        "command": "codeQLQueryHistory.showEvalLog",
+        "title": "Show Evaluator Log (Raw)"
+      },
+      {
+        "command": "codeQLQueryHistory.showEvalLogSummary",
+        "title": "Show Evaluator Log (Summary)"
+      },
       {
         "command": "codeQLQueryHistory.cancel",
         "title": "Cancel"
@@ -725,6 +733,16 @@
           "group": "9_qlCommands",
           "when": "view == codeQLQueryHistory && !hasRemoteServer"
         },
+        {
+          "command": "codeQLQueryHistory.showEvalLog",
+          "group": "9_qlCommands",
+          "when": "viewItem == rawResultsItem || viewItem == interpretedResultsItem || viewItem == cancelledResultsItem"
+        },
+        {
+          "command": "codeQLQueryHistory.showEvalLogSummary",
+          "group": "9_qlCommands",
+          "when": "viewItem == rawResultsItem || viewItem == interpretedResultsItem || viewItem == cancelledResultsItem"
+        },
         {
           "command": "codeQLQueryHistory.showQueryText",
           "group": "9_qlCommands",
@@ -924,6 +942,14 @@
           "command": "codeQLQueryHistory.showQueryLog",
           "when": "false"
         },
+        {
+          "command": "codeQLQueryHistory.showEvalLog",
+          "when": "false"
+        },
+        {
+          "command": "codeQLQueryHistory.showEvalLogSummary",
+          "when": "false"
+        },
         {
           "command": "codeQLQueryHistory.openQueryDirectory",
           "when": "false"

extensions/ql-vscode/src/cli.ts

@@ -665,6 +665,23 @@ export class CodeQLCliServer implements Disposable {
     return await this.runCodeQlCliCommand(['generate', 'query-help'], subcommandArgs, `Generating qhelp in markdown format at ${outputDirectory}`);
   }
 
+  /**
+  * Generate a summary of an evaluation log.
+  * @param inputPath The path of an evaluation event log.
+  * @param outputPath The path to write a human-readable summary of it to.
+  */
+   async generateLogSummary(
+    inputPath: string,
+    outputPath: string,
+  ): Promise<string> {
+    const subcommandArgs = [
+      '--format=text',
+      inputPath,
+      outputPath
+    ];
+    return await this.runCodeQlCliCommand(['generate', 'log-summary'], subcommandArgs, 'Generating log summary');
+  }
+
   /**
   * Gets the results from a bqrs.
   * @param bqrsPath The path to the bqrs.
@@ -1256,6 +1273,11 @@ export class CliVersionConstraint {
    */
   public static CLI_VERSION_WITH_STRUCTURED_EVAL_LOG = new SemVer('2.8.2');
 
+   /**
+    * CLI version that supports rotating structured logs to produce one per query.
+    */
+    public static CLI_VERSION_WITH_PER_QUERY_EVAL_LOG = new SemVer('2.8.4');
+
   constructor(private readonly cli: CodeQLCliServer) {
     /**/
   }
@@ -1315,4 +1337,8 @@ export class CliVersionConstraint {
   async supportsStructuredEvalLog() {
     return this.isVersionAtLeast(CliVersionConstraint.CLI_VERSION_WITH_STRUCTURED_EVAL_LOG);
   }
+
+  async supportsPerQueryEvalLog() {
+    return this.isVersionAtLeast(CliVersionConstraint.CLI_VERSION_WITH_PER_QUERY_EVAL_LOG);
+  }
 }

extensions/ql-vscode/src/extension.ts

@@ -535,6 +535,8 @@ async function activateWithInstalledDistribution(
           queryStorageDir,
           progress,
           source.token,
+          undefined,
+          item,
         );
         item.completeThisQuery(completedQueryInfo);
         await showResultsForCompletedQuery(item as CompletedLocalQueryInfo, WebviewReveal.NotForced);

extensions/ql-vscode/src/pure/messages.ts

@@ -646,6 +646,35 @@ export interface ClearCacheParams {
    */
   dryRun: boolean;
 }
+
+/**
+ * Parameters to start a new structured log
+ */
+ export interface StartLogParams {
+  /**
+   * The dataset for which we want to start a new structured log
+   */
+  db: Dataset;
+  /**
+   * The path where we want to place the new structured log
+   */
+  logPath: string;
+}
+
+/**
+ * Parameters to terminate a structured log
+ */
+ export interface EndLogParams {
+  /**
+   * The dataset for which we want to terminated the log
+   */
+  db: Dataset;
+  /**
+   * The path of the log to terminate, will be a no-op if we aren't logging here
+   */
+  logPath: string;
+}
+
 /**
  * Parameters for trimming the cache of a dataset
  */
@@ -682,6 +711,26 @@ export interface ClearCacheResult {
   deletionMessage: string;
 }
 
+/**
+ * The result of starting a new structured log.
+ */
+export interface StartLogResult {
+  /**
+   * A user friendly message saying what happened.
+   */
+  outcomeMessage: string;
+}
+
+/**
+ * The result of terminating a structured.
+ */
+export interface EndLogResult {
+  /**
+   * A user friendly message saying what happened.
+   */
+  outcomeMessage: string;
+}
+
 /**
  * Parameters for running a set of queries
  */
@@ -1018,6 +1067,16 @@ export const compileUpgrade = new rpc.RequestType<WithProgressId<CompileUpgradeP
  */
 export const compileUpgradeSequence = new rpc.RequestType<WithProgressId<CompileUpgradeSequenceParams>, CompileUpgradeSequenceResult, void, void>('compilation/compileUpgradeSequence');
 
+/**
+ * Start a new structured log in the evaluator, terminating the previous one if it exists
+ */
+ export const startLog = new rpc.RequestType<WithProgressId<StartLogParams>, StartLogResult, void, void>('evaluation/startLog');
+
+/**
+ * Terminate a structured log in the evaluator. Is a no-op if we aren't logging to the given location
+ */
+ export const endLog = new rpc.RequestType<WithProgressId<EndLogParams>, EndLogResult, void, void>('evaluation/endLog');
+
 /**
  * Clear the cache of a dataset
  */

extensions/ql-vscode/src/query-history.ts

@@ -34,6 +34,8 @@ import { DatabaseManager } from './databases';
 import { registerQueryHistoryScubber } from './query-history-scrubber';
 import { QueryStatus } from './query-status';
 import { slurpQueryHistory, splatQueryHistory } from './query-serialization';
+import * as fs from 'fs-extra';
+import { CliVersionConstraint } from './cli';
 
 /**
  * query-history.ts
@@ -406,6 +408,18 @@ export class QueryHistoryManager extends DisposableObject {
         this.handleOpenQueryDirectory.bind(this)
       )
     );
+    this.push(
+      commandRunner(
+        'codeQLQueryHistory.showEvalLog',
+        this.handleShowEvalLog.bind(this)
+      )
+    );
+    this.push(
+      commandRunner(
+        'codeQLQueryHistory.showEvalLogSummary',
+        this.handleShowEvalLogSummary.bind(this)
+      )
+    );
     this.push(
       commandRunner(
         'codeQLQueryHistory.cancel',
@@ -744,6 +758,46 @@ export class QueryHistoryManager extends DisposableObject {
       }
     }
   }
+  
+  private warnNoEvalLog() {
+    void showAndLogWarningMessage('No evaluator log is available for this run. Perhaps it failed before evaluation, or you are running with a version of CodeQL before ' + CliVersionConstraint.CLI_VERSION_WITH_PER_QUERY_EVAL_LOG + '?');
+  }
+
+  async handleShowEvalLog(
+    singleItem: QueryHistoryInfo,
+    multiSelect: QueryHistoryInfo[]
+  ) {
+    // Local queries only
+    if (!this.assertSingleQuery(multiSelect) || singleItem?.t !== 'local') {
+      return;
+    }
+
+    if (singleItem.evalLogLocation) {
+      await this.tryOpenExternalFile(singleItem.evalLogLocation);
+    } else {
+      this.warnNoEvalLog();
+    }
+  }
+
+  async handleShowEvalLogSummary(
+    singleItem: QueryHistoryInfo,
+    multiSelect: QueryHistoryInfo[]
+  ) {
+    // Local queries only
+    if (!this.assertSingleQuery(multiSelect) || singleItem?.t !== 'local') {
+      return;
+    }
+
+    if (singleItem.evalLogLocation) {
+      const summaryLocation = singleItem.evalLogLocation + '.summary';
+      if (!fs.existsSync(summaryLocation)) {
+        await this.qs.cliServer.generateLogSummary(singleItem.evalLogLocation, summaryLocation);
+      }
+      await this.tryOpenExternalFile(summaryLocation);
+    } else {
+      this.warnNoEvalLog();
+    }
+  }
 
   async handleCancel(
     singleItem: QueryHistoryInfo,

extensions/ql-vscode/src/query-results.ts

@@ -216,6 +216,7 @@ export class LocalQueryInfo {
 
   public failureReason: string | undefined;
   public completedQuery: CompletedQueryInfo | undefined;
+  public evalLogLocation: string | undefined;
   private config: QueryHistoryConfig | undefined;
 
   /**

extensions/ql-vscode/src/queryserver-client.ts

@@ -146,7 +146,7 @@ export class QueryServerClient extends DisposableObject {
       args.push('--require-db-registration');
     }
 
-    if (await this.cliServer.cliConstraints.supportsOldEvalStats()) {
+    if (await this.cliServer.cliConstraints.supportsOldEvalStats() && !(await this.cliServer.cliConstraints.supportsPerQueryEvalLog())) {
       args.push('--old-eval-stats');
     }
 
@@ -258,3 +258,7 @@ export class QueryServerClient extends DisposableObject {
 export function findQueryLogFile(resultPath: string): string {
   return path.join(resultPath, 'query.log');
 }
+
+export function findQueryStructLogFile(resultPath: string): string {
+  return path.join(resultPath, 'evaluator-log.jsonl');
+}

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

@@ -29,7 +29,7 @@ import { ProgressCallback, UserCancellationException } from './commandRunner';
 import { DatabaseInfo, QueryMetadata } from './pure/interface-types';
 import { logger } from './logging';
 import * as messages from './pure/messages';
-import { InitialQueryInfo } from './query-results';
+import { InitialQueryInfo, LocalQueryInfo } from './query-results';
 import * as qsClient from './queryserver-client';
 import { isQuickQueryPath } from './quick-query';
 import { compileDatabaseUpgradeSequence, hasNondestructiveUpgradeCapabilities, upgradeDatabaseExplicit } from './upgrades';
@@ -95,6 +95,10 @@ export class QueryEvaluationInfo {
     return qsClient.findQueryLogFile(this.querySaveDir);
   }
 
+  get structLogPath() {
+    return qsClient.findQueryStructLogFile(this.querySaveDir);
+  }
+
   get resultsPaths() {
     return {
       resultsPath: path.join(this.querySaveDir, 'results.bqrs'),
@@ -125,6 +129,7 @@ export class QueryEvaluationInfo {
     dbItem: DatabaseItem,
     progress: ProgressCallback,
     token: CancellationToken,
+    queryInfo?: LocalQueryInfo,
   ): Promise<messages.EvaluationResult> {
     if (!dbItem.contents || dbItem.error) {
       throw new Error('Can\'t run query on invalid database.');
@@ -156,6 +161,12 @@ export class QueryEvaluationInfo {
       dbDir: dbItem.contents.datasetUri.fsPath,
       workingSet: 'default'
     };
+    if (queryInfo && await qs.cliServer.cliConstraints.supportsPerQueryEvalLog()) {
+      await qs.sendRequest(messages.startLog, {
+        db: dataset,
+        logPath: this.structLogPath,
+      });
+    }
     const params: messages.EvaluateQueriesParams = {
       db: dataset,
       evaluateId: callbackId,
@@ -172,6 +183,13 @@ export class QueryEvaluationInfo {
       }
     } finally {
       qs.unRegisterCallback(callbackId);
+      if (queryInfo && await qs.cliServer.cliConstraints.supportsPerQueryEvalLog()) {
+        await qs.sendRequest(messages.endLog, {
+          db: dataset,
+          logPath: this.structLogPath,
+        });
+        queryInfo.evalLogLocation = this.structLogPath;
+      }
     }
     return result || {
       evaluationTime: 0,
@@ -658,6 +676,7 @@ export async function compileAndRunQueryAgainstDatabase(
   progress: ProgressCallback,
   token: CancellationToken,
   templates?: messages.TemplateDefinitions,
+  queryInfo?: LocalQueryInfo,
 ): Promise<QueryWithResults> {
   if (!dbItem.contents || !dbItem.contents.dbSchemeUri) {
     throw new Error(`Database ${dbItem.databaseUri} does not have a CodeQL database scheme.`);
@@ -743,7 +762,7 @@ export async function compileAndRunQueryAgainstDatabase(
     }
 
     if (errors.length === 0) {
-      const result = await query.run(qs, upgradeQlo, availableMlModels, dbItem, progress, token);
+      const result = await query.run(qs, upgradeQlo, availableMlModels, dbItem, progress, token, queryInfo);
       if (result.resultType !== messages.QueryResultType.SUCCESS) {
         const message = result.message || 'Failed to run query';
         void logger.log(message);