Improve logging and error messages (#134)

trovi/api/patches.py

@@ -201,6 +201,11 @@ def apply(self, obj: dict[str, JSON], in_place: bool = False) -> dict[str, JSON]
         return updated_fields
 
     def _get_operation(self, operation: JSONObject) -> jsonpatch.PatchOperation:
+        """
+        This override associates an ID with each operation object so that the
+        owner of the object is able to aggregate errors from all the operations
+        it owns.
+        """
         try:
             op = super(ArtifactPatch, self)._get_operation(operation)
         except jsonpatch.InvalidJsonPatch as e:

trovi/api/serializers.py

@@ -233,6 +233,8 @@ def update(
             # Because of strict_schema validation, this should be unreachable
             raise ValueError("Unknown event type")
 
+        LOG.info(f"Recording {count} {event_type} event(s) from {origin}")
+
         # We don't call bulk_create here, because it doesn't run any save signals
         # even though it persists the models to the database
         with transaction.atomic():
@@ -376,6 +378,10 @@ def create(self, validated_data: dict) -> ArtifactVersion:
             contents_serializer.is_valid(raise_exception=True)
             contents_serializer.save()
 
+        view = self.context["view"]
+        artifact_uuid = view.kwargs.get("parent_lookup_artifact")
+        LOG.info(f"Created new version for artifact {artifact_uuid}: {version.slug}")
+
         return version
 
     def to_representation(self, instance: ArtifactVersion) -> dict:
@@ -402,7 +408,9 @@ class Meta:
 
     def create(self, validated_data: dict) -> ArtifactRole:
         validated_data["assigned_by"] = get_requesting_user_urn(self)
-        return super(ArtifactRoleSerializer, self).create(validated_data)
+        role = super(ArtifactRoleSerializer, self).create(validated_data)
+        LOG.info(f"New role: {role.user} as {role.role} on {role.artifact.uuid}")
+        return role
 
     def update(self, instance, validated_data: dict):
         raise NotImplementedError(f"Incorrect use of {self.__class__.__name__}")
@@ -581,6 +589,8 @@ def create(self, validated_data: dict) -> Artifact:
                 role=ArtifactRole.RoleType.ADMINISTRATOR,
             )
 
+        LOG.info(f"Created new artifact: {artifact.uuid}")
+
         return artifact
 
     def update(self, instance: Artifact, validated_data: dict) -> Artifact:
@@ -653,7 +663,9 @@ def update(self, instance: Artifact, validated_data: dict) -> Artifact:
                     role=ArtifactRole.RoleType.ADMINISTRATOR,
                 )
 
-            return super(ArtifactSerializer, self).update(instance, validated_data)
+            updated = super(ArtifactSerializer, self).update(instance, validated_data)
+            LOG.info(f"Updated artifact {updated.uuid}: {', '.join(validated_data)}")
+            return updated
 
     def to_internal_value(self, data: dict) -> dict:
         # If this is a new Artifact, its default owner is the user who is creating it
@@ -775,7 +787,7 @@ def create(self, validated_data: dict[str, JSON]) -> ArtifactVersionMigration:
         if version.migrations.filter(
             status=ArtifactVersionMigration.MigrationStatus.IN_PROGRESS
         ).exists():
-            raise MethodNotAllowed(
+            raise ConflictError(
                 f"Artifact version {artifact.uuid}/{version.slug} "
                 f"already has a migration in progress."
             )

trovi/api/tasks.py

@@ -90,16 +90,18 @@ def migrate_artifact_version(migration: ArtifactVersionMigration):
     migration_status = ArtifactVersionMigration.MigrationStatus
     dest_backend_name = migration.backend
     source = migration.source_urn
+    version = migration.artifact_version
     # urn:trovi:contents:<backend>:<id>
     source_backend_name, source_id = source.split(":")[3:5]
     source_backend = get_backend(
-        source_backend_name, content_id=source_id, version=migration.artifact_version
+        source_backend_name, content_id=source_id, version=version
     )
     dest_backend = get_backend(
         dest_backend_name,
-        version=migration.artifact_version,
+        version=version,
     )
     with ArtifactVersionMigrationErrorHandler(migration) as error_handler:
+        LOG.info(f"Beginning migration: {source} to {dest_backend_name}")
         dest_backend.open()
         # We want to throw first via the source backend
         # so uploads are short-circuited
@@ -140,8 +142,10 @@ def migrate_artifact_version(migration: ArtifactVersionMigration):
             destination_urn=dest_backend.to_urn(),
         )
         with transaction.atomic():
