tests/test_log_sys.py

@@ -1,177 +0,0 @@
-'''
-`tractor.log`-wrapping unit tests.
-
-'''
-import importlib
-from pathlib import Path
-import shutil
-import sys
-from types import ModuleType
-
-import pytest
-import tractor
-
-
-def test_root_pkg_not_duplicated_in_logger_name():
-    '''
-    When both `pkg_name` and `name` are passed and they have
-    a common `<root_name>.< >` prefix, ensure that it is not
-    duplicated in the child's `StackLevelAdapter.name: str`.
-
-    '''
-    project_name: str = 'pylib'
-    pkg_path: str = 'pylib.subpkg.mod'
-
-    proj_log = tractor.log.get_logger(
-        pkg_name=project_name,
-        mk_sublog=False,
-    )
-
-    sublog = tractor.log.get_logger(
-        pkg_name=project_name,
-        name=pkg_path,
-    )
-
-    assert proj_log is not sublog
-    assert sublog.name.count(proj_log.name) == 1
-    assert 'mod' not in sublog.name
-
-
-# ?TODO, move this into internal libs?
-# -[ ] we already use it in `modden.config._pymod` as well
-def load_module_from_path(
-    path: Path,
-    module_name: str|None = None,
-) -> ModuleType:
-    '''
-    Taken from SO,
-    https://stackoverflow.com/a/67208147
-
-    which is based on stdlib docs,
-    https://docs.python.org/3/library/importlib.html#importing-a-source-file-directly
-
-    '''
-    module_name = module_name or path.stem
-    spec = importlib.util.spec_from_file_location(
-        module_name,
-        str(path),
-    )
-    module = importlib.util.module_from_spec(spec)
-    sys.modules[module_name] = module
-    spec.loader.exec_module(module)
-    return module
-
-
-def test_implicit_mod_name_applied_for_child(
-    testdir: pytest.Pytester,
-    loglevel: str,
-):
-    '''
-    Verify that when `.log.get_logger(pkg_name='pylib')` is called
-    from a given sub-mod from within the `pylib` pkg-path, we
-    implicitly set the equiv of `name=__name__` from the caller's
-    module.
-
-    '''
-    # tractor.log.get_console_log(level=loglevel)
-    proj_name: str = 'snakelib'
-    mod_code: str = (
-        f'import tractor\n'
-        f'\n'
-        f'log = tractor.log.get_logger(pkg_name="{proj_name}")\n'
-    )
-
-    # create a sub-module for each pkg layer
-    _lib = testdir.mkpydir(proj_name)
-    pkg: Path = Path(_lib)
-    subpkg: Path = pkg / 'subpkg'
-    subpkg.mkdir()
-
-    pkgmod: Path = subpkg / "__init__.py"
-    pkgmod.touch()
-
-    _submod: Path = testdir.makepyfile(
-        _mod=mod_code,
-    )
-
-    pkg_mod = pkg / 'mod.py'
-    pkg_subpkg_submod = subpkg / 'submod.py'
-    shutil.copyfile(
-        _submod,
-        pkg_mod,
-    )
-    shutil.copyfile(
-        _submod,
-        pkg_subpkg_submod,
-    )
-    testdir.chdir()
-
-    # XXX NOTE, once the "top level" pkg mod has been
-    # imported, we can then use `import` syntax to
-    # import it's sub-pkgs and modules.
-    pkgmod = load_module_from_path(
-        Path(pkg / '__init__.py'),
-        module_name=proj_name,
-    )
-    pkg_root_log = tractor.log.get_logger(
-        pkg_name=proj_name,
-        mk_sublog=False,
-    )
-    assert pkg_root_log.name == proj_name
-    assert not pkg_root_log.logger.getChildren()
-
-    from snakelib import mod
-    assert mod.log.name == proj_name
-
-    from snakelib.subpkg import submod
-    assert (
-        submod.log.name
-        ==
-        submod.__package__  # ?TODO, use this in `.get_logger()` instead?
-        ==
-        f'{proj_name}.subpkg'
-    )
-
-    sub_logs = pkg_root_log.logger.getChildren()
-    assert len(sub_logs) == 1  # only one nested sub-pkg module
-    assert submod.log.logger in sub_logs
-
-    # breakpoint()
-
-
-# TODO, moar tests against existing feats:
-# ------ - ------
-# - [ ] color settings?
-# - [ ] header contents like,
-#   - actor + thread + task names from various conc-primitives,
-# - [ ] `StackLevelAdapter` extensions,
-#   - our custom levels/methods: `transport|runtime|cance|pdb|devx`
-# - [ ] custom-headers support?
-#
-
-# TODO, test driven dev of new-ideas/long-wanted feats,
-# ------ - ------
-# - [ ] https://github.com/goodboy/tractor/issues/244
-#  - [ ] @catern mentioned using a sync / deterministic sys
-#       and in particular `svlogd`?
-#       |_ https://smarden.org/runit/svlogd.8
-
-# - [ ] using adapter vs. filters?
-#    - https://stackoverflow.com/questions/60691759/add-information-to-every-log-message-in-python-logging/61830838#61830838
-
-# - [ ] `.at_least_level()` optimization which short circuits wtv
-#      `logging` is doing behind the scenes when the level filters
-#      the emission..?
-
-# - [ ] use of `.log.get_console_log()` in subactors and the
-#    subtleties of ensuring it actually emits from a subproc.
-
-# - [ ] this idea of activating per-subsys emissions with some
-#    kind of `.name` filter passed to the runtime or maybe configured
-#    via the root `StackLevelAdapter`?
-
-# - [ ] use of `logging.dict.dictConfig()` to simplify the impl
-#      of any of ^^ ??
-#    - https://stackoverflow.com/questions/7507825/where-is-a-complete-example-of-logging-config-dictconfig
-#    - https://docs.python.org/3/library/logging.config.html#configuration-dictionary-schema
-#    - https://docs.python.org/3/library/logging.config.html#logging.config.dictConfig

