Merge pull request #402 from goodboy/log_sys_testing
Log sys testing, starting to get "serious" about it..copilot_typing_suggestions
commit
51ac0c623e
|
|
@ -65,7 +65,11 @@ def loglevel(request):
|
|||
import tractor
|
||||
orig = tractor.log._default_loglevel
|
||||
level = tractor.log._default_loglevel = request.config.option.loglevel
|
||||
tractor.log.get_console_log(level)
|
||||
log = tractor.log.get_console_log(
|
||||
level=level,
|
||||
name='tractor', # <- enable root logger
|
||||
)
|
||||
log.info(f'Test-harness logging level: {level}\n')
|
||||
yield level
|
||||
tractor.log._default_loglevel = orig
|
||||
|
||||
|
|
|
|||
|
|
@ -34,7 +34,10 @@ if TYPE_CHECKING:
|
|||
|
||||
# a fn that sub-instantiates a `pexpect.spawn()`
|
||||
# and returns it.
|
||||
type PexpectSpawner = Callable[[str], pty_spawn.spawn]
|
||||
type PexpectSpawner = Callable[
|
||||
[str],
|
||||
pty_spawn.spawn,
|
||||
]
|
||||
|
||||
|
||||
@pytest.fixture
|
||||
|
|
@ -109,7 +112,11 @@ def ctlc(
|
|||
'https://github.com/goodboy/tractor/issues/320'
|
||||
)
|
||||
|
||||
if mark.name == 'ctlcs_bish':
|
||||
if (
|
||||
mark.name == 'ctlcs_bish'
|
||||
and
|
||||
use_ctlc
|
||||
):
|
||||
pytest.skip(
|
||||
f'Test {node} prolly uses something from the stdlib (namely `asyncio`..)\n'
|
||||
f'The test and/or underlying example script can *sometimes* run fine '
|
||||
|
|
|
|||
|
|
@ -0,0 +1,185 @@
|
|||
'''
|
||||
`tractor.log`-wrapping unit tests.
|
||||
|
||||
'''
|
||||
from pathlib import Path
|
||||
import shutil
|
||||
from types import ModuleType
|
||||
|
||||
import pytest
|
||||
import tractor
|
||||
from tractor import (
|
||||
_code_load,
|
||||
log,
|
||||
)
|
||||
|
||||
|
||||
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'
|
||||
|
||||
assert not tractor.current_actor(
|
||||
err_on_no_runtime=False,
|
||||
)
|
||||
proj_log = log.get_logger(
|
||||
pkg_name=project_name,
|
||||
mk_sublog=False,
|
||||
)
|
||||
|
||||
sublog = 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
|
||||
|
||||
|
||||
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'
|
||||
# if you need to trace `testdir` stuff @ import-time..
|
||||
# f'breakpoint()\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)
|
||||
pkg_init_mod: Path = pkg / "__init__.py"
|
||||
pkg_init_mod.write_text(mod_code)
|
||||
|
||||
subpkg: Path = pkg / 'subpkg'
|
||||
subpkg.mkdir()
|
||||
subpkgmod: Path = subpkg / "__init__.py"
|
||||
subpkgmod.touch()
|
||||
subpkgmod.write_text(mod_code)
|
||||
|
||||
_submod: Path = testdir.makepyfile(
|
||||
_mod=mod_code,
|
||||
)
|
||||
|
||||
pkg_submod = pkg / 'mod.py'
|
||||
pkg_subpkg_submod = subpkg / 'submod.py'
|
||||
shutil.copyfile(
|
||||
_submod,
|
||||
pkg_submod,
|
||||
)
|
||||
shutil.copyfile(
|
||||
_submod,
|
||||
pkg_subpkg_submod,
|
||||
)
|
||||
testdir.chdir()
|
||||
# NOTE, to introspect the py-file-module-layout use (in .xsh
|
||||
# syntax): `ranger @str(testdir)`
|
||||
|
||||
# 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.
|
||||
subpkgmod: ModuleType = _code_load.load_module_from_path(
|
||||
Path(pkg / '__init__.py'),
|
||||
module_name=proj_name,
|
||||
)
|
||||
|
||||
pkg_root_log = log.get_logger(
|
||||
pkg_name=proj_name,
|
||||
mk_sublog=False,
|
||||
)
|
||||
# the top level pkg-mod, created just now,
|
||||
# by above API call.
|
||||
assert pkg_root_log.name == proj_name
|
||||
assert not pkg_root_log.logger.getChildren()
|
||||
#
|
||||
# ^TODO! test this same output but created via a `get_logger()`
|
||||
# call in the `snakelib.__init__py`!!
|
||||
|
||||
# NOTE, the pkg-level "init mod" should of course
|
||||
# have the same name as the package ns-path.
|
||||
import snakelib as init_mod
|
||||
assert init_mod.log.name == proj_name
|
||||
|
||||
# NOTE, a first-pkg-level sub-module should only
|
||||
# use the package-name since the leaf-node-module
|
||||
# will be included in log headers by default.
|
||||
from snakelib import mod
|
||||
assert mod.log.name == proj_name
|
||||
|
||||
from snakelib import subpkg
|
||||
assert (
|
||||
subpkg.log.name
|
||||
==
|
||||
subpkg.__package__
|
||||
==
|
||||
f'{proj_name}.subpkg'
|
||||
)
|
||||
|
||||
from snakelib.subpkg import submod
|
||||
assert (
|
||||
submod.log.name
|
||||
==
|
||||
submod.__package__
|
||||
==
|
||||
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
|
||||
|
||||
|
||||
# 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
|
||||
|
|
@ -17,9 +17,8 @@ from tractor.log import (
|
|||
get_console_log,
|
||||
get_logger,
|
||||
)
|
||||
log = get_logger(__name__)
|
||||
|
||||
|
||||
log = get_logger()
|
||||
|
||||
_resource: int = 0
|
||||
|
||||
|
|
|
|||
|
|
@ -37,7 +37,7 @@ from .ipc._uds import UDSAddress
|
|||
if TYPE_CHECKING:
|
||||
from ._runtime import Actor
|
||||
|
||||
log = get_logger(__name__)
|
||||
log = get_logger()
|
||||
|
||||
|
||||
# TODO, maybe breakout the netns key to a struct?
|
||||
|
|
@ -259,6 +259,8 @@ def wrap_address(
|
|||
|
||||
case _:
|
||||
# import pdbp; pdbp.set_trace()
|
||||
# from tractor.devx import mk_pdb
|
||||
# mk_pdb().set_trace()
|
||||
raise TypeError(
|
||||
f'Can not wrap unwrapped-address ??\n'
|
||||
f'type(addr): {type(addr)!r}\n'
|
||||
|
|
|
|||
|
|
@ -0,0 +1,48 @@
|
|||
# tractor: structured concurrent "actors".
|
||||
# Copyright 2018-eternity Tyler Goodlet.
|
||||
|
||||
# This program is free software: you can redistribute it and/or modify
|
||||
# it under the terms of the GNU Affero General Public License as published by
|
||||
# the Free Software Foundation, either version 3 of the License, or
|
||||
# (at your option) any later version.
|
||||
|
||||
# This program is distributed in the hope that it will be useful,
|
||||
# but WITHOUT ANY WARRANTY; without even the implied warranty of
|
||||
# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
|
||||
# GNU Affero General Public License for more details.
|
||||
|
||||
# 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/>.
|
||||
|
||||
'''
|
||||
(Hot) coad (re-)load utils for python.
|
||||
|
||||
'''
|
||||
import importlib
|
||||
from pathlib import Path
|
||||
import sys
|
||||
from types import ModuleType
|
||||
|
||||
# ?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
|
||||
|
|
@ -113,7 +113,7 @@ if TYPE_CHECKING:
|
|||
CallerInfo,
|
||||
)
|
||||
|
||||
log = get_logger(__name__)
|
||||
log = get_logger()
|
||||
|
||||
|
||||
class Unresolved:
|
||||
|
|
@ -2391,16 +2391,18 @@ async def open_context_from_portal(
|
|||
case trio.Cancelled():
|
||||
logmeth = log.cancel
|
||||
cause: str = 'cancelled'
|
||||
msg: str = (
|
||||
f'ctx {ctx.side!r}-side {cause!r} with,\n'
|
||||
f'{ctx.repr_outcome()!r}\n'
|
||||
)
|
||||
|
||||
# XXX explicitly report on any non-graceful-taskc cases
|
||||
case _:
|
||||
cause: str = 'errored'
|
||||
logmeth = log.exception
|
||||
msg: str = f'ctx {ctx.side!r}-side {cause!r} with,\n'
|
||||
|
||||
logmeth(
|
||||
f'ctx {ctx.side!r}-side {cause!r} with,\n'
|
||||
f'{ctx.repr_outcome()!r}\n'
|
||||
)
|
||||
logmeth(msg)
|
||||
|
||||
if debug_mode():
|
||||
# async with debug.acquire_debug_lock(portal.actor.uid):
|
||||
|
|
|
|||
|
|
@ -53,7 +53,7 @@ if TYPE_CHECKING:
|
|||
from ._runtime import Actor
|
||||
|
||||
|
||||
log = get_logger(__name__)
|
||||
log = get_logger()
|
||||
|
||||
|
||||
@acm
|
||||
|
|
|
|||
|
|
@ -50,7 +50,7 @@ if TYPE_CHECKING:
|
|||
from ._spawn import SpawnMethodKey
|
||||
|
||||
|
||||
log = get_logger(__name__)
|
||||
log = get_logger()
|
||||
|
||||
|
||||
def _mp_main(
|
||||
|
|
@ -72,11 +72,15 @@ def _mp_main(
|
|||
spawn_ctx: mp.context.BaseContext = try_set_start_method(start_method)
|
||||
assert spawn_ctx
|
||||
|
||||
# XXX, enable root log at level
|
||||
if actor.loglevel is not None:
|
||||
log.info(
|
||||
f'Setting loglevel for {actor.uid} to {actor.loglevel}'
|
||||
f'Setting loglevel for {actor.uid} to {actor.loglevel!r}'
|
||||
)
|
||||
get_console_log(
|
||||
level=actor.loglevel,
|
||||
name='tractor',
|
||||
)
|
||||
get_console_log(actor.loglevel)
|
||||
|
||||
# TODO: use scops headers like for `trio` below!
|
||||
# (well after we libify it maybe..)
|
||||
|
|
@ -126,8 +130,12 @@ def _trio_main(
|
|||
parent_addr=parent_addr
|
||||
)
|
||||
|
||||
# XXX, enable root log at level
|
||||
if actor.loglevel is not None:
|
||||
get_console_log(actor.loglevel)
|
||||
get_console_log(
|
||||
level=actor.loglevel,
|
||||
name='tractor',
|
||||
)
|
||||
log.info(
|
||||
f'Starting `trio` subactor from parent @ '
|
||||
f'{parent_addr}\n'
|
||||
|
|
|
|||
|
|
@ -69,7 +69,7 @@ from ._streaming import (
|
|||
if TYPE_CHECKING:
|
||||
from ._runtime import Actor
|
||||
|
||||
log = get_logger(__name__)
|
||||
log = get_logger()
|
||||
|
||||
|
||||
class Portal:
|
||||
|
|
|
|||
|
|
@ -289,10 +289,12 @@ async def open_root_actor(
|
|||
for uw_addr in uw_reg_addrs
|
||||
]
|
||||
|
||||
loglevel = (
|
||||
loglevel: str = (
|
||||
loglevel
|
||||
or log._default_loglevel
|
||||
).upper()
|
||||
or
|
||||
log._default_loglevel
|
||||
)
|
||||
loglevel: str = loglevel.upper()
|
||||
|
||||
if (
|
||||
debug_mode
|
||||
|
|
@ -323,7 +325,10 @@ async def open_root_actor(
|
|||
)
|
||||
|
||||
assert loglevel
|
||||
_log = log.get_console_log(loglevel)
|
||||
_log = log.get_console_log(
|
||||
level=loglevel,
|
||||
name='tractor',
|
||||
)
|
||||
assert _log
|
||||
|
||||
# TODO: factor this into `.devx._stackscope`!!
|
||||
|
|
|
|||
|
|
@ -59,7 +59,7 @@ if TYPE_CHECKING:
|
|||
from .ipc import Channel
|
||||
|
||||
|
||||
log = get_logger(__name__)
|
||||
log = get_logger()
|
||||
|
||||
|
||||
# TODO: the list
|
||||
|
|
|
|||
|
|
@ -62,7 +62,7 @@ if TYPE_CHECKING:
|
|||
from .ipc import IPCServer
|
||||
|
||||
|
||||
log = get_logger(__name__)
|
||||
log = get_logger()
|
||||
|
||||
|
||||
class ActorNursery:
|
||||
|
|
|
|||
|
|
@ -49,7 +49,7 @@ from tractor.msg import (
|
|||
import wrapt
|
||||
|
||||
|
||||
log = get_logger(__name__)
|
||||
log = get_logger()
|
||||
|
||||
# TODO: yeah, i don't love this and we should prolly just
|
||||
# write a decorator that actually keeps a stupid ref to the func
|
||||
|
|
|
|||
|
|
@ -51,7 +51,7 @@ from tractor import (
|
|||
)
|
||||
from tractor.devx import debug
|
||||
|
||||
log = logmod.get_logger(__name__)
|
||||
log = logmod.get_logger()
|
||||
|
||||
|
||||
if TYPE_CHECKING:
|
||||
|
|
|
|||
|
|
@ -59,7 +59,7 @@ from ._sigint import (
|
|||
_ctlc_ignore_header as _ctlc_ignore_header
|
||||
)
|
||||
|
||||
log = get_logger(__name__)
|
||||
log = get_logger()
|
||||
|
||||
# ----------------
|
||||
# XXX PKG TODO XXX
|
||||
|
|
|
|||
|
|
@ -84,7 +84,7 @@ _crash_msg: str = (
|
|||
'Opening a pdb REPL in crashed actor'
|
||||
)
|
||||
|
||||
log = get_logger(__package__)
|
||||
log = get_logger()
|
||||
|
||||
|
||||
class BoxedMaybeException(Struct):
|
||||
|
|
|
|||
|
|
@ -47,7 +47,7 @@ if TYPE_CHECKING:
|
|||
Actor,
|
||||
)
|
||||
|
||||
log = get_logger(__name__)
|
||||
log = get_logger()
|
||||
|
||||
_ctlc_ignore_header: str = (
|
||||
'Ignoring SIGINT while debug REPL in use'
|
||||
|
|
|
|||
|
|
@ -58,7 +58,7 @@ from ._sigint import (
|
|||
_ctlc_ignore_header as _ctlc_ignore_header
|
||||
)
|
||||
|
||||
log = get_logger(__package__)
|
||||
log = get_logger()
|
||||
|
||||
|
||||
async def maybe_wait_for_debugger(
|
||||
|
|
|
|||
|
|
@ -93,7 +93,7 @@ if TYPE_CHECKING:
|
|||
# from ._post_mortem import BoxedMaybeException
|
||||
from ._repl import PdbREPL
|
||||
|
||||
log = get_logger(__package__)
|
||||
log = get_logger()
|
||||
|
||||
_pause_msg: str = 'Opening a pdb REPL in paused actor'
|
||||
_repl_fail_msg: str|None = (
|
||||
|
|
@ -628,7 +628,7 @@ def _set_trace(
|
|||
log.pdb(
|
||||
f'{_pause_msg}\n'
|
||||
f'>(\n'
|
||||
f'|_{actor.uid}\n'
|
||||
f'|_{actor.aid.uid}\n'
|
||||
f' |_{task}\n' # @ {actor.uid}\n'
|
||||
# f'|_{task}\n'
|
||||
# ^-TODO-^ more compact pformating?
|
||||
|
|
|
|||
|
|
@ -81,7 +81,7 @@ if TYPE_CHECKING:
|
|||
BoxedMaybeException,
|
||||
)
|
||||
|
||||
log = get_logger(__name__)
|
||||
log = get_logger()
|
||||
|
||||
|
||||
class LockStatus(
|
||||
|
|
|
|||
|
|
@ -60,7 +60,7 @@ if TYPE_CHECKING:
|
|||
from ._transport import MsgTransport
|
||||
|
||||
|
||||
log = get_logger(__name__)
|
||||
log = get_logger()
|
||||
|
||||
_is_windows = platform.system() == 'Windows'
|
||||
|
||||
|
|
|
|||
|
|
@ -72,7 +72,7 @@ if TYPE_CHECKING:
|
|||
from .._supervise import ActorNursery
|
||||
|
||||
|
||||
log = log.get_logger(__name__)
|
||||
log = log.get_logger()
|
||||
|
||||
|
||||
async def maybe_wait_on_canced_subs(
|
||||
|
|
|
|||
|
|
@ -59,7 +59,7 @@ except ImportError:
|
|||
pass
|
||||
|
||||
|
||||
log = get_logger(__name__)
|
||||
log = get_logger()
|
||||
|
||||
|
||||
SharedMemory = disable_mantracker()
|
||||
|
|
|
|||
|
|
@ -41,7 +41,7 @@ from tractor.ipc._transport import (
|
|||
)
|
||||
|
||||
|
||||
log = get_logger(__name__)
|
||||
log = get_logger()
|
||||
|
||||
|
||||
class TCPAddress(
|
||||
|
|
|
|||
|
|
@ -56,7 +56,7 @@ from tractor.msg import (
|
|||
if TYPE_CHECKING:
|
||||
from tractor._addr import Address
|
||||
|
||||
log = get_logger(__name__)
|
||||
log = get_logger()
|
||||
|
||||
|
||||
# (codec, transport)
|
||||
|
|
|
|||
|
|
@ -63,7 +63,7 @@ if TYPE_CHECKING:
|
|||
from ._runtime import Actor
|
||||
|
||||
|
||||
log = get_logger(__name__)
|
||||
log = get_logger()
|
||||
|
||||
|
||||
def unwrap_sockpath(
|
||||
|
|
@ -166,6 +166,10 @@ class UDSAddress(
|
|||
)
|
||||
if actor:
|
||||
sockname: str = '::'.join(actor.uid) + f'@{pid}'
|
||||
# ?^TODO, for `multiaddr`'s parser we can't use the `::`
|
||||
# above^, SO maybe a `.` or something else here?
|
||||
# sockname: str = '.'.join(actor.uid) + f'@{pid}'
|
||||
# -[ ] CURRENTLY using `.` BREAKS TEST SUITE tho..
|
||||
else:
|
||||
prefix: str = '<unknown-actor>'
|
||||
if is_root_process():
|
||||
|
|
|
|||
373
tractor/log.py
373
tractor/log.py
|
|
@ -14,11 +14,23 @@
|
|||
# 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/>.
|
||||
|
||||
"""
|
||||
Log like a forester!
|
||||
'''
|
||||
An enhanced logging subsys.
|
||||
|
||||
"""
|
||||
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 functools import partial
|
||||
from inspect import (
|
||||
FrameInfo,
|
||||
getmodule,
|
||||
stack,
|
||||
)
|
||||
import sys
|
||||
import logging
|
||||
from logging import (
|
||||
|
|
@ -26,20 +38,24 @@ from logging import (
|
|||
Logger,
|
||||
StreamHandler,
|
||||
)
|
||||
import colorlog # type: ignore
|
||||
from types import ModuleType
|
||||
import warnings
|
||||
|
||||
import colorlog # type: ignore
|
||||
# ?TODO, some other (modern) alt libs?
|
||||
# import coloredlogs
|
||||
# import colored_traceback.auto # ?TODO, need better config?
|
||||
import trio
|
||||
|
||||
from ._state import current_actor
|
||||
|
||||
|
||||
_proj_name: str = 'tractor'
|
||||
_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 = (
|
||||
LOG_FORMAT: str = (
|
||||
# "{bold_white}{log_color}{asctime}{reset}"
|
||||
"{log_color}{asctime}{reset}"
|
||||
" {bold_white}{thin_white}({reset}"
|
||||
|
|
@ -51,7 +67,7 @@ LOG_FORMAT = (
|
|||
" {reset}{bold_white}{thin_white}{message}"
|
||||
)
|
||||
|
||||
DATE_FORMAT = '%b %d %H:%M:%S'
|
||||
DATE_FORMAT: str = '%b %d %H:%M:%S'
|
||||
|
||||
# FYI, ERROR is 40
|
||||
# TODO: use a `bidict` to avoid the :155 check?
|
||||
|
|
@ -75,7 +91,10 @@ STD_PALETTE = {
|
|||
'TRANSPORT': 'cyan',
|
||||
}
|
||||
|
||||
BOLD_PALETTE = {
|
||||
BOLD_PALETTE: dict[
|
||||
str,
|
||||
dict[int, str],
|
||||
] = {
|
||||
'bold': {
|
||||
level: f"bold_{color}" for level, color in STD_PALETTE.items()}
|
||||
}
|
||||
|
|
@ -97,9 +116,26 @@ 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".
|
||||
|
||||
'''
|
||||
@property
|
||||
def level(self) -> str:
|
||||
'''
|
||||
The currently set `str` emit level (in lowercase).
|
||||
|
||||
'''
|
||||
return logging.getLevelName(
|
||||
self.getEffectiveLevel()
|
||||
).lower()
|
||||
|
||||
def at_least_level(
|
||||
self,
|
||||
|
|
@ -248,9 +284,14 @@ def pformat_task_uid(
|
|||
return f'{task.name}[{tid_part}]'
|
||||
|
||||
|
||||
_curr_actor_no_exc = partial(
|
||||
current_actor,
|
||||
err_on_no_runtime=False,
|
||||
)
|
||||
|
||||
_conc_name_getters = {
|
||||
'task': pformat_task_uid,
|
||||
'actor': lambda: current_actor(),
|
||||
'actor': lambda: _curr_actor_no_exc(),
|
||||
'actor_name': lambda: current_actor().name,
|
||||
'actor_uid': lambda: current_actor().uid[1][:6],
|
||||
}
|
||||
|
|
@ -282,9 +323,16 @@ class ActorContextInfo(Mapping):
|
|||
return f'no {key} context'
|
||||
|
||||
|
||||
_proj_name: str = 'tractor'
|
||||
|
||||
|
||||
def get_logger(
|
||||
name: str|None = None,
|
||||
_root_name: str = _proj_name,
|
||||
# ^NOTE, setting `name=_proj_name=='tractor'` enables the "root
|
||||
# logger" for `tractor` itself.
|
||||
pkg_name: str = _proj_name,
|
||||
# XXX, deprecated, use ^
|
||||
_root_name: str|None = None,
|
||||
|
||||
logger: Logger|None = None,
|
||||
|
||||
|
|
@ -293,49 +341,287 @@ 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,
|
||||
_strict_debug: bool = False,
|
||||
|
||||
) -> StackLevelAdapter:
|
||||
'''
|
||||
Return the `tractor`-library root logger or a sub-logger for
|
||||
`name` if provided.
|
||||
|
||||
'''
|
||||
log: Logger
|
||||
log = rlog = logger or logging.getLogger(_root_name)
|
||||
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
|
||||
|
||||
def get_caller_mod(
|
||||
frames_up:int = 2
|
||||
):
|
||||
'''
|
||||
Attempt to get the module which called `tractor.get_logger()`.
|
||||
|
||||
'''
|
||||
callstack: list[FrameInfo] = stack()
|
||||
caller_fi: FrameInfo = callstack[frames_up]
|
||||
caller_mod: ModuleType = getmodule(caller_fi.frame)
|
||||
return caller_mod
|
||||
|
||||
# --- Auto--naming-CASE ---
|
||||
# -------------------------
|
||||
# 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 to get free module-path tracing and
|
||||
# filtering (well once we implement that) oriented around the
|
||||
# py-module code hierarchy of the consuming project.
|
||||
#
|
||||
if (
|
||||
mk_sublog
|
||||
and
|
||||
name is None
|
||||
and
|
||||
pkg_name
|
||||
):
|
||||
if (caller_mod := get_caller_mod()):
|
||||
# ?XXX how is this `caller_mod.__name__` defined?
|
||||
# => well by how the mod is imported.. XD
|
||||
# |_https://stackoverflow.com/a/15883682
|
||||
#
|
||||
# if pkg_name in caller_mod.__package__:
|
||||
# from tractor.devx.debug import mk_pdb
|
||||
# mk_pdb().set_trace()
|
||||
|
||||
mod_ns_path: str = caller_mod.__name__
|
||||
mod_pkg_ns_path: str = caller_mod.__package__
|
||||
if (
|
||||
mod_pkg_ns_path in mod_ns_path
|
||||
or
|
||||
pkg_name in mod_ns_path
|
||||
):
|
||||
# proper_mod_name = mod_ns_path.lstrip(
|
||||
proper_mod_name = mod_pkg_ns_path.removeprefix(
|
||||
f'{pkg_name}.'
|
||||
)
|
||||
name = proper_mod_name
|
||||
|
||||
elif (
|
||||
pkg_name
|
||||
# and
|
||||
# pkg_name in mod_ns_path
|
||||
):
|
||||
name = mod_ns_path
|
||||
|
||||
if _strict_debug:
|
||||
msg: str = (
|
||||
f'@ {get_caller_mod()}\n'
|
||||
f'Generating sub-logger name,\n'
|
||||
f'{pkg_name}.{name}\n'
|
||||
)
|
||||
if _curr_actor_no_exc():
|
||||
_root_log.debug(msg)
|
||||
elif pkg_name != _proj_name:
|
||||
print(
|
||||
f'=> tractor.log.get_logger():\n'
|
||||
f'{msg}\n'
|
||||
)
|
||||
|
||||
# build a root logger instance
|
||||
log: Logger
|
||||
rlog = log = (
|
||||
logger
|
||||
or
|
||||
logging.getLogger(pkg_name)
|
||||
)
|
||||
|
||||
# XXX, lowlevel debuggin..
|
||||
# if pkg_name != _proj_name:
|
||||
# from tractor.devx.debug import mk_pdb
|
||||
# mk_pdb().set_trace()
|
||||
|
||||
# NOTE: for handling for modules that use the unecessary,
|
||||
# `get_logger(__name__)`
|
||||
#
|
||||
# we make the following stylistic choice:
|
||||
# - always avoid duplicate project-package token
|
||||
# in msg output: i.e. tractor.tractor.ipc._chan.py in header
|
||||
# looks ridiculous XD
|
||||
# - never show the leaf module name in the {name} part
|
||||
# since in python the {filename} is always this same
|
||||
# module-file.
|
||||
if (
|
||||
name
|
||||
and
|
||||
name != _proj_name
|
||||
# ?TODO? more correct?
|
||||
# _proj_name not in name
|
||||
name != pkg_name
|
||||
):
|
||||
# ex. modden.runtime.progman
|
||||
# -> rname='modden', _, pkg_path='runtime.progman'
|
||||
if (
|
||||
pkg_name
|
||||
and
|
||||
pkg_name in name
|
||||
):
|
||||
proper_name: str = name.removeprefix(
|
||||
f'{pkg_name}.'
|
||||
)
|
||||
msg: str = (
|
||||
f'@ {get_caller_mod()}\n'
|
||||
f'Duplicate pkg-name in sub-logger `name`-key?\n'
|
||||
f'pkg_name = {pkg_name!r}\n'
|
||||
f'name = {name!r}\n'
|
||||
f'\n'
|
||||
f'=> You should change your input params to,\n'
|
||||
f'get_logger(\n'
|
||||
f' pkg_name={pkg_name!r}\n'
|
||||
f' name={proper_name!r}\n'
|
||||
f')'
|
||||
)
|
||||
# assert _duplicate == rname
|
||||
if _curr_actor_no_exc():
|
||||
_root_log.warning(msg)
|
||||
else:
|
||||
print(
|
||||
f'=> tractor.log.get_logger() ERROR:\n'
|
||||
f'{msg}\n'
|
||||
)
|
||||
|
||||
# NOTE: for handling for modules that use `get_logger(__name__)`
|
||||
# we make the following stylistic choice:
|
||||
# - always avoid duplicate project-package token
|
||||
# in msg output: i.e. tractor.tractor.ipc._chan.py in header
|
||||
# looks ridiculous XD
|
||||
# - never show the leaf module name in the {name} part
|
||||
# since in python the {filename} is always this same
|
||||
# module-file.
|
||||
name = proper_name
|
||||
|
||||
sub_name: None|str = None
|
||||
rname, _, sub_name = name.partition('.')
|
||||
pkgpath, _, modfilename = sub_name.rpartition('.')
|
||||
rname: str = pkg_name
|
||||
pkg_path: str = name
|
||||
|
||||
# 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
|
||||
|
||||
if _root_name in sub_name:
|
||||
duplicate, _, sub_name = sub_name.partition('.')
|
||||
# (
|
||||
# rname,
|
||||
# _,
|
||||
# pkg_path,
|
||||
# ) = name.partition('.')
|
||||
|
||||
if not sub_name:
|
||||
# For ex. 'modden.runtime.progman'
|
||||
# -> pkgpath='runtime', _, leaf_mod='progman'
|
||||
(
|
||||
subpkg_path,
|
||||
_,
|
||||
leaf_mod,
|
||||
) = pkg_path.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
|
||||
# `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 (
|
||||
# XXX, TRY to remove duplication cases
|
||||
# which get warn-logged on below!
|
||||
(
|
||||
# when, subpkg_path == pkg_path
|
||||
subpkg_path
|
||||
and
|
||||
rname == pkg_name
|
||||
)
|
||||
# ) or (
|
||||
# # when, pkg_path == leaf_mod
|
||||
# pkg_path
|
||||
# and
|
||||
# leaf_mod == pkg_path
|
||||
# )
|
||||
):
|
||||
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 (
|
||||
_strict_debug
|
||||
and
|
||||
pkg_name
|
||||
and
|
||||
pkg_name in pkg_path
|
||||
):
|
||||
_duplicate, _, pkg_path = pkg_path.partition('.')
|
||||
if _duplicate:
|
||||
msg: str = (
|
||||
f'@ {get_caller_mod()}\n'
|
||||
f'Duplicate pkg-name in sub-logger key?\n'
|
||||
f'pkg_name = {pkg_name!r}\n'
|
||||
f'pkg_path = {pkg_path!r}\n'
|
||||
)
|
||||
# assert _duplicate == rname
|
||||
if _curr_actor_no_exc():
|
||||
_root_log.warning(msg)
|
||||
else:
|
||||
print(
|
||||
f'=> tractor.log.get_logger() ERROR:\n'
|
||||
f'{msg}\n'
|
||||
)
|
||||
# XXX, should never get here?
|
||||
breakpoint()
|
||||
if (
|
||||
_strict_debug
|
||||
and
|
||||
leaf_mod
|
||||
and
|
||||
leaf_mod in pkg_path
|
||||
):
|
||||
msg: str = (
|
||||
f'@ {get_caller_mod()}\n'
|
||||
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 _curr_actor_no_exc():
|
||||
_root_log.warning(msg)
|
||||
else:
|
||||
print(
|
||||
f'=> tractor.log.get_logger() ERROR:\n'
|
||||
f'{msg}\n'
|
||||
)
|
||||
|
||||
# mk/get underlying (sub-)`Logger`
|
||||
if (
|
||||
not pkg_path
|
||||
and
|
||||
leaf_mod == pkg_name
|
||||
):
|
||||
# breakpoint()
|
||||
log = rlog
|
||||
else:
|
||||
log = rlog.getChild(sub_name)
|
||||
|
||||
elif mk_sublog:
|
||||
# breakpoint()
|
||||
log = rlog.getChild(pkg_path)
|
||||
|
||||
log.level = rlog.level
|
||||
|
||||
|
|
@ -350,8 +636,13 @@ def get_logger(
|
|||
for name, val in CUSTOM_LEVELS.items():
|
||||
logging.addLevelName(val, name)
|
||||
|
||||
# ensure customs levels exist as methods
|
||||
assert getattr(logger, name.lower()), f'Logger does not define {name}'
|
||||
# ensure our custom adapter levels exist as methods
|
||||
assert getattr(
|
||||
logger,
|
||||
name.lower()
|
||||
), (
|
||||
f'Logger does not define {name}'
|
||||
)
|
||||
|
||||
return logger
|
||||
|
||||
|
|
@ -425,4 +716,4 @@ def get_loglevel() -> str:
|
|||
|
||||
|
||||
# global module logger for tractor itself
|
||||
log: StackLevelAdapter = get_logger('tractor')
|
||||
_root_log: StackLevelAdapter = get_logger('tractor')
|
||||
|
|
|
|||
|
|
@ -68,7 +68,7 @@ from tractor.log import get_logger
|
|||
if TYPE_CHECKING:
|
||||
from tractor._context import Context
|
||||
|
||||
log = get_logger(__name__)
|
||||
log = get_logger()
|
||||
|
||||
|
||||
# TODO: unify with `MsgCodec` by making `._dec` part this?
|
||||
|
|
|
|||
|
|
@ -77,7 +77,7 @@ if TYPE_CHECKING:
|
|||
from tractor._streaming import MsgStream
|
||||
|
||||
|
||||
log = get_logger(__name__)
|
||||
log = get_logger()
|
||||
|
||||
|
||||
_def_any_pldec: MsgDec[Any] = mk_dec(spec=Any)
|
||||
|
|
|
|||
|
|
@ -51,7 +51,7 @@ from tractor.log import get_logger
|
|||
# from tractor._addr import UnwrappedAddress
|
||||
|
||||
|
||||
log = get_logger('tractor.msgspec')
|
||||
log = get_logger()
|
||||
|
||||
# type variable for the boxed payload field `.pld`
|
||||
PayloadT = TypeVar('PayloadT')
|
||||
|
|
@ -202,7 +202,10 @@ class SpawnSpec(
|
|||
# TODO: similar to the `Start` kwargs spec needed below, we need
|
||||
# a hard `Struct` def for all of these fields!
|
||||
_parent_main_data: dict
|
||||
_runtime_vars: dict[str, Any]
|
||||
_runtime_vars: (
|
||||
dict[str, Any]
|
||||
#|RuntimeVars # !TODO
|
||||
)
|
||||
# ^NOTE see `._state._runtime_vars: dict`
|
||||
|
||||
# module import capability
|
||||
|
|
|
|||
|
|
@ -71,7 +71,7 @@ from outcome import (
|
|||
Outcome,
|
||||
)
|
||||
|
||||
log: StackLevelAdapter = get_logger(__name__)
|
||||
log: StackLevelAdapter = get_logger()
|
||||
|
||||
|
||||
__all__ = [
|
||||
|
|
|
|||
|
|
@ -42,7 +42,7 @@ from trio.lowlevel import current_task
|
|||
from msgspec import Struct
|
||||
from tractor.log import get_logger
|
||||
|
||||
log = get_logger(__name__)
|
||||
log = get_logger()
|
||||
|
||||
# TODO: use new type-vars syntax from 3.12
|
||||
# https://realpython.com/python312-new-features/#dedicated-type-variable-syntax
|
||||
|
|
|
|||
|
|
@ -49,7 +49,7 @@ if TYPE_CHECKING:
|
|||
from tractor import ActorNursery
|
||||
|
||||
|
||||
log = get_logger(__name__)
|
||||
log = get_logger()
|
||||
|
||||
# A regular invariant generic type
|
||||
T = TypeVar("T")
|
||||
|
|
|
|||
|
|
@ -34,7 +34,7 @@ from typing import (
|
|||
import trio
|
||||
from tractor.log import get_logger
|
||||
|
||||
log = get_logger(__name__)
|
||||
log = get_logger()
|
||||
|
||||
|
||||
if TYPE_CHECKING:
|
||||
|
|
@ -246,23 +246,12 @@ async def maybe_raise_from_masking_exc(
|
|||
type(exc_match) # masked type
|
||||
)
|
||||
|
||||
# Add to masked `exc_ctx`
|
||||
if do_warn:
|
||||
exc_ctx.add_note(note)
|
||||
|
||||
if (
|
||||
do_warn
|
||||
and
|
||||
type(exc_match) in always_warn_on
|
||||
):
|
||||
log.warning(note)
|
||||
|
||||
if (
|
||||
do_warn
|
||||
and
|
||||
raise_unmasked
|
||||
):
|
||||
# don't unmask already known "special" cases..
|
||||
if len(masked) < 2:
|
||||
# don't unmask already known "special" cases..
|
||||
if (
|
||||
_mask_cases
|
||||
and
|
||||
|
|
@ -283,11 +272,26 @@ async def maybe_raise_from_masking_exc(
|
|||
)
|
||||
raise exc_match
|
||||
|
||||
raise exc_ctx from exc_match
|
||||
# ^?TODO, see above but, possibly unmasking sub-exc
|
||||
# entries if there are > 1
|
||||
# else:
|
||||
# await pause(shield=True)
|
||||
|
||||
if type(exc_match) in always_warn_on:
|
||||
import traceback
|
||||
trace: list[str] = traceback.format_exception(
|
||||
type(exc_ctx),
|
||||
exc_ctx,
|
||||
exc_ctx.__traceback__
|
||||
)
|
||||
tb_str: str = ''.join(trace)
|
||||
log.warning(tb_str)
|
||||
# XXX, for debug
|
||||
# from tractor import pause
|
||||
# await pause(shield=True)
|
||||
|
||||
if raise_unmasked:
|
||||
raise exc_ctx from exc_match
|
||||
|
||||
# ??TODO, see above but, possibly unmasking sub-exc
|
||||
# entries if there are > 1
|
||||
# else:
|
||||
# await pause(shield=True)
|
||||
else:
|
||||
raise
|
||||
|
|
|
|||
Loading…
Reference in New Issue