From fd649dea376ca1308d8dc00adfbce8b2d43bf49a Mon Sep 17 00:00:00 2001 From: rmorshea Date: Fri, 15 Apr 2022 19:20:52 -0700 Subject: [PATCH 1/6] add use debug value hook --- src/idom/core/hooks.py | 56 ++++++++++++++++++--- src/idom/core/layout.py | 2 +- src/idom/testing/__init__.py | 4 +- src/idom/testing/logs.py | 4 +- tests/test_core/test_hooks.py | 91 +++++++++++++++++++++++++++++++--- tests/test_core/test_layout.py | 16 +++--- tests/test_testing.py | 18 +++---- tests/test_web/test_module.py | 10 ++-- tests/test_web/test_utils.py | 4 +- 9 files changed, 163 insertions(+), 42 deletions(-) diff --git a/src/idom/core/hooks.py b/src/idom/core/hooks.py index d6e8983ec..94994a300 100644 --- a/src/idom/core/hooks.py +++ b/src/idom/core/hooks.py @@ -24,10 +24,11 @@ from typing_extensions import Protocol +from idom.config import IDOM_DEBUG_MODE from idom.utils import Ref from ._thread_local import ThreadLocal -from .types import Key, VdomDict +from .types import ComponentType, Key, VdomDict from .vdom import vdom @@ -204,6 +205,40 @@ def effect() -> None: return add_effect +def use_debug_value( + message: Any | Callable[[], Any], + dependencies: Sequence[Any] | ellipsis | None = ..., +) -> None: + """Log debug information when the given message changes. + + .. note:: + This hook only logs if :data:`~idom.config.IDOM_DEBUG_MODE` is active. + + Unlike other hooks, a message is considered to have changed if the old and new + values are ``!=``. Because this comparison is performed on every render of the + component, it may be worth considering the performance cost in some situations. + + Parameters: + message: + The value to log or a memoized function for generating the value. + dependencies: + Dependencies for the memoized function. The message will only be recomputed + if the identity of any value in the given sequence changes (i.e. their + :func:`id` is different). By default these are inferred based on local + variables that are referenced by the given function. + """ + if not IDOM_DEBUG_MODE.current: + return + + old: Ref[Any] = _use_const(lambda: Ref(object())) + memo_func = message if callable(message) else lambda: message + new = use_memo(memo_func, dependencies) + + if old.current != new: + old.current = new + logger.debug(f"{current_hook().component} {new}") + + def create_context( default_value: _StateType, name: str | None = None ) -> type[Context[_StateType]]: @@ -614,16 +649,19 @@ class LifeCycleHook: """ __slots__ = ( + "__weakref__", + "_current_state_index", + "_event_effects", + "_is_rendering", + "_rendered_atleast_once", "_schedule_render_callback", "_schedule_render_later", - "_current_state_index", "_state", - "_rendered_atleast_once", - "_is_rendering", - "_event_effects", - "__weakref__", + "component", ) + component: ComponentType + def __init__( self, schedule_render: Callable[[], None], @@ -662,13 +700,17 @@ def add_effect(self, effect_type: EffectType, function: Callable[[], None]) -> N """Trigger a function on the occurance of the given effect type""" self._event_effects[effect_type].append(function) - def affect_component_will_render(self) -> None: + def affect_component_will_render(self, component: ComponentType) -> None: """The component is about to render""" + self.component = component + self._is_rendering = True self._event_effects[COMPONENT_WILL_UNMOUNT_EFFECT].clear() def affect_component_did_render(self) -> None: """The component completed a render""" + del self.component + component_did_render_effects = self._event_effects[COMPONENT_DID_RENDER_EFFECT] for effect in component_did_render_effects: try: diff --git a/src/idom/core/layout.py b/src/idom/core/layout.py index b8b2346ae..d77431bc1 100644 --- a/src/idom/core/layout.py +++ b/src/idom/core/layout.py @@ -199,7 +199,7 @@ def _render_component( new_state.model.current = old_state.model.current else: life_cycle_hook = life_cycle_state.hook - life_cycle_hook.affect_component_will_render() + life_cycle_hook.affect_component_will_render(component) try: life_cycle_hook.set_current() try: diff --git a/src/idom/testing/__init__.py b/src/idom/testing/__init__.py index 62c80adcb..34d68cb91 100644 --- a/src/idom/testing/__init__.py +++ b/src/idom/testing/__init__.py @@ -2,8 +2,8 @@ from .display import DisplayFixture from .logs import ( LogAssertionError, + assert_idom_did_log, assert_idom_did_not_log, - assert_idom_logged, capture_idom_logs, ) from .server import ServerFixture @@ -11,7 +11,7 @@ __all__ = [ "assert_idom_did_not_log", - "assert_idom_logged", + "assert_idom_did_log", "capture_idom_logs", "clear_idom_web_modules_dir", "DisplayFixture", diff --git a/src/idom/testing/logs.py b/src/idom/testing/logs.py index f0639bb40..10e99a67b 100644 --- a/src/idom/testing/logs.py +++ b/src/idom/testing/logs.py @@ -14,7 +14,7 @@ class LogAssertionError(AssertionError): @contextmanager -def assert_idom_logged( +def assert_idom_did_log( match_message: str = "", error_type: type[Exception] | None = None, match_error: str = "", @@ -77,7 +77,7 @@ def assert_idom_did_not_log( ) -> Iterator[None]: """Assert the inverse of :func:`assert_idom_logged`""" try: - with assert_idom_logged(match_message, error_type, match_error): + with assert_idom_did_log(match_message, error_type, match_error): yield None except LogAssertionError: pass diff --git a/tests/test_core/test_hooks.py b/tests/test_core/test_hooks.py index 6aac2fec1..185b39b34 100644 --- a/tests/test_core/test_hooks.py +++ b/tests/test_core/test_hooks.py @@ -5,10 +5,12 @@ import idom from idom import html +from idom.config import IDOM_DEBUG_MODE from idom.core.hooks import COMPONENT_DID_RENDER_EFFECT, LifeCycleHook, current_hook from idom.core.layout import Layout from idom.core.serve import render_json_patch -from idom.testing import DisplayFixture, HookCatcher, assert_idom_logged, poll +from idom.testing import DisplayFixture, HookCatcher, assert_idom_did_log, poll +from idom.testing.logs import assert_idom_did_not_log from idom.utils import Ref from tests.tooling.asserts import assert_same_items @@ -553,7 +555,7 @@ def bad_effect(): return idom.html.div() - with assert_idom_logged(match_message=r"Layout post-render effect .* failed"): + with assert_idom_did_log(match_message=r"Layout post-render effect .* failed"): async with idom.Layout(ComponentWithEffect()) as layout: await layout.render() # no error @@ -574,7 +576,7 @@ def bad_cleanup(): return idom.html.div() - with assert_idom_logged(match_error=r"Layout post-render effect .* failed"): + with assert_idom_did_log(match_error=r"Layout post-render effect .* failed"): async with idom.Layout(ComponentWithEffect()) as layout: await layout.render() component_hook.latest.schedule_render() @@ -600,7 +602,7 @@ def bad_cleanup(): return idom.html.div() - with assert_idom_logged( + with assert_idom_did_log( match_message=r"Pre-unmount effect .*? failed", error_type=ValueError, ): @@ -843,7 +845,7 @@ def test_bad_schedule_render_callback(): def bad_callback(): raise ValueError("something went wrong") - with assert_idom_logged( + with assert_idom_did_log( match_message=f"Failed to schedule render via {bad_callback}" ): LifeCycleHook(bad_callback).schedule_render() @@ -1137,7 +1139,7 @@ def bad_effect(): hook.add_effect(COMPONENT_DID_RENDER_EFFECT, bad_effect) return idom.html.div() - with assert_idom_logged( + with assert_idom_did_log( match_message="Component post-render effect .*? failed", error_type=ValueError, match_error="The error message", @@ -1168,3 +1170,80 @@ def SetStateDuringRender(): # there should be no more renders to perform with pytest.raises(asyncio.TimeoutError): await asyncio.wait_for(layout.render(), timeout=0.1) + + +@pytest.mark.skipif(not IDOM_DEBUG_MODE.current, reason="only logs in debug mode") +async def test_use_debug_mode(): + set_message = idom.Ref() + component_hook = HookCatcher() + + @idom.component + @component_hook.capture + def SomeComponent(): + message, set_message.current = idom.use_state("hello") + idom.use_debug_value(f"message is {message!r}") + return idom.html.div() + + with idom.Layout(SomeComponent()) as layout: + + with assert_idom_did_log(r"SomeComponent\(.*?\) message is 'hello'"): + await layout.render() + + set_message.current("bye") + + with assert_idom_did_log(r"SomeComponent\(.*?\) message is 'bye'"): + await layout.render() + + component_hook.latest.schedule_render() + + with assert_idom_did_not_log(r"SomeComponent\(.*?\) message is 'bye'"): + await layout.render() + + +@pytest.mark.skipif(not IDOM_DEBUG_MODE.current, reason="only logs in debug mode") +async def test_use_debug_mode_with_factory(): + set_message = idom.Ref() + component_hook = HookCatcher() + + @idom.component + @component_hook.capture + def SomeComponent(): + message, set_message.current = idom.use_state("hello") + idom.use_debug_value(lambda: f"message is {message!r}") + return idom.html.div() + + with idom.Layout(SomeComponent()) as layout: + + with assert_idom_did_log(r"SomeComponent\(.*?\) message is 'hello'"): + await layout.render() + + set_message.current("bye") + + with assert_idom_did_log(r"SomeComponent\(.*?\) message is 'bye'"): + await layout.render() + + component_hook.latest.schedule_render() + + with assert_idom_did_not_log(r"SomeComponent\(.*?\) message is 'bye'"): + await layout.render() + + +@pytest.mark.skipif(IDOM_DEBUG_MODE.current, reason="logs in debug mode") +async def test_use_debug_mode_does_not_log_if_not_in_debug_mode(): + set_message = idom.Ref() + + @idom.component + def SomeComponent(): + message, set_message.current = idom.use_state("hello") + idom.use_debug_value(lambda: f"message is {message!r}") + return idom.html.div() + + with idom.Layout(SomeComponent()) as layout: + + with assert_idom_did_not_log(r"SomeComponent\(.*?\) message is 'hello'"): + await layout.render() + + set_message.current("bye") + + with assert_idom_did_not_log(r"SomeComponent\(.*?\) message is 'bye'"): + await layout.render() diff --git a/tests/test_core/test_layout.py b/tests/test_core/test_layout.py index fb6f6267a..bf77b6b63 100644 --- a/tests/test_core/test_layout.py +++ b/tests/test_core/test_layout.py @@ -17,7 +17,7 @@ from idom.testing import ( HookCatcher, StaticEventHandler, - assert_idom_logged, + assert_idom_did_log, capture_idom_logs, ) from idom.utils import Ref @@ -181,7 +181,7 @@ def OkChild(): def BadChild(): raise ValueError("error from bad child") - with assert_idom_logged(match_error="error from bad child"): + with assert_idom_did_log(match_error="error from bad child"): async with idom.Layout(Main()) as layout: patch = await render_json_patch(layout) @@ -237,7 +237,7 @@ def OkChild(): def BadChild(): raise ValueError("error from bad child") - with assert_idom_logged(match_error="error from bad child"): + with assert_idom_did_log(match_error="error from bad child"): async with idom.Layout(Main()) as layout: patch = await render_json_patch(layout) @@ -734,7 +734,7 @@ def ComponentReturnsDuplicateKeys(): return idom.html.div() async with idom.Layout(ComponentReturnsDuplicateKeys()) as layout: - with assert_idom_logged( + with assert_idom_did_log( error_type=ValueError, match_error=r"Duplicate keys \['duplicate'\] at '/children/0'", ): @@ -747,7 +747,7 @@ def ComponentReturnsDuplicateKeys(): should_error = True hook.latest.schedule_render() - with assert_idom_logged( + with assert_idom_did_log( error_type=ValueError, match_error=r"Duplicate keys \['duplicate'\] at '/children/0'", ): @@ -788,7 +788,7 @@ def raise_error(): return idom.html.button({"onClick": raise_error}) - with assert_idom_logged(match_error="bad event handler"): + with assert_idom_did_log(match_error="bad event handler"): async with idom.Layout(ComponentWithBadEventHandler()) as layout: await layout.render() @@ -812,7 +812,7 @@ def Child(state): idom.hooks.use_effect(lambda: lambda: print("unmount", state)) return idom.html.div(state) - with assert_idom_logged( + with assert_idom_did_log( r"Did not render component with model state ID .*? - component already unmounted", ): async with idom.Layout(Parent()) as layout: @@ -1218,7 +1218,7 @@ def bad_should_render(new): return ComponentShouldRender(html.div(), should_render=bad_should_render) - with assert_idom_logged( + with assert_idom_did_log( match_message=r".* component failed to check if .* should be rendered", error_type=ValueError, match_error="The error message", diff --git a/tests/test_testing.py b/tests/test_testing.py index 70d882a81..f42120f20 100644 --- a/tests/test_testing.py +++ b/tests/test_testing.py @@ -11,20 +11,20 @@ def test_assert_idom_logged_does_not_supress_errors(): with pytest.raises(RuntimeError, match="expected error"): - with testing.assert_idom_logged(): + with testing.assert_idom_did_log(): raise RuntimeError("expected error") def test_assert_idom_logged_message(): - with testing.assert_idom_logged(match_message="my message"): + with testing.assert_idom_did_log(match_message="my message"): ROOT_LOGGER.info("my message") - with testing.assert_idom_logged(match_message=r".*"): + with testing.assert_idom_did_log(match_message=r".*"): ROOT_LOGGER.info("my message") def test_assert_idom_logged_error(): - with testing.assert_idom_logged( + with testing.assert_idom_did_log( match_message="log message", error_type=ValueError, match_error="my value error", @@ -38,7 +38,7 @@ def test_assert_idom_logged_error(): AssertionError, match=r"Could not find a log record matching the given", ): - with testing.assert_idom_logged( + with testing.assert_idom_did_log( match_message="log message", error_type=ValueError, match_error="my value error", @@ -53,7 +53,7 @@ def test_assert_idom_logged_error(): AssertionError, match=r"Could not find a log record matching the given", ): - with testing.assert_idom_logged( + with testing.assert_idom_did_log( match_message="log message", error_type=ValueError, match_error="my value error", @@ -68,7 +68,7 @@ def test_assert_idom_logged_error(): AssertionError, match=r"Could not find a log record matching the given", ): - with testing.assert_idom_logged( + with testing.assert_idom_did_log( match_message="log message", error_type=ValueError, match_error="my value error", @@ -85,7 +85,7 @@ def test_assert_idom_logged_assertion_error_message(): AssertionError, match=r"Could not find a log record matching the given", ): - with testing.assert_idom_logged( + with testing.assert_idom_did_log( # put in all possible params full assertion error message match_message=r".*", error_type=Exception, @@ -98,7 +98,7 @@ def test_assert_idom_logged_ignores_level(): original_level = ROOT_LOGGER.level ROOT_LOGGER.setLevel(logging.INFO) try: - with testing.assert_idom_logged(match_message=r".*"): + with testing.assert_idom_did_log(match_message=r".*"): # this log would normally be ignored ROOT_LOGGER.debug("my message") finally: diff --git a/tests/test_web/test_module.py b/tests/test_web/test_module.py index 16846d2f5..5f967be8d 100644 --- a/tests/test_web/test_module.py +++ b/tests/test_web/test_module.py @@ -8,8 +8,8 @@ from idom.testing import ( DisplayFixture, ServerFixture, + assert_idom_did_log, assert_idom_did_not_log, - assert_idom_logged, poll, ) from idom.web.module import NAME_SOURCE, WebModule @@ -132,7 +132,7 @@ def test_module_from_file_source_conflict(tmp_path): third_file = tmp_path / "third.js" third_file.write_text("something-different") - with assert_idom_logged(r"Existing web module .* will be replaced with"): + with assert_idom_did_log(r"Existing web module .* will be replaced with"): idom.web.module_from_file("temp", third_file) @@ -161,7 +161,7 @@ def test_web_module_from_file_symlink_twice(tmp_path): file_2 = tmp_path / "temp_2.js" file_2.write_text("something") - with assert_idom_logged(r"Existing web module .* will be replaced with"): + with assert_idom_did_log(r"Existing web module .* will be replaced with"): idom.web.module_from_file("temp", file_2, symlink=True) @@ -174,7 +174,7 @@ def test_web_module_from_file_replace_existing(tmp_path): file2 = tmp_path / "temp2.js" file2.write_text("something") - with assert_idom_logged(r"Existing web module .* will be replaced with"): + with assert_idom_did_log(r"Existing web module .* will be replaced with"): idom.web.module_from_file("temp", file2) @@ -230,5 +230,5 @@ async def test_imported_components_can_render_children(display: DisplayFixture): def test_module_from_string(): idom.web.module_from_string("temp", "old") - with assert_idom_logged(r"Existing web module .* will be replaced with"): + with assert_idom_did_log(r"Existing web module .* will be replaced with"): idom.web.module_from_string("temp", "new") diff --git a/tests/test_web/test_utils.py b/tests/test_web/test_utils.py index 5286db53d..29a24142c 100644 --- a/tests/test_web/test_utils.py +++ b/tests/test_web/test_utils.py @@ -3,7 +3,7 @@ import pytest import responses -from idom.testing import assert_idom_logged +from idom.testing import assert_idom_did_log from idom.web.utils import ( module_name_suffix, resolve_module_exports_from_file, @@ -147,7 +147,7 @@ def test_resolve_module_exports_from_source(): def test_log_on_unknown_export_type(): - with assert_idom_logged(match_message="Unknown export type "): + with assert_idom_did_log(match_message="Unknown export type "): assert resolve_module_exports_from_source( "export something unknown;", exclude_default=False ) == (set(), set()) From 44936ecedcc74c21b8184e7dd7d5af60de7ae848 Mon Sep 17 00:00:00 2001 From: rmorshea Date: Fri, 15 Apr 2022 19:25:41 -0700 Subject: [PATCH 2/6] changelog entry --- docs/source/about/changelog.rst | 8 +++++++- 1 file changed, 7 insertions(+), 1 deletion(-) diff --git a/docs/source/about/changelog.rst b/docs/source/about/changelog.rst index fbf9ce815..d8d9ea4c5 100644 --- a/docs/source/about/changelog.rst +++ b/docs/source/about/changelog.rst @@ -23,7 +23,13 @@ more info, see the :ref:`Contributor Guide `. Unreleased ---------- -No changes. +**Added** + +- :pull:`733` - ``use_debug_value`` hook + +**Changed** + +- :pull:`733` - renamed ``assert_idom_logged`` testing util to ``assert_idom_did_log`` v0.38.0-a3 From 5aa4ea11db4c296e97959ecfeafedfcf1019a90e Mon Sep 17 00:00:00 2001 From: rmorshea Date: Fri, 15 Apr 2022 19:28:06 -0700 Subject: [PATCH 3/6] fix tests --- tests/test_core/test_hooks.py | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/tests/test_core/test_hooks.py b/tests/test_core/test_hooks.py index 185b39b34..e0d5694fe 100644 --- a/tests/test_core/test_hooks.py +++ b/tests/test_core/test_hooks.py @@ -1184,7 +1184,7 @@ def SomeComponent(): idom.use_debug_value(f"message is {message!r}") return idom.html.div() - with idom.Layout(SomeComponent()) as layout: + async with idom.Layout(SomeComponent()) as layout: with assert_idom_did_log(r"SomeComponent\(.*?\) message is 'hello'"): await layout.render() @@ -1212,7 +1212,7 @@ def SomeComponent(): idom.use_debug_value(lambda: f"message is {message!r}") return idom.html.div() - with idom.Layout(SomeComponent()) as layout: + async with idom.Layout(SomeComponent()) as layout: with assert_idom_did_log(r"SomeComponent\(.*?\) message is 'hello'"): await layout.render() @@ -1238,7 +1238,7 @@ def SomeComponent(): idom.use_debug_value(lambda: f"message is {message!r}") return idom.html.div() - with idom.Layout(SomeComponent()) as layout: + async with idom.Layout(SomeComponent()) as layout: with assert_idom_did_not_log(r"SomeComponent\(.*?\) message is 'hello'"): await layout.render() From 9df0721a3d0efa266c633564b160f2470ffaa042 Mon Sep 17 00:00:00 2001 From: rmorshea Date: Fri, 15 Apr 2022 19:31:34 -0700 Subject: [PATCH 4/6] export at top level --- src/idom/__init__.py | 2 ++ 1 file changed, 2 insertions(+) diff --git a/src/idom/__init__.py b/src/idom/__init__.py index e08eefbd2..3dc594f44 100644 --- a/src/idom/__init__.py +++ b/src/idom/__init__.py @@ -7,6 +7,7 @@ create_context, use_callback, use_context, + use_debug_value, use_effect, use_memo, use_reducer, @@ -42,6 +43,7 @@ "types", "use_callback", "use_context", + "use_debug_value", "use_effect", "use_memo", "use_reducer", From 896e7df9cf5d96df001f16e39b8c387a10c3e096 Mon Sep 17 00:00:00 2001 From: rmorshea Date: Fri, 15 Apr 2022 19:36:10 -0700 Subject: [PATCH 5/6] no cover --- src/idom/core/hooks.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/idom/core/hooks.py b/src/idom/core/hooks.py index 94994a300..78dda2b0d 100644 --- a/src/idom/core/hooks.py +++ b/src/idom/core/hooks.py @@ -228,7 +228,7 @@ def use_debug_value( variables that are referenced by the given function. """ if not IDOM_DEBUG_MODE.current: - return + return # pragma: no cover old: Ref[Any] = _use_const(lambda: Ref(object())) memo_func = message if callable(message) else lambda: message From 7c4801aa8db9b91daa4effb8282e38601f11108d Mon Sep 17 00:00:00 2001 From: rmorshea Date: Fri, 15 Apr 2022 19:39:51 -0700 Subject: [PATCH 6/6] fix doctest --- src/idom/core/hooks.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/idom/core/hooks.py b/src/idom/core/hooks.py index 78dda2b0d..3d00478f1 100644 --- a/src/idom/core/hooks.py +++ b/src/idom/core/hooks.py @@ -611,7 +611,7 @@ class LifeCycleHook: # --- start render cycle --- - hook.affect_component_will_render() + hook.affect_component_will_render(...) hook.set_current()