Add logging #154

rating_api/routes/base.py

@@ -1,14 +1,15 @@
-from fastapi import FastAPI
+from fastapi import FastAPI, Request, Response
 from fastapi.middleware.cors import CORSMiddleware
 from fastapi_sqlalchemy import DBSessionMiddleware
 
 from rating_api import __version__
 from rating_api.routes.comment import comment
 from rating_api.routes.lecturer import lecturer
-from rating_api.settings import get_settings
+from rating_api.settings import Settings, get_settings
+from rating_api.utils.logging_utils import get_request_body, log_request
 
 
-settings = get_settings()
+settings: Settings = get_settings()
 app = FastAPI(
     title='Рейтинг преподавателей',
     description='Хранение и работа с рейтингом преподавателей и отзывами на них.',
@@ -19,7 +20,6 @@
     redoc_url=None,
 )
 
-
 app.add_middleware(
     DBSessionMiddleware,
     db_url=str(settings.DB_DSN),
@@ -36,3 +36,19 @@
 
 app.include_router(lecturer)
 app.include_router(comment)
+
+
+@app.middleware("http")
+async def add_process_time_header(request: Request, call_next):
+    """Основной middleware, который логирует запрос и восстанавливает тело."""
+    try:
+        request, json_body = await get_request_body(request)  # Получаем тело и восстанавливаем request
+        response: Response = await call_next(request)
+        status_code = response.status_code
+    except Exception:
+        status_code = 500
+        response = Response(content="Internal server error", status_code=500)
+
+    await log_request(request, status_code, json_body)  # Логируем запрос
+
+    return response

rating_api/routes/lecturer.py

@@ -135,7 +135,9 @@ async def get_lecturers(
                 if comment.review_status is ReviewStatus.APPROVED
             ]
             if "comments" in info and approved_comments:
-                lecturer_to_result.comments = sorted(approved_comments, key=lambda comment: comment.create_ts, reverse=True)
+                lecturer_to_result.comments = sorted(
+                    approved_comments, key=lambda comment: comment.create_ts, reverse=True
+                )
             if "mark" in info and approved_comments:
                 lecturer_to_result.mark_freebie = sum([comment.mark_freebie for comment in approved_comments]) / len(
                     approved_comments

rating_api/settings.py

@@ -5,6 +5,13 @@
 from pydantic_settings import BaseSettings
 
 
+LOGGING_MARKETING_URLS = {
+    "dev": f"http://localhost:{os.getenv('MARKETING_PORT', 8000)}/v1/action",
+    "test": "https://api.test.profcomff.com/marketing/v1/action",
+    "prod": "https://api.profcomff.com/marketing/v1/action",
+}
+
+
 class Settings(BaseSettings):
     """Application settings"""
 
@@ -18,6 +25,9 @@ class Settings(BaseSettings):
     CORS_ALLOW_CREDENTIALS: bool = True
     CORS_ALLOW_METHODS: list[str] = ['*']
     CORS_ALLOW_HEADERS: list[str] = ['*']
+    LOGGING_MARKETING_URL: str = LOGGING_MARKETING_URLS.get(
+        os.getenv("APP_VERSION", "dev"), LOGGING_MARKETING_URLS["test"]
+    )
 
     model_config = ConfigDict(case_sensitive=True, env_file=".env", extra="ignore")
 

rating_api/utils/logging_utils.py

@@ -0,0 +1,83 @@
+import asyncio
+import json
+import logging
+
+import httpx
+from auth_lib.fastapi import UnionAuth
+from fastapi import Request
+
+from rating_api.settings import Settings, get_settings
+
+
+settings: Settings = get_settings()
+
+log = logging.getLogger(__name__)
+
+RETRY_DELAYS = [2, 4, 8]  # Задержки перед повторными попытками (в секундах)
+
+
+async def send_log(log_data):
+    """Отправляем лог на внешний сервис асинхронно с обработкой ошибок и ретраями"""
+    async with httpx.AsyncClient() as client:
+        for attempt, sleep_time in enumerate(RETRY_DELAYS, start=1):
+            try:
+                response = await client.post(settings.LOGGING_MARKETING_URL, json=log_data)
+
+                if response.status_code not in {408, 409, 429, 500, 502, 503, 504}:
+                    log.info(f"Ответ записи логов от markting status_code: {response.status_code}")
+                    break  # Успешно или ошибки, которые не стоит повторять (например, неправильные данные)
+
+            except httpx.HTTPStatusError as e:
+                log.warning(f"HTTP ошибка ({e.response.status_code}): {e.response.text}")
+
+            except httpx.RequestError as e:
+                log.warning(f"Ошибка сети: {e}")
+
+            except Exception as e:
+                log.warning(f"Неизвестная ошибка: {e}")
+
+            await asyncio.sleep(sleep_time)  # Ожидание перед повторной попыткой
+
+        else:
+            log.warning("Не удалось отправить лог после нескольких попыток.")
+
+
+async def get_request_body(request: Request) -> tuple[Request, str]:
+    """Читает тело запроса и возвращает новый request и тело в виде JSON."""
+    body = await request.body()
+    json_body = json.loads(body) if body else {}  # В json(dict) from byte string
+
+    async def new_stream():
+        yield body
+
+    return Request(request.scope, receive=new_stream()), json_body
+
+
+async def get_user_id(request: Request):
+    """Получает user_id из UnionAuth"""
+    try:
+        user_id = UnionAuth()(request).get('id')
+    except Exception as e:
+        user_id = "Not auth"  # Или лучше -1? чтобы типизация :int была?
+        log.error(f"USER_AUTH: {e}")
+
+    return user_id
+
+
+async def log_request(request: Request, status_code: int, json_body: dict):
+    """Формирует лог и отправляет его в асинхронную задачу."""
+
+    additional_data = {
+        "response_status_code": status_code,
+        "auth_user_id": await get_user_id(request),
+        "query": request.url.path + "?" + request.url.query,
+        "request": json_body,
+    }
+    log_data = {
+        "user_id": -2,
+        "action": request.method,
+        "additional_data": json.dumps(additional_data),
+        "path_from": '',  # app.root_path
+        "path_to": request.url.path,
+    }
+    asyncio.create_task(send_log(log_data))