From e899cc42bf7dfb961d07e0c8d93146582200a12a Mon Sep 17 00:00:00 2001 From: Tyler Goodlet Date: Thu, 11 Mar 2021 10:07:39 -0500 Subject: [PATCH 01/13] Add per actor debug mode toggle --- tractor/_supervise.py | 8 ++++++-- 1 file changed, 6 insertions(+), 2 deletions(-) diff --git a/tractor/_supervise.py b/tractor/_supervise.py index 3f381ef..ea0ecfa 100644 --- a/tractor/_supervise.py +++ b/tractor/_supervise.py @@ -11,9 +11,8 @@ import warnings import trio from async_generator import asynccontextmanager -from . import _debug from ._debug import maybe_wait_for_debugger -from ._state import current_actor, is_main_process, is_root_process +from ._state import current_actor, is_main_process from .log import get_logger, get_loglevel from ._actor import Actor from ._portal import Portal @@ -63,6 +62,7 @@ class ActorNursery: enable_modules: List[str] = None, loglevel: str = None, # set log level per subactor nursery: trio.Nursery = None, + debug_mode: Optional[bool] = None, ) -> Portal: loglevel = loglevel or self._actor.loglevel or get_loglevel() @@ -70,6 +70,10 @@ class ActorNursery: _rtv = _state._runtime_vars.copy() _rtv['_is_root'] = False + # allow setting debug policy per actor + if debug_mode is not None: + _rtv['_debug_mode'] = debug_mode + enable_modules = enable_modules or [] if rpc_module_paths: From 9bd5226e76dff4bdf31bef8baced3fee1ee8e147 Mon Sep 17 00:00:00 2001 From: Tyler Goodlet Date: Wed, 17 Nov 2021 14:45:24 -0500 Subject: [PATCH 02/13] Only adjust logging in debug mode if not noisy enough already --- tractor/_root.py | 12 +++++++++++- 1 file changed, 11 insertions(+), 1 deletion(-) diff --git a/tractor/_root.py b/tractor/_root.py index 7731488..506c682 100644 --- a/tractor/_root.py +++ b/tractor/_root.py @@ -4,6 +4,7 @@ Root actor runtime ignition(s). from contextlib import asynccontextmanager from functools import partial import importlib +import logging import os from typing import Tuple, Optional, List, Any import typing @@ -87,8 +88,17 @@ async def open_root_actor( # for use of ``await tractor.breakpoint()`` enable_modules.append('tractor._debug') + # if debug mode get's enabled *at least* use that level of + # logging for some informative console prompts. if loglevel is None: - loglevel = 'pdb' + if ( + logging.getLevelName( + # lul, need the upper case for the -> int map? + # sweet "dynamic function behaviour" stdlib... + log.get_loglevel().upper() + ) > logging.getLevelName('PDB') + ): + loglevel = 'PDB' elif debug_mode: raise RuntimeError( From 205e254072f57e1a0fc99604d71377e7566f6499 Mon Sep 17 00:00:00 2001 From: Tyler Goodlet Date: Mon, 22 Nov 2021 13:27:47 -0500 Subject: [PATCH 03/13] Make test suite use default log level --- tests/conftest.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/tests/conftest.py b/tests/conftest.py index 347cc7d..70c81f2 100644 --- a/tests/conftest.py +++ b/tests/conftest.py @@ -52,7 +52,7 @@ def repodir(): def pytest_addoption(parser): parser.addoption( "--ll", action="store", dest='loglevel', - default=None, help="logging level to set when testing" + default='ERROR', help="logging level to set when testing" ) parser.addoption( From 72eef2a4a11ac1be5e9398373ec6b1d6f47ec9a1 Mon Sep 17 00:00:00 2001 From: Tyler Goodlet Date: Mon, 22 Nov 2021 13:28:30 -0500 Subject: [PATCH 04/13] Config debug mode log level *after* initial setup --- tractor/_root.py | 64 +++++++++++++++++++++++++----------------------- 1 file changed, 33 insertions(+), 31 deletions(-) diff --git a/tractor/_root.py b/tractor/_root.py index 506c682..4d48aca 100644 --- a/tractor/_root.py +++ b/tractor/_root.py @@ -1,6 +1,7 @@ -""" +''' Root actor runtime ignition(s). -""" + +''' from contextlib import asynccontextmanager from functools import partial import importlib @@ -81,30 +82,6 @@ async def open_root_actor( if start_method is not None: _spawn.try_set_start_method(start_method) - if debug_mode and _spawn._spawn_method == 'trio': - _state._runtime_vars['_debug_mode'] = True - - # expose internal debug module to every actor allowing - # for use of ``await tractor.breakpoint()`` - enable_modules.append('tractor._debug') - - # if debug mode get's enabled *at least* use that level of - # logging for some informative console prompts. - if loglevel is None: - if ( - logging.getLevelName( - # lul, need the upper case for the -> int map? - # sweet "dynamic function behaviour" stdlib... - log.get_loglevel().upper() - ) > logging.getLevelName('PDB') - ): - loglevel = 'PDB' - - elif debug_mode: - raise RuntimeError( - "Debug mode is only supported for the `trio` backend!" - ) - arbiter_addr = (host, port) = arbiter_addr or ( _default_arbiter_host, _default_arbiter_port, @@ -115,6 +92,29 @@ async def open_root_actor( log._default_loglevel = loglevel log.get_console_log(loglevel) + if debug_mode and _spawn._spawn_method == 'trio': + _state._runtime_vars['_debug_mode'] = True + + # expose internal debug module to every actor allowing + # for use of ``await tractor.breakpoint()`` + enable_modules.append('tractor._debug') + + # if debug mode get's enabled *at least* use that level of + # logging for some informative console prompts. + if ( + logging.getLevelName( + # lul, need the upper case for the -> int map? + # sweet "dynamic function behaviour" stdlib... + log.get_loglevel().upper() + ) > logging.getLevelName('PDB') + ): + loglevel = 'PDB' + + elif debug_mode: + raise RuntimeError( + "Debug mode is only supported for the `trio` backend!" + ) + # make a temporary connection to see if an arbiter exists arbiter_found = False @@ -248,18 +248,20 @@ def run( def run_daemon( - rpc_module_paths: List[str], + enable_modules: list[str], **kwargs ) -> None: - """Spawn daemon actor which will respond to RPC. + ''' + Spawn daemon actor which will respond to RPC. This is a convenience wrapper around ``tractor.run(trio.sleep(float('inf')))`` such that the first actor spawned is meant to run forever responding to RPC requests. - """ - kwargs['rpc_module_paths'] = list(rpc_module_paths) - for path in rpc_module_paths: + ''' + kwargs['enable_modules'] = list(enable_modules) + + for path in enable_modules: importlib.import_module(path) return run(partial(trio.sleep, float('inf')), **kwargs) From 92c6ec188229628d69c650667537aefd5a63f61a Mon Sep 17 00:00:00 2001 From: Tyler Goodlet Date: Sun, 28 Nov 2021 12:46:57 -0500 Subject: [PATCH 05/13] `get_loglevel()` always returns a str --- tractor/_root.py | 10 +++++++--- tractor/log.py | 6 +++--- 2 files changed, 10 insertions(+), 6 deletions(-) diff --git a/tractor/_root.py b/tractor/_root.py index 4d48aca..0d082fc 100644 --- a/tractor/_root.py +++ b/tractor/_root.py @@ -87,11 +87,15 @@ async def open_root_actor( _default_arbiter_port, ) - loglevel = loglevel or log.get_loglevel() - if loglevel is not None: + + if loglevel is None: + loglevel = log.get_loglevel() + else: log._default_loglevel = loglevel log.get_console_log(loglevel) + assert loglevel + if debug_mode and _spawn._spawn_method == 'trio': _state._runtime_vars['_debug_mode'] = True @@ -105,7 +109,7 @@ async def open_root_actor( logging.getLevelName( # lul, need the upper case for the -> int map? # sweet "dynamic function behaviour" stdlib... - log.get_loglevel().upper() + loglevel.upper() ) > logging.getLevelName('PDB') ): loglevel = 'PDB' diff --git a/tractor/log.py b/tractor/log.py index bcba228..8daf20d 100644 --- a/tractor/log.py +++ b/tractor/log.py @@ -9,8 +9,8 @@ from typing import Optional from ._state import ActorContextInfo -_proj_name = 'tractor' -_default_loglevel = 'ERROR' +_proj_name: str = 'tractor' +_default_loglevel: str = 'ERROR' # Super sexy formatting thanks to ``colorlog``. # (NOTE: we use the '{' format style) @@ -189,5 +189,5 @@ def get_console_log( return log -def get_loglevel() -> Optional[str]: +def get_loglevel() -> str: return _default_loglevel From e51c0e17a22d196b25f6b1f5cf23b6f622f390d1 Mon Sep 17 00:00:00 2001 From: Tyler Goodlet Date: Thu, 2 Dec 2021 08:12:02 -0500 Subject: [PATCH 06/13] Properly set console logging in test suite --- tests/conftest.py | 1 + 1 file changed, 1 insertion(+) diff --git a/tests/conftest.py b/tests/conftest.py index 70c81f2..38ee2ff 100644 --- a/tests/conftest.py +++ b/tests/conftest.py @@ -75,6 +75,7 @@ def pytest_configure(config): def loglevel(request): orig = tractor.log._default_loglevel level = tractor.log._default_loglevel = request.config.option.loglevel + tractor.log.get_console_log(level) yield level tractor.log._default_loglevel = orig From 95c52436e5182946225f083f51a09138e8eb6734 Mon Sep 17 00:00:00 2001 From: Tyler Goodlet Date: Tue, 7 Dec 2021 16:46:03 -0500 Subject: [PATCH 07/13] Adjust multi-actor debugger test It turns out recent improvements have made the debugger too good so we need to just terminate the continue loop in this test when we finally see the "spawn error" crash out because the breakpoint forever case will literally, continue forever XD --- tests/test_debugger.py | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/tests/test_debugger.py b/tests/test_debugger.py index bd1cba6..4f9ff80 100644 --- a/tests/test_debugger.py +++ b/tests/test_debugger.py @@ -279,8 +279,10 @@ def test_multi_subactors(spawn): assert "Attaching pdb to actor: ('breakpoint_forever'" in before # wait for spawn error to show up - while 'breakpoint_forever' in before: + spawn_err = "Attaching to pdb in crashed actor: ('spawn_error'" + while spawn_err not in before: child.sendline('c') + time.sleep(0.1) child.expect(r"\(Pdb\+\+\)") before = str(child.before.decode()) @@ -288,7 +290,7 @@ def test_multi_subactors(spawn): # child.sendline('c') # child.expect(r"\(Pdb\+\+\)") # before = str(child.before.decode()) - assert "Attaching to pdb in crashed actor: ('spawn_error'" in before + assert spawn_err in before assert "RemoteActorError: ('name_error_1'" in before # now run some "continues" to show re-entries From 5d9e3d1163f96e1a8431474a8cb0bf21605c0a7c Mon Sep 17 00:00:00 2001 From: Tyler Goodlet Date: Thu, 9 Dec 2021 17:50:16 -0500 Subject: [PATCH 08/13] Add a manual debug mode kwarg to debugger waiter --- tractor/_debug.py | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/tractor/_debug.py b/tractor/_debug.py index 876e5f1..9ee9674 100644 --- a/tractor/_debug.py +++ b/tractor/_debug.py @@ -577,10 +577,12 @@ async def acquire_debug_lock( async def maybe_wait_for_debugger( poll_steps: int = 2, - poll_delay: float = 0.1, + poll_delay: float = 0.01, + child_in_debug: bool = False, + ) -> None: - if not debug_mode(): + if not debug_mode() and not child_in_debug: return if ( From 9bee513136616a80472c3b4e700f3fcd0fec51b8 Mon Sep 17 00:00:00 2001 From: Tyler Goodlet Date: Thu, 9 Dec 2021 17:51:36 -0500 Subject: [PATCH 09/13] Use manual debugger-in-use flag in nursery and spawn task --- tractor/_spawn.py | 4 +++- tractor/_supervise.py | 14 +++++++++++++- 2 files changed, 16 insertions(+), 2 deletions(-) diff --git a/tractor/_spawn.py b/tractor/_spawn.py index c7eb2d2..ac5bb5a 100644 --- a/tractor/_spawn.py +++ b/tractor/_spawn.py @@ -366,7 +366,9 @@ async def new_proc( await proc.wait() if is_root_process(): - await maybe_wait_for_debugger() + await maybe_wait_for_debugger( + child_in_debug=_runtime_vars.get('_debug_mode', False), + ) if proc.poll() is None: log.cancel(f"Attempting to hard kill {proc}") diff --git a/tractor/_supervise.py b/tractor/_supervise.py index ea0ecfa..ae224a8 100644 --- a/tractor/_supervise.py +++ b/tractor/_supervise.py @@ -50,6 +50,7 @@ class ActorNursery: self._cancel_after_result_on_exit: set = set() self.cancelled: bool = False self._join_procs = trio.Event() + self._at_least_one_child_in_debug: bool = False self.errors = errors self.exited = trio.Event() @@ -64,6 +65,11 @@ class ActorNursery: nursery: trio.Nursery = None, debug_mode: Optional[bool] = None, ) -> Portal: + ''' + Start a (daemon) actor: an process that has no designated + "main task" besides the runtime. + + ''' loglevel = loglevel or self._actor.loglevel or get_loglevel() # configure and pass runtime state @@ -73,6 +79,7 @@ class ActorNursery: # allow setting debug policy per actor if debug_mode is not None: _rtv['_debug_mode'] = debug_mode + self._at_least_one_child_in_debug = True enable_modules = enable_modules or [] @@ -287,7 +294,9 @@ async def _open_and_supervise_one_cancels_all_nursery( # will make the pdb repl unusable. # Instead try to wait for pdb to be released before # tearing down. - await maybe_wait_for_debugger() + await maybe_wait_for_debugger( + child_in_debug=anursery._at_least_one_child_in_debug + ) # if the caller's scope errored then we activate our # one-cancels-all supervisor strategy (don't @@ -341,6 +350,9 @@ async def _open_and_supervise_one_cancels_all_nursery( ) as err: + await maybe_wait_for_debugger( + child_in_debug=anursery._at_least_one_child_in_debug + ) # If actor-local error was raised while waiting on # ".run_in_actor()" actors then we also want to cancel all # remaining sub-actors (due to our lone strategy: From 4f411d69263ac654a4ad4c373082a57db1bdf593 Mon Sep 17 00:00:00 2001 From: Tyler Goodlet Date: Thu, 9 Dec 2021 17:51:53 -0500 Subject: [PATCH 10/13] Add a per actor debug mode test --- tests/test_debugger.py | 35 ++++++++++++++++++++++++++++++++++- 1 file changed, 34 insertions(+), 1 deletion(-) diff --git a/tests/test_debugger.py b/tests/test_debugger.py index 4f9ff80..5feed31 100644 --- a/tests/test_debugger.py +++ b/tests/test_debugger.py @@ -4,7 +4,11 @@ That native debug better work! All these tests can be understood (somewhat) by running the equivalent `examples/debugging/` scripts manually. -TODO: None of these tests have been run successfully on windows yet. +TODO: + - none of these tests have been run successfully on windows yet but + there's been manual testing that verified it works. + - wonder if any of it'll work on OS X? + """ import time from os import path @@ -561,3 +565,32 @@ def test_root_cancels_child_context_during_startup( child.sendline('c') child.expect(pexpect.EOF) + + +def test_different_debug_mode_per_actor( + spawn, +): + child = spawn('per_actor_debug') + child.expect(r"\(Pdb\+\+\)") + + # only one actor should enter the debugger + before = str(child.before.decode()) + assert "Attaching to pdb in crashed actor: ('debugged_boi'" in before + assert "RuntimeError" in before + + # the crash boi should not have made a debugger request but + # instead crashed completely + assert "tractor._exceptions.RemoteActorError: ('crash_boi'" in before + + child.sendline('c') + child.expect(pexpect.EOF) + + before = str(child.before.decode()) + + # NOTE: this debugged actor error currently WON'T show up since the + # root will actually cancel and terminate the nursery before the error + # msg reported back from the debug mode actor is processed. + # assert "tractor._exceptions.RemoteActorError: ('debugged_boi'" in before + + assert "tractor._exceptions.RemoteActorError: ('crash_boi'" in before + assert "RuntimeError" in before From a38a9832258a122c9631edbb66c1bd72e1cb371a Mon Sep 17 00:00:00 2001 From: Tyler Goodlet Date: Fri, 10 Dec 2021 11:54:27 -0500 Subject: [PATCH 11/13] Increase debugger poll delay back to prior value If we make it too fast a nursery with debug mode children can cancel too fast and causes some test failures. It's likely not a huge deal anyway since the purpose of this poll/check is for human interaction and the current delay isn't really that noticeable. Decrease log levels in the debug module to avoid console noise when in use. Toss in some more detailed comments around the new debugger lock points. --- tests/test_debugger.py | 14 ++++++++------ tractor/_debug.py | 10 +++++----- tractor/_supervise.py | 3 +++ 3 files changed, 16 insertions(+), 11 deletions(-) diff --git a/tests/test_debugger.py b/tests/test_debugger.py index 5feed31..0e88f5d 100644 --- a/tests/test_debugger.py +++ b/tests/test_debugger.py @@ -405,9 +405,11 @@ def test_multi_daemon_subactors(spawn, loglevel): def test_multi_subactors_root_errors(spawn): - """Multiple subactors, both erroring and breakpointing as well as + ''' + Multiple subactors, both erroring and breakpointing as well as a nested subactor erroring. - """ + + ''' child = spawn('multi_subactor_root_errors') # scan for the pdbpp prompt @@ -578,10 +580,6 @@ def test_different_debug_mode_per_actor( assert "Attaching to pdb in crashed actor: ('debugged_boi'" in before assert "RuntimeError" in before - # the crash boi should not have made a debugger request but - # instead crashed completely - assert "tractor._exceptions.RemoteActorError: ('crash_boi'" in before - child.sendline('c') child.expect(pexpect.EOF) @@ -592,5 +590,9 @@ def test_different_debug_mode_per_actor( # msg reported back from the debug mode actor is processed. # assert "tractor._exceptions.RemoteActorError: ('debugged_boi'" in before + assert "tractor._exceptions.RemoteActorError: ('crash_boi'" in before + + # the crash boi should not have made a debugger request but + # instead crashed completely assert "tractor._exceptions.RemoteActorError: ('crash_boi'" in before assert "RuntimeError" in before diff --git a/tractor/_debug.py b/tractor/_debug.py index 9ee9674..34097f1 100644 --- a/tractor/_debug.py +++ b/tractor/_debug.py @@ -252,7 +252,7 @@ async def _hijack_stdin_for_child( # indicate to child that we've locked stdio await ctx.started('Locked') - log.pdb(f"Actor {subactor_uid} ACQUIRED stdin hijack lock") + log.debug(f"Actor {subactor_uid} acquired stdin hijack lock") # wait for unlock pdb by child async with ctx.open_stream() as stream: @@ -577,7 +577,7 @@ async def acquire_debug_lock( async def maybe_wait_for_debugger( poll_steps: int = 2, - poll_delay: float = 0.01, + poll_delay: float = 0.1, child_in_debug: bool = False, ) -> None: @@ -604,7 +604,7 @@ async def maybe_wait_for_debugger( if _global_actor_in_debug: sub_in_debug = tuple(_global_actor_in_debug) - log.warning( + log.debug( 'Root polling for debug') with trio.CancelScope(shield=True): @@ -621,7 +621,7 @@ async def maybe_wait_for_debugger( (debug_complete and not debug_complete.is_set()) ): - log.warning( + log.debug( 'Root has errored but pdb is in use by ' f'child {sub_in_debug}\n' 'Waiting on tty lock to release..') @@ -631,6 +631,6 @@ async def maybe_wait_for_debugger( await trio.sleep(poll_delay) continue else: - log.warning( + log.debug( 'Root acquired TTY LOCK' ) diff --git a/tractor/_supervise.py b/tractor/_supervise.py index ae224a8..3bc8694 100644 --- a/tractor/_supervise.py +++ b/tractor/_supervise.py @@ -350,9 +350,12 @@ async def _open_and_supervise_one_cancels_all_nursery( ) as err: + # XXX: yet another guard before allowing the cancel + # sequence in case a (single) child is in debug. await maybe_wait_for_debugger( child_in_debug=anursery._at_least_one_child_in_debug ) + # If actor-local error was raised while waiting on # ".run_in_actor()" actors then we also want to cancel all # remaining sub-actors (due to our lone strategy: From 949aa9c40594c7eaa4a3954a0e9959f94e411b4a Mon Sep 17 00:00:00 2001 From: Tyler Goodlet Date: Fri, 10 Dec 2021 12:48:05 -0500 Subject: [PATCH 12/13] Lol. should probably push the example code... --- examples/debugging/per_actor_debug.py | 27 +++++++++++++++++++++++++++ 1 file changed, 27 insertions(+) create mode 100644 examples/debugging/per_actor_debug.py diff --git a/examples/debugging/per_actor_debug.py b/examples/debugging/per_actor_debug.py new file mode 100644 index 0000000..1db5698 --- /dev/null +++ b/examples/debugging/per_actor_debug.py @@ -0,0 +1,27 @@ +import trio +import tractor + +async def die(): + raise RuntimeError + + +async def main(): + async with tractor.open_nursery() as tn: + + debug_actor = await tn.start_actor( + 'debugged_boi', + enable_modules=[__name__], + debug_mode=True, + ) + crash_boi = await tn.start_actor( + 'crash_boi', + enable_modules=[__name__], + # debug_mode=True, + ) + + async with trio.open_nursery() as n: + n.start_soon(debug_actor.run, die) + n.start_soon(crash_boi.run, die) + +if __name__ == '__main__': + trio.run(main) From 94f098e5f7ebfe435bab96aac775c15929fbcdba Mon Sep 17 00:00:00 2001 From: Tyler Goodlet Date: Fri, 10 Dec 2021 13:07:59 -0500 Subject: [PATCH 13/13] Add nooz --- newsfragments/271.feature.rst | 9 +++++++++ 1 file changed, 9 insertions(+) create mode 100644 newsfragments/271.feature.rst diff --git a/newsfragments/271.feature.rst b/newsfragments/271.feature.rst new file mode 100644 index 0000000..fcf58a4 --- /dev/null +++ b/newsfragments/271.feature.rst @@ -0,0 +1,9 @@ +Add a per actor ``debug_mode: bool`` control to our nursery. + +This allows spawning actors via ``ActorNursery.start_actor()`` (and +other dependent methods) with a ``debug_mode=True`` flag much like +``tractor.open_nursery():`` such that per process crash handling +can be toggled for cases where a user does not need/want all child actors +to drop into the debugger on error. This is often useful when you have +actor-tasks which are expected to error often (and be re-run) but want +to specifically interact with some (problematic) child.