Fix join-order scoring for recursive predicates

The evaluator log summary JSON needs to be read in two passes, to avoid
trying to calculate scores for a recursive layer before all the events
for it have been processed. Doing it in one pass meant that, for
predicates associated with an IN_LAYER event that came after the
corresponding COMPUTE_RECURSIVE event, we were missing their delta sizes
and were not even attempting to their join-order scores.

I had to remove some of the generic machinery for registering log
processors, but the JoinOrderScanner was the only processor being
registered anyway.

Author: nickrolfe

extensions/ql-vscode/src/compare-performance/compare-performance-view.ts

@@ -16,8 +16,9 @@ import { withProgress } from "../common/vscode/progress";
 import { telemetryListener } from "../common/vscode/telemetry";
 import type { HistoryItemLabelProvider } from "../query-history/history-item-label-provider";
 import { PerformanceOverviewScanner } from "../log-insights/performance-comparison";
-import { scanLog } from "../log-insights/log-scanner";
 import type { ResultsView } from "../local-queries";
+import { readJsonlFile } from "../common/jsonl-reader";
+import type { SummaryEvent } from "../log-insights/log-summary";
 
 export class ComparePerformanceView extends AbstractWebview<
   ToComparePerformanceViewMessage,
@@ -46,8 +47,20 @@ export class ComparePerformanceView extends AbstractWebview<
     function scanLogWithProgress(log: string, logDescription: string) {
       const bytes = statSync(log).size;
       return withProgress(
-        async (progress) =>
-          scanLog(log, new PerformanceOverviewScanner(), progress),
+        async (progress) => {
+          progress?.({
+            // all scans have step 1 - the backing progress tracker allows increments instead of
+            // steps - but for now we are happy with a tiny UI that says what is happening
+            message: `Scanning ...`,
+            step: 1,
+            maxStep: 2,
+          });
+          const scanner = new PerformanceOverviewScanner();
+          await readJsonlFile<SummaryEvent>(log, async (obj) => {
+            scanner.onEvent(obj);
+          });
+          return scanner;
+        },
 
         {
           title: `Scanning evaluator log ${logDescription} (${(bytes / 1024 / 1024).toFixed(1)} MB)`,

extensions/ql-vscode/src/extension.ts

@@ -28,7 +28,6 @@ import {
   CliConfigListener,
   DistributionConfigListener,
   GitHubDatabaseConfigListener,
-  joinOrderWarningThreshold,
   QueryHistoryConfigListener,
   QueryServerConfigListener,
   VariantAnalysisConfigListener,
@@ -102,7 +101,6 @@ import { getPackagingCommands } from "./packaging";
 import { HistoryItemLabelProvider } from "./query-history/history-item-label-provider";
 import { EvalLogViewer } from "./query-evaluation-logging";
 import { SummaryLanguageSupport } from "./log-insights/summary-language-support";
-import { JoinOrderScannerProvider } from "./log-insights/join-order";
 import { LogScannerService } from "./log-insights/log-scanner-service";
 import { VariantAnalysisView } from "./variant-analysis/variant-analysis-view";
 import { VariantAnalysisViewSerializer } from "./variant-analysis/variant-analysis-view-serializer";
@@ -941,11 +939,6 @@ async function activateWithInstalledDistribution(
   void extLogger.log("Initializing evaluation log scanners.");
   const logScannerService = new LogScannerService(qhm);
   ctx.subscriptions.push(logScannerService);
-  ctx.subscriptions.push(
-    logScannerService.scanners.registerLogScannerProvider(
-      new JoinOrderScannerProvider(() => joinOrderWarningThreshold()),
-    ),
-  );
 
   void extLogger.log("Initializing compare view.");
   const compareView = new CompareView(

extensions/ql-vscode/src/log-insights/join-order.ts

@@ -1,8 +1,5 @@
-import type {
-  EvaluationLogProblemReporter,
-  EvaluationLogScanner,
-  EvaluationLogScannerProvider,
-} from "./log-scanner";
+import { readJsonlFile } from "../common/jsonl-reader";
+import type { EvaluationLogProblemReporter } from "./log-scanner";
 import type {
   InLayer,
   ComputeRecursive,
@@ -129,36 +126,18 @@ interface Bucket {
   dependentPredicateSizes: Map<string, number>;
 }
 
-class JoinOrderScanner implements EvaluationLogScanner {
+class PredicateSizeScanner {
   // Map a predicate hash to its result size
-  private readonly predicateSizes = new Map<string, number>();
-  private readonly layerEvents = new Map<
-    string,
-    Array<ComputeRecursive | InLayer>
-  >();
+  readonly predicateSizes = new Map<string, number>();
+  readonly layerEvents = new Map<string, Array<ComputeRecursive | InLayer>>();
 
-  constructor(
-    private readonly problemReporter: EvaluationLogProblemReporter,
-    private readonly warningThreshold: number,
-  ) {}
-
-  public onEvent(event: SummaryEvent): void {
+  onEvent(event: SummaryEvent): void {
     if (
       event.completionType !== undefined &&
       event.completionType !== "SUCCESS"
     ) {
       return; // Skip any evaluation that wasn't successful
     }
-
-    this.recordPredicateSizes(event);
-    this.computeBadnessMetric(event);
-  }
-
-  public onDone(): void {
-    void this;
-  }
-
-  private recordPredicateSizes(event: SummaryEvent): void {
     switch (event.evaluationStrategy) {
       case "EXTENSIONAL":
       case "COMPUTED_EXTENSIONAL":
@@ -185,8 +164,20 @@ class JoinOrderScanner implements EvaluationLogScanner {
       }
     }
   }
+}
 
-  private computeBadnessMetric(event: SummaryEvent): void {
+class JoinOrderScanner {
+  constructor(
+    private readonly predicateSizes: Map<string, number>,
+    private readonly layerEvents: Map<
+      string,
+      Array<ComputeRecursive | InLayer>
+    >,
+    private readonly problemReporter: EvaluationLogProblemReporter,
+    private readonly warningThreshold: number,
+  ) {}
+
+  public onEvent(event: SummaryEvent): void {
     if (
       event.completionType !== undefined &&
       event.completionType !== "SUCCESS"
@@ -475,13 +466,26 @@ class JoinOrderScanner implements EvaluationLogScanner {
   }
 }
 
-export class JoinOrderScannerProvider implements EvaluationLogScannerProvider {
-  constructor(private readonly getThreshdold: () => number) {}
+export async function scanAndReportJoinOrderProblems(
+  jsonSummaryLocation: string,
+  problemReporter: EvaluationLogProblemReporter,
+  warningThreshold: number,
+) {
+  // Do two passes over the summary JSON. The first pass collects the sizes of predicates, along
+  // with collecting layer events for each recursive SCC.
+  const predicateSizeScanner = new PredicateSizeScanner();
+  await readJsonlFile<SummaryEvent>(jsonSummaryLocation, async (obj) => {
+    predicateSizeScanner.onEvent(obj);
+  });
 
-  public createScanner(
-    problemReporter: EvaluationLogProblemReporter,
-  ): EvaluationLogScanner {
-    const threshold = this.getThreshdold();
-    return new JoinOrderScanner(problemReporter, threshold);
-  }
+  // The second pass takes the information from the first pass, computes join order scores, and reports those that exceed the threshold.
+  const joinOrderScanner = new JoinOrderScanner(
+    predicateSizeScanner.predicateSizes,
+    predicateSizeScanner.layerEvents,
+    problemReporter,
+    warningThreshold,
+  );
+  await readJsonlFile<SummaryEvent>(jsonSummaryLocation, async (obj) => {
+    joinOrderScanner.onEvent(obj);
+  });
 }

extensions/ql-vscode/src/log-insights/log-scanner-service.ts

@@ -2,11 +2,12 @@ import { Diagnostic, DiagnosticSeverity, languages, Range, Uri } from "vscode";
 import { DisposableObject } from "../common/disposable-object";
 import type { QueryHistoryInfo } from "../query-history/query-history-info";
 import type { EvaluationLogProblemReporter } from "./log-scanner";
-import { EvaluationLogScannerSet } from "./log-scanner";
 import type { PipelineInfo, SummarySymbols } from "./summary-parser";
 import { readFile } from "fs-extra";
 import { extLogger } from "../common/logging/vscode";
 import type { QueryHistoryManager } from "../query-history/query-history-manager";
+import { scanAndReportJoinOrderProblems } from "./join-order";
+import { joinOrderWarningThreshold } from "../config";
 
 /**
  * Compute the key used to find a predicate in the summary symbols.
@@ -83,7 +84,6 @@ class ProblemReporter implements EvaluationLogProblemReporter {
 }
 
 export class LogScannerService extends DisposableObject {
-  public readonly scanners = new EvaluationLogScannerSet();
   private readonly diagnosticCollection = this.push(
     languages.createDiagnosticCollection("ql-eval-log"),
   );
@@ -151,9 +151,11 @@ export class LogScannerService extends DisposableObject {
       );
     }
     const problemReporter = new ProblemReporter(symbols);
-
-    await this.scanners.scanLog(jsonSummaryLocation, problemReporter);
-
+    await scanAndReportJoinOrderProblems(
+      jsonSummaryLocation,
+      problemReporter,
+      joinOrderWarningThreshold(),
+    );
     return problemReporter.diagnostics;
   }
 }

extensions/ql-vscode/src/log-insights/log-scanner.ts

@@ -1,6 +1,3 @@
-import type { Disposable } from "../common/disposable-object";
-import { readJsonlFile } from "../common/jsonl-reader";
-import type { ProgressCallback } from "../common/vscode/progress";
 import type { SummaryEvent } from "./log-summary";
 
 /**
@@ -75,77 +72,3 @@ export interface EvaluationLogScannerProvider {
     problemReporter: EvaluationLogProblemReporter,
   ): EvaluationLogScanner;
 }
-
-export class EvaluationLogScannerSet {
-  private readonly scannerProviders = new Map<
-    number,
-    EvaluationLogScannerProvider
-  >();
-  private nextScannerProviderId = 0;
-
-  /**
-   * Register a provider that can create instances of `EvaluationLogScanner` to scan evaluation logs
-   * for problems.
-   * @param provider The provider.
-   * @returns A `Disposable` that, when disposed, will unregister the provider.
-   */
-  public registerLogScannerProvider(
-    provider: EvaluationLogScannerProvider,
-  ): Disposable {
-    const id = this.nextScannerProviderId;
-    this.nextScannerProviderId++;
-
-    this.scannerProviders.set(id, provider);
-    return {
-      dispose: () => {
-        this.scannerProviders.delete(id);
-      },
-    };
-  }
-
-  /**
-   * Scan the evaluator summary log for problems, using the scanners for all registered providers.
-   * @param jsonSummaryLocation The file path of the JSON summary log.
-   * @param problemReporter Callback interface for reporting any problems discovered.
-   */
-  public async scanLog(
-    jsonSummaryLocation: string,
-    problemReporter: EvaluationLogProblemReporter,
-  ): Promise<void> {
-    const scanners = [...this.scannerProviders.values()].map((p) =>
-      p.createScanner(problemReporter),
-    );
-
-    await readJsonlFile<SummaryEvent>(jsonSummaryLocation, async (obj) => {
-      scanners.forEach((scanner) => {
-        scanner.onEvent(obj);
-      });
-    });
-
-    scanners.forEach((scanner) => scanner.onDone());
-  }
-}
-
-/**
- * Scan the evaluator summary log using the given scanner. For convenience, returns the scanner.
- *
- * @param jsonSummaryLocation The file path of the JSON summary log.
- * @param scanner The scanner to process events from the log
- */
-export async function scanLog<T extends EvaluationLogScanner>(
-  jsonSummaryLocation: string,
-  scanner: T,
-  progress?: ProgressCallback,
-): Promise<T> {
-  progress?.({
-    // all scans have step 1 - the backing progress tracker allows increments instead of steps - but for now we are happy with a tiny UI that says what is happening
-    message: `Scanning ...`,
-    step: 1,
-    maxStep: 2,
-  });
-  await readJsonlFile<SummaryEvent>(jsonSummaryLocation, async (obj) => {
-    scanner.onEvent(obj);
-  });
-  scanner.onDone();
-  return scanner;
-}

extensions/ql-vscode/src/log-insights/performance-comparison.ts

@@ -1,4 +1,3 @@
-import type { EvaluationLogScanner } from "./log-scanner";
 import type { SummaryEvent } from "./log-summary";
 
 export interface PipelineSummary {
@@ -55,7 +54,7 @@ export interface PerformanceComparisonDataFromLog {
   pipelineSummaryList: Array<Record<string, PipelineSummary>>;
 }
 
-export class PerformanceOverviewScanner implements EvaluationLogScanner {
+export class PerformanceOverviewScanner {
   private readonly nameToIndex = new Map<string, number>();
   private readonly data: PerformanceComparisonDataFromLog = {
     names: [],
@@ -178,6 +177,4 @@ export class PerformanceOverviewScanner implements EvaluationLogScanner {
       }
     }
   }
-
-  onDone(): void {}
 }

extensions/ql-vscode/test/unit-tests/data/evaluator-log-summaries/bad-join-order.jsonl

@@ -11458,7 +11458,7 @@
     "duplicationPercentages" : [ 0, -1, 1, 0, -1, 0, -1, 0, 0, -1, 1, 0, 1, -1, 1, 0 ]
   }, {
     "raReference" : "order_500000",
-    "counts" : [ 0, -1, 0, -1, 3138, -1, 3138, 3138, -1, 0, -1, 0, 0, -1, 0, -1, 133, 133, -1, 0, 0, -1, 133, 133, 3271, 3271, 3271 ],
+    "counts" : [ 0, -1, 0, -1, 31380000, -1, 3138, 3138, -1, 0, -1, 0, 0, -1, 0, -1, 133, 133, -1, 0, 0, -1, 133, 133, 3271, 3271, 3271 ],
     "duplicationPercentages" : [ 0, -1, 0, -1, 0, -1, 0, 0, -1, 0, -1, 0, 0, -1, 0, -1, 0, 0, -1, 0, 0, -1, 0, 0, 0, 0, 1 ]
   }, {
     "raReference" : "order_500000",