Fixing #112: adding the ability to filter on pipes (#114)

.vscode/settings.json

@@ -33,6 +33,7 @@
         "KPIs",
         "Nanaimo",
         "Nanaimo's",
+        "PYTHONIOENCODING",
         "Segger",
         "Segger's",
         "TLYF",
@@ -108,6 +109,7 @@
         "sched",
         "shutil",
         "sonarcloud",
+        "sploding",
         "startswith",
         "submodule",
         "toctree",
@@ -126,5 +128,6 @@
         "ykush",
         "ykushcmd",
         "ylabel"
-    ]
+    ],
+    "workbench.enableExperiments": false
 }

docs/guide.rst

@@ -301,8 +301,6 @@ You'll see sections with titles like ``fixtures defined from nanaimo...``. For e
 
         :param pytest_request: The request object passed into the pytest fixture factory.
         :type pytest_request: _pytest.fixtures.FixtureRequest
-        :param event_loop: The event loop used by the fixture manager and its fixtures.
-        :type event_loop: asyncio.AbstractEventLoop
         :return: A new fixture manager.
         :rtype: nanaimo.fixtures.FixtureManager
 

src/nanaimo/display.py

@@ -238,6 +238,10 @@ def set_bg_colour(self, r: int, g: int, b: int) -> None:
         except serial.SerialException:
             pass
 
+    def set_status(self, status: str) -> None:
+        status_colour = self._colour_map[status]
+        self.set_bg_colour(status_colour[0], status_colour[1], status_colour[2])
+
     async def on_gather(self, args: nanaimo.Namespace) -> nanaimo.Artifacts:
         if args.character_display_configure:
             self.configure()
@@ -252,8 +256,7 @@ async def on_gather(self, args: nanaimo.Namespace) -> nanaimo.Artifacts:
             self.write(args.character_display_write)
 
         if args.character_display_status is not None:
-            status_colour = self._colour_map[args.character_display_status]
-            self.set_bg_colour(status_colour[0], status_colour[1], status_colour[2])
+            self.set_status(args.character_display_status)
 
         return nanaimo.Artifacts()
 

src/nanaimo/fixtures.py

@@ -65,7 +65,7 @@ async def on_gather(self, args: nanaimo.Namespace) -> nanaimo.Artifacts:
 
     .. invisible-code-block: python
 
-        foo = MyFixture(nanaimo.fixtures.FixtureManager(), nanaimo.Namespace(), loop=_doc_loop)
+        foo = MyFixture(nanaimo.fixtures.FixtureManager(_doc_loop), nanaimo.Namespace())
 
         _doc_loop.run_until_complete(foo.gather())
 
