Merge pull request #3453 from netbox-community/3452-change-logging

Fixes #3452: Queue deletion ObjectChanges until after response is sent

netbox/circuits/models.py

@@ -270,23 +270,21 @@ class CircuitTermination(CableTermination):
     def __str__(self):
         return 'Side {}'.format(self.get_term_side_display())
 
-    def log_change(self, user, request_id, action):
-        """
-        Reference the parent circuit when recording the change.
-        """
+    def to_objectchange(self, action):
+        # Annotate the parent Circuit
         try:
             related_object = self.circuit
         except Circuit.DoesNotExist:
             # Parent circuit has been deleted
             related_object = None
-        ObjectChange(
-            user=user,
-            request_id=request_id,
+
+        return ObjectChange(
             changed_object=self,
-            related_object=related_object,
+            object_repr=str(self),
             action=action,
+            related_object=related_object,
             object_data=serialize_object(self)
-        ).save()
+        )
 
     @property
     def parent(self):

netbox/dcim/models.py

@@ -37,18 +37,14 @@ class ComponentTemplateModel(models.Model):
         """
         raise NotImplementedError()
 
-    def log_change(self, user, request_id, action):
-        """
-        Log an ObjectChange including the parent DeviceType.
-        """
-        ObjectChange(
-            user=user,
-            request_id=request_id,
+    def to_objectchange(self, action):
+        return ObjectChange(
             changed_object=self,
-            related_object=self.device_type,
+            object_repr=str(self),
             action=action,
+            related_object=self.device_type,
             object_data=serialize_object(self)
-        ).save()
+        )
 
 
 class ComponentModel(models.Model):
@@ -60,23 +56,21 @@ class ComponentModel(models.Model):
     class Meta:
         abstract = True
 
-    def log_change(self, user, request_id, action):
-        """
-        Log an ObjectChange including the parent Device/VM.
-        """
+    def to_objectchange(self, action):
+        # Annotate the parent Device/VM
         try:
             parent = getattr(self, 'device', None) or getattr(self, 'virtual_machine', None)
         except ObjectDoesNotExist:
             # The parent device/VM has already been deleted
             parent = None
-        ObjectChange(
-            user=user,
-            request_id=request_id,
+
+        return ObjectChange(
             changed_object=self,
-            related_object=parent,
+            object_repr=str(self),
             action=action,
+            related_object=parent,
             object_data=serialize_object(self)
-        ).save()
+        )
 
     @property
     def parent(self):
@@ -2327,27 +2321,20 @@ class Interface(CableTermination, ComponentModel):
 
         return super().save(*args, **kwargs)
 
-    def log_change(self, user, request_id, action):
-        """
-        Include the connected Interface (if any).
-        """
-
-        # It's possible that an Interface can be deleted _after_ its parent Device/VM, in which case trying to resolve
-        # the component parent will raise DoesNotExist. For more discussion, see
-        # https://github.com/netbox-community/netbox/issues/2323
+    def to_objectchange(self, action):
+        # Annotate the parent Device/VM
         try:
             parent_obj = self.device or self.virtual_machine
         except ObjectDoesNotExist:
             parent_obj = None
 
-        ObjectChange(
-            user=user,
-            request_id=request_id,
+        return ObjectChange(
             changed_object=self,
-            related_object=parent_obj,
+            object_repr=str(self),
             action=action,
+            related_object=parent_obj,
             object_data=serialize_object(self)
-        ).save()
+        )
 
     # TODO: Remove in v2.7
     @property

netbox/extras/middleware.py

@@ -6,7 +6,6 @@ from datetime import timedelta
 from django.conf import settings
 from django.db.models.signals import post_delete, post_save
 from django.utils import timezone
-from django.utils.functional import curry
 from django_prometheus.models import model_deletes, model_inserts, model_updates
 
 from .constants import (
@@ -19,31 +18,27 @@ from .webhooks import enqueue_webhooks
 _thread_locals = threading.local()
 
 
-def cache_changed_object(instance, **kwargs):
-
-    action = OBJECTCHANGE_ACTION_CREATE if kwargs['created'] else OBJECTCHANGE_ACTION_UPDATE
-
-    # Cache the object for further processing was the response has completed.
-    _thread_locals.changed_objects.append(
-        (instance, action)
-    )
+def cache_changed_object(sender, instance, **kwargs):
+    """
+    Cache an object being created or updated for the changelog.
+    """
+    if hasattr(instance, 'to_objectchange'):
+        action = OBJECTCHANGE_ACTION_CREATE if kwargs['created'] else OBJECTCHANGE_ACTION_UPDATE
+        objectchange = instance.to_objectchange(action)
+        _thread_locals.changed_objects.append(
+            (instance, objectchange)
+        )
 
 
-def _record_object_deleted(request, instance, **kwargs):
-
-    # TODO: Can we cache deletions for later processing like we do for saves? Currently this will trigger an exception
-    # when trying to serialize ManyToMany relations after the object has been deleted. This should be doable if we alter
-    # log_change() to return ObjectChanges to be saved rather than saving them directly.
-
-    # Record that the object was deleted
-    if hasattr(instance, 'log_change'):
-        instance.log_change(request.user, request.id, OBJECTCHANGE_ACTION_DELETE)
-
-    # Enqueue webhooks
-    enqueue_webhooks(instance, request.user, request.id, OBJECTCHANGE_ACTION_DELETE)
-
-    # Increment metric counters
-    model_deletes.labels(instance._meta.model_name).inc()
+def cache_deleted_object(sender, instance, **kwargs):
+    """
+    Cache an object being deleted for the changelog.
+    """
+    if hasattr(instance, 'to_objectchange'):
+        objectchange = instance.to_objectchange(OBJECTCHANGE_ACTION_DELETE)
+        _thread_locals.changed_objects.append(
+            (instance, objectchange)
+        )
 
 
 def purge_objectchange_cache(sender, **kwargs):
@@ -79,12 +74,9 @@ class ObjectChangeMiddleware(object):
         # the same request.
         request.id = uuid.uuid4()
 
-        # Signals don't include the request context, so we're currying it into the post_delete function ahead of time.
-        record_object_deleted = curry(_record_object_deleted, request)
-
         # Connect our receivers to the post_save and post_delete signals.
-        post_save.connect(cache_changed_object, dispatch_uid='record_object_saved')
-        post_delete.connect(record_object_deleted, dispatch_uid='record_object_deleted')
+        post_save.connect(cache_changed_object, dispatch_uid='cache_changed_object')
+        post_delete.connect(cache_deleted_object, dispatch_uid='cache_deleted_object')
 
         # Provide a hook for purging the change cache
         purge_changelog.connect(purge_objectchange_cache)
@@ -95,27 +87,26 @@ class ObjectChangeMiddleware(object):
         # If the change cache has been purged (e.g. due to an exception) abort the logging of all changes resulting from
         # this request.
         if _thread_locals.changed_objects is None:
-
-            # Delete ObjectChanges representing deletions, since these have already been written
-            ObjectChange.objects.filter(request_id=request.id).delete()
-
             return response
 
         # Create records for any cached objects that were created/updated.
-        for obj, action in _thread_locals.changed_objects:
+        for obj, objectchange in _thread_locals.changed_objects:
 
             # Record the change
-            if hasattr(obj, 'log_change'):
-                obj.log_change(request.user, request.id, action)
+            objectchange.user = request.user
+            objectchange.request_id = request.id
+            objectchange.save()
 
             # Enqueue webhooks
-            enqueue_webhooks(obj, request.user, request.id, action)
+            enqueue_webhooks(obj, request.user, request.id, objectchange.action)
 
             # Increment metric counters
-            if action == OBJECTCHANGE_ACTION_CREATE:
+            if objectchange.action == OBJECTCHANGE_ACTION_CREATE:
                 model_inserts.labels(obj._meta.model_name).inc()
-            elif action == OBJECTCHANGE_ACTION_UPDATE:
+            elif objectchange.action == OBJECTCHANGE_ACTION_UPDATE:
                 model_updates.labels(obj._meta.model_name).inc()
+            elif objectchange.action == OBJECTCHANGE_ACTION_DELETE:
+                model_deletes.labels(obj._meta.model_name).inc()
 
         # Housekeeping: 1% chance of clearing out expired ObjectChanges
         if _thread_locals.changed_objects and settings.CHANGELOG_RETENTION and random.randint(1, 100) == 1:

netbox/extras/models.py

@@ -953,8 +953,10 @@ class ObjectChange(models.Model):
     def save(self, *args, **kwargs):
 
         # Record the user's name and the object's representation as static strings
-        self.user_name = self.user.username
-        self.object_repr = str(self.changed_object)
+        if not self.user_name:
+            self.user_name = self.user.username
+        if not self.object_repr:
+            self.object_repr = str(self.changed_object)
 
         return super().save(*args, **kwargs)
 

netbox/extras/tests/test_tags.py

@@ -35,9 +35,9 @@ class TaggedItemTest(APITestCase):
 
         site = Site.objects.create(
             name='Test Site',
-            slug='test-site',
-            tags=['Foo', 'Bar', 'Baz']
+            slug='test-site'
         )
+        site.tags.add('Foo', 'Bar', 'Baz')
 
         data = {
             'tags': ['Foo', 'Bar', 'New Tag']

netbox/extras/tests/test_views.py

@@ -6,6 +6,7 @@ from django.test import Client, TestCase
 from django.urls import reverse
 
 from dcim.models import Site
+from extras.constants import OBJECTCHANGE_ACTION_UPDATE
 from extras.models import ConfigContext, ObjectChange, Tag
 from utilities.testing import create_test_user
 
@@ -82,11 +83,10 @@ class ObjectChangeTestCase(TestCase):
 
         # Create three ObjectChanges
         for i in range(1, 4):
-            site.log_change(
-                user=user,
-                request_id=uuid.uuid4(),
-                action=2
-            )
+            oc = site.to_objectchange(action=OBJECTCHANGE_ACTION_UPDATE)
+            oc.user = user
+            oc.request_id = uuid.uuid4()
+            oc.save()
 
     def test_objectchange_list(self):
 

netbox/ipam/models.py

@@ -647,26 +647,20 @@ class IPAddress(ChangeLoggedModel, CustomFieldModel):
 
         super().save(*args, **kwargs)
 
-    def log_change(self, user, request_id, action):
-        """
-        Include the connected Interface (if any).
-        """
-
-        # It's possible that an IPAddress can be deleted _after_ its parent Interface, in which case trying to resolve
-        # the interface will raise DoesNotExist.
+    def to_objectchange(self, action):
+        # Annotate the assigned Interface (if any)
         try:
             parent_obj = self.interface
         except ObjectDoesNotExist:
             parent_obj = None
 
-        ObjectChange(
-            user=user,
-            request_id=request_id,
+        return ObjectChange(
             changed_object=self,
-            related_object=parent_obj,
+            object_repr=str(self),
             action=action,
+            related_object=parent_obj,
             object_data=serialize_object(self)
-        ).save()
+        )
 
     def to_csv(self):
 

netbox/utilities/models.py

@@ -23,15 +23,14 @@ class ChangeLoggedModel(models.Model):
     class Meta:
         abstract = True
 
-    def log_change(self, user, request_id, action):
+    def to_objectchange(self, action):
         """
-        Create a new ObjectChange representing a change made to this object. This will typically be called automatically
+        Return a new ObjectChange representing a change made to this object. This will typically be called automatically
         by extras.middleware.ChangeLoggingMiddleware.
         """
-        ObjectChange(
-            user=user,
-            request_id=request_id,
+        return ObjectChange(
             changed_object=self,
+            object_repr=str(self),
             action=action,
             object_data=serialize_object(self)
-        ).save()
+        )