diff --git a/.github/PULL_REQUEST_TEMPLATE.md b/.github/PULL_REQUEST_TEMPLATE.md index 3b32f16ead56..2cee7eee89fe 100644 --- a/.github/PULL_REQUEST_TEMPLATE.md +++ b/.github/PULL_REQUEST_TEMPLATE.md @@ -7,6 +7,8 @@ For # - [ ] Pull request represents a single change (i.e. not fixing disparate/unrelated things in a single PR) - [ ] Title summarizes what is changing - [ ] Has a [news entry](https://github.com/Microsoft/vscode-python/tree/master/news) file (remember to thank yourself!) +- [ ] Has sufficient logging. +- [ ] Has telemetry for enhancements. - [ ] Unit tests & system/integration tests are added/updated - [ ] [Test plan](https://github.com/Microsoft/vscode-python/blob/master/.github/test_plan.md) is updated as appropriate - [ ] [`package-lock.json`](https://github.com/Microsoft/vscode-python/blob/master/package-lock.json) has been regenerated by running `npm install` (if dependencies have changed) diff --git a/src/client/common/logger.ts b/src/client/common/logger.ts index 1390ba63edb0..87b0c013cb0c 100644 --- a/src/client/common/logger.ts +++ b/src/client/common/logger.ts @@ -110,6 +110,7 @@ function trace(message: string, options: LogOptions = LogOptions.None, logLevel? const originalMethod = descriptor.value; // tslint:disable-next-line:no-function-expression no-any descriptor.value = function (...args: any[]) { + const className = _ && _.constructor ? _.constructor.name : ''; // tslint:disable-next-line:no-any function writeSuccess(returnValue?: any) { if (logLevel === LogLevel.Error) { @@ -123,6 +124,7 @@ function trace(message: string, options: LogOptions = LogOptions.None, logLevel? // tslint:disable-next-line:no-any function writeToLog(returnValue?: any, ex?: Error) { const messagesToLog = [message]; + messagesToLog.push(`Class name = ${className}`); if ((options && LogOptions.Arguments) === LogOptions.Arguments) { messagesToLog.push(argsToLogString(args)); } diff --git a/src/client/interpreter/autoSelection/index.ts b/src/client/interpreter/autoSelection/index.ts index 43fbffa515e7..f5c66eae4291 100644 --- a/src/client/interpreter/autoSelection/index.ts +++ b/src/client/interpreter/autoSelection/index.ts @@ -10,6 +10,8 @@ import { IWorkspaceService } from '../../common/application/types'; import '../../common/extensions'; import { IFileSystem } from '../../common/platform/types'; import { IPersistentState, IPersistentStateFactory, Resource } from '../../common/types'; +import { captureTelemetry } from '../../telemetry'; +import { PYTHON_INTERPRETER_AUTO_SELECTION } from '../../telemetry/constants'; import { IInterpreterHelper, PythonInterpreter } from '../contracts'; import { AutoSelectionRule, IInterpreterAutoSelectionRule, IInterpreterAutoSelectionService, IInterpreterAutoSeletionProxyService } from './types'; @@ -61,6 +63,7 @@ export class InterpreterAutoSelectionService implements IInterpreterAutoSelectio currentPathInterpreter.setNextRule(winRegInterpreter); winRegInterpreter.setNextRule(systemInterpreter); } + @captureTelemetry(PYTHON_INTERPRETER_AUTO_SELECTION, { rule: AutoSelectionRule.all }, true) public async autoSelectInterpreter(resource: Resource): Promise { Promise.all(this.rules.map(item => item.autoSelectInterpreter(undefined))).ignoreErrors(); await this.initializeStore(); diff --git a/src/client/interpreter/autoSelection/rules/baseRule.ts b/src/client/interpreter/autoSelection/rules/baseRule.ts index e4fa897dd19a..16ad9d49c12a 100644 --- a/src/client/interpreter/autoSelection/rules/baseRule.ts +++ b/src/client/interpreter/autoSelection/rules/baseRule.ts @@ -6,6 +6,7 @@ import { inject, injectable, unmanaged } from 'inversify'; import { compare } from 'semver'; import '../../../common/extensions'; +import { traceDecorators, traceVerbose } from '../../../common/logger'; import { IFileSystem } from '../../../common/platform/types'; import { IPersistentState, IPersistentStateFactory, Resource } from '../../../common/types'; import { StopWatch } from '../../../common/utils/stopWatch'; @@ -23,7 +24,7 @@ export enum NextAction { export abstract class BaseRuleService implements IInterpreterAutoSelectionRule { protected nextRule?: IInterpreterAutoSelectionRule; private readonly stateStore: IPersistentState; - constructor(@unmanaged() private readonly ruleName: AutoSelectionRule, + constructor(@unmanaged() protected readonly ruleName: AutoSelectionRule, @inject(IFileSystem) private readonly fs: IFileSystem, @inject(IPersistentStateFactory) stateFactory: IPersistentStateFactory) { this.stateStore = stateFactory.createGlobalPersistentState(`InterpreterAutoSeletionRule-${this.ruleName}`, undefined); @@ -31,10 +32,12 @@ export abstract class BaseRuleService implements IInterpreterAutoSelectionRule { public setNextRule(rule: IInterpreterAutoSelectionRule): void { this.nextRule = rule; } + @traceDecorators.verbose('autoSelectInterpreter') public async autoSelectInterpreter(resource: Resource, manager?: IInterpreterAutoSelectionService): Promise { await this.clearCachedInterpreterIfInvalid(resource); const stopWatch = new StopWatch(); const action = await this.onAutoSelectInterpreter(resource, manager); + traceVerbose(`Rule = ${this.ruleName}, result = ${action}`); const identified = action === NextAction.runNextRule; sendTelemetryEvent(PYTHON_INTERPRETER_AUTO_SELECTION, { elapsedTime: stopWatch.elapsedTime }, { rule: this.ruleName, identified }); if (action === NextAction.runNextRule) { @@ -42,9 +45,12 @@ export abstract class BaseRuleService implements IInterpreterAutoSelectionRule { } } public getPreviouslyAutoSelectedInterpreter(_resource: Resource): PythonInterpreter | undefined { - return this.stateStore.value; + const value = this.stateStore.value; + traceVerbose(`Current value for rule ${this.ruleName} is ${value ? JSON.stringify(value) : 'nothing'}`); + return value; } protected abstract onAutoSelectInterpreter(resource: Resource, manager?: IInterpreterAutoSelectionService): Promise; + @traceDecorators.verbose('setGlobalInterpreter') protected async setGlobalInterpreter(interpreter?: PythonInterpreter, manager?: IInterpreterAutoSelectionService): Promise { await this.cacheSelectedInterpreter(undefined, interpreter); if (!interpreter || !manager || !interpreter.version) { @@ -77,6 +83,7 @@ export abstract class BaseRuleService implements IInterpreterAutoSelectionRule { await this.stateStore.updateValue(interpreter); } protected async next(resource: Resource, manager?: IInterpreterAutoSelectionService): Promise { + traceVerbose(`Executing next rule from ${this.ruleName}`); return this.nextRule && manager ? this.nextRule.autoSelectInterpreter(resource, manager) : undefined; } } diff --git a/src/client/interpreter/autoSelection/rules/cached.ts b/src/client/interpreter/autoSelection/rules/cached.ts index cbc3fe1ef01b..d9ddf1c74866 100644 --- a/src/client/interpreter/autoSelection/rules/cached.ts +++ b/src/client/interpreter/autoSelection/rules/cached.ts @@ -4,6 +4,7 @@ 'use strict'; import { inject, injectable, named } from 'inversify'; +import { traceVerbose } from '../../../common/logger'; import { IFileSystem } from '../../../common/platform/types'; import { IPersistentStateFactory, Resource } from '../../../common/types'; import { IInterpreterHelper } from '../../contracts'; @@ -29,6 +30,7 @@ export class CachedInterpretersAutoSelectionRule extends BaseRuleService { .filter(item => !!item) .map(item => item!); const bestInterpreter = this.helper.getBestInterpreter(cachedInterpreters); + traceVerbose(`Selected Interpreter from ${this.ruleName}, ${bestInterpreter ? JSON.stringify(bestInterpreter) : 'Nothing Selected'}`); return await this.setGlobalInterpreter(bestInterpreter, manager) ? NextAction.exit : NextAction.runNextRule; } } diff --git a/src/client/interpreter/autoSelection/rules/currentPath.ts b/src/client/interpreter/autoSelection/rules/currentPath.ts index b277cfe9ab31..091481ca9de1 100644 --- a/src/client/interpreter/autoSelection/rules/currentPath.ts +++ b/src/client/interpreter/autoSelection/rules/currentPath.ts @@ -4,6 +4,7 @@ 'use strict'; import { inject, injectable, named } from 'inversify'; +import { traceVerbose } from '../../../common/logger'; import { IFileSystem } from '../../../common/platform/types'; import { IPersistentStateFactory, Resource } from '../../../common/types'; import { CURRENT_PATH_SERVICE, IInterpreterHelper, IInterpreterLocatorService } from '../../contracts'; @@ -23,6 +24,7 @@ export class CurrentPathInterpretersAutoSelectionRule extends BaseRuleService { protected async onAutoSelectInterpreter(resource: Resource, manager?: IInterpreterAutoSelectionService): Promise { const interpreters = await this.currentPathInterpreterLocator.getInterpreters(resource); const bestInterpreter = this.helper.getBestInterpreter(interpreters); + traceVerbose(`Selected Interpreter from ${this.ruleName}, ${bestInterpreter ? JSON.stringify(bestInterpreter) : 'Nothing Selected'}`); return await this.setGlobalInterpreter(bestInterpreter, manager) ? NextAction.exit : NextAction.runNextRule; } } diff --git a/src/client/interpreter/autoSelection/rules/system.ts b/src/client/interpreter/autoSelection/rules/system.ts index 15bee26fd16d..ee374616c1fa 100644 --- a/src/client/interpreter/autoSelection/rules/system.ts +++ b/src/client/interpreter/autoSelection/rules/system.ts @@ -4,6 +4,7 @@ 'use strict'; import { inject, injectable } from 'inversify'; +import { traceVerbose } from '../../../common/logger'; import { IFileSystem } from '../../../common/platform/types'; import { IPersistentStateFactory, Resource } from '../../../common/types'; import { IInterpreterHelper, IInterpreterService, InterpreterType } from '../../contracts'; @@ -27,6 +28,7 @@ export class SystemWideInterpretersAutoSelectionRule extends BaseRuleService { int.type !== InterpreterType.Venv && int.type !== InterpreterType.PipEnv); const bestInterpreter = this.helper.getBestInterpreter(filteredInterpreters); + traceVerbose(`Selected Interpreter from ${this.ruleName}, ${bestInterpreter ? JSON.stringify(bestInterpreter) : 'Nothing Selected'}`); return await this.setGlobalInterpreter(bestInterpreter, manager) ? NextAction.exit : NextAction.runNextRule; } } diff --git a/src/client/interpreter/autoSelection/rules/winRegistry.ts b/src/client/interpreter/autoSelection/rules/winRegistry.ts index e043f751539a..4155fd5ade7c 100644 --- a/src/client/interpreter/autoSelection/rules/winRegistry.ts +++ b/src/client/interpreter/autoSelection/rules/winRegistry.ts @@ -4,6 +4,7 @@ 'use strict'; import { inject, injectable, named } from 'inversify'; +import { traceVerbose } from '../../../common/logger'; import { IFileSystem, IPlatformService } from '../../../common/platform/types'; import { IPersistentStateFactory, Resource } from '../../../common/types'; import { OSType } from '../../../common/utils/platform'; @@ -28,6 +29,7 @@ export class WindowsRegistryInterpretersAutoSelectionRule extends BaseRuleServic } const interpreters = await this.winRegInterpreterLocator.getInterpreters(resource); const bestInterpreter = this.helper.getBestInterpreter(interpreters); + traceVerbose(`Selected Interpreter from ${this.ruleName}, ${bestInterpreter ? JSON.stringify(bestInterpreter) : 'Nothing Selected'}`); return await this.setGlobalInterpreter(bestInterpreter, manager) ? NextAction.exit : NextAction.runNextRule; } } diff --git a/src/client/interpreter/autoSelection/rules/workspaceEnv.ts b/src/client/interpreter/autoSelection/rules/workspaceEnv.ts index 6a4230391dad..a6bd68cae4d4 100644 --- a/src/client/interpreter/autoSelection/rules/workspaceEnv.ts +++ b/src/client/interpreter/autoSelection/rules/workspaceEnv.ts @@ -6,6 +6,7 @@ import { inject, injectable, named } from 'inversify'; import { Uri } from 'vscode'; import { IWorkspaceService } from '../../../common/application/types'; +import { traceVerbose } from '../../../common/logger'; import { IFileSystem, IPlatformService } from '../../../common/platform/types'; import { IPersistentStateFactory, Resource } from '../../../common/types'; import { createDeferredFromPromise } from '../../../common/utils/async'; @@ -60,6 +61,7 @@ export class WorkspaceVirtualEnvInterpretersAutoSelectionRule extends BaseRuleSe await this.cacheSelectedInterpreter(workspacePath.folderUri, bestInterpreter); await manager.setWorkspaceInterpreter(workspacePath.folderUri!, bestInterpreter); } + traceVerbose(`Selected Interpreter from ${this.ruleName}, ${bestInterpreter ? JSON.stringify(bestInterpreter) : 'Nothing Selected'}`); return NextAction.runNextRule; } protected async getWorkspaceVirtualEnvInterpreters(resource: Resource): Promise { diff --git a/src/client/interpreter/autoSelection/types.ts b/src/client/interpreter/autoSelection/types.ts index 4cd37b359358..2bc24f46a139 100644 --- a/src/client/interpreter/autoSelection/types.ts +++ b/src/client/interpreter/autoSelection/types.ts @@ -33,6 +33,7 @@ export interface IInterpreterAutoSelectionService extends IInterpreterAutoSeleti } export enum AutoSelectionRule { + all = 'all', currentPath = 'currentPath', workspaceVirtualEnvs = 'workspaceEnvs', settings = 'settings',