Audit Logging Update

common/logging.py

@@ -0,0 +1,14 @@
+import logging
+import typing
+from datetime import UTC, datetime
+
+
+class AuditFormatter(logging.Formatter):
+    @typing.override
+    def formatTime(self, record, datefmt=None):
+        return (
+            datetime.fromtimestamp(record.created, tz=UTC).strftime(
+                "%Y-%m-%dT%H:%M:%S."
+            )
+            + f"{record.msecs:03.0f}Z"
+        )

common/signals.py

@@ -7,6 +7,10 @@
 
 audit_logger = logging.getLogger("audit")
 
+AUDIT_EXCLUDED_FIELDS: dict[str, set[str]] = {
+    "User": {"last_login"},
+    "PermissionSet": set(),
+}
 AUDITABLE_MODELS = ["PermissionSet", "User"]
 AUDITABLE_RELATIONSHIPS = ["User_permission_sets"]
 
@@ -25,6 +29,8 @@ def track_concrete_field_changes(sender, instance, update_fields=None, **kwargs)
     if sender.__name__ not in AUDITABLE_MODELS:
         return
 
+    excluded = AUDIT_EXCLUDED_FIELDS.get(sender.__name__, set())
+
     if not instance.pk:
         instance.audit_fields_changed = True
         return
@@ -35,14 +41,16 @@ def track_concrete_field_changes(sender, instance, update_fields=None, **kwargs)
             for f in instance._meta.get_fields()  # noqa: E261 SLF001
             if f.many_to_many
         }
-        instance.audit_fields_changed = bool(set(update_fields) - m2m_names)
+        auditable_fields = set(update_fields) - m2m_names - excluded
+        instance.audit_fields_changed = bool(auditable_fields)
         return
 
     try:
         stored = sender.objects.get(pk=instance.pk)
         instance.audit_fields_changed = any(
             getattr(instance, f) != getattr(stored, f)
             for f in _concrete_field_names(instance)
+            if f not in excluded
         )
     except sender.DoesNotExist:
         instance.audit_fields_changed = True
@@ -58,14 +66,19 @@ def audit_m2m_relationships_log(sender, instance, action, pk_set, **kwargs):
 
     user = get_current_user()
     user_id = user.id if user and user.is_authenticated else "anonymous"
+    target_string = (
+        f"pk={instance.pk}, id={instance.user_id}"
+        if hasattr(instance, "user_id")
+        else f"pk={instance.pk}"
+    )
 
     if action == "post_add":
         audit_logger.info(
             "User permission sets relationship added",
             extra={
                 "user": user_id,
                 "action": f"ADD {sender.__name__} {pk_set}",
-                "target": instance.pk,
+                "target": target_string,
             },
         )
     elif action == "post_remove":
@@ -74,7 +87,7 @@ def audit_m2m_relationships_log(sender, instance, action, pk_set, **kwargs):
             extra={
                 "user": user_id,
                 "action": f"REMOVE {sender.__name__} {pk_set}",
-                "target": instance.pk,
+                "target": target_string,
             },
         )
     elif action == "post_clear":
@@ -83,7 +96,7 @@ def audit_m2m_relationships_log(sender, instance, action, pk_set, **kwargs):
             extra={
                 "user": user_id,
                 "action": f"CLEAR {sender.__name__}",
-                "target": instance.pk,
+                "target": target_string,
             },
         )
 
@@ -99,13 +112,18 @@ def audit_save_log(sender, instance, created, **kwargs):
     user = get_current_user()
     user_id = user.id if user else "anonymous"
     action = "CREATED" if created else "UPDATED"
+    target_string = (
+        f"pk={instance.pk}, id={instance.user_id}"
+        if hasattr(instance, "user_id")
+        else f"pk={instance.pk}"
+    )
 
     audit_logger.info(
         "Model saved",
         extra={
             "user": user_id,
             "action": f"{action} {sender.__name__}",
-            "target": f"id={instance.pk}",
+            "target": target_string,
         },
     )
 
@@ -117,12 +135,17 @@ def audit_delete_log(sender, instance, **kwargs):
 
     user = get_current_user()
     user_id = user.id if user else "anonymous"
+    target_string = (
+        f"pk={instance.pk}, id={instance.user_id}"
+        if hasattr(instance, "user_id")
+        else f"pk={instance.pk}"
+    )
 
     audit_logger.info(
         "Model deleted",
         extra={
             "user": user_id,
-            "action": f"DELETE {sender.__name__}",
-            "target": f"id={instance.pk}",
+            "action": f"pk={instance.pk}, DELETE {sender.__name__}",
+            "target": target_string,
         },
     )

metrics/api/settings/default.py

@@ -197,7 +197,8 @@
             "format": f"%(asctime)s [%(levelname)s] [ENVIRONMENT:{config.APIENV}] [%(name)s - %(funcName)s] %(message)s"
         },
         "audit": {
-            "format": "[AUDIT_EVENT] %(asctime)s [User:%(user)s - Action:%(action)s - Target:%(target)s]"
+            "()": "common.logging.AuditFormatter",
+            "format": "[AUDIT_EVENT] %(asctime)s [User:%(user)s - Action:%(action)s - Target:%(target)s]",
         },
     },
     "handlers": {