Unified logging behaviour

- Logger doesn't start with log level DEBUG by default, instead reads a environment variable
- Secret handler raises exceptions instead of using the module os to exit
- Added extensive debug logging
- Fixed RabbitMQ exception catch being too broad in scope

src/main.py

@@ -6,10 +6,9 @@ from typing import Dict
 from pydantic import BaseModel
 from validator import verify_api_key
 from db import get_db, create_connection_pool, close_connection_pool, start_healthcheck_thread
-from logger_handler import setup_logger
+from logger_handler import setup_logger, LOG_LEVEL
 from rabbitmq_handler import RabbitMQProducer
 import uvicorn
-from uvicorn_logging_config import LOGGING_CONFIG
 from contextlib import asynccontextmanager
 from metrics_server import REQUEST_COUNTER
 import asyncio
@@ -54,26 +53,34 @@ api = FastAPI(
 
 @api.middleware("http")
 async def prometheus_middleware(request: Request, call_next):
+	logger.debug(f"Incoming request: {request.method} {request.url.path}")
 	status = 500
 	try:
 		response = await call_next(request)
 		status = response.status_code
+		logger.debug(f"Request processed with status: {status}")
 	except Exception:
+		logger.exception(f"Exception during request processing: {e}")
 		raise
 	finally:
 		REQUEST_COUNTER.labels(request.method, request.url.path, status).inc()
+		logger.debug(f"Prometheus counter incremented: {request.method} {request.url.path} {status}")
 	return response
 
 def verify_api_key_dependency_internal(db=Depends(get_db), api_key: str = Depends(api_key_header_internal)) -> str:
+	logger.debug(f"Verifying internal API key: {api_key}")
 	cursor = db.cursor()
 	cursor.execute("SELECT program_name, api_key FROM internal_api_keys WHERE status = 'active'")
 	for program_name, hashed_key in cursor.fetchall():
 		if verify_api_key(api_key=api_key, hashed=hashed_key):
+			logger.debug(f"API key verified for program: {program_name}")
 			return program_name
+	logger.warning("Internal API key verification failed")
 	raise HTTPException(status_code=403, detail="Unauthorized")
 
 @api.exception_handler(StarletteHTTPException)
 async def custom_http_exception_handler(request,exc):
+	logger.debug(f"Handling HTTP exception: {exc}")
 	if exc.status_code == 404:
 		return JSONResponse(
 			status_code=403,
@@ -93,6 +100,7 @@ async def receive_notifications(
 ):
 
 	logger.info(f"Received notifcation data from {program_name} for RMQ")
+	logger.debug(f"Notification data: {notification_data}")
 	await request.app.state.rmq_producer.publish(
 		notification_data.receipent_user_id,
 		notification_data.message
@@ -101,13 +109,15 @@ async def receive_notifications(
 	return {"status": "queued"}
 
 async def start_servers():
-	config_main = uvicorn.Config("main:api", host="0.0.0.0", port=8101, log_level="info")
-	config_metrics = uvicorn.Config("metrics_server:metrics_api", host="0.0.0.0", port=9000, log_level="info")
+	logger.debug("Starting FastAPI and metrics servers")
+	config_main = uvicorn.Config("main:api", host="0.0.0.0", port=8101, log_level=LOG_LEVEL.lower())
+	config_metrics = uvicorn.Config("metrics_server:metrics_api", host="0.0.0.0", port=9000, log_level=LOG_LEVEL.lower())
 
 	server_main = uvicorn.Server(config_main)
 	server_metrics = uvicorn.Server(config_metrics)
 
 	await asyncio.gather(server_main.serve(), server_metrics.serve())
+	logger.debug("Servers started")
 
 if __name__ == "__main__":
 	asyncio.run(start_servers())