Start a logging-sys unit-test module

To start ensuring that when `name=__name__` is passed we try to
de-duplicate the `_root_name` and any `leaf_mod: str` since it's already
included in the headers as `{filename}`.

Deats,
- heavily document the de-duplication `str.partition()`s in
  `.log.get_logger()` and provide the end fix by changing the predicate,
  `if rname == 'tractor':` -> `if rname == _root_name`.
  * also toss in some warnings for when we still detect duplicates.
- add todo comments around logging "filters" (vs. our "adapter").
- create the new `test_log_sys.test_root_pkg_not_duplicated()` which
  runs green with the fixes from ^.
- add a ton of test-suite todos both for existing and anticipated
  logging sys feats in the new mod.

tests/test_log_sys.py

@@ -0,0 +1,62 @@
+'''
+`tractor.log`-wrapping unit tests.
+
+'''
+import tractor
+
+
+def test_root_pkg_not_duplicated():
+
+    project_name: str = 'pylib'
+    pkg_path: str = 'pylib.subpkg.mod'
+
+    log = tractor.log.get_logger(
+        _root_name=project_name,
+    )
+
+    sublog = tractor.log.get_logger(
+        _root_name=project_name,
+        name=pkg_path,
+    )
+
+    assert log is not sublog
+    assert sublog.name.count(log.name) == 1
+    assert 'mod' not in sublog.name
+
+
+# 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

@@ -97,10 +97,17 @@ def at_least_level(
     return False
 
 
-# TODO: this isn't showing the correct '{filename}'
-# as it did before..
+# 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?
+#
 class StackLevelAdapter(LoggerAdapter):
+    '''
+    A (software) stack oriented logger "adapter".
 
+    '''
     def at_least_level(
         self,
         level: str,
@@ -283,6 +290,9 @@ class ActorContextInfo(Mapping):
 
 
 def get_logger(
+    # ?TODO, could we just grab the caller's `mod.__name__`?
+    # -[ ] do it with `inspect` says SO,
+    # |_https://stackoverflow.com/a/1095621
     name: str|None = None,
     _root_name: str = _proj_name,
 
@@ -304,9 +314,10 @@ def get_logger(
     log = rlog = logger or logging.getLogger(_root_name)
 
     if (
-        name
-        and
         name != _proj_name
+        and
+        name
+        # ^TODO? see caller_mod.__name__ as default above?
     ):
 
         # NOTE: for handling for modules that use `get_logger(__name__)`
@@ -319,18 +330,53 @@ def get_logger(
         #   module-file.
 
         sub_name: None|str = None
+
+        # ex. modden.runtime.progman
+        # -> rname='modden', _, sub_name='runtime.progman'
         rname, _, sub_name = name.partition('.')
-        pkgpath, _, modfilename = sub_name.rpartition('.')
 
-        # 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 = sub_name.rpartition('.')
 
+        # 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
+        #   `_root_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 == _root_name:
+            sub_name = 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 _root_name in sub_name:
-            duplicate, _, sub_name = sub_name.partition('.')
+            _duplicate, _, sub_name = sub_name.partition('.')
+            if _duplicate:
+                assert _duplicate == rname
+                log.warning(
+                    f'Duplicate pkg-name in sub-logger key?\n'
+                    f'_root_name = {_root_name!r}\n'
+                    f'sub_name = {sub_name!r}\n'
+                )
+
+        if leaf_mod in sub_name:
+            # XXX, for debuggin..
+            # import pdbp; pdbp.set_trace()
+            log.warning(
+                f'Duplicate leaf-module-name in sub-logger key?\n'
+                f'leaf_mod = {leaf_mod!r}\n'
+                f'sub_name = {sub_name!r}\n'
+            )
 
         if not sub_name:
             log = rlog