allure-pytest raises an exception when writing to log from a thread started inside pytest_generate_tests

[eltimen]

I'm submitting a ...

• bug report

What is the current behavior?

I have a function that creates a thread which writes some information in the log. When I try to call it from pytest_generate_tests allure-pytest raises the following StopIteration exception:

platform linux -- Python 3.9.16, pytest-7.4.0, pluggy-1.2.0
rootdir: /mnt/c/storage/allure_bug
plugins: allure-pytest-2.13.2
collecting ... Exception in thread Thread-1:
Traceback (most recent call last):
  File "/usr/lib/python3.9/threading.py", line 980, in _bootstrap_inner
    self.run()
  File "/usr/lib/python3.9/threading.py", line 917, in run
    self._target(*self._args, **self._kwargs)
  File "/mnt/c/storage/allure_bug/conftest.py", line 17, in _thread
    log.warning('thread')
  File "/usr/lib/python3.9/logging/init.py", line 1458, in warning
    self._log(WARNING, msg, args, **kwargs)
  File "/usr/lib/python3.9/logging/init.py", line 1589, in _log
    self.handle(record)
  File "/usr/lib/python3.9/logging/init.py", line 1599, in handle
    self.callHandlers(record)
  File "/usr/lib/python3.9/logging/init.py", line 1661, in callHandlers
    hdlr.handle(record)
  File "/usr/lib/python3.9/logging/init.py", line 952, in handle
    self.emit(record)
  File "/mnt/c/storage/allure_bug/conftest.py", line 9, in emit
    with step(f'[{record.levelname}] {record.getMessage()}'):
  File "/tmp/test_venv/lib/python3.9/site-packages/allure_commons/_allure.py", line 179, in enter
    plugin_manager.hook.start_step(uuid=self.uuid, title=self.title, params=self.params)
  File "/tmp/test_venv/lib/python3.9/site-packages/pluggy/_hooks.py", line 433, in call
    return self._hookexec(self.name, self._hookimpls, kwargs, firstresult)
  File "/tmp/test_venv/lib/python3.9/site-packages/pluggy/_manager.py", line 112, in _hookexec
    return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
  File "/tmp/test_venv/lib/python3.9/site-packages/pluggy/_callers.py", line 116, in _multicall
    raise exception.with_traceback(exception.traceback)
  File "/tmp/test_venv/lib/python3.9/site-packages/pluggy/_callers.py", line 80, in _multicall
    res = hook_impl.function(*args)
  File "/tmp/test_venv/lib/python3.9/site-packages/allure_pytest/listener.py", line 48, in start_step
    self.allure_logger.start_step(None, uuid, step)
  File "/tmp/test_venv/lib/python3.9/site-packages/allure_commons/reporter.py", line 128, in start_step
    parent_uuid = parent_uuid if parent_uuid else self._last_executable()
  File "/tmp/test_venv/lib/python3.9/site-packages/allure_commons/reporter.py", line 71, in _last_executable
    for _uuid in reversed(self._items):
  File "/tmp/test_venv/lib/python3.9/site-packages/allure_commons/reporter.py", line 39, in reversed
    return self.thread_context.reversed()
  File "/tmp/test_venv/lib/python3.9/site-packages/allure_commons/reporter.py", line 21, in thread_context
    uuid, last_item = next(reversed(self._thread_context[self._init_thread].items()))
StopIteration
collected 1 item

test_bug.py test
.

If the current behavior is a bug, please provide the steps to reproduce and if possible a minimal demo of the problem

1. Install requirements pip install pytest allure-pytest
2. Prepare the demo test suite:

conftest.py

import logging
from threading import Thread

from allure import step

class AllureLoggerHandler(logging.Handler):
    def emit(self, record):
        with step(f'[{record.levelname}] {record.getMessage()}'):
            pass

log = logging.getLogger()
allure_handler = AllureLoggerHandler()
log.addHandler(allure_handler)

def _thread():
    log.warning('thread')

def pytest_generate_tests(metafunc):
    log.info('generate')
    thread = Thread(target=_thread)
    thread.start()
    thread.join(100)

test_bug.py

def test_allure_log():
    print('test')

3. Run test: pytest -s --alluredir=./allure

What is the expected behavior?

Test suite works without any exceptions

What is the motivation / use case for changing the behavior?

Please tell us about your environment:

• Allure version: 2.22.0
• Test framework: pytest 7.4.0
• Allure adaptor: allure-pytest 2.13.2

Other information

[delatrie]

Hi, @eltimen, thanks for the report.

Looks like our long-running problem with concurrency. See #697 and #720
We'll fix that eventually, but unfortunately, I can't estimate the date right now.

[dmakhno]

@delatrie, I got the same issue having a fork of pytest-parallell. Aka main and threads can call pytest_runtest_protocol concurrently.

Afaiu,
ThreadContextItems.thread_context

    if not context and threading.current_thread() is not self._init_thread:
            uuid, last_item = next(reversed(self._thread_context[self._init_thread].items()))
            context[uuid] = last_item

tries to bind non-initial thread to init thread. It was made in #647 to support steps from thread.

In my case, this was not an issue. Worker threads and main - should act independently.
And in order to combine everything together, sacrificing "steps/attachement in sub threads"

I got to do following monkey-patching, pseudo code

# ... somewhere in pytest_configure
if not config.pluginmanager.hasplugin('allure_listener'):
   return
allure_listener = config.pluginmanager.get_plugin('allure_listener')

# 1. do not bind threads
allure_listener.allure_logger._items = PatchedThreadContextItems()  # no "if" in thread_context property

# 2. thread independent cache, in orther ThreadContextItems do not complain on fixtures/containers in other thread's context
class ThreadItemCache(threading.local, listener.ItemCache):
    pass
allure_listener._cache = ThreadItemCache()

# 3. timeline fix. Make `_thread` a property,  to cope when test teardown wrong labels, 
delattr(allure_listener, '_thread')
listener.AllureListener._thread = property(lambda self: threading.current_thread().name)

Writing, maybe to help gain a better fix, especially having heated 3.13t.
Do not have enough knowledge to contribute, to make solid fix and strategy matching.