Add more logging

CHANGES.md

@@ -0,0 +1,19 @@
+# Eurovision 25 Backend Changelog
+
+## 1.0rc2 (2025-05-10)
+
+### Changes
+- Updated application version to 1.0rc2
+- Added more comprehensive logging throughout the application
+
+
+## 1.0rc1 (Previous Release)
+
+### Features
+- Initial release candidate
+- Eurovision 25 Homereview API implementation
+- Authentication and authorization system
+- User management features
+- Song management
+- Review system
+- Results calculation

README.md

@@ -220,6 +220,10 @@ Automated tests are not implemented at this time. Manual testing via the API doc
 ## TODOs
 
 * [ ]   Replace password hashing with passlib
+* [ ]   Switch to PostgreSQL from DuckDB
+* [x]   Implement more comprehensive logging
+* [ ]   Implement user disabling functionality
+* [ ]   Implement user password change functionality
 
 ## Contributing
 

pyproject.toml

@@ -1,6 +1,6 @@
 [project]
 name = "Eurovision-25-backend"
-version = "1.0rc1"
+version = "1.0rc2"
 description = "Backend for Eurovision 25"
 readme = "README.md"
 requires-python = ">=3.12"

src/app.py

@@ -12,9 +12,18 @@ from lib.db import init_db
 app = FastAPI(
     title="Eurovision 25 Homereview API",
     description="Backend API for Eurovision 25 Homereview application",
-    version="1.0rc1",
+    version="1.0rc2",
 )
 
