Reduce warning/debug messages (#15361)

* Do not log unnecessary warning msgs * More updatews * Reduced logging * oops * oops * oops
microsoft · Mar 14, 2024 · df25cd4 · df25cd4
1 parent a346521
commit df25cd4
Show file tree

Hide file tree

Showing 17 changed files with 91 additions and 67 deletions.
diff --git a/src/extension.node.ts b/src/extension.node.ts
@@ -100,6 +100,7 @@ import {
 import { setDisposableTracker } from './platform/common/utils/lifecycle';
 import { sendTelemetryEvent } from './telemetry';
 import { getVSCodeChannel } from './platform/common/application/applicationEnvironment';
+import { isUsingPylance } from './standalone/intellisense/notebookPythonPathService';
 
 durations.codeLoadingTime = stopWatch.elapsedTime;
 
@@ -305,7 +306,11 @@ function addOutputChannel(context: IExtensionContext, serviceManager: IServiceMa
     }
     const pylanceExtension = extensions.getExtension(PylanceExtension);
     if (pylanceExtension) {
-        standardOutputChannel.appendLine(`Pylance Extension Version: ${pylanceExtension.packageJSON['version']}.`);
+        standardOutputChannel.appendLine(
+            `Pylance Extension Version${isUsingPylance() ? '' : ' (Not Used) '}: ${
+                pylanceExtension.packageJSON['version']
+            }.`
+        );
     } else {
         standardOutputChannel.appendLine('Pylance Extension not installed.');
     }

diff --git a/src/extension.web.ts b/src/extension.web.ts
@@ -104,6 +104,7 @@ import { initializeGlobals as initializeTelemetryGlobals } from './platform/tele
 import { setDisposableTracker } from './platform/common/utils/lifecycle';
 import { sendTelemetryEvent } from './telemetry';
 import { getVSCodeChannel } from './platform/common/application/applicationEnvironment';
+import { isUsingPylance } from './standalone/intellisense/notebookPythonPathService';
 
 durations.codeLoadingTime = stopWatch.elapsedTime;
 
@@ -272,7 +273,11 @@ function addOutputChannel(context: IExtensionContext, serviceManager: IServiceMa
     }
     const pylanceExtension = extensions.getExtension(PylanceExtension);
     if (pylanceExtension) {
-        standardOutputChannel.appendLine(`Pylance Extension Version: ${pylanceExtension.packageJSON['version']}.`);
+        standardOutputChannel.appendLine(
+            `Pylance Extension Version${isUsingPylance() ? '' : ' (Not Used) '}: ${
+                pylanceExtension.packageJSON['version']
+            }.`
+        );
     } else {
         standardOutputChannel.appendLine('Pylance Extension not installed.');
     }

diff --git a/src/kernels/execution/cellExecutionCreator.ts b/src/kernels/execution/cellExecutionCreator.ts
@@ -72,9 +72,9 @@ export class NotebookCellExecutionWrapper implements NotebookCellExecution {
             try {
                 this._impl.end(success, endTime, this.errorInfo);
                 traceInfo(
-                    `End cell ${this.cell.index} execution after ${
+                    `Cell ${this.cell.index} completed in ${
                         ((endTime || 0) - (this._startTime || 0)) / 1000
-                    }s, completed @ ${endTime}, started @ ${this._startTime}`
+                    }s (start: ${this._startTime}, end: ${endTime})`
                 );
             } finally {
                 this._endCallback();

diff --git a/src/kernels/helpers.node.ts b/src/kernels/helpers.node.ts
@@ -5,7 +5,7 @@ import * as path from '../platform/vscode-path/path';
 import type * as nbformat from '@jupyterlab/nbformat';
 import { IJupyterKernelSpec, IKernelSession, isLocalConnection, KernelConnectionMetadata } from './types';
 import { Uri } from 'vscode';
-import { traceError, traceVerbose } from '../platform/logging';
+import { traceError } from '../platform/logging';
 import { Resource } from '../platform/common/types';
 import { concatMultilineString } from '../platform/common/utils';
 import { trackKernelResourceInformation } from './telemetry/helper';
@@ -54,7 +54,6 @@ export async function sendTelemetryForPythonKernelExecutable(
     } catch (ex) {
         traceError(`Failed to compare interpreters after ${stopWatch.elapsedTime}ms`, ex);
     }
-    traceVerbose(`End sendTelemetryForPythonKernelExecutable after ${stopWatch.elapsedTime}ms`);
 }
 
 /**

diff --git a/src/kernels/kernelRefreshIndicator.node.ts b/src/kernels/kernelRefreshIndicator.node.ts
@@ -9,7 +9,7 @@ import { InteractiveWindowView, JupyterNotebookView } from '../platform/common/c
 import { dispose } from '../platform/common/utils/lifecycle';
 import { IDisposable, IDisposableRegistry } from '../platform/common/types';
 import { IInterpreterService } from '../platform/interpreter/contracts';
-import { traceInfo } from '../platform/logging';
+import { traceVerbose } from '../platform/logging';
 import { IKernelFinder } from './types';
 import { isJupyterNotebook } from '../platform/common/utils';
 import { noop } from '../platform/common/utils/misc';
@@ -57,7 +57,7 @@ export class KernelRefreshIndicator implements IExtensionSyncActivationService {
 
         const displayProgress = () => {
             const id = Date.now().toString();
-            traceInfo(`Start refreshing Kernel Picker (${id})`);
+            traceVerbose(`Start refreshing Kernel Picker (${id})`);
             const taskNb = notebooks.createNotebookControllerDetectionTask(JupyterNotebookView);
             const taskIW = notebooks.createNotebookControllerDetectionTask(InteractiveWindowView);
             this.disposables.push(taskNb);
@@ -66,7 +66,7 @@ export class KernelRefreshIndicator implements IExtensionSyncActivationService {
             this.kernelFinder.onDidChangeStatus(
                 () => {
                     if (this.kernelFinder.status === 'idle') {
-                        traceInfo(`End refreshing Kernel Picker (${id})`);
+                        traceVerbose(`End refreshing Kernel Picker (${id})`);
                         taskNb.dispose();
                         taskIW.dispose();
                     }
@@ -104,7 +104,7 @@ export class KernelRefreshIndicator implements IExtensionSyncActivationService {
             (e) => {
                 if (!refreshedInterpreters && e && isJupyterNotebook(e.notebook)) {
                     refreshedInterpreters = true;
-                    traceInfo(`Start refreshing Interpreter Kernel Picker`);
+                    traceVerbose(`Start refreshing Interpreter Kernel Picker`);
                     this.interpreterService.refreshInterpreters().catch(noop);
                 }
             },
@@ -115,7 +115,7 @@ export class KernelRefreshIndicator implements IExtensionSyncActivationService {
             (e) => {
                 if (!refreshedInterpreters && isJupyterNotebook(e)) {
                     refreshedInterpreters = true;
-                    traceInfo(`Start refreshing Interpreter Kernel Picker`);
+                    traceVerbose(`Start refreshing Interpreter Kernel Picker`);
                     this.interpreterService.refreshInterpreters().catch(noop);
                 }
             },
@@ -130,7 +130,7 @@ export class KernelRefreshIndicator implements IExtensionSyncActivationService {
                 return kernelProgress;
             }
             id = Date.now().toString();
-            traceInfo(`Start refreshing Kernel Picker (${id})`);
+            traceVerbose(`Start refreshing Kernel Picker (${id})`);
             kernelProgress = new DisposableStore(
                 notebooks.createNotebookControllerDetectionTask(JupyterNotebookView),
                 notebooks.createNotebookControllerDetectionTask(InteractiveWindowView)
@@ -140,15 +140,15 @@ export class KernelRefreshIndicator implements IExtensionSyncActivationService {
         };
 
         if (this.kernelFinder.status === 'idle') {
-            traceInfo(`End refreshing Kernel Picker (${id})`);
+            traceVerbose(`End refreshing Kernel Picker (${id})`);
             kernelProgress?.dispose();
         } else {
             createProgressIndicator();
         }
         this.kernelFinder.onDidChangeStatus(
             () => {
                 if (this.kernelFinder.status === 'idle') {
-                    traceInfo(`End refreshing Kernel Picker (${id})`);
+                    traceVerbose(`End refreshing Kernel Picker (${id})`);
                     kernelProgress?.dispose();
                 } else {
                     createProgressIndicator();

diff --git a/src/kernels/kernelRefreshIndicator.web.ts b/src/kernels/kernelRefreshIndicator.web.ts
@@ -7,7 +7,7 @@ import { IExtensionSyncActivationService } from '../platform/activation/types';
 import { InteractiveWindowView, JupyterNotebookView } from '../platform/common/constants';
 import { dispose } from '../platform/common/utils/lifecycle';
 import { IDisposable, IDisposableRegistry } from '../platform/common/types';
-import { traceInfo } from '../platform/logging';
+import { traceVerbose } from '../platform/logging';
 import { IKernelFinder } from './types';
 /**
  * Ensures we refresh the list of Python environments upon opening a Notebook.
@@ -54,7 +54,7 @@ export class KernelRefreshIndicator implements IExtensionSyncActivationService {
     }
     private displayProgressIndicator() {
         const id = Date.now().toString();
-        traceInfo(`Start refreshing Kernel Picker (${id})`);
+        traceVerbose(`Start refreshing Kernel Picker (${id})`);
         const taskNb = notebooks.createNotebookControllerDetectionTask(JupyterNotebookView);
         const taskIW = notebooks.createNotebookControllerDetectionTask(InteractiveWindowView);
         this.disposables.push(taskNb);
@@ -63,7 +63,7 @@ export class KernelRefreshIndicator implements IExtensionSyncActivationService {
         this.kernelFinder.onDidChangeStatus(
             () => {
                 if (this.kernelFinder.status === 'idle') {
-                    traceInfo(`End refreshing Kernel Picker (${id})`);
+                    traceVerbose(`End refreshing Kernel Picker (${id})`);
                     taskNb.dispose();
                     taskIW.dispose();
                 }

diff --git a/src/kernels/raw/finder/interpreterKernelSpecFinderHelper.node.ts b/src/kernels/raw/finder/interpreterKernelSpecFinderHelper.node.ts
@@ -176,11 +176,24 @@ export class InterpreterSpecificKernelSpecsFinder extends DisposableBase {
         this.cancelToken.dispose();
         this.cancelToken = this._register(new CancellationTokenSource());
         this.kernelSpecPromise = this.listKernelSpecsImpl();
-        void this.kernelSpecPromise.then(() =>
-            traceVerbose(
-                `Kernels for interpreter ${this.interpreter.id} are ${Array.from(this._kernels.keys()).join(', ')}`
-            )
-        );
+        void this.kernelSpecPromise.then(() => {
+            switch (this._kernels.size) {
+                case 0:
+                    traceVerbose(`No Kernels found in interpreter ${this.interpreter.id}`);
+                    break;
+                case 1:
+                    // Thats the default kernel we create for this interpreter.
+                    // It will be the startUsingPythonInterpreter kernel.
+                    // No need to log this, just noise. It will be an obvious entry
+                    break;
+                default:
+                    traceVerbose(
+                        `Kernels for interpreter ${this.interpreter.id} are ${Array.from(this._kernels.keys()).join(
+                            ', '
+                        )}`
+                    );
+            }
+        });
         return this.kernelSpecPromise;
     }
 
@@ -232,13 +245,13 @@ export class InterpreterSpecificKernelSpecsFinder extends DisposableBase {
                 (!jupyterKernelSpec.env || Object.keys(jupyterKernelSpec.env).length === 0) &&
                 isDefaultKernelSpec(jupyterKernelSpec)
             ) {
-                traceVerbose(
-                    `Hiding default kernel spec '${jupyterKernelSpec.display_name}', '${
-                        jupyterKernelSpec.name
-                    }', ${getDisplayPath(jupyterKernelSpec.argv[0])} for interpreter ${getDisplayPath(
-                        jupyterKernelSpec.interpreterPath
-                    )} and spec ${getDisplayPath(jupyterKernelSpec.specFile)}`
-                );
+                // traceVerbose(
+                //     `Hiding default KernelSpec '${jupyterKernelSpec.name}', ${getDisplayPath(
+                //         jupyterKernelSpec.argv[0]
+                //     )} for interpreter ${getDisplayPath(
+                //         jupyterKernelSpec.interpreterPath
+                //     )} (KernelSpec file ${getDisplayPath(jupyterKernelSpec.specFile)})`
+                // );
                 return;
             }
             const kernelSpec = isKernelLaunchedViaLocalPythonIPyKernel(jupyterKernelSpec)
@@ -567,7 +580,6 @@ export class GlobalPythonKernelSpecFinder implements IDisposable {
         );
     }
     private async listKernelSpecsImpl() {
-        traceVerbose(`Finding Global Python KernelSpecs`);
         const cancelToken = this.cancelToken.token;
         const globalPythonKernelSpecs = this.listGlobalPythonKernelSpecs().filter(
             // Its impossible to have kernels registered by us that are in global.

diff --git a/src/kernels/raw/finder/localKernelSpecFinderBase.node.ts b/src/kernels/raw/finder/localKernelSpecFinderBase.node.ts
@@ -330,11 +330,11 @@ export async function loadKernelSpec(
     }
     let kernelJson: ReadWrite<IJupyterKernelSpec>;
     try {
-        traceVerbose(
-            `Loading kernelspec from ${getDisplayPath(specPath)} ${
-                interpreter?.uri ? `for ${getDisplayPath(interpreter.uri)}` : ''
-            }`
-        );
+        // traceVerbose(
+        //     `Loading kernelspec from ${getDisplayPath(specPath)} ${
+        //         interpreter?.uri ? `for ${getDisplayPath(interpreter.uri)}` : ''
+        //     }`
+        // );
         kernelJson = JSON.parse(await fs.readFile(specPath));
     } catch (ex) {
         traceError(`Failed to parse kernelspec ${specPath}`, ex);

diff --git a/src/kernels/raw/launcher/kernelProcess.node.ts b/src/kernels/raw/launcher/kernelProcess.node.ts
@@ -221,7 +221,15 @@ export class KernelProcess extends ObservableDisposable implements IKernelProces
                 // Capture stderr, incase kernel doesn't start.
                 stderr += output.out;
 
-                if (output.out.trim().length) {
+                if (
+                    output.out.trim().length &&
+                    // Exclude these warning messages, as users get confused about these when sharing logs.
+                    // I.e. they assume that issues in Jupyter ext are due to these warnings messages from ipykernel.
+                    !output.out.includes('It seems that frozen modules are being used, which may') &&
+                    !output.out.includes('make the debugger miss breakpoints. Please pass -Xfrozen_modules=off') &&
+                    !output.out.includes('to python to disable frozen modules') &&
+                    !output.out.includes('Debugging will proceed. Set PYDEVD_DISABLE_FILE_VALIDATION')
+                ) {
                     traceWarning(`StdErr from Kernel Process ${output.out.trim()}`);
                 }
             } else {

diff --git a/src/notebooks/controllers/ipywidgets/message/commonMessageCoordinator.ts b/src/notebooks/controllers/ipywidgets/message/commonMessageCoordinator.ts
@@ -117,7 +117,6 @@ export class CommonMessageCoordinator {
             const stopWatch = new StopWatch();
             if (!deferred.completed) {
                 // Determine the version of ipywidgets and send the appropriate script url to the webview.
-                traceVerbose('Attempting to determine version of IPyWidgets');
                 const disposables: IDisposable[] = [];
                 const kernelProvider = this.serviceContainer.get<IKernelProvider>(IKernelProvider);
                 const kernelPromise = createDeferred<IKernel>();
@@ -142,7 +141,6 @@ export class CommonMessageCoordinator {
                                 deferred.resolve(kernel.ipywidgetsVersion);
                             }
                         } else {
-                            traceVerbose('Waiting for IPyWidgets version');
                             kernel.onIPyWidgetVersionResolved(
                                 () => {
                                     if (kernel.ipywidgetsVersion) {
@@ -166,7 +164,6 @@ export class CommonMessageCoordinator {
                 if (disposables.length) {
                     this.disposables.push(...disposables);
                 }
-                traceVerbose('Waiting for IPyWidgets version promise');
             }
             // IPyWidgets scripts will not be loaded if we're unable to determine the version of IPyWidgets.
             const version = await deferred.promise;
@@ -238,7 +235,6 @@ export class CommonMessageCoordinator {
     }
 
     private initialize() {
-        traceVerbose('initialize CommonMessageCoordinator');
         // First hook up the widget script source that will listen to messages even before we start sending messages.
         this.getIPyWidgetScriptSource().initialize();
         this.getIPyWidgetMessageDispatcher().initialize();

diff --git a/src/notebooks/controllers/ipywidgets/message/ipyWidgetMessageDispatcher.ts b/src/notebooks/controllers/ipywidgets/message/ipyWidgetMessageDispatcher.ts
@@ -192,7 +192,6 @@ export class IPyWidgetMessageDispatcher implements IIPyWidgetMessageDispatcher {
             this.subscribeToKernelSocket(kernel);
             this.registerCommTargets(kernel);
         }
-        traceVerbose('IPyWidgetMessageDispatcher.initialize');
     }
     protected raisePostMessage<M extends IInteractiveWindowMapping, T extends keyof IInteractiveWindowMapping>(
         message: IPyWidgetMessages,

diff --git a/src/notebooks/controllers/notebookIPyWidgetCoordinator.ts b/src/notebooks/controllers/notebookIPyWidgetCoordinator.ts
@@ -150,18 +150,13 @@ export class NotebookIPyWidgetCoordinator implements IExtensionSyncActivationSer
             return;
         }
         if (this.notebookCommunications.has(editor)) {
-            traceVerbose(
-                `notebook communications already initialized for editor ${getDisplayPath(editor.notebook.uri)}`
-            );
             return;
         }
-        traceVerbose(`Initialize notebook communications for editor ${getDisplayPath(editor.notebook.uri)}`);
         const comms = new NotebookCommunication(editor, controller);
         this.addNotebookDisposables(notebook, [comms]);
         this.notebookCommunications.set(editor, comms);
         // Create a handler for this notebook if we don't already have one. Since there's one of the notebookMessageCoordinator's for the
         // entire VS code session, we have a map of notebook document to message coordinator
-        traceVerbose(`Resolving notebook UI Comms (resolve) for ${getDisplayPath(notebook.uri)}`);
         let coordinator = this.messageCoordinators.get(notebook);
         if (!coordinator) {
             coordinator = new CommonMessageCoordinator(notebook, this.serviceContainer);

diff --git a/src/platform/common/variables/customEnvironmentVariablesProvider.node.ts b/src/platform/common/variables/customEnvironmentVariablesProvider.node.ts
@@ -44,7 +44,7 @@ export class CustomEnvironmentVariablesProvider implements ICustomEnvironmentVar
         dispose(this.disposables);
     }
 
-    @traceDecoratorVerbose('Get Custom Env Variables', TraceOptions.BeforeCall | TraceOptions.Arguments)
+    @traceDecoratorVerbose('Get Custom Env Variables', TraceOptions.Arguments)
     public async getEnvironmentVariables(
         resource: Resource,
         purpose: 'RunPythonCode' | 'RunNonPythonCode',

diff --git a/src/platform/interpreter/condaService.node.ts b/src/platform/interpreter/condaService.node.ts
@@ -83,7 +83,7 @@ export class CondaService {
                 .then((api) => (api.getCondaFile ? api.getCondaFile() : undefined));
             latestInfo
                 .then((file) => {
-                    traceVerbose(`Conda file returned by Python Extension is ${file}`);
+                    traceVerbose(`Conda file is ${file}`);
                     this._file = file ? Uri.file(file) : undefined;
                     this.updateCache().catch(noop);
                 })