Skip to content

Commit fea1a83

Browse files
XeteraXetera
committed
better debugging
1 parent 21ae511 commit fea1a83

File tree

5 files changed

+125
-155
lines changed

5 files changed

+125
-155
lines changed

‎bootstrap.sql‎

Lines changed: 0 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -126,8 +126,6 @@ ALTER TABLE public.guest_ip_addresses ALTER COLUMN id ADD GENERATED BY DEFAULT A
126126
CACHE 1
127127
);
128128

129-
insert into guest_ip_addresses (guest_id, ip_address) values (1, '127.0.0.1');
130-
131129

132130
--
133131
-- Name: guests; Type: TABLE; Schema: public; Owner: postgres
@@ -185,13 +183,6 @@ INSERT INTO public.assets VALUES (5, 'video', 1, 3, 4, '/images/thatslife.mov',
185183
INSERT INTO public.events VALUES (1, '01JKCVP4M2CH34SVTQGHSW4Y5G', 'test event', 'Test', '/images/banner.jpg', '2025-06-25 14:30:42.758+00', '2026-06-26 14:30:42.758+00', NULL, NULL, NULL, NULL, '## Hello', '2025-06-26 14:30:42.82511+00', '2025-06-26 14:30:42.759+00');
186184
INSERT INTO public.events VALUES (2, '00JKCVP4M2CH34SVTQGHSW4Y5G', 'expired event', 'sey olmus event', NULL, '2025-06-19 14:30:42.758+00', '2025-06-25 14:30:42.758+00', NULL, NULL, 'Test', 'testing', NULL, '2025-06-26 14:30:42.848842+00', '2025-06-26 14:30:42.845+00');
187185

188-
189-
--
190-
-- Data for Name: guest_ip_addresses; Type: TABLE DATA; Schema: public; Owner: postgres
191-
--
192-
193-
194-
195186
--
196187
-- Data for Name: guests; Type: TABLE DATA; Schema: public; Owner: postgres
197188
--

‎main.ts‎

Lines changed: 118 additions & 111 deletions
Original file line numberDiff line numberDiff line change
@@ -31,30 +31,37 @@ async function main() {
3131
}
3232
const startDate = new Date();
3333
const fileSize = Deno.statSync(logPath).size;
34+
console.log(`logPath=${logPath},fileSize=${fileSize}`);
3435
// core.setOutput("time", new Date().toLocaleTimeString());
36+
const args = [
37+
"--dump-raw-csv",
38+
"--no-progressbar",
39+
"-f",
40+
"stderr",
41+
// "--begin",
42+
// "2025-06-24 10:00:00",
43+
logPath,
44+
];
3545
const command = new Deno.Command("pgbadger", {
3646
stdout: "piped",
3747
stderr: "piped",
38-
args: [
39-
"--dump-raw-csv",
40-
"--no-progressbar",
41-
// "--begin",
42-
// "2025-06-24 10:00:00",
43-
logPath,
44-
],
48+
args,
4549
});
50+
console.log(`pgbadger ${args.join(" ")}`);
4651
const output = command.spawn();
4752
output.stderr.pipeTo(Deno.stderr.writable);
53+
let error: Error | undefined;
4854
const stream = csv
4955
.parseStream(Readable.from(output.stdout), {
5056
headers: false,
5157
})
5258
.on("error", (err) => {
53-
console.error(err);
59+
error = err;
5460
});
5561

5662
const seenQueries = new Set<number>();
5763
const recommendations: ReportIndexRecommendation[] = [];
64+
let allQueries = 0;
5865
let matching = 0;
5966
const pg = postgres(postgresUrl);
6067
const stats = new Statistics(pg);
@@ -75,16 +82,16 @@ async function main() {
7582
loglevel,
7683
_sqlstate,
7784
_duration,
78-
query,
85+
queryString,
7986
_parameters,
8087
_appname,
8188
_backendtype,
8289
_queryid,
8390
] = chunk as string[];
84-
if (loglevel !== "LOG" || !query.startsWith("plan:")) {
91+
if (loglevel !== "LOG" || !queryString.startsWith("plan:")) {
8592
continue;
8693
}
87-
const plan: string = query.split("plan:")[1].trim();
94+
const plan: string = queryString.split("plan:")[1].trim();
8895
let isJSONOutput = false;
8996
let i = 0;
9097
for (; i < plan.length; i++) {
@@ -99,120 +106,120 @@ async function main() {
99106
break;
100107
}
101108
}
102-
if (isJSONOutput) {
103-
const json = plan
104-
.slice(i)
105-
.replace(/\\n/g, "\n")
106-
// there are random control characters in the json lol
107-
// deno-lint-ignore no-control-regex
108-
.replace(/[\u0000-\u001F]+/g, (c) =>
109-
c === "\n" ? "\\n" : c === "\r" ? "\\r" : c === "\t" ? "\\t" : ""
110-
);
111-
let parsed: any;
112-
try {
113-
parsed = JSON.parse(json);
114-
} catch (e) {
115-
console.log(e);
116-
break;
117-
}
118-
const queryFingerprint = await fingerprint(parsed["Query Text"]);
119-
if (
120-
parsed.Plan["Node Type"] === "ModifyTable" ||
121-
// we get some infinite loops in development here
122-
parsed["Query Text"].includes("pg_catalog") ||
123-
parsed["Query Text"].includes("@qd_introspection")
124-
) {
125-
continue;
126-
}
127-
const fingerprintNum = parseInt(queryFingerprint, 16);
128-
if (seenQueries.has(fingerprintNum)) {
129-
console.log("Skipping duplicate query", fingerprintNum);
130-
continue;
131-
}
132-
seenQueries.add(fingerprintNum);
133-
const query = parsed["Query Text"];
134-
const rawParams = parsed["Query Parameters"];
135-
const params = rawParams ? extractParams(rawParams) : [];
136-
const analyzer = new Analyzer();
109+
if (!isJSONOutput) {
110+
return;
111+
}
112+
const json = plan
113+
.slice(i)
114+
.replace(/\\n/g, "\n")
115+
// there are random control characters in the json lol
116+
// deno-lint-ignore no-control-regex
117+
.replace(/[\u0000-\u001F]+/g, (c) =>
118+
c === "\n" ? "\\n" : c === "\r" ? "\\r" : c === "\t" ? "\\t" : ""
119+
);
120+
let parsed: any;
121+
try {
122+
parsed = JSON.parse(json);
123+
} catch (e) {
124+
console.log(e);
125+
break;
126+
}
127+
allQueries++;
128+
const queryFingerprint = await fingerprint(parsed["Query Text"]);
129+
if (
130+
// TODO: we can support inserts/updates too. Just need the right optimization for it.
131+
parsed.Plan["Node Type"] === "ModifyTable" ||
132+
parsed["Query Text"].includes("@qd_introspection")
133+
) {
134+
continue;
135+
}
136+
const fingerprintNum = parseInt(queryFingerprint, 16);
137+
if (seenQueries.has(fingerprintNum)) {
138+
console.log("Skipping duplicate query", fingerprintNum);
139+
continue;
140+
}
141+
seenQueries.add(fingerprintNum);
142+
const query = parsed["Query Text"];
143+
const rawParams = parsed["Query Parameters"];
144+
const params = rawParams ? extractParams(rawParams) : [];
145+
const analyzer = new Analyzer();
137146

138-
const { indexesToCheck, ansiHighlightedQuery, referencedTables } =
139-
await analyzer.analyze(formatQuery(query), params);
147+
const { indexesToCheck, ansiHighlightedQuery, referencedTables } =
148+
await analyzer.analyze(formatQuery(query), params);
140149

141-
const selectsCatalog = referencedTables.find((table) =>
142-
table.startsWith("pg_")
150+
const selectsCatalog = referencedTables.find((table) =>
151+
table.startsWith("pg_")
152+
);
153+
if (selectsCatalog) {
154+
console.log(
155+
"Skipping query that selects from catalog tables",
156+
selectsCatalog,
157+
fingerprintNum
143158
);
144-
if (selectsCatalog) {
145-
console.log(
146-
"Skipping query that selects from catalog tables",
147-
selectsCatalog,
148-
fingerprintNum
149-
);
150-
continue;
151-
}
152-
const indexCandidates = analyzer.deriveIndexes(tables, indexesToCheck);
153-
if (indexCandidates.length > 0) {
154-
await core.group(`query:${fingerprintNum}`, async () => {
155-
console.time(`timing`);
156-
matching++;
157-
printLegend();
158-
console.log(ansiHighlightedQuery);
159-
const out = await optimizer.run(
160-
query,
161-
params,
162-
indexCandidates,
163-
tables
164-
);
165-
if (out.newIndexes.size > 0) {
166-
const newIndexes = Array.from(out.newIndexes)
167-
.map((n) => out.triedIndexes.get(n)?.definition)
168-
.filter((n) => n !== undefined);
169-
const existingIndexesForQuery = Array.from(out.existingIndexes)
170-
.map((index) => {
171-
const existing = existingIndexes.find(
172-
(e) => e.index_name === index
173-
);
174-
if (existing) {
175-
return `${existing.schema_name}.${
176-
existing.table_name
177-
}(${existing.index_columns
178-
.map((c) => `"${c.name}" ${c.order}`)
179-
.join(", ")})`;
180-
}
181-
})
182-
.filter((i) => i !== undefined);
183-
console.log(dedent`
184-
Optimized cost from ${out.baseCost} to ${out.finalCost}
185-
Existing indexes: ${Array.from(out.existingIndexes).join(", ")}
186-
New indexes: ${newIndexes.join(", ")}
187-
`);
188-
recommendations.push({
189-
formattedQuery: formatQuery(query),
190-
baseCost: out.baseCost,
191-
optimizedCost: out.finalCost,
192-
existingIndexes: existingIndexesForQuery,
193-
proposedIndexes: newIndexes,
194-
explainPlan: out.explainPlan,
195-
});
196-
} else {
197-
console.log("No new indexes found");
198-
}
199-
console.timeEnd(`timing`);
200-
});
201-
}
159+
continue;
160+
}
161+
console.log(query);
162+
const indexCandidates = analyzer.deriveIndexes(tables, indexesToCheck);
163+
if (indexCandidates.length > 0) {
164+
await core.group(`query:${fingerprintNum}`, async () => {
165+
console.time(`timing`);
166+
matching++;
167+
printLegend();
168+
console.log(ansiHighlightedQuery);
169+
const out = await optimizer.run(query, params, indexCandidates, tables);
170+
if (out.newIndexes.size > 0) {
171+
const newIndexes = Array.from(out.newIndexes)
172+
.map((n) => out.triedIndexes.get(n)?.definition)
173+
.filter((n) => n !== undefined);
174+
const existingIndexesForQuery = Array.from(out.existingIndexes)
175+
.map((index) => {
176+
const existing = existingIndexes.find(
177+
(e) => e.index_name === index
178+
);
179+
if (existing) {
180+
return `${existing.schema_name}.${
181+
existing.table_name
182+
}(${existing.index_columns
183+
.map((c) => `"${c.name}" ${c.order}`)
184+
.join(", ")})`;
185+
}
186+
})
187+
.filter((i) => i !== undefined);
188+
console.log(dedent`
189+
Optimized cost from ${out.baseCost} to ${out.finalCost}
190+
Existing indexes: ${Array.from(out.existingIndexes).join(", ")}
191+
New indexes: ${newIndexes.join(", ")}
192+
`);
193+
recommendations.push({
194+
formattedQuery: formatQuery(query),
195+
baseCost: out.baseCost,
196+
optimizedCost: out.finalCost,
197+
existingIndexes: existingIndexesForQuery,
198+
proposedIndexes: newIndexes,
199+
explainPlan: out.explainPlan,
200+
});
201+
} else {
202+
console.log("No new indexes found");
203+
}
204+
console.timeEnd(`timing`);
205+
});
202206
}
203207
}
208+
await output.status;
209+
console.log(`Matched ${matching} queries out of ${allQueries}`);
210+
// output.unref();
204211
const reporter = new GithubReporter(process.env.GITHUB_TOKEN);
205212
await reporter.report({
206213
recommendations,
207-
queriesLookedAt: seenQueries.size,
214+
queriesLookedAt: matching,
215+
totalQueries: allQueries,
216+
error,
208217
metadata: {
209218
logSize: fileSize,
210219
timeElapsed: Date.now() - startDate.getTime(),
211220
},
212221
});
213222
console.timeEnd("total");
214-
await output.status;
215-
console.log(`Ran ${matching} queries`);
216223
Deno.exit(0);
217224
}
218225

‎main_test.ts‎

Lines changed: 1 addition & 31 deletions
Original file line numberDiff line numberDiff line change
@@ -97,29 +97,8 @@ Deno.test(async function analyzer() {
9797
query1,
9898
[]
9999
);
100-
// printLegend();
101-
// console.log(ansiHighlightedQuery);
102-
// console.log(indexesToCheck);
103-
// console.log(indexesToCheck);
104-
// assertEquals(
105-
// indexesToCheck,
106-
// new Set([
107-
// ["avg_salary"],
108-
// ["audits", "result"],
109-
// ["audits", "department_id"],
110-
// ["employees", "department_id"],
111-
// ["projects", "department_id"],
112-
// ["projects", "status"],
113-
// ["projects", "budget"],
114-
// ["departments", "name"],
115-
// ["departments", "id"],
116-
// ["employees", "id"],
117-
// ["employees", "manager_id"],
118-
// ["employees", "name"],
119-
// ["manager_id"],
120-
// ])
121-
// );
122100
});
101+
123102
Deno.test(async function analyzer2() {
124103
const analyzer = new Analyzer();
125104
const query2 = await Deno.readTextFile("./test/query-2.sql");
@@ -152,12 +131,3 @@ Deno.test(async function analyzer2() {
152131
Deno.test(async function analyzer() {
153132
//
154133
});
155-
156-
function printLegend() {
157-
console.log(`--Legend--------------------------`);
158-
console.log(`| \x1b[48;5;205m column \x1b[0m | Candidate |`);
159-
console.log(`| \x1b[33m column \x1b[0m | Ignored |`);
160-
console.log(`| \x1b[34m column \x1b[0m | Temp table reference |`);
161-
console.log(`-----------------------------------`);
162-
console.log();
163-
}

‎optimizer/genalgo.ts‎

Lines changed: 0 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1,7 +1,5 @@
11
import postgres from "postgresjs";
2-
import * as core from "@actions/core";
32
import { IndexedTable, TableMetadata } from "./statistics.ts";
4-
import dedent from "dedent";
53

64
type IndexRecommendation = PermutedIndexCandidate & {
75
definition: string;

‎reporters/github.ts‎

Lines changed: 6 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -13,11 +13,11 @@ export class GithubReporter {
1313

1414
async report(ctx: ReportContext) {
1515
if (typeof this.prNumber === "undefined") {
16-
console.warn(`Not a PR, skipping report...`);
16+
console.log(`Not a PR, skipping report...`);
1717
return;
1818
}
1919
if (!this.githubToken) {
20-
console.warn(`No GitHub token provided, skipping report...`);
20+
console.log(`No GitHub token provided, skipping report...`);
2121
return;
2222
}
2323
const octokit = github.getOctokit(this.githubToken);
@@ -108,6 +108,8 @@ export class GithubReporter {
108108
`<dd>${ctx.metadata.timeElapsed}ms</dd>`,
109109
"<dt>Queries processed</dt>",
110110
`<dd>${ctx.queriesLookedAt}</dd>`,
111+
"<dt>Total queries found</dt>",
112+
`<dd>${ctx.totalQueries}</dd>`,
111113
"</dl>",
112114
"</details>",
113115
].join("\n");
@@ -155,6 +157,8 @@ export type ReportContext = {
155157
recommendations: ReportIndexRecommendation[];
156158
metadata: ReportMetadata;
157159
queriesLookedAt: number;
160+
totalQueries: number;
161+
error?: Error;
158162
};
159163

160164
export type ReportIndexRecommendation = {

0 commit comments

Comments
 (0)