Add support for correlation_id to pulp

CHANGES/4689.feature

@@ -0,0 +1,2 @@
+Add support for logging messages with a correlation id that can either be autogenerated or passed in
+with a ``Correlation-ID`` header. This feature is provided as a tech preview in pulpcore 3.9.

docs/settings.rst

@@ -266,3 +266,17 @@ ADMIN_SITE_URL
 ^^^^^^^^^^^^^^
 
     The Django admin site URL. Defaults to ``admin/``.
+
+
+DJANGO_GUID
+^^^^^^^^^^^
+
+    Pulp uses ``django-guid`` to append correlation IDs to logging messages. Correlation IDs are
+    autogenerated by default but can also be sent as a header with each request. They are also
+    returned as a header in the response and are recorded in the ``logging_cid`` field of tasks.
+
+    For more information on how to configure the ``DJANGO_GUID`` setting, see the `django-guid
+    settings documentation <https://django-guid.readthedocs.io/en/latest/settings.html>`_.
+
+    This feature is provided as a tech preview and backwards incompatible changes may affect it in
+    future releases of Pulp.

pulpcore/app/migrations/0052_tasking_logging_cid.py

@@ -0,0 +1,18 @@
+# Generated by Django 2.2.16 on 2020-09-25 22:47
+
+from django.db import migrations, models
+
+
+class Migration(migrations.Migration):
+
+    dependencies = [
+        ('core', '0051_timeoutfields'),
+    ]
+
+    operations = [
+        migrations.AddField(
+            model_name='task',
+            name='logging_cid',
+            field=models.CharField(db_index=True, default='', max_length=256),
+        ),
+    ]

pulpcore/app/models/task.py

@@ -321,6 +321,7 @@ class Task(BaseModel, AutoDeleteObjPermsMixin, AutoAddObjPermsMixin):
 
         state (models.TextField): The state of the task
         name (models.TextField): The name of the task
+        logging_cid (models.CharField): The logging CID associated with the task
         started_at (models.DateTimeField): The time the task started executing
         finished_at (models.DateTimeField): The time the task finished executing
         error (pulpcore.app.fields.JSONField): Fatal errors generated by the task
@@ -333,6 +334,7 @@ class Task(BaseModel, AutoDeleteObjPermsMixin, AutoAddObjPermsMixin):
 
     state = models.TextField(choices=TASK_CHOICES)
     name = models.TextField()
+    logging_cid = models.CharField(max_length=256, db_index=True, default="")
 
     started_at = models.DateTimeField(null=True)
     finished_at = models.DateTimeField(null=True)

pulpcore/app/serializers/task.py

@@ -67,6 +67,9 @@ class TaskSerializer(ModelSerializer):
         read_only=True,
     )
     name = serializers.CharField(help_text=_("The name of task."))
+    logging_cid = serializers.CharField(
+        help_text=_("The logging correlation id associated with this task")
+    )
     started_at = serializers.DateTimeField(
         help_text=_("Timestamp of the when this task started execution."), read_only=True
     )
