From f88d91d8d1b39612cdba4899b95e3398fc0438e6 Mon Sep 17 00:00:00 2001 From: Toru Kawakubo Date: Wed, 7 Jun 2023 21:47:43 +0900 Subject: [PATCH 01/35] First draft of recording feature --- .../core/quri_parts/core/utils/recording.py | 138 ++++++++++++++++++ .../core/tests/core/utils/test_recording.py | 41 ++++++ 2 files changed, 179 insertions(+) create mode 100644 packages/core/quri_parts/core/utils/recording.py create mode 100644 packages/core/tests/core/utils/test_recording.py diff --git a/packages/core/quri_parts/core/utils/recording.py b/packages/core/quri_parts/core/utils/recording.py new file mode 100644 index 00000000..eee91321 --- /dev/null +++ b/packages/core/quri_parts/core/utils/recording.py @@ -0,0 +1,138 @@ +from collections.abc import Callable, Hashable, Iterable, Iterator +from contextlib import contextmanager +from dataclasses import dataclass +from functools import update_wrapper +from typing import Any, Generic, TypeVar + +from typing_extensions import Concatenate, ParamSpec, TypeAlias + +P = ParamSpec("P") +R = TypeVar("R", covariant=True) + +_FunctionId: TypeAlias = tuple[str, str, Hashable] + + +class RecordableFunction(Generic[P, R]): + def __init__(self, f: Callable[P, R], id: _FunctionId): + self._f = f + self._id = id + + def __call__(self, *args: P.args, **kwargs: P.kwargs) -> R: + return self._f(*args, **kwargs) + + @property + def id(self) -> _FunctionId: + return self._id + + +RecordLevel: TypeAlias = int + +INFO: RecordLevel = 20 + +_RecKey: TypeAlias = Hashable +_RecValue: TypeAlias = Any +_RecData: TypeAlias = tuple[_RecKey, _RecValue] + + +class Recorder: + def __init__(self, fid: _FunctionId) -> None: + self._func_id = fid + + @contextmanager + def start_func(self) -> Iterator[None]: + for session in _active_sessions: + session.enter_func(self._func_id) + yield + for session in _active_sessions: + session.exit_func(self._func_id) + + def info(self, key: _RecKey, value: _RecValue) -> None: + for session in _active_sessions: + session.handler(self._func_id, key, value) + + +_recorders: dict[_FunctionId, Recorder] = {} + + +def _get_recorder(fid: _FunctionId) -> Recorder: + if fid in _recorders: + return _recorders[fid] + else: + recorder = Recorder(fid) + _recorders[fid] = recorder + return recorder + + +def recordable(f: Callable[Concatenate[Recorder, P], R]) -> RecordableFunction[P, R]: + param = () # TODO + f_id = (f.__module__, f.__qualname__, param) + + def wrapper(*args: P.args, **kwargs: P.kwargs) -> R: + recorder = _get_recorder(f_id) + with recorder.start_func(): + return f(recorder, *args, **kwargs) + + rf = RecordableFunction(wrapper, f_id) + + return update_wrapper(rf, f) + + +@dataclass +class RecordEntry: + func_id: _FunctionId + data: _RecData + + +@dataclass +class RecordGroup: + func_id: _FunctionId + entries: list[RecordEntry] + + def add_entry(self, entry: RecordEntry) -> None: + self.entries.append(entry) + + +class RecordSet: + def __init__(self) -> None: + self._history: list[RecordGroup] = [] + + def add_group(self, fid: _FunctionId) -> RecordGroup: + group = RecordGroup(fid, []) + self._history.append(group) + return group + + def get_history(self, func: RecordableFunction[P, R]) -> Iterable[RecordGroup]: + return filter(lambda g: g.func_id == func.id, self._history) + + +class RecordSession: + def __init__(self) -> None: + self._levels: dict[_FunctionId, RecordLevel] = {} + self._record_set = RecordSet() + self._group_stack: list[RecordGroup] = [] + + def set_level(self, level: RecordLevel, func: RecordableFunction[P, R]) -> None: + self._levels[func.id] = level + + def handler(self, fid: _FunctionId, key: _RecKey, value: _RecValue) -> None: + entry = RecordEntry(fid, (key, value)) + self._group_stack[-1].add_entry(entry) + + @contextmanager + def start(self) -> Iterator[None]: + _active_sessions.append(self) + yield + _active_sessions.pop() + + def enter_func(self, fid: _FunctionId) -> None: + group = self._record_set.add_group(fid) + self._group_stack.append(group) + + def exit_func(self, fid: _FunctionId) -> None: + self._group_stack.pop() + + def get_records(self) -> RecordSet: + return self._record_set + + +_active_sessions: list[RecordSession] = [] diff --git a/packages/core/tests/core/utils/test_recording.py b/packages/core/tests/core/utils/test_recording.py new file mode 100644 index 00000000..9f7c20b3 --- /dev/null +++ b/packages/core/tests/core/utils/test_recording.py @@ -0,0 +1,41 @@ +from quri_parts.core.utils.recording import ( + INFO, + RecordEntry, + Recorder, + RecordSession, + recordable, +) + + +@recordable +def func_to_record(recorder: Recorder, x: int) -> int: + recorder.info("x", x) + recorder.info("2x", 2 * x) + return 2 * x + + +def test_recordable() -> None: + fid = func_to_record.id + session = RecordSession() + session.set_level(INFO, func_to_record) + + with session.start(): + assert func_to_record(3) == 6 + assert func_to_record(4) == 8 + + records = session.get_records() + history = list(records.get_history(func_to_record)) + assert len(history) == 2 + group0, group1 = history + + assert group0.func_id == func_to_record.id + assert group0.entries == [ + RecordEntry(fid, ("x", 3)), + RecordEntry(fid, ("2x", 6)), + ] + + assert group1.func_id == func_to_record.id + assert group1.entries == [ + RecordEntry(fid, ("x", 4)), + RecordEntry(fid, ("2x", 8)), + ] From 684aea6ea9c922884152c92296b52bc300ab7424 Mon Sep 17 00:00:00 2001 From: Toru Kawakubo Date: Tue, 20 Jun 2023 19:38:05 +0900 Subject: [PATCH 02/35] Add a NamedTuple for function ID --- .../core/quri_parts/core/utils/recording.py | 43 ++++++++++++------- .../core/tests/core/utils/test_recording.py | 4 +- 2 files changed, 30 insertions(+), 17 deletions(-) diff --git a/packages/core/quri_parts/core/utils/recording.py b/packages/core/quri_parts/core/utils/recording.py index eee91321..4e4aa13f 100644 --- a/packages/core/quri_parts/core/utils/recording.py +++ b/packages/core/quri_parts/core/utils/recording.py @@ -2,18 +2,29 @@ from contextlib import contextmanager from dataclasses import dataclass from functools import update_wrapper -from typing import Any, Generic, TypeVar +from typing import Any, Generic, NamedTuple, TypeVar from typing_extensions import Concatenate, ParamSpec, TypeAlias P = ParamSpec("P") R = TypeVar("R", covariant=True) -_FunctionId: TypeAlias = tuple[str, str, Hashable] + +class RecordableFunctionId(NamedTuple): + module: str + qualname: str + param: Hashable + + def __str__(self) -> str: + base = f"{self.module}.{self.qualname}" + if self.param: + return f"{base}<{str(self.param)}>" + else: + return base class RecordableFunction(Generic[P, R]): - def __init__(self, f: Callable[P, R], id: _FunctionId): + def __init__(self, f: Callable[P, R], id: RecordableFunctionId): self._f = f self._id = id @@ -21,7 +32,7 @@ def __call__(self, *args: P.args, **kwargs: P.kwargs) -> R: return self._f(*args, **kwargs) @property - def id(self) -> _FunctionId: + def id(self) -> RecordableFunctionId: return self._id @@ -35,7 +46,7 @@ def id(self) -> _FunctionId: class Recorder: - def __init__(self, fid: _FunctionId) -> None: + def __init__(self, fid: RecordableFunctionId) -> None: self._func_id = fid @contextmanager @@ -51,10 +62,10 @@ def info(self, key: _RecKey, value: _RecValue) -> None: session.handler(self._func_id, key, value) -_recorders: dict[_FunctionId, Recorder] = {} +_recorders: dict[RecordableFunctionId, Recorder] = {} -def _get_recorder(fid: _FunctionId) -> Recorder: +def _get_recorder(fid: RecordableFunctionId) -> Recorder: if fid in _recorders: return _recorders[fid] else: @@ -65,7 +76,7 @@ def _get_recorder(fid: _FunctionId) -> Recorder: def recordable(f: Callable[Concatenate[Recorder, P], R]) -> RecordableFunction[P, R]: param = () # TODO - f_id = (f.__module__, f.__qualname__, param) + f_id = RecordableFunctionId(f.__module__, f.__qualname__, param) def wrapper(*args: P.args, **kwargs: P.kwargs) -> R: recorder = _get_recorder(f_id) @@ -79,13 +90,13 @@ def wrapper(*args: P.args, **kwargs: P.kwargs) -> R: @dataclass class RecordEntry: - func_id: _FunctionId + func_id: RecordableFunctionId data: _RecData @dataclass class RecordGroup: - func_id: _FunctionId + func_id: RecordableFunctionId entries: list[RecordEntry] def add_entry(self, entry: RecordEntry) -> None: @@ -96,7 +107,7 @@ class RecordSet: def __init__(self) -> None: self._history: list[RecordGroup] = [] - def add_group(self, fid: _FunctionId) -> RecordGroup: + def add_group(self, fid: RecordableFunctionId) -> RecordGroup: group = RecordGroup(fid, []) self._history.append(group) return group @@ -107,14 +118,16 @@ def get_history(self, func: RecordableFunction[P, R]) -> Iterable[RecordGroup]: class RecordSession: def __init__(self) -> None: - self._levels: dict[_FunctionId, RecordLevel] = {} + self._levels: dict[RecordableFunctionId, RecordLevel] = {} self._record_set = RecordSet() self._group_stack: list[RecordGroup] = [] def set_level(self, level: RecordLevel, func: RecordableFunction[P, R]) -> None: self._levels[func.id] = level - def handler(self, fid: _FunctionId, key: _RecKey, value: _RecValue) -> None: + def handler( + self, fid: RecordableFunctionId, key: _RecKey, value: _RecValue + ) -> None: entry = RecordEntry(fid, (key, value)) self._group_stack[-1].add_entry(entry) @@ -124,11 +137,11 @@ def start(self) -> Iterator[None]: yield _active_sessions.pop() - def enter_func(self, fid: _FunctionId) -> None: + def enter_func(self, fid: RecordableFunctionId) -> None: group = self._record_set.add_group(fid) self._group_stack.append(group) - def exit_func(self, fid: _FunctionId) -> None: + def exit_func(self, fid: RecordableFunctionId) -> None: self._group_stack.pop() def get_records(self) -> RecordSet: diff --git a/packages/core/tests/core/utils/test_recording.py b/packages/core/tests/core/utils/test_recording.py index 9f7c20b3..7a4f7779 100644 --- a/packages/core/tests/core/utils/test_recording.py +++ b/packages/core/tests/core/utils/test_recording.py @@ -28,13 +28,13 @@ def test_recordable() -> None: assert len(history) == 2 group0, group1 = history - assert group0.func_id == func_to_record.id + assert group0.func_id == fid assert group0.entries == [ RecordEntry(fid, ("x", 3)), RecordEntry(fid, ("2x", 6)), ] - assert group1.func_id == func_to_record.id + assert group1.func_id == fid assert group1.entries == [ RecordEntry(fid, ("x", 4)), RecordEntry(fid, ("2x", 8)), From 5b898fe7606d2e76cdae5be05547a24a4b8570be Mon Sep 17 00:00:00 2001 From: Toru Kawakubo Date: Tue, 20 Jun 2023 19:47:48 +0900 Subject: [PATCH 03/35] Add a test for recording tested function invocations --- .../core/tests/core/utils/test_recording.py | 46 +++++++++++++++++++ 1 file changed, 46 insertions(+) diff --git a/packages/core/tests/core/utils/test_recording.py b/packages/core/tests/core/utils/test_recording.py index 7a4f7779..41024d9c 100644 --- a/packages/core/tests/core/utils/test_recording.py +++ b/packages/core/tests/core/utils/test_recording.py @@ -39,3 +39,49 @@ def test_recordable() -> None: RecordEntry(fid, ("x", 4)), RecordEntry(fid, ("2x", 8)), ] + + +@recordable +def nested_func(recorder: Recorder, x: int) -> int: + recorder.info("x", x) + if x // 2 == 1: + y = nested_func(2 * x) + recorder.info("y", y) + else: + y = x + recorder.info("2y", 2 * y) + return 2 * y + + +def test_nested_func_record() -> None: + fid = nested_func.id + session = RecordSession() + session.set_level(INFO, nested_func) + + with session.start(): + assert nested_func(3) == 24 + assert nested_func(4) == 8 + + records = session.get_records() + history = list(records.get_history(nested_func)) + assert len(history) == 3 + group0, group1, group2 = history + + assert group0.func_id == fid + assert group0.entries == [ + RecordEntry(fid, ("x", 3)), + RecordEntry(fid, ("y", 12)), + RecordEntry(fid, ("2y", 24)), + ] + + assert group1.func_id == fid + assert group1.entries == [ + RecordEntry(fid, ("x", 6)), + RecordEntry(fid, ("2y", 12)), + ] + + assert group2.func_id == fid + assert group2.entries == [ + RecordEntry(fid, ("x", 4)), + RecordEntry(fid, ("2y", 8)), + ] From 4aba065ee0bf8e02f745400a0fd295748bc26bdb Mon Sep 17 00:00:00 2001 From: Toru Kawakubo Date: Tue, 20 Jun 2023 20:16:22 +0900 Subject: [PATCH 04/35] Add record level support --- .../core/quri_parts/core/utils/recording.py | 22 ++++++-- .../core/tests/core/utils/test_recording.py | 53 +++++++++++++++++++ 2 files changed, 72 insertions(+), 3 deletions(-) diff --git a/packages/core/quri_parts/core/utils/recording.py b/packages/core/quri_parts/core/utils/recording.py index 4e4aa13f..a768415c 100644 --- a/packages/core/quri_parts/core/utils/recording.py +++ b/packages/core/quri_parts/core/utils/recording.py @@ -39,6 +39,7 @@ def id(self) -> RecordableFunctionId: RecordLevel: TypeAlias = int INFO: RecordLevel = 20 +DEBUG: RecordLevel = 10 _RecKey: TypeAlias = Hashable _RecValue: TypeAlias = Any @@ -57,9 +58,16 @@ def start_func(self) -> Iterator[None]: for session in _active_sessions: session.exit_func(self._func_id) - def info(self, key: _RecKey, value: _RecValue) -> None: + def record(self, level: RecordLevel, key: _RecKey, value: _RecValue) -> None: for session in _active_sessions: - session.handler(self._func_id, key, value) + if session.is_enabled_for(level, self._func_id): + session.handler(self._func_id, key, value) + + def debug(self, key: _RecKey, value: _RecValue) -> None: + self.record(DEBUG, key, value) + + def info(self, key: _RecKey, value: _RecValue) -> None: + self.record(INFO, key, value) _recorders: dict[RecordableFunctionId, Recorder] = {} @@ -112,6 +120,9 @@ def add_group(self, fid: RecordableFunctionId) -> RecordGroup: self._history.append(group) return group + def remove_last_group(self) -> None: + self._history.pop() + def get_history(self, func: RecordableFunction[P, R]) -> Iterable[RecordGroup]: return filter(lambda g: g.func_id == func.id, self._history) @@ -125,6 +136,9 @@ def __init__(self) -> None: def set_level(self, level: RecordLevel, func: RecordableFunction[P, R]) -> None: self._levels[func.id] = level + def is_enabled_for(self, level: RecordLevel, fid: RecordableFunctionId) -> bool: + return fid in self._levels and level >= self._levels[fid] + def handler( self, fid: RecordableFunctionId, key: _RecKey, value: _RecValue ) -> None: @@ -142,7 +156,9 @@ def enter_func(self, fid: RecordableFunctionId) -> None: self._group_stack.append(group) def exit_func(self, fid: RecordableFunctionId) -> None: - self._group_stack.pop() + group = self._group_stack.pop() + if not group.entries: + self._record_set.remove_last_group() def get_records(self) -> RecordSet: return self._record_set diff --git a/packages/core/tests/core/utils/test_recording.py b/packages/core/tests/core/utils/test_recording.py index 41024d9c..4b67305e 100644 --- a/packages/core/tests/core/utils/test_recording.py +++ b/packages/core/tests/core/utils/test_recording.py @@ -1,4 +1,5 @@ from quri_parts.core.utils.recording import ( + DEBUG, INFO, RecordEntry, Recorder, @@ -85,3 +86,55 @@ def test_nested_func_record() -> None: RecordEntry(fid, ("x", 4)), RecordEntry(fid, ("2y", 8)), ] + + +@recordable +def rec_level_func(recorder: Recorder, x: int) -> int: + recorder.info("info", x) + recorder.debug("debug", 2 * x) + return 2 * x + + +class TestRecordLevel: + def test_default_level(self) -> None: + session = RecordSession() + + with session.start(): + assert rec_level_func(3) == 6 + + records = session.get_records() + history = list(records.get_history(rec_level_func)) + assert len(history) == 0 + + def test_info_level(self) -> None: + fid = rec_level_func.id + session = RecordSession() + session.set_level(INFO, rec_level_func) + + with session.start(): + assert rec_level_func(3) == 6 + + records = session.get_records() + history = list(records.get_history(rec_level_func)) + assert len(history) == 1 + (group,) = history + + assert group.entries == [RecordEntry(fid, ("info", 3))] + + def test_debug_level(self) -> None: + fid = rec_level_func.id + session = RecordSession() + session.set_level(DEBUG, rec_level_func) + + with session.start(): + assert rec_level_func(3) == 6 + + records = session.get_records() + history = list(records.get_history(rec_level_func)) + assert len(history) == 1 + (group,) = history + + assert group.entries == [ + RecordEntry(fid, ("info", 3)), + RecordEntry(fid, ("debug", 6)), + ] From d3672d243e31e60060fd293984f187a748069406 Mon Sep 17 00:00:00 2001 From: Toru Kawakubo Date: Tue, 20 Jun 2023 20:24:23 +0900 Subject: [PATCH 05/35] Add Recorder.is_enabled_for --- .../core/quri_parts/core/utils/recording.py | 5 +++ .../core/tests/core/utils/test_recording.py | 37 +++++++++++++++++++ 2 files changed, 42 insertions(+) diff --git a/packages/core/quri_parts/core/utils/recording.py b/packages/core/quri_parts/core/utils/recording.py index a768415c..138f8653 100644 --- a/packages/core/quri_parts/core/utils/recording.py +++ b/packages/core/quri_parts/core/utils/recording.py @@ -69,6 +69,11 @@ def debug(self, key: _RecKey, value: _RecValue) -> None: def info(self, key: _RecKey, value: _RecValue) -> None: self.record(INFO, key, value) + def is_enabled_for(self, level: RecordLevel) -> bool: + return all( + session.is_enabled_for(level, self._func_id) for session in _active_sessions + ) + _recorders: dict[RecordableFunctionId, Recorder] = {} diff --git a/packages/core/tests/core/utils/test_recording.py b/packages/core/tests/core/utils/test_recording.py index 4b67305e..f280c839 100644 --- a/packages/core/tests/core/utils/test_recording.py +++ b/packages/core/tests/core/utils/test_recording.py @@ -138,3 +138,40 @@ def test_debug_level(self) -> None: RecordEntry(fid, ("info", 3)), RecordEntry(fid, ("debug", 6)), ] + + +@recordable +def is_enabled_for_func(recorder: Recorder, x: int) -> int: + # arg of is_enabled for (DEBUG) and recorder.info are inconsistent + # for testing purpose + if recorder.is_enabled_for(DEBUG): + recorder.info("x", x) + return 2 * x + + +class TestIsEnabledFor: + def test_is_enabled_for_true(self) -> None: + fid = is_enabled_for_func.id + session = RecordSession() + session.set_level(DEBUG, is_enabled_for_func) + + with session.start(): + assert is_enabled_for_func(3) == 6 + + records = session.get_records() + history = list(records.get_history(is_enabled_for_func)) + assert len(history) == 1 + (group,) = history + + assert group.entries == [RecordEntry(fid, ("x", 3))] + + def test_is_enabled_for_false(self) -> None: + session = RecordSession() + session.set_level(INFO, is_enabled_for_func) + + with session.start(): + assert is_enabled_for_func(3) == 6 + + records = session.get_records() + history = list(records.get_history(is_enabled_for_func)) + assert len(history) == 0 From e5967745219c2c9aab8f396b4e5863e72383b61e Mon Sep 17 00:00:00 2001 From: Toru Kawakubo Date: Wed, 21 Jun 2023 10:43:55 +0900 Subject: [PATCH 06/35] Fix is_enabled_for --- .../core/quri_parts/core/utils/recording.py | 2 +- .../core/tests/core/utils/test_recording.py | 22 +++++++++++++++++++ 2 files changed, 23 insertions(+), 1 deletion(-) diff --git a/packages/core/quri_parts/core/utils/recording.py b/packages/core/quri_parts/core/utils/recording.py index 138f8653..1c045dbe 100644 --- a/packages/core/quri_parts/core/utils/recording.py +++ b/packages/core/quri_parts/core/utils/recording.py @@ -70,7 +70,7 @@ def info(self, key: _RecKey, value: _RecValue) -> None: self.record(INFO, key, value) def is_enabled_for(self, level: RecordLevel) -> bool: - return all( + return any( session.is_enabled_for(level, self._func_id) for session in _active_sessions ) diff --git a/packages/core/tests/core/utils/test_recording.py b/packages/core/tests/core/utils/test_recording.py index f280c839..bdd74fd7 100644 --- a/packages/core/tests/core/utils/test_recording.py +++ b/packages/core/tests/core/utils/test_recording.py @@ -175,3 +175,25 @@ def test_is_enabled_for_false(self) -> None: records = session.get_records() history = list(records.get_history(is_enabled_for_func)) assert len(history) == 0 + + def test_is_enabled_for_multiple_sessions(self) -> None: + fid = is_enabled_for_func.id + # session1 is set to the default level + session1 = RecordSession() + session2 = RecordSession() + session2.set_level(DEBUG, is_enabled_for_func) + + with session1.start(): + with session2.start(): + assert is_enabled_for_func(3) == 6 + + records1 = session1.get_records() + history1 = list(records1.get_history(is_enabled_for_func)) + assert len(history1) == 0 + + records2 = session2.get_records() + history2 = list(records2.get_history(is_enabled_for_func)) + assert len(history2) == 1 + (group,) = history2 + + assert group.entries == [RecordEntry(fid, ("x", 3))] From 74e95b263a2fcae5c659e94627ebcc7131222527 Mon Sep 17 00:00:00 2001 From: Toru Kawakubo Date: Wed, 21 Jun 2023 10:53:24 +0900 Subject: [PATCH 07/35] Add a test for nested sessions --- .../core/tests/core/utils/test_recording.py | 44 +++++++++++++++++++ 1 file changed, 44 insertions(+) diff --git a/packages/core/tests/core/utils/test_recording.py b/packages/core/tests/core/utils/test_recording.py index bdd74fd7..2f8b84bf 100644 --- a/packages/core/tests/core/utils/test_recording.py +++ b/packages/core/tests/core/utils/test_recording.py @@ -42,6 +42,50 @@ def test_recordable() -> None: ] +def test_nested_sessions() -> None: + fid = func_to_record.id + session1 = RecordSession() + session1.set_level(INFO, func_to_record) + session2 = RecordSession() + session2.set_level(INFO, func_to_record) + + with session1.start(): + assert func_to_record(1) == 2 + with session2.start(): + assert func_to_record(2) == 4 + assert func_to_record(3) == 6 + + records1 = session1.get_records() + history1 = list(records1.get_history(func_to_record)) + assert len(history1) == 3 + group0, group1, group2 = history1 + + assert all(group.func_id == fid for group in history1) + assert group0.entries == [ + RecordEntry(fid, ("x", 1)), + RecordEntry(fid, ("2x", 2)), + ] + assert group1.entries == [ + RecordEntry(fid, ("x", 2)), + RecordEntry(fid, ("2x", 4)), + ] + assert group2.entries == [ + RecordEntry(fid, ("x", 3)), + RecordEntry(fid, ("2x", 6)), + ] + + records2 = session2.get_records() + history2 = list(records2.get_history(func_to_record)) + assert len(history2) == 1 + (group,) = history2 + + assert group.func_id == fid + assert group.entries == [ + RecordEntry(fid, ("x", 2)), + RecordEntry(fid, ("2x", 4)), + ] + + @recordable def nested_func(recorder: Recorder, x: int) -> int: recorder.info("x", x) From a387ecab87ae857d2cf77b6021781f49a83d4ef1 Mon Sep 17 00:00:00 2001 From: Toru Kawakubo Date: Wed, 21 Jun 2023 11:00:12 +0900 Subject: [PATCH 08/35] Hold record level in RecordEntry --- .../core/quri_parts/core/utils/recording.py | 21 +++++--- .../core/tests/core/utils/test_recording.py | 48 +++++++++---------- 2 files changed, 39 insertions(+), 30 deletions(-) diff --git a/packages/core/quri_parts/core/utils/recording.py b/packages/core/quri_parts/core/utils/recording.py index 1c045dbe..ebb80c4b 100644 --- a/packages/core/quri_parts/core/utils/recording.py +++ b/packages/core/quri_parts/core/utils/recording.py @@ -1,6 +1,7 @@ from collections.abc import Callable, Hashable, Iterable, Iterator from contextlib import contextmanager from dataclasses import dataclass +from enum import IntEnum from functools import update_wrapper from typing import Any, Generic, NamedTuple, TypeVar @@ -36,10 +37,13 @@ def id(self) -> RecordableFunctionId: return self._id -RecordLevel: TypeAlias = int +class RecordLevel(IntEnum): + INFO = 20 + DEBUG = 10 -INFO: RecordLevel = 20 -DEBUG: RecordLevel = 10 + +INFO = RecordLevel.INFO +DEBUG = RecordLevel.DEBUG _RecKey: TypeAlias = Hashable _RecValue: TypeAlias = Any @@ -61,7 +65,7 @@ def start_func(self) -> Iterator[None]: def record(self, level: RecordLevel, key: _RecKey, value: _RecValue) -> None: for session in _active_sessions: if session.is_enabled_for(level, self._func_id): - session.handler(self._func_id, key, value) + session.handler(level, self._func_id, key, value) def debug(self, key: _RecKey, value: _RecValue) -> None: self.record(DEBUG, key, value) @@ -103,6 +107,7 @@ def wrapper(*args: P.args, **kwargs: P.kwargs) -> R: @dataclass class RecordEntry: + level: RecordLevel func_id: RecordableFunctionId data: _RecData @@ -145,9 +150,13 @@ def is_enabled_for(self, level: RecordLevel, fid: RecordableFunctionId) -> bool: return fid in self._levels and level >= self._levels[fid] def handler( - self, fid: RecordableFunctionId, key: _RecKey, value: _RecValue + self, + level: RecordLevel, + fid: RecordableFunctionId, + key: _RecKey, + value: _RecValue, ) -> None: - entry = RecordEntry(fid, (key, value)) + entry = RecordEntry(level, fid, (key, value)) self._group_stack[-1].add_entry(entry) @contextmanager diff --git a/packages/core/tests/core/utils/test_recording.py b/packages/core/tests/core/utils/test_recording.py index 2f8b84bf..d7c7b45b 100644 --- a/packages/core/tests/core/utils/test_recording.py +++ b/packages/core/tests/core/utils/test_recording.py @@ -31,14 +31,14 @@ def test_recordable() -> None: assert group0.func_id == fid assert group0.entries == [ - RecordEntry(fid, ("x", 3)), - RecordEntry(fid, ("2x", 6)), + RecordEntry(INFO, fid, ("x", 3)), + RecordEntry(INFO, fid, ("2x", 6)), ] assert group1.func_id == fid assert group1.entries == [ - RecordEntry(fid, ("x", 4)), - RecordEntry(fid, ("2x", 8)), + RecordEntry(INFO, fid, ("x", 4)), + RecordEntry(INFO, fid, ("2x", 8)), ] @@ -62,16 +62,16 @@ def test_nested_sessions() -> None: assert all(group.func_id == fid for group in history1) assert group0.entries == [ - RecordEntry(fid, ("x", 1)), - RecordEntry(fid, ("2x", 2)), + RecordEntry(INFO, fid, ("x", 1)), + RecordEntry(INFO, fid, ("2x", 2)), ] assert group1.entries == [ - RecordEntry(fid, ("x", 2)), - RecordEntry(fid, ("2x", 4)), + RecordEntry(INFO, fid, ("x", 2)), + RecordEntry(INFO, fid, ("2x", 4)), ] assert group2.entries == [ - RecordEntry(fid, ("x", 3)), - RecordEntry(fid, ("2x", 6)), + RecordEntry(INFO, fid, ("x", 3)), + RecordEntry(INFO, fid, ("2x", 6)), ] records2 = session2.get_records() @@ -81,8 +81,8 @@ def test_nested_sessions() -> None: assert group.func_id == fid assert group.entries == [ - RecordEntry(fid, ("x", 2)), - RecordEntry(fid, ("2x", 4)), + RecordEntry(INFO, fid, ("x", 2)), + RecordEntry(INFO, fid, ("2x", 4)), ] @@ -114,21 +114,21 @@ def test_nested_func_record() -> None: assert group0.func_id == fid assert group0.entries == [ - RecordEntry(fid, ("x", 3)), - RecordEntry(fid, ("y", 12)), - RecordEntry(fid, ("2y", 24)), + RecordEntry(INFO, fid, ("x", 3)), + RecordEntry(INFO, fid, ("y", 12)), + RecordEntry(INFO, fid, ("2y", 24)), ] assert group1.func_id == fid assert group1.entries == [ - RecordEntry(fid, ("x", 6)), - RecordEntry(fid, ("2y", 12)), + RecordEntry(INFO, fid, ("x", 6)), + RecordEntry(INFO, fid, ("2y", 12)), ] assert group2.func_id == fid assert group2.entries == [ - RecordEntry(fid, ("x", 4)), - RecordEntry(fid, ("2y", 8)), + RecordEntry(INFO, fid, ("x", 4)), + RecordEntry(INFO, fid, ("2y", 8)), ] @@ -163,7 +163,7 @@ def test_info_level(self) -> None: assert len(history) == 1 (group,) = history - assert group.entries == [RecordEntry(fid, ("info", 3))] + assert group.entries == [RecordEntry(INFO, fid, ("info", 3))] def test_debug_level(self) -> None: fid = rec_level_func.id @@ -179,8 +179,8 @@ def test_debug_level(self) -> None: (group,) = history assert group.entries == [ - RecordEntry(fid, ("info", 3)), - RecordEntry(fid, ("debug", 6)), + RecordEntry(INFO, fid, ("info", 3)), + RecordEntry(DEBUG, fid, ("debug", 6)), ] @@ -207,7 +207,7 @@ def test_is_enabled_for_true(self) -> None: assert len(history) == 1 (group,) = history - assert group.entries == [RecordEntry(fid, ("x", 3))] + assert group.entries == [RecordEntry(INFO, fid, ("x", 3))] def test_is_enabled_for_false(self) -> None: session = RecordSession() @@ -240,4 +240,4 @@ def test_is_enabled_for_multiple_sessions(self) -> None: assert len(history2) == 1 (group,) = history2 - assert group.entries == [RecordEntry(fid, ("x", 3))] + assert group.entries == [RecordEntry(INFO, fid, ("x", 3))] From e7f56e36920c132581d4ead58db2bc65beb7b800 Mon Sep 17 00:00:00 2001 From: Toru Kawakubo Date: Wed, 21 Jun 2023 11:18:52 +0900 Subject: [PATCH 09/35] String representations for record data --- .../core/quri_parts/core/utils/recording.py | 18 ++++++++++++++++++ 1 file changed, 18 insertions(+) diff --git a/packages/core/quri_parts/core/utils/recording.py b/packages/core/quri_parts/core/utils/recording.py index ebb80c4b..8f3df672 100644 --- a/packages/core/quri_parts/core/utils/recording.py +++ b/packages/core/quri_parts/core/utils/recording.py @@ -41,6 +41,9 @@ class RecordLevel(IntEnum): INFO = 20 DEBUG = 10 + def __str__(self) -> str: + return self.name + INFO = RecordLevel.INFO DEBUG = RecordLevel.DEBUG @@ -111,6 +114,9 @@ class RecordEntry: func_id: RecordableFunctionId data: _RecData + def __str__(self) -> str: + return f"{self.level}:{self.func_id}:{self.data}" + @dataclass class RecordGroup: @@ -120,6 +126,18 @@ class RecordGroup: def add_entry(self, entry: RecordEntry) -> None: self.entries.append(entry) + def __str__(self) -> str: + return ( + f"""RecordGroup( + func_id: {self.func_id}, + entries: [ +""" + + "\n".join(f" {entry}," for entry in self.entries) + + """ + ] +)""" + ) + class RecordSet: def __init__(self) -> None: From d78e3d218919f379a17ba95c9d7b6523e82417b6 Mon Sep 17 00:00:00 2001 From: Toru Kawakubo Date: Wed, 21 Jun 2023 14:17:02 +0900 Subject: [PATCH 10/35] Add logging feature --- .../core/quri_parts/core/utils/recording.py | 57 +++++++++++-- .../core/tests/core/utils/test_recording.py | 84 +++++++++++++++++++ 2 files changed, 136 insertions(+), 5 deletions(-) diff --git a/packages/core/quri_parts/core/utils/recording.py b/packages/core/quri_parts/core/utils/recording.py index 8f3df672..68c9689c 100644 --- a/packages/core/quri_parts/core/utils/recording.py +++ b/packages/core/quri_parts/core/utils/recording.py @@ -1,9 +1,11 @@ from collections.abc import Callable, Hashable, Iterable, Iterator from contextlib import contextmanager -from dataclasses import dataclass +from dataclasses import dataclass, field from enum import IntEnum from functools import update_wrapper -from typing import Any, Generic, NamedTuple, TypeVar +import logging +import threading +from typing import Any, Generic, NamedTuple, Optional, TypeVar from typing_extensions import Concatenate, ParamSpec, TypeAlias @@ -16,13 +18,19 @@ class RecordableFunctionId(NamedTuple): qualname: str param: Hashable - def __str__(self) -> str: - base = f"{self.module}.{self.qualname}" + def to_str(self, full: bool = True) -> str: + if full: + base = f"{self.module}.{self.qualname}" + else: + base = self.qualname if self.param: return f"{base}<{str(self.param)}>" else: return base + def __str__(self) -> str: + return self.to_str() + class RecordableFunction(Generic[P, R]): def __init__(self, f: Callable[P, R], id: RecordableFunctionId): @@ -48,6 +56,8 @@ def __str__(self) -> str: INFO = RecordLevel.INFO DEBUG = RecordLevel.DEBUG +_DEFAULT_LOGGER_NAME = f"{logging.Logger.root.name}.quri_parts_recording" + _RecKey: TypeAlias = Hashable _RecValue: TypeAlias = Any _RecData: TypeAlias = tuple[_RecKey, _RecValue] @@ -118,10 +128,21 @@ def __str__(self) -> str: return f"{self.level}:{self.func_id}:{self.data}" +_group_id = threading.local() +_group_id.current = 0 + + +def _next_group_id() -> int: + id: int = _group_id.current + _group_id.current += 1 + return id + + @dataclass class RecordGroup: func_id: RecordableFunctionId entries: list[RecordEntry] + id: int = field(default_factory=_next_group_id) def add_entry(self, entry: RecordEntry) -> None: self.entries.append(entry) @@ -155,11 +176,17 @@ def get_history(self, func: RecordableFunction[P, R]) -> Iterable[RecordGroup]: return filter(lambda g: g.func_id == func.id, self._history) +def _to_logging_level(level: RecordLevel) -> int: + # Each RecordLevel has the same value as a logging level at least at the moment + return level.value + + class RecordSession: def __init__(self) -> None: self._levels: dict[RecordableFunctionId, RecordLevel] = {} self._record_set = RecordSet() self._group_stack: list[RecordGroup] = [] + self._loggers: set[logging.Logger] = set() def set_level(self, level: RecordLevel, func: RecordableFunction[P, R]) -> None: self._levels[func.id] = level @@ -175,7 +202,22 @@ def handler( value: _RecValue, ) -> None: entry = RecordEntry(level, fid, (key, value)) - self._group_stack[-1].add_entry(entry) + group = self._group_stack[-1] + group.add_entry(entry) + self._log(entry, group) + + def _log(self, entry: RecordEntry, group: RecordGroup) -> None: + log_level = _to_logging_level(entry.level) + msg = "" + for logger in self._loggers: + if not logger.isEnabledFor(log_level): + continue + if not msg: + k, v = entry.data + msg = f"{entry.func_id.to_str(False)}: {k}={v}" + logger.getChild(entry.func_id.module).log( + log_level, msg, extra={"record_group": group.id} + ) @contextmanager def start(self) -> Iterator[None]: @@ -195,5 +237,10 @@ def exit_func(self, fid: RecordableFunctionId) -> None: def get_records(self) -> RecordSet: return self._record_set + def add_logger(self, logger: Optional[logging.Logger] = None) -> None: + if logger is None: + logger = logging.getLogger(_DEFAULT_LOGGER_NAME) + self._loggers.add(logger) + _active_sessions: list[RecordSession] = [] diff --git a/packages/core/tests/core/utils/test_recording.py b/packages/core/tests/core/utils/test_recording.py index d7c7b45b..c8bac3cd 100644 --- a/packages/core/tests/core/utils/test_recording.py +++ b/packages/core/tests/core/utils/test_recording.py @@ -1,3 +1,6 @@ +import logging +import pytest + from quri_parts.core.utils.recording import ( DEBUG, INFO, @@ -241,3 +244,84 @@ def test_is_enabled_for_multiple_sessions(self) -> None: (group,) = history2 assert group.entries == [RecordEntry(INFO, fid, ("x", 3))] + + +@recordable +def logging_func(recorder: Recorder, x: int) -> int: + recorder.info("x", x) + recorder.debug("2x", 2 * x) + return 2 * x + + +class TestLogging: + def test_default_logger_info(self, caplog: pytest.LogCaptureFixture) -> None: + caplog.set_level(logging.INFO) + + session = RecordSession() + session.set_level(INFO, logging_func) + session.add_logger() + + with session.start(): + assert logging_func(3) == 6 + + assert len(caplog.records) == 1 + log_record = caplog.records[0] + assert log_record.name == f"root.quri_parts_recording.{logging_func.id.module}" + assert log_record.levelno == logging.INFO + assert log_record.message == f"{logging_func.id.qualname}: x=3" + assert isinstance(getattr(log_record, "record_group"), int) + + def test_default_logger_debug(self, caplog: pytest.LogCaptureFixture) -> None: + caplog.set_level(logging.DEBUG) + + session = RecordSession() + session.set_level(DEBUG, logging_func) + session.add_logger() + + with session.start(): + assert logging_func(3) == 6 + + assert len(caplog.records) == 2 + log_record0, log_record1 = caplog.records + + assert log_record0.name == f"root.quri_parts_recording.{logging_func.id.module}" + assert log_record0.levelno == logging.INFO + assert log_record0.message == f"{logging_func.id.qualname}: x=3" + assert isinstance(getattr(log_record0, "record_group"), int) + + assert log_record1.name == f"root.quri_parts_recording.{logging_func.id.module}" + assert log_record1.levelno == logging.DEBUG + assert log_record1.message == f"{logging_func.id.qualname}: 2x=6" + assert isinstance(getattr(log_record1, "record_group"), int) + + assert getattr(log_record0, "record_group") == getattr( + log_record1, "record_group" + ) + + def test_custom_logger(self, caplog: pytest.LogCaptureFixture) -> None: + log_name = "test_recording" + caplog.set_level(logging.INFO, logger=log_name) + logger = logging.getLogger(log_name) + + session = RecordSession() + session.set_level(INFO, logging_func) + session.add_logger(logger) + + with session.start(): + assert logging_func(3) == 6 + + assert len(caplog.records) == 1 + log_record = caplog.records[0] + assert log_record.name == f"{log_name}.{logging_func.id.module}" + assert log_record.levelno == logging.INFO + assert log_record.message == f"{logging_func.id.qualname}: x=3" + assert isinstance(getattr(log_record, "record_group"), int) + + def test_no_logging_by_default(self, caplog: pytest.LogCaptureFixture) -> None: + session = RecordSession() + session.set_level(INFO, logging_func) + + with session.start(): + assert logging_func(3) == 6 + + assert len(caplog.record_tuples) == 0 From 80f2dc79529a0b20052e77d2ae416421b6ec6d6e Mon Sep 17 00:00:00 2001 From: Toru Kawakubo Date: Wed, 21 Jun 2023 14:26:46 +0900 Subject: [PATCH 11/35] isort, formatting --- packages/core/quri_parts/core/utils/recording.py | 4 ++-- packages/core/tests/core/utils/test_recording.py | 1 + 2 files changed, 3 insertions(+), 2 deletions(-) diff --git a/packages/core/quri_parts/core/utils/recording.py b/packages/core/quri_parts/core/utils/recording.py index 68c9689c..155df999 100644 --- a/packages/core/quri_parts/core/utils/recording.py +++ b/packages/core/quri_parts/core/utils/recording.py @@ -1,10 +1,10 @@ +import logging +import threading from collections.abc import Callable, Hashable, Iterable, Iterator from contextlib import contextmanager from dataclasses import dataclass, field from enum import IntEnum from functools import update_wrapper -import logging -import threading from typing import Any, Generic, NamedTuple, Optional, TypeVar from typing_extensions import Concatenate, ParamSpec, TypeAlias diff --git a/packages/core/tests/core/utils/test_recording.py b/packages/core/tests/core/utils/test_recording.py index c8bac3cd..ba4fb7ef 100644 --- a/packages/core/tests/core/utils/test_recording.py +++ b/packages/core/tests/core/utils/test_recording.py @@ -1,4 +1,5 @@ import logging + import pytest from quri_parts.core.utils.recording import ( From 9f929321f1acc63f6ff6dfea5a6083073d457cc3 Mon Sep 17 00:00:00 2001 From: Toru Kawakubo Date: Thu, 22 Jun 2023 20:23:54 +0900 Subject: [PATCH 12/35] Documentation (WIP) --- .../core/quri_parts/core/utils/recording.py | 101 ++++++++++++------ .../core/tests/core/utils/test_recording.py | 10 ++ 2 files changed, 81 insertions(+), 30 deletions(-) diff --git a/packages/core/quri_parts/core/utils/recording.py b/packages/core/quri_parts/core/utils/recording.py index 155df999..608cf83b 100644 --- a/packages/core/quri_parts/core/utils/recording.py +++ b/packages/core/quri_parts/core/utils/recording.py @@ -1,3 +1,16 @@ +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# http://www.apache.org/licenses/LICENSE-2.0 +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. + +"""This module provides features of recording and logging intermediate data +from inside functions.""" + import logging import threading from collections.abc import Callable, Hashable, Iterable, Iterator @@ -5,20 +18,52 @@ from dataclasses import dataclass, field from enum import IntEnum from functools import update_wrapper -from typing import Any, Generic, NamedTuple, Optional, TypeVar +from typing import Any, NamedTuple, Optional, Protocol, TypeVar, cast from typing_extensions import Concatenate, ParamSpec, TypeAlias + +class RecordLevel(IntEnum): + """Level of recording, which specifies importance of a recording event. + + A larger value means higher importance. Record level is a concept + similar to :py:mod:`logging` level. Currently each record level has + its counterpart :py:mod:`logging` level with the same integer value. + """ + + INFO = 20 + DEBUG = 10 + + def __str__(self) -> str: + return self.name + + +#: INFO level +INFO = RecordLevel.INFO +#: DEBUG level +DEBUG = RecordLevel.DEBUG + + P = ParamSpec("P") R = TypeVar("R", covariant=True) class RecordableFunctionId(NamedTuple): + """Represents an identifier for a recordable function.""" + + #: Name of the module which the function belongs to. module: str + #: Qualified name of the function. qualname: str + #: Other parameters necessary for identifying a function. It is currently unused. param: Hashable def to_str(self, full: bool = True) -> str: + """Returns a string representation of itself. + + If ``full`` is True, the returned string contains the module + name. + """ if full: base = f"{self.module}.{self.qualname}" else: @@ -32,29 +77,39 @@ def __str__(self) -> str: return self.to_str() -class RecordableFunction(Generic[P, R]): - def __init__(self, f: Callable[P, R], id: RecordableFunctionId): - self._f = f - self._id = id +class RecordableFunction(Protocol[P, R]): + """Represents an instance of a recordable function with its identifier, + which can be accessed via :attr:`id` attribute.""" + + id: RecordableFunctionId def __call__(self, *args: P.args, **kwargs: P.kwargs) -> R: - return self._f(*args, **kwargs) + ... - @property - def id(self) -> RecordableFunctionId: - return self._id +def recordable(f: Callable[Concatenate["Recorder", P], R]) -> RecordableFunction[P, R]: + """A decorator for creating a recordable function. -class RecordLevel(IntEnum): - INFO = 20 - DEBUG = 10 + A function to which this decorator is applied must receive a + :class:`Recorder` as its first positional argument, which can be + used for recording in the function body. This decorator removes the + :class:`Recorder` argument, so a user of the recordable function + does not need to pass a :class:`Recorder` instance. This decorator + also adds a :class:`RecordableFunctionId`, which can be accesed via + :attr:`id` attribute. + """ + param = () # TODO + f_id = RecordableFunctionId(f.__module__, f.__qualname__, param) - def __str__(self) -> str: - return self.name + def wrapper(*args: P.args, **kwargs: P.kwargs) -> R: + recorder = _get_recorder(f_id) + with recorder.start_func(): + return f(recorder, *args, **kwargs) + wrapper = cast(RecordableFunction[P, R], wrapper) + wrapper.id = f_id + return update_wrapper(wrapper, f) -INFO = RecordLevel.INFO -DEBUG = RecordLevel.DEBUG _DEFAULT_LOGGER_NAME = f"{logging.Logger.root.name}.quri_parts_recording" @@ -104,20 +159,6 @@ def _get_recorder(fid: RecordableFunctionId) -> Recorder: return recorder -def recordable(f: Callable[Concatenate[Recorder, P], R]) -> RecordableFunction[P, R]: - param = () # TODO - f_id = RecordableFunctionId(f.__module__, f.__qualname__, param) - - def wrapper(*args: P.args, **kwargs: P.kwargs) -> R: - recorder = _get_recorder(f_id) - with recorder.start_func(): - return f(recorder, *args, **kwargs) - - rf = RecordableFunction(wrapper, f_id) - - return update_wrapper(rf, f) - - @dataclass class RecordEntry: level: RecordLevel diff --git a/packages/core/tests/core/utils/test_recording.py b/packages/core/tests/core/utils/test_recording.py index ba4fb7ef..4dae1e6e 100644 --- a/packages/core/tests/core/utils/test_recording.py +++ b/packages/core/tests/core/utils/test_recording.py @@ -1,3 +1,13 @@ +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# http://www.apache.org/licenses/LICENSE-2.0 +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. + import logging import pytest From 5511881d1e797274cf8aee9d59c3ef2e04ab41a7 Mon Sep 17 00:00:00 2001 From: Toru Shibamiya Date: Thu, 17 Aug 2023 14:26:49 +0900 Subject: [PATCH 13/35] Add docstrings --- .../core/quri_parts/core/utils/recording.py | 61 +++++++++++++++++++ 1 file changed, 61 insertions(+) diff --git a/packages/core/quri_parts/core/utils/recording.py b/packages/core/quri_parts/core/utils/recording.py index 608cf83b..b3f15954 100644 --- a/packages/core/quri_parts/core/utils/recording.py +++ b/packages/core/quri_parts/core/utils/recording.py @@ -119,11 +119,21 @@ def wrapper(*args: P.args, **kwargs: P.kwargs) -> R: class Recorder: + """Data recorder given to the function which uses data to record. + + For the function generated by :func:`recordable`, each function call + starts with calling :meth:`start_func`, which creates a new + :class:`RecordGroup` for the function. Note that you should first create + :class:`RecordSession` to record the data. + """ + def __init__(self, fid: RecordableFunctionId) -> None: self._func_id = fid @contextmanager def start_func(self) -> Iterator[None]: + """Context manager to be called for each :class:`RecordableFunction` + call.""" for session in _active_sessions: session.enter_func(self._func_id) yield @@ -131,17 +141,23 @@ def start_func(self) -> Iterator[None]: session.exit_func(self._func_id) def record(self, level: RecordLevel, key: _RecKey, value: _RecValue) -> None: + """Records the given data to :class:`RecordGroup` belongs to active + :class:`RecordSession`s.""" for session in _active_sessions: if session.is_enabled_for(level, self._func_id): session.handler(level, self._func_id, key, value) def debug(self, key: _RecKey, value: _RecValue) -> None: + """Records the given data with `DEBUG` level.""" self.record(DEBUG, key, value) def info(self, key: _RecKey, value: _RecValue) -> None: + """Records the given data with `INFO` level.""" self.record(INFO, key, value) def is_enabled_for(self, level: RecordLevel) -> bool: + """Checks if there is any active :class:`RecordSession` which records + the data with `level` or lower.""" return any( session.is_enabled_for(level, self._func_id) for session in _active_sessions ) @@ -151,6 +167,7 @@ def is_enabled_for(self, level: RecordLevel) -> bool: def _get_recorder(fid: RecordableFunctionId) -> Recorder: + """Returns :class:`Recorder` corresponding to the `fid`""" if fid in _recorders: return _recorders[fid] else: @@ -161,6 +178,9 @@ def _get_recorder(fid: RecordableFunctionId) -> Recorder: @dataclass class RecordEntry: + """Represents a record data entry with its :class:`RecordLevel` and + :class:`RecordableFunctionId`.""" + level: RecordLevel func_id: RecordableFunctionId data: _RecData @@ -181,11 +201,17 @@ def _next_group_id() -> int: @dataclass class RecordGroup: + """Represents a group of data, which contains the list of + :class:`RecordEntry`s with :class:`RecordableFunctionId`. This group is created for + every :class:`RecordableFunction` calls. + """ + func_id: RecordableFunctionId entries: list[RecordEntry] id: int = field(default_factory=_next_group_id) def add_entry(self, entry: RecordEntry) -> None: + """Adds entry to the group.""" self.entries.append(entry) def __str__(self) -> str: @@ -202,18 +228,25 @@ def __str__(self) -> str: class RecordSet: + """Set of :class:`RecordGroup` stored in sequence.""" + def __init__(self) -> None: self._history: list[RecordGroup] = [] def add_group(self, fid: RecordableFunctionId) -> RecordGroup: + """Creates and adds a :class:`RecordGroup` for given + :class:`RecordableFunctionId`.""" group = RecordGroup(fid, []) self._history.append(group) return group def remove_last_group(self) -> None: + """Remove the last group from the sequence of :class:`RecordGroup`s.""" self._history.pop() def get_history(self, func: RecordableFunction[P, R]) -> Iterable[RecordGroup]: + """Returns the :class:`RecordGroup`s corresponding to the + :class:`RecordableFunction` as an Iterable.""" return filter(lambda g: g.func_id == func.id, self._history) @@ -223,6 +256,10 @@ def _to_logging_level(level: RecordLevel) -> int: class RecordSession: + """ "A session used to store information about :class:`RecordableFunctionId` + of functions and their :class:`RecordLevel`s, and :class:`RecordGroup`s as + a :class:`RecordSet`.""" + def __init__(self) -> None: self._levels: dict[RecordableFunctionId, RecordLevel] = {} self._record_set = RecordSet() @@ -230,9 +267,17 @@ def __init__(self) -> None: self._loggers: set[logging.Logger] = set() def set_level(self, level: RecordLevel, func: RecordableFunction[P, R]) -> None: + """Set the correspondense of the :class:`RecordableFunction` and it's + :class:`RecordLevel` as a dict.""" self._levels[func.id] = level def is_enabled_for(self, level: RecordLevel, fid: RecordableFunctionId) -> bool: + """Checks if the function given as :class:`RecordableFunctionId` is + enabled for given :class:`RecordLevel`. + + I.e. returns if the registered function's level is equal to or + smaller than given `level`. + """ return fid in self._levels and level >= self._levels[fid] def handler( @@ -242,6 +287,7 @@ def handler( key: _RecKey, value: _RecValue, ) -> None: + """Store the given record data.""" entry = RecordEntry(level, fid, (key, value)) group = self._group_stack[-1] group.add_entry(entry) @@ -262,23 +308,38 @@ def _log(self, entry: RecordEntry, group: RecordGroup) -> None: @contextmanager def start(self) -> Iterator[None]: + """Context manager to be called when the session starts.""" _active_sessions.append(self) yield _active_sessions.pop() def enter_func(self, fid: RecordableFunctionId) -> None: + """Creates and adds a new group for given + :class:`RecordableFunctionId`. + + This function is called for each :class:`RecordableFunction` + calls. + """ group = self._record_set.add_group(fid) self._group_stack.append(group) def exit_func(self, fid: RecordableFunctionId) -> None: + """Removes the group added by :meth:`start_func` from + :class:`RecordSet` if it's empty. + + This function is called for each :class:`RecordableFunction` + calls. + """ group = self._group_stack.pop() if not group.entries: self._record_set.remove_last_group() def get_records(self) -> RecordSet: + """Returns the :class:`RecordSet`""" return self._record_set def add_logger(self, logger: Optional[logging.Logger] = None) -> None: + """Adds the :class:`logging.Logger`.""" if logger is None: logger = logging.getLogger(_DEFAULT_LOGGER_NAME) self._loggers.add(logger) From 999d89076d6c9a5d0c29c34db556ad64ab46bc04 Mon Sep 17 00:00:00 2001 From: Toru Shibamiya Date: Fri, 18 Aug 2023 08:15:46 +0900 Subject: [PATCH 14/35] Fix failing checks (docformatter) --- packages/core/quri_parts/core/utils/recording.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/core/quri_parts/core/utils/recording.py b/packages/core/quri_parts/core/utils/recording.py index b3f15954..63f60679 100644 --- a/packages/core/quri_parts/core/utils/recording.py +++ b/packages/core/quri_parts/core/utils/recording.py @@ -256,7 +256,7 @@ def _to_logging_level(level: RecordLevel) -> int: class RecordSession: - """ "A session used to store information about :class:`RecordableFunctionId` + """A session used to store information about :class:`RecordableFunctionId` of functions and their :class:`RecordLevel`s, and :class:`RecordGroup`s as a :class:`RecordSet`.""" From 90d46f0c17bf504ff2ac735540425c5e375713e3 Mon Sep 17 00:00:00 2001 From: Toru Shibamiya <49753430+toru4838@users.noreply.github.com> Date: Fri, 10 Nov 2023 14:28:27 +0900 Subject: [PATCH 15/35] Update packages/core/quri_parts/core/utils/recording.py Co-authored-by: KAWAKUBO Toru --- packages/core/quri_parts/core/utils/recording.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/packages/core/quri_parts/core/utils/recording.py b/packages/core/quri_parts/core/utils/recording.py index 63f60679..f2026d0b 100644 --- a/packages/core/quri_parts/core/utils/recording.py +++ b/packages/core/quri_parts/core/utils/recording.py @@ -141,8 +141,8 @@ def start_func(self) -> Iterator[None]: session.exit_func(self._func_id) def record(self, level: RecordLevel, key: _RecKey, value: _RecValue) -> None: - """Records the given data to :class:`RecordGroup` belongs to active - :class:`RecordSession`s.""" + """Records the given data to :class:`RecordGroup`\ s which belong to active + :class:`RecordSession`\ s.""" for session in _active_sessions: if session.is_enabled_for(level, self._func_id): session.handler(level, self._func_id, key, value) From fb4d962b6aa9d1dc08ca72d1f408746e32cb8e1c Mon Sep 17 00:00:00 2001 From: Toru Shibamiya <49753430+toru4838@users.noreply.github.com> Date: Fri, 10 Nov 2023 14:28:44 +0900 Subject: [PATCH 16/35] Update packages/core/quri_parts/core/utils/recording.py Co-authored-by: KAWAKUBO Toru --- packages/core/quri_parts/core/utils/recording.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/core/quri_parts/core/utils/recording.py b/packages/core/quri_parts/core/utils/recording.py index f2026d0b..38b557c8 100644 --- a/packages/core/quri_parts/core/utils/recording.py +++ b/packages/core/quri_parts/core/utils/recording.py @@ -202,7 +202,7 @@ def _next_group_id() -> int: @dataclass class RecordGroup: """Represents a group of data, which contains the list of - :class:`RecordEntry`s with :class:`RecordableFunctionId`. This group is created for + :class:`RecordEntry`\ s with :class:`RecordableFunctionId`. This group is created for every :class:`RecordableFunction` calls. """ From c6917d16646008f94acb3e5c303d865f4e1ff4ba Mon Sep 17 00:00:00 2001 From: Toru Shibamiya <49753430+toru4838@users.noreply.github.com> Date: Fri, 10 Nov 2023 14:28:51 +0900 Subject: [PATCH 17/35] Update packages/core/quri_parts/core/utils/recording.py Co-authored-by: KAWAKUBO Toru --- packages/core/quri_parts/core/utils/recording.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/core/quri_parts/core/utils/recording.py b/packages/core/quri_parts/core/utils/recording.py index 38b557c8..cf1b3d3d 100644 --- a/packages/core/quri_parts/core/utils/recording.py +++ b/packages/core/quri_parts/core/utils/recording.py @@ -241,7 +241,7 @@ def add_group(self, fid: RecordableFunctionId) -> RecordGroup: return group def remove_last_group(self) -> None: - """Remove the last group from the sequence of :class:`RecordGroup`s.""" + """Remove the last group from the sequence of :class:`RecordGroup`\ s.""" self._history.pop() def get_history(self, func: RecordableFunction[P, R]) -> Iterable[RecordGroup]: From aa4f0f58cc3eee2b28e8522f4c681dd5ab83899e Mon Sep 17 00:00:00 2001 From: Toru Shibamiya <49753430+toru4838@users.noreply.github.com> Date: Fri, 10 Nov 2023 14:28:59 +0900 Subject: [PATCH 18/35] Update packages/core/quri_parts/core/utils/recording.py Co-authored-by: KAWAKUBO Toru --- packages/core/quri_parts/core/utils/recording.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/core/quri_parts/core/utils/recording.py b/packages/core/quri_parts/core/utils/recording.py index cf1b3d3d..b3882f9c 100644 --- a/packages/core/quri_parts/core/utils/recording.py +++ b/packages/core/quri_parts/core/utils/recording.py @@ -245,7 +245,7 @@ def remove_last_group(self) -> None: self._history.pop() def get_history(self, func: RecordableFunction[P, R]) -> Iterable[RecordGroup]: - """Returns the :class:`RecordGroup`s corresponding to the + """Returns the :class:`RecordGroup`\ s corresponding to the :class:`RecordableFunction` as an Iterable.""" return filter(lambda g: g.func_id == func.id, self._history) From 085621d825687a4fd880b1b159aa08be487a68b8 Mon Sep 17 00:00:00 2001 From: Toru Shibamiya <49753430+toru4838@users.noreply.github.com> Date: Fri, 10 Nov 2023 14:29:20 +0900 Subject: [PATCH 19/35] Update packages/core/quri_parts/core/utils/recording.py Co-authored-by: KAWAKUBO Toru --- packages/core/quri_parts/core/utils/recording.py | 9 ++++++--- 1 file changed, 6 insertions(+), 3 deletions(-) diff --git a/packages/core/quri_parts/core/utils/recording.py b/packages/core/quri_parts/core/utils/recording.py index b3882f9c..20086d4c 100644 --- a/packages/core/quri_parts/core/utils/recording.py +++ b/packages/core/quri_parts/core/utils/recording.py @@ -256,9 +256,12 @@ def _to_logging_level(level: RecordLevel) -> int: class RecordSession: - """A session used to store information about :class:`RecordableFunctionId` - of functions and their :class:`RecordLevel`s, and :class:`RecordGroup`s as - a :class:`RecordSet`.""" + """A session manages data recording from recordable functions. + + It internally stores recording data received from recordable + functions. It also calls associated loggers when receiving data + recording events. + """ def __init__(self) -> None: self._levels: dict[RecordableFunctionId, RecordLevel] = {} From 251996bcbc680b4381cc8d115ed32f80a34604db Mon Sep 17 00:00:00 2001 From: Toru Shibamiya <49753430+toru4838@users.noreply.github.com> Date: Fri, 10 Nov 2023 14:29:35 +0900 Subject: [PATCH 20/35] Update packages/core/quri_parts/core/utils/recording.py Co-authored-by: KAWAKUBO Toru --- packages/core/quri_parts/core/utils/recording.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/core/quri_parts/core/utils/recording.py b/packages/core/quri_parts/core/utils/recording.py index 20086d4c..01365b02 100644 --- a/packages/core/quri_parts/core/utils/recording.py +++ b/packages/core/quri_parts/core/utils/recording.py @@ -311,7 +311,7 @@ def _log(self, entry: RecordEntry, group: RecordGroup) -> None: @contextmanager def start(self) -> Iterator[None]: - """Context manager to be called when the session starts.""" + """Starts the data recording session.""" _active_sessions.append(self) yield _active_sessions.pop() From dac71ebe21adcf43e513c7f6ecc2979a15a04773 Mon Sep 17 00:00:00 2001 From: Toru Shibamiya <49753430+toru4838@users.noreply.github.com> Date: Fri, 10 Nov 2023 14:29:55 +0900 Subject: [PATCH 21/35] Update packages/core/quri_parts/core/utils/recording.py Co-authored-by: KAWAKUBO Toru --- packages/core/quri_parts/core/utils/recording.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/packages/core/quri_parts/core/utils/recording.py b/packages/core/quri_parts/core/utils/recording.py index 01365b02..96e78dbc 100644 --- a/packages/core/quri_parts/core/utils/recording.py +++ b/packages/core/quri_parts/core/utils/recording.py @@ -270,8 +270,8 @@ def __init__(self) -> None: self._loggers: set[logging.Logger] = set() def set_level(self, level: RecordLevel, func: RecordableFunction[P, R]) -> None: - """Set the correspondense of the :class:`RecordableFunction` and it's - :class:`RecordLevel` as a dict.""" + """Set a record level for the specified recordable function in this + session.""" self._levels[func.id] = level def is_enabled_for(self, level: RecordLevel, fid: RecordableFunctionId) -> bool: From e25a9ef21e9caa37cdfdb49a66f0f85a09e3a664 Mon Sep 17 00:00:00 2001 From: Toru Shibamiya <49753430+toru4838@users.noreply.github.com> Date: Fri, 10 Nov 2023 14:30:23 +0900 Subject: [PATCH 22/35] Update packages/core/quri_parts/core/utils/recording.py Co-authored-by: KAWAKUBO Toru --- packages/core/quri_parts/core/utils/recording.py | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/packages/core/quri_parts/core/utils/recording.py b/packages/core/quri_parts/core/utils/recording.py index 96e78dbc..428e0057 100644 --- a/packages/core/quri_parts/core/utils/recording.py +++ b/packages/core/quri_parts/core/utils/recording.py @@ -275,11 +275,11 @@ def set_level(self, level: RecordLevel, func: RecordableFunction[P, R]) -> None: self._levels[func.id] = level def is_enabled_for(self, level: RecordLevel, fid: RecordableFunctionId) -> bool: - """Checks if the function given as :class:`RecordableFunctionId` is - enabled for given :class:`RecordLevel`. + """Checks if recording of the given level is enabled for the specified + recordable function in this session. - I.e. returns if the registered function's level is equal to or - smaller than given `level`. + Returns true if the record level set for the function is equal + to or smaller than given `level`. """ return fid in self._levels and level >= self._levels[fid] From 7c6edc762ba63e2374133ab7289338bdcc297fbf Mon Sep 17 00:00:00 2001 From: Toru Shibamiya <49753430+toru4838@users.noreply.github.com> Date: Fri, 10 Nov 2023 14:30:41 +0900 Subject: [PATCH 23/35] Update packages/core/quri_parts/core/utils/recording.py Co-authored-by: KAWAKUBO Toru --- packages/core/quri_parts/core/utils/recording.py | 6 +++++- 1 file changed, 5 insertions(+), 1 deletion(-) diff --git a/packages/core/quri_parts/core/utils/recording.py b/packages/core/quri_parts/core/utils/recording.py index 428e0057..0166a217 100644 --- a/packages/core/quri_parts/core/utils/recording.py +++ b/packages/core/quri_parts/core/utils/recording.py @@ -290,7 +290,11 @@ def handler( key: _RecKey, value: _RecValue, ) -> None: - """Store the given record data.""" + """Handles a data recording event. + + Internally, a :class:`RecordEntry` for the event is created and + loggers associated with the session are invoked. + """ entry = RecordEntry(level, fid, (key, value)) group = self._group_stack[-1] group.add_entry(entry) From 84e30e59ffd2593e740ad884a9cad5884693fb58 Mon Sep 17 00:00:00 2001 From: Toru Shibamiya <49753430+toru4838@users.noreply.github.com> Date: Fri, 10 Nov 2023 14:30:59 +0900 Subject: [PATCH 24/35] Update packages/core/quri_parts/core/utils/recording.py Co-authored-by: KAWAKUBO Toru --- packages/core/quri_parts/core/utils/recording.py | 7 +++---- 1 file changed, 3 insertions(+), 4 deletions(-) diff --git a/packages/core/quri_parts/core/utils/recording.py b/packages/core/quri_parts/core/utils/recording.py index 0166a217..07bde12c 100644 --- a/packages/core/quri_parts/core/utils/recording.py +++ b/packages/core/quri_parts/core/utils/recording.py @@ -321,11 +321,10 @@ def start(self) -> Iterator[None]: _active_sessions.pop() def enter_func(self, fid: RecordableFunctionId) -> None: - """Creates and adds a new group for given - :class:`RecordableFunctionId`. + """A hook called on invocation of a recordable function. - This function is called for each :class:`RecordableFunction` - calls. + Internally it creates and pushes a new record group for the + specified function. """ group = self._record_set.add_group(fid) self._group_stack.append(group) From 9727617fb40b7db6ebac5ae7fbbca3dbecc22585 Mon Sep 17 00:00:00 2001 From: Toru Shibamiya <49753430+toru4838@users.noreply.github.com> Date: Fri, 10 Nov 2023 14:31:20 +0900 Subject: [PATCH 25/35] Update packages/core/quri_parts/core/utils/recording.py Co-authored-by: KAWAKUBO Toru --- packages/core/quri_parts/core/utils/recording.py | 6 ++---- 1 file changed, 2 insertions(+), 4 deletions(-) diff --git a/packages/core/quri_parts/core/utils/recording.py b/packages/core/quri_parts/core/utils/recording.py index 07bde12c..c786da59 100644 --- a/packages/core/quri_parts/core/utils/recording.py +++ b/packages/core/quri_parts/core/utils/recording.py @@ -330,11 +330,9 @@ def enter_func(self, fid: RecordableFunctionId) -> None: self._group_stack.append(group) def exit_func(self, fid: RecordableFunctionId) -> None: - """Removes the group added by :meth:`start_func` from - :class:`RecordSet` if it's empty. + """A hook called on exit of a recordable function. - This function is called for each :class:`RecordableFunction` - calls. + Internally it pops the record group for the specified function. """ group = self._group_stack.pop() if not group.entries: From 072b0ff7e1c870704a35b2e2f118c527d1cec0fc Mon Sep 17 00:00:00 2001 From: Toru Shibamiya <49753430+toru4838@users.noreply.github.com> Date: Fri, 10 Nov 2023 14:31:32 +0900 Subject: [PATCH 26/35] Update packages/core/quri_parts/core/utils/recording.py Co-authored-by: KAWAKUBO Toru --- packages/core/quri_parts/core/utils/recording.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/core/quri_parts/core/utils/recording.py b/packages/core/quri_parts/core/utils/recording.py index c786da59..c3f2cea3 100644 --- a/packages/core/quri_parts/core/utils/recording.py +++ b/packages/core/quri_parts/core/utils/recording.py @@ -339,7 +339,7 @@ def exit_func(self, fid: RecordableFunctionId) -> None: self._record_set.remove_last_group() def get_records(self) -> RecordSet: - """Returns the :class:`RecordSet`""" + """Returns all the records saved in the session.""" return self._record_set def add_logger(self, logger: Optional[logging.Logger] = None) -> None: From 7f27e7677a790c947362e20c3e5759c58f31812e Mon Sep 17 00:00:00 2001 From: Toru Shibamiya <49753430+toru4838@users.noreply.github.com> Date: Fri, 10 Nov 2023 14:31:43 +0900 Subject: [PATCH 27/35] Update packages/core/quri_parts/core/utils/recording.py Co-authored-by: KAWAKUBO Toru --- packages/core/quri_parts/core/utils/recording.py | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/packages/core/quri_parts/core/utils/recording.py b/packages/core/quri_parts/core/utils/recording.py index c3f2cea3..c67fb3ea 100644 --- a/packages/core/quri_parts/core/utils/recording.py +++ b/packages/core/quri_parts/core/utils/recording.py @@ -343,7 +343,9 @@ def get_records(self) -> RecordSet: return self._record_set def add_logger(self, logger: Optional[logging.Logger] = None) -> None: - """Adds the :class:`logging.Logger`.""" + """Connect a logger which logs data recording events received by the + session.""" + if logger is None: logger = logging.getLogger(_DEFAULT_LOGGER_NAME) self._loggers.add(logger) From e5fca799de4682fa2b8bd07eb0badb59b32f801c Mon Sep 17 00:00:00 2001 From: Toru Shibamiya Date: Fri, 10 Nov 2023 14:44:35 +0900 Subject: [PATCH 28/35] Fix linting error --- packages/core/quri_parts/core/utils/recording.py | 12 ++++++------ 1 file changed, 6 insertions(+), 6 deletions(-) diff --git a/packages/core/quri_parts/core/utils/recording.py b/packages/core/quri_parts/core/utils/recording.py index c67fb3ea..3b614241 100644 --- a/packages/core/quri_parts/core/utils/recording.py +++ b/packages/core/quri_parts/core/utils/recording.py @@ -141,7 +141,7 @@ def start_func(self) -> Iterator[None]: session.exit_func(self._func_id) def record(self, level: RecordLevel, key: _RecKey, value: _RecValue) -> None: - """Records the given data to :class:`RecordGroup`\ s which belong to active + r"""Records the given data to :class:`RecordGroup`\ s which belong to active :class:`RecordSession`\ s.""" for session in _active_sessions: if session.is_enabled_for(level, self._func_id): @@ -201,9 +201,9 @@ def _next_group_id() -> int: @dataclass class RecordGroup: - """Represents a group of data, which contains the list of - :class:`RecordEntry`\ s with :class:`RecordableFunctionId`. This group is created for - every :class:`RecordableFunction` calls. + r"""Represents a group of data, which contains the list of + :class:`RecordEntry`\ s with :class:`RecordableFunctionId`. This group is created + for every :class:`RecordableFunction` calls. """ func_id: RecordableFunctionId @@ -241,11 +241,11 @@ def add_group(self, fid: RecordableFunctionId) -> RecordGroup: return group def remove_last_group(self) -> None: - """Remove the last group from the sequence of :class:`RecordGroup`\ s.""" + r"""Remove the last group from the sequence of :class:`RecordGroup`\ s.""" self._history.pop() def get_history(self, func: RecordableFunction[P, R]) -> Iterable[RecordGroup]: - """Returns the :class:`RecordGroup`\ s corresponding to the + r"""Returns the :class:`RecordGroup`\ s corresponding to the :class:`RecordableFunction` as an Iterable.""" return filter(lambda g: g.func_id == func.id, self._history) From 0f6f6aefc6f3cb67ef4c1cba19d5f55ba30f10c6 Mon Sep 17 00:00:00 2001 From: Toru Shibamiya Date: Fri, 10 Nov 2023 14:48:50 +0900 Subject: [PATCH 29/35] Make methods private --- packages/core/quri_parts/core/utils/recording.py | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/packages/core/quri_parts/core/utils/recording.py b/packages/core/quri_parts/core/utils/recording.py index 3b614241..d041865d 100644 --- a/packages/core/quri_parts/core/utils/recording.py +++ b/packages/core/quri_parts/core/utils/recording.py @@ -135,10 +135,10 @@ def start_func(self) -> Iterator[None]: """Context manager to be called for each :class:`RecordableFunction` call.""" for session in _active_sessions: - session.enter_func(self._func_id) + session._enter_func(self._func_id) yield for session in _active_sessions: - session.exit_func(self._func_id) + session._exit_func(self._func_id) def record(self, level: RecordLevel, key: _RecKey, value: _RecValue) -> None: r"""Records the given data to :class:`RecordGroup`\ s which belong to active @@ -320,7 +320,7 @@ def start(self) -> Iterator[None]: yield _active_sessions.pop() - def enter_func(self, fid: RecordableFunctionId) -> None: + def _enter_func(self, fid: RecordableFunctionId) -> None: """A hook called on invocation of a recordable function. Internally it creates and pushes a new record group for the @@ -329,7 +329,7 @@ def enter_func(self, fid: RecordableFunctionId) -> None: group = self._record_set.add_group(fid) self._group_stack.append(group) - def exit_func(self, fid: RecordableFunctionId) -> None: + def _exit_func(self, fid: RecordableFunctionId) -> None: """A hook called on exit of a recordable function. Internally it pops the record group for the specified function. From aeacb9894792942ec57ca385da5a98910c26ff90 Mon Sep 17 00:00:00 2001 From: Toru Shibamiya Date: Fri, 10 Nov 2023 14:56:25 +0900 Subject: [PATCH 30/35] Fix failing checks (docformatter) --- packages/core/quri_parts/core/utils/recording.py | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/packages/core/quri_parts/core/utils/recording.py b/packages/core/quri_parts/core/utils/recording.py index d041865d..d108cc42 100644 --- a/packages/core/quri_parts/core/utils/recording.py +++ b/packages/core/quri_parts/core/utils/recording.py @@ -241,7 +241,8 @@ def add_group(self, fid: RecordableFunctionId) -> RecordGroup: return group def remove_last_group(self) -> None: - r"""Remove the last group from the sequence of :class:`RecordGroup`\ s.""" + r"""Remove the last group from the sequence of + :class:`RecordGroup`\ s.""" self._history.pop() def get_history(self, func: RecordableFunction[P, R]) -> Iterable[RecordGroup]: From 8968496019ae75811b6cea776360976b3dc5e564 Mon Sep 17 00:00:00 2001 From: Toru Shibamiya Date: Thu, 16 Nov 2023 11:09:45 +0900 Subject: [PATCH 31/35] Add short comment --- packages/core/quri_parts/core/utils/recording.py | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/packages/core/quri_parts/core/utils/recording.py b/packages/core/quri_parts/core/utils/recording.py index d108cc42..6f1ef271 100644 --- a/packages/core/quri_parts/core/utils/recording.py +++ b/packages/core/quri_parts/core/utils/recording.py @@ -98,7 +98,8 @@ def recordable(f: Callable[Concatenate["Recorder", P], R]) -> RecordableFunction also adds a :class:`RecordableFunctionId`, which can be accesed via :attr:`id` attribute. """ - param = () # TODO + # Currently `param` is an empty tuple. But we may add support for it in the future. + param = () f_id = RecordableFunctionId(f.__module__, f.__qualname__, param) def wrapper(*args: P.args, **kwargs: P.kwargs) -> R: From a77897f3e5646cfff39fd758206ceb4086b3e869 Mon Sep 17 00:00:00 2001 From: Toru Shibamiya Date: Wed, 22 Nov 2023 12:02:40 +0900 Subject: [PATCH 32/35] deepcopy RecValue before storing --- .../core/quri_parts/core/utils/recording.py | 6 +++- .../core/tests/core/utils/test_recording.py | 28 ++++++++++++++++++- 2 files changed, 32 insertions(+), 2 deletions(-) diff --git a/packages/core/quri_parts/core/utils/recording.py b/packages/core/quri_parts/core/utils/recording.py index 6f1ef271..7375e9d7 100644 --- a/packages/core/quri_parts/core/utils/recording.py +++ b/packages/core/quri_parts/core/utils/recording.py @@ -11,6 +11,7 @@ """This module provides features of recording and logging intermediate data from inside functions.""" +import copy import logging import threading from collections.abc import Callable, Hashable, Iterable, Iterator @@ -97,6 +98,9 @@ def recordable(f: Callable[Concatenate["Recorder", P], R]) -> RecordableFunction does not need to pass a :class:`Recorder` instance. This decorator also adds a :class:`RecordableFunctionId`, which can be accesed via :attr:`id` attribute. + + Note that since data is deepcopied before storing, recording large + mutable data may introduces a performance penalty. """ # Currently `param` is an empty tuple. But we may add support for it in the future. param = () @@ -297,7 +301,7 @@ def handler( Internally, a :class:`RecordEntry` for the event is created and loggers associated with the session are invoked. """ - entry = RecordEntry(level, fid, (key, value)) + entry = RecordEntry(level, fid, (key, copy.deepcopy(value))) group = self._group_stack[-1] group.add_entry(entry) self._log(entry, group) diff --git a/packages/core/tests/core/utils/test_recording.py b/packages/core/tests/core/utils/test_recording.py index 4dae1e6e..3dd1e9ba 100644 --- a/packages/core/tests/core/utils/test_recording.py +++ b/packages/core/tests/core/utils/test_recording.py @@ -9,7 +9,9 @@ # limitations under the License. import logging +from typing import Any +import numpy as np import pytest from quri_parts.core.utils.recording import ( @@ -23,7 +25,7 @@ @recordable -def func_to_record(recorder: Recorder, x: int) -> int: +def func_to_record(recorder: Recorder, x: Any) -> int: recorder.info("x", x) recorder.info("2x", 2 * x) return 2 * x @@ -56,6 +58,30 @@ def test_recordable() -> None: ] +def test_mutable_recdata() -> None: + session = RecordSession() + session.set_level(INFO, func_to_record) + + with session.start(): + array = np.array([1, 2]) + assert np.allclose(func_to_record(array), np.array(2 * array)) + array[0] = 3 + assert np.allclose(func_to_record(array), np.array(2 * array)) + + records = session.get_records() + history = list(records.get_history(func_to_record)) + assert len(history) == 2 + group0, group1 = history + + k, v = group0.entries[0].data + k == "x" + assert np.allclose(v, np.array([1, 2])) + + k, v = group1.entries[1].data + k == "2x" + assert np.allclose(v, np.array([6, 4])) + + def test_nested_sessions() -> None: fid = func_to_record.id session1 = RecordSession() From 4ff3ef4160ff4f14ca3513ccac9de55221eca862 Mon Sep 17 00:00:00 2001 From: Toru Shibamiya Date: Wed, 22 Nov 2023 12:09:20 +0900 Subject: [PATCH 33/35] fix failing type check --- packages/core/tests/core/utils/test_recording.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/core/tests/core/utils/test_recording.py b/packages/core/tests/core/utils/test_recording.py index 3dd1e9ba..4c13bae9 100644 --- a/packages/core/tests/core/utils/test_recording.py +++ b/packages/core/tests/core/utils/test_recording.py @@ -25,7 +25,7 @@ @recordable -def func_to_record(recorder: Recorder, x: Any) -> int: +def func_to_record(recorder: Recorder, x: Any) -> Any: recorder.info("x", x) recorder.info("2x", 2 * x) return 2 * x From 48727d929556170c86cd90a463dc21f33ad20790 Mon Sep 17 00:00:00 2001 From: Toru Shibamiya Date: Wed, 22 Nov 2023 15:52:41 +0900 Subject: [PATCH 34/35] Revert --- .../core/quri_parts/core/utils/recording.py | 6 +--- .../core/tests/core/utils/test_recording.py | 28 +------------------ 2 files changed, 2 insertions(+), 32 deletions(-) diff --git a/packages/core/quri_parts/core/utils/recording.py b/packages/core/quri_parts/core/utils/recording.py index 7375e9d7..6f1ef271 100644 --- a/packages/core/quri_parts/core/utils/recording.py +++ b/packages/core/quri_parts/core/utils/recording.py @@ -11,7 +11,6 @@ """This module provides features of recording and logging intermediate data from inside functions.""" -import copy import logging import threading from collections.abc import Callable, Hashable, Iterable, Iterator @@ -98,9 +97,6 @@ def recordable(f: Callable[Concatenate["Recorder", P], R]) -> RecordableFunction does not need to pass a :class:`Recorder` instance. This decorator also adds a :class:`RecordableFunctionId`, which can be accesed via :attr:`id` attribute. - - Note that since data is deepcopied before storing, recording large - mutable data may introduces a performance penalty. """ # Currently `param` is an empty tuple. But we may add support for it in the future. param = () @@ -301,7 +297,7 @@ def handler( Internally, a :class:`RecordEntry` for the event is created and loggers associated with the session are invoked. """ - entry = RecordEntry(level, fid, (key, copy.deepcopy(value))) + entry = RecordEntry(level, fid, (key, value)) group = self._group_stack[-1] group.add_entry(entry) self._log(entry, group) diff --git a/packages/core/tests/core/utils/test_recording.py b/packages/core/tests/core/utils/test_recording.py index 4c13bae9..4dae1e6e 100644 --- a/packages/core/tests/core/utils/test_recording.py +++ b/packages/core/tests/core/utils/test_recording.py @@ -9,9 +9,7 @@ # limitations under the License. import logging -from typing import Any -import numpy as np import pytest from quri_parts.core.utils.recording import ( @@ -25,7 +23,7 @@ @recordable -def func_to_record(recorder: Recorder, x: Any) -> Any: +def func_to_record(recorder: Recorder, x: int) -> int: recorder.info("x", x) recorder.info("2x", 2 * x) return 2 * x @@ -58,30 +56,6 @@ def test_recordable() -> None: ] -def test_mutable_recdata() -> None: - session = RecordSession() - session.set_level(INFO, func_to_record) - - with session.start(): - array = np.array([1, 2]) - assert np.allclose(func_to_record(array), np.array(2 * array)) - array[0] = 3 - assert np.allclose(func_to_record(array), np.array(2 * array)) - - records = session.get_records() - history = list(records.get_history(func_to_record)) - assert len(history) == 2 - group0, group1 = history - - k, v = group0.entries[0].data - k == "x" - assert np.allclose(v, np.array([1, 2])) - - k, v = group1.entries[1].data - k == "2x" - assert np.allclose(v, np.array([6, 4])) - - def test_nested_sessions() -> None: fid = func_to_record.id session1 = RecordSession() From 5b539cf6c4eb328bb88f14da4ab544ffddd18a53 Mon Sep 17 00:00:00 2001 From: Toru Shibamiya Date: Wed, 22 Nov 2023 16:09:33 +0900 Subject: [PATCH 35/35] Add a cautionary note for mutable data --- packages/core/quri_parts/core/utils/recording.py | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/packages/core/quri_parts/core/utils/recording.py b/packages/core/quri_parts/core/utils/recording.py index 6f1ef271..2d7f7f31 100644 --- a/packages/core/quri_parts/core/utils/recording.py +++ b/packages/core/quri_parts/core/utils/recording.py @@ -97,6 +97,11 @@ def recordable(f: Callable[Concatenate["Recorder", P], R]) -> RecordableFunction does not need to pass a :class:`Recorder` instance. This decorator also adds a :class:`RecordableFunctionId`, which can be accesed via :attr:`id` attribute. + + Note that when you store mutable data such as list, `RecordEntry` + does not store the snapshot of the data. This means that the data + you get is the latest one when you access it. If you want to get + the snapshot of the data, you need to copy it by yourself. """ # Currently `param` is an empty tuple. But we may add support for it in the future. param = ()