tractor/log.py

@@ -14,22 +14,11 @@
 # You should have received a copy of the GNU Affero General Public License
 # along with this program.  If not, see <https://www.gnu.org/licenses/>.
 
-'''
-An enhanced logging subsys.
+"""
+Log like a forester!
 
-An extended logging layer using (for now) the stdlib's `logging`
-+ `colorlog` which embeds concurrency-primitive/runtime info into
-records (headers) to help you better grok your distributed systems
-built on `tractor`.
-
-
-'''
+"""
 from collections.abc import Mapping
-from inspect import (
-    FrameInfo,
-    getmodule,
-    stack,
-)
 import sys
 import logging
 from logging import (
@@ -37,10 +26,8 @@ from logging import (
     Logger,
     StreamHandler,
 )
-from types import ModuleType
-import warnings
-
 import colorlog  # type: ignore
+
 import trio
 
 from ._state import current_actor
@@ -52,7 +39,7 @@ _default_loglevel: str = 'ERROR'
 # Super sexy formatting thanks to ``colorlog``.
 # (NOTE: we use the '{' format style)
 # Here, `thin_white` is just the layperson's gray.
-LOG_FORMAT: str = (
+LOG_FORMAT = (
     # "{bold_white}{log_color}{asctime}{reset}"
     "{log_color}{asctime}{reset}"
     " {bold_white}{thin_white}({reset}"
@@ -64,7 +51,7 @@ LOG_FORMAT: str = (
     " {reset}{bold_white}{thin_white}{message}"
 )
 
-DATE_FORMAT: str = '%b %d %H:%M:%S'
+DATE_FORMAT = '%b %d %H:%M:%S'
 
 # FYI, ERROR is 40
 # TODO: use a `bidict` to avoid the :155 check?
@@ -88,10 +75,7 @@ STD_PALETTE = {
     'TRANSPORT': 'cyan',
 }
 
-BOLD_PALETTE: dict[
-    str,
-    dict[int, str],
-] = {
+BOLD_PALETTE = {
     'bold': {
         level: f"bold_{color}" for level, color in STD_PALETTE.items()}
 }
@@ -113,17 +97,10 @@ def at_least_level(
     return False
 
 
-# TODO, compare with using a "filter" instead?
-# - https://stackoverflow.com/questions/60691759/add-information-to-every-log-message-in-python-logging/61830838#61830838
-#  |_corresponding dict-config,
-#    https://stackoverflow.com/questions/7507825/where-is-a-complete-example-of-logging-config-dictconfig/7507842#7507842
-#  - [ ] what's the benefit/tradeoffs?
-#
+# TODO: this isn't showing the correct '{filename}'
+# as it did before..
 class StackLevelAdapter(LoggerAdapter):
-    '''
-    A (software) stack oriented logger "adapter".
 
-    '''
     def at_least_level(
         self,
         level: str,
@@ -307,9 +284,7 @@ class ActorContextInfo(Mapping):
 
 def get_logger(
     name: str|None = None,
-    pkg_name: str = _proj_name,
-    # XXX, deprecated, use ^
-    _root_name: str|None = None,
+    _root_name: str = _proj_name,
 
     logger: Logger|None = None,
 
@@ -318,89 +293,22 @@ def get_logger(
     #  |_https://stackoverflow.com/questions/7507825/where-is-a-complete-example-of-logging-config-dictconfig
     #  |_https://docs.python.org/3/library/logging.config.html#configuration-dictionary-schema
     subsys_spec: str|None = None,
-    mk_sublog: bool = True,
 
 ) -> StackLevelAdapter:
     '''
     Return the `tractor`-library root logger or a sub-logger for
     `name` if provided.
 
-    When `name` is left null we try to auto-detect the caller's
-    `mod.__name__` and use that as a the sub-logger key.
-    This allows for example creating a module level instance like,
-
-    .. code:: python
-
-        log = tractor.log.get_logger(_root_name='mylib')
-
-    and by default all console record headers will show the caller's
-    (of any `log.<level>()`-method) correct sub-pkg's
-    + py-module-file.
-
     '''
-    if _root_name:
-        msg: str = (
-            'The `_root_name: str` param of `get_logger()` is now deprecated.\n'
-            'Use the new `pkg_name: str` instead, it is the same usage.\n'
-        )
-        warnings.warn(
-            msg,
-            DeprecationWarning,
-            stacklevel=2,
-        )
-    pkg_name: str = _root_name or pkg_name
     log: Logger
-    log = rlog = logger or logging.getLogger(pkg_name)
-
-    # Implicitly introspect the caller's module-name whenever `name`
-    # if left as the null default.
-    #
-    # When the `pkg_name` is `in` in the `mod.__name__` we presume
-    # this instance can be created as a sub-`StackLevelAdapter` and
-    # that the intention is get free module-path tracing and
-    # filtering (well once we implement that) oriented around the
-    # py-module code hierarchy of the consuming project.
-    if (
-        pkg_name != _proj_name
-        and
-        name is None
-        and
-        mk_sublog
-    ):
-        callstack: list[FrameInfo] = stack()
-        caller_fi: FrameInfo = callstack[1]
-        caller_mod: ModuleType = getmodule(caller_fi.frame)
-        if caller_mod:
-            # ?how is this `mod.__name__` defined?
-            # -> well by how the mod is imported..
-            # |_https://stackoverflow.com/a/15883682
-            mod_name: str = caller_mod.__name__
-            mod_pkg: str = caller_mod.__package__
-            log.info(
-                f'Generating sub-logger name,\n'
-                f'{mod_pkg}.{mod_name}\n'
-            )
-            # if pkg_name in caller_mod.__package__:
-            #     from tractor.devx.debug import mk_pdb
-            #     mk_pdb().set_trace()
-
-            if (
-                pkg_name
-                # and
-                # pkg_name in mod_name
-            ):
-                name = mod_name
-
-    # XXX, lowlevel debuggin..
-    # if pkg_name != _proj_name:
-        # from tractor.devx.debug import mk_pdb
-        # mk_pdb().set_trace()
+    log = rlog = logger or logging.getLogger(_root_name)
 
     if (
-        name != _proj_name
-        and
         name
+        and
+        name != _proj_name
     ):
+
         # NOTE: for handling for modules that use `get_logger(__name__)`
         # we make the following stylistic choice:
         # - always avoid duplicate project-package token
@@ -410,63 +318,24 @@ def get_logger(
         #   since in python the {filename} is always this same
         #   module-file.
 
-        rname: str = pkg_name
-        pkg_path: str = name
+        sub_name: None|str = None
+        rname, _, sub_name = name.partition('.')
+        pkgpath, _, modfilename = sub_name.rpartition('.')
 
-        # ex. modden.runtime.progman
-        # -> rname='modden', _, pkg_path='runtime.progman'
-        if pkg_name in name:
-            rname, _, pkg_path = name.partition('.')
+        # NOTE: for tractor itself never include the last level
+        # module key in the name such that something like: eg.
+        # 'tractor.trionics._broadcast` only includes the first
+        # 2 tokens in the (coloured) name part.
+        if rname == 'tractor':
+            sub_name = pkgpath
 
-        # ex. modden.runtime.progman
-        # -> pkgpath='runtime', _, leaf_mod='progman'
-        subpkg_path, _, leaf_mod = pkg_path.rpartition('.')
+        if _root_name in sub_name:
+            duplicate, _, sub_name = sub_name.partition('.')
 
-        # NOTE: special usage for passing `name=__name__`,
-        #
-        # - remove duplication of any root-pkg-name in the
-        #   (sub/child-)logger name; i.e. never include the
-        #   `pkg_name` *twice* in the top-most-pkg-name/level
-        #
-        # -> this happens normally since it is added to `.getChild()`
-        #   and as the name of its root-logger.
-        #
-        # => So for ex. (module key in the name) something like
-        #   `name='tractor.trionics._broadcast` is passed,
-        #   only includes the first 2 sub-pkg name-tokens in the
-        #   child-logger's name; the colored "pkg-namespace" header
-        #   will then correctly show the same value as `name`.
-        if rname == pkg_name:
-            pkg_path = subpkg_path
-
-        # XXX, do some double-checks for duplication of,
-        # - root-pkg-name, already in root logger
-        # - leaf-module-name already in `{filename}` header-field
-        if pkg_name in pkg_path:
-            _duplicate, _, pkg_path = pkg_path.partition('.')
-            if _duplicate:
-                # assert _duplicate == rname
-                _root_log.warning(
-                    f'Duplicate pkg-name in sub-logger key?\n'
-                    f'pkg_name = {pkg_name!r}\n'
-                    f'pkg_path = {pkg_path!r}\n'
-                )
-
-        if (
-            leaf_mod
-            and
-            leaf_mod in pkg_path
-        ):
-            _root_log.warning(
-                f'Duplicate leaf-module-name in sub-logger key?\n'
-                f'leaf_mod = {leaf_mod!r}\n'
-                f'pkg_path = {pkg_path!r}\n'
-            )
-
-        if not pkg_path:
+        if not sub_name:
             log = rlog
-        elif mk_sublog:
-            log = rlog.getChild(pkg_path)
+        else:
+            log = rlog.getChild(sub_name)
 
         log.level = rlog.level
 
@@ -481,13 +350,8 @@ def get_logger(
     for name, val in CUSTOM_LEVELS.items():
         logging.addLevelName(val, name)
 
-        # ensure our custom adapter levels exist as methods
-        assert getattr(
-            logger,
-            name.lower()
-        ), (
-            f'Logger does not define {name}'
-        )
+        # ensure customs levels exist as methods
+        assert getattr(logger, name.lower()), f'Logger does not define {name}'
 
     return logger
 
@@ -561,4 +425,4 @@ def get_loglevel() -> str:
 
 
 # global module logger for tractor itself
-_root_log: StackLevelAdapter = get_logger('tractor')
+log: StackLevelAdapter = get_logger('tractor')