@@ -118,6 +121,7 @@ class Meta:
         fields = ModelSerializer.Meta.fields + (
             "state",
             "name",
+            "logging_cid",
             "started_at",
             "finished_at",
             "error",

pulpcore/app/settings.py

@@ -64,6 +64,7 @@
     "import_export",
     # third-party
     "django_filters",
+    "django_guid",
     "drf_spectacular",
     "guardian",
     "rest_framework",
@@ -93,6 +94,7 @@
         INSTALLED_APPS.append(app)
 
 MIDDLEWARE = [
+    "django_guid.middleware.GuidMiddleware",
     "django.middleware.security.SecurityMiddleware",
     "whitenoise.middleware.WhiteNoiseMiddleware",
     "django.contrib.sessions.middleware.SessionMiddleware",
@@ -186,13 +188,23 @@
 LOGGING = {
     "version": 1,
     "disable_existing_loggers": False,
-    "formatters": {"simple": {"format": "pulp: %(name)s:%(levelname)s: %(message)s"}},
-    "handlers": {"console": {"class": "logging.StreamHandler", "formatter": "simple"}},
+    "formatters": {
+        "simple": {"format": "pulp [%(correlation_id)s]: %(name)s:%(levelname)s: %(message)s"}
+    },
+    "filters": {"correlation_id": {"()": "django_guid.log_filters.CorrelationId"}},
+    "handlers": {
+        "console": {
+            "class": "logging.StreamHandler",
+            "formatter": "simple",
+            "filters": ["correlation_id"],
+        }
+    },
     "loggers": {
         "": {
             # The root logger
             "handlers": ["console"],
             "level": "INFO",
+            "filters": ["correlation_id"],
         },
     },
 }

pulpcore/tasking/tasks.py

@@ -5,6 +5,7 @@
 
 from django.db import IntegrityError, transaction
 from django.db.models import Model
+from django_guid.middleware import GuidMiddleware
 from redis.exceptions import ConnectionError as RedisConnectionError
 from rq import Queue
 from rq.job import Job, get_current_job
@@ -80,6 +81,7 @@ def _queue_reserved_task(func, inner_task_id, resources, inner_args, inner_kwarg
     """
     redis_conn = connection.get_redis_connection()
     task_status = Task.objects.get(pk=inner_task_id)
+    GuidMiddleware.set_guid(task_status.logging_cid)
     task_name = func.__module__ + "." + func.__name__
 
     while True:
@@ -231,6 +233,7 @@ def as_url(r):
             pk=inner_task_id,
             _resource_job_id=resource_task_id,
             state=TASK_STATES.WAITING,
+            logging_cid=(GuidMiddleware.get_guid() or ""),
             task_group=task_group,
             name=f"{func.__module__}.{func.__name__}",
             **parent_kwarg,

pulpcore/tasking/worker.py

@@ -16,6 +16,7 @@
 from django_currentuser.middleware import (  # noqa: E402: module level not at top of file
     _set_current_user,
 )
+from django_guid.middleware import GuidMiddleware  # noqa: E402: module level not at top of file
 
 from pulpcore.app.models import Task  # noqa: E402: module level not at top of file
 
@@ -98,6 +99,7 @@ def perform_job(self, job, queue):
             task.set_running()
             user = get_users_with_perms(task).first()
             _set_current_user(user)
+            GuidMiddleware.set_guid(task.logging_cid)
 
         return super().perform_job(job, queue)
 

pulpcore/tests/functional/api/test_correlation_id.py

@@ -0,0 +1,35 @@
+import unittest
+import uuid
+
+from pulp_smash import api, cli, config
+from pulp_smash.pulp3.bindings import monitor_task
+
+from pulpcore.client.pulpcore import ApiClient, OrphansApi, TasksApi
+
+
+class CorrelationIdTestCase(unittest.TestCase):
+    """Test correlation id functionality."""
+
+    @classmethod
+    def setUpClass(cls):
+        """Set up class variables."""
+        cls.cid = str(uuid.uuid4())
+        cls.cfg = config.get_config()
+        cls.client = api.Client(cls.cfg, api.json_handler)
+        cls.client = ApiClient(
+            configuration=cls.cfg.get_bindings_config(),
+            header_name="Correlation-ID",
+            header_value=cls.cid,
+        )
+        cls.cli_client = cli.Client(cls.cfg)
+
+        cls.orphan_api = OrphansApi(cls.client)
+        cls.task_api = TasksApi(cls.client)
+
+    def test_correlation_id(self):
+        """Test that a correlation can be passed as a header and logged."""
+        response, status, headers = self.orphan_api.delete_with_http_info()
+        monitor_task(response.task)
+        task = self.task_api.read(response.task)
+        self.assertEqual(headers["Correlation-ID"], self.cid)
+        self.assertEqual(task.logging_cid, self.cid)

requirements.txt

@@ -6,6 +6,7 @@ Django~=2.2.17  # LTS version, switch only if we have a compelling reason to
 django-currentuser~=0.5.1
 django-filter~=2.4.0
 django-guardian~=2.3.0
+django-guid<3.0
 django-import-export~=2.4.0
 django-lifecycle~=0.8.0
 djangorestframework~=3.12.2