Skip to content

Commit

Permalink
tweaks to perf telemetry (#10363)
Browse files Browse the repository at this point in the history
  • Loading branch information
@eanders-ms
eanders-ms authored Jan 30, 2025
1 parent c4ab93c commit 2648d89
Show file tree
Hide file tree
Showing 8 changed files with 61 additions and 57 deletions.
86 changes: 40 additions & 46 deletions docfiles/pxtweb/cookieCompliance.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -38,17 +38,21 @@ namespace pxt {
let eventLogger: TelemetryQueue<string, Map<string>, Map<number>>;
let exceptionLogger: TelemetryQueue<any, string, Map<string>>;

type EventListener<T = any> = (payload: T) => void;
type EventListener<T = any> = (ev: T) => void;
type EventSource<T> = {
subscribe(listener: (payload: T) => void): () => void;
emit(payload: T): void;
subscribe(listener: (ev: T) => void): () => void;
emit(ev: T): void;
forEach(callback: (ev: T) => void): void;
};

function createEventSource<T = any>(): EventSource<T> {
function createEventSource<T = any>(filter?: ((ev: T) => boolean)): EventSource<T> {
filter = filter || (() => true);
const listeners: EventListener<T>[] = [];
const eventCache: T[] = [];

return {
subscribe(listener: EventListener<T>): () => void {
eventCache.forEach(ev => filter(ev) && listener(ev));
listeners.push(listener);
// Return an unsubscribe function
return () => {
Expand All @@ -58,8 +62,12 @@ namespace pxt {
}
};
},
emit(payload: T): void {
listeners.forEach(listener => listener(payload));
emit(ev: T): void {
eventCache.push(ev);
if (filter(ev)) listeners.forEach(listener => listener(ev));
},
forEach(callback: (ev: T) => void): void {
eventCache.forEach(ev => filter(ev) && callback(ev));
}
};
}
Expand All @@ -68,18 +76,14 @@ namespace pxt {
export namespace perf {
let enabled: boolean;

export const onMilestone = createEventSource<{ milestone: string, time: number, params?: Map<string> }>();
export const onMeasurement = createEventSource<{ name: string, start: number, duration: number, params?: Map<string> }>();

export let startTimeMs: number;
export let measurementThresholdMs = 10;
export let stats: {
// name, start, duration, params
durations: [string, number, number, Map<string>?][],
// name, event
milestones: [string, number, Map<string>?][]
durations: EventSource<{ name: string, start: number, duration: number, params?: Map<string> }>,
milestones: EventSource<{ milestone: string, time: number, params?: Map<string> }>,
} = {
durations: [],
milestones: []
durations: createEventSource((ev) => ev.duration >= measurementThresholdMs),
milestones: createEventSource(),
}
export function isEnabled() { return enabled; }
export let perfReportLogged = false
Expand Down Expand Up @@ -107,8 +111,7 @@ namespace pxt {

export function recordMilestone(msg: string, params?: Map<string>) {
const time = splitMs()
stats.milestones.push([msg, time, params])
onMilestone.emit({ milestone: msg, time, params });
stats.milestones.emit({ milestone: msg, time, params });
}
export function init() {
enabled = performance && !!performance.mark && !!performance.measure;
Expand All @@ -129,17 +132,14 @@ namespace pxt {
if (e && e.length === 1) {
let measure = e[0]
let durMs = measure.duration
if (durMs > 10) {
stats.durations.push([name, measure.startTime, durMs, params])
onMeasurement.emit({ name, start: measure.startTime, duration: durMs, params });
}
stats.durations.emit({ name, start: measure.startTime, duration: durMs, params });
}
performance.clearMarks(`${name} start`)
performance.clearMarks(`${name} end`)
performance.clearMeasures(`${name} elapsed`)
}
}
export function report(filter: string = null) {
export function report() {
perfReportLogged = true;
if (enabled) {
const milestones: { [index: string]: number } = {};
Expand All @@ -148,35 +148,29 @@ namespace pxt {
let report = `Performance Report:\n`
report += `\n`
report += `\tMilestones:\n`
for (let [msg, time, params] of stats.milestones) {
if (!filter || msg.indexOf(filter) >= 0) {
let pretty = prettyStr(time)
report += `\t\t${msg} @ ${pretty}`
for (let k of Object.keys(params || {})) {
report += `\n\t\t\t${k}: ${params[k]}`
}
report += `\n`
milestones[msg] = time;
stats.milestones.forEach(({ milestone, time, params }) => {
let pretty = prettyStr(time)
report += `\t\t${milestone} @ ${pretty}`
for (let k of Object.keys(params || {})) {
report += `\n\t\t\t${k}: ${params[k]}`
}
}
report += `\n`
milestones[milestone] = time;
});

report += `\n`
report += `\tMeasurements:\n`
for (let [msg, start, duration, params] of stats.durations) {
let filterIncl = filter && msg.indexOf(filter) >= 0
if ((duration > 50 && !filter) || filterIncl) {
let pretty = prettyStr(duration)
report += `\t\t${msg} took ~ ${pretty}`
if (duration > 1000) {
report += ` (${prettyStr(start)} - ${prettyStr(start + duration)})`
for (let k of Object.keys(params || {})) {
report += `\n\t\t\t${k}: ${params[k]}`
}
}
report += `\n`
stats.durations.forEach(({ name, start, duration, params }) => {
let pretty = prettyStr(duration)
report += `\t\t${name} took ~ ${pretty}`
report += ` (${prettyStr(start)} - ${prettyStr(start + duration)})`
for (let k of Object.keys(params || {})) {
report += `\n\t\t\t${k}: ${params[k]}`
}
durations[msg] = duration;
}
report += `\n`
durations[name] = duration;
});

console.log(report)
enabled = false; // stop collecting milestones and measurements after report
return { milestones, durations };
Expand Down
1 change: 1 addition & 0 deletions localtypings/pxteditor.d.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -1146,6 +1146,7 @@ declare namespace pxt.editor {
webUsbPairDialogAsync?: (pairAsync: () => Promise<boolean>, confirmAsync: (options: any) => Promise<number>) => Promise<number>;
mkPacketIOWrapper?: (io: pxt.packetio.PacketIO) => pxt.packetio.PacketIOWrapper;
onPostHostMessage?: (msg: pxt.editor.EditorMessageRequest) => void;
perfMeasurementThresholdMs?: number;
onPerfMilestone?: (payload: { milestone: string, time: number, params?: Map<string> }) => void;
onPerfMeasurement?: (payload: { name: string, start: number, duration: number, params?: Map<string> }) => void;

Expand Down
2 changes: 1 addition & 1 deletion pxteditor/editorcontroller.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -439,7 +439,7 @@ export function postHostMessageAsync(msg: pxt.editor.EditorMessageRequest): Prom
// Note this is a one-way notification. Responses are not supported.
if (pxt.commands.onPostHostMessage) {
try {
pxt.commands.onPostHostMessage(msg);
pxt.commands.onPostHostMessage(env);
} catch (err) {
pxt.reportException(err);
}
Expand Down
1 change: 1 addition & 0 deletions pxtlib/cmds.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -39,6 +39,7 @@ namespace pxt.commands {
export let webUsbPairDialogAsync: (pairAsync: () => Promise<boolean>, confirmAsync: (options: any) => Promise<WebUSBPairResult>, implicitlyCalled?: boolean) => Promise<WebUSBPairResult> = undefined;
export let onTutorialCompleted: () => void = undefined;
export let onPostHostMessage: (msg: any /*pxt.editor.EditorMessageRequest*/) => void;
export let perfMeasurementThresholdMs: number = undefined;
export let onPerfMilestone: (payload: { milestone: string, time: number, params?: Map<string> }) => void = undefined;
export let onPerfMeasurement: (payload: { name: string, start: number, duration: number, params?: Map<string> }) => void = undefined;
export let workspaceLoadedAsync: () => Promise<void> = undefined;
Expand Down
12 changes: 8 additions & 4 deletions pxtlib/main.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -8,8 +8,9 @@

namespace pxt.perf {
export type EventSource<T> = {
subscribe(listener: (payload: T) => void): () => void;
//emit(payload: T): void; // not used externally
subscribe(listener: (ev: T) => void): () => void;
//emit(ev: T): void; // not used externally
//forEach(listener: (ev: T) => void): void; // not used externally
};

// These functions are defined in docfiles/pxtweb/cookieCompliance.ts
Expand All @@ -19,8 +20,11 @@ namespace pxt.perf {
export declare function recordMilestone(msg: string, params?: Map<string>): void;
export declare function measureStart(name: string): void;
export declare function measureEnd(name: string, params?: Map<string>): void;
export declare const onMilestone: EventSource<{ milestone: string, time: number, params?: Map<string> }>;
export declare const onMeasurement: EventSource<{ name: string, start: number, duration: number, params?: Map<string> }>;
export declare let measurementThresholdMs: number;
export declare const stats: {
milestones: EventSource<{ milestone: string, time: number, params?: Map<string> }>;
durations: EventSource<{ name: string, start: number, duration: number, params?: Map<string> }>;
};
}
(function () {
// Sometimes these aren't initialized, for example in tests. We only care about them
Expand Down
12 changes: 8 additions & 4 deletions webapp/src/app.tsx
View file
Original file line number Diff line number Diff line change
Expand Up @@ -2774,7 +2774,7 @@ export class ProjectView
}

private editorLoaded() {
pxt.tickEvent('app.editor');
pxt.tickEvent('app.editor', { projectHeaderId: this.state.header?.id });
}

unloadProjectAsync(home?: boolean) {
Expand Down Expand Up @@ -4982,7 +4982,8 @@ export class ProjectView
this.postTutorialLoaded();
}

pxt.perf.recordMilestone(Milestones.EditorContentLoaded);
pxt.perf.recordMilestone(Milestones.EditorContentLoaded, { projectHeaderId: this.state.header?.id });

if (!this.autoRunOnStart()) {
pxt.analytics.trackPerformanceReport();
}
Expand Down Expand Up @@ -5893,11 +5894,14 @@ function initExtensionsAsync(): Promise<void> {
monacoToolbox.overrideToolbox(res.toolboxOptions.monacoToolbox);
}
}
if (typeof res.perfMeasurementThresholdMs === "number") {
pxt.perf.measurementThresholdMs = res.perfMeasurementThresholdMs;
}
if (res.onPerfMilestone) {
pxt.perf.onMilestone.subscribe(res.onPerfMilestone);
pxt.perf.stats.milestones.subscribe(res.onPerfMilestone);
}
if (res.onPerfMeasurement) {
pxt.perf.onMeasurement.subscribe(res.onPerfMeasurement);
pxt.perf.stats.durations.subscribe(res.onPerfMeasurement);
}
cmds.setExtensionResult(res);
});
Expand Down
2 changes: 1 addition & 1 deletion webapp/src/blocks.tsx
View file
Original file line number Diff line number Diff line change
Expand Up @@ -236,7 +236,7 @@ export class Editor extends toolboxeditor.ToolboxEditor {
} catch { }
this.loadingXml = false;
this.loadingXmlPromise = null;
pxt.perf.measureEnd(Measurements.DomUpdateLoadBlockly)
pxt.perf.measureEnd(Measurements.DomUpdateLoadBlockly, { projectHeaderId: this.parent.state.header?.id });
// Do Not Remove: This is used by the skillmap
this.parent.onEditorContentLoaded();
});
Expand Down
2 changes: 1 addition & 1 deletion webapp/src/projects.tsx
View file
Original file line number Diff line number Diff line change
Expand Up @@ -90,7 +90,7 @@ export class Projects extends auth.Component<ISettingsProps, ProjectsState> {
}

chgHeader(hdr: pxt.workspace.Header) {
pxt.tickEvent("projects.header");
pxt.tickEvent("projects.header", { projectHeaderId: hdr?.id });
core.showLoading("changeheader", lf("loading..."));
this.props.parent.loadHeaderAsync(hdr)
.catch(e => {
Expand Down

0 comments on commit 2648d89

Please sign in to comment.