Skip to content

Commit

Permalink
Add comments clarifying the logger isolation in tests
Browse files Browse the repository at this point in the history
  • Loading branch information
abravalheri committed Jun 11, 2018
1 parent ae9d96e commit 58a41e0
Show file tree
Hide file tree
Showing 3 changed files with 38 additions and 0 deletions.
3 changes: 3 additions & 0 deletions src/pyscaffold/log.py
Original file line number Diff line number Diff line change
Expand Up @@ -279,6 +279,9 @@ def indent(self, count=1):
# --------------------------------------
# Note how the spacing between activity and subject in the
# second entry is greater than the equivalent in the first one.
Note:
This method is not thread-safe and should be used with care.
"""
prev = self.nesting
self.nesting += count
Expand Down
28 changes: 28 additions & 0 deletions tests/conftest.py
Original file line number Diff line number Diff line change
Expand Up @@ -69,17 +69,44 @@ def logger():

@pytest.fixture(autouse=True)
def isolated_logger(request, logger):
# In Python the common idiom of using logging is to share the same log
# globally, even between threads. While this is usually OK because
# internally Python takes care of locking the shared resources, it also
# makes very difficult to build things on top of the logging system without
# using the same global approach.
# For simplicity, to make things easier to extension developers and because
# PyScaffold not really uses multiple threads, this is the case in
# `pyscaffold.log`.
# On the other hand, shared state and streams can make the testing
# environment a real pain, since we are messing with everything all the
# time, specially when running tests in parallel (so we not guarantee the
# execution order).
# This fixture do a huge effort in trying to isolate as much as possible
# each test function regarding logging. We keep the global object, so the
# tests can be seamless, but internally replace the underlying native
# loggers and handlers for "one-shot" ones.
# (Of course, we can keep the same global object just because the plugins
# for running tests in parallel are based in multiple processes instead of
# threads, otherwise we would need another strategy)

if 'original_logger' in request.keywords:
# Some tests need to check the original implementation to make sure
# side effects of the shared object are consistent. We have to try to
# make them as few as possible.
yield
return

# Get a fresh new logger, not used anywhere
raw_logger = logging.getLogger(uniqstr())
# ^ Python docs advert against instantiating Loggers directly and instruct
# devs to use `getLogger`. So we use a unique name to guarantee we get a
# new logger each time.
raw_logger.setLevel(logging.NOTSET)
new_handler = logging.StreamHandler()

# Replace the internals of the LogAdapter
# --> Messing with global state: don't try this at home ...
# (if we start to use threads, we cannot do this)
old_handler = logger.handler
old_formatter = logger.formatter
old_wrapped = logger.wrapped
Expand All @@ -106,6 +133,7 @@ def isolated_logger(request, logger):
logger.nesting = old_nesting

new_handler.close()
# ^ Force the handler to not be re-used


@pytest.fixture
Expand Down
7 changes: 7 additions & 0 deletions tests/test_log.py
Original file line number Diff line number Diff line change
Expand Up @@ -25,6 +25,13 @@
match_report
)

# When adding tests to this file, please have in mind that the global shared
# logging strategy followed by Python and PyScaffold can lead to pain while
# testing. Try to create a new ReportLogger with a brand new underlying native
# Logger object as much as possible (see test_pass_handler for an example), and
# just deactivate the `isolated_logger` fixture with the `original_logger` mark
# if really necessary.


@pytest.fixture
def uniq_raw_logger():
Expand Down

0 comments on commit 58a41e0

Please sign in to comment.