Added logs for crud operations

Author: avirajsingh7

backend/app/crud/api_key.py

@@ -1,5 +1,6 @@
 import uuid
 import secrets
+import logging
 from sqlmodel import Session, select
 from app.core.security import (
     get_password_hash,
@@ -11,11 +12,19 @@
 from app.core.exception_handlers import HTTPException
 from app.models.api_key import APIKey, APIKeyPublic
 
+logger = logging.getLogger(__name__)
+
 
 def generate_api_key() -> tuple[str, str]:
     """Generate a new API key and its hash."""
+    logger.info(
+        f"[generate_api_key] Generating new API key | {{'action': 'generate'}}"
+    )
     raw_key = "ApiKey " + secrets.token_urlsafe(32)
     hashed_key = get_password_hash(raw_key)
+    logger.info(
+        f"[generate_api_key] API key generated successfully | {{'action': 'generated'}}"
+    )
     return raw_key, hashed_key
 
 
@@ -26,11 +35,15 @@ def create_api_key(
     Generates a new API key for an organization and associates it with a user.
     Returns the API key details with the raw key (shown only once).
     """
+    logger.info(
+        f"[create_api_key] Starting API key creation | {{'organization_id': {organization_id}, 'user_id': {user_id}, 'project_id': {project_id}}}"
+    )
     # Generate raw key and its hash using the helper function
     raw_key, hashed_key = generate_api_key()
-    encrypted_key = encrypt_api_key(
-        raw_key
-    )  # Encrypt the raw key instead of hashed key
+    encrypted_key = encrypt_api_key(raw_key)  # Encrypt the raw key instead of hashed key
+    logger.info(
+        f"[create_api_key] API key encrypted | {{'user_id': {user_id}, 'project_id': {project_id}}}"
+    )
 
     # Create API key record with encrypted raw key
     api_key = APIKey(
@@ -43,11 +56,17 @@ def create_api_key(
     session.add(api_key)
     session.commit()
     session.refresh(api_key)
+    logger.info(
+        f"[create_api_key] API key created and stored | {{'api_key_id': {api_key.id}, 'user_id': {user_id}, 'project_id': {project_id}}}"
+    )
 
     # Set the raw key in the response (shown only once)
     api_key_dict = api_key.model_dump()
     api_key_dict["key"] = raw_key  # Return the raw key to the user
 
+    logger.info(
+        f"[create_api_key] API key creation completed | {{'api_key_id': {api_key.id}, 'user_id': {user_id}, 'project_id': {project_id}}}"
+    )
     return APIKeyPublic.model_validate(api_key_dict)
 
 
@@ -56,6 +75,9 @@ def get_api_key(session: Session, api_key_id: int) -> APIKeyPublic | None:
     Retrieves an API key by its ID if it exists and is not deleted.
     Returns the API key in its original format.
     """
+    logger.info(
+        f"[get_api_key] Retrieving API key | {{'api_key_id': {api_key_id}}}"
+    )
     api_key = session.exec(
         select(APIKey).where(APIKey.id == api_key_id, APIKey.is_deleted == False)
     ).first()
@@ -66,41 +88,67 @@ def get_api_key(session: Session, api_key_id: int) -> APIKeyPublic | None:
         # Decrypt the key
         decrypted_key = decrypt_api_key(api_key.key)
         api_key_dict["key"] = decrypted_key
-
+        logger.info(
+            f"[get_api_key] API key retrieved successfully | {{'api_key_id': {api_key_id}}}"
+        )
         return APIKeyPublic.model_validate(api_key_dict)
+    
+    logger.warning(
+        f"[get_api_key] API key not found | {{'api_key_id': {api_key_id}}}"
+    )
     return None
 
 
 def delete_api_key(session: Session, api_key_id: int) -> None:
     """
     Soft deletes (revokes) an API key by marking it as deleted.
     """
+    logger.info(
+        f"[delete_api_key] Starting API key deletion | {{'api_key_id': {api_key_id}}}"
+    )
     api_key = session.get(APIKey, api_key_id)
 
+    if not api_key:
+        logger.error(
+            f"[delete_api_key] API key not found | {{'api_key_id': {api_key_id}}}"
+        )
+        return
+
     api_key.is_deleted = True
     api_key.deleted_at = now()
     api_key.updated_at = now()
 
     session.add(api_key)
     session.commit()
+    logger.info(
+        f"[delete_api_key] API key soft deleted successfully | {{'api_key_id': {api_key_id}}}"
+    )
 
 
 def get_api_key_by_value(session: Session, api_key_value: str) -> APIKeyPublic | None:
     """
     Retrieve an API Key record by verifying the provided key against stored hashes.
     Returns the API key in its original format.
     """
+    logger.info(
+        f"[get_api_key_by_value] Retrieving API key by value | {{'action': 'lookup'}}"
+    )
     # Get all active API keys
     api_keys = session.exec(select(APIKey).where(APIKey.is_deleted == False)).all()
 
     for api_key in api_keys:
         decrypted_key = decrypt_api_key(api_key.key)
         if api_key_value == decrypted_key:
             api_key_dict = api_key.model_dump()
-
             api_key_dict["key"] = decrypted_key
-
+            logger.info(
+                f"[get_api_key_by_value] API key found | {{'api_key_id': {api_key.id}}}"
+            )
             return APIKeyPublic.model_validate(api_key_dict)
+    
+    logger.warning(
+        f"[get_api_key_by_value] API key not found | {{'action': 'not_found'}}"
+    )
     return None
 
 
@@ -110,6 +158,9 @@ def get_api_key_by_project_user(
     """
     Retrieves the single API key associated with a project.
     """
+    logger.info(
+        f"[get_api_key_by_project_user] Retrieving API key | {{'project_id': {project_id}, 'user_id': '{user_id}'}}"
+    )
     statement = select(APIKey).where(
         APIKey.user_id == user_id,
         APIKey.project_id == project_id,
@@ -120,15 +171,24 @@ def get_api_key_by_project_user(
     if api_key:
         api_key_dict = api_key.model_dump()
         api_key_dict["key"] = decrypt_api_key(api_key.key)
+        logger.info(
+            f"[get_api_key_by_project_user] API key retrieved successfully | {{'api_key_id': {api_key.id}, 'project_id': {project_id}, 'user_id': '{user_id}'}}"
+        )
         return APIKeyPublic.model_validate(api_key_dict)
 
+    logger.warning(
+        f"[get_api_key_by_project_user] API key not found | {{'project_id': {project_id}, 'user_id': '{user_id}'}}"
+    )
     return None
 
 
 def get_api_keys_by_project(session: Session, project_id: int) -> list[APIKeyPublic]:
     """
     Retrieves all API keys associated with a project.
     """
+    logger.info(
+        f"[get_api_keys_by_project] Retrieving API keys for project | {{'project_id': {project_id}}}"
+    )
     statement = select(APIKey).where(
         APIKey.project_id == project_id, APIKey.is_deleted == False
     )
@@ -139,5 +199,8 @@ def get_api_keys_by_project(session: Session, project_id: int) -> list[APIKeyPub
         key_dict = key.model_dump()
         key_dict["key"] = decrypt_api_key(key.key)
         result.append(APIKeyPublic.model_validate(key_dict))
-
-    return result
+    
+    logger.info(
+        f"[get_api_keys_by_project] API keys retrieved successfully | {{'project_id': {project_id}, 'key_count': {len(result)}}}"
+    )
+    return result

backend/app/crud/collection.py

@@ -1,3 +1,4 @@
+import logging
 import functools as ft
 from uuid import UUID
 from typing import Optional
@@ -10,29 +11,52 @@
 
 from .document_collection import DocumentCollectionCrud
 
+logger = logging.getLogger(__name__)
+
 
 class CollectionCrud:
     def __init__(self, session: Session, owner_id: int):
         self.session = session
         self.owner_id = owner_id
+        logger.info(
+            f"[CollectionCrud.init] Initialized CollectionCrud | {{'owner_id': {owner_id}}}"
+        )
 
     def _update(self, collection: Collection):
+        logger.info(
+            f"[CollectionCrud._update] Starting collection update | {{'collection_id': '{collection.id}', 'owner_id': {self.owner_id}}}"
+        )
         if not collection.owner_id:
+            logger.info(
+                f"[CollectionCrud._update] Assigning owner ID | {{'collection_id': '{collection.id}', 'owner_id': {self.owner_id}}}"
+            )
             collection.owner_id = self.owner_id
         elif collection.owner_id != self.owner_id:
+            logger.warning(
+                f"[CollectionCrud._update] Ownership mismatch detected | {{'collection_id': '{collection.id}', 'owner_id': {collection.owner_id}, 'attempted_owner_id': {self.owner_id}}}"
+            )
             err = "Invalid collection ownership: owner={} attempter={}".format(
                 self.owner_id,
                 collection.owner_id,
             )
+            logger.error(
+                f"[CollectionCrud._update] Permission error | {{'collection_id': '{collection.id}', 'error': '{err}'}}"
+            )
             raise PermissionError(err)
 
         self.session.add(collection)
         self.session.commit()
         self.session.refresh(collection)
+        logger.info(
+            f"[CollectionCrud._update] Collection updated successfully | {{'collection_id': '{collection.id}'}}"
+        )
 
         return collection
 
     def _exists(self, collection: Collection):
+        logger.info(
+            f"[CollectionCrud._exists] Checking if collection exists | {{'llm_service_id': '{collection.llm_service_id}', 'llm_service_name': '{collection.llm_service_name}'}}"
+        )
         present = (
             self.session.query(func.count(Collection.id))
             .filter(
@@ -41,6 +65,9 @@ def _exists(self, collection: Collection):
             )
             .scalar()
         )
+        logger.info(
+            f"[CollectionCrud._exists] Existence check completed | {{'llm_service_id': '{collection.llm_service_id}', 'exists': {bool(present)}}}"
+        )
 
         return bool(present)
 
@@ -66,37 +93,64 @@ def create(
         return collection
 
     def read_one(self, collection_id: UUID):
+        logger.info(
+            f"[CollectionCrud.read_one] Retrieving collection | {{'collection_id': '{collection_id}', 'owner_id': {self.owner_id}}}"
+        )
         statement = select(Collection).where(
             and_(
                 Collection.owner_id == self.owner_id,
                 Collection.id == collection_id,
             )
         )
 
-        return self.session.exec(statement).one()
+        collection = self.session.exec(statement).one()
+        logger.info(
+            f"[CollectionCrud.read_one] Collection retrieved successfully | {{'collection_id': '{collection_id}'}}"
+        )
+        return collection
 
     def read_all(self):
+        logger.info(
+            f"[CollectionCrud.read_all] Retrieving all collections | {{'owner_id': {self.owner_id}}}"
+        )
         statement = select(Collection).where(
             and_(
                 Collection.owner_id == self.owner_id,
                 Collection.deleted_at.is_(None),
             )
         )
 
-        return self.session.exec(statement).all()
+        collections = self.session.exec(statement).all()
+        logger.info(
+            f"[CollectionCrud.read_all] Collections retrieved successfully | {{'owner_id': {self.owner_id}, 'collection_count': {len(collections)}}}"
+        )
+        return collections
 
     @ft.singledispatchmethod
     def delete(self, model, remote):  # remote should be an OpenAICrud
+        logger.error(
+            f"[CollectionCrud.delete] Invalid model type | {{'model_type': '{type(model).__name__}'}}"
+        )
         raise TypeError(type(model))
 
     @delete.register
     def _(self, model: Collection, remote):
+        logger.info(
+            f"[CollectionCrud.delete] Starting collection deletion | {{'collection_id': '{model.id}', 'llm_service_id': '{model.llm_service_id}'}}"
+        )
         remote.delete(model.llm_service_id)
         model.deleted_at = now()
-        return self._update(model)
+        collection = self._update(model)
+        logger.info(
+            f"[CollectionCrud.delete] Collection deleted successfully | {{'collection_id': '{model.id}'}}"
+        )
+        return collection
 
     @delete.register
     def _(self, model: Document, remote):
+        logger.info(
+            f"[CollectionCrud.delete] Starting document deletion from collections | {{'document_id': '{model.id}'}}"
+        )
         statement = (
             select(Collection)
             .join(
@@ -108,7 +162,13 @@ def _(self, model: Document, remote):
         )
 
         for c in self.session.execute(statement):
+            logger.info(
+                f"[CollectionCrud.delete] Deleting collection associated with document | {{'document_id': '{model.id}', 'collection_id': '{c.Collection.id}'}}"
+            )
             self.delete(c.Collection, remote)
         self.session.refresh(model)
+        logger.info(
+            f"[CollectionCrud.delete] Document deletion from collections completed | {{'document_id': '{model.id}'}}"
+        )
 
-        return model
+        return model