-            migration.artifact_version.contents_urn = dest_backend.to_urn()
-            migration.artifact_version.save()
+            version.contents_urn = dest_backend.to_urn()
+            version.save()
+
+        LOG.info(f"Finished migration: {source} to {version.contents_urn}")
 
         # New threads get their own DB connection which has to be manually closed
         db.connection.close()

trovi/api/views.py

@@ -1,3 +1,4 @@
+import logging
 from functools import cache
 
 from django.db import transaction
@@ -54,6 +55,8 @@
 from trovi.models import Artifact, ArtifactVersion, ArtifactRole
 from trovi.storage.serializers import StorageRequestSerializer
 
+LOG = logging.getLogger(__name__)
+
 
 @extend_schema_view(
     list=extend_schema(
@@ -235,7 +238,11 @@ def create(self, request: Request, *args, **kwargs) -> Response:
     @transaction.atomic
     def unassign(self, request: Request, *args, **kwargs) -> Response:
         role = self.get_object()
+        user = role.user
+        role_type = role.role
+        artifact = role.artifact
         role.delete()
+        LOG.info(f"Unassigned Role: {user} from {role_type} on {artifact.uuid}")
         return Response(status=status.HTTP_204_NO_CONTENT)
 
 

trovi/common/permissions.py

@@ -110,7 +110,7 @@ def has_permission(self, request: Request, view: views.View) -> bool:
         artifact_uuid = view.kwargs.get("parent_lookup_artifact")
         if not artifact_uuid:
             raise ValueError(
-                "/versions/ endpoint was called without a parent artifact. "
+                "child endpoint of /artifacts was called without a parent artifact. "
                 "Routes are misconfigured."
             )
         artifact = generics.get_object_or_404(

trovi/common/serializers.py

@@ -1,3 +1,4 @@
+import logging
 from typing import Type, Any, Callable, Optional
 
 from django.conf import settings
@@ -11,6 +12,8 @@
 from trovi.fields import URNField
 from util.types import JSON
 
+LOG = logging.getLogger(__name__)
+
 
 class JsonPointerField(serializers.RegexField):
     regex = r"^(/[^/~]*(~[01][^/~]*)*)*$"
@@ -126,6 +129,7 @@ def _is_valid_force_request(self: serializers.Serializer) -> bool:
         if not token:
             raise PermissionDenied("Unauthenticated user attempted to use ?force flag.")
         if token.is_admin():
+            LOG.warning(f"Recorded a forced update from {token.to_urn()}")
             self.context.setdefault("force", True)
             return True
         else:

trovi/storage/backends/base.py

@@ -190,7 +190,9 @@ def get_links(self) -> list[dict[str, JSON]]:
             links.append(git_remote.to_json())
 
         if not links:
-            raise AttributeError(f"Storage backend {self.name} could not generate ")
+            raise AttributeError(
+                f"Storage backend {self.name} could not generate links"
+            )
 
         return links
 

trovi/storage/backends/git.py

@@ -30,7 +30,7 @@ def __init__(
             # this functionality of `giturlparse` is broken currently.
             if protocol not in ["https", "git"]:
                 raise RuntimeError(
-                    f"Can't create a git backend for remote protocl {protocol}"
+                    f"Can't create a git backend for remote protocol {protocol}"
                 )
             self.parsed_git_url = parse_result
         except Exception: