Too large commit: Add actions plugin and lots of rework to solve some logging config weirdness it revealed

Author: crimsonknave

annotated_logger/__init__.py

@@ -23,6 +23,7 @@
 
 from makefun import wraps
 
+from annotated_logger.filter import AnnotatedFilter
 from annotated_logger.plugins import BasePlugin
 
 if TYPE_CHECKING:  # pragma: no cover
@@ -98,16 +99,12 @@ class AnnotatedClass(Protocol[C_co]):
     "handlers": {
         "annotated_handler": {
             "class": "logging.StreamHandler",
-            "filters": ["annotated_filter"],
             "formatter": "annotated_formatter",
         },
     },
     "formatters": {
         "annotated_formatter": {
             "class": "pythonjsonlogger.jsonlogger.JsonFormatter",  # pragma: no mutate
-            # Note that this format string uses `time` and `level` which are
-            # set by the renamer plugin. Because the handler is using the
-            # annotated_filter the plugings will be run and the fields will be renamed
             "format": "{created} {levelname} {name} {message}",  # pragma: no mutate
             "style": "{",
         },
@@ -167,61 +164,6 @@ def __next__(self) -> T:
         return value
 
 
-class AnnotatedFilter(logging.Filter):
-    """Filter class that stores the annotations and plugins."""
-
-    def __init__(
-        self,
-        annotations: Annotations,
-        runtime_annotations: Annotations,
-        class_annotations: Annotations,
-        plugins: list[BasePlugin],
-    ) -> None:
-        """Store the annotations, attributes and plugins."""
-        self.annotations = annotations
-        self.class_annotations = class_annotations
-        self.runtime_annotations = runtime_annotations or {}
-        self.plugins = plugins
-
-        # This allows plugins to determine what fields were added by the user
-        # vs the ones native to the log record
-        # TODO(crimsonknave): Make a test for this # noqa: TD003, FIX002
-        self.base_attributes = logging.makeLogRecord({}).__dict__  # pragma: no mutate
-
-    def _all_annotations(self, record: logging.LogRecord) -> Annotations:
-        annotations = {}
-        # Using copy might be better, but, we don't want to add
-        # the runtime annotations to the stored annotations
-        annotations.update(self.class_annotations)
-        annotations.update(self.annotations)
-        for key, function in self.runtime_annotations.items():
-            annotations[key] = function(record)
-        annotations["annotated"] = True
-        return annotations
-
-    def filter(self, record: logging.LogRecord) -> bool:
-        """Add the annotations to the record and allow plugins to filter the record.
-
-        The `filter` method is called on each plugin in the order they are listed.
-        The plugin is then able to maniuplate the record object before the next plugin
-        sees it. Returning False from the filter method will stop the evaluation and
-        the log record won't be emitted.
-        """
-        record.__dict__.update(self._all_annotations(record))
-        for plugin in self.plugins:
-            try:
-                result = plugin.filter(record)
-            except Exception:  # noqa: BLE001
-                failed_plugins = record.__dict__.get("failed_plugins", [])
-                failed_plugins.append(str(plugin.__class__))
-                record.__dict__["failed_plugins"] = failed_plugins
-                result = True
-
-            if not result:
-                return False
-        return True
-
-
 class AnnotatedAdapter(logging.LoggerAdapter):  # pyright: ignore[reportMissingTypeArgument]
     """Adapter that provides extra methods."""
 

annotated_logger/filter.py

@@ -0,0 +1,63 @@
+from __future__ import annotations
+
+import logging
+from typing import Any
+
+import annotated_logger
+
+Annotations = dict[str, Any]
+
+
+class AnnotatedFilter(logging.Filter):
+    """Filter class that stores the annotations and plugins."""
+
+    def __init__(
+        self,
+        annotations: Annotations | None = None,
+        runtime_annotations: Annotations | None = None,
+        class_annotations: Annotations | None = None,
+        plugins: list[annotated_logger.BasePlugin] | None = None,
+    ) -> None:
+        """Store the annotations, attributes and plugins."""
+        self.annotations = annotations or {}
+        self.class_annotations = class_annotations or {}
+        self.runtime_annotations = runtime_annotations or {}
+        self.plugins = plugins or [annotated_logger.BasePlugin()]
+
+        # This allows plugins to determine what fields were added by the user
+        # vs the ones native to the log record
+        # TODO(crimsonknave): Make a test for this # noqa: TD003, FIX002
+        self.base_attributes = logging.makeLogRecord({}).__dict__  # pragma: no mutate
+
+    def _all_annotations(self, record: logging.LogRecord) -> Annotations:
+        annotations = {}
+        # Using copy might be better, but, we don't want to add
+        # the runtime annotations to the stored annotations
+        annotations.update(self.class_annotations)
+        annotations.update(self.annotations)
+        for key, function in self.runtime_annotations.items():
+            annotations[key] = function(record)
+        annotations["annotated"] = True
+        return annotations
+
+    def filter(self, record: logging.LogRecord) -> bool:
+        """Add the annotations to the record and allow plugins to filter the record.
+
+        The `filter` method is called on each plugin in the order they are listed.
+        The plugin is then able to maniuplate the record object before the next plugin
+        sees it. Returning False from the filter method will stop the evaluation and
+        the log record won't be emitted.
+        """
+        record.__dict__.update(self._all_annotations(record))
+        for plugin in self.plugins:
+            try:
+                result = plugin.filter(record)
+            except Exception:  # noqa: BLE001
+                failed_plugins = record.__dict__.get("failed_plugins", [])
+                failed_plugins.append(str(plugin.__class__))
+                record.__dict__["failed_plugins"] = failed_plugins
+                result = True
+
+            if not result:
+                return False
+        return True

annotated_logger/plugins.py

@@ -1,13 +1,14 @@
 from __future__ import annotations
 
 import contextlib
+import logging
 from typing import TYPE_CHECKING
 
 from requests.exceptions import HTTPError
 
-if TYPE_CHECKING:  # pragma: no cover
-    import logging
+from annotated_logger.filter import AnnotatedFilter
 
+if TYPE_CHECKING:  # pragma: no cover
     from annotated_logger import AnnotatedAdapter
 
 
@@ -122,3 +123,68 @@ def delete_keys_nested(
 
         record.__dict__ = delete_keys_nested(record.__dict__, self.keys_to_remove)
         return True
+
+
+class GitHubActionsPlugin(BasePlugin):
+    """Plugin that will format log messages for actions annotations."""
+
+    def __init__(self, annotation_level: int) -> None:
+        """Save the annotation level."""
+        self.annotation_level = annotation_level
+        self.base_attributes = logging.makeLogRecord({}).__dict__  # pragma: no mutate
+        self.attributes_to_exclude = {"annotated"}
+
+    def filter(self, record: logging.LogRecord) -> bool:
+        """Set the actions command to be an annotation if desired."""
+        if record.levelno < self.annotation_level:
+            return False
+
+        added_attributes = {
+            k: v
+            for k, v in record.__dict__.items()
+            if k not in self.base_attributes and k not in self.attributes_to_exclude
+        }
+        record.__dict__["added_attributes"] = added_attributes
+        name = record.levelname.lower()
+        if name == "info":  # pragma: no cover
+            name = "notice"
+        record.__dict__["github_annotation"] = f"{name}::"
+
+        return True
+
+    def logging_config(self) -> dict[str, dict[str, object]]:
+        """Generate the default logging config for the plugin."""
+        return {
+            "handlers": {
+                "actions_handler": {
+                    "class": "logging.StreamHandler",
+                    "filters": ["actions_filter"],
+                    "formatter": "actions_formatter",
+                },
+            },
+            "filters": {
+                "actions_filter": {
+                    "()": AnnotatedFilter,
+                    "plugins": [
+                        BasePlugin(),
+                        self,
+                    ],
+                },
+            },
+            "formatters": {
+                "actions_formatter": {
+                    "format": "{github_annotation} {message} - {added_attributes}",
+                    "style": "{",
+                },
+            },
+            "loggers": {
+                "annotated_logger.actions": {
+                    "level": "DEBUG",
+                    "handlers": [
+                        # This is from the default logging config
+                        "annotated_handler",
+                        "actions_handler",
+                    ],
+                },
+            },
+        }

example/actions.py

@@ -0,0 +1,43 @@
+import logging
+from copy import deepcopy
+
+from annotated_logger import (
+    DEFAULT_LOGGING_CONFIG,
+    AnnotatedAdapter,
+    AnnotatedLogger,
+)
+from annotated_logger.plugins import GitHubActionsPlugin
+
+actions_plugin = GitHubActionsPlugin(annotation_level=logging.INFO)
+
+LOGGING = deepcopy(DEFAULT_LOGGING_CONFIG)
+
+# The GitHubActionsPlugin provides a `logging_config` method that returns some
+# defaults that will annotate at the info (notice) and above.
+# Making a copy of the default logging config and updating with this
+# lets us keep the standard logger and also annotate in actions.
+# But, we need to do it bit by bit so we are updating the loggers and so on
+# instead of replacing the loggers.
+LOGGING["loggers"].update(actions_plugin.logging_config()["loggers"])
+LOGGING["filters"].update(actions_plugin.logging_config()["filters"])
+LOGGING["handlers"].update(actions_plugin.logging_config()["handlers"])
+LOGGING["formatters"].update(actions_plugin.logging_config()["formatters"])
+
+annotated_logger = AnnotatedLogger(
+    plugins=[
+        actions_plugin,
+    ],
+    name="annotated_logger.actions",
+    config=LOGGING,
+)
+
+annotate_logs = annotated_logger.annotate_logs
+
+
+class ActionsExample:
+    """Example application that is designed to run in actions."""
+
+    @annotate_logs(_typing_requested=True)
+    def first_step(self, annotated_logger: AnnotatedAdapter) -> None:
+        """First step of your action."""
+        annotated_logger.info("Step 1 running!")

example/logging_config.py

@@ -57,6 +57,16 @@
         },
         "logging_config.logger_handler": {
             "class": "logging.StreamHandler",
+            # Note that this handler is specifically attached to
+            # `annotated_logger.logging_config.logger` which we intend to use only as a
+            # logger not generated by a decorator. If you add filters to a handler that
+            # will be invoked when logging from a logger generated by the decorator
+            # AKA, logging via the `annotated_logger` parameter, these filters will
+            # be applied *after* the filters that are dynamically generated/updated
+            # and so can override any annotations that share a name.
+            # In this case, if a function annotated `custom_runtime` or one of the
+            # other fields set in the filters above, that value would be overridden
+            # by the value in the filter set in the config.
             "filters": [
                 "logging_config.logger_filter",
                 "logging_config.logger_filter_parens",

pyproject.toml

@@ -61,10 +61,10 @@ dependencies = [
   "pyright",
   "pytest",
   "pytest-cov",
-  "pytest-forked",
   "pytest-freezer",
   "pytest-github-actions-annotate-failures",
   "pytest-mock",
+  "pytest-randomly",
   "requests-mock",
   "ruff",
   "typing_extensions",
@@ -92,11 +92,9 @@ reportMissingTypeArgument = true
 
 [tool.pytest.ini_options]
 # -p no:annotated_logger disables the plugin so that we can request it conftest.py
-# get coverage correctly, users will not have to do this.
+# to get coverage correctly, users will not have to do this.
 # See https://github.com/pytest-dev/pytest/issues/935
-# --forked will run each test in it's own process, which prevents the logging configs
-# from overriding eachother and clobbering the handlers and the like
-addopts = "--cov=annotated_logger --cov=example --cov-report html --cov-report term -p no:annotated_logger --forked"
+addopts = "--cov=annotated_logger --cov=example --cov-report html --cov-report term -p no:annotated_logger"
 filterwarnings = [
   "error",
 ]

requirements/requirements-dev.txt

@@ -7,10 +7,10 @@
 # - pyright
 # - pytest
 # - pytest-cov
-# - pytest-forked
 # - pytest-freezer
 # - pytest-github-actions-annotate-failures
 # - pytest-mock
+# - pytest-randomly
 # - requests-mock
 # - ruff
 # - typing_extensions
@@ -70,8 +70,6 @@ pony==0.7.17
     # via mutmut
 pre-commit==3.7.1
     # via hatch.envs.dev
-py==1.11.0
-    # via pytest-forked
 pychoir==0.0.27
     # via hatch.envs.dev
 pyright==1.1.376
@@ -80,20 +78,20 @@ pytest==8.2.2
     # via
     #   hatch.envs.dev
     #   pytest-cov
-    #   pytest-forked
     #   pytest-freezer
     #   pytest-github-actions-annotate-failures
     #   pytest-mock
+    #   pytest-randomly
 pytest-cov==5.0.0
     # via hatch.envs.dev
-pytest-forked==1.6.0
-    # via hatch.envs.dev
 pytest-freezer==0.4.8
     # via hatch.envs.dev
 pytest-github-actions-annotate-failures==0.2.0
     # via hatch.envs.dev
 pytest-mock==3.14.0
     # via hatch.envs.dev
+pytest-randomly==3.15.0
+    # via hatch.envs.dev
 python-dateutil==2.9.0.post0
     # via freezegun
 python-json-logger==2.0.7