From de36eb9ce9698f54bc3e1948f23e89dff8a5d032 Mon Sep 17 00:00:00 2001 From: Cliff Hill Date: Fri, 22 Aug 2025 22:05:20 -0400 Subject: [PATCH] Added logging throughout sql.py, setting up error handling and reporting. Made logging configuration for app. Signed-off-by: Cliff Hill --- backend/src/backend/logging.py | 5 + backend/src/backend/sql.py | 322 ++++++++++++++++++++++++++------- compose.dev.yml | 1 + compose.yml | 1 + 4 files changed, 265 insertions(+), 64 deletions(-) diff --git a/backend/src/backend/logging.py b/backend/src/backend/logging.py index 951acb9c..b9bac60c 100644 --- a/backend/src/backend/logging.py +++ b/backend/src/backend/logging.py @@ -10,6 +10,8 @@ from fastapi import FastAPI from fastapi import Request from fastapi import Response +from backend import config + class RedactFilter(logging.Filter): """Filter to redact sensitive information in logs.""" @@ -39,6 +41,9 @@ def setup_logging(app: FastAPI) -> None: logger: logging.Logger = logging.getLogger() logger.setLevel(log_level) + if config("ENVIRONMENT", default="development") == "development": + logging.getLogger("sqlalchemy.engine").setLevel(logging.INFO) + # Clear any existing handlers to avoid duplicate logs logger.handlers.clear() diff --git a/backend/src/backend/sql.py b/backend/src/backend/sql.py index 9af3d061..00e76e1c 100644 --- a/backend/src/backend/sql.py +++ b/backend/src/backend/sql.py @@ -1,11 +1,6 @@ -"""SQL functions for the Numinar coding project backend. - -Note: - The session parameter is automatically injected by the `sessionize` decorator. - The type hint for session is ignored to avoid needless complications with - getting the type checkers to accept it. -""" +"""SQL Database access functions for the Numinar coding project backend.""" +import logging from datetime import datetime from typing import TypedDict from typing import Unpack @@ -23,35 +18,97 @@ from backend.models import Room from backend.models import User -async def get_users(session: AsyncSession) -> list[User]: +# Configure logging +logger = logging.getLogger(__name__) + +# Python 3.13 type aliases +type UserList = list[User] +type RoomList = list[Room] +type BookingList = list[Booking] + + +async def get_users(session: AsyncSession) -> UserList: """Retrieve all users from the database.""" - result = await session.execute(select(User)) - return cast(list[User], result.scalars().all()) + logger.debug("Entering get_users") + try: + stmt = select(User) + result = await session.scalars(stmt) + users = cast(UserList, result.all()) + logger.info(f"Successfully retrieved {len(users)} users") + return users + except Exception as e: + logger.error(f"Failed to retrieve users: {str(e)}") + raise + finally: + logger.debug("Exiting get_users") async def get_user_by_email(session: AsyncSession, email: str) -> User: """Retrieve a user by their email address.""" - result = await session.execute(select(User).where(User.email == email)) - return result.scalar_one() + logger.debug(f"Entering get_user_by_email with email: {email}") + try: + stmt = select(User).where(User.email == email) + user = await session.scalar(stmt) + logger.info(f"Successfully retrieved user with email: {email}") + return cast(User, user) + except NoResultFound: + logger.error(f"User with email {email} not found") + raise + except Exception as e: + logger.error(f"Failed to retrieve user with email {email}: {str(e)}") + raise + finally: + logger.debug("Exiting get_user_by_email") -async def get_rooms(session: AsyncSession) -> list[Room]: +async def get_rooms(session: AsyncSession) -> RoomList: """Retrieve all rooms from the database.""" - result = await session.execute(select(Room)) - return cast(list[Room], result.scalars().all()) + logger.debug("Entering get_rooms") + try: + stmt = select(Room) + result = await session.scalars(stmt) + rooms = cast(RoomList, result.all()) + logger.info(f"Successfully retrieved {len(rooms)} rooms") + return rooms + except Exception as e: + logger.error(f"Failed to retrieve rooms: {str(e)}") + raise + finally: + logger.debug("Exiting get_rooms") async def get_room(session: AsyncSession, room_id: int) -> Room: """Retrieve a room by its ID.""" - result = await session.execute(select(Room).where(Room.id == room_id)) - return result.scalar_one() + logger.debug(f"Entering get_room with room_id: {room_id}") + try: + stmt = select(Room).where(Room.id == room_id) + room = await session.scalar(stmt) + logger.info(f"Successfully retrieved room with id: {room_id}") + return cast(Room, room) + except NoResultFound: + logger.error(f"Room with id {room_id} not found") + raise + except Exception as e: + logger.error(f"Failed to retrieve room with id {room_id}: {str(e)}") + raise + finally: + logger.debug("Exiting get_room") async def new_room(session: AsyncSession, room: Room) -> Room: """Create a new room in the database.""" - session.add(room) - await session.commit() - return room + logger.debug("Entering new_room") + try: + session.add(room) + await session.commit() + logger.info(f"Successfully created new room with id: {room.id}") + return room + except Exception as e: + logger.error(f"Failed to create new room: {str(e)}") + await session.rollback() + raise + finally: + logger.debug("Exiting new_room") class RoomParams(TypedDict): @@ -65,38 +122,96 @@ class RoomParams(TypedDict): async def update_room( session: AsyncSession, room_id: int, **kwargs: Unpack[RoomParams] -) -> Room | None: +) -> Room: """Update an existing room.""" - stmt = update(Room).where(Room.id == room_id).values(**kwargs) - await session.execute(stmt) - await session.commit() - return await get_room(session, room_id) + logger.debug(f"Entering update_room with room_id: {room_id}, params: {kwargs}") + try: + stmt = update(Room).where(Room.id == room_id).values(**kwargs) + result = await session.execute(stmt) + if result.rowcount == 0: + logger.error(f"No room found with id {room_id} for update") + raise ValueError(f"No room found with id {room_id}") + await session.commit() + room = await get_room(session, room_id) + logger.info(f"Successfully updated room with id: {room_id}") + return room + except Exception as e: + logger.error(f"Failed to update room with id {room_id}: {str(e)}") + await session.rollback() + raise + finally: + logger.debug("Exiting update_room") async def delete_room(session: AsyncSession, room_id: int) -> None: """Delete a room from the database.""" - stmt = delete(Room).where(Room.id == room_id) - await session.execute(stmt) - await session.commit() + logger.debug(f"Entering delete_room with room_id: {room_id}") + try: + stmt = delete(Room).where(Room.id == room_id) + result = await session.execute(stmt) + if result.rowcount == 0: + logger.error(f"No room found with id {room_id} for deletion") + raise ValueError(f"No room found with id {room_id}") + await session.commit() + logger.info(f"Successfully deleted room with id: {room_id}") + except Exception as e: + logger.error(f"Failed to delete room with id {room_id}: {str(e)}") + await session.rollback() + raise + finally: + logger.debug("Exiting delete_room") -async def get_bookings_for_room(session: AsyncSession, room_id: int) -> list[Booking]: +async def get_bookings_for_room(session: AsyncSession, room_id: int) -> BookingList: """Retrieve all bookings for a specific room.""" - result = await session.execute(select(Booking).where(Booking.room_id == room_id)) - return cast(list[Booking], result.scalars().all()) + logger.debug(f"Entering get_bookings_for_room with room_id: {room_id}") + try: + stmt = select(Booking).where(Booking.room_id == room_id) + result = await session.scalars(stmt) + bookings = cast(BookingList, result.all()) + logger.info( + f"Successfully retrieved {len(bookings)} bookings for room_id: {room_id}" + ) + return bookings + except Exception as e: + logger.error(f"Failed to retrieve bookings for room_id {room_id}: {str(e)}") + raise + finally: + logger.debug("Exiting get_bookings_for_room") async def get_booking(session: AsyncSession, booking_id: int) -> Booking: """Retrieve a booking by its ID.""" - result = await session.execute(select(Booking).where(Booking.id == booking_id)) - return result.scalar_one() + logger.debug(f"Entering get_booking with booking_id: {booking_id}") + try: + stmt = select(Booking).where(Booking.id == booking_id) + booking = await session.scalar(stmt) + logger.info(f"Successfully retrieved booking with id: {booking_id}") + return cast(Booking, booking) + except NoResultFound: + logger.error(f"Booking with id {booking_id} not found") + raise + except Exception as e: + logger.error(f"Failed to retrieve booking with id {booking_id}: {str(e)}") + raise + finally: + logger.debug("Exiting get_booking") async def new_booking(session: AsyncSession, booking: Booking) -> Booking: """Create a new booking in the database.""" - session.add(booking) - await session.commit() - return booking + logger.debug("Entering new_booking") + try: + session.add(booking) + await session.commit() + logger.info(f"Successfully created new booking with id: {booking.id}") + return booking + except Exception as e: + logger.error(f"Failed to create new booking: {str(e)}") + await session.rollback() + raise + finally: + logger.debug("Exiting new_booking") class BookingParams(TypedDict): @@ -111,55 +226,134 @@ async def update_booking( session: AsyncSession, booking_id: int, **kwargs: Unpack[BookingParams], -) -> Booking | None: +) -> Booking: """Update an existing booking.""" - stmt = update(Booking).where(Booking.id == booking_id).values(**kwargs) - await session.execute(stmt) - await session.commit() - return await get_booking(session, booking_id) + logger.debug( + f"Entering update_booking with booking_id: {booking_id}, params: {kwargs}" + ) + try: + stmt = update(Booking).where(Booking.id == booking_id).values(**kwargs) + result = await session.execute(stmt) + if result.rowcount == 0: + logger.error(f"No booking found with id {booking_id} for update") + raise ValueError(f"No booking found with id {booking_id}") + await session.commit() + booking = await get_booking(session, booking_id) + logger.info(f"Successfully updated booking with id: {booking_id}") + return booking + except Exception as e: + logger.error(f"Failed to update booking with id {booking_id}: {str(e)}") + await session.rollback() + raise + finally: + logger.debug("Exiting update_booking") async def delete_booking(session: AsyncSession, booking_id: int) -> None: """Delete a booking from the database.""" - stmt = delete(Booking).where(Booking.id == booking_id) - await session.execute(stmt) - await session.commit() + logger.debug(f"Entering delete_booking with booking_id: {booking_id}") + try: + stmt = delete(Booking).where(Booking.id == booking_id) + result = await session.execute(stmt) + if result.rowcount == 0: + logger.error(f"No booking found with id {booking_id} for deletion") + raise ValueError(f"No booking found with id {booking_id}") + await session.commit() + logger.info(f"Successfully deleted booking with id: {booking_id}") + except Exception as e: + logger.error(f"Failed to delete booking with id {booking_id}: {str(e)}") + await session.rollback() + raise + finally: + logger.debug("Exiting delete_booking") -async def get_invitees_for_booking( - session: AsyncSession, booking_id: int -) -> list[User]: +async def get_invitees_for_booking(session: AsyncSession, booking_id: int) -> UserList: """Retrieve all invitees for a specific booking.""" - result = await session.execute( - select(Invitee.user).where(Invitee.booking_id == booking_id) - ) - return cast(list[User], result.scalars().all()) + logger.debug(f"Entering get_invitees_for_booking with booking_id: {booking_id}") + try: + stmt = select(Invitee.user).where(Invitee.booking_id == booking_id) + result = await session.scalars(stmt) + invitees = cast(UserList, result.all()) + logger.info( + f"Successfully retrieved {len(invitees)} invitees for booking_id: {booking_id}" + ) + return invitees + except Exception as e: + logger.error( + f"Failed to retrieve invitees for booking_id {booking_id}: {str(e)}" + ) + raise + finally: + logger.debug("Exiting get_invitees_for_booking") -async def add_invitee_to_booking(session: AsyncSession, booking_id: int, email: str): +async def add_invitee_to_booking( + session: AsyncSession, booking_id: int, email: str +) -> Invitee: """Add an invitee to a booking.""" + logger.debug( + f"Entering add_invitee_to_booking with booking_id: {booking_id}, email: {email}" + ) try: user = await get_user_by_email(session, email) + invitee = Invitee(booking_id=booking_id, user_id=user.id) + session.add(invitee) + await session.commit() + logger.info( + f"Successfully added invitee with email {email} to booking_id: {booking_id}" + ) + return invitee except NoResultFound as e: + logger.error( + f"User with email {email} does not exist for booking_id {booking_id}" + ) raise ValueError(f"User with email {email} does not exist.") from e - - invitee = Invitee(booking_id=booking_id, user_id=user.id) - session.add(invitee) - await session.commit() - return invitee + except Exception as e: + logger.error( + f"Failed to add invitee with email {email} to booking_id {booking_id}: {str(e)}" + ) + await session.rollback() + raise + finally: + logger.debug("Exiting add_invitee_to_booking") async def remove_invitee_from_booking( session: AsyncSession, booking_id: int, email: str -): +) -> None: """Remove an invitee from a booking.""" + logger.debug( + f"Entering remove_invitee_from_booking with booking_id: {booking_id}, email: {email}" + ) try: user = await get_user_by_email(session, email) + stmt = delete(Invitee).where( + Invitee.booking_id == booking_id, Invitee.user_id == user.id + ) + result = await session.execute(stmt) + if result.rowcount == 0: + logger.error( + f"No invitee with email {email} found for booking_id {booking_id}" + ) + raise ValueError( + f"No invitee with email {email} found for booking_id {booking_id}" + ) + await session.commit() + logger.info( + f"Successfully removed invitee with email {email} from booking_id: {booking_id}" + ) except NoResultFound as e: + logger.error( + f"User with email {email} does not exist for booking_id {booking_id}" + ) raise ValueError(f"User with email {email} does not exist.") from e - - stmt = delete(Invitee).where( - Invitee.booking_id == booking_id, Invitee.user_id == user.id - ) - await session.execute(stmt) - await session.commit() + except Exception as e: + logger.error( + f"Failed to remove invitee with email {email}" + f" from booking_id {booking_id}: {str(e)}" + ) + await session.rollback() + raise + finally: + logger.debug("Exiting remove_invitee_from_booking") diff --git a/compose.dev.yml b/compose.dev.yml index e42b4287..a63ddd08 100644 --- a/compose.dev.yml +++ b/compose.dev.yml @@ -14,6 +14,7 @@ services: - ./backend/migrations:/app/migrations environment: ENVIRONMENT: development + LOG_LEVEL: debug ports: - "8000:8000" command: diff --git a/compose.yml b/compose.yml index 69b69542..c5d45fd2 100644 --- a/compose.yml +++ b/compose.yml @@ -10,6 +10,7 @@ services: environment: ENVIRONMENT: production POSTGRES_HOST: postgres + LOG_LEVEL: warning depends_on: postgres: condition: service_healthy