diff --git a/native_locator/Cargo.toml b/native_locator/Cargo.toml index 4814adf1044c..c6ae0f27c36f 100644 --- a/native_locator/Cargo.toml +++ b/native_locator/Cargo.toml @@ -12,7 +12,8 @@ serde_json = "1.0.93" serde_repr = "0.1.10" regex = "1.10.4" log = "0.4.21" -env_logger = "0.11.3" +env_logger = "0.10.2" + [lib] doctest = false diff --git a/src/client/common/utils/async.ts b/src/client/common/utils/async.ts index c119d8f19b06..a99db8e94562 100644 --- a/src/client/common/utils/async.ts +++ b/src/client/common/utils/async.ts @@ -155,6 +155,7 @@ export async function* chain( ): IAsyncIterableIterator { const promises = iterators.map(getNext); let numRunning = iterators.length; + while (numRunning > 0) { // Promise.race will not fail, because each promise calls getNext, // Which handles failures by wrapping each iterator in a try/catch block. diff --git a/src/client/pythonEnvironments/base/info/environmentInfoService.ts b/src/client/pythonEnvironments/base/info/environmentInfoService.ts index 6a981d21b6df..251834b29683 100644 --- a/src/client/pythonEnvironments/base/info/environmentInfoService.ts +++ b/src/client/pythonEnvironments/base/info/environmentInfoService.ts @@ -106,6 +106,13 @@ class EnvironmentInfoService implements IEnvironmentInfoService { } const deferred = createDeferred(); + const info = EnvironmentInfoService.getInterpreterInfo(env); + if (info !== undefined) { + this.cache.set(normCasePath(interpreterPath), deferred); + deferred.resolve(info); + return info; + } + this.cache.set(normCasePath(interpreterPath), deferred); this._getEnvironmentInfo(env, priority) .then((r) => { @@ -205,6 +212,22 @@ class EnvironmentInfoService implements IEnvironmentInfoService { } }); } + + private static getInterpreterInfo(env: PythonEnvInfo): InterpreterInformation | undefined { + if (env.version.major > -1 && env.version.minor > -1 && env.version.micro > -1 && env.location) { + return { + arch: env.arch, + executable: { + filename: env.executable.filename, + ctime: -1, + mtime: -1, + sysPrefix: env.location, + }, + version: env.version, + }; + } + return undefined; + } } function addToQueue( diff --git a/src/client/pythonEnvironments/base/locators/composite/envsCollectionService.ts b/src/client/pythonEnvironments/base/locators/composite/envsCollectionService.ts index a54489e34633..30da89c87628 100644 --- a/src/client/pythonEnvironments/base/locators/composite/envsCollectionService.ts +++ b/src/client/pythonEnvironments/base/locators/composite/envsCollectionService.ts @@ -5,7 +5,7 @@ import { Event, EventEmitter } from 'vscode'; import '../../../../common/extensions'; import { createDeferred, Deferred } from '../../../../common/utils/async'; import { StopWatch } from '../../../../common/utils/stopWatch'; -import { traceError, traceVerbose } from '../../../../logging'; +import { traceError, traceInfo, traceVerbose } from '../../../../logging'; import { sendTelemetryEvent } from '../../../../telemetry'; import { EventName } from '../../../../telemetry/constants'; import { normalizePath } from '../../../common/externalDependencies'; @@ -107,14 +107,18 @@ export class EnvsCollectionService extends PythonEnvsWatcher { - const stopWatch = new StopWatch(); let refreshPromise = this.getRefreshPromiseForQuery(query); if (!refreshPromise) { if (options?.ifNotTriggerredAlready && this.hasRefreshFinished(query)) { // Do not trigger another refresh if a refresh has previously finished. return Promise.resolve(); } - refreshPromise = this.startRefresh(query).then(() => this.sendTelemetry(query, stopWatch)); + const stopWatch = new StopWatch(); + traceInfo(`Starting Environment refresh`); + refreshPromise = this.startRefresh(query).then(() => { + this.sendTelemetry(query, stopWatch); + traceInfo(`Environment refresh took ${stopWatch.elapsedTime} milliseconds`); + }); } return refreshPromise; } @@ -139,7 +143,7 @@ export class EnvsCollectionService extends PythonEnvsWatcher(); - + const stopWatch = new StopWatch(); if (iterator.onUpdated !== undefined) { const listener = iterator.onUpdated(async (event) => { if (isProgressEvent(event)) { @@ -147,9 +151,13 @@ export class EnvsCollectionService extends PythonEnvsWatcher { + const stopWatch = new StopWatch(); const state = await ActiveState.getState(); if (state === undefined) { traceVerbose(`Couldn't locate the state binary.`); return; } - traceVerbose(`Searching for active state environments`); + traceInfo(`Searching for active state environments`); const projects = await state.getProjects(); if (projects === undefined) { traceVerbose(`Couldn't fetch State Tool projects.`); @@ -41,6 +43,6 @@ export class ActiveStateLocator extends LazyResourceBasedLocator { } } } - traceVerbose(`Finished searching for active state environments`); + traceInfo(`Finished searching for active state environments: ${stopWatch.elapsedTime} milliseconds`); } } diff --git a/src/client/pythonEnvironments/base/locators/lowLevel/condaLocator.ts b/src/client/pythonEnvironments/base/locators/lowLevel/condaLocator.ts index a58bfdd65b2c..bb48ba75b9dd 100644 --- a/src/client/pythonEnvironments/base/locators/lowLevel/condaLocator.ts +++ b/src/client/pythonEnvironments/base/locators/lowLevel/condaLocator.ts @@ -4,8 +4,9 @@ import '../../../../common/extensions'; import { PythonEnvKind } from '../../info'; import { BasicEnvInfo, IPythonEnvsIterator } from '../../locator'; import { Conda, getCondaEnvironmentsTxt } from '../../../common/environmentManagers/conda'; -import { traceError, traceVerbose } from '../../../../logging'; +import { traceError, traceInfo, traceVerbose } from '../../../../logging'; import { FSWatchingLocator } from './fsWatchingLocator'; +import { StopWatch } from '../../../../common/utils/stopWatch'; export class CondaEnvironmentLocator extends FSWatchingLocator { public readonly providerId: string = 'conda-envs'; @@ -20,6 +21,8 @@ export class CondaEnvironmentLocator extends FSWatchingLocator { // eslint-disable-next-line class-methods-use-this public async *doIterEnvs(_: unknown): IPythonEnvsIterator { + const stopWatch = new StopWatch(); + traceInfo('Searching for conda environments'); const conda = await Conda.getConda(); if (conda === undefined) { traceVerbose(`Couldn't locate the conda binary.`); @@ -38,6 +41,6 @@ export class CondaEnvironmentLocator extends FSWatchingLocator { traceError(`Failed to process conda env: ${JSON.stringify(env)}`, ex); } } - traceVerbose(`Finished searching for conda environments`); + traceInfo(`Finished searching for conda environments: ${stopWatch.elapsedTime} milliseconds`); } } diff --git a/src/client/pythonEnvironments/base/locators/lowLevel/customVirtualEnvLocator.ts b/src/client/pythonEnvironments/base/locators/lowLevel/customVirtualEnvLocator.ts index e4daeee640c9..ae74d2f3e189 100644 --- a/src/client/pythonEnvironments/base/locators/lowLevel/customVirtualEnvLocator.ts +++ b/src/client/pythonEnvironments/base/locators/lowLevel/customVirtualEnvLocator.ts @@ -23,7 +23,8 @@ import { } from '../../../common/environmentManagers/simplevirtualenvs'; import '../../../../common/extensions'; import { asyncFilter } from '../../../../common/utils/arrayUtils'; -import { traceError, traceVerbose } from '../../../../logging'; +import { traceError, traceInfo, traceVerbose } from '../../../../logging'; +import { StopWatch } from '../../../../common/utils/stopWatch'; /** * Default number of levels of sub-directories to recurse when looking for interpreters. */ @@ -99,6 +100,8 @@ export class CustomVirtualEnvironmentLocator extends FSWatchingLocator { // eslint-disable-next-line class-methods-use-this protected doIterEnvs(): IPythonEnvsIterator { async function* iterator() { + const stopWatch = new StopWatch(); + traceInfo('Searching for custom virtual environments'); const envRootDirs = await getCustomVirtualEnvDirs(); const envGenerators = envRootDirs.map((envRootDir) => { async function* generator() { @@ -132,7 +135,7 @@ export class CustomVirtualEnvironmentLocator extends FSWatchingLocator { }); yield* iterable(chain(envGenerators)); - traceVerbose(`Finished searching for custom virtual envs`); + traceInfo(`Finished searching for custom virtual envs: ${stopWatch.elapsedTime} milliseconds`); } return iterator(); diff --git a/src/client/pythonEnvironments/base/locators/lowLevel/globalVirtualEnvronmentLocator.ts b/src/client/pythonEnvironments/base/locators/lowLevel/globalVirtualEnvronmentLocator.ts index cc623be8392d..3964a6ceb893 100644 --- a/src/client/pythonEnvironments/base/locators/lowLevel/globalVirtualEnvronmentLocator.ts +++ b/src/client/pythonEnvironments/base/locators/lowLevel/globalVirtualEnvronmentLocator.ts @@ -19,7 +19,8 @@ import { } from '../../../common/environmentManagers/simplevirtualenvs'; import '../../../../common/extensions'; import { asyncFilter } from '../../../../common/utils/arrayUtils'; -import { traceError, traceVerbose } from '../../../../logging'; +import { traceError, traceInfo, traceVerbose } from '../../../../logging'; +import { StopWatch } from '../../../../common/utils/stopWatch'; const DEFAULT_SEARCH_DEPTH = 2; /** @@ -118,6 +119,8 @@ export class GlobalVirtualEnvironmentLocator extends FSWatchingLocator { const searchDepth = this.searchDepth ?? DEFAULT_SEARCH_DEPTH; async function* iterator() { + const stopWatch = new StopWatch(); + traceInfo('Searching for global virtual environments'); const envRootDirs = await getGlobalVirtualEnvDirs(); const envGenerators = envRootDirs.map((envRootDir) => { async function* generator() { @@ -152,7 +155,7 @@ export class GlobalVirtualEnvironmentLocator extends FSWatchingLocator { }); yield* iterable(chain(envGenerators)); - traceVerbose(`Finished searching for global virtual envs`); + traceInfo(`Finished searching for global virtual envs: ${stopWatch.elapsedTime} milliseconds`); } return iterator(); diff --git a/src/client/pythonEnvironments/base/locators/lowLevel/microsoftStoreLocator.ts b/src/client/pythonEnvironments/base/locators/lowLevel/microsoftStoreLocator.ts index 7adeeae89858..60528bd939aa 100644 --- a/src/client/pythonEnvironments/base/locators/lowLevel/microsoftStoreLocator.ts +++ b/src/client/pythonEnvironments/base/locators/lowLevel/microsoftStoreLocator.ts @@ -12,7 +12,8 @@ import { isStorePythonInstalled, getMicrosoftStoreAppsRoot, } from '../../../common/environmentManagers/microsoftStoreEnv'; -import { traceVerbose } from '../../../../logging'; +import { traceInfo } from '../../../../logging'; +import { StopWatch } from '../../../../common/utils/stopWatch'; /** * This is a glob pattern which matches following file names: @@ -87,13 +88,14 @@ export class MicrosoftStoreLocator extends FSWatchingLocator { protected doIterEnvs(): IPythonEnvsIterator { const iterator = async function* (kind: PythonEnvKind) { - traceVerbose('Searching for windows store envs'); + const stopWatch = new StopWatch(); + traceInfo('Searching for windows store envs'); const exes = await getMicrosoftStorePythonExes(); yield* exes.map(async (executablePath: string) => ({ kind, executablePath, })); - traceVerbose(`Finished searching for windows store envs`); + traceInfo(`Finished searching for windows store envs: ${stopWatch.elapsedTime} milliseconds`); }; return iterator(this.kind); } diff --git a/src/client/pythonEnvironments/base/locators/lowLevel/nativeLocator.ts b/src/client/pythonEnvironments/base/locators/lowLevel/nativeLocator.ts index 4ec6723705f8..d39a0af1a61f 100644 --- a/src/client/pythonEnvironments/base/locators/lowLevel/nativeLocator.ts +++ b/src/client/pythonEnvironments/base/locators/lowLevel/nativeLocator.ts @@ -7,7 +7,7 @@ import { ILocator, BasicEnvInfo, IPythonEnvsIterator } from '../../locator'; import { PythonEnvsChangedEvent } from '../../watcher'; import { PythonEnvKind, PythonVersion } from '../../info'; import { Conda } from '../../../common/environmentManagers/conda'; -import { traceError } from '../../../../logging'; +import { traceError, traceInfo } from '../../../../logging'; import type { KnownEnvironmentTools } from '../../../../api/types'; import { setPyEnvBinary } from '../../../common/environmentManagers/pyenv'; import { @@ -17,6 +17,7 @@ import { createNativeGlobalPythonFinder, } from '../common/nativePythonFinder'; import { disposeAll } from '../../../../common/utils/resourceLifecycle'; +import { StopWatch } from '../../../../common/utils/stopWatch'; function categoryToKind(category: string): PythonEnvKind { switch (category.toLowerCase()) { @@ -96,6 +97,8 @@ export class NativeLocator implements ILocator, IDisposable { } public iterEnvs(): IPythonEnvsIterator { + const stopWatch = new StopWatch(); + traceInfo('Searching for Python environments using Native Locator'); const promise = this.finder.startSearch(); const envs: BasicEnvInfo[] = []; const disposables: IDisposable[] = []; @@ -133,9 +136,17 @@ export class NativeLocator implements ILocator, IDisposable { ); const iterator = async function* (): IPythonEnvsIterator { + // When this promise is complete, we know that the search is complete. await promise; + traceInfo( + `Finished searching for Python environments using Native Locator: ${stopWatch.elapsedTime} milliseconds`, + ); yield* envs; + traceInfo( + `Finished yielding Python environments using Native Locator: ${stopWatch.elapsedTime} milliseconds`, + ); }; + return iterator(); } } diff --git a/src/client/pythonEnvironments/base/locators/lowLevel/posixKnownPathsLocator.ts b/src/client/pythonEnvironments/base/locators/lowLevel/posixKnownPathsLocator.ts index 2d7ebc2af111..daca4b860907 100644 --- a/src/client/pythonEnvironments/base/locators/lowLevel/posixKnownPathsLocator.ts +++ b/src/client/pythonEnvironments/base/locators/lowLevel/posixKnownPathsLocator.ts @@ -9,7 +9,8 @@ import { commonPosixBinPaths, getPythonBinFromPosixPaths } from '../../../common import { isPyenvShimDir } from '../../../common/environmentManagers/pyenv'; import { getOSType, OSType } from '../../../../common/utils/platform'; import { isMacDefaultPythonPath } from '../../../common/environmentManagers/macDefault'; -import { traceError, traceVerbose } from '../../../../logging'; +import { traceError, traceInfo, traceVerbose } from '../../../../logging'; +import { StopWatch } from '../../../../common/utils/stopWatch'; export class PosixKnownPathsLocator extends Locator { public readonly providerId = 'posixKnownPaths'; @@ -26,7 +27,8 @@ export class PosixKnownPathsLocator extends Locator { } const iterator = async function* (kind: PythonEnvKind) { - traceVerbose('Searching for interpreters in posix paths locator'); + const stopWatch = new StopWatch(); + traceInfo('Searching for interpreters in posix paths locator'); try { // Filter out pyenv shims. They are not actual python binaries, they are used to launch // the binaries specified in .python-version file in the cwd. We should not be reporting @@ -50,7 +52,9 @@ export class PosixKnownPathsLocator extends Locator { } catch (ex) { traceError('Failed to process posix paths', ex); } - traceVerbose('Finished searching for interpreters in posix paths locator'); + traceInfo( + `Finished searching for interpreters in posix paths locator: ${stopWatch.elapsedTime} milliseconds`, + ); }; return iterator(this.kind); } diff --git a/src/client/pythonEnvironments/base/locators/lowLevel/pyenvLocator.ts b/src/client/pythonEnvironments/base/locators/lowLevel/pyenvLocator.ts index 4fd1891a179c..e97b69c6b882 100644 --- a/src/client/pythonEnvironments/base/locators/lowLevel/pyenvLocator.ts +++ b/src/client/pythonEnvironments/base/locators/lowLevel/pyenvLocator.ts @@ -7,7 +7,8 @@ import { FSWatchingLocator } from './fsWatchingLocator'; import { getInterpreterPathFromDir } from '../../../common/commonUtils'; import { getSubDirs } from '../../../common/externalDependencies'; import { getPyenvVersionsDir } from '../../../common/environmentManagers/pyenv'; -import { traceError, traceVerbose } from '../../../../logging'; +import { traceError, traceInfo } from '../../../../logging'; +import { StopWatch } from '../../../../common/utils/stopWatch'; /** * Gets all the pyenv environments. @@ -16,25 +17,31 @@ import { traceError, traceVerbose } from '../../../../logging'; * all the environments (global or virtual) in that directory. */ async function* getPyenvEnvironments(): AsyncIterableIterator { - traceVerbose('Searching for pyenv environments'); - const pyenvVersionDir = getPyenvVersionsDir(); + const stopWatch = new StopWatch(); + traceInfo('Searching for pyenv environments'); + try { + const pyenvVersionDir = getPyenvVersionsDir(); - const subDirs = getSubDirs(pyenvVersionDir, { resolveSymlinks: true }); - for await (const subDirPath of subDirs) { - const interpreterPath = await getInterpreterPathFromDir(subDirPath); + const subDirs = getSubDirs(pyenvVersionDir, { resolveSymlinks: true }); + for await (const subDirPath of subDirs) { + const interpreterPath = await getInterpreterPathFromDir(subDirPath); - if (interpreterPath) { - try { - yield { - kind: PythonEnvKind.Pyenv, - executablePath: interpreterPath, - }; - } catch (ex) { - traceError(`Failed to process environment: ${interpreterPath}`, ex); + if (interpreterPath) { + try { + yield { + kind: PythonEnvKind.Pyenv, + executablePath: interpreterPath, + }; + } catch (ex) { + traceError(`Failed to process environment: ${interpreterPath}`, ex); + } } } + } catch (ex) { + // This is expected when pyenv is not installed + traceInfo(`pyenv is not installed`); } - traceVerbose('Finished searching for pyenv environments'); + traceInfo(`Finished searching for pyenv environments: ${stopWatch.elapsedTime} milliseconds`); } export class PyenvLocator extends FSWatchingLocator { diff --git a/src/client/pythonEnvironments/base/locators/lowLevel/windowsKnownPathsLocator.ts b/src/client/pythonEnvironments/base/locators/lowLevel/windowsKnownPathsLocator.ts index d158d1da156c..440d075b4071 100644 --- a/src/client/pythonEnvironments/base/locators/lowLevel/windowsKnownPathsLocator.ts +++ b/src/client/pythonEnvironments/base/locators/lowLevel/windowsKnownPathsLocator.ts @@ -16,10 +16,11 @@ import { Locators } from '../../locators'; import { getEnvs } from '../../locatorUtils'; import { PythonEnvsChangedEvent } from '../../watcher'; import { DirFilesLocator } from './filesLocator'; -import { traceVerbose } from '../../../../logging'; +import { traceInfo } from '../../../../logging'; import { inExperiment, pathExists } from '../../../common/externalDependencies'; import { DiscoveryUsingWorkers } from '../../../../common/experiments/groups'; import { iterPythonExecutablesInDir, looksLikeBasicGlobalPython } from '../../../common/commonUtils'; +import { StopWatch } from '../../../../common/utils/stopWatch'; /** * A locator for Windows locators found under the $PATH env var. @@ -68,11 +69,12 @@ export class WindowsPathEnvVarLocator implements ILocator, IDispos // are valid executables. That is left to callers (e.g. composite // locators). async function* iterator(it: IPythonEnvsIterator) { - traceVerbose(`Searching windows known paths locator`); + const stopWatch = new StopWatch(); + traceInfo(`Searching windows known paths locator`); for await (const env of it) { yield env; } - traceVerbose(`Finished searching windows known paths locator`); + traceInfo(`Finished searching windows known paths locator: ${stopWatch.elapsedTime} milliseconds`); } return iterator(this.locators.iterEnvs(query)); } diff --git a/src/client/pythonEnvironments/base/locators/lowLevel/windowsRegistryLocator.ts b/src/client/pythonEnvironments/base/locators/lowLevel/windowsRegistryLocator.ts index a574116f1854..1447c2a90767 100644 --- a/src/client/pythonEnvironments/base/locators/lowLevel/windowsRegistryLocator.ts +++ b/src/client/pythonEnvironments/base/locators/lowLevel/windowsRegistryLocator.ts @@ -6,11 +6,12 @@ import { PythonEnvKind, PythonEnvSource } from '../../info'; import { BasicEnvInfo, IPythonEnvsIterator, Locator, PythonLocatorQuery, IEmitter } from '../../locator'; import { getRegistryInterpreters } from '../../../common/windowsUtils'; -import { traceError, traceVerbose } from '../../../../logging'; +import { traceError, traceInfo } from '../../../../logging'; import { isMicrosoftStoreDir } from '../../../common/environmentManagers/microsoftStoreEnv'; import { PythonEnvsChangedEvent } from '../../watcher'; import { DiscoveryUsingWorkers } from '../../../../common/experiments/groups'; import { inExperiment } from '../../../common/externalDependencies'; +import { StopWatch } from '../../../../common/utils/stopWatch'; export const WINDOWS_REG_PROVIDER_ID = 'windows-registry'; @@ -42,13 +43,15 @@ async function* iterateEnvsLazily(changed: IEmitter): IP } async function loadAllEnvs(changed: IEmitter) { - traceVerbose('Searching for windows registry interpreters'); - await getRegistryInterpreters(); + const stopWatch = new StopWatch(); + traceInfo('Searching for windows registry interpreters'); changed.fire({ providerId: WINDOWS_REG_PROVIDER_ID }); - traceVerbose('Finished searching for windows registry interpreters'); + traceInfo(`Finished searching for windows registry interpreters: ${stopWatch.elapsedTime} milliseconds`); } async function* iterateEnvs(): IPythonEnvsIterator { + const stopWatch = new StopWatch(); + traceInfo('Searching for windows registry interpreters'); const interpreters = await getRegistryInterpreters(); // Value should already be loaded at this point, so this returns immediately. for (const interpreter of interpreters) { try { @@ -68,5 +71,5 @@ async function* iterateEnvs(): IPythonEnvsIterator { traceError(`Failed to process environment: ${interpreter}`, ex); } } - traceVerbose('Finished searching for windows registry interpreters'); + traceInfo(`Finished searching for windows registry interpreters: ${stopWatch.elapsedTime} milliseconds`); }