Compare commits
No commits in common. "final_eg_refinements" and "main" have entirely different histories.
final_eg_r
...
main
|
|
@ -1,145 +0,0 @@
|
|||
from contextlib import (
|
||||
contextmanager as cm,
|
||||
# TODO, any diff in async case(s)??
|
||||
# asynccontextmanager as acm,
|
||||
)
|
||||
from functools import partial
|
||||
|
||||
import tractor
|
||||
import trio
|
||||
|
||||
|
||||
log = tractor.log.get_logger(__name__)
|
||||
tractor.log.get_console_log('info')
|
||||
|
||||
@cm
|
||||
def teardown_on_exc(
|
||||
raise_from_handler: bool = False,
|
||||
):
|
||||
'''
|
||||
You could also have a teardown handler which catches any exc and
|
||||
does some required teardown. In this case the problem is
|
||||
compounded UNLESS you ensure the handler's scope is OUTSIDE the
|
||||
`ux.aclose()`.. that is in the caller's enclosing scope.
|
||||
|
||||
'''
|
||||
try:
|
||||
yield
|
||||
except BaseException as _berr:
|
||||
berr = _berr
|
||||
log.exception(
|
||||
f'Handling termination teardown in child due to,\n'
|
||||
f'{berr!r}\n'
|
||||
)
|
||||
if raise_from_handler:
|
||||
# XXX teardown ops XXX
|
||||
# on termination these steps say need to be run to
|
||||
# ensure wider system consistency (like the state of
|
||||
# remote connections/services).
|
||||
#
|
||||
# HOWEVER, any bug in this teardown code is also
|
||||
# masked by the `tx.aclose()`!
|
||||
# this is also true if `_tn.cancel_scope` is
|
||||
# `.cancel_called` by the parent in a graceful
|
||||
# request case..
|
||||
|
||||
# simulate a bug in teardown handler.
|
||||
raise RuntimeError(
|
||||
'woopsie teardown bug!'
|
||||
)
|
||||
|
||||
raise # no teardown bug.
|
||||
|
||||
|
||||
async def finite_stream_to_rent(
|
||||
tx: trio.abc.SendChannel,
|
||||
child_errors_mid_stream: bool,
|
||||
|
||||
task_status: trio.TaskStatus[
|
||||
trio.CancelScope,
|
||||
] = trio.TASK_STATUS_IGNORED,
|
||||
):
|
||||
async with (
|
||||
# XXX without this unmasker the mid-streaming RTE is never
|
||||
# reported since it is masked by the `tx.aclose()`
|
||||
# call which in turn raises `Cancelled`!
|
||||
#
|
||||
# NOTE, this is WITHOUT doing any exception handling
|
||||
# inside the child task!
|
||||
#
|
||||
# TODO, uncomment next LoC to see the supprsessed beg[RTE]!
|
||||
# tractor.trionics.maybe_raise_from_masking_exc(),
|
||||
|
||||
tx as tx, # .aclose() is the guilty masker chkpt!
|
||||
trio.open_nursery() as _tn,
|
||||
):
|
||||
# pass our scope back to parent for supervision\
|
||||
# control.
|
||||
task_status.started(_tn.cancel_scope)
|
||||
|
||||
with teardown_on_exc(
|
||||
raise_from_handler=not child_errors_mid_stream,
|
||||
):
|
||||
for i in range(100):
|
||||
log.info(
|
||||
f'Child tx {i!r}\n'
|
||||
)
|
||||
if (
|
||||
child_errors_mid_stream
|
||||
and
|
||||
i == 66
|
||||
):
|
||||
# oh wait but WOOPS there's a bug
|
||||
# in that teardown code!?
|
||||
raise RuntimeError(
|
||||
'woopsie, a mid-streaming bug!?'
|
||||
)
|
||||
|
||||
await tx.send(i)
|
||||
|
||||
|
||||
async def main(
|
||||
# TODO! toggle this for the 2 cases!
|
||||
# 1. child errors mid-stream while parent is also requesting
|
||||
# (graceful) cancel of that child streamer.
|
||||
#
|
||||
# 2. child contains a teardown handler which contains a
|
||||
# bug and raises.
|
||||
#
|
||||
child_errors_mid_stream: bool,
|
||||
):
|
||||
tx, rx = trio.open_memory_channel(1)
|
||||
|
||||
async with (
|
||||
trio.open_nursery() as tn,
|
||||
rx as rx,
|
||||
):
|
||||
|
||||
_child_cs = await tn.start(
|
||||
partial(
|
||||
finite_stream_to_rent,
|
||||
child_errors_mid_stream=child_errors_mid_stream,
|
||||
tx=tx,
|
||||
)
|
||||
)
|
||||
async for msg in rx:
|
||||
log.info(
|
||||
f'Rent rx {msg!r}\n'
|
||||
)
|
||||
|
||||
# simulate some external cancellation
|
||||
# request **JUST BEFORE** the child errors.
|
||||
if msg == 65:
|
||||
log.cancel(
|
||||
f'Cancelling parent on,\n'
|
||||
f'msg={msg}\n'
|
||||
f'\n'
|
||||
f'Simulates OOB cancel request!\n'
|
||||
)
|
||||
tn.cancel_scope.cancel()
|
||||
|
||||
|
||||
if __name__ == '__main__':
|
||||
|
||||
for case in [True, False]:
|
||||
trio.run(main, case)
|
||||
|
|
@ -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
|
||||
|
|
@ -117,9 +117,11 @@ def test_acm_embedded_nursery_propagates_enter_err(
|
|||
async with (
|
||||
trio.open_nursery() as tn,
|
||||
tractor.trionics.maybe_raise_from_masking_exc(
|
||||
tn=tn,
|
||||
unmask_from=(
|
||||
(trio.Cancelled,) if unmask_from_canc
|
||||
else ()
|
||||
trio.Cancelled
|
||||
if unmask_from_canc
|
||||
else None
|
||||
),
|
||||
)
|
||||
):
|
||||
|
|
@ -134,7 +136,8 @@ def test_acm_embedded_nursery_propagates_enter_err(
|
|||
with tractor.devx.maybe_open_crash_handler(
|
||||
pdb=debug_mode,
|
||||
) as bxerr:
|
||||
assert not bxerr.value
|
||||
if bxerr:
|
||||
assert not bxerr.value
|
||||
|
||||
async with (
|
||||
wraps_tn_that_always_cancels() as tn,
|
||||
|
|
@ -142,12 +145,11 @@ def test_acm_embedded_nursery_propagates_enter_err(
|
|||
assert not tn.cancel_scope.cancel_called
|
||||
assert 0
|
||||
|
||||
if debug_mode:
|
||||
assert (
|
||||
(err := bxerr.value)
|
||||
and
|
||||
type(err) is AssertionError
|
||||
)
|
||||
assert (
|
||||
(err := bxerr.value)
|
||||
and
|
||||
type(err) is AssertionError
|
||||
)
|
||||
|
||||
with pytest.raises(ExceptionGroup) as excinfo:
|
||||
trio.run(_main)
|
||||
|
|
|
|||
|
|
@ -284,10 +284,6 @@ async def _errors_relayed_via_ipc(
|
|||
try:
|
||||
yield # run RPC invoke body
|
||||
|
||||
except TransportClosed:
|
||||
log.exception('Tpt disconnect during remote-exc relay?')
|
||||
raise
|
||||
|
||||
# box and ship RPC errors for wire-transit via
|
||||
# the task's requesting parent IPC-channel.
|
||||
except (
|
||||
|
|
@ -323,9 +319,6 @@ async def _errors_relayed_via_ipc(
|
|||
and debug_kbis
|
||||
)
|
||||
)
|
||||
# TODO? better then `debug_filter` below?
|
||||
and
|
||||
not isinstance(err, TransportClosed)
|
||||
):
|
||||
# XXX QUESTION XXX: is there any case where we'll
|
||||
# want to debug IPC disconnects as a default?
|
||||
|
|
@ -334,25 +327,13 @@ async def _errors_relayed_via_ipc(
|
|||
# recovery logic - the only case is some kind of
|
||||
# strange bug in our transport layer itself? Going
|
||||
# to keep this open ended for now.
|
||||
|
||||
if _state.debug_mode():
|
||||
log.exception(
|
||||
f'RPC task crashed!\n'
|
||||
f'Attempting to enter debugger\n'
|
||||
f'\n'
|
||||
f'{ctx}'
|
||||
)
|
||||
|
||||
log.debug(
|
||||
'RPC task crashed, attempting to enter debugger\n'
|
||||
f'|_{ctx}'
|
||||
)
|
||||
entered_debug = await debug._maybe_enter_pm(
|
||||
err,
|
||||
api_frame=inspect.currentframe(),
|
||||
|
||||
# don't REPL any psuedo-expected tpt-disconnect
|
||||
# debug_filter=lambda exc: (
|
||||
# type (exc) not in {
|
||||
# TransportClosed,
|
||||
# }
|
||||
# ),
|
||||
)
|
||||
if not entered_debug:
|
||||
# if we prolly should have entered the REPL but
|
||||
|
|
@ -673,7 +654,8 @@ async def _invoke(
|
|||
# scope ensures unasking of the `await coro` below
|
||||
# *should* never be interfered with!!
|
||||
maybe_raise_from_masking_exc(
|
||||
unmask_from=(Cancelled,),
|
||||
tn=tn,
|
||||
unmask_from=Cancelled,
|
||||
) as _mbme, # maybe boxed masked exc
|
||||
):
|
||||
ctx._scope_nursery = tn
|
||||
|
|
@ -694,22 +676,6 @@ async def _invoke(
|
|||
f'{pretty_struct.pformat(return_msg)}\n'
|
||||
)
|
||||
await chan.send(return_msg)
|
||||
# ?TODO, remove the below since .send() already
|
||||
# doesn't raise on tpt-closed?
|
||||
# try:
|
||||
# await chan.send(return_msg)
|
||||
# except TransportClosed:
|
||||
# log.exception(
|
||||
# f"Failed send final result to 'parent'-side of IPC-ctx!\n"
|
||||
# f'\n'
|
||||
# f'{chan}\n'
|
||||
# f'Channel already disconnected ??\n'
|
||||
# f'\n'
|
||||
# f'{pretty_struct.pformat(return_msg)}'
|
||||
# )
|
||||
# # ?TODO? will this ever be true though?
|
||||
# if chan.connected():
|
||||
# raise
|
||||
|
||||
# NOTE: this happens IFF `ctx._scope.cancel()` is
|
||||
# called by any of,
|
||||
|
|
|
|||
|
|
@ -561,9 +561,6 @@ async def _pause(
|
|||
return
|
||||
|
||||
elif isinstance(pause_err, trio.Cancelled):
|
||||
__tracebackhide__: bool = False
|
||||
# XXX, unmask to REPL it.
|
||||
# mk_pdb().set_trace(frame=inspect.currentframe())
|
||||
_repl_fail_report += (
|
||||
'You called `tractor.pause()` from an already cancelled scope!\n\n'
|
||||
'Consider `await tractor.pause(shield=True)` to make it work B)\n'
|
||||
|
|
|
|||
198
tractor/log.py
198
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')
|
||||
|
|
|
|||
|
|
@ -337,12 +337,9 @@ def _run_asyncio_task(
|
|||
|
||||
'''
|
||||
__tracebackhide__: bool = hide_tb
|
||||
if not (actor := tractor.current_actor()).is_infected_aio():
|
||||
if not tractor.current_actor().is_infected_aio():
|
||||
raise RuntimeError(
|
||||
f'`infect_asyncio: bool` mode is not enabled ??\n'
|
||||
f'Ensure you pass `ActorNursery.start_actor(infect_asyncio=True)`\n'
|
||||
f'\n'
|
||||
f'{actor}\n'
|
||||
"`infect_asyncio` mode is not enabled!?"
|
||||
)
|
||||
|
||||
# ITC (inter task comms), these channel/queue names are mostly from
|
||||
|
|
|
|||
|
|
@ -31,6 +31,7 @@ from typing import (
|
|||
AsyncIterator,
|
||||
Callable,
|
||||
Hashable,
|
||||
Optional,
|
||||
Sequence,
|
||||
TypeVar,
|
||||
TYPE_CHECKING,
|
||||
|
|
@ -203,7 +204,7 @@ class _Cache:
|
|||
a kept-alive-while-in-use async resource.
|
||||
|
||||
'''
|
||||
service_tn: trio.Nursery|None = None
|
||||
service_tn: Optional[trio.Nursery] = None
|
||||
locks: dict[Hashable, trio.Lock] = {}
|
||||
users: int = 0
|
||||
values: dict[Any, Any] = {}
|
||||
|
|
@ -212,7 +213,7 @@ class _Cache:
|
|||
tuple[trio.Nursery, trio.Event]
|
||||
] = {}
|
||||
# nurseries: dict[int, trio.Nursery] = {}
|
||||
no_more_users: trio.Event|None = None
|
||||
no_more_users: Optional[trio.Event] = None
|
||||
|
||||
@classmethod
|
||||
async def run_ctx(
|
||||
|
|
@ -222,18 +223,16 @@ class _Cache:
|
|||
task_status: trio.TaskStatus[T] = trio.TASK_STATUS_IGNORED,
|
||||
|
||||
) -> None:
|
||||
try:
|
||||
async with mng as value:
|
||||
_, no_more_users = cls.resources[ctx_key]
|
||||
try:
|
||||
cls.values[ctx_key] = value
|
||||
task_status.started(value)
|
||||
await no_more_users.wait()
|
||||
finally:
|
||||
value = cls.values.pop(ctx_key)
|
||||
finally:
|
||||
# discard nursery ref so it won't be re-used (an error)?
|
||||
cls.resources.pop(ctx_key)
|
||||
async with mng as value:
|
||||
_, no_more_users = cls.resources[ctx_key]
|
||||
cls.values[ctx_key] = value
|
||||
task_status.started(value)
|
||||
try:
|
||||
await no_more_users.wait()
|
||||
finally:
|
||||
# discard nursery ref so it won't be re-used (an error)?
|
||||
value = cls.values.pop(ctx_key)
|
||||
cls.resources.pop(ctx_key)
|
||||
|
||||
|
||||
@acm
|
||||
|
|
|
|||
|
|
@ -22,14 +22,7 @@ from __future__ import annotations
|
|||
from contextlib import (
|
||||
asynccontextmanager as acm,
|
||||
)
|
||||
import inspect
|
||||
from types import (
|
||||
TracebackType,
|
||||
)
|
||||
from typing import (
|
||||
Type,
|
||||
TYPE_CHECKING,
|
||||
)
|
||||
from typing import TYPE_CHECKING
|
||||
|
||||
import trio
|
||||
from tractor.log import get_logger
|
||||
|
|
@ -67,71 +60,12 @@ def find_masked_excs(
|
|||
return None
|
||||
|
||||
|
||||
_mask_cases: dict[
|
||||
Type[Exception], # masked exc type
|
||||
dict[
|
||||
int, # inner-frame index into `inspect.getinnerframes()`
|
||||
# `FrameInfo.function/filename: str`s to match
|
||||
tuple[str, str],
|
||||
],
|
||||
] = {
|
||||
trio.WouldBlock: {
|
||||
# `trio.Lock.acquire()` has a checkpoint inside the
|
||||
# `WouldBlock`-no_wait path's handler..
|
||||
-5: { # "5th frame up" from checkpoint
|
||||
'filename': 'trio/_sync.py',
|
||||
'function': 'acquire',
|
||||
# 'lineno': 605, # matters?
|
||||
},
|
||||
}
|
||||
}
|
||||
|
||||
|
||||
def is_expected_masking_case(
|
||||
cases: dict,
|
||||
exc_ctx: Exception,
|
||||
exc_match: BaseException,
|
||||
|
||||
) -> bool|inspect.FrameInfo:
|
||||
'''
|
||||
Determine whether the provided masked exception is from a known
|
||||
bug/special/unintentional-`trio`-impl case which we do not wish
|
||||
to unmask.
|
||||
|
||||
Return any guilty `inspect.FrameInfo` ow `False`.
|
||||
|
||||
'''
|
||||
exc_tb: TracebackType = exc_match.__traceback__
|
||||
if cases := _mask_cases.get(type(exc_ctx)):
|
||||
inner: list[inspect.FrameInfo] = inspect.getinnerframes(exc_tb)
|
||||
|
||||
# from tractor.devx.debug import mk_pdb
|
||||
# mk_pdb().set_trace()
|
||||
for iframe, matchon in cases.items():
|
||||
try:
|
||||
masker_frame: inspect.FrameInfo = inner[iframe]
|
||||
except IndexError:
|
||||
continue
|
||||
|
||||
for field, in_field in matchon.items():
|
||||
val = getattr(
|
||||
masker_frame,
|
||||
field,
|
||||
)
|
||||
if in_field not in val:
|
||||
break
|
||||
else:
|
||||
return masker_frame
|
||||
|
||||
return False
|
||||
|
||||
|
||||
|
||||
# XXX, relevant discussion @ `trio`-core,
|
||||
# https://github.com/python-trio/trio/issues/455
|
||||
#
|
||||
@acm
|
||||
async def maybe_raise_from_masking_exc(
|
||||
tn: trio.Nursery|None = None,
|
||||
unmask_from: (
|
||||
BaseException|
|
||||
tuple[BaseException]
|
||||
|
|
@ -140,26 +74,15 @@ async def maybe_raise_from_masking_exc(
|
|||
raise_unmasked: bool = True,
|
||||
extra_note: str = (
|
||||
'This can occurr when,\n'
|
||||
'\n'
|
||||
' - a `trio.Nursery/CancelScope` embeds a `finally/except:`-block '
|
||||
'which execs an un-shielded checkpoint!'
|
||||
' - a `trio.Nursery` scope embeds a `finally:`-block '
|
||||
'which executes a checkpoint!'
|
||||
#
|
||||
# ^TODO? other cases?
|
||||
),
|
||||
|
||||
always_warn_on: tuple[Type[BaseException]] = (
|
||||
always_warn_on: tuple[BaseException] = (
|
||||
trio.Cancelled,
|
||||
),
|
||||
|
||||
# don't ever unmask or warn on any masking pair,
|
||||
# {<masked-excT-key> -> <masking-excT-value>}
|
||||
never_warn_on: dict[
|
||||
Type[BaseException],
|
||||
Type[BaseException],
|
||||
] = {
|
||||
KeyboardInterrupt: trio.Cancelled,
|
||||
trio.Cancelled: trio.Cancelled,
|
||||
},
|
||||
# ^XXX, special case(s) where we warn-log bc likely
|
||||
# there will be no operational diff since the exc
|
||||
# is always expected to be consumed.
|
||||
|
|
@ -181,109 +104,81 @@ async def maybe_raise_from_masking_exc(
|
|||
individual sub-excs but maintain the eg-parent's form right?
|
||||
|
||||
'''
|
||||
if not isinstance(unmask_from, tuple):
|
||||
raise ValueError(
|
||||
f'Invalid unmask_from = {unmask_from!r}\n'
|
||||
f'Must be a `tuple[Type[BaseException]]`.\n'
|
||||
)
|
||||
|
||||
from tractor.devx.debug import (
|
||||
BoxedMaybeException,
|
||||
pause,
|
||||
)
|
||||
boxed_maybe_exc = BoxedMaybeException(
|
||||
raise_on_exit=raise_unmasked,
|
||||
)
|
||||
matching: list[BaseException]|None = None
|
||||
try:
|
||||
yield boxed_maybe_exc
|
||||
return
|
||||
except BaseException as _bexc:
|
||||
bexc = _bexc
|
||||
if isinstance(bexc, BaseExceptionGroup):
|
||||
matches: ExceptionGroup
|
||||
matches, _ = bexc.split(unmask_from)
|
||||
if matches:
|
||||
matching = matches.exceptions
|
||||
maybe_eg: ExceptionGroup|None
|
||||
|
||||
elif (
|
||||
unmask_from
|
||||
and
|
||||
type(bexc) in unmask_from
|
||||
):
|
||||
matching = [bexc]
|
||||
if tn:
|
||||
try: # handle egs
|
||||
yield boxed_maybe_exc
|
||||
return
|
||||
except* unmask_from as _maybe_eg:
|
||||
maybe_eg = _maybe_eg
|
||||
matches: ExceptionGroup
|
||||
matches, _ = maybe_eg.split(
|
||||
unmask_from
|
||||
)
|
||||
if not matches:
|
||||
raise
|
||||
|
||||
matching: list[BaseException] = matches.exceptions
|
||||
else:
|
||||
try: # handle non-egs
|
||||
yield boxed_maybe_exc
|
||||
return
|
||||
except unmask_from as _maybe_exc:
|
||||
maybe_exc = _maybe_exc
|
||||
matching: list[BaseException] = [
|
||||
maybe_exc
|
||||
]
|
||||
|
||||
# XXX, only unmask-ed for debuggin!
|
||||
# TODO, remove eventually..
|
||||
except BaseException as _berr:
|
||||
berr = _berr
|
||||
await pause(shield=True)
|
||||
raise berr
|
||||
|
||||
if matching is None:
|
||||
raise
|
||||
|
||||
masked: list[tuple[BaseException, BaseException]] = []
|
||||
for exc_match in matching:
|
||||
|
||||
if exc_ctx := find_masked_excs(
|
||||
maybe_masker=exc_match,
|
||||
unmask_from=set(unmask_from),
|
||||
unmask_from={unmask_from},
|
||||
):
|
||||
masked.append((
|
||||
exc_ctx,
|
||||
exc_match,
|
||||
))
|
||||
masked.append((exc_ctx, exc_match))
|
||||
boxed_maybe_exc.value = exc_match
|
||||
note: str = (
|
||||
f'\n'
|
||||
f'^^WARNING^^\n'
|
||||
f'the above {type(exc_ctx)!r} was masked by a {type(exc_match)!r}\n'
|
||||
f'^^WARNING^^ the above {exc_ctx!r} was masked by a {unmask_from!r}\n'
|
||||
)
|
||||
if extra_note:
|
||||
note += (
|
||||
f'\n'
|
||||
f'{extra_note}\n'
|
||||
)
|
||||
exc_ctx.add_note(note)
|
||||
|
||||
do_warn: bool = (
|
||||
never_warn_on.get(
|
||||
type(exc_ctx) # masking type
|
||||
)
|
||||
is not
|
||||
type(exc_match) # masked type
|
||||
)
|
||||
|
||||
if do_warn:
|
||||
exc_ctx.add_note(note)
|
||||
|
||||
if (
|
||||
do_warn
|
||||
and
|
||||
type(exc_match) in always_warn_on
|
||||
):
|
||||
if type(exc_match) in always_warn_on:
|
||||
log.warning(note)
|
||||
|
||||
if (
|
||||
do_warn
|
||||
and
|
||||
raise_unmasked
|
||||
):
|
||||
# await tractor.pause(shield=True)
|
||||
if raise_unmasked:
|
||||
|
||||
if len(masked) < 2:
|
||||
# don't unmask already known "special" cases..
|
||||
if (
|
||||
(cases := _mask_cases.get(type(exc_ctx)))
|
||||
and
|
||||
(masker_frame := is_expected_masking_case(
|
||||
cases,
|
||||
exc_ctx,
|
||||
exc_match,
|
||||
))
|
||||
):
|
||||
log.warning(
|
||||
f'Ignoring already-known/non-ideally-valid masker code @\n'
|
||||
f'{masker_frame}\n'
|
||||
f'\n'
|
||||
f'NOT raising {exc_ctx} from masker {exc_match!r}\n'
|
||||
)
|
||||
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)
|
||||
else:
|
||||
# ?TODO, see above but, possibly unmasking sub-exc
|
||||
# entries if there are > 1
|
||||
await pause(shield=True)
|
||||
else:
|
||||
raise
|
||||
|
|
|
|||
Loading…
Reference in New Issue