Skip to content

Add more logging and some tweaks #23425

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 4 commits into from
May 14, 2024
Merged

Add more logging and some tweaks #23425

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
4 commits
Select commit Hold shift + click to select a range
7687da4
Add more logging and some tweaks
karthiknadig May 14, 2024
744a5f4
Adding even more logging
karthiknadig May 14, 2024
1c5d9dd
Platform specific logging
karthiknadig May 14, 2024
88ccc1a
Remove unnecessary logging
karthiknadig May 14, 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
3 changes: 2 additions & 1 deletion native_locator/Cargo.toml
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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
1 change: 1 addition & 0 deletions src/client/common/utils/async.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -155,6 +155,7 @@ export async function* chain<T>(
): IAsyncIterableIterator<T> {
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.
Expand Down
23 changes: 23 additions & 0 deletions src/client/pythonEnvironments/base/info/environmentInfoService.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -106,6 +106,13 @@ class EnvironmentInfoService implements IEnvironmentInfoService {
}

const deferred = createDeferred<InterpreterInformation>();
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) => {
Expand Down Expand Up @@ -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(
Expand Down
17 changes: 13 additions & 4 deletions src/client/pythonEnvironments/base/locators/composite/envsCollectionService.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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';
Expand Down Expand Up @@ -107,14 +107,18 @@ export class EnvsCollectionService extends PythonEnvsWatcher<PythonEnvCollection
}

public triggerRefresh(query?: PythonLocatorQuery, options?: TriggerRefreshOptions): Promise<void> {
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;
}
Expand All @@ -139,17 +143,21 @@ export class EnvsCollectionService extends PythonEnvsWatcher<PythonEnvCollection
pending: 0,
};
const updatesDone = createDeferred<void>();

const stopWatch = new StopWatch();
if (iterator.onUpdated !== undefined) {
const listener = iterator.onUpdated(async (event) => {
if (isProgressEvent(event)) {
switch (event.stage) {
case ProgressReportStage.discoveryFinished:
state.done = true;
listener.dispose();
traceInfo(`Environments refresh finished (event): ${stopWatch.elapsedTime} milliseconds`);
break;
case ProgressReportStage.allPathsDiscovered:
if (!query) {
traceInfo(
`Environments refresh paths discovered (event): ${stopWatch.elapsedTime} milliseconds`,
);
// Only mark as all paths discovered when querying for all envs.
this.progress.fire(event);
}
Expand Down Expand Up @@ -178,6 +186,7 @@ export class EnvsCollectionService extends PythonEnvsWatcher<PythonEnvCollection
seen.push(env);
this.cache.addEnv(env);
}
traceInfo(`Environments refresh paths discovered: ${stopWatch.elapsedTime} milliseconds`);
await updatesDone.promise;
// If query for all envs is done, `seen` should contain the list of all envs.
await this.cache.validateCache(seen, query === undefined);
Expand Down
8 changes: 5 additions & 3 deletions src/client/pythonEnvironments/base/locators/lowLevel/activeStateLocator.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -6,21 +6,23 @@
import { ActiveState } from '../../../common/environmentManagers/activestate';
import { PythonEnvKind } from '../../info';
import { BasicEnvInfo, IPythonEnvsIterator } from '../../locator';
import { traceError, traceVerbose } from '../../../../logging';
import { traceError, traceInfo, traceVerbose } from '../../../../logging';
import { LazyResourceBasedLocator } from '../common/resourceBasedLocator';
import { findInterpretersInDir } from '../../../common/commonUtils';
import { StopWatch } from '../../../../common/utils/stopWatch';

export class ActiveStateLocator extends LazyResourceBasedLocator {
public readonly providerId: string = 'activestate';

// eslint-disable-next-line class-methods-use-this
public async *doIterEnvs(): IPythonEnvsIterator<BasicEnvInfo> {
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.`);
Expand All @@ -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`);
}
}
7 changes: 5 additions & 2 deletions src/client/pythonEnvironments/base/locators/lowLevel/condaLocator.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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';
Expand All @@ -20,6 +21,8 @@ export class CondaEnvironmentLocator extends FSWatchingLocator {

// eslint-disable-next-line class-methods-use-this
public async *doIterEnvs(_: unknown): IPythonEnvsIterator<BasicEnvInfo> {
const stopWatch = new StopWatch();
traceInfo('Searching for conda environments');
const conda = await Conda.getConda();
if (conda === undefined) {
traceVerbose(`Couldn't locate the conda binary.`);
Expand All @@ -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`);
}
}
7 changes: 5 additions & 2 deletions src/client/pythonEnvironments/base/locators/lowLevel/customVirtualEnvLocator.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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.
*/
Expand Down Expand Up @@ -99,6 +100,8 @@ export class CustomVirtualEnvironmentLocator extends FSWatchingLocator {
// eslint-disable-next-line class-methods-use-this
protected doIterEnvs(): IPythonEnvsIterator<BasicEnvInfo> {
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() {
Expand Down Expand Up @@ -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();
Expand Down
7 changes: 5 additions & 2 deletions src/client/pythonEnvironments/base/locators/lowLevel/globalVirtualEnvronmentLocator.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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;
/**
Expand Down Expand Up @@ -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() {
Expand Down Expand Up @@ -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();
Expand Down
8 changes: 5 additions & 3 deletions src/client/pythonEnvironments/base/locators/lowLevel/microsoftStoreLocator.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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:
Expand Down Expand Up @@ -87,13 +88,14 @@ export class MicrosoftStoreLocator extends FSWatchingLocator {

protected doIterEnvs(): IPythonEnvsIterator<BasicEnvInfo> {
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);
}
Expand Down
13 changes: 12 additions & 1 deletion src/client/pythonEnvironments/base/locators/lowLevel/nativeLocator.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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 {
Expand All @@ -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()) {
Expand Down Expand Up @@ -96,6 +97,8 @@ export class NativeLocator implements ILocator<BasicEnvInfo>, IDisposable {
}

public iterEnvs(): IPythonEnvsIterator<BasicEnvInfo> {
const stopWatch = new StopWatch();
traceInfo('Searching for Python environments using Native Locator');
const promise = this.finder.startSearch();
const envs: BasicEnvInfo[] = [];
const disposables: IDisposable[] = [];
Expand Down Expand Up @@ -133,9 +136,17 @@ export class NativeLocator implements ILocator<BasicEnvInfo>, IDisposable {
);

const iterator = async function* (): IPythonEnvsIterator<BasicEnvInfo> {
// 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();
}
}
10 changes: 7 additions & 3 deletions src/client/pythonEnvironments/base/locators/lowLevel/posixKnownPathsLocator.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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<BasicEnvInfo> {
public readonly providerId = 'posixKnownPaths';
Expand All @@ -26,7 +27,8 @@ export class PosixKnownPathsLocator extends Locator<BasicEnvInfo> {
}

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
Expand All @@ -50,7 +52,9 @@ export class PosixKnownPathsLocator extends Locator<BasicEnvInfo> {
} 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);
}
Expand Down
37 changes: 22 additions & 15 deletions src/client/pythonEnvironments/base/locators/lowLevel/pyenvLocator.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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.
Expand All @@ -16,25 +17,31 @@ import { traceError, traceVerbose } from '../../../../logging';
* all the environments (global or virtual) in that directory.
*/
async function* getPyenvEnvironments(): AsyncIterableIterator<BasicEnvInfo> {
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 {
Expand Down
Loading
Loading