Add logs, evolve Django demo to use blueprints

docs/howto/django.md

@@ -174,7 +174,10 @@ PROCRASTINATE_ON_APP_READY: str
 ## Logs
 
 Procrastinate logs to the `procrastinate` logger. You can configure it
-in your `LOGGING` settings.
+in your `LOGGING` settings. The exact setup depends on whether you use
+a structured logging library such as [`structlog`].
+
+See {doc}`logging` for more information.
 
 ## Startup actions
 
@@ -227,3 +230,4 @@ postgres' LISTEN/NOTIFY that integrate with Django. For instance,
 [open an issue]: https://github.com/procrastinate-org/procrastinate/issues
 [this talk at djangocon 2019]: https://www.youtube.com/watch?v=_DIlE-yc9ZQ
 [`AppConfig.ready()`]: https://docs.djangoproject.com/en/5.0/ref/applications/#django.apps.AppConfig.ready
+[`structlog`]: (https://www.structlog.org/en/stable/)

docs/howto/logging.md

@@ -18,8 +18,17 @@ class ProcrastinateLogFilter(logging.Filter):
 logging.getLogger("procrastinate").addFilter(ProcrastinateLogFilter)
 ```
 
-We'll try to document what attribute is available on each log, but one common thing is
-the "action" attribute, that describes the event that triggered the logging. You can
+One extra attribute that should be common to all procrastinate logs is
+`action` attribute, that describes the event that triggered the logging. You can
 match on this.
 
+By default, extra attributes are not shown in the log output. The easiest way
+to see them is to use a structured logging library such as [`structlog`].
+
+If you want a minimal example of a logging setup that displays the extra
+attributes without using third party logging libraries, look at the
+[Django demo]
+
 [extra]: https://timber.io/blog/the-pythonic-guide-to-logging/#adding-context
+[`structlog`]: https://www.structlog.org/en/stable/
+[Django demo]: https://github.com/procrastinate-org/procrastinate/blob/main/procrastinate_demos/demo_django/project/settings.py#L151

procrastinate/blueprints.py

@@ -168,6 +168,15 @@ def add_tasks_from(self, blueprint: Blueprint, *, namespace: str) -> None:
             task.blueprint = self
         blueprint.tasks = new_tasks
 
+        logger.info(
+            "Adding tasks from blueprint",
+            extra={
+                "action": "loading_blueprint",
+                "namespace": namespace,
+                "tasks": [t.name for t in new_tasks.values()],
+            },
+        )
+
         # Add the namespaced tasks to this namespace
         self.tasks.update(new_tasks)
 

procrastinate/worker.py

@@ -234,8 +234,8 @@ async def process_job(self, job: jobs.Job, worker_id: int = 0) -> None:
     def find_task(self, task_name: str) -> tasks.Task:
         try:
             return self.app.tasks[task_name]
-        except KeyError:
-            raise exceptions.TaskNotFound
+        except KeyError as exc:
+            raise exceptions.TaskNotFound from exc
 
     async def run_job(self, job: jobs.Job, worker_id: int) -> None:
         task_name = job.task_name

procrastinate_demos/demo_django/demo/tasks.py

@@ -4,6 +4,7 @@
 
 from django.db import transaction
 
+from procrastinate import App, Blueprint
 from procrastinate.contrib.django import app
 
 from .models import Book
@@ -18,7 +19,16 @@ def index_book(book_id: int):
     set_indexed.defer(book_id=book_id)
 
 
-@app.task(queue="index")
+# Showcasing a task using blueprints. This is not mandatory at all.
+# The blueprint is loaded in PROCRASTINATE_ON_APP_READY
+blueprint = Blueprint()
+
+
+@blueprint.task(queue="index")
 async def set_indexed(book_id: int):
     # Async ORM call
     await Book.objects.filter(id=book_id).aupdate(indexed=True)
+
+
+def on_app_ready(app: App):
+    app.add_tasks_from(blueprint, namespace="bp")

procrastinate_demos/demo_django/project/settings.py

@@ -12,6 +12,7 @@
 
 from __future__ import annotations
 
+import logging
 from pathlib import Path
 
 # Build paths inside the project like this: BASE_DIR / 'subdir'.
@@ -126,16 +127,46 @@
 
 DEFAULT_AUTO_FIELD = "django.db.models.BigAutoField"
 
+
+# This emulates what a normal structured logging setup (e.g. structlog)
+# would get you out of the box, but we didn't want the demo to depend on
+# a specific logging library.
+class ProcrastinateFilter(logging.Filter):
+    _reserved_log_keys = frozenset(
+        """args asctime created exc_info exc_text filename
+        funcName levelname levelno lineno module msecs message msg name pathname
+        process processName relativeCreated stack_info thread threadName""".split()
+    )
+
+    def filter(self, record: logging.LogRecord):
+        record.procrastinate = {}
+        for key, value in vars(record).items():
+            if not key.startswith("_") and key not in self._reserved_log_keys | {
+                "procrastinate"
+            }:
+                record.procrastinate[key] = value  # type: ignore
+        return True
+
+
 LOGGING = {
     "version": 1,
     "formatters": {
-        "procrastinate": {"format": "%(asctime)s %(levelname)-7s %(name)s %(message)s"},
+        "procrastinate": {
+            "format": "%(asctime)s %(levelname)-7s %(name)s %(message)s %(procrastinate)s"
+        },
     },
     "handlers": {
         "procrastinate": {
             "level": "DEBUG",
             "class": "logging.StreamHandler",
             "formatter": "procrastinate",
+            "filters": ["procrastinate"],
+        },
+    },
+    "filters": {
+        "procrastinate": {
+            "()": "procrastinate_demos.demo_django.project.settings.ProcrastinateFilter",
+            "name": "procrastinate",
         },
     },
     "loggers": {
@@ -146,3 +177,5 @@
         },
     },
 }
+
+PROCRASTINATE_ON_APP_READY = "procrastinate_demos.demo_django.demo.tasks.on_app_ready"