diff --git a/tests/conftest.py b/tests/conftest.py index b198aee0..7d9f01b8 100644 --- a/tests/conftest.py +++ b/tests/conftest.py @@ -120,74 +120,13 @@ def cpu_scaling_factor() -> float: return 1. -def pytest_addoption( - parser: pytest.Parser, -): - # ?TODO? should this be exposed from our `._testing.pytest` - # plugin or should we make it more explicit with `--tl` for - # tractor logging like we do in other client projects? - parser.addoption( - "--ll", - action="store", - dest='loglevel', - default=None, - help="logging level to set when testing", - ) - - -@pytest.fixture(scope='session', autouse=True) -def loglevel( - request: pytest.FixtureRequest, -) -> str|None: - import tractor - orig = tractor.log._default_loglevel - flag_level: str|None = request.config.option.loglevel - - if flag_level is not None: - tractor.log._default_loglevel = flag_level - - log = tractor.log.get_console_log( - level=flag_level, - name='tractor', # <- enable root logger - ) - log.info( - f'Test-harness set runtime loglevel: {flag_level!r}\n' - ) - yield flag_level - tractor.log._default_loglevel = orig - - -@pytest.fixture(scope='function') -def test_log( - request: pytest.FixtureRequest, - loglevel: str, -) -> tractor.log.StackLevelAdapter: - ''' - Deliver a per test-module-fn logger instance for reporting from - within actual test bodies/fixtures. - - For example this can be handy to report certain error cases from - exception handlers using `test_log.exception()`. - - ''' - modname: str = request.function.__module__ - log = tractor.log.get_logger( - name=modname, # <- enable root logger - # pkg_name='tests', - ) - _log = tractor.log.get_console_log( - level=loglevel, - logger=log, - name=modname, - # pkg_name='tests', - ) - _log.debug( - f'In-test-logging requested\n' - f'test_log.name: {log.name!r}\n' - f'level: {loglevel!r}\n' - - ) - yield _log +# NOTE, the `--ll`/`--tl` CLI flags + the `loglevel`, `test_log` +# and `testing_pkg_name` fixtures have been factored into the +# `tractor._testing.pytest` plugin (loaded via the `-p` entry in +# `pyproject.toml`'s `[tool.pytest.ini_options]`) so downstream +# consuming projects (eg. `modden`) inherit them for free. The +# plugin's `testing_pkg_name` fixture defaults to `'tractor'`, so +# this suite keeps treating `--ll` as the runtime loglevel. @pytest.fixture(scope='session') diff --git a/tractor/_testing/pytest.py b/tractor/_testing/pytest.py index 38d9ebec..8d3d174e 100644 --- a/tractor/_testing/pytest.py +++ b/tractor/_testing/pytest.py @@ -405,6 +405,46 @@ def pytest_addoption( help="Transport protocol to use under the `tractor.ipc.Channel`", ) + # console loglevel for the test-session, scoped to the + # consuming-project's OWN pkg-hierarchy (see the + # `testing_pkg_name` fixture). For `tractor` itself this IS the + # runtime loglevel; downstream projects use `--ll` for their own + # ("internal") app-logging and `--tl` for tractor-as-runtime. + parser.addoption( + "--ll", + "--loglevel", + action="store", + dest='loglevel', + default=None, + help=( + "console loglevel to set for the test session, scoped to " + "the consuming-project pkg (see `testing_pkg_name`). " + "Falls through as the `--tl` default." + ), + ) + + # tractor-as-runtime loglevel, DISTINCT from `--ll` so downstream + # projects can split their app-logs from the `tractor.*` runtime + # hierarchy. Accepts a `tractor.log` "logging-spec" (see + # `tractor.log.apply_logspec()`). + parser.addoption( + "--tl", + "--tractor-loglevel", + action="store", + dest='tractor_loglevel', + default=None, + help=( + "loglevel (or logging-spec) for `tractor`-as-runtime, " + "distinct from `--ll`. Accepts a bare level (eg. " + "'info', 'cancel') or a sub-logger filter-spec, " + "':,...' (eg. " + "'devx:runtime,trionics:cancel'). Falls back to `--ll` " + "when unset. Mirrors the logging-spec grammar consumed " + "by `tractor.log.apply_logspec()` (see its sub-pkg " + "granularity caveat)." + ), + ) + def pytest_configure( config: pytest.Config, @@ -547,6 +587,135 @@ def debug_mode( return debug_mode +@pytest.fixture(scope='session') +def testing_pkg_name() -> str: + ''' + Root pkg-name of the project consuming this plugin, used to + scope `--ll` "internal"/app-level console logging into that + project's OWN `tractor.log.get_logger(pkg_name=<.>)` hierarchy + — distinct from the `tractor.*` runtime hierarchy configured + via `--tl`. + + Defaults to `'tractor'` (so tractor's own suite treats `--ll` + as the runtime level). Downstream projects override this from + their `conftest.py`, eg. + + .. code:: python + + @pytest.fixture(scope='session') + def testing_pkg_name() -> str: + return 'modden' + + ''' + return 'tractor' + + +@pytest.fixture( + scope='session', + autouse=True, +) +def loglevel( + request: pytest.FixtureRequest, + testing_pkg_name: str, +) -> str|None: + ''' + Resolve + apply the test-session console loglevels and yield + the `tractor`-runtime level (also passed to + `open_root_actor(loglevel=<.>)` by `@tractor_test`). + + - `--tl `: tractor-runtime level (falls back to the + generic `--ll`); applied to the `tractor.*` logger hierarchy + and `tractor.log._default_loglevel` via + `tractor.log.apply_logspec()`. + - `--ll `: the consuming-project's OWN console loglevel, + applied to its `testing_pkg_name` hierarchy when that isn't + `tractor` itself. + + ''' + import tractor + orig: str = tractor.log._default_loglevel + + ll: str|None = request.config.option.loglevel + tl: str|None = request.config.option.tractor_loglevel + + # tractor-runtime loglevel: explicit `--tl` wins, else fall + # back to the generic `--ll`, else leave the lib default. + logspec: str|None = tl if tl is not None else ll + tractor_level: str|None = None + if logspec is not None: + tractor_level, _ = tractor.log.apply_logspec( + logspec, + default_level=ll, + pkg_name='tractor', + ) + if tractor_level is not None: + tractor.log._default_loglevel = tractor_level + + # consuming-project ("internal") console logging at the generic + # `--ll` level, scoped to ITS OWN pkg-hierarchy (NOT `tractor.*`) + # so downstream projects can split app-logs from runtime-logs. + if ( + ll is not None + and + testing_pkg_name + and + testing_pkg_name != 'tractor' + ): + tractor.log.get_console_log( + level=ll, + pkg_name=testing_pkg_name, + name=testing_pkg_name, + ) + + log = tractor.log.get_console_log( + level=tractor_level, + name='tractor', # <- enable root logger + ) + log.info( + f'Test-harness set session loglevels:\n' + f'tractor-runtime (`--tl`/`--ll`): {tractor_level!r}\n' + f'{testing_pkg_name!r} (`--ll`): {ll!r}\n' + ) + yield tractor_level + tractor.log._default_loglevel = orig + + +@pytest.fixture(scope='function') +def test_log( + request: pytest.FixtureRequest, + loglevel: str, + testing_pkg_name: str, +) -> tractor.log.StackLevelAdapter: + ''' + Deliver a per test-module-fn logger instance for reporting from + within actual test bodies/fixtures. + + For example this can be handy to report certain error cases from + exception handlers using `test_log.exception()`. + + The logger is scoped to the consuming-project's + `testing_pkg_name` hierarchy so downstream suites' in-test logs + land under their own pkg, not `tractor.*`. + + ''' + modname: str = request.function.__module__ + log = tractor.log.get_logger( + name=modname, + pkg_name=testing_pkg_name, + ) + _log = tractor.log.get_console_log( + level=loglevel, + logger=log, + name=modname, + ) + _log.debug( + f'In-test-logging requested\n' + f'test_log.name: {log.name!r}\n' + f'level: {loglevel!r}\n' + ) + yield _log + + @pytest.fixture(scope='session') def spawn_backend( request: pytest.FixtureRequest, diff --git a/tractor/log.py b/tractor/log.py index 8d164d87..d11901a7 100644 --- a/tractor/log.py +++ b/tractor/log.py @@ -711,6 +711,160 @@ def get_console_log( return log +# A `tractor` "logging-spec": a compact, code-free way for a +# consuming project's test-iface (or runtime) to dial-in console +# loglevels across the lib's logger hierarchy. Mirrors the grammar +# consumed by `modden.runtime.daemon.setup_tractor_logging()`. +# +# Accepted forms (`str|bool`), +# - `True` -> enable the `pkg_name` root-logger at +# `default_level` (or 'cancel'). +# - `False` -> disable (no-op, configure nothing). +# - 'info' -> a bare level for the root-logger. +# - 'sub:info,x:cancel' -> per-sub-logger levels; each `` is +# RELATIVE to `pkg_name` (must NOT include +# the `pkg_name` token itself), eg. +# 'devx:runtime,trionics:cancel'. +# +# !GRANULARITY CAVEAT! sub-logger names are matched at the +# `pkg_name.` *logger* level, which (per `get_logger()`'s +# name-derivation) is effectively the *sub-package* granularity: +# - leaf module-names are stripped, so 'devx.debug' collapses to +# the same `tractor.devx` logger as a bare 'devx' (you CANNOT +# isolate a single leaf-module's emits from its sub-pkg). +# - top-level lib modules (eg. `tractor.to_asyncio`) emit under the +# *root* `pkg_name` logger (their `__package__` IS `pkg_name`), +# so a 'to_asyncio:' filter targets a phantom child that +# nothing emits to -> no-op. Use the root-level form for those. +LogSpec = str|bool + + +def parse_logspec( + logspec: LogSpec, + default_level: str|None = None, + pkg_name: str = _proj_name, + +) -> dict[str|None, str]: + ''' + Parse a `tractor` "logging-spec" (see `LogSpec`) into a + `{sublog_name|None: level}` mapping where a `None` key denotes + the `pkg_name` root-logger itself. + + ''' + match logspec: + + # explicit disable -> configure nothing. + case False: + return {} + + # enable the root-logger at the fallback level. + case True: + return {None: (default_level or 'cancel')} + + case str(spec): + filters: list[str] = [ + part.strip() + for part in spec.split(',') + if part.strip() + ] + # i. a bare level (no sub-logger filtering), + # eg. 'info' | 'cancel' + if ( + len(filters) == 1 + and + ':' not in filters[0] + ): + return {None: filters[0]} + + # ii. a per-sub-logger filter-spec of the form, + # ':,<.. N-other-parts>' + # eg. 'to_asyncio:cancel,devx._debug:runtime' + out: dict[str|None, str] = {} + for log_filter in filters: + name, sep, level = log_filter.partition(':') + if not sep: + raise ValueError( + f'Invalid `tractor` logging-spec part!\n' + f'{log_filter!r}\n' + f'\n' + f'Mixed bare-level + sub-logger filters are ' + f'not supported; every comma-part must be ' + f'`:`.\n' + ) + # the sub-logger name is RELATIVE to `pkg_name`; + # duplicating the pkg-token is a user error since + # the root-logger already IS `pkg_name`. + if pkg_name in name.split('.'): + raise ValueError( + f'logging-spec sub-name should NOT include ' + f'the `pkg_name={pkg_name!r}` token!\n' + f'got name={name!r}\n' + ) + out[name] = level + return out + + case _: + raise ValueError( + f'Invalid `tractor` logging-spec!\n' + f'{logspec!r}\n' + ) + + +def apply_logspec( + logspec: LogSpec, + default_level: str|None = None, + pkg_name: str = _proj_name, + +) -> tuple[ + str|None, + dict[str, StackLevelAdapter], +]: + ''' + Parse + apply a `tractor` "logging-spec" (see `parse_logspec()`): + enable a `colorlog` stderr console handler for each + (sub-)logger named in the spec at its requested level. + + Returns a 2-tuple, + - the resolved "primary" runtime-level: the root-logger level if + the spec set one, else `default_level`; suitable for passing + to `open_root_actor(loglevel=<.>)`, + - a `{logger_name: StackLevelAdapter}` map of every logger the + spec touched. + + ''' + specs: dict[str|None, str] = parse_logspec( + logspec, + default_level=default_level, + pkg_name=pkg_name, + ) + logs: dict[str, StackLevelAdapter] = {} + for sub_name, level in specs.items(): + # NOTE, pass the RELATIVE sub-name (no `pkg_name.` prefix) + # to avoid `get_logger()`'s duplicate-pkg-token warning; + # it re-adds the pkg-name via `.getChild()` internally. + log: StackLevelAdapter = get_console_log( + level=level, + pkg_name=pkg_name, + name=(sub_name or pkg_name), + ) + # XXX, a sub-logger filter is "authoritative" for its + # subtree: it gets its OWN stderr handler (added by + # `get_console_log()` above), so DON'T also let its records + # propagate up to a root `pkg_name`-logger handler — that + # would double-emit every line when a root-level console + # (eg. via `--ll`) is also active. The root-level form + # (`sub_name is None`) keeps default propagation. + if sub_name is not None: + log.logger.propagate = False + logs[log.name] = log + + primary_level: str|None = specs.get(None, default_level) + return ( + primary_level, + logs, + ) + + def get_loglevel() -> str: return _default_loglevel