logs appearing twice when using custom logger and xdist

[greeshmad]

I have the following plugin

import logging import os import pytest from shutil import copyfile from utilities import constants, shared_resources

class OutputHandler(object): """ This plugin handles the output captured for each test. By default it will print all output, separated by stderr, stdout, log, and exceptions. Optionally, this output can also be written to a file per test. """ def init(self, log_to_console=True, log_to_file=False): self.exceptions = {} self.log_to_file = log_to_file self.log_to_console = log_to_console self.log_formatter = logging.Formatter( fmt='%(asctime)s %(message)s', datefmt='%Y-%m-%d %H:%M:%S')

def get_header(self, text):
    return "\n" + " {} ".format(text).center(60, "-")

def get_subheader(self, text):
    return "\n" + " {} ".format(text).center(30, "-")

def get_logger(self, file_path):
    logger = logging.getLogger(file_path)
    logger.setLevel(logging.DEBUG)
    logger.propagate = False

    if self.log_to_console:
        stream_handler = logging.StreamHandler()
        stream_handler.setFormatter(self.log_formatter)
        logger.addHandler(stream_handler)

    if self.log_to_file:
        file_handler = logging.FileHandler(file_path)
        file_handler.setFormatter(self.log_formatter)
        logger.addHandler(file_handler)

    return logger

def pytest_runtest_logreport(self, report):
    """
    This is called 3 times per test, once for each phase: setup/call/teardown
    An exception that happens in one of these phases is only shown in the report for that phase.
    stdout, stderr and log statements are built up and kept through all phases.

    """

    # Don't print anything until all output is done being captured in the final phase
    if report.when == "teardown":

        logs_directory = shared_resources.get_logs_directory()
        file_path = os.path.abspath(os.path.join(logs_directory, report.location[-1]))
        logger = self.get_logger(file_path)
        logger.info("\n{}".format(report.nodeid))

        for report_section_name, report_section_content in report.sections:
            logger.info(self.get_header(report_section_name))
            logger.info(report_section_content)


        # Upload the log file to VSO
        if self.log_to_file:
            # Logger doesn't close file until process ends so VSO can't upload it. Make a copy for VSO.
            copied_file_path = file_path + ".log"
            file_path = copyfile(file_path, copied_file_path)
            print("\n##vso[task.uploadfile]" + copied_file_path + "\n")

        logger.info("\n\n")
        logger.disabled = True

def pytest_addoption(parser): group = parser.getgroup(constants.plugin_group_name) group._addoption("--log-to-files", action="store_true", help="log each test to a file")

def pytest_configure(config): log_to_file = config.getvalue("--log-to-files") log_to_console = not config.getvalue("--quiet")

if log_to_file or log_to_console:
    config.pluginmanager.register(
        OutputHandler(log_to_console=log_to_console, log_to_file=log_to_file),
        "output_handler")

when I run tests using command pytest {test path}

all the stdout, stderr from tests are captured and printed to console in teardown stage once as expected.

when I run tests using distributed pytest -n 3 {test path}

all the stdout and stderr from tests are captured and printed to console twice.

If I replace log.info with print

the console logs only appear once.

Any idea what is causing the duplication? I tried logger.propogate = False but didnt work

[greeshmad]

I am using pytest-xdist 1.34 pytest 6.1.1

[levid0s]

Having the same issue. Any solution yet?