Use new logging API for python extension logger and LS logger (micros…

…oft#21062)

In this PR:
1. Changes the python extension logging to use LogOutputChannel
2. Changes the language server logger with LogOutputChannel
3. Test output channel uses OutputChannel as it needs to show test
output and not really logging. Also, using logging test output makes it
pretty much unreadable.
4. Simplifies logging channel and output channel registration.

We need to do this now to make it easier for new test work to integrate
with output logging.

For microsoft#20844

This still doesn't get rid of the log level setting.

src/client/activation/common/analysisOptions.ts

@@ -5,7 +5,7 @@ import { DocumentFilter, LanguageClientOptions, RevealOutputChannelOn } from 'vs
 import { IWorkspaceService } from '../../common/application/types';
 
 import { PYTHON, PYTHON_LANGUAGE } from '../../common/constants';
-import { IOutputChannel, Resource } from '../../common/types';
+import { ILogOutputChannel, Resource } from '../../common/types';
 import { debounceSync } from '../../common/utils/decorators';
 import { IEnvironmentVariablesProvider } from '../../common/variables/types';
 import { traceDecoratorError } from '../../logging';
@@ -14,7 +14,7 @@ import { ILanguageServerAnalysisOptions, ILanguageServerOutputChannel } from '..
 
 export abstract class LanguageServerAnalysisOptionsBase implements ILanguageServerAnalysisOptions {
     protected readonly didChange = new EventEmitter<void>();
-    private readonly output: IOutputChannel;
+    private readonly output: ILogOutputChannel;
 
     protected constructor(
         lsOutputChannel: ILanguageServerOutputChannel,

src/client/activation/common/outputChannel.ts

@@ -6,13 +6,13 @@
 import { inject, injectable } from 'inversify';
 import { IApplicationShell, ICommandManager } from '../../common/application/types';
 import '../../common/extensions';
-import { IDisposableRegistry, IOutputChannel } from '../../common/types';
+import { IDisposableRegistry, ILogOutputChannel } from '../../common/types';
 import { OutputChannelNames } from '../../common/utils/localize';
 import { ILanguageServerOutputChannel } from '../types';
 
 @injectable()
 export class LanguageServerOutputChannel implements ILanguageServerOutputChannel {
-    public output: IOutputChannel | undefined;
+    public output: ILogOutputChannel | undefined;
 
     private registered = false;
 
@@ -22,7 +22,7 @@ export class LanguageServerOutputChannel implements ILanguageServerOutputChannel
         @inject(IDisposableRegistry) private readonly disposable: IDisposableRegistry,
     ) {}
 
-    public get channel(): IOutputChannel {
+    public get channel(): ILogOutputChannel {
         if (!this.output) {
             this.output = this.appShell.createOutputChannel(OutputChannelNames.languageServer);
             this.disposable.push(this.output);

src/client/activation/types.ts

@@ -5,7 +5,7 @@
 
 import { Event } from 'vscode';
 import { LanguageClient, LanguageClientOptions } from 'vscode-languageclient/node';
-import type { IDisposable, IOutputChannel, Resource } from '../common/types';
+import type { IDisposable, ILogOutputChannel, Resource } from '../common/types';
 import { PythonEnvironment } from '../pythonEnvironments/info';
 
 export const IExtensionActivationManager = Symbol('IExtensionActivationManager');
@@ -110,10 +110,10 @@ export interface ILanguageServerOutputChannel {
     /**
      * Creates output channel if necessary and returns it
      *
-     * @type {IOutputChannel}
+     * @type {ILogOutputChannel}
      * @memberof ILanguageServerOutputChannel
      */
-    readonly channel: IOutputChannel;
+    readonly channel: ILogOutputChannel;
 }
 
 export const IExtensionSingleActivationService = Symbol('IExtensionSingleActivationService');

src/client/common/application/applicationShell.ts

@@ -14,10 +14,10 @@ import {
     InputBoxOptions,
     languages,
     LanguageStatusItem,
+    LogOutputChannel,
     MessageItem,
     MessageOptions,
     OpenDialogOptions,
-    OutputChannel,
     Progress,
     ProgressOptions,
     QuickPick,
@@ -166,8 +166,8 @@ export class ApplicationShell implements IApplicationShell {
     public createTreeView<T>(viewId: string, options: TreeViewOptions<T>): TreeView<T> {
         return window.createTreeView<T>(viewId, options);
     }
-    public createOutputChannel(name: string): OutputChannel {
-        return window.createOutputChannel(name);
+    public createOutputChannel(name: string): LogOutputChannel {
+        return window.createOutputChannel(name, { log: true });
     }
     public createLanguageStatusItem(id: string, selector: DocumentSelector): LanguageStatusItem {
         return languages.createLanguageStatusItem(id, selector);

src/client/common/application/types.ts

@@ -25,10 +25,10 @@ import {
     InputBox,
     InputBoxOptions,
     LanguageStatusItem,
+    LogOutputChannel,
     MessageItem,
     MessageOptions,
     OpenDialogOptions,
-    OutputChannel,
     Progress,
     ProgressOptions,
     QuickPick,
@@ -429,7 +429,7 @@ export interface IApplicationShell {
      *
      * @param name Human-readable string which will be used to represent the channel in the UI.
      */
-    createOutputChannel(name: string): OutputChannel;
+    createOutputChannel(name: string): LogOutputChannel;
     createLanguageStatusItem(id: string, selector: DocumentSelector): LanguageStatusItem;
 }
 

src/client/common/constants.ts

@@ -93,8 +93,6 @@ export namespace ThemeIcons {
 
 export const DEFAULT_INTERPRETER_SETTING = 'python';
 
-export const STANDARD_OUTPUT_CHANNEL = 'STANDARD_OUTPUT_CHANNEL';
-
 export const isCI = process.env.TRAVIS === 'true' || process.env.TF_BUILD !== undefined;
 
 export function isTestExecution(): boolean {

src/client/common/installer/moduleInstaller.ts

@@ -12,12 +12,11 @@ import { sendTelemetryEvent } from '../../telemetry';
 import { EventName } from '../../telemetry/constants';
 import { IApplicationShell } from '../application/types';
 import { wrapCancellationTokens } from '../cancellation';
-import { STANDARD_OUTPUT_CHANNEL } from '../constants';
 import { IFileSystem } from '../platform/types';
 import * as internalPython from '../process/internal/python';
 import { IProcessServiceFactory } from '../process/types';
 import { ITerminalServiceFactory, TerminalCreationOptions } from '../terminal/types';
-import { ExecutionInfo, IConfigurationService, IOutputChannel, Product } from '../types';
+import { ExecutionInfo, IConfigurationService, ILogOutputChannel, Product } from '../types';
 import { isResource } from '../utils/misc';
 import { ProductNames } from './productNames';
 import { IModuleInstaller, InstallOptions, InterpreterUri, ModuleInstallFlags } from './types';
@@ -152,7 +151,7 @@ export abstract class ModuleInstaller implements IModuleInstaller {
         const options = {
             name: 'VS Code Python',
         };
-        const outputChannel = this.serviceContainer.get<IOutputChannel>(IOutputChannel, STANDARD_OUTPUT_CHANNEL);
+        const outputChannel = this.serviceContainer.get<ILogOutputChannel>(ILogOutputChannel);
         const command = `"${execPath.replace(/\\/g, '/')}" ${args.join(' ')}`;
 
         traceLog(`[Elevated] ${command}`);

src/client/common/process/rawProcessApis.ts

@@ -121,7 +121,10 @@ export function plainExec(
     }
 
     const stdoutBuffers: Buffer[] = [];
-    on(proc.stdout, 'data', (data: Buffer) => stdoutBuffers.push(data));
+    on(proc.stdout, 'data', (data: Buffer) => {
+        stdoutBuffers.push(data);
+        options.outputChannel?.append(data.toString());
+    });
     const stderrBuffers: Buffer[] = [];
     on(proc.stderr, 'data', (data: Buffer) => {
         if (options.mergeStdOutErr) {
@@ -130,6 +133,7 @@ export function plainExec(
         } else {
             stderrBuffers.push(data);
         }
+        options.outputChannel?.append(data.toString());
     });
 
     proc.once('close', () => {

src/client/common/process/types.ts

@@ -3,7 +3,7 @@
 
 import { ChildProcess, ExecOptions, SpawnOptions as ChildProcessSpawnOptions } from 'child_process';
 import { Observable } from 'rxjs/Observable';
-import { CancellationToken, Uri } from 'vscode';
+import { CancellationToken, OutputChannel, Uri } from 'vscode';
 import { PythonExecInfo } from '../../pythonEnvironments/exec';
 import { InterpreterInformation, PythonEnvironment } from '../../pythonEnvironments/info';
 import { ExecutionInfo, IDisposable } from '../types';
@@ -24,6 +24,7 @@ export type SpawnOptions = ChildProcessSpawnOptions & {
     mergeStdOutErr?: boolean;
     throwOnStdErr?: boolean;
     extraVariables?: NodeJS.ProcessEnv;
+    outputChannel?: OutputChannel;
 };
 
 export type ShellOptions = ExecOptions & { throwOnStdErr?: boolean };

src/client/common/types.ts

@@ -15,9 +15,10 @@ import {
     Extension,
     ExtensionContext,
     Memento,
-    OutputChannel,
+    LogOutputChannel,
     Uri,
     WorkspaceEdit,
+    OutputChannel,
 } from 'vscode';
 import { LanguageServerType } from '../activation/types';
 import type { InstallOptions, InterpreterUri, ModuleInstallFlags } from './installer/types';
@@ -29,8 +30,10 @@ export interface IDisposable {
     dispose(): void | undefined | Promise<void>;
 }
 
-export const IOutputChannel = Symbol('IOutputChannel');
-export interface IOutputChannel extends OutputChannel {}
+export const ILogOutputChannel = Symbol('ILogOutputChannel');
+export interface ILogOutputChannel extends LogOutputChannel {}
+export const ITestOutputChannel = Symbol('ITestOutputChannel');
+export interface ITestOutputChannel extends OutputChannel {}
 export const IDocumentSymbolProvider = Symbol('IDocumentSymbolProvider');
 export interface IDocumentSymbolProvider extends DocumentSymbolProvider {}
 export const IsWindows = Symbol('IS_WINDOWS');

src/client/extensionActivation.ts

@@ -3,29 +3,22 @@
 
 'use strict';
 
-import {
-    debug,
-    DebugConfigurationProvider,
-    DebugConfigurationProviderTriggerKind,
-    languages,
-    OutputChannel,
-    window,
-} from 'vscode';
+import { debug, DebugConfigurationProvider, DebugConfigurationProviderTriggerKind, languages, window } from 'vscode';
 
 import { registerTypes as activationRegisterTypes } from './activation/serviceRegistry';
 import { IExtensionActivationManager } from './activation/types';
 import { registerTypes as appRegisterTypes } from './application/serviceRegistry';
 import { IApplicationDiagnostics } from './application/types';
 import { IApplicationEnvironment, ICommandManager, IWorkspaceService } from './common/application/types';
-import { Commands, PYTHON, PYTHON_LANGUAGE, STANDARD_OUTPUT_CHANNEL, UseProposedApi } from './common/constants';
+import { Commands, PYTHON, PYTHON_LANGUAGE, UseProposedApi } from './common/constants';
 import { registerTypes as installerRegisterTypes } from './common/installer/serviceRegistry';
 import { IFileSystem } from './common/platform/types';
 import {
     IConfigurationService,
     IDisposableRegistry,
     IExtensions,
     IInterpreterPathService,
-    IOutputChannel,
+    ILogOutputChannel,
     IPathUtils,
 } from './common/types';
 import { noop } from './common/utils/misc';
@@ -173,7 +166,7 @@ async function activateLegacy(ext: ExtensionState): Promise<ActivationResult> {
             const dispatcher = new DebugSessionEventDispatcher(handlers, DebugService.instance, disposables);
             dispatcher.registerEventHandlers();
 
-            const outputChannel = serviceManager.get<OutputChannel>(IOutputChannel, STANDARD_OUTPUT_CHANNEL);
+            const outputChannel = serviceManager.get<ILogOutputChannel>(ILogOutputChannel);
             disposables.push(cmdManager.registerCommand(Commands.ViewOutput, () => outputChannel.show()));
             cmdManager.executeCommand('setContext', 'python.vscode.channel', applicationEnv.channel).then(noop, noop);
 

src/client/extensionInit.ts

@@ -4,9 +4,8 @@
 'use strict';
 
 import { Container } from 'inversify';
-import { Disposable, Memento, OutputChannel, window } from 'vscode';
+import { Disposable, Memento, window } from 'vscode';
 import { instance, mock } from 'ts-mockito';
-import { STANDARD_OUTPUT_CHANNEL } from './common/constants';
 import { registerTypes as platformRegisterTypes } from './common/platform/serviceRegistry';
 import { registerTypes as processRegisterTypes } from './common/process/serviceRegistry';
 import { registerTypes as commonRegisterTypes } from './common/serviceRegistry';
@@ -16,7 +15,8 @@ import {
     IDisposableRegistry,
     IExtensionContext,
     IMemento,
-    IOutputChannel,
+    ILogOutputChannel,
+    ITestOutputChannel,
     WORKSPACE_MEMENTO,
 } from './common/types';
 import { registerTypes as variableRegisterTypes } from './common/variables/serviceRegistry';
@@ -26,7 +26,6 @@ import { ServiceContainer } from './ioc/container';
 import { ServiceManager } from './ioc/serviceManager';
 import { IServiceContainer, IServiceManager } from './ioc/types';
 import * as pythonEnvironments from './pythonEnvironments';
-import { TEST_OUTPUT_CHANNEL } from './testing/constants';
 import { IDiscoveryAPI } from './pythonEnvironments/base/locator';
 import { registerLogger } from './logging';
 import { OutputChannelLogger } from './logging/outputChannelLogger';
@@ -54,20 +53,20 @@ export function initializeGlobals(
     serviceManager.addSingletonInstance<Memento>(IMemento, context.workspaceState, WORKSPACE_MEMENTO);
     serviceManager.addSingletonInstance<IExtensionContext>(IExtensionContext, context);
 
-    const standardOutputChannel = window.createOutputChannel(OutputChannelNames.python);
+    const standardOutputChannel = window.createOutputChannel(OutputChannelNames.python, { log: true });
     disposables.push(standardOutputChannel);
     disposables.push(registerLogger(new OutputChannelLogger(standardOutputChannel)));
 
     const workspaceService = new WorkspaceService();
     const unitTestOutChannel =
         workspaceService.isVirtualWorkspace || !workspaceService.isTrusted
             ? // Do not create any test related output UI when using virtual workspaces.
-              instance(mock<IOutputChannel>())
+              instance(mock<ITestOutputChannel>())
             : window.createOutputChannel(OutputChannelNames.pythonTest);
     disposables.push(unitTestOutChannel);
 
-    serviceManager.addSingletonInstance<OutputChannel>(IOutputChannel, standardOutputChannel, STANDARD_OUTPUT_CHANNEL);
-    serviceManager.addSingletonInstance<OutputChannel>(IOutputChannel, unitTestOutChannel, TEST_OUTPUT_CHANNEL);
+    serviceManager.addSingletonInstance<ILogOutputChannel>(ILogOutputChannel, standardOutputChannel);
+    serviceManager.addSingletonInstance<ITestOutputChannel>(ITestOutputChannel, unitTestOutChannel);
 
     return {
         context,

src/client/linters/errorHandlers/standard.ts

@@ -1,7 +1,6 @@
 import { l10n, Uri } from 'vscode';
 import { IApplicationShell } from '../../common/application/types';
-import { STANDARD_OUTPUT_CHANNEL } from '../../common/constants';
-import { ExecutionInfo, IOutputChannel } from '../../common/types';
+import { ExecutionInfo, ILogOutputChannel } from '../../common/types';
 import { traceError, traceLog } from '../../logging';
 import { ILinterManager, LinterId } from '../types';
 import { BaseErrorHandler } from './baseErrorHandler';
@@ -29,7 +28,7 @@ export class StandardErrorHandler extends BaseErrorHandler {
     private async displayLinterError(linterId: LinterId) {
         const message = l10n.t("There was an error in running the linter '{0}'", linterId);
         const appShell = this.serviceContainer.get<IApplicationShell>(IApplicationShell);
-        const outputChannel = this.serviceContainer.get<IOutputChannel>(IOutputChannel, STANDARD_OUTPUT_CHANNEL);
+        const outputChannel = this.serviceContainer.get<ILogOutputChannel>(ILogOutputChannel);
         const action = await appShell.showErrorMessage(message, 'View Errors');
         if (action === 'View Errors') {
             outputChannel.show();

src/client/logging/outputChannelLogger.ts

@@ -2,34 +2,29 @@
 // Licensed under the MIT License.
 
 import * as util from 'util';
-import { OutputChannel } from 'vscode';
+import { LogOutputChannel } from 'vscode';
 import { Arguments, ILogging } from './types';
-import { getTimeForLogging } from './util';
-
-function formatMessage(level?: string, ...data: Arguments): string {
-    return level ? `[${level.toUpperCase()} ${getTimeForLogging()}]: ${util.format(...data)}` : util.format(...data);
-}
 
 export class OutputChannelLogger implements ILogging {
-    constructor(private readonly channel: OutputChannel) {}
+    constructor(private readonly channel: LogOutputChannel) {}
 
     public traceLog(...data: Arguments): void {
         this.channel.appendLine(util.format(...data));
     }
 
     public traceError(...data: Arguments): void {
-        this.channel.appendLine(formatMessage('error', ...data));
+        this.channel.error(util.format(...data));
     }
 
     public traceWarn(...data: Arguments): void {
-        this.channel.appendLine(formatMessage('warn', ...data));
+        this.channel.warn(util.format(...data));
     }
 
     public traceInfo(...data: Arguments): void {
-        this.channel.appendLine(formatMessage('info', ...data));
+        this.channel.info(util.format(...data));
     }
 
     public traceVerbose(...data: Arguments): void {
-        this.channel.appendLine(formatMessage('debug', ...data));
+        this.channel.debug(util.format(...data));
     }
 }

src/client/testing/testController/common/server.ts

@@ -99,6 +99,7 @@ export class PythonTestServer implements ITestServer, Disposable {
             token: options.token,
             cwd: options.cwd,
             throwOnStdErr: true,
+            outputChannel: options.outChannel,
         };
 
         // Create the Python environment in which to execute the command.