[#132] Add steps logger and refactor reporter usage

Signed-off-by: Andrey Berezin <a.berezin@yadro.com>

src/frostfs_testlib/reporter/__init__.py

@@ -1,6 +1,7 @@
 from frostfs_testlib.reporter.allure_handler import AllureHandler
 from frostfs_testlib.reporter.interfaces import ReporterHandler
 from frostfs_testlib.reporter.reporter import Reporter
+from frostfs_testlib.reporter.steps_logger import StepsLogger
 
 __reporter = Reporter()
 
@@ -15,3 +16,7 @@ def get_reporter() -> Reporter:
         Singleton reporter instance.
     """
     return __reporter
+
+
+def step(title: str):
+    return __reporter.step(title)

src/frostfs_testlib/reporter/allure_handler.py

@@ -1,5 +1,5 @@
 import os
-from contextlib import AbstractContextManager
+from contextlib import AbstractContextManager, ContextDecorator
 from textwrap import shorten
 from typing import Any, Callable
 
@@ -12,7 +12,7 @@ from frostfs_testlib.reporter.interfaces import ReporterHandler
 class AllureHandler(ReporterHandler):
     """Handler that stores test artifacts in Allure report."""
 
-    def step(self, name: str) -> AbstractContextManager:
+    def step(self, name: str) -> AbstractContextManager | ContextDecorator:
         name = shorten(name, width=140, placeholder="...")
         return allure.step(name)
 

src/frostfs_testlib/reporter/interfaces.py

@@ -1,5 +1,5 @@
 from abc import ABC, abstractmethod
-from contextlib import AbstractContextManager
+from contextlib import AbstractContextManager, ContextDecorator
 from typing import Any, Callable
 
 
@@ -7,7 +7,7 @@ class ReporterHandler(ABC):
     """Interface of handler that stores test artifacts in some reporting tool."""
 
     @abstractmethod
-    def step(self, name: str) -> AbstractContextManager:
+    def step(self, name: str) -> AbstractContextManager | ContextDecorator:
         """Register a new step in test execution.
 
         Args:

src/frostfs_testlib/reporter/reporter.py

@@ -5,6 +5,7 @@ from typing import Any, Callable, Optional
 
 from frostfs_testlib.plugins import load_plugin
 from frostfs_testlib.reporter.interfaces import ReporterHandler
+from frostfs_testlib.utils.func_utils import format_by_args
 
 
 @contextmanager
@@ -63,7 +64,8 @@ class Reporter:
             def wrapper(*a, **kw):
                 resulting_func = func
                 for handler in self.handlers:
-                    decorator = handler.step_decorator(name)
+                    parsed_name = format_by_args(func, name, *a, **kw)
+                    decorator = handler.step_decorator(parsed_name)
                     resulting_func = decorator(resulting_func)
 
                 return resulting_func(*a, **kw)
@@ -81,11 +83,11 @@ class Reporter:
         Returns:
             Step context.
         """
-        if not self.handlers:
-            return _empty_step()
-
         step_contexts = [handler.step(name) for handler in self.handlers]
-        return AggregateContextManager(step_contexts)
+        if not step_contexts:
+            step_contexts = [_empty_step()]
+        decorated_wrapper = self.step_deco(name)
+        return AggregateContextManager(step_contexts, decorated_wrapper)
 
     def attach(self, content: Any, file_name: str) -> None:
         """Attach specified content with given file name to the test report.
@@ -104,9 +106,10 @@ class AggregateContextManager(AbstractContextManager):
 
     contexts: list[AbstractContextManager]
 
-    def __init__(self, contexts: list[AbstractContextManager]) -> None:
+    def __init__(self, contexts: list[AbstractContextManager], decorated_wrapper: Callable) -> None:
         super().__init__()
         self.contexts = contexts
+        self.wrapper = decorated_wrapper
 
     def __enter__(self):
         for context in self.contexts:
@@ -127,3 +130,6 @@ class AggregateContextManager(AbstractContextManager):
         # If all context agreed to suppress exception, then suppress it;
         # otherwise return None to reraise
         return True if all(suppress_decisions) else None
+
+    def __call__(self, *args: Any, **kwds: Any) -> Any:
+        return self.wrapper(*args, **kwds)

src/frostfs_testlib/reporter/steps_logger.py

@@ -0,0 +1,56 @@
+import logging
+import threading
+from contextlib import AbstractContextManager, ContextDecorator
+from functools import wraps
+from types import TracebackType
+from typing import Any, Callable
+
+from frostfs_testlib.reporter.interfaces import ReporterHandler
+
+
+class StepsLogger(ReporterHandler):
+    """Handler that prints steps to log."""
+
+    def step(self, name: str) -> AbstractContextManager | ContextDecorator:
+        return StepLoggerContext(name)
+
+    def step_decorator(self, name: str) -> Callable:
+        return StepLoggerContext(name)
+
+    def attach(self, body: Any, file_name: str) -> None:
+        pass
+
+
+class StepLoggerContext(AbstractContextManager):
+    INDENT = {}
+
+    def __init__(self, title: str):
+        self.title = title
+        self.logger = logging.getLogger("NeoLogger")
+        self.thread = threading.get_ident()
+        if self.thread not in StepLoggerContext.INDENT:
+            StepLoggerContext.INDENT[self.thread] = 1
+
+    def __enter__(self) -> Any:
+        indent = ">" * StepLoggerContext.INDENT[self.thread]
+        self.logger.info(f"[{self.thread}] {indent} {self.title}")
+        StepLoggerContext.INDENT[self.thread] += 1
+
+    def __exit__(
+        self,
+        __exc_type: type[BaseException] | None,
+        __exc_value: BaseException | None,
+        __traceback: TracebackType | None,
+    ) -> bool | None:
+
+        StepLoggerContext.INDENT[self.thread] -= 1
+        indent = "<" * StepLoggerContext.INDENT[self.thread]
+        self.logger.info(f"[{self.thread}] {indent} {self.title}")
+
+    def __call__(self, func):
+        @wraps(func)
+        def impl(*a, **kw):
+            with self:
+                return func(*a, **kw)
+
+        return impl

src/frostfs_testlib/testing/parallel.py

@@ -42,7 +42,7 @@ def parallel(
     exceptions = [future.exception() for future in futures if future.exception()]
     if exceptions:
         message = "\n".join([str(e) for e in exceptions])
-        raise RuntimeError(f"The following exceptions occured during parallel run:\n {message}")
+        raise RuntimeError(f"The following exceptions occured during parallel run:\n{message}")
     return futures
 
 

src/frostfs_testlib/testing/test_control.py

@@ -7,6 +7,9 @@ from typing import Any
 from _pytest.outcomes import Failed
 from pytest import fail
 
+from frostfs_testlib import reporter
+from frostfs_testlib.utils.func_utils import format_by_args
+
 logger = logging.getLogger("NeoLogger")
 
 # TODO: we may consider deprecating some methods here and use tenacity instead
@@ -50,7 +53,7 @@ class expect_not_raises:
         return impl
 
 
-def retry(max_attempts: int, sleep_interval: int = 1, expected_result: Any = None):
+def retry(max_attempts: int, sleep_interval: int = 1, expected_result: Any = None, title: str = None):
     """
     Decorator to wait for some conditions/functions to pass successfully.
     This is useful if you don't know exact time when something should pass successfully and do not
@@ -62,8 +65,7 @@ def retry(max_attempts: int, sleep_interval: int = 1, expected_result: Any = Non
     assert max_attempts >= 1, "Cannot apply retry decorator with max_attempts < 1"
 
     def wrapper(func):
-        @wraps(func)
-        def impl(*a, **kw):
+        def call(func, *a, **kw):
             last_exception = None
             for _ in range(max_attempts):
                 try:
@@ -84,6 +86,14 @@ def retry(max_attempts: int, sleep_interval: int = 1, expected_result: Any = Non
             if last_exception is not None:
                 raise last_exception
 
+        @wraps(func)
+        def impl(*a, **kw):
+            if title is not None:
+                with reporter.step(format_by_args(func, title, *a, **kw)):
+                    return call(func, *a, **kw)
+
+            return call(func, *a, **kw)
+
         return impl
 
     return wrapper
@@ -124,6 +134,7 @@ def wait_for_success(
     expected_result: Any = None,
     fail_testcase: bool = False,
     fail_message: str = "",
+    title: str = None,
 ):
     """
     Decorator to wait for some conditions/functions to pass successfully.
@@ -134,8 +145,7 @@ def wait_for_success(
     """
 
     def wrapper(func):
-        @wraps(func)
-        def impl(*a, **kw):
+        def call(func, *a, **kw):
             start = int(round(time()))
             last_exception = None
             while start + max_wait_time >= int(round(time())):
@@ -160,6 +170,14 @@ def wait_for_success(
             if last_exception is not None:
                 raise last_exception
 
+        @wraps(func)
+        def impl(*a, **kw):
+            if title is not None:
+                with reporter.step(format_by_args(func, title, *a, **kw)):
+                    return call(func, *a, **kw)
+
+            return call(func, *a, **kw)
+
         return impl
 
     return wrapper

src/frostfs_testlib/utils/__init__.py

@@ -1,3 +1,7 @@
+"""
+Idea of utils is to have small utilitary functions which are not dependent of anything.
+"""
+
 import frostfs_testlib.utils.converting_utils
 import frostfs_testlib.utils.datetime_utils
 import frostfs_testlib.utils.json_utils

src/frostfs_testlib/utils/func_utils.py

@@ -0,0 +1,58 @@
+import collections
+import inspect
+import sys
+from typing import Callable
+
+
+def format_by_args(__func: Callable, __title: str, *a, **kw) -> str:
+    params = _func_parameters(__func, *a, **kw)
+    args = list(map(lambda x: _represent(x), a))
+
+    return __title.format(*args, **params)
+
+
+# These 2 functions are copied from allure_commons._allure
+# Duplicate it here in order to be independent of allure and make some adjustments.
+def _represent(item):
+    if isinstance(item, str):
+        return item
+    elif isinstance(item, (bytes, bytearray)):
+        return repr(type(item))
+    else:
+        return repr(item)
+
+
+def _func_parameters(func, *args, **kwargs):
+    parameters = {}
+    arg_spec = inspect.getfullargspec(func)
+    arg_order = list(arg_spec.args)
+    args_dict = dict(zip(arg_spec.args, args))
+
+    if arg_spec.defaults:
+        kwargs_defaults_dict = dict(zip(arg_spec.args[-len(arg_spec.defaults) :], arg_spec.defaults))
+        parameters.update(kwargs_defaults_dict)
+
+    if arg_spec.varargs:
+        arg_order.append(arg_spec.varargs)
+        varargs = args[len(arg_spec.args) :]
+        parameters.update({arg_spec.varargs: varargs} if varargs else {})
+
+    if arg_spec.args and arg_spec.args[0] in ["cls", "self"]:
+        args_dict.pop(arg_spec.args[0], None)
+
+    if kwargs:
+        if sys.version_info < (3, 7):
+            # Sort alphabetically as old python versions does
+            # not preserve call order for kwargs.
+            arg_order.extend(sorted(list(kwargs.keys())))
+        else:
+            # Keep py3.7 behaviour to preserve kwargs order
+            arg_order.extend(list(kwargs.keys()))
+        parameters.update(kwargs)
+
+    parameters.update(args_dict)
+
+    items = parameters.items()
+    sorted_items = sorted(map(lambda kv: (kv[0], _represent(kv[1])), items), key=lambda x: arg_order.index(x[0]))
+
+    return collections.OrderedDict(sorted_items)