diff --git a/extensions/ql-vscode/CHANGELOG.md b/extensions/ql-vscode/CHANGELOG.md index 03054c92082..5b6000ac0a6 100644 --- a/extensions/ql-vscode/CHANGELOG.md +++ b/extensions/ql-vscode/CHANGELOG.md @@ -2,6 +2,8 @@ ## [UNRELEASED] +- Fix reporting of bad join orders in recursive predicates. [#4019](https://github.com/github/vscode-codeql/pull/4019) + ## 1.17.2 - 27 March 2025 - Always authenticate when downloading databases from GitHub, instead of only when in canary mode. [#3941](https://github.com/github/vscode-codeql/pull/3941) diff --git a/extensions/ql-vscode/src/compare-performance/compare-performance-view.ts b/extensions/ql-vscode/src/compare-performance/compare-performance-view.ts index c1633801ed6..a59367ea135 100644 --- a/extensions/ql-vscode/src/compare-performance/compare-performance-view.ts +++ b/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(log, async (obj) => { + scanner.onEvent(obj); + }); + return scanner; + }, { title: `Scanning evaluator log ${logDescription} (${(bytes / 1024 / 1024).toFixed(1)} MB)`, diff --git a/extensions/ql-vscode/src/extension.ts b/extensions/ql-vscode/src/extension.ts index bf9e9be2b3d..bb36d958ef4 100644 --- a/extensions/ql-vscode/src/extension.ts +++ b/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( diff --git a/extensions/ql-vscode/src/log-insights/join-order.ts b/extensions/ql-vscode/src/log-insights/join-order.ts index 788da0a98e6..ce10487caf6 100644 --- a/extensions/ql-vscode/src/log-insights/join-order.ts +++ b/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, @@ -19,23 +16,6 @@ function safeMax(it?: Iterable) { return Number.isFinite(m) ? m : 0; } -/** - * Compute a key for the maps that that is sent to report generation. - * Should only be used on events that are known to define queryCausingWork. - */ -function makeKey( - queryCausingWork: string | undefined, - predicate: string, - suffix = "", -): string { - if (queryCausingWork === undefined) { - throw new Error( - "queryCausingWork was not defined on an event we expected it to be defined for!", - ); - } - return `${queryCausingWork}:${predicate}${suffix ? ` ${suffix}` : ""}`; -} - function getDependentPredicates(operations: string[]): string[] { const id = String.raw`[0-9a-zA-Z:#_\./]+`; const idWithAngleBrackets = String.raw`[0-9a-zA-Z:#_<>\./]+`; @@ -128,14 +108,6 @@ function pointwiseSum( return result; } -function pushValue(m: Map, k: K, v: V) { - if (!m.has(k)) { - m.set(k, []); - } - m.get(k)!.push(v); - return m; -} - function computeJoinOrderBadness( maxTupleCount: number, maxDependentPredicateSize: number, @@ -154,41 +126,18 @@ interface Bucket { dependentPredicateSizes: Map; } -class JoinOrderScanner implements EvaluationLogScanner { +class PredicateSizeScanner { // Map a predicate hash to its result size - private readonly predicateSizes = new Map(); - private readonly layerEvents = new Map< - string, - Array - >(); - // Map a key of the form 'query-with-demand : predicate name' to its badness input. - private readonly maxTupleCountMap = new Map(); - private readonly resultSizeMap = new Map(); - private readonly maxDependentPredicateSizeMap = new Map(); - private readonly joinOrderMetricMap = new Map(); - - constructor( - private readonly problemReporter: EvaluationLogProblemReporter, - private readonly warningThreshold: number, - ) {} + readonly predicateSizes = new Map(); + readonly layerEvents = new Map>(); - 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": @@ -215,29 +164,20 @@ class JoinOrderScanner implements EvaluationLogScanner { } } } +} - private reportProblemIfNecessary( - event: SummaryEvent, - iteration: number, - metric: number, - ): void { - if (metric >= this.warningThreshold) { - this.problemReporter.reportProblem( - event.predicateName, - event.raHash, - iteration, - `Relation '${ - event.predicateName - }' has an inefficient join order. Its join order metric is ${metric.toFixed( - 2, - )}, which is larger than the threshold of ${this.warningThreshold.toFixed( - 2, - )}.`, - ); - } - } +class JoinOrderScanner { + constructor( + private readonly predicateSizes: Map, + private readonly layerEvents: Map< + string, + Array + >, + private readonly problemReporter: EvaluationLogProblemReporter, + private readonly warningThreshold: number, + ) {} - private computeBadnessMetric(event: SummaryEvent): void { + public onEvent(event: SummaryEvent): void { if ( event.completionType !== undefined && event.completionType !== "SUCCESS" @@ -252,7 +192,6 @@ class JoinOrderScanner implements EvaluationLogScanner { } // Compute the badness metric for a non-recursive predicate. The metric in this case is defined as: // badness = (max tuple count in the pipeline) / (largest predicate this pipeline depends on) - const key = makeKey(event.queryCausingWork, event.predicateName); const resultSize = event.resultSize; // There is only one entry in `pipelineRuns` if it's a non-recursive predicate. @@ -260,20 +199,26 @@ class JoinOrderScanner implements EvaluationLogScanner { this.badnessInputsForNonRecursiveDelta(event.pipelineRuns[0], event); if (maxDependentPredicateSize > 0) { - pushValue(this.maxTupleCountMap, key, maxTupleCount); - pushValue(this.resultSizeMap, key, resultSize); - pushValue( - this.maxDependentPredicateSizeMap, - key, - maxDependentPredicateSize, - ); const metric = computeJoinOrderBadness( maxTupleCount, maxDependentPredicateSize, resultSize!, ); - this.joinOrderMetricMap.set(key, metric); - this.reportProblemIfNecessary(event, 0, metric); + if (metric >= this.warningThreshold) { + const message = `'${event.predicateName}@${event.raHash.substring( + 0, + 8, + )}' has an inefficient join order. Its join order metric is ${metric.toFixed( + 2, + )}, which is larger than the threshold of ${this.warningThreshold.toFixed( + 2, + )}.`; + this.problemReporter.reportProblemNonRecursive( + event.predicateName, + event.raHash, + message, + ); + } } break; } @@ -282,39 +227,40 @@ class JoinOrderScanner implements EvaluationLogScanner { // Compute the badness metric for a recursive predicate for each ordering. const sccMetricInput = this.badnessInputsForRecursiveDelta(event); // Loop through each predicate in the SCC - sccMetricInput.forEach((buckets, predicate) => { - // Loop through each ordering of the predicate - buckets.forEach((bucket, raReference) => { - // Format the key as demanding-query:name (ordering) - const key = makeKey( - event.queryCausingWork, - predicate, - `(${raReference})`, - ); - const maxTupleCount = Math.max(...bucket.tupleCounts); - const resultSize = bucket.resultSize; - const maxDependentPredicateSize = Math.max( - ...bucket.dependentPredicateSizes.values(), - ); - - if (maxDependentPredicateSize > 0) { - pushValue(this.maxTupleCountMap, key, maxTupleCount); - pushValue(this.resultSizeMap, key, resultSize); - pushValue( - this.maxDependentPredicateSizeMap, - key, - maxDependentPredicateSize, - ); - const metric = computeJoinOrderBadness( - maxTupleCount, - maxDependentPredicateSize, - resultSize, + sccMetricInput.forEach((hashToOrderToBucket, predicateName) => { + hashToOrderToBucket.forEach((orderToBucket, raHash) => { + // Loop through each ordering of the predicate. + orderToBucket.forEach((bucket, raReference) => { + const maxDependentPredicateSize = Math.max( + ...bucket.dependentPredicateSizes.values(), ); - const oldMetric = this.joinOrderMetricMap.get(key); - if (oldMetric === undefined || metric > oldMetric) { - this.joinOrderMetricMap.set(key, metric); + + if (maxDependentPredicateSize > 0) { + const maxTupleCount = Math.max(...bucket.tupleCounts); + const resultSize = bucket.resultSize; + const metric = computeJoinOrderBadness( + maxTupleCount, + maxDependentPredicateSize, + resultSize, + ); + if (metric >= this.warningThreshold) { + const message = `The ${raReference} pipeline for '${predicateName}@${raHash.substring( + 0, + 8, + )}' has an inefficient join order. Its join order metric is ${metric.toFixed( + 2, + )}, which is larger than the threshold of ${this.warningThreshold.toFixed( + 2, + )}.`; + this.problemReporter.reportProblemForRecursionSummary( + predicateName, + raHash, + raReference, + message, + ); + } } - } + }); }); }); break; @@ -457,20 +403,28 @@ class JoinOrderScanner implements EvaluationLogScanner { */ private badnessInputsForRecursiveDelta( event: ComputeRecursive, - ): Map> { - // nameToOrderToBucket : predicate name -> ordering (i.e., standard, order_500000, etc.) -> bucket - const nameToOrderToBucket = new Map>(); + ): Map>> { + // nameToHashToOrderToBucket : predicate name -> RA hash -> ordering (i.e., standard, order_500000, etc.) -> bucket + const nameToHashToOrderToBucket = new Map< + string, + Map> + >(); // Iterate through the SCC and compute the metric inputs this.iterateSCC(event, (inLayerEvent, run, iteration) => { const raReference = run.raReference; const predicateName = inLayerEvent.predicateName; - if (!nameToOrderToBucket.has(predicateName)) { - nameToOrderToBucket.set(predicateName, new Map()); + if (!nameToHashToOrderToBucket.has(predicateName)) { + nameToHashToOrderToBucket.set(predicateName, new Map()); } - const orderTobucket = nameToOrderToBucket.get(predicateName)!; - if (!orderTobucket.has(raReference)) { - orderTobucket.set(raReference, { + const hashToOrderToBucket = nameToHashToOrderToBucket.get(predicateName)!; + const raHash = inLayerEvent.raHash; + if (!hashToOrderToBucket.has(raHash)) { + hashToOrderToBucket.set(raHash, new Map()); + } + const orderToBucket = hashToOrderToBucket.get(raHash)!; + if (!orderToBucket.has(raReference)) { + orderToBucket.set(raReference, { tupleCounts: new Int32Array(0), resultSize: 0, dependentPredicateSizes: new Map(), @@ -484,7 +438,7 @@ class JoinOrderScanner implements EvaluationLogScanner { iteration, ); - const bucket = orderTobucket.get(raReference)!; + const bucket = orderToBucket.get(raReference)!; // Pointwise sum the tuple counts const newTupleCounts = pointwiseSum( bucket.tupleCounts, @@ -504,23 +458,36 @@ class JoinOrderScanner implements EvaluationLogScanner { ); } - orderTobucket.set(raReference, { + orderToBucket.set(raReference, { tupleCounts: newTupleCounts, resultSize, dependentPredicateSizes: newDependentPredicateSizes, }); }); - return nameToOrderToBucket; + return nameToHashToOrderToBucket; } } -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(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(jsonSummaryLocation, async (obj) => { + joinOrderScanner.onEvent(obj); + }); } diff --git a/extensions/ql-vscode/src/log-insights/log-scanner-service.ts b/extensions/ql-vscode/src/log-insights/log-scanner-service.ts index 3d78bb30aa8..e8e79d60bc5 100644 --- a/extensions/ql-vscode/src/log-insights/log-scanner-service.ts +++ b/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. @@ -28,17 +29,41 @@ class ProblemReporter implements EvaluationLogProblemReporter { constructor(private readonly symbols: SummarySymbols | undefined) {} - public reportProblem( + public reportProblemNonRecursive( predicateName: string, raHash: string, - iteration: number, message: string, ): void { const nameWithHash = predicateSymbolKey(predicateName, raHash); const predicateSymbol = this.symbols?.predicates[nameWithHash]; let predicateInfo: PipelineInfo | undefined = undefined; if (predicateSymbol !== undefined) { - predicateInfo = predicateSymbol.iterations[iteration]; + predicateInfo = predicateSymbol.iterations[0]; + } + if (predicateInfo !== undefined) { + const range = new Range( + predicateInfo.raStartLine, + 0, + predicateInfo.raEndLine + 1, + 0, + ); + this.diagnostics.push( + new Diagnostic(range, message, DiagnosticSeverity.Error), + ); + } + } + + public reportProblemForRecursionSummary( + predicateName: string, + raHash: string, + order: string, + message: string, + ): void { + const nameWithHash = predicateSymbolKey(predicateName, raHash); + const predicateSymbol = this.symbols?.predicates[nameWithHash]; + let predicateInfo: PipelineInfo | undefined = undefined; + if (predicateSymbol !== undefined) { + predicateInfo = predicateSymbol.recursionSummaries[order]; } if (predicateInfo !== undefined) { const range = new Range( @@ -59,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"), ); @@ -127,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; } } diff --git a/extensions/ql-vscode/src/log-insights/log-scanner.ts b/extensions/ql-vscode/src/log-insights/log-scanner.ts index 0ad775e6ec1..22a9a5cdf78 100644 --- a/extensions/ql-vscode/src/log-insights/log-scanner.ts +++ b/extensions/ql-vscode/src/log-insights/log-scanner.ts @@ -1,139 +1,38 @@ -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"; - /** * Callback interface used to report diagnostics from a log scanner. */ export interface EvaluationLogProblemReporter { /** - * Report a potential problem detected in the evaluation log. + * Report a potential problem detected in the evaluation log for a non-recursive predicate. * * @param predicateName The mangled name of the predicate with the problem. * @param raHash The RA hash of the predicate with the problem. - * @param iteration The iteration number with the problem. For a non-recursive predicate, this - * must be zero. * @param message The problem message. */ - reportProblem( + reportProblemNonRecursive( predicateName: string, raHash: string, - iteration: number, message: string, ): void; /** - * Log a message about a problem in the implementation of the scanner. These will typically be - * displayed separate from any problems reported via `reportProblem()`. - */ - log(message: string): void; -} - -/** - * Interface implemented by a log scanner. Instances are created via - * `EvaluationLogScannerProvider.createScanner()`. - */ -export interface EvaluationLogScanner { - /** - * Called for each event in the log summary, in order. The implementation can report problems via - * the `EvaluationLogProblemReporter` interface that was supplied to `createScanner()`. - * @param event The log summary event. - */ - onEvent(event: SummaryEvent): void; - /** - * Called after all events in the log summary have been processed. The implementation can report - * problems via the `EvaluationLogProblemReporter` interface that was supplied to - * `createScanner()`. - */ - onDone(): void; -} - -/** - * A factory for log scanners. When a log is to be scanned, all registered - * `EvaluationLogScannerProviders` will be asked to create a new instance of `EvaluationLogScanner` - * to do the scanning. - */ -export interface EvaluationLogScannerProvider { - /** - * Create a new instance of `EvaluationLogScanner` to scan a single summary log. - * @param problemReporter Callback interface for reporting any problems discovered. - */ - createScanner( - 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. + * Report a potential problem detected in the evaluation log for the summary of a recursive pipeline. + * + * @param predicateName The mangled name of the predicate with the problem. + * @param raHash The RA hash of the predicate with the problem. + * @param order The particular order (pipeline name) that had the problem. + * @param message The problem message. */ - public registerLogScannerProvider( - provider: EvaluationLogScannerProvider, - ): Disposable { - const id = this.nextScannerProviderId; - this.nextScannerProviderId++; - - this.scannerProviders.set(id, provider); - return { - dispose: () => { - this.scannerProviders.delete(id); - }, - }; - } + reportProblemForRecursionSummary( + predicateName: string, + raHash: string, + order: string, + message: string, + ): void; /** - * 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. + * Log a message about a problem in the implementation of the scanner. These will typically be + * displayed separate from any problems reported via `reportProblem()`. */ - public async scanLog( - jsonSummaryLocation: string, - problemReporter: EvaluationLogProblemReporter, - ): Promise { - const scanners = [...this.scannerProviders.values()].map((p) => - p.createScanner(problemReporter), - ); - - await readJsonlFile(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( - jsonSummaryLocation: string, - scanner: T, - progress?: ProgressCallback, -): Promise { - 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(jsonSummaryLocation, async (obj) => { - scanner.onEvent(obj); - }); - scanner.onDone(); - return scanner; + log(message: string): void; } diff --git a/extensions/ql-vscode/src/log-insights/performance-comparison.ts b/extensions/ql-vscode/src/log-insights/performance-comparison.ts index 46634cf8bf3..023d4fa536f 100644 --- a/extensions/ql-vscode/src/log-insights/performance-comparison.ts +++ b/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>; } -export class PerformanceOverviewScanner implements EvaluationLogScanner { +export class PerformanceOverviewScanner { private readonly nameToIndex = new Map(); private readonly data: PerformanceComparisonDataFromLog = { names: [], @@ -178,6 +177,4 @@ export class PerformanceOverviewScanner implements EvaluationLogScanner { } } } - - onDone(): void {} } diff --git a/extensions/ql-vscode/src/log-insights/summary-parser.ts b/extensions/ql-vscode/src/log-insights/summary-parser.ts index 6a42efca187..f00923e53ea 100644 --- a/extensions/ql-vscode/src/log-insights/summary-parser.ts +++ b/extensions/ql-vscode/src/log-insights/summary-parser.ts @@ -18,6 +18,11 @@ interface PredicateSymbol { * `PipelineInfo` for each iteration. A non-recursive predicate will have a single iteration `0`. */ iterations: Record; + + /** + * `PipelineInfo` for each order, summarised for all iterations that used that order. Empty for non-recursive predicates. + */ + recursionSummaries: Record; } /** @@ -105,6 +110,7 @@ async function generateSummarySymbols( if (symbol === undefined) { symbol = { iterations: {}, + recursionSummaries: {}, }; symbols.predicates[predicateName] = symbol; } diff --git a/extensions/ql-vscode/test/unit-tests/data/evaluator-log-summaries/bad-join-order.jsonl b/extensions/ql-vscode/test/unit-tests/data/evaluator-log-summaries/bad-join-order.jsonl index 8d366067387..59d6e67f64a 100644 --- a/extensions/ql-vscode/test/unit-tests/data/evaluator-log-summaries/bad-join-order.jsonl +++ b/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", diff --git a/extensions/ql-vscode/test/unit-tests/log-scanner.test.ts b/extensions/ql-vscode/test/unit-tests/log-scanner.test.ts index 3d49f3362a1..0012cecda23 100644 --- a/extensions/ql-vscode/test/unit-tests/log-scanner.test.ts +++ b/extensions/ql-vscode/test/unit-tests/log-scanner.test.ts @@ -1,28 +1,39 @@ +import { scanAndReportJoinOrderProblems } from "../../src/log-insights/join-order"; import type { EvaluationLogProblemReporter } from "../../src/log-insights/log-scanner"; -import { EvaluationLogScannerSet } from "../../src/log-insights/log-scanner"; -import { JoinOrderScannerProvider } from "../../src/log-insights/join-order"; import { join } from "path"; interface TestProblem { predicateName: string; raHash: string; - iteration: number; + order: string | undefined; message: string; } class TestProblemReporter implements EvaluationLogProblemReporter { public readonly problems: TestProblem[] = []; - public reportProblem( + public reportProblemNonRecursive( predicateName: string, raHash: string, - iteration: number, message: string, ): void { this.problems.push({ predicateName, raHash, - iteration, + order: undefined, + message, + }); + } + public reportProblemForRecursionSummary( + predicateName: string, + raHash: string, + order: string, + message: string, + ): void { + this.problems.push({ + predicateName, + raHash, + order, message, }); } @@ -34,23 +45,33 @@ class TestProblemReporter implements EvaluationLogProblemReporter { describe("log scanners", () => { it("should detect bad join orders", async () => { - const scanners = new EvaluationLogScannerSet(); - scanners.registerLogScannerProvider(new JoinOrderScannerProvider(() => 50)); const summaryPath = join( __dirname, "data/evaluator-log-summaries/bad-join-order.jsonl", ); const problemReporter = new TestProblemReporter(); - await scanners.scanLog(summaryPath, problemReporter); + await scanAndReportJoinOrderProblems(summaryPath, problemReporter, 50); + + expect(problemReporter.problems.length).toBe(2); - expect(problemReporter.problems.length).toBe(1); - expect(problemReporter.problems[0].predicateName).toBe("#select#ff"); + expect(problemReporter.problems[0].predicateName).toBe( + "Enclosing::exprEnclosingElement#c50c5fbf#ff", + ); expect(problemReporter.problems[0].raHash).toBe( - "1bb43c97jpmuh8r2v0f9hktim63", + "7cc60wtoigvl1lheqqa12d8fmi4", ); - expect(problemReporter.problems[0].iteration).toBe(0); + expect(problemReporter.problems[0].order).toBe("order_500000"); expect(problemReporter.problems[0].message).toBe( - "Relation '#select#ff' has an inefficient join order. Its join order metric is 4961.83, which is larger than the threshold of 50.00.", + "The order_500000 pipeline for 'Enclosing::exprEnclosingElement#c50c5fbf#ff@7cc60wto' has an inefficient join order. Its join order metric is 98.07, which is larger than the threshold of 50.00.", + ); + + expect(problemReporter.problems[1].predicateName).toBe("#select#ff"); + expect(problemReporter.problems[1].raHash).toBe( + "1bb43c97jpmuh8r2v0f9hktim63", + ); + expect(problemReporter.problems[1].order).toBeUndefined(); + expect(problemReporter.problems[1].message).toBe( + "'#select#ff@1bb43c97' has an inefficient join order. Its join order metric is 4961.83, which is larger than the threshold of 50.00.", ); }); });