Python commands are printed twice in the output channel

[kimadeline]

Environment data

• VS Code version: 1.37.1
• Extension version (available under the Extensions sidebar): master 39cf9e0
• OS and version: macOS Mojave 10.14.6

Expected behaviour

Python commands should only be displayed once in the "Python" output channel.

Actual behaviour

Some Python commands (for example linting or formatting) are displayed twice.

Steps to reproduce:

1. Start debugging the extension
2. Open a python file and enable linting or formatting on save
3. Set 2 breakpoints:

   • vscode-python/src/client/common/process/logger.ts

     Line 19 in 39cf9e0

     const argsList = args.reduce((accumulator, current, index) => {

   • vscode-python/src/client/common/process/proc.ts

     Line 184 in 39cf9e0

     this.emit('exec', file, args, options);

4. Save the file
5. Notice that this.emit('exec', file, args, options); is only hit once, but the debugger stops twice onlogger.logProcess().

Cause

We register 2 'exec' listeners to the python process:

• In the create or createActivatedEnvironment method in PythonExecutionFactory:
  

  vscode-python/src/client/common/process/pythonExecutionFactory.ts

  Lines 31 to 37 in 39cf9e0

  	public async create(options: ExecutionFactoryCreationOptions): Promise<IPythonExecutionService> {
  	const pythonPath = options.pythonPath ? options.pythonPath : this.configService.getSettings(options.resource).pythonPath;
  	const processService: IProcessService = await this.processServiceFactory.create(options.resource);
  	const processLogger = this.serviceContainer.get<IProcessLogger>(IProcessLogger);
  	processService.on('exec', processLogger.logProcess.bind(processLogger));
  	return new PythonExecutionService(this.serviceContainer, processService, pythonPath);
  	}

• But also in the call to await this.processServiceFactory.create:
  

  vscode-python/src/client/common/process/processFactory.ts

  Lines 21 to 26 in 39cf9e0

  	public async create(resource?: Uri): Promise<IProcessService> {
  	const customEnvVars = await this.envVarsService.getEnvironmentVariables(resource);
  	const proc: IProcessService = new ProcessService(this.decoder, customEnvVars);
  	this.disposableRegistry.push(proc);
  	return proc.on('exec', this.processLogger.logProcess.bind(this.processLogger));
  	}

[kbd]

As an easy-to-reproduce example of this, when I use "Format Document", the Python output log appears to show that Black is run twice:

~/.../.venv/bin/python -m black --diff --quiet ~/.../src/app/views.py.c64f5302f131d47a9d9da0861e28ac43.tmp
cwd: ~/...
~/.../.venv/bin/python -m black --diff --quiet ~/.../src/app/views.py.c64f5302f131d47a9d9da0861e28ac43.tmp
cwd: ~/...

[DanielNoord]

Is there anything we can provide to get this issue some traction? I am mainly interested in whether commands are actually ran twice (which it seems it does). I'll gladly perform any tests or work with somebody to get this issue fixed!

[kimadeline]

Hi @DanielNoord, if this issue gets more upvotes it'll help us prioritize it.

I am mainly interested in whether commands are actually ran twice (which it seems it does)

They are not, it is just the logger being called twice.