Skip to content

Commit d494522

Browse files
authored
joh/super quelea (#163642)
* change how profiling sampling nodes are stringifyied so that they don't get confused as mail-address * re-enable renderer auto-profile * use/copy profiling model from https://github.com/microsoft/vscode-js-profile-visualizer extract heaviest call path from bottom up profile and submit as telemetry event
1 parent 5e8b680 commit d494522

File tree

4 files changed

+450
-135
lines changed

4 files changed

+450
-135
lines changed

src/vs/platform/profiling/common/profiling.ts

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -45,6 +45,10 @@ export interface IV8InspectProfilingService {
4545

4646
export namespace Utils {
4747

48+
export function isValidProfile(profile: IV8Profile): profile is Required<IV8Profile> {
49+
return Boolean(profile.samples && profile.timeDeltas);
50+
}
51+
4852
export function rewriteAbsolutePaths(profile: IV8Profile, replace: string = 'noAbsolutePaths') {
4953
for (const node of profile.nodes) {
5054
if (node.callFrame && node.callFrame.url) {

src/vs/platform/profiling/electron-main/windowProfiling.ts

Lines changed: 14 additions & 107 deletions
Original file line numberDiff line numberDiff line change
@@ -3,7 +3,7 @@
33
* Licensed under the MIT License. See License.txt in the project root for license information.
44
*--------------------------------------------------------------------------------------------*/
55

6-
import type { Profile, ProfileNode, ProfileResult } from 'v8-inspect-profiler';
6+
import type { Profile, ProfileResult } from 'v8-inspect-profiler';
77
import { BrowserWindow } from 'electron';
88
import { timeout } from 'vs/base/common/async';
99
import { DisposableStore, toDisposable } from 'vs/base/common/lifecycle';
@@ -13,12 +13,14 @@ import { tmpdir } from 'os';
1313
import { join } from 'vs/base/common/path';
1414
import { ITelemetryService } from 'vs/platform/telemetry/common/telemetry';
1515
import { Utils } from 'vs/platform/profiling/common/profiling';
16+
import { bottomUp, } from 'vs/platform/profiling/node/profilingModel';
1617

1718

1819
type TelemetrySampleData = {
1920
sessionId: string;
2021
selfTime: number;
2122
totalTime: number;
23+
percentage: number;
2224
functionName: string;
2325
callstack: string;
2426
};
@@ -27,44 +29,13 @@ type TelemetrySampleDataClassification = {
2729
owner: 'jrieken';
2830
comment: 'A callstack that took a long time to execute';
2931
sessionId: { classification: 'SystemMetaData'; purpose: 'PerformanceAndHealth'; comment: 'Session identifier that allows to correlate samples from one profile' };
30-
selfTime: { classification: 'SystemMetaData'; purpose: 'PerformanceAndHealth'; comment: 'Self time of the sample' };
31-
totalTime: { classification: 'SystemMetaData'; purpose: 'PerformanceAndHealth'; comment: 'Total time of the sample' };
32+
selfTime: { classification: 'SystemMetaData'; purpose: 'PerformanceAndHealth'; isMeasurement: true; comment: 'Self time of the sample' };
33+
totalTime: { classification: 'SystemMetaData'; purpose: 'PerformanceAndHealth'; isMeasurement: true; comment: 'Total time of the sample' };
34+
percentage: { classification: 'SystemMetaData'; purpose: 'PerformanceAndHealth'; isMeasurement: true; comment: 'Relative time (percentage) of the sample' };
3235
functionName: { classification: 'SystemMetaData'; purpose: 'PerformanceAndHealth'; comment: 'The name of the sample' };
3336
callstack: { classification: 'CallstackOrException'; purpose: 'PerformanceAndHealth'; comment: 'The stacktrace leading into the sample' };
3437
};
3538

36-
class Node {
37-
38-
// these are set later
39-
parent: Node | undefined;
40-
children: Node[] = [];
41-
selfTime: number = -1;
42-
totalTime: number = -1;
43-
44-
constructor(
45-
readonly node: ProfileNode,
46-
readonly callFrame: typeof node.callFrame,
47-
) {
48-
// noop
49-
}
50-
51-
toString() {
52-
return `${this.callFrame.url}#${this.callFrame.functionName}@${this.callFrame.lineNumber}:${this.callFrame.columnNumber}`;
53-
}
54-
55-
static makeTotals(call: Node) {
56-
if (call.totalTime !== -1) {
57-
return call.totalTime;
58-
}
59-
let result = call.selfTime;
60-
for (const child of call.children) {
61-
result += Node.makeTotals(child);
62-
}
63-
call.totalTime = result;
64-
return result;
65-
}
66-
}
67-
6839
export class WindowProfiler {
6940

7041
private _profileAtOrAfter: number = 0;
@@ -173,85 +144,21 @@ export class WindowProfiler {
173144
private _digest(profile: Profile): void {
174145
// https://chromedevtools.github.io/devtools-protocol/tot/Profiler/#type-Profile
175146

176-
if (!profile.samples || !profile.timeDeltas) {
147+
if (!Utils.isValidProfile(profile)) {
177148
this._logService.warn('[perf] INVALID profile: no samples or timeDeltas', this._sessionId);
178149
return;
179150
}
180151

181-
// PII removal - no absolute paths
182-
Utils.rewriteAbsolutePaths(profile, 'piiRemoved');
183-
184-
// create nodes
185-
const all = new Map<number, Node>();
186-
for (const node of profile.nodes) {
187-
all.set(node.id, new Node(node, node.callFrame));
188-
}
189-
190-
// set children/parents
191-
for (const node of profile.nodes) {
192-
if (node.children) {
193-
const parent = all.get(node.id)!;
194-
for (const id of node.children) {
195-
const child = all.get(id)!;
196-
parent.children.push(child);
197-
child.parent = parent;
198-
}
199-
}
200-
}
201-
202-
// SELF times
203-
const duration = (profile.endTime - profile.startTime);
204-
let lastNodeTime = duration - profile.timeDeltas[0];
205-
for (let i = 0; i < profile.samples.length - 1; i++) {
206-
const sample = profile.samples[i];
207-
const node = all.get(sample);
208-
if (node) {
209-
const duration = profile.timeDeltas[i + 1];
210-
node.selfTime += duration;
211-
lastNodeTime -= duration;
212-
}
213-
}
214-
const lastNode = all.get(profile.samples[profile.samples.length - 1]);
215-
if (lastNode) {
216-
lastNode.selfTime += lastNodeTime;
217-
}
218-
219-
// TOTAL times
220-
all.forEach(Node.makeTotals);
221-
222-
const sorted = Array.from(all.values()).sort((a, b) => b.selfTime - a.selfTime);
223-
224-
if (sorted[0].callFrame.functionName === '(idle)') {
225-
this._logService.warn('[perf] top stack is IDLE, ignoring this profile...', this._sessionId);
226-
this._telemetryService.publicLog2<TelemetrySampleData, TelemetrySampleDataClassification>('prof.sample', {
227-
sessionId: this._sessionId,
228-
selfTime: 0,
229-
totalTime: 0,
230-
functionName: '(idle)',
231-
callstack: ''
232-
});
233-
return;
234-
}
235-
236-
for (let i = 0; i < sorted.length; i++) {
237-
if (i > 4) {
238-
// report top 5
239-
break;
240-
}
241-
const node = sorted[i];
242-
const callstack: string[] = [];
243-
let candidate: Node | undefined = node;
244-
while (candidate) {
245-
callstack.push(candidate.toString());
246-
candidate = candidate.parent;
247-
}
152+
const samples = bottomUp(profile, 5, false);
248153

154+
for (const sample of samples) {
249155
const data: TelemetrySampleData = {
250156
sessionId: this._sessionId,
251-
selfTime: node.selfTime / 1000,
252-
totalTime: node.totalTime / 1000,
253-
functionName: node.callFrame.functionName,
254-
callstack: callstack.join('\n')
157+
selfTime: sample.selfTime,
158+
totalTime: sample.totalTime,
159+
percentage: sample.percentage,
160+
functionName: sample.location,
161+
callstack: sample.caller.map(c => `${c.percentage}|${c.location}`).join('<')
255162
};
256163
this._telemetryService.publicLog2<TelemetrySampleData, TelemetrySampleDataClassification>('prof.freeze.sample', data);
257164
}

0 commit comments

Comments
 (0)