@@ -188,15 +188,50 @@ def __init__(self,
         self._name = self.get_canonical_name()
         self._logger = logging.getLogger(self._name)
         if 'loop' in kwargs:
-            self._loop = typing.cast(typing.Optional[asyncio.AbstractEventLoop], kwargs['loop'])
-        else:
-            self._loop = None
+            print('WARNING: Passing loop into Fixture is deprecated. (This will be an exception in a future release).')
         if 'gather_timeout_seconds' in kwargs:
             gather_timeout_seconds = typing.cast(typing.Optional[float], kwargs['gather_timeout_seconds'])
             self._gather_timeout_seconds = gather_timeout_seconds
         else:
             self._gather_timeout_seconds = None
 
+    def gather_until_complete(self, *args: typing.Any, **kwargs: typing.Any) -> nanaimo.Artifacts:
+        """
+        helper function where this:
+
+        .. invisible-code-block: python
+
+            import nanaimo
+            import nanaimo.fixtures
+            import asyncio
+
+            _doc_loop = asyncio.new_event_loop()
+
+            class MyFixture(nanaimo.fixtures.Fixture):
+
+                @classmethod
+                def on_visit_test_arguments(cls, arguments: nanaimo.Arguments) -> None:
+                    pass
+
+                async def on_gather(self, args: nanaimo.Namespace) -> nanaimo.Artifacts:
+                    artifacts = nanaimo.Artifacts(0)
+                    return artifacts
+
+            foo = MyFixture(nanaimo.fixtures.FixtureManager(_doc_loop), nanaimo.Namespace())
+
+        .. code-block:: python
+
+            foo.gather_until_complete()
+
+        is equivalent to this:
+
+        .. code-block:: python
+
+            foo.loop.run_until_complete(foo.gather())
+
+        """
+        return self.loop.run_until_complete(self.gather(*args, **kwargs))
+
     async def gather(self, *args: typing.Any, **kwargs: typing.Any) -> nanaimo.Artifacts:
         """
         Coroutine awaited to gather a new set of fixture artifacts.
@@ -214,7 +249,7 @@ async def gather(self, *args: typing.Any, **kwargs: typing.Any) -> nanaimo.Artif
             routine = self.on_gather(self._args)  # type: typing.Coroutine
             if self._gather_timeout_seconds is not None:
                 done, pending = await asyncio.wait([asyncio.ensure_future(routine)],
-                                                   loop=self.manager.loop,
+                                                   loop=self.loop,
                                                    timeout=self._gather_timeout_seconds,
                                                    return_when=asyncio.ALL_COMPLETED)  \
                     # type: typing.Set[asyncio.Future], typing.Set[asyncio.Future]
@@ -247,11 +282,7 @@ def loop(self) -> asyncio.AbstractEventLoop:
         running otherwise the loop will be a running loop retrieved by :func:`asyncio.get_event_loop`.
         :raises RuntimeError: if no running event loop could be found.
         """
-        if self._loop is None or not self._loop.is_running():
-            self._loop = self.manager.loop
-        if not self._loop.is_running():
-            raise RuntimeError('No running event loop was found!')
-        return self._loop
+        return self.manager.loop
 
     @property
     def manager(self) -> 'FixtureManager':
@@ -608,6 +639,42 @@ def filter(self, record: logging.LogRecord) -> bool:
                 self.write(record.getMessage())
             return True
 
+    class SubprocessMessageMatcher(logging.Filter):
+        """
+        Helper class for working with :meth:`SubprocessFixture.stdout_filter` or
+        :meth:`SubprocessFixture.stderr_filter`. This implementation will watch every
+        log message and store any that match the provided pattern.
+
+        This matcher does not buffer all logged messages.
+
+        :param pattern: A regular expression to match messages on.
+        :param minimum_level: The minimum loglevel to accumulate messages for.
+        """
+
+        def __init__(self, pattern: typing.Any, minimum_level: int = logging.INFO):
+            logging.Filter.__init__(self)
+            self._pattern = pattern
+            self._minimum_level = minimum_level
+            self._matches = []  # type: typing.List
+
+        @property
+        def match_count(self) -> int:
+            """
+            The number of messages that matched the provided pattern.
+            """
+            return len(self._matches)
+
+        @property
+        def matches(self) -> typing.List:
+            return self._matches
+
+        def filter(self, record: logging.LogRecord) -> bool:
+            if record.levelno >= self._minimum_level:
+                match = self._pattern.match(record.getMessage())
+                if match is not None:
+                    self._matches.append(match)
+            return True
+
     def __init__(self,
                  manager: 'FixtureManager',
                  args: typing.Optional[nanaimo.Namespace] = None,
@@ -658,6 +725,28 @@ def on_visit_test_arguments(cls, arguments: nanaimo.Arguments) -> None:
         arguments.add_argument('--logfile-date-format',
                                default='%Y-%m-%d %H:%M:%S',
                                help='Logger date format to use for the logfile.')
+        arguments.add_argument('--log-stdout',
+                               action='store_true',
+                               help=textwrap.dedent('''
+                               Log stdout to the logfile as INFO logs. This also makes the stdout text
+                               available to the stdout_filter for this fixture.
+
+                               WARNING: Setting this flag may impact performance if the subprocess sends
+                               a significant amount of data through stdout. The fixture buffers all
+                               data sent through pipes in-memory when this flag is set. Prefer subprocesses
+                               that log data directly to disk and filter on that file instead.
+                               ''').strip())
+        arguments.add_argument('--log-stderr',
+                               action='store_true',
+                               help=textwrap.dedent('''
+                               Log stderr to the logfile as ERROR logs. This also makes the stderr text
+                               available to the stderr_filter for this fixture.
+
+                               WARNING: Setting this flag may impact performance if the subprocess sends
+                               a significant amount of data through stderr. The fixture buffers all
+                               data sent through pipes in-memory when this flag is set. Prefer subprocesses
+                               that log data directly to disk and filter on that file instead.
+                               ''').strip())
 
     async def on_gather(self, args: nanaimo.Namespace) -> nanaimo.Artifacts:
         """
@@ -683,6 +772,8 @@ async def on_gather(self, args: nanaimo.Namespace) -> nanaimo.Artifacts:
         logfile_amend = bool(self.get_arg_covariant(args, 'logfile-amend'))
         logfile_fmt = self.get_arg_covariant(args, 'logfile-format')
         logfile_datefmt = self.get_arg_covariant(args, 'logfile-date-format')
+        log_stdout = self.get_arg_covariant(args, 'log-stdout', False)
+        log_stderr = self.get_arg_covariant(args, 'log-stderr', False)
 
         cwd = self.get_arg_covariant(args, 'cwd')
 
@@ -711,9 +802,19 @@ async def on_gather(self, args: nanaimo.Namespace) -> nanaimo.Artifacts:
                 cwd=cwd
             )  # type: asyncio.subprocess.Process
 
-            await self._wait_for_either_until_neither(
-                (proc.stdout if proc.stdout is not None else self._NoopStreamReader()),
-                (proc.stderr if proc.stderr is not None else self._NoopStreamReader()))
+            if log_stdout or log_stderr:
+                # Take the hit to route the pipes through our process
+                stdout, stderr = await proc.communicate()
+
+                if log_stdout and stdout:
+                    self._log_bytes_like_as_lines(logging.INFO, stdout)
+                if log_stderr and stderr:
+                    self._log_bytes_like_as_lines(logging.ERROR, stderr)
+            else:
+                # Simply let the background process do it's thing and wait for it to finish.
+                await self._wait_for_either_until_neither(
+                    (proc.stdout if proc.stdout is not None else self._NoopStreamReader()),
+                    (proc.stderr if proc.stderr is not None else self._NoopStreamReader()))
 
             await proc.wait()
 
@@ -751,6 +852,14 @@ def on_construct_command(self, arguments: nanaimo.Namespace, inout_artifacts: na
     # | PRIVATE METHODS
     # +-----------------------------------------------------------------------+
 
+    def _log_bytes_like_as_lines(self, log_level: int, bytes_like: bytes) -> None:
+        """
+        Given a bytes-like object decode using the system default into text
+        and split the text into lines logging each line at the given log level.
+        """
+        for line in bytes_like.decode(errors='replace').split('\n'):
+            self._logger.log(log_level, (line[:-1] if line.endswith('\r') else line))
+
     class _NoopStreamReader(asyncio.StreamReader):
 
         def __init__(self) -> None:
@@ -809,10 +918,8 @@ def loop(self) -> asyncio.AbstractEventLoop:
         running otherwise the loop will be a running loop retrieved by :func:`asyncio.get_event_loop`.
         :raises RuntimeError: if no running event loop could be found.
         """
-        if self._loop is None or not self._loop.is_running():
+        if self._loop is None or self._loop.is_closed():
             self._loop = asyncio.get_event_loop()
-        if not self._loop.is_running():
-            raise RuntimeError('No running event loop was found!')
         return self._loop
 
     def create_fixture(self,

src/nanaimo/pytest/plugin.py

@@ -103,6 +103,7 @@ def my_fixture_name(nanaimo_fixture_manager, nanaimo_arguments) -> 'nanaimo.fixt
 import nanaimo
 import nanaimo.config
 import nanaimo.fixtures
+import nanaimo.display
 
 
 def create_pytest_fixture(request: typing.Any, fixture_name: str) -> 'nanaimo.fixtures.Fixture':
@@ -123,7 +124,7 @@ def create_pytest_fixture(request: typing.Any, fixture_name: str) -> 'nanaimo.fi
 
 
 @pytest.fixture
-def nanaimo_fixture_manager(request: typing.Any, event_loop: asyncio.AbstractEventLoop) \
+def nanaimo_fixture_manager(request: typing.Any) \
         -> nanaimo.fixtures.FixtureManager:
     """
     Provides a default :class:`FixtureManager <nanaimo.fixtures.FixtureManager>` to a test.
@@ -140,12 +141,10 @@ def test_example(nanaimo_fixture_manager: nanaimo.Namespace) -> None:
 
     :param pytest_request: The request object passed into the pytest fixture factory.
     :type pytest_request: _pytest.fixtures.FixtureRequest
-    :param event_loop: The event loop used by the fixture manager and its fixtures.
-    :type event_loop: asyncio.AbstractEventLoop
     :return: A new fixture manager.
     :rtype: nanaimo.fixtures.FixtureManager
     """
-    return PytestFixtureManager(request.config.pluginmanager, event_loop)
+    return PytestFixtureManager(request.config.pluginmanager)
 
 
 @pytest.fixture
@@ -338,7 +337,9 @@ class PytestFixtureManager(nanaimo.fixtures.FixtureManager):
     pytest plugin APIs.
     """
 
-    def __init__(self, pluginmanager: '_pytest.config.PytestPluginManager', loop: asyncio.AbstractEventLoop):
+    def __init__(self,
+                 pluginmanager: '_pytest.config.PytestPluginManager',
+                 loop: typing.Optional[asyncio.AbstractEventLoop] = None):
         super().__init__(loop=loop)
         self._pluginmanager = pluginmanager
 
@@ -348,17 +349,17 @@ def create_fixture(self,
                        loop: typing.Optional[asyncio.AbstractEventLoop] = None) -> nanaimo.fixtures.Fixture:
         fixture_plugin = self._pluginmanager.get_plugin(canonical_name)
         fixture_type = fixture_plugin.fixture_type
-        return fixture_type(self, args, loop=loop)
+        return fixture_type(self, args)
 
 
 # +---------------------------------------------------------------------------+
 # | INTERNALS :: INTEGRATED DISPLAY
 # +---------------------------------------------------------------------------+
 
-_display_singleton = None  # type: typing.Optional[nanaimo.fixtures.Fixture]
+_display_singleton = None  # type: typing.Optional[nanaimo.display.CharacterDisplay]
 
 
-def _get_display(config: _pytest.config.Config) -> 'nanaimo.fixtures.Fixture':
+def _get_display(config: _pytest.config.Config) -> 'nanaimo.display.CharacterDisplay':
     global _display_singleton
     if _display_singleton is None:
         for fixture_type in config.pluginmanager.hook.pytest_nanaimo_fixture_type():
@@ -581,9 +582,7 @@ def pytest_sessionstart(session: _pytest.main.Session) -> None:
     args = session.config.option
     args_ns = nanaimo.Namespace(args, nanaimo.config.ArgumentDefaults(args), allow_none_values=False)
     nanaimo.set_subprocess_environment(args_ns)
-    display = _get_display(session.config)
-    loop = asyncio.get_event_loop()
-    loop.run_until_complete(display.gather(character_display_status='busy'))
+    _get_display(session.config).set_status('busy')
 
 
 def pytest_runtest_setup(item: pytest.Item) -> None:
@@ -595,11 +594,8 @@ def pytest_runtest_setup(item: pytest.Item) -> None:
     if isinstance(item, _NanaimoItem):
         item.on_setup()
     display = _get_display(item.config)
-    loop = asyncio.get_event_loop()
-    loop.run_until_complete(display.gather(
-        character_display_clear=True,
-        character_display_write=item.name
-    ))
+    display.clear(display_default_message=False)
+    display.write(item.name)
 
 
 def pytest_sessionfinish(session: _pytest.main.Session, exitstatus: int) -> None:
@@ -609,11 +605,8 @@ def pytest_sessionfinish(session: _pytest.main.Session, exitstatus: int) -> None
     guide.
     """
     display = _get_display(session.config)
-    loop = asyncio.get_event_loop()
-    loop.run_until_complete(display.gather(
-        character_display_clear_to_default=True,
-        character_display_status=('okay' if exitstatus == 0 else 'fail')
-    ))
+    display.clear(display_default_message=True)
+    display.set_status('okay' if exitstatus == 0 else 'fail')
 
 # +---------------------------------------------------------------------------+
 # | INTERNALS :: PYTEST HOOKS :: REPORTING

src/nanaimo/version.py

@@ -18,6 +18,6 @@
 #  nanaimo                                   (@&&&&####@@*
 #
 
-__version__ = '0.2.0'
+__version__ = '0.2.1'
 
 __license__ = 'MIT'