+
+@app.middleware("http")
+async def log_requests(request, call_next):
+    body = await request.body()
+    logger.debug(f"Request body: {body.decode('utf-8')}")
+    response = await call_next(request)
+    return response
+
+
 # Add CORS middleware
 app.add_middleware(
     CORSMiddleware,

src/lib/db.py

@@ -6,6 +6,7 @@ from dotenv import load_dotenv
 import os
 
 from lib.helpers import hash_password
+from lib.logger import logger
 
 load_dotenv()
 
@@ -61,6 +62,9 @@ def seed_db() -> None:
     # Seed Admin users
     admin_username = os.getenv("ADMIN_USERNAME")
     hashed_admin_password = hash_password(os.getenv("ADMIN_PASSWORD", "password"))
+    logger.debug(
+        f"Admin user: {admin_username}, hashed password: {hashed_admin_password}"
+    )
     with get_connection() as conn:
         conn.execute(
             'INSERT INTO "User" (username, hashed_password, team_id, is_active, is_admin) VALUES (?, ?, ?, ?, ?)',

src/lib/logger.py

@@ -1,16 +1,26 @@
 from loguru import logger
 from pathlib import Path
 import sys
+from dotenv import load_dotenv
+import os
 
-LOG_PATH = Path("./data/logs/logs.log").absolute()
-ERROR_PATH = Path("./data/logs/errors.log").absolute()
+load_dotenv()
+
+LOG_PATH = Path(os.getenv("LOG_PATH", "./data/logs/logs.log")).absolute()
+ERROR_PATH = Path(os.getenv("ERROR_PATH", "./data/logs/errors.log")).absolute()
 
 logger.remove()
-logger.add(LOG_PATH, rotation="10 MB", compression="gz", level="INFO")
-logger.add(sys.stdout, level="INFO")
+logger.add(
+    LOG_PATH, rotation="10 MB", compression="gz", level=os.getenv("LOG_LEVEL", "INFO")
+)
+logger.add(sys.stdout, level=os.getenv("LOG_LEVEL", "INFO"))
 
-logger.add(ERROR_PATH, rotation="10 MB", compression="gz", level="ERROR")
-logger.add(sys.stderr, level="ERROR")
-logger.add(sys.stdout, level="DEBUG")
+logger.add(
+    ERROR_PATH,
+    rotation="10 MB",
+    compression="gz",
+    level=os.getenv("LOG_LEVEL_ERROR", "ERROR"),
+)
+logger.add(sys.stderr, level=os.getenv("LOG_LEVEL_ERROR", "ERROR"))
 
 logger = logger

src/models/msg.py

@@ -0,0 +1,8 @@
+from pydantic import BaseModel, Field
+from datetime import datetime
+
+
+class Message(BaseModel):
+    type: str | None = None
+    message: str
+    timestamp: datetime = Field(default_factory=datetime.now)

src/routes/admin.py

@@ -1,9 +1,10 @@
-from fastapi import APIRouter, Body, HTTPException
+from fastapi import APIRouter, Body, HTTPException, Request
 
 from models.user import CreateUser
 from models.team import TeamBase, Team
 from lib.db import get_connection
 from lib.helpers import hash_password
+from lib.logger import logger
 
 router = APIRouter(prefix="/admin", tags=["Admin"])
 
@@ -19,36 +20,73 @@ router = APIRouter(prefix="/admin", tags=["Admin"])
 
 
 @router.post("/teams")
-async def create_team(team: TeamBase):
-    with get_connection() as conn:
-        conn.execute("INSERT INTO Team (name) VALUES (?)", (team.name,))
-    return {"message": "Team created successfully"}
+async def create_team(team: TeamBase, request: Request):
+    logger.info(
+        f"Admin action: Creating new team '{team.name}' from IP: {request.client.host}"
+    )
+    try:
+        with get_connection() as conn:
+            conn.execute("INSERT INTO Team (name) VALUES (?)", (team.name,))
+        logger.info(f"Team '{team.name}' created successfully")
+        return {"message": "Team created successfully"}
+    except Exception as e:
+        logger.error(f"Failed to create team '{team.name}': {str(e)}")
+        raise HTTPException(status_code=500, detail="Failed to create team")
 
 
 @router.get("/teams", response_model=list[Team])
-async def list_teams():
+async def list_teams(request: Request):
+    logger.debug(f"Admin action: Listing all teams from IP: {request.client.host}")
     with get_connection() as conn:
         teams = conn.execute("SELECT * FROM Team").fetchdf()
     return teams.to_dict(orient="records")
 
 
 @router.post("/users")
-async def create_user(user: CreateUser):
-    with get_connection() as conn:
-        conn.execute(
-            "INSERT INTO User (username, hashed_password, team_id, is_admin) VALUES (?, ?, ?, ?)",
-            (
-                user.username,
-                hash_password(user.password),
-                user.team_id,
-                user.is_admin,
-            ),
+async def create_user(user: CreateUser, request: Request):
+    logger.info(
+        f"Admin action: Creating new user '{user.username}' from IP: {request.client.host}"
+    )
+    try:
+        with get_connection() as conn:
+            # Check if username already exists
+            existing = conn.execute(
+                "SELECT COUNT(*) as count FROM User WHERE username = ?",
+                (user.username,),
+            ).fetchdf()
+            if existing["count"][0] > 0:
+                logger.warning(
+                    f"Failed to create user: Username '{user.username}' already exists"
+                )
+                raise HTTPException(status_code=400, detail="Username already exists")
+
+            conn.execute(
+                "INSERT INTO User (username, hashed_password, team_id, is_admin) VALUES (?, ?, ?, ?)",
+                (
+                    user.username,
+                    hash_password(user.password),
+                    user.team_id,
+                    user.is_admin,
+                ),
+            )
+        logger.info(
+            f"User '{user.username}' created successfully with team_id: {user.team_id}, admin status: {user.is_admin}"
         )
-    return {"message": "User created successfully"}
+        return {"message": "User created successfully"}
+    except HTTPException:
+        # Re-raise HTTP exceptions
+        raise
+    except Exception as e:
+        logger.error(f"Failed to create user '{user.username}': {str(e)}")
+        raise HTTPException(status_code=500, detail="Failed to create user")
 
 
-@router.post("/users/")
-async def disable_user(user_id: int = Body(..., embed=True)):
+@router.post("/users/disable")
+async def disable_user(user_id: int = Body(..., embed=True), request: Request = None):
+    logger.info(
+        f"Admin action: Attempting to disable user with ID: {user_id} from IP: {request.client.host}"
+    )
+    logger.warning(f"Disable user functionality not implemented for user_id: {user_id}")
     raise HTTPException(status_code=405, detail="Method not yet implemented")
 
 

src/routes/auth.py

@@ -1,24 +1,34 @@
-from fastapi import APIRouter, HTTPException
+from fastapi import APIRouter, HTTPException, Request
 
 from lib.db import get_connection
 from models.user import User, UserLogin
 from lib.helpers import verify_password
+from lib.logger import logger
 
 router = APIRouter(prefix="/auth", tags=["auth"])
 
 
 @router.post("/token", response_model=User)
-async def login(user_login: UserLogin):
+async def login(user_login: UserLogin, request: Request):
+    logger.debug(
+        f"Login attempt for user: {user_login.username} from IP: {request.client.host}"
+    )
     with get_connection() as conn:
         user_df = conn.execute(
             'SELECT * FROM "User" WHERE username = ?', (user_login.username,)
         ).fetchdf()
 
     if user_df.empty:
+        logger.warning(
+            f"Failed login: Username {user_login.username} not found - IP: {request.client.host}"
+        )
         raise HTTPException(status_code=401, detail="Invalid username or password")
 
     user_data = user_df.to_dict(orient="records")[0]
     if not verify_password(user_login.password, user_data["hashed_password"]):
+        logger.warning(
+            f"Failed login: Incorrect password for user {user_login.username} - IP: {request.client.host}"
+        )
         raise HTTPException(status_code=401, detail="Invalid username or password")
 
     # Update the login timestamp in the database
@@ -29,9 +39,14 @@ async def login(user_login: UserLogin):
         )
 
         # Fetch the updated user data with the new last_login timestamp
-        updated_user = conn.execute(
-            'SELECT * FROM "User" WHERE id = ?', 
-            (user_data["id"],)
-        ).fetchdf().to_dict(orient="records")[0]
+        updated_user = (
+            conn.execute('SELECT * FROM "User" WHERE id = ?', (user_data["id"],))
+            .fetchdf()
+            .to_dict(orient="records")[0]
+        )
+
+        logger.info(
+            f"Successful login: User {user_login.username} (ID: {user_data['id']}) logged in from {request.client.host}"
+        )
 
     return User(**updated_user)

src/routes/reviews.py

@@ -1,7 +1,9 @@
 from fastapi import APIRouter, HTTPException
 
-from models.review import ReviewOut, ReviewSearch, ReviewIn
+from models.review import ReviewOut, ReviewIn
+from models.msg import Message
 from lib.db import get_connection
+from lib.logger import logger
 
 router = APIRouter(prefix="/reviews", tags=["reviews"])
 
@@ -16,52 +18,114 @@ async def list_reviews():
 
 
 @router.get("/", response_model=ReviewOut)
-async def get_review(review_id: ReviewSearch):
+async def get_review(song_id: int, user_id: int):
     with get_connection() as conn:
         review = conn.execute(
             "SELECT * FROM Review WHERE song_id = ? AND user_id = ?",
-            (review_id.song_id, review_id.user_id),
+            (song_id, user_id),
         ).fetchdf()
     if review.empty:
         raise HTTPException(status_code=404, detail="Review not found")
     return review.to_dict(orient="records")[0]
 
 
-@router.post("/", response_model=ReviewOut)
+@router.post("/", response_model=Message)
 async def create_review(review: ReviewIn):
-    with get_connection() as conn:
-        review = conn.execute(
-            "INSERT INTO Review (user_id, song_id, score_song, score_show, score_costume, text_review) VALUES (?, ?, ?, ?, ?, ?)",
-            (
-                review.user_id,
-                review.song_id,
-                review.score_song,
-                review.score_show,
-                review.score_costume,
-                review.text_review,
-            ),
-        ).fetchdf()
-    if review.empty:
-        raise HTTPException(status_code=404, detail="Review not found")
-    return review.to_dict(orient="records")[0]
+    logger.debug(f"Received create review request with data: {review.dict()}")
+    try:
+        with get_connection() as conn:
+            # Log the SQL query and parameters
+            logger.debug(
+                f"Executing INSERT INTO Review (user_id, song_id, score_song, score_show, score_costume, text_review) "
+                f"VALUES ({review.user_id}, {review.song_id}, {review.score_song}, "
+                f"{review.score_show}, {review.score_costume}, '{review.text_review}')"
+            )
+
+            # Insert the review
+            conn.execute(
+                "INSERT INTO Review (user_id, song_id, score_song, score_show, score_costume, text_review) VALUES (?, ?, ?, ?, ?, ?)",
+                (
+                    review.user_id,
+                    review.song_id,
+                    review.score_song,
+                    review.score_show,
+                    review.score_costume,
+                    review.text_review,
+                ),
+            )
+
+            # Fetch the newly created review
+            logger.debug(
+                f"Checking if review was created for song_id={review.song_id}, user_id={review.user_id}"
+            )
+            result = conn.execute(
+                "SELECT * FROM Review WHERE song_id = ? AND user_id = ?",
+                (review.song_id, review.user_id),
+            ).fetchdf()
+            logger.debug(f"Database result for newly created review: {result}")
+
+        if result.empty:
+            logger.warning(
+                f"Review not found after insert attempt: song_id={review.song_id}, user_id={review.user_id}"
+            )
+            raise HTTPException(status_code=404, detail="Review not found")
+
+        logger.info(
+            f"Review created successfully for song_id={review.song_id}, user_id={review.user_id}"
+        )
+        return Message(type="success", message="Review created successfully")
+    except Exception as e:
+        logger.error(f"Error creating review: {str(e)}")
+        raise
 
 
-@router.put("/", response_model=ReviewOut)
+@router.put("/", response_model=Message)
 async def update_review(review: ReviewIn):
-    with get_connection() as conn:
-        review = conn.execute(
-            "UPDATE Review SET user_id = ?, song_id = ?, score_song = ?, score_show = ?, score_costume = ?, text_review = ? WHERE song_id = ? AND user_id = ?",
-            (
-                review.user_id,
-                review.song_id,
-                review.score_song,
-                review.score_show,
-                review.score_costume,
-                review.text_review,
-                review.song_id,
-                review.user_id,
-            ),
-        ).fetchdf()
-    if review.empty:
-        raise HTTPException(status_code=404, detail="Review not found")
-    return review.to_dict(orient="records")[0]
+    print("update_review")
+    logger.debug(f"Received update review request with data: {review.dict()}")
+    try:
+        with get_connection() as conn:
+            # Log the SQL query and parameters
+            logger.debug(
+                f"Executing UPDATE Review SET score_song = {review.score_song}, "
+                f"score_show = {review.score_show}, score_costume = {review.score_costume}, "
+                f"text_review = '{review.text_review}' WHERE song_id = {review.song_id} "
+                f"AND user_id = {review.user_id}"
+            )
+
+            # Update the review
+            conn.execute(
+                "UPDATE Review SET score_song = ?, score_show = ?, score_costume = ?, text_review = ? WHERE song_id = ? AND user_id = ?",
+                (
+                    review.score_song,
+                    review.score_show,
+                    review.score_costume,
+                    review.text_review,
+                    review.song_id,
+                    review.user_id,
+                ),
+            )
+
+            # Fetch the updated review
+            logger.debug(
+                f"Checking if review was updated for song_id={review.song_id}, user_id={review.user_id}"
+            )
+            result = conn.execute(
+                "SELECT * FROM Review WHERE song_id = ? AND user_id = ?",
+                (review.song_id, review.user_id),
+            ).fetchdf()
+            logger.debug(f"Database result: {result}")
+
+        if result.empty:
+            logger.warning(
+                f"Review not found after update attempt: song_id={review.song_id}, user_id={review.user_id}"
+            )
+            raise HTTPException(status_code=404, detail="Review not found")
+
+        logger.info(
+            f"Review updated successfully for song_id={review.song_id}, user_id={review.user_id}"
+        )
+        return Message(type="success", message="Review updated successfully")
+    except Exception as e:
+        logger.error(f"Error updating review: {str(e)}")
+        raise

src/routes/users.py

@@ -1,14 +1,15 @@
-from fastapi import APIRouter
-from fastapi import HTTPException
+from fastapi import APIRouter, HTTPException, Request
 
 from models.user import User, UserChangePassword
 from lib.db import get_connection
+from lib.logger import logger
 
 router = APIRouter(prefix="/users", tags=["users"])
 
 
 @router.get("/", response_model=list[User])
-async def list_users():
+async def list_users(request: Request):
+    logger.info(f"User list requested from {request.client.host}")
     with get_connection() as conn:
         users = conn.execute('SELECT * FROM "User"').fetchdf()
 
@@ -18,19 +19,29 @@ async def list_users():
 
 
 @router.get("/{user_id}", response_model=User)
-async def get_user(user_id: int):
+async def get_user(user_id: int, request: Request):
+    logger.debug(
+        f"User details requested for user_id: {user_id} from {request.client.host}"
+    )
     with get_connection() as conn:
         user_df = conn.execute(
             'SELECT * FROM "User" WHERE id = ?', (user_id,)
         ).fetchdf()
 
     if user_df.empty:
+        logger.warning(f"Failed user lookup: user_id {user_id} not found")
         raise HTTPException(status_code=404, detail="User not found")
 
     user_data = user_df.to_dict(orient="records")[0]
+    logger.debug(f"User details retrieved: {user_data}")
     return User(**user_data)
 
 
 @router.patch("/{user_id}")
-async def change_password(user: UserChangePassword):
+async def change_password(user_id: int, user: UserChangePassword, request: Request):
+    logger.info(
+        f"Password change attempt for user_id: {user_id} from {request.client.host}"
+    )
+    # Implementation will go here when completed
+    logger.warning(f"Password change not implemented for user_id: {user_id}")
     raise HTTPException(status_code=401, detail="Not implemented")

uv.lock

@@ -131,7 +131,7 @@ wheels = [
 
 [[package]]
 name = "eurovision-25-backend"
-version = "0.1.0"
+version = "1.0rc2"
 source = { virtual = "." }
 dependencies = [
     { name = "aiofiles" },