Skip to content

Commit c9d895e

Browse files
angelapwenadityasharadaeisenberg
authored
Parse summary of evaluator logs into data model (#1405)
Co-authored-by: Aditya Sharad <6874315+adityasharad@users.noreply.github.com> Co-authored-by: Andrew Eisenberg <aeisenberg@github.com>
1 parent e57bbcb commit c9d895e

File tree

8 files changed

+301
-16
lines changed

8 files changed

+301
-16
lines changed

‎extensions/ql-vscode/src/cli.ts‎

Lines changed: 17 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -689,6 +689,23 @@ export class CodeQLCliServer implements Disposable {
689689
return await this.runCodeQlCliCommand(['generate', 'log-summary'], subcommandArgs, 'Generating log summary');
690690
}
691691

692+
/**
693+
* Generate a JSON summary of an evaluation log.
694+
* @param inputPath The path of an evaluation event log.
695+
* @param outputPath The path to write a JSON summary of it to.
696+
*/
697+
async generateJsonLogSummary(
698+
inputPath: string,
699+
outputPath: string,
700+
): Promise<string> {
701+
const subcommandArgs = [
702+
'--format=predicates',
703+
inputPath,
704+
outputPath
705+
];
706+
return await this.runCodeQlCliCommand(['generate', 'log-summary'], subcommandArgs, 'Generating JSON log summary');
707+
}
708+
692709
/**
693710
* Gets the results from a bqrs.
694711
* @param bqrsPath The path to the bqrs.

‎extensions/ql-vscode/src/pure/log-summary-parser.ts‎

Lines changed: 44 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,44 @@
1+
import * as os from 'os';
2+
3+
// TODO(angelapwen): Only load in necessary information and
4+
// location in bytes for this log to save memory.
5+
export interface EvaluatorLogData {
6+
queryCausingWork: string;
7+
predicateName: string;
8+
millis: number;
9+
resultSize: number;
10+
ra: Pipelines;
11+
}
12+
13+
interface Pipelines {
14+
// Key: pipeline identifier; Value: array of pipeline steps
15+
pipelineNamesToSteps: Map<string, string[]>;
16+
}
17+
18+
/**
19+
* A pure method that parses a string of evaluator log summaries into
20+
* an array of EvaluatorLogData objects.
21+
*
22+
*/
23+
export function parseVisualizerData(logSummary: string): EvaluatorLogData[] {
24+
// Remove newline delimiters because summary is in .jsonl format.
25+
const jsonSummaryObjects: string[] = logSummary.split(os.EOL + os.EOL);
26+
const visualizerData: EvaluatorLogData[] = [];
27+
28+
for (const obj of jsonSummaryObjects) {
29+
const jsonObj = JSON.parse(obj);
30+
31+
// Only convert log items that have an RA and millis field
32+
if (jsonObj.ra !== undefined && jsonObj.millis !== undefined) {
33+
const newLogData: EvaluatorLogData = {
34+
queryCausingWork: jsonObj.queryCausingWork,
35+
predicateName: jsonObj.predicateName,
36+
millis: jsonObj.millis,
37+
resultSize: jsonObj.resultSize,
38+
ra: jsonObj.ra
39+
};
40+
visualizerData.push(newLogData);
41+
}
42+
}
43+
return visualizerData;
44+
}

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

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -267,6 +267,10 @@ export function findQueryEvalLogSummaryFile(resultPath: string): string {
267267
return path.join(resultPath, 'evaluator-log.summary');
268268
}
269269

270+
export function findJsonQueryEvalLogSummaryFile(resultPath: string): string {
271+
return path.join(resultPath, 'evaluator-log.summary.jsonl');
272+
}
273+
270274
export function findQueryEvalLogEndSummaryFile(resultPath: string): string {
271275
return path.join(resultPath, 'evaluator-log-end.summary');
272276
}

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

Lines changed: 51 additions & 16 deletions
Original file line numberDiff line numberDiff line change
@@ -37,6 +37,7 @@ import { ensureMetadataIsComplete } from './query-results';
3737
import { SELECT_QUERY_NAME } from './contextual/locationFinder';
3838
import { DecodedBqrsChunk } from './pure/bqrs-cli-types';
3939
import { getErrorMessage } from './pure/helpers-pure';
40+
import { parseVisualizerData } from './pure/log-summary-parser';
4041

4142
/**
4243
* run-queries.ts
@@ -103,6 +104,10 @@ export class QueryEvaluationInfo {
103104
return qsClient.findQueryEvalLogSummaryFile(this.querySaveDir);
104105
}
105106

107+
get jsonEvalLogSummaryPath() {
108+
return qsClient.findJsonQueryEvalLogSummaryFile(this.querySaveDir);
109+
}
110+
106111
get evalLogEndSummaryPath() {
107112
return qsClient.findQueryEvalLogEndSummaryFile(this.querySaveDir);
108113
}
@@ -198,22 +203,10 @@ export class QueryEvaluationInfo {
198203
logPath: this.evalLogPath,
199204
});
200205
if (await this.hasEvalLog()) {
201-
queryInfo.evalLogLocation = this.evalLogPath;
202-
void qs.cliServer.generateLogSummary(this.evalLogPath, this.evalLogSummaryPath, this.evalLogEndSummaryPath)
203-
.then(() => {
204-
queryInfo.evalLogSummaryLocation = this.evalLogSummaryPath;
205-
fs.readFile(this.evalLogEndSummaryPath, (err, buffer) => {
206-
if (err) {
207-
throw new Error(`Could not read structured evaluator log end of summary file at ${this.evalLogEndSummaryPath}.`);
208-
}
209-
void qs.logger.log(' --- Evaluator Log Summary --- ', { additionalLogLocation: this.logPath });
210-
void qs.logger.log(buffer.toString(), { additionalLogLocation: this.logPath });
211-
});
212-
})
213-
214-
.catch(err => {
215-
void showAndLogWarningMessage(`Failed to generate structured evaluator log summary. Reason: ${err.message}`);
216-
});
206+
this.displayHumanReadableLogSummary(queryInfo, qs);
207+
if (config.isCanary()) {
208+
this.parseJsonLogSummary(qs.cliServer);
209+
}
217210
} else {
218211
void showAndLogWarningMessage(`Failed to write structured evaluator log to ${this.evalLogPath}.`);
219212
}
@@ -338,6 +331,48 @@ export class QueryEvaluationInfo {
338331
return fs.pathExists(this.evalLogPath);
339332
}
340333

334+
/**
335+
* Calls the appropriate CLI command to generate a human-readable log summary
336+
* and logs to the Query Server console and query log file.
337+
*/
338+
displayHumanReadableLogSummary(queryInfo: LocalQueryInfo, qs: qsClient.QueryServerClient): void {
339+
queryInfo.evalLogLocation = this.evalLogPath;
340+
void qs.cliServer.generateLogSummary(this.evalLogPath, this.evalLogSummaryPath, this.evalLogEndSummaryPath)
341+
.then(() => {
342+
queryInfo.evalLogSummaryLocation = this.evalLogSummaryPath;
343+
fs.readFile(this.evalLogEndSummaryPath, (err, buffer) => {
344+
if (err) {
345+
throw new Error(`Could not read structured evaluator log end of summary file at ${this.evalLogEndSummaryPath}.`);
346+
}
347+
void qs.logger.log(' --- Evaluator Log Summary --- ', { additionalLogLocation: this.logPath });
348+
void qs.logger.log(buffer.toString(), { additionalLogLocation: this.logPath });
349+
});
350+
})
351+
.catch(err => {
352+
void showAndLogWarningMessage(`Failed to generate human-readable structured evaluator log summary. Reason: ${err.message}`);
353+
});
354+
}
355+
356+
/**
357+
* Calls the appropriate CLI command to generate a JSON log summary and parse it
358+
* into the appropriate data model for the log visualizer.
359+
*/
360+
parseJsonLogSummary(cliServer: cli.CodeQLCliServer): void {
361+
void cliServer.generateJsonLogSummary(this.evalLogPath, this.jsonEvalLogSummaryPath)
362+
.then(() => {
363+
// TODO(angelapwen): Stream the file in.
364+
fs.readFile(this.jsonEvalLogSummaryPath, (err, buffer) => {
365+
if (err) {
366+
throw new Error(`Could not read structured evaluator log summary JSON file at ${this.jsonEvalLogSummaryPath}.`);
367+
}
368+
parseVisualizerData(buffer.toString()); // Eventually this return value will feed into the tree visualizer.
369+
});
370+
})
371+
.catch(err => {
372+
void showAndLogWarningMessage(`Failed to generate JSON structured evaluator log summary. Reason: ${err.message}`);
373+
});
374+
}
375+
341376
/**
342377
* Creates the CSV file containing the results of this query. This will only be called if the query
343378
* does not have interpreted results and the CSV file does not already exist.

‎extensions/ql-vscode/test/pure-tests/evaluator-log-summaries/invalid-header.jsonl‎

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,5 @@
1+
{
2+
"summaryLogVersion" : "0.3.0",
3+
"codeqlVersion" : "2.9.0+202204201304plus",
4+
"startTime" : "2022-06-23T14:02:41.607Z"
5+
}

‎extensions/ql-vscode/test/pure-tests/evaluator-log-summaries/invalid-summary.jsonl‎

Lines changed: 14 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,14 @@
1+
{
2+
"completionTime" : "2022-06-23T14:02:42.019Z",
3+
"raHash" : "8caddafufc3it9svjph9m8d43me",
4+
"predicateName" : "function_instantiation",
5+
"appearsAs" : {
6+
"function_instantiation" : {
7+
"uboot-taint.ql" : [ 3, 9, 10, 11, 13, 14, 15, 17, 18, 20, 21, 22, 23, 24 ]
8+
}
9+
},
10+
"queryCausingWork" : "uboot-taint.ql",
11+
"evaluationStrategy" : "EXTENSIONAL",
12+
"millis" : 0,
13+
"resultSize" : 0
14+
}

‎extensions/ql-vscode/test/pure-tests/evaluator-log-summaries/valid-summary.jsonl‎

Lines changed: 124 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,124 @@
1+
{
2+
"completionTime" : "2022-06-23T14:02:42.007Z",
3+
"raHash" : "e77dfaa9ciimqv7gb3imoesdb11",
4+
"predicateName" : "query::ClassPointerType::getBaseType#dispred#f0820431#ff",
5+
"appearsAs" : {
6+
"query::ClassPointerType::getBaseType#dispred#f0820431#ff" : {
7+
"uboot-taint.ql" : [ 3 ]
8+
}
9+
},
10+
"queryCausingWork" : "uboot-taint.ql",
11+
"evaluationStrategy" : "COMPUTE_SIMPLE",
12+
"millis" : 11,
13+
"resultSize" : 1413,
14+
"dependencies" : {
15+
"derivedtypes_2013#join_rhs" : "0da8f1fqbiin9i0mcitjedvlbc7",
16+
"query::Class#class#f0820431#f" : "2e5d24rnudi1l99mvtse9u567b7",
17+
"derivedtypes" : "070e120iu2i3dhj6pt13oqnbi66"
18+
},
19+
"ra" : {
20+
"pipeline" : [
21+
" {1} r1 = CONSTANT(unique int)[1]",
22+
" {3} r2 = JOIN r1 WITH derivedtypes_2013#join_rhs ON FIRST 1 OUTPUT Rhs.3, Rhs.1, Rhs.2",
23+
" {4} r3 = JOIN r2 WITH query::Class#class#f0820431#f ON FIRST 1 OUTPUT Lhs.1, Lhs.2, 1, Lhs.0",
24+
" {2} r4 = JOIN r3 WITH derivedtypes ON FIRST 4 OUTPUT Lhs.0, Lhs.3",
25+
" return r4"
26+
]
27+
},
28+
"pipelineRuns" : [ {
29+
"raReference" : "pipeline"
30+
} ]
31+
}
32+
33+
{
34+
"completionTime" : "2022-06-23T14:02:42.072Z",
35+
"raHash" : "0a0e3cicgtsru1m0cun896qhi61",
36+
"predicateName" : "query::DefinedMemberFunction#class#f0820431#f",
37+
"appearsAs" : {
38+
"query::DefinedMemberFunction#class#f0820431#f" : {
39+
"uboot-taint.ql" : [ 3 ]
40+
}
41+
},
42+
"queryCausingWork" : "uboot-taint.ql",
43+
"evaluationStrategy" : "COMPUTE_SIMPLE",
44+
"millis" : 20,
45+
"resultSize" : 8740,
46+
"dependencies" : {
47+
"fun_decls" : "e6e2e6vn02fcrrtp1ks1f75cd01",
48+
"fun_def" : "6bec314lcq8sm3skg9mpecscp02",
49+
"function_instantiation" : "8caddafufc3it9svjph9m8d43me",
50+
"fun_decls_10#join_rhs" : "16474d6lehg7ssk83gnv2q7r8t8"
51+
},
52+
"ra" : {
53+
"pipeline" : [
54+
" {2} r1 = SCAN fun_decls OUTPUT In.0, In.1",
55+
" {2} r2 = STREAM DEDUP r1",
56+
" {1} r3 = JOIN r2 WITH fun_def ON FIRST 1 OUTPUT Lhs.1",
57+
"",
58+
" {2} r4 = SCAN function_instantiation OUTPUT In.1, In.0",
59+
" {2} r5 = JOIN r4 WITH fun_decls_10#join_rhs ON FIRST 1 OUTPUT Rhs.1, Lhs.1",
60+
" {1} r6 = JOIN r5 WITH fun_def ON FIRST 1 OUTPUT Lhs.1",
61+
"",
62+
" {1} r7 = r3 UNION r6",
63+
" return r7"
64+
]
65+
},
66+
"pipelineRuns" : [ {
67+
"raReference" : "pipeline"
68+
} ]
69+
}
70+
71+
{
72+
"completionTime" : "2022-06-23T14:02:43.799Z",
73+
"raHash" : "1d0c6wplpr6bnlnii51r7f6lh85",
74+
"predicateName" : "QualifiedName::Namespace::getAQualifierForMembers#f0820431#ff",
75+
"appearsAs" : {
76+
"QualifiedName::Namespace::getAQualifierForMembers#f0820431#ff" : {
77+
"uboot-taint.ql" : [ 10 ]
78+
}
79+
},
80+
"queryCausingWork" : "uboot-taint.ql",
81+
"evaluationStrategy" : "COMPUTE_RECURSIVE",
82+
"millis" : 2,
83+
"predicateIterationMillis" : [ 1, 0 ],
84+
"deltaSizes" : [ 1, 0 ],
85+
"resultSize" : 1,
86+
"dependencies" : {
87+
"namespaces" : "bf72dcmerq68kur5k2uttmjoco4",
88+
"namespacembrs_1#antijoin_rhs" : "3c47bbkgae024k8hgf148mgeqi2",
89+
"QualifiedName::Namespace::getAQualifierForMembers#f0820431#ff#join_rhs#1" : "d55d698lva8n15u4v7055ma1vl9",
90+
"namespacembrs" : "08a148i70tonoa8fp0mb5eb44r1",
91+
"QualifiedName::Namespace::getAQualifierForMembers#f0820431#ff#join_rhs" : "77cd9dha843p3v12qso4qpe4qoe"
92+
},
93+
"layerSize" : 1,
94+
"ra" : {
95+
"base" : [
96+
" {2} r1 = namespaces AND NOT namespacembrs_1#antijoin_rhs(Lhs.0)",
97+
" return r1"
98+
],
99+
"standard" : [
100+
" {2} r1 = JOIN QualifiedName::Namespace::getAQualifierForMembers#f0820431#ff#prev_delta WITH QualifiedName::Namespace::getAQualifierForMembers#f0820431#ff#join_rhs#1 ON FIRST 1 OUTPUT Rhs.1, Lhs.1",
101+
"",
102+
" {2} r2 = JOIN QualifiedName::Namespace::getAQualifierForMembers#f0820431#ff#prev_delta WITH QualifiedName::Namespace::getAQualifierForMembers#f0820431#ff#join_rhs ON FIRST 1 OUTPUT Rhs.1, (Lhs.1 ++ \"::\" ++ Rhs.2)",
103+
"",
104+
" {2} r3 = r1 UNION r2",
105+
" {2} r4 = r3 AND NOT QualifiedName::Namespace::getAQualifierForMembers#f0820431#ff#prev(Lhs.0, Lhs.1)",
106+
" return r4"
107+
],
108+
"order_500000" : [
109+
" {2} r1 = JOIN QualifiedName::Namespace::getAQualifierForMembers#f0820431#ff#prev_delta WITH QualifiedName::Namespace::getAQualifierForMembers#f0820431#ff#join_rhs#1 ON FIRST 1 OUTPUT Rhs.1, Lhs.1",
110+
"",
111+
" {2} r2 = JOIN QualifiedName::Namespace::getAQualifierForMembers#f0820431#ff#prev_delta WITH namespacembrs ON FIRST 1 OUTPUT Rhs.1, Lhs.1",
112+
" {2} r3 = JOIN r2 WITH namespaces ON FIRST 1 OUTPUT Lhs.0, (Lhs.1 ++ \"::\" ++ Rhs.1)",
113+
"",
114+
" {2} r4 = r1 UNION r3",
115+
" {2} r5 = r4 AND NOT QualifiedName::Namespace::getAQualifierForMembers#f0820431#ff#prev(Lhs.0, Lhs.1)",
116+
" return r5"
117+
]
118+
},
119+
"pipelineRuns" : [ {
120+
"raReference" : "base"
121+
}, {
122+
"raReference" : "order_500000"
123+
} ]
124+
}

‎extensions/ql-vscode/test/pure-tests/log-summary-parser.test.ts‎

Lines changed: 42 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,42 @@
1+
import { expect } from 'chai';
2+
import * as fs from 'fs-extra';
3+
import * as path from 'path';
4+
import 'mocha';
5+
6+
import { parseVisualizerData } from '../../src/pure/log-summary-parser';
7+
8+
describe('Evaluator log summary tests', async function () {
9+
describe('for a valid summary text', async function () {
10+
it('should return only valid EvaluatorLogData objects', async function () {
11+
const validSummaryText = await fs.readFile(path.join(__dirname, 'evaluator-log-summaries/valid-summary.jsonl'), 'utf8');
12+
const logDataItems = parseVisualizerData(validSummaryText.toString());
13+
expect(logDataItems).to.not.be.undefined;
14+
expect (logDataItems.length).to.eq(3);
15+
for (const item of logDataItems) {
16+
expect(item.queryCausingWork).to.not.be.empty;
17+
expect(item.predicateName).to.not.be.empty;
18+
expect(item.millis).to.be.a('number');
19+
expect(item.resultSize).to.be.a('number');
20+
expect(item.ra).to.not.be.undefined;
21+
expect(item.ra).to.not.be.empty;
22+
for (const [pipeline, steps] of Object.entries(item.ra)) {
23+
expect (pipeline).to.not.be.empty;
24+
expect (steps).to.not.be.undefined;
25+
expect (steps.length).to.be.greaterThan(0);
26+
}
27+
}
28+
});
29+
30+
it('should not parse a summary header object', async function () {
31+
const invalidHeaderText = await fs.readFile(path.join(__dirname, 'evaluator-log-summaries/invalid-header.jsonl'), 'utf8');
32+
const logDataItems = parseVisualizerData(invalidHeaderText);
33+
expect (logDataItems.length).to.eq(0);
34+
});
35+
36+
it('should not parse a log event missing RA or millis fields', async function () {
37+
const invalidSummaryText = await fs.readFile(path.join(__dirname, 'evaluator-log-summaries/invalid-summary.jsonl'), 'utf8');
38+
const logDataItems = parseVisualizerData(invalidSummaryText);
39+
expect (logDataItems.length).to.eq(0);
40+
});
41+
});
42+
});

0 commit comments

Comments
 (0)