Skip to content

Metrics tracking launch times for native locator #23854

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 3 commits into from
Jul 23, 2024
Merged

Metrics tracking launch times for native locator #23854

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
11cded1
Metrics tracking launch times for native locator
DonJayamanne Jul 23, 2024
0fa7951
add comments
DonJayamanne Jul 23, 2024
d3dd360
misc
DonJayamanne Jul 23, 2024
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
21 changes: 19 additions & 2 deletions src/client/pythonEnvironments/base/locators/common/nativePythonFinder.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -20,6 +20,7 @@ import { createLogOutputChannel } from '../../../../common/vscodeApis/windowApis
import { sendNativeTelemetry, NativePythonTelemetry } from './nativePythonTelemetry';
import { NativePythonEnvironmentKind } from './nativePythonUtils';
import type { IExtensionContext } from '../../../../common/types';
import { StopWatch } from '../../../../common/utils/stopWatch';

const untildify = require('untildify');

Expand Down Expand Up @@ -100,6 +101,12 @@ class NativePythonFinderImpl extends DisposableBase implements NativePythonFinde

private readonly outputChannel = this._register(createLogOutputChannel('Python Locator', { log: true }));

private initialRefreshMetrics = {
timeToSpawn: 0,
timeToConfigure: 0,
timeToRefresh: 0,
};

constructor(private readonly cacheDirectory?: Uri) {
super();
this.connection = this.start();
Expand Down Expand Up @@ -199,7 +206,9 @@ class NativePythonFinderImpl extends DisposableBase implements NativePythonFinde
const writable = new PassThrough();
const disposables: Disposable[] = [];
try {
const stopWatch = new StopWatch();
const proc = ch.spawn(PYTHON_ENV_TOOLS_PATH, ['server'], { env: process.env });
this.initialRefreshMetrics.timeToSpawn = stopWatch.elapsedTime;
proc.stdout.pipe(readable, { end: false });
proc.stderr.on('data', (data) => this.outputChannel.error(data.toString()));
writable.pipe(proc.stdin, { end: false });
Expand Down Expand Up @@ -251,7 +260,9 @@ class NativePythonFinderImpl extends DisposableBase implements NativePythonFinde
this.outputChannel.trace(data.message);
}
}),
connection.onNotification('telemetry', (data: NativePythonTelemetry) => sendNativeTelemetry(data)),
connection.onNotification('telemetry', (data: NativePythonTelemetry) =>
sendNativeTelemetry(data, this.initialRefreshMetrics),
),
connection.onClose(() => {
disposables.forEach((d) => d.dispose());
}),
Expand All @@ -269,6 +280,7 @@ class NativePythonFinderImpl extends DisposableBase implements NativePythonFinde
const discovered = disposable.add(new EventEmitter<NativeEnvInfo | NativeEnvManagerInfo>());
const completed = createDeferred<void>();
const pendingPromises: Promise<void>[] = [];
const stopWatch = new StopWatch();

