auto profiling telemetry tweak (#164259)

* auto profiling telemetry tweak

reuse the same code to send the telemetry data for
the renderer and the extension host

send telemetry event without annotated stacktraces
send fake error event with annotated stacktraces

* use fixed telemetry name and source to tell events apart, drop error log and send callers twice (annotated and not)

* piggy bag on the experiemental profiling setting and control extension host profile analysis by that
This commit is contained in:
Johannes Rieken
2022-10-21 20:12:39 +02:00
committed by GitHub
parent 61fc7e709b
commit 2ea3c8294f
3 changed files with 60 additions and 40 deletions
@@ -3,26 +3,60 @@
* Licensed under the MIT License. See License.txt in the project root for license information.
*--------------------------------------------------------------------------------------------*/
export type TelemetrySampleData = {
sessionId: string;
import { ILogService } from 'vs/platform/log/common/log';
import { BottomUpSample } from 'vs/platform/profiling/common/profilingModel';
import { ITelemetryService } from 'vs/platform/telemetry/common/telemetry';
type TelemetrySampleData = {
selfTime: number;
totalTime: number;
percentage: number;
perfBaseline: number;
functionName: string;
callstack: string;
extensionId: string;
callers: string;
callersAnnotated: string;
source: string;
};
export type TelemetrySampleDataClassification = {
type TelemetrySampleDataClassification = {
owner: 'jrieken';
comment: 'A callstack that took a long time to execute';
sessionId: { classification: 'SystemMetaData'; purpose: 'PerformanceAndHealth'; comment: 'Session identifier that allows to correlate samples from one profile' };
selfTime: { classification: 'SystemMetaData'; purpose: 'PerformanceAndHealth'; isMeasurement: true; comment: 'Self time of the sample' };
totalTime: { classification: 'SystemMetaData'; purpose: 'PerformanceAndHealth'; isMeasurement: true; comment: 'Total time of the sample' };
percentage: { classification: 'SystemMetaData'; purpose: 'PerformanceAndHealth'; isMeasurement: true; comment: 'Relative time (percentage) of the sample' };
perfBaseline: { classification: 'SystemMetaData'; purpose: 'PerformanceAndHealth'; isMeasurement: true; comment: 'Performance baseline for the machine' };
functionName: { classification: 'SystemMetaData'; purpose: 'PerformanceAndHealth'; comment: 'The name of the sample' };
callstack: { classification: 'CallstackOrException'; purpose: 'PerformanceAndHealth'; comment: 'The stacktrace leading into the sample' };
extensionId: { classification: 'SystemMetaData'; purpose: 'PerformanceAndHealth'; comment: 'The extension for the sample (iff applicable)' };
callers: { classification: 'CallstackOrException'; purpose: 'PerformanceAndHealth'; comment: 'The heaviest call trace into this sample' };
callersAnnotated: { classification: 'SystemMetaData'; purpose: 'PerformanceAndHealth'; comment: 'The heaviest call trace into this sample annotated with respective costs' };
source: { classification: 'SystemMetaData'; purpose: 'PerformanceAndHealth'; comment: 'The source - either renderer or an extension' };
};
export interface SampleData {
perfBaseline: number;
sample: BottomUpSample;
source: string;
}
export function reportSample(data: SampleData, telemetryService: ITelemetryService, logService: ILogService): void {
const { sample, perfBaseline, source } = data;
// log a fake error with a clearer stack
const fakeError = new Error(`[PerfSampleError]|${sample.selfTime}ms`);
fakeError.name = 'PerfSampleError';
fakeError.stack = `${fakeError.message} by ${data.source} in ${sample.location}\n` + sample.caller.map(c => `\t at ${c.location} (${c.percentage}%)`).join('\n');
logService.error(fakeError);
// send telemetry event
telemetryService.publicLog2<TelemetrySampleData, TelemetrySampleDataClassification>(`unresponsive.sample`, {
perfBaseline,
selfTime: sample.selfTime,
totalTime: sample.totalTime,
percentage: sample.percentage,
functionName: sample.location,
callers: sample.caller.map(c => c.location).join('<'),
callersAnnotated: sample.caller.map(c => `${c.percentage}|${c.location}`).join('<'),
source
});
}
@@ -13,7 +13,7 @@ import { join } from 'vs/base/common/path';
import { ITelemetryService } from 'vs/platform/telemetry/common/telemetry';
import { Utils } from 'vs/platform/profiling/common/profiling';
import { bottomUp, buildModel, } from 'vs/platform/profiling/common/profilingModel';
import { TelemetrySampleData, TelemetrySampleDataClassification } from 'vs/platform/profiling/common/profilingTelemetrySpec';
import { reportSample } from 'vs/platform/profiling/common/profilingTelemetrySpec';
import { onUnexpectedError } from 'vs/base/common/errors';
export const enum ProfilingOutput {
@@ -92,23 +92,11 @@ export class WindowProfiler {
// send telemetry events
for (const sample of samples) {
const data: TelemetrySampleData = {
sessionId: this._sessionId,
perfBaseline,
selfTime: sample.selfTime,
totalTime: sample.totalTime,
percentage: sample.percentage,
functionName: sample.location,
callstack: sample.caller.map(c => c.location).join('<'),
extensionId: '<<renderer>>'
};
this._telemetryService.publicLog2<TelemetrySampleData, TelemetrySampleDataClassification>('prof.freeze.sample', data);
// log a fake error with a clearer stack
const fakeError = new Error();
fakeError.name = 'PerfHeavyFunction';
fakeError.stack = `Spend ${sample.selfTime}ms in ${sample.location}\n` + sample.caller.map(c => `\t at ${c.location} (${c.percentage}%)`).join('\n');
this._logService.error(fakeError, `[perf] HEAVY function sample`);
reportSample(
{ sample, perfBaseline, source: '<<renderer>>' },
this._telemetryService,
this._logService
);
}
// save to disk
@@ -28,9 +28,10 @@ import { bottomUp, buildModel } from 'vs/platform/profiling/common/profilingMode
import { TernarySearchTree } from 'vs/base/common/ternarySearchTree';
import { Schemas } from 'vs/base/common/network';
import { URI } from 'vs/base/common/uri';
import { TelemetrySampleData, TelemetrySampleDataClassification } from 'vs/platform/profiling/common/profilingTelemetrySpec';
import { reportSample } from 'vs/platform/profiling/common/profilingTelemetrySpec';
import { generateUuid } from 'vs/base/common/uuid';
import { ITimerService } from 'vs/workbench/services/timer/browser/timerService';
import { IConfigurationService } from 'vs/platform/configuration/common/configuration';
export class ExtensionsAutoProfiler implements IWorkbenchContribution {
@@ -49,6 +50,7 @@ export class ExtensionsAutoProfiler implements IWorkbenchContribution {
@IEditorService private readonly _editorService: IEditorService,
@IInstantiationService private readonly _instantiationService: IInstantiationService,
@INativeWorkbenchEnvironmentService private readonly _environmentServie: INativeWorkbenchEnvironmentService,
@IConfigurationService private readonly _configService: IConfigurationService,
@IFileService private readonly _fileService: IFileService,
@ITimerService timerService: ITimerService
) {
@@ -201,19 +203,15 @@ export class ExtensionsAutoProfiler implements IWorkbenchContribution {
});
// send heavy samples
const samples = bottomUp(model, 5, false);
for (const sample of samples) {
const data: TelemetrySampleData = {
sessionId,
selfTime: sample.selfTime,
totalTime: sample.totalTime,
percentage: sample.percentage,
functionName: sample.location,
callstack: sample.caller.map(c => `${c.percentage}|${c.location}`).join('<'),
extensionId: searchTree.findSubstr(URI.parse(sample.url))?.identifier.value ?? '<not_extension>',
perfBaseline: this._perfBaseline,
};
this._telemetryService.publicLog2<TelemetrySampleData, TelemetrySampleDataClassification>('exthostunresponsive.sample', data);
if (this._configService.getValue('application.experimental.rendererProfiling')) {
const samples = bottomUp(model, 5, false);
for (const sample of samples) {
reportSample(
{ sample, perfBaseline: this._perfBaseline, source: searchTree.findSubstr(URI.parse(sample.url))?.identifier.value ?? '<<not-found>>' },
this._telemetryService,
this._logService
);
}
}
// add to running extensions view