diff --git a/src/api/routes.py b/src/api/routes.py index 18ffe3c..028955c 100644 --- a/src/api/routes.py +++ b/src/api/routes.py @@ -1,13 +1,15 @@ """API routes - OpenAI compatible endpoints""" -from fastapi import APIRouter, Depends, HTTPException +from fastapi import APIRouter, Depends, HTTPException, Request from fastapi.responses import StreamingResponse, JSONResponse from datetime import datetime from typing import List import json import re +import time from ..core.auth import verify_api_key_header from ..core.models import ChatCompletionRequest from ..services.generation_handler import GenerationHandler, MODEL_CONFIG +from ..core.logger import debug_logger router = APIRouter() @@ -71,10 +73,22 @@ async def list_models(api_key: str = Depends(verify_api_key_header)): @router.post("/v1/chat/completions") async def create_chat_completion( request: ChatCompletionRequest, - api_key: str = Depends(verify_api_key_header) + api_key: str = Depends(verify_api_key_header), + http_request: Request = None ): """Create chat completion (unified endpoint for image and video generation)""" + start_time = time.time() + try: + # Log client request + debug_logger.log_request( + method="POST", + url="/v1/chat/completions", + headers=dict(http_request.headers) if http_request else {}, + body=request.dict(), + source="Client" + ) + # Extract prompt from messages if not request.messages: raise HTTPException(status_code=400, detail="Messages cannot be empty") @@ -153,18 +167,36 @@ async def create_chat_completion( result = chunk if result: - return JSONResponse(content=json.loads(result)) + duration_ms = (time.time() - start_time) * 1000 + response_data = json.loads(result) + debug_logger.log_response( + status_code=200, + headers={"Content-Type": "application/json"}, + body=response_data, + duration_ms=duration_ms, + source="Client" + ) + return JSONResponse(content=response_data) else: + duration_ms = (time.time() - start_time) * 1000 + error_response = { + "error": { + "message": "Availability check failed", + "type": "server_error", + "param": None, + "code": None + } + } + debug_logger.log_response( + status_code=500, + headers={"Content-Type": "application/json"}, + body=error_response, + duration_ms=duration_ms, + source="Client" + ) return JSONResponse( status_code=500, - content={ - "error": { - "message": "Availability check failed", - "type": "server_error", - "param": None, - "code": None - } - } + content=error_response ) # Handle streaming @@ -229,31 +261,64 @@ async def create_chat_completion( result = chunk if result: - return JSONResponse(content=json.loads(result)) + duration_ms = (time.time() - start_time) * 1000 + response_data = json.loads(result) + debug_logger.log_response( + status_code=200, + headers={"Content-Type": "application/json"}, + body=response_data, + duration_ms=duration_ms, + source="Client" + ) + return JSONResponse(content=response_data) else: # Return OpenAI-compatible error format + duration_ms = (time.time() - start_time) * 1000 + error_response = { + "error": { + "message": "Availability check failed", + "type": "server_error", + "param": None, + "code": None + } + } + debug_logger.log_response( + status_code=500, + headers={"Content-Type": "application/json"}, + body=error_response, + duration_ms=duration_ms, + source="Client" + ) return JSONResponse( status_code=500, - content={ - "error": { - "message": "Availability check failed", - "type": "server_error", - "param": None, - "code": None - } - } + content=error_response ) except Exception as e: # Return OpenAI-compatible error format + duration_ms = (time.time() - start_time) * 1000 + error_response = { + "error": { + "message": str(e), + "type": "server_error", + "param": None, + "code": None + } + } + debug_logger.log_error( + error_message=str(e), + status_code=500, + response_text=str(e), + source="Client" + ) + debug_logger.log_response( + status_code=500, + headers={"Content-Type": "application/json"}, + body=error_response, + duration_ms=duration_ms, + source="Client" + ) return JSONResponse( status_code=500, - content={ - "error": { - "message": str(e), - "type": "server_error", - "param": None, - "code": None - } - } + content=error_response ) diff --git a/src/core/logger.py b/src/core/logger.py index 8e58324..8fdc663 100644 --- a/src/core/logger.py +++ b/src/core/logger.py @@ -68,9 +68,20 @@ class DebugLogger: headers: Dict[str, str], body: Optional[Any] = None, files: Optional[Dict] = None, - proxy: Optional[str] = None + proxy: Optional[str] = None, + source: str = "Server" ): - """Log API request details to log.txt""" + """Log API request details to log.txt + + Args: + method: HTTP method + url: Request URL + headers: Request headers + body: Request body + files: Files to upload + proxy: Proxy URL + source: Request source - "Client" for user->sora2api, "Server" for sora2api->Sora + """ # Check if debug mode is enabled if not config.debug_enabled: @@ -78,7 +89,7 @@ class DebugLogger: try: self._write_separator() - self.logger.info(f"🔵 [REQUEST] {self._format_timestamp()}") + self.logger.info(f"🔵 [REQUEST][{source}] {self._format_timestamp()}") self._write_separator("-") # Basic info @@ -136,9 +147,18 @@ class DebugLogger: status_code: int, headers: Dict[str, str], body: Any, - duration_ms: Optional[float] = None + duration_ms: Optional[float] = None, + source: str = "Server" ): - """Log API response details to log.txt""" + """Log API response details to log.txt + + Args: + status_code: HTTP status code + headers: Response headers + body: Response body + duration_ms: Request duration in milliseconds + source: Request source - "Client" for user->sora2api, "Server" for sora2api->Sora + """ # Check if debug mode is enabled if not config.debug_enabled: @@ -146,7 +166,7 @@ class DebugLogger: try: self._write_separator() - self.logger.info(f"🟢 [RESPONSE] {self._format_timestamp()}") + self.logger.info(f"🟢 [RESPONSE][{source}] {self._format_timestamp()}") self._write_separator("-") # Status @@ -192,9 +212,17 @@ class DebugLogger: self, error_message: str, status_code: Optional[int] = None, - response_text: Optional[str] = None + response_text: Optional[str] = None, + source: str = "Server" ): - """Log API error details to log.txt""" + """Log API error details to log.txt + + Args: + error_message: Error message + status_code: HTTP status code + response_text: Response text + source: Request source - "Client" for user->sora2api, "Server" for sora2api->Sora + """ # Check if debug mode is enabled if not config.debug_enabled: @@ -202,7 +230,7 @@ class DebugLogger: try: self._write_separator() - self.logger.info(f"🔴 [ERROR] {self._format_timestamp()}") + self.logger.info(f"🔴 [ERROR][{source}] {self._format_timestamp()}") self._write_separator("-") if status_code: diff --git a/src/services/sora_client.py b/src/services/sora_client.py index 58a2068..61c693f 100644 --- a/src/services/sora_client.py +++ b/src/services/sora_client.py @@ -226,7 +226,8 @@ class SoraClient: debug_logger.log_error( error_message=f"nf/create request failed: {str(e)}", status_code=0, - response_text=str(e) + response_text=str(e), + source="Server" ) raise @@ -259,7 +260,8 @@ class SoraClient: debug_logger.log_error( error_message=f"Sentinel request failed: {str(e)}", status_code=0, - response_text=str(e) + response_text=str(e), + source="Server" ) raise @@ -386,7 +388,8 @@ class SoraClient: headers=headers, body=json_data, files=multipart, - proxy=proxy_url + proxy=proxy_url, + source="Server" ) # Record start time @@ -414,7 +417,8 @@ class SoraClient: status_code=response.status_code, headers=dict(response.headers), body=response_json if response_json else response.text, - duration_ms=duration_ms + duration_ms=duration_ms, + source="Server" ) # Check status @@ -436,7 +440,8 @@ class SoraClient: debug_logger.log_error( error_message=f"Unsupported country: {error_msg}", status_code=response.status_code, - response_text=error_msg + response_text=error_msg, + source="Server" ) # Raise exception with structured error data raise Exception(error_msg) @@ -446,7 +451,8 @@ class SoraClient: debug_logger.log_error( error_message=error_msg, status_code=response.status_code, - response_text=response.text + response_text=response.text, + source="Server" ) raise Exception(error_msg) @@ -654,7 +660,8 @@ class SoraClient: status_code=response.status_code, headers=dict(response.headers), body=response.text if response.text else "No content", - duration_ms=duration_ms + duration_ms=duration_ms, + source="Server" ) # Check status (DELETE typically returns 204 No Content or 200 OK) @@ -663,7 +670,8 @@ class SoraClient: debug_logger.log_error( error_message=error_msg, status_code=response.status_code, - response_text=response.text + response_text=response.text, + source="Server" ) raise Exception(error_msg) @@ -719,7 +727,8 @@ class SoraClient: status_code=response.status_code, headers=dict(response.headers), body=response.text if response.text else "No content", - duration_ms=duration_ms + duration_ms=duration_ms, + source="Server" ) # Check status @@ -728,7 +737,8 @@ class SoraClient: debug_logger.log_error( error_message=error_msg, status_code=response.status_code, - response_text=response.text + response_text=response.text, + source="Server" ) raise Exception(error_msg) @@ -741,7 +751,8 @@ class SoraClient: debug_logger.log_error( error_message=error_msg, status_code=401, - response_text=str(result) + response_text=str(result), + source="Server" ) raise Exception(error_msg) @@ -757,7 +768,8 @@ class SoraClient: debug_logger.log_error( error_message=f"Custom parse request failed: {str(e)}", status_code=500, - response_text=str(e) + response_text=str(e), + source="Server" ) raise