const notifyUponCompletion = () => {
const initialCount = pendingPromises.length;
Expand Down Expand Up @@ -339,7 +351,10 @@ class NativePythonFinderImpl extends DisposableBase implements NativePythonFinde
this.configure().then(() =>
this.connection
.sendRequest<{ duration: number }>('refresh', refreshOptions)
.then(({ duration }) => this.outputChannel.info(`Refresh completed in ${duration}ms`))
.then(({ duration }) => {
this.outputChannel.info(`Refresh completed in ${duration}ms`);
this.initialRefreshMetrics.timeToRefresh = stopWatch.elapsedTime;
})
.catch((ex) => this.outputChannel.error('Refresh error', ex)),
),
);
Expand Down Expand Up @@ -371,8 +386,10 @@ class NativePythonFinderImpl extends DisposableBase implements NativePythonFinde
return;
}
try {
const stopWatch = new StopWatch();
this.lastConfiguration = options;
await this.connection.sendRequest('configure', options);
this.initialRefreshMetrics.timeToConfigure = stopWatch.elapsedTime;
} catch (ex) {
this.outputChannel.error('Refresh error', ex);
}
Expand Down
12 changes: 11 additions & 1 deletion src/client/pythonEnvironments/base/locators/common/nativePythonTelemetry.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -81,7 +81,14 @@ export type RefreshPerformance = {

let refreshTelemetrySent = false;

export function sendNativeTelemetry(data: NativePythonTelemetry): void {
export function sendNativeTelemetry(
data: NativePythonTelemetry,
initialRefreshMetrics: {
timeToSpawn: number;
timeToConfigure: number;
timeToRefresh: number;
},
): void {
switch (data.event) {
case 'MissingCondaEnvironments': {
sendTelemetryEvent(
Expand Down Expand Up @@ -124,6 +131,9 @@ export function sendNativeTelemetry(data: NativePythonTelemetry): void {
locatorVirtualEnvWrapper: data.data.refreshPerformance.locators.VirtualEnvWrapper || 0,
locatorWindowsRegistry: data.data.refreshPerformance.locators.WindowsRegistry || 0,
locatorWindowsStore: data.data.refreshPerformance.locators.WindowsStore || 0,
timeToSpawn: initialRefreshMetrics.timeToSpawn,
timeToConfigure: initialRefreshMetrics.timeToConfigure,
timeToRefresh: initialRefreshMetrics.timeToRefresh,
});
break;
}
Expand Down
77 changes: 75 additions & 2 deletions src/client/telemetry/index.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -1755,38 +1755,111 @@ export interface IEventNamePropertyMapping {
"locatorVirtualEnv" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true, "owner": "donjayamanne" },
"locatorVirtualEnvWrapper" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true, "owner": "donjayamanne" },
"locatorWindowsRegistry" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true, "owner": "donjayamanne" },
"locatorWindowsStore" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true, "owner": "donjayamanne" }
"locatorWindowsStore" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true, "owner": "donjayamanne" },
"timeToSpawn" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true, "owner": "donjayamanne" },
"timeToConfigure" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true, "owner": "donjayamanne" },
"timeToRefresh" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true, "owner": "donjayamanne" }
}
*/
[EventName.NATIVE_FINDER_PERF]: {
/**
* Total duration to find envs using native locator.
* This is the time from the perspective of the Native Locator.
* I.e. starting from the time the request to refresh was received until the end of the refresh.
*/
duration: number;
/**
* Time taken by all locators to find the environments.
* I.e. time for Conda + Poetry + Pyenv, etc (note: all of them run in parallel).
*/
breakdownLocators?: number;
/**
* Time taken to find Python environments in the paths found in the PATH env variable.
*/
breakdownPath?: number;
/**
* Time taken to find Python environments in the global virtual env locations.
*/
breakdownGlobalVirtualEnvs?: number;
/**
* Time taken to find Python environments in the workspaces.
*/
breakdownWorkspaces?: number;
/**
* Time taken to find all global Conda environments.
*/
locatorConda?: number;
/**
* Time taken to find all Homebrew environments.
*/
locatorHomebrew?: number;
/**
* Time taken to find all global Python environments on Linux.
*/
locatorLinuxGlobalPython?: number;
/**
* Time taken to find all Python environments belonging to Mac Command Line Tools .
*/
locatorMacCmdLineTools?: number;
/**
* Time taken to find all Python environments belonging to Mac Python Org.
*/
locatorMacPythonOrg?: number;
/**
* Time taken to find all Python environments belonging to Mac XCode.
*/
locatorMacXCode?: number;
/**
* Time taken to find all Pipenv environments.
*/
locatorPipEnv?: number;
/**
* Time taken to find all Poetry environments.
*/
locatorPoetry?: number;
/**
* Time taken to find all Pyenv environments.
*/
locatorPyEnv?: number;
/**
* Time taken to find all Venv environments.
*/
locatorVenv?: number;
/**
* Time taken to find all VirtualEnv environments.
*/
locatorVirtualEnv?: number;
/**
* Time taken to find all VirtualEnvWrapper environments.
*/
locatorVirtualEnvWrapper?: number;
/**
* Time taken to find all Windows Registry environments.
*/
locatorWindowsRegistry?: number;
/**
* Time taken to find all Windows Store environments.
*/
locatorWindowsStore?: number;
/**
* Total time taken to spawn the Native Python finder process.
*/
timeToSpawn?: number;
/**
* Total time taken to configure the Native Python finder process.
*/
timeToConfigure?: number;
/**
* Total time taken to refresh the Environments (from perspective of Python extension).
* Time = total time taken to process the `refresh` request.
*/
timeToRefresh?: number;
};
/**
* Telemetry event sent when discovery of all python environments using the native locator(virtualenv, conda, pipenv etc.) finishes.
*/
/* __GDPR__
"python_interpreter_discovery_native" : {
"python_interpreter_discovery_invalid_native" : {
"duration" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true, "owner": "donjayamanne" },
"invalidVersionsCondaEnvs" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true, "owner": "donjayamanne" },
"invalidVersionsCustomEnvs" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true, "owner": "donjayamanne" },
Expand Down
Loading