Live logging from background threads is racy and can make capfd/capsys lose messages

The live logging plugin will "temporarily suspend" std{out,err} capture in order to emit logging messages. This is prone to race conditions when logging happens from background threads.

Pytest capture works by replacing sys.std{out,err} with alternate implementations that capture output in various way. The _LiveLoggingStreamHandler.emit() function will temporarily "suspend capture" meaning revert stdout/err to the default implementation. It is possible for the main thread to print while capture is suspended because a background thread is logging, when that happens output will not be captured.

This is normally hard to notice but if you use capsys or capfd to check exact output from user code then messages might get lost because of this race condition. This can lead to flaky tests where sometimes some messages are missing from capfd.getouterr()

Python code is often single-threaded, one way to encounter this is using the popular paramiko ssh library because it does a lot of debug logging from a background transport thread.

• The issue happens when activating --log-cli at a level that actually prints logs from a background thread.
• The various --capture do not influence this, all are affected
• Using caplog fixture does not work as a workaround
• This affects both capsys and capfd

Sample code, run with pytest --log-cli-level=INFO. This reliably reproduces the issue for me.

import logging
import sys
import threading
import time

import pytest

logger = logging.getLogger(__name__)


def noisy_thread(print_count: int, sleep_delta: float) -> None:
    for i in range(print_count):
        logger.info("thread-%d", i)
        time.sleep(sleep_delta)


def test_capfd_race_with_logging(capfd: pytest.CaptureFixture) -> None:
    assert isinstance(capfd, pytest.CaptureFixture)
    main_print_count = 1000
    main_sleep_delta = 0.001
    thread_print_count = 1000
    thread_sleep_delta = 0.001
    t = threading.Thread(
        target=noisy_thread,
        kwargs={
            "print_count": thread_print_count,
            "sleep_delta": thread_sleep_delta,
        },
    )

    expected_stderr = ""
    t.start()
    for i in range(main_print_count):
        msg = f"main-{i}\n"
        expected_stderr += msg
        sys.stderr.write(msg)
        time.sleep(main_sleep_delta)
    t.join()

    out, err = capfd.readouterr()
    loss_count = 0
    for i in range(main_print_count):
        msg = f"main-{i}\n"
        if msg not in err:
            logger.warning("missing: %r", msg)
            loss_count += 1
    logger.error("loss_count=%d", loss_count)
    assert out == "" and expected_stderr == err and loss_count == 0

Possible fixes:

1. Print a warning whenever "capture suspend" is used outside the main thread.
2. Replace "capture suspend" with writing directly to origin stdout/stderr as saved by CaptureManager
3. Add heavy-duty locking in capture manager and the replacement sys.stdout/stderr streams so that logging and user printing never overlaps

I don't know how easy it would be to implement solution (2) above, but it seems to me that the whole suspend/resume dance shouldn't actually be required when the original streams are still available.

Reproduce the race with the provided test and --log-cli-level=INFO, then inspect _LiveLoggingStreamHandler.emit(), CaptureManager, and the replacement sys.stdout/sys.stderr streams. Compare the proposed capture-suspend approaches and verify that capfd and capsys retain all main-thread output while background-thread logs remain visible.