Spaces:
Running
Migrate logging from stdlib to Loguru for structured logging
Browse filesThis migration replaces Python's standard logging module with Loguru,
providing structured logging with automatic request ID propagation,
environment-aware formatting, and improved developer experience.
## Changes
### Core Implementation
- app/core/logging.py: Complete rewrite (224 lines)
- Environment-aware formatting (JSON for prod, colored text for dev)
- Context variables for automatic request ID propagation
- Custom JSON serializer with structured fields
- Backward-compatible get_logger() and RequestLogger APIs
- app/core/middleware.py:
- Integrated context var (request_id_var) for request ID injection
- Automatic propagation eliminates manual parameter passing
- app/core/config.py:
- Added LOG_FORMAT setting (json/text/auto) with validator
- Auto-detection based on HF_SPACE_ROOT_PATH environment
- requirements.txt:
- Added loguru>=0.7.0 dependency
### Testing (44 tests, 100% passing)
- tests/test_loguru_context.py: Context variable propagation (7 tests)
- tests/test_loguru_imports.py: Import verification (10 tests)
- tests/test_loguru_integration.py: FastAPI integration (5 tests)
- tests/test_loguru_performance.py: Performance & lazy eval (8 tests)
- tests/test_loguru_setup.py: Format switching (4 tests)
- tests/test_logging.py: Backward compatibility (5 tests)
- tests/test_middleware.py: Request ID handling (5 tests)
### Documentation
- CLAUDE.md: Updated logging section with Loguru details
## Features
**Dual-Mode Logging:**
- Development: Colored, human-readable console output
- Production: Structured JSON logs for aggregation tools
**Automatic Request ID Tracking:**
- No manual passing through function calls
- Context variables handle propagation automatically
- Preserved in response headers
**Performance:**
- Lazy evaluation (logger.opt(lazy=True))
- Efficient string formatting
- No overhead when logs are filtered
**Backward Compatibility:**
- Existing code works without changes
- get_logger(__name__) pattern maintained
- RequestLogger class still functional
## Manual Testing
β
Server starts successfully with colored logs
β
Health endpoint responds with request ID tracking
β
Request/response cycle logging verified
β
Auto-generated and custom request IDs work correctly
π€ Generated with [Claude Code](https://claude.com/claude-code)
Co-Authored-By: Claude <[email protected]>
- CLAUDE.md +16 -4
- app/core/config.py +13 -0
- app/core/logging.py +195 -34
- app/core/middleware.py +4 -1
- requirements.txt +3 -0
- tests/test_logging.py +78 -38
- tests/test_loguru_context.py +175 -0
- tests/test_loguru_imports.py +133 -0
- tests/test_loguru_integration.py +83 -0
- tests/test_loguru_performance.py +173 -0
- tests/test_loguru_setup.py +71 -0
- tests/test_middleware.py +69 -28
|
@@ -161,16 +161,28 @@ Settings are managed via `app/core/config.py` using Pydantic BaseSettings. Key e
|
|
| 161 |
- `SCRAPING_RATE_LIMIT_PER_MINUTE` - Rate limit per IP (default: `10`)
|
| 162 |
|
| 163 |
**Server Configuration**:
|
| 164 |
-
- `SERVER_HOST`, `SERVER_PORT`, `LOG_LEVEL`
|
| 165 |
|
| 166 |
### Core Infrastructure
|
| 167 |
|
| 168 |
-
**Logging** (`app/core/logging.py`)
|
| 169 |
-
- Structured
|
| 170 |
-
-
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
| 171 |
|
| 172 |
**Middleware** (`app/core/middleware.py`)
|
| 173 |
- Request context middleware for tracking
|
|
|
|
|
|
|
| 174 |
- CORS middleware for cross-origin requests
|
| 175 |
|
| 176 |
**Error Handling** (`app/core/errors.py`)
|
|
|
|
| 161 |
- `SCRAPING_RATE_LIMIT_PER_MINUTE` - Rate limit per IP (default: `10`)
|
| 162 |
|
| 163 |
**Server Configuration**:
|
| 164 |
+
- `SERVER_HOST`, `SERVER_PORT`, `LOG_LEVEL`, `LOG_FORMAT`
|
| 165 |
|
| 166 |
### Core Infrastructure
|
| 167 |
|
| 168 |
+
**Logging** (`app/core/logging.py`) - **Powered by Loguru**
|
| 169 |
+
- **Structured Logging**: Automatic JSON serialization for production, colored text for development
|
| 170 |
+
- **Environment-Aware**: Auto-detects HuggingFace Spaces (JSON logs) vs local development (colored logs)
|
| 171 |
+
- **Request ID Context**: Automatic propagation via `contextvars` (no manual passing required)
|
| 172 |
+
- **Backward Compatible**: `get_logger()` and `RequestLogger` class maintain existing API
|
| 173 |
+
- **Configuration**:
|
| 174 |
+
- `LOG_LEVEL`: DEBUG, INFO, WARNING, ERROR, CRITICAL (default: INFO)
|
| 175 |
+
- `LOG_FORMAT`: `json`, `text`, or `auto` (default: auto-detect based on environment)
|
| 176 |
+
- **Features**:
|
| 177 |
+
- Lazy evaluation for performance (`logger.opt(lazy=True)`)
|
| 178 |
+
- Exception tracing with full stack traces
|
| 179 |
+
- Automatic request ID binding without manual propagation
|
| 180 |
+
- Structured fields (request_id, status_code, duration_ms, etc.)
|
| 181 |
|
| 182 |
**Middleware** (`app/core/middleware.py`)
|
| 183 |
- Request context middleware for tracking
|
| 184 |
+
- Automatic request ID generation/extraction from headers
|
| 185 |
+
- Context variable injection for automatic logging propagation
|
| 186 |
- CORS middleware for cross-origin requests
|
| 187 |
|
| 188 |
**Error Handling** (`app/core/errors.py`)
|
|
@@ -18,6 +18,11 @@ class Settings(BaseSettings):
|
|
| 18 |
server_host: str = Field(default="127.0.0.1", env="SERVER_HOST")
|
| 19 |
server_port: int = Field(default=8000, env="SERVER_PORT", ge=1, le=65535)
|
| 20 |
log_level: str = Field(default="INFO", env="LOG_LEVEL")
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
| 21 |
|
| 22 |
# Optional: API Security
|
| 23 |
api_key_enabled: bool = Field(default=False, env="API_KEY_ENABLED")
|
|
@@ -143,6 +148,14 @@ class Settings(BaseSettings):
|
|
| 143 |
return "INFO" # Default to INFO for invalid levels
|
| 144 |
return v.upper()
|
| 145 |
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
| 146 |
class Config:
|
| 147 |
env_file = ".env"
|
| 148 |
case_sensitive = False
|
|
|
|
| 18 |
server_host: str = Field(default="127.0.0.1", env="SERVER_HOST")
|
| 19 |
server_port: int = Field(default=8000, env="SERVER_PORT", ge=1, le=65535)
|
| 20 |
log_level: str = Field(default="INFO", env="LOG_LEVEL")
|
| 21 |
+
log_format: str = Field(
|
| 22 |
+
default="auto",
|
| 23 |
+
env="LOG_FORMAT",
|
| 24 |
+
description="Log format: 'json' for structured logs, 'text' for colored output, 'auto' for environment-based selection",
|
| 25 |
+
)
|
| 26 |
|
| 27 |
# Optional: API Security
|
| 28 |
api_key_enabled: bool = Field(default=False, env="API_KEY_ENABLED")
|
|
|
|
| 148 |
return "INFO" # Default to INFO for invalid levels
|
| 149 |
return v.upper()
|
| 150 |
|
| 151 |
+
@validator("log_format")
|
| 152 |
+
def validate_log_format(cls, v):
|
| 153 |
+
"""Validate log format is one of the supported formats."""
|
| 154 |
+
valid_formats = ["auto", "json", "text"]
|
| 155 |
+
if v.lower() not in valid_formats:
|
| 156 |
+
return "auto" # Default to auto for invalid formats
|
| 157 |
+
return v.lower()
|
| 158 |
+
|
| 159 |
class Config:
|
| 160 |
env_file = ".env"
|
| 161 |
case_sensitive = False
|
|
@@ -1,62 +1,223 @@
|
|
| 1 |
"""
|
| 2 |
-
Logging configuration for the text summarizer backend.
|
|
|
|
|
|
|
|
|
|
|
|
|
| 3 |
"""
|
| 4 |
|
| 5 |
-
import
|
| 6 |
import sys
|
|
|
|
| 7 |
from typing import Any
|
| 8 |
|
|
|
|
|
|
|
| 9 |
from app.core.config import settings
|
| 10 |
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
| 11 |
|
| 12 |
def setup_logging() -> None:
|
| 13 |
-
"""
|
| 14 |
-
logging.
|
| 15 |
-
|
| 16 |
-
|
| 17 |
-
|
| 18 |
-
|
| 19 |
-
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
| 20 |
)
|
| 21 |
|
| 22 |
|
| 23 |
-
def get_logger(name: str) ->
|
| 24 |
-
"""
|
| 25 |
-
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
| 26 |
|
| 27 |
|
| 28 |
class RequestLogger:
|
| 29 |
-
"""
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
| 30 |
|
| 31 |
-
|
|
|
|
|
|
|
|
|
|
| 32 |
self.logger = logger
|
| 33 |
|
| 34 |
def log_request(
|
| 35 |
self, method: str, path: str, request_id: str, **kwargs: Any
|
| 36 |
) -> None:
|
| 37 |
-
"""
|
| 38 |
-
|
| 39 |
-
|
| 40 |
-
|
| 41 |
-
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
| 42 |
|
| 43 |
def log_response(
|
| 44 |
self, request_id: str, status_code: int, duration_ms: float, **kwargs: Any
|
| 45 |
) -> None:
|
| 46 |
-
"""
|
| 47 |
-
|
| 48 |
-
|
| 49 |
-
|
| 50 |
-
|
| 51 |
-
|
| 52 |
-
|
| 53 |
-
|
| 54 |
-
|
| 55 |
-
)
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
| 56 |
|
| 57 |
def log_error(self, request_id: str, error: str, **kwargs: Any) -> None:
|
| 58 |
-
"""
|
| 59 |
-
|
| 60 |
-
|
| 61 |
-
|
| 62 |
-
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
| 1 |
"""
|
| 2 |
+
Logging configuration for the text summarizer backend using Loguru.
|
| 3 |
+
|
| 4 |
+
This module provides structured logging with automatic request ID tracking,
|
| 5 |
+
environment-aware formatting (JSON for production, colored text for development),
|
| 6 |
+
and backward-compatible API with the previous stdlib logging implementation.
|
| 7 |
"""
|
| 8 |
|
| 9 |
+
import os
|
| 10 |
import sys
|
| 11 |
+
from contextvars import ContextVar
|
| 12 |
from typing import Any
|
| 13 |
|
| 14 |
+
from loguru import logger
|
| 15 |
+
|
| 16 |
from app.core.config import settings
|
| 17 |
|
| 18 |
+
# Context variable for request ID (automatic propagation across async contexts)
|
| 19 |
+
request_id_var: ContextVar[str | None] = ContextVar("request_id", default=None)
|
| 20 |
+
|
| 21 |
+
|
| 22 |
+
def _serialize_record(record: dict) -> str:
|
| 23 |
+
"""
|
| 24 |
+
Custom serializer for JSON format that includes extra fields.
|
| 25 |
+
|
| 26 |
+
Args:
|
| 27 |
+
record: Loguru record dictionary
|
| 28 |
+
|
| 29 |
+
Returns:
|
| 30 |
+
JSON formatted log string
|
| 31 |
+
"""
|
| 32 |
+
import json
|
| 33 |
+
|
| 34 |
+
# Build structured log entry
|
| 35 |
+
log_entry = {
|
| 36 |
+
"timestamp": record["time"].isoformat(),
|
| 37 |
+
"level": record["level"].name,
|
| 38 |
+
"logger": record["name"],
|
| 39 |
+
"message": record["message"],
|
| 40 |
+
"function": record["function"],
|
| 41 |
+
"line": record["line"],
|
| 42 |
+
}
|
| 43 |
+
|
| 44 |
+
# Add request ID from context if available
|
| 45 |
+
request_id = request_id_var.get()
|
| 46 |
+
if request_id:
|
| 47 |
+
log_entry["request_id"] = request_id
|
| 48 |
+
|
| 49 |
+
# Add any extra fields bound to the logger
|
| 50 |
+
if record["extra"]:
|
| 51 |
+
log_entry.update(record["extra"])
|
| 52 |
+
|
| 53 |
+
# Add exception info if present
|
| 54 |
+
if record["exception"]:
|
| 55 |
+
log_entry["exception"] = {
|
| 56 |
+
"type": record["exception"].type.__name__ if record["exception"].type else None,
|
| 57 |
+
"value": str(record["exception"].value),
|
| 58 |
+
}
|
| 59 |
+
|
| 60 |
+
return json.dumps(log_entry)
|
| 61 |
+
|
| 62 |
+
|
| 63 |
+
def _determine_log_format() -> str:
|
| 64 |
+
"""
|
| 65 |
+
Determine log format based on environment.
|
| 66 |
+
|
| 67 |
+
Returns:
|
| 68 |
+
"json" for production (HF Spaces), "text" for development
|
| 69 |
+
"""
|
| 70 |
+
# Check if LOG_FORMAT is explicitly set
|
| 71 |
+
log_format = getattr(settings, "log_format", "auto")
|
| 72 |
+
|
| 73 |
+
if log_format == "auto":
|
| 74 |
+
# Auto-detect: JSON if running on HuggingFace Spaces, text otherwise
|
| 75 |
+
is_hf_spaces = os.getenv("HF_SPACE_ROOT_PATH") is not None
|
| 76 |
+
return "json" if is_hf_spaces else "text"
|
| 77 |
+
|
| 78 |
+
return log_format
|
| 79 |
+
|
| 80 |
|
| 81 |
def setup_logging() -> None:
|
| 82 |
+
"""
|
| 83 |
+
Set up Loguru logging configuration.
|
| 84 |
+
|
| 85 |
+
Configures logging with environment-aware formatting:
|
| 86 |
+
- Production (HF Spaces): Structured JSON output for log aggregation
|
| 87 |
+
- Development: Colored, human-readable text output
|
| 88 |
+
|
| 89 |
+
The logger automatically includes request IDs from context variables.
|
| 90 |
+
"""
|
| 91 |
+
# Remove default handler
|
| 92 |
+
logger.remove()
|
| 93 |
+
|
| 94 |
+
# Determine format based on environment
|
| 95 |
+
log_format_type = _determine_log_format()
|
| 96 |
+
log_level = settings.log_level.upper()
|
| 97 |
+
|
| 98 |
+
if log_format_type == "json":
|
| 99 |
+
# Production: JSON structured logging
|
| 100 |
+
logger.add(
|
| 101 |
+
sys.stdout,
|
| 102 |
+
format=_serialize_record,
|
| 103 |
+
level=log_level,
|
| 104 |
+
serialize=False, # We handle serialization ourselves
|
| 105 |
+
backtrace=True,
|
| 106 |
+
diagnose=False, # Don't show local variables in production
|
| 107 |
+
)
|
| 108 |
+
else:
|
| 109 |
+
# Development: Colored text logging
|
| 110 |
+
logger.add(
|
| 111 |
+
sys.stdout,
|
| 112 |
+
format=(
|
| 113 |
+
"<green>{time:YYYY-MM-DD HH:mm:ss.SSS}</green> | "
|
| 114 |
+
"<level>{level: <8}</level> | "
|
| 115 |
+
"<cyan>{name}</cyan>:<cyan>{function}</cyan>:<cyan>{line}</cyan> | "
|
| 116 |
+
"<level>{message}</level>"
|
| 117 |
+
),
|
| 118 |
+
level=log_level,
|
| 119 |
+
colorize=True,
|
| 120 |
+
backtrace=True,
|
| 121 |
+
diagnose=True, # Show local variables for debugging
|
| 122 |
+
)
|
| 123 |
+
|
| 124 |
+
# Log startup configuration
|
| 125 |
+
logger.info(
|
| 126 |
+
f"Logging initialized with format={log_format_type}, level={log_level}"
|
| 127 |
)
|
| 128 |
|
| 129 |
|
| 130 |
+
def get_logger(name: str) -> Any:
|
| 131 |
+
"""
|
| 132 |
+
Get a logger instance (backward-compatible with stdlib logging).
|
| 133 |
+
|
| 134 |
+
Args:
|
| 135 |
+
name: Logger name (typically __name__ of the calling module)
|
| 136 |
+
|
| 137 |
+
Returns:
|
| 138 |
+
Loguru logger instance bound to the module name
|
| 139 |
+
"""
|
| 140 |
+
# Bind the logger to the module name for context
|
| 141 |
+
return logger.bind(module=name)
|
| 142 |
|
| 143 |
|
| 144 |
class RequestLogger:
|
| 145 |
+
"""
|
| 146 |
+
Logger for request/response logging with automatic request ID tracking.
|
| 147 |
+
|
| 148 |
+
This class provides a backward-compatible API with the previous
|
| 149 |
+
stdlib logging implementation, but uses Loguru with automatic
|
| 150 |
+
context variable propagation for request IDs.
|
| 151 |
+
"""
|
| 152 |
+
|
| 153 |
+
def __init__(self, base_logger: Any = None):
|
| 154 |
+
"""
|
| 155 |
+
Initialize request logger.
|
| 156 |
|
| 157 |
+
Args:
|
| 158 |
+
base_logger: Base logger (ignored, uses global Loguru logger)
|
| 159 |
+
"""
|
| 160 |
+
# Always use the global logger with automatic request ID binding
|
| 161 |
self.logger = logger
|
| 162 |
|
| 163 |
def log_request(
|
| 164 |
self, method: str, path: str, request_id: str, **kwargs: Any
|
| 165 |
) -> None:
|
| 166 |
+
"""
|
| 167 |
+
Log incoming request with structured fields.
|
| 168 |
+
|
| 169 |
+
Args:
|
| 170 |
+
method: HTTP method (GET, POST, etc.)
|
| 171 |
+
path: Request path
|
| 172 |
+
request_id: Unique request identifier
|
| 173 |
+
**kwargs: Additional fields to log
|
| 174 |
+
"""
|
| 175 |
+
# Get request ID from context var (fallback to parameter)
|
| 176 |
+
context_request_id = request_id_var.get() or request_id
|
| 177 |
+
|
| 178 |
+
self.logger.bind(
|
| 179 |
+
request_id=context_request_id,
|
| 180 |
+
method=method,
|
| 181 |
+
path=path,
|
| 182 |
+
**kwargs
|
| 183 |
+
).info(f"Request {context_request_id}: {method} {path}")
|
| 184 |
|
| 185 |
def log_response(
|
| 186 |
self, request_id: str, status_code: int, duration_ms: float, **kwargs: Any
|
| 187 |
) -> None:
|
| 188 |
+
"""
|
| 189 |
+
Log response with structured fields.
|
| 190 |
+
|
| 191 |
+
Args:
|
| 192 |
+
request_id: Unique request identifier
|
| 193 |
+
status_code: HTTP status code
|
| 194 |
+
duration_ms: Request duration in milliseconds
|
| 195 |
+
**kwargs: Additional fields to log
|
| 196 |
+
"""
|
| 197 |
+
# Get request ID from context var (fallback to parameter)
|
| 198 |
+
context_request_id = request_id_var.get() or request_id
|
| 199 |
+
|
| 200 |
+
self.logger.bind(
|
| 201 |
+
request_id=context_request_id,
|
| 202 |
+
status_code=status_code,
|
| 203 |
+
duration_ms=duration_ms,
|
| 204 |
+
**kwargs
|
| 205 |
+
).info(f"Response {context_request_id}: {status_code} ({duration_ms:.2f}ms)")
|
| 206 |
|
| 207 |
def log_error(self, request_id: str, error: str, **kwargs: Any) -> None:
|
| 208 |
+
"""
|
| 209 |
+
Log error with structured fields.
|
| 210 |
+
|
| 211 |
+
Args:
|
| 212 |
+
request_id: Unique request identifier
|
| 213 |
+
error: Error message
|
| 214 |
+
**kwargs: Additional fields to log
|
| 215 |
+
"""
|
| 216 |
+
# Get request ID from context var (fallback to parameter)
|
| 217 |
+
context_request_id = request_id_var.get() or request_id
|
| 218 |
+
|
| 219 |
+
self.logger.bind(
|
| 220 |
+
request_id=context_request_id,
|
| 221 |
+
error=error,
|
| 222 |
+
**kwargs
|
| 223 |
+
).error(f"Error {context_request_id}: {error}")
|
|
@@ -8,7 +8,7 @@ from collections.abc import Callable
|
|
| 8 |
|
| 9 |
from fastapi import Request, Response
|
| 10 |
|
| 11 |
-
from app.core.logging import RequestLogger, get_logger
|
| 12 |
|
| 13 |
logger = get_logger(__name__)
|
| 14 |
request_logger = RequestLogger(logger)
|
|
@@ -19,6 +19,9 @@ async def request_context_middleware(request: Request, call_next: Callable) -> R
|
|
| 19 |
request_id = request.headers.get("X-Request-ID") or str(uuid.uuid4())
|
| 20 |
request.state.request_id = request_id
|
| 21 |
|
|
|
|
|
|
|
|
|
|
| 22 |
start = time.time()
|
| 23 |
request_logger.log_request(request.method, request.url.path, request_id)
|
| 24 |
try:
|
|
|
|
| 8 |
|
| 9 |
from fastapi import Request, Response
|
| 10 |
|
| 11 |
+
from app.core.logging import RequestLogger, get_logger, request_id_var
|
| 12 |
|
| 13 |
logger = get_logger(__name__)
|
| 14 |
request_logger = RequestLogger(logger)
|
|
|
|
| 19 |
request_id = request.headers.get("X-Request-ID") or str(uuid.uuid4())
|
| 20 |
request.state.request_id = request_id
|
| 21 |
|
| 22 |
+
# Set request ID in context variable for automatic propagation
|
| 23 |
+
request_id_var.set(request_id)
|
| 24 |
+
|
| 25 |
start = time.time()
|
| 26 |
request_logger.log_request(request.method, request.url.path, request_id)
|
| 27 |
try:
|
|
@@ -30,6 +30,9 @@ pytest-mock>=3.10.0,<4.0.0
|
|
| 30 |
# Development tools
|
| 31 |
ruff>=0.1.0
|
| 32 |
|
|
|
|
|
|
|
|
|
|
| 33 |
# Optional: for better performance
|
| 34 |
uvloop>=0.17.0,<0.20.0
|
| 35 |
|
|
|
|
| 30 |
# Development tools
|
| 31 |
ruff>=0.1.0
|
| 32 |
|
| 33 |
+
# Logging
|
| 34 |
+
loguru>=0.7.0,<1.0.0
|
| 35 |
+
|
| 36 |
# Optional: for better performance
|
| 37 |
uvloop>=0.17.0,<0.20.0
|
| 38 |
|
|
@@ -1,47 +1,87 @@
|
|
| 1 |
"""
|
| 2 |
-
Tests for logging configuration.
|
|
|
|
|
|
|
|
|
|
| 3 |
"""
|
| 4 |
|
| 5 |
-
import
|
| 6 |
-
from unittest.mock import Mock, patch
|
| 7 |
|
| 8 |
-
|
|
|
|
| 9 |
|
| 10 |
|
| 11 |
class TestLoggingSetup:
|
| 12 |
"""Test logging setup functionality."""
|
| 13 |
|
| 14 |
-
def
|
| 15 |
-
"""Test logging setup
|
| 16 |
-
|
| 17 |
-
|
| 18 |
-
|
| 19 |
-
|
| 20 |
-
|
| 21 |
-
|
| 22 |
-
|
| 23 |
-
|
| 24 |
-
|
| 25 |
-
|
| 26 |
-
|
| 27 |
-
|
| 28 |
-
|
| 29 |
-
assert
|
| 30 |
-
assert
|
| 31 |
-
|
| 32 |
-
|
| 33 |
-
|
| 34 |
-
|
| 35 |
-
|
| 36 |
-
|
| 37 |
-
|
| 38 |
-
|
| 39 |
-
|
| 40 |
-
|
| 41 |
-
|
| 42 |
-
|
| 43 |
-
|
| 44 |
-
|
| 45 |
-
|
| 46 |
-
|
| 47 |
-
assert
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
| 1 |
"""
|
| 2 |
+
Tests for logging configuration (backward compatibility tests).
|
| 3 |
+
|
| 4 |
+
These tests verify the core logging functionality works correctly
|
| 5 |
+
without using mocks - testing real behavior with Loguru.
|
| 6 |
"""
|
| 7 |
|
| 8 |
+
from pathlib import Path
|
|
|
|
| 9 |
|
| 10 |
+
import pytest
|
| 11 |
+
from loguru import logger
|
| 12 |
|
| 13 |
|
| 14 |
class TestLoggingSetup:
|
| 15 |
"""Test logging setup functionality."""
|
| 16 |
|
| 17 |
+
def test_setup_logging_initializes_without_error(self):
|
| 18 |
+
"""Test logging setup runs without errors."""
|
| 19 |
+
from app.core.logging import setup_logging
|
| 20 |
+
|
| 21 |
+
# Should not raise any exceptions
|
| 22 |
+
setup_logging()
|
| 23 |
+
|
| 24 |
+
def test_get_logger_returns_valid_logger(self):
|
| 25 |
+
"""Test get_logger function returns valid logger instance."""
|
| 26 |
+
from app.core.logging import get_logger
|
| 27 |
+
|
| 28 |
+
test_logger = get_logger("test_module")
|
| 29 |
+
|
| 30 |
+
# Should be a Loguru logger with standard methods
|
| 31 |
+
assert test_logger is not None
|
| 32 |
+
assert hasattr(test_logger, "info")
|
| 33 |
+
assert hasattr(test_logger, "error")
|
| 34 |
+
assert hasattr(test_logger, "warning")
|
| 35 |
+
assert hasattr(test_logger, "debug")
|
| 36 |
+
assert hasattr(test_logger, "bind")
|
| 37 |
+
|
| 38 |
+
def test_get_logger_can_log_messages(self, tmp_path: Path):
|
| 39 |
+
"""Test logger can actually log messages."""
|
| 40 |
+
from app.core.logging import get_logger
|
| 41 |
+
|
| 42 |
+
log_file = tmp_path / "test.log"
|
| 43 |
+
logger.remove()
|
| 44 |
+
logger.add(log_file, format="{message}", level="INFO")
|
| 45 |
+
|
| 46 |
+
test_logger = get_logger("test_module")
|
| 47 |
+
test_logger.info("Test log message")
|
| 48 |
+
|
| 49 |
+
content = log_file.read_text()
|
| 50 |
+
assert "Test log message" in content
|
| 51 |
+
|
| 52 |
+
def test_request_logger_class_works(self, tmp_path: Path):
|
| 53 |
+
"""Test RequestLogger class functionality."""
|
| 54 |
+
from app.core.logging import RequestLogger
|
| 55 |
+
|
| 56 |
+
log_file = tmp_path / "request.log"
|
| 57 |
+
logger.remove()
|
| 58 |
+
logger.add(log_file, format="{message}", level="INFO")
|
| 59 |
+
|
| 60 |
+
req_logger = RequestLogger()
|
| 61 |
+
|
| 62 |
+
# Test log_request
|
| 63 |
+
req_logger.log_request("GET", "/api/test", "req-123")
|
| 64 |
+
|
| 65 |
+
# Test log_response
|
| 66 |
+
req_logger.log_response("req-123", 200, 45.6)
|
| 67 |
+
|
| 68 |
+
# Test log_error
|
| 69 |
+
req_logger.log_error("req-123", "Test error")
|
| 70 |
+
|
| 71 |
+
content = log_file.read_text()
|
| 72 |
+
assert "GET /api/test" in content
|
| 73 |
+
assert "200" in content
|
| 74 |
+
assert "Test error" in content
|
| 75 |
+
|
| 76 |
+
def test_multiple_loggers_with_different_names(self):
|
| 77 |
+
"""Test creating multiple loggers with different names."""
|
| 78 |
+
from app.core.logging import get_logger
|
| 79 |
+
|
| 80 |
+
logger1 = get_logger("module1")
|
| 81 |
+
logger2 = get_logger("module2")
|
| 82 |
+
|
| 83 |
+
assert logger1 is not None
|
| 84 |
+
assert logger2 is not None
|
| 85 |
+
# Both should be able to log
|
| 86 |
+
logger1.info("Logger 1 message")
|
| 87 |
+
logger2.info("Logger 2 message")
|
|
@@ -0,0 +1,175 @@
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
| 1 |
+
"""
|
| 2 |
+
Tests for Loguru context variable propagation.
|
| 3 |
+
|
| 4 |
+
These tests verify:
|
| 5 |
+
- Request ID propagates through context vars
|
| 6 |
+
- Context preserves across async operations
|
| 7 |
+
- Logging works correctly in async task chains
|
| 8 |
+
"""
|
| 9 |
+
|
| 10 |
+
import asyncio
|
| 11 |
+
import io
|
| 12 |
+
from pathlib import Path
|
| 13 |
+
|
| 14 |
+
import pytest
|
| 15 |
+
from loguru import logger
|
| 16 |
+
|
| 17 |
+
|
| 18 |
+
class TestLoguruContext:
|
| 19 |
+
"""Test Loguru context variable propagation."""
|
| 20 |
+
|
| 21 |
+
def test_context_vars_propagation(self, tmp_path: Path):
|
| 22 |
+
"""Verify request ID propagates through context vars."""
|
| 23 |
+
from app.core.logging import request_id_var
|
| 24 |
+
|
| 25 |
+
# Configure logger to write to file
|
| 26 |
+
log_file = tmp_path / "context.log"
|
| 27 |
+
logger.remove()
|
| 28 |
+
logger.add(log_file, format="{extra[request_id]} | {message}", level="INFO")
|
| 29 |
+
|
| 30 |
+
# Set context and log
|
| 31 |
+
request_id_var.set("req-abc-123")
|
| 32 |
+
logger.bind(request_id=request_id_var.get()).info("Processing request")
|
| 33 |
+
|
| 34 |
+
output = log_file.read_text()
|
| 35 |
+
assert "req-abc-123" in output
|
| 36 |
+
assert "Processing request" in output
|
| 37 |
+
|
| 38 |
+
@pytest.mark.asyncio
|
| 39 |
+
async def test_logging_in_async_tasks(self, tmp_path: Path):
|
| 40 |
+
"""Verify logging works correctly in async task chains."""
|
| 41 |
+
from app.core.logging import request_id_var
|
| 42 |
+
|
| 43 |
+
log_file = tmp_path / "async.log"
|
| 44 |
+
logger.remove()
|
| 45 |
+
logger.add(log_file, format="{message}", level="INFO")
|
| 46 |
+
|
| 47 |
+
async def async_task(task_id: int):
|
| 48 |
+
# Each task has its own context
|
| 49 |
+
request_id_var.set(f"task-{task_id}")
|
| 50 |
+
logger.bind(task_id=task_id).info(f"Task {task_id} executing")
|
| 51 |
+
await asyncio.sleep(0.01)
|
| 52 |
+
logger.bind(task_id=task_id).info(f"Task {task_id} complete")
|
| 53 |
+
|
| 54 |
+
# Run multiple async tasks
|
| 55 |
+
await asyncio.gather(*[async_task(i) for i in range(3)])
|
| 56 |
+
|
| 57 |
+
output = log_file.read_text()
|
| 58 |
+
assert "Task 0 executing" in output
|
| 59 |
+
assert "Task 1 executing" in output
|
| 60 |
+
assert "Task 2 executing" in output
|
| 61 |
+
assert "Task 0 complete" in output
|
| 62 |
+
assert "Task 1 complete" in output
|
| 63 |
+
assert "Task 2 complete" in output
|
| 64 |
+
|
| 65 |
+
def test_context_isolation_between_requests(self, tmp_path: Path):
|
| 66 |
+
"""Verify context variables are isolated between different request contexts."""
|
| 67 |
+
from app.core.logging import request_id_var
|
| 68 |
+
|
| 69 |
+
log_file = tmp_path / "isolation.log"
|
| 70 |
+
logger.remove()
|
| 71 |
+
logger.add(
|
| 72 |
+
log_file, format="{extra[request_id]} | {message}", level="INFO"
|
| 73 |
+
)
|
| 74 |
+
|
| 75 |
+
# Simulate first request
|
| 76 |
+
request_id_var.set("request-1")
|
| 77 |
+
logger.bind(request_id=request_id_var.get()).info("First request")
|
| 78 |
+
|
| 79 |
+
# Simulate second request (new context)
|
| 80 |
+
request_id_var.set("request-2")
|
| 81 |
+
logger.bind(request_id=request_id_var.get()).info("Second request")
|
| 82 |
+
|
| 83 |
+
output = log_file.read_text()
|
| 84 |
+
assert "request-1 | First request" in output
|
| 85 |
+
assert "request-2 | Second request" in output
|
| 86 |
+
|
| 87 |
+
@pytest.mark.asyncio
|
| 88 |
+
async def test_context_preservation_across_await(self, tmp_path: Path):
|
| 89 |
+
"""Verify context is preserved across await calls."""
|
| 90 |
+
from app.core.logging import request_id_var
|
| 91 |
+
|
| 92 |
+
log_file = tmp_path / "preservation.log"
|
| 93 |
+
logger.remove()
|
| 94 |
+
logger.add(
|
| 95 |
+
log_file, format="{extra[request_id]} | {message}", level="INFO"
|
| 96 |
+
)
|
| 97 |
+
|
| 98 |
+
async def process_with_delay(request_id: str):
|
| 99 |
+
request_id_var.set(request_id)
|
| 100 |
+
|
| 101 |
+
logger.bind(request_id=request_id_var.get()).info("Before await")
|
| 102 |
+
await asyncio.sleep(0.01)
|
| 103 |
+
logger.bind(request_id=request_id_var.get()).info("After await")
|
| 104 |
+
|
| 105 |
+
await process_with_delay("preserved-id")
|
| 106 |
+
|
| 107 |
+
output = log_file.read_text()
|
| 108 |
+
assert "preserved-id | Before await" in output
|
| 109 |
+
assert "preserved-id | After await" in output
|
| 110 |
+
|
| 111 |
+
def test_request_logger_uses_context(self, tmp_path: Path):
|
| 112 |
+
"""Verify RequestLogger class uses context variables."""
|
| 113 |
+
from app.core.logging import RequestLogger, request_id_var
|
| 114 |
+
|
| 115 |
+
log_file = tmp_path / "request_logger.log"
|
| 116 |
+
logger.remove()
|
| 117 |
+
logger.add(log_file, format="{message}", level="INFO")
|
| 118 |
+
|
| 119 |
+
# Set request ID in context
|
| 120 |
+
request_id_var.set("context-req-456")
|
| 121 |
+
|
| 122 |
+
# Create RequestLogger and log
|
| 123 |
+
req_logger = RequestLogger()
|
| 124 |
+
req_logger.log_request("POST", "/api/test", "context-req-456")
|
| 125 |
+
|
| 126 |
+
output = log_file.read_text()
|
| 127 |
+
assert "context-req-456" in output
|
| 128 |
+
assert "POST /api/test" in output
|
| 129 |
+
|
| 130 |
+
def test_context_with_none_value(self, tmp_path: Path):
|
| 131 |
+
"""Verify logger handles None request ID gracefully."""
|
| 132 |
+
from app.core.logging import request_id_var
|
| 133 |
+
|
| 134 |
+
log_file = tmp_path / "none_context.log"
|
| 135 |
+
logger.remove()
|
| 136 |
+
logger.add(log_file, format="{message}", level="INFO")
|
| 137 |
+
|
| 138 |
+
# Don't set request ID (should be None)
|
| 139 |
+
request_id_var.set(None)
|
| 140 |
+
logger.info("No request ID")
|
| 141 |
+
|
| 142 |
+
output = log_file.read_text()
|
| 143 |
+
assert "No request ID" in output # Should not raise exception
|
| 144 |
+
|
| 145 |
+
@pytest.mark.asyncio
|
| 146 |
+
async def test_concurrent_async_tasks_with_different_request_ids(
|
| 147 |
+
self, tmp_path: Path
|
| 148 |
+
):
|
| 149 |
+
"""Verify concurrent tasks maintain separate request ID contexts."""
|
| 150 |
+
from app.core.logging import request_id_var
|
| 151 |
+
|
| 152 |
+
log_file = tmp_path / "concurrent.log"
|
| 153 |
+
logger.remove()
|
| 154 |
+
logger.add(log_file, format="{message}", level="INFO")
|
| 155 |
+
|
| 156 |
+
async def task_with_context(request_id: str, delay: float):
|
| 157 |
+
request_id_var.set(request_id)
|
| 158 |
+
logger.bind(request_id=request_id).info(f"{request_id} started")
|
| 159 |
+
await asyncio.sleep(delay)
|
| 160 |
+
logger.bind(request_id=request_id).info(f"{request_id} finished")
|
| 161 |
+
|
| 162 |
+
# Run tasks concurrently with different delays
|
| 163 |
+
await asyncio.gather(
|
| 164 |
+
task_with_context("req-fast", 0.01),
|
| 165 |
+
task_with_context("req-slow", 0.02),
|
| 166 |
+
task_with_context("req-medium", 0.015),
|
| 167 |
+
)
|
| 168 |
+
|
| 169 |
+
output = log_file.read_text()
|
| 170 |
+
assert "req-fast started" in output
|
| 171 |
+
assert "req-slow started" in output
|
| 172 |
+
assert "req-medium started" in output
|
| 173 |
+
assert "req-fast finished" in output
|
| 174 |
+
assert "req-slow finished" in output
|
| 175 |
+
assert "req-medium finished" in output
|
|
@@ -0,0 +1,133 @@
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
| 1 |
+
"""
|
| 2 |
+
Tests for Loguru imports across modules.
|
| 3 |
+
|
| 4 |
+
These tests verify:
|
| 5 |
+
- get_logger() works when imported from different modules
|
| 6 |
+
- Logger instances have the correct Loguru interface
|
| 7 |
+
- Module-level logger instances work correctly
|
| 8 |
+
"""
|
| 9 |
+
|
| 10 |
+
import pytest
|
| 11 |
+
|
| 12 |
+
|
| 13 |
+
class TestLoguruImports:
|
| 14 |
+
"""Test Loguru imports and module-level loggers."""
|
| 15 |
+
|
| 16 |
+
def test_get_logger_import_from_logging_module(self):
|
| 17 |
+
"""Verify get_logger() can be imported from logging module."""
|
| 18 |
+
from app.core.logging import get_logger
|
| 19 |
+
|
| 20 |
+
logger = get_logger(__name__)
|
| 21 |
+
|
| 22 |
+
assert logger is not None
|
| 23 |
+
assert hasattr(logger, "bind")
|
| 24 |
+
assert hasattr(logger, "info")
|
| 25 |
+
assert hasattr(logger, "error")
|
| 26 |
+
assert hasattr(logger, "warning")
|
| 27 |
+
assert hasattr(logger, "debug")
|
| 28 |
+
|
| 29 |
+
def test_logger_in_middleware_module(self):
|
| 30 |
+
"""Verify logger works in middleware module."""
|
| 31 |
+
from app.core.middleware import logger
|
| 32 |
+
|
| 33 |
+
assert logger is not None
|
| 34 |
+
assert hasattr(logger, "bind")
|
| 35 |
+
assert callable(logger.bind)
|
| 36 |
+
|
| 37 |
+
def test_logger_in_service_modules(self):
|
| 38 |
+
"""Verify loggers work across different service modules."""
|
| 39 |
+
# These imports will fail if logging setup is broken
|
| 40 |
+
try:
|
| 41 |
+
from app.services.hf_streaming_summarizer import logger as hf_logger
|
| 42 |
+
except ImportError:
|
| 43 |
+
pytest.skip("HF streaming summarizer not available")
|
| 44 |
+
|
| 45 |
+
assert hf_logger is not None
|
| 46 |
+
assert hasattr(hf_logger, "bind")
|
| 47 |
+
|
| 48 |
+
def test_request_logger_class_available(self):
|
| 49 |
+
"""Verify RequestLogger class can be imported."""
|
| 50 |
+
from app.core.logging import RequestLogger
|
| 51 |
+
|
| 52 |
+
req_logger = RequestLogger()
|
| 53 |
+
|
| 54 |
+
assert hasattr(req_logger, "log_request")
|
| 55 |
+
assert hasattr(req_logger, "log_response")
|
| 56 |
+
assert hasattr(req_logger, "log_error")
|
| 57 |
+
|
| 58 |
+
def test_get_logger_with_different_module_names(self):
|
| 59 |
+
"""Verify get_logger() works with different module names."""
|
| 60 |
+
from app.core.logging import get_logger
|
| 61 |
+
|
| 62 |
+
logger1 = get_logger("module1")
|
| 63 |
+
logger2 = get_logger("module2")
|
| 64 |
+
logger3 = get_logger("app.services.test")
|
| 65 |
+
|
| 66 |
+
# All should be valid loggers
|
| 67 |
+
assert logger1 is not None
|
| 68 |
+
assert logger2 is not None
|
| 69 |
+
assert logger3 is not None
|
| 70 |
+
|
| 71 |
+
# All should have bind method
|
| 72 |
+
assert hasattr(logger1, "bind")
|
| 73 |
+
assert hasattr(logger2, "bind")
|
| 74 |
+
assert hasattr(logger3, "bind")
|
| 75 |
+
|
| 76 |
+
def test_logger_bind_method_works(self):
|
| 77 |
+
"""Verify logger.bind() method works correctly."""
|
| 78 |
+
from app.core.logging import get_logger
|
| 79 |
+
|
| 80 |
+
logger = get_logger(__name__)
|
| 81 |
+
|
| 82 |
+
# Bind should return a logger-like object
|
| 83 |
+
bound_logger = logger.bind(test_field="value", request_id="test-123")
|
| 84 |
+
|
| 85 |
+
assert bound_logger is not None
|
| 86 |
+
assert hasattr(bound_logger, "info")
|
| 87 |
+
assert hasattr(bound_logger, "error")
|
| 88 |
+
|
| 89 |
+
# Should be able to log without errors
|
| 90 |
+
bound_logger.info("Test message")
|
| 91 |
+
|
| 92 |
+
def test_logger_methods_callable(self):
|
| 93 |
+
"""Verify all standard logger methods are callable."""
|
| 94 |
+
from app.core.logging import get_logger
|
| 95 |
+
|
| 96 |
+
logger = get_logger(__name__)
|
| 97 |
+
|
| 98 |
+
assert callable(logger.info)
|
| 99 |
+
assert callable(logger.debug)
|
| 100 |
+
assert callable(logger.warning)
|
| 101 |
+
assert callable(logger.error)
|
| 102 |
+
assert callable(logger.critical)
|
| 103 |
+
assert callable(logger.exception)
|
| 104 |
+
assert callable(logger.bind)
|
| 105 |
+
|
| 106 |
+
def test_request_logger_methods_callable(self):
|
| 107 |
+
"""Verify RequestLogger methods are callable."""
|
| 108 |
+
from app.core.logging import RequestLogger
|
| 109 |
+
|
| 110 |
+
req_logger = RequestLogger()
|
| 111 |
+
|
| 112 |
+
assert callable(req_logger.log_request)
|
| 113 |
+
assert callable(req_logger.log_response)
|
| 114 |
+
assert callable(req_logger.log_error)
|
| 115 |
+
|
| 116 |
+
def test_context_var_import(self):
|
| 117 |
+
"""Verify request_id_var can be imported."""
|
| 118 |
+
from app.core.logging import request_id_var
|
| 119 |
+
|
| 120 |
+
assert request_id_var is not None
|
| 121 |
+
|
| 122 |
+
# Should be a ContextVar
|
| 123 |
+
assert hasattr(request_id_var, "get")
|
| 124 |
+
assert hasattr(request_id_var, "set")
|
| 125 |
+
|
| 126 |
+
def test_setup_logging_function_exists(self):
|
| 127 |
+
"""Verify setup_logging() function exists and is callable."""
|
| 128 |
+
from app.core.logging import setup_logging
|
| 129 |
+
|
| 130 |
+
assert callable(setup_logging)
|
| 131 |
+
|
| 132 |
+
# Should be able to call without errors
|
| 133 |
+
setup_logging()
|
|
@@ -0,0 +1,83 @@
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
| 1 |
+
"""
|
| 2 |
+
Tests for Loguru integration with FastAPI.
|
| 3 |
+
|
| 4 |
+
These tests verify observable behavior through the API rather than log output,
|
| 5 |
+
since log output testing is covered by unit tests.
|
| 6 |
+
"""
|
| 7 |
+
|
| 8 |
+
import pytest
|
| 9 |
+
from fastapi.testclient import TestClient
|
| 10 |
+
|
| 11 |
+
|
| 12 |
+
class TestLoguruIntegration:
|
| 13 |
+
"""Test Loguru integration with FastAPI application."""
|
| 14 |
+
|
| 15 |
+
def test_request_id_header_preservation(self, client: TestClient):
|
| 16 |
+
"""Verify request ID is preserved in response headers."""
|
| 17 |
+
custom_request_id = "header-preservation-test-456"
|
| 18 |
+
|
| 19 |
+
response = client.get(
|
| 20 |
+
"/health", headers={"X-Request-ID": custom_request_id}
|
| 21 |
+
)
|
| 22 |
+
|
| 23 |
+
assert response.status_code == 200
|
| 24 |
+
assert response.headers["X-Request-ID"] == custom_request_id
|
| 25 |
+
|
| 26 |
+
def test_auto_generated_request_id(self, client: TestClient):
|
| 27 |
+
"""Verify request ID is auto-generated when not provided."""
|
| 28 |
+
# Make request without X-Request-ID header
|
| 29 |
+
response = client.get("/health")
|
| 30 |
+
|
| 31 |
+
assert response.status_code == 200
|
| 32 |
+
assert "X-Request-ID" in response.headers
|
| 33 |
+
|
| 34 |
+
# Should have UUID format (8-4-4-4-12 characters)
|
| 35 |
+
request_id = response.headers["X-Request-ID"]
|
| 36 |
+
assert len(request_id) == 36 # UUID length with hyphens
|
| 37 |
+
|
| 38 |
+
def test_multiple_sequential_requests_have_different_ids(self, client: TestClient):
|
| 39 |
+
"""Verify each request gets a unique ID when not specified."""
|
| 40 |
+
response1 = client.get("/health")
|
| 41 |
+
response2 = client.get("/health")
|
| 42 |
+
response3 = client.get("/health")
|
| 43 |
+
|
| 44 |
+
assert response1.status_code == 200
|
| 45 |
+
assert response2.status_code == 200
|
| 46 |
+
assert response3.status_code == 200
|
| 47 |
+
|
| 48 |
+
# All should have request IDs
|
| 49 |
+
id1 = response1.headers["X-Request-ID"]
|
| 50 |
+
id2 = response2.headers["X-Request-ID"]
|
| 51 |
+
id3 = response3.headers["X-Request-ID"]
|
| 52 |
+
|
| 53 |
+
# All should be unique
|
| 54 |
+
assert id1 != id2
|
| 55 |
+
assert id2 != id3
|
| 56 |
+
assert id1 != id3
|
| 57 |
+
|
| 58 |
+
def test_request_id_preserved_through_error_response(self, client: TestClient):
|
| 59 |
+
"""Verify request ID is preserved even when request fails."""
|
| 60 |
+
custom_request_id = "error-test-999"
|
| 61 |
+
|
| 62 |
+
# Make request that should fail validation (empty text)
|
| 63 |
+
response = client.post(
|
| 64 |
+
"/api/v2/summarize/stream",
|
| 65 |
+
json={"text": "", "max_tokens": 50},
|
| 66 |
+
headers={"X-Request-ID": custom_request_id},
|
| 67 |
+
)
|
| 68 |
+
|
| 69 |
+
# Should get validation error
|
| 70 |
+
assert response.status_code == 422
|
| 71 |
+
|
| 72 |
+
# Request ID should still be in headers
|
| 73 |
+
assert response.headers["X-Request-ID"] == custom_request_id
|
| 74 |
+
|
| 75 |
+
def test_logging_context_does_not_interfere_with_responses(self, client: TestClient):
|
| 76 |
+
"""Verify logging context doesn't affect normal request/response cycle."""
|
| 77 |
+
# Make several requests to ensure logging doesn't cause issues
|
| 78 |
+
for i in range(5):
|
| 79 |
+
response = client.get("/health", headers={"X-Request-ID": f"test-{i}"})
|
| 80 |
+
assert response.status_code == 200
|
| 81 |
+
assert response.headers["X-Request-ID"] == f"test-{i}"
|
| 82 |
+
# Response should contain status
|
| 83 |
+
assert "status" in response.json()
|
|
@@ -0,0 +1,173 @@
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
| 1 |
+
"""
|
| 2 |
+
Tests for Loguru performance optimizations.
|
| 3 |
+
|
| 4 |
+
These tests verify:
|
| 5 |
+
- Lazy evaluation doesn't execute expensive operations when filtered
|
| 6 |
+
- Logger level filtering works correctly
|
| 7 |
+
- Performance characteristics of Loguru logging
|
| 8 |
+
"""
|
| 9 |
+
|
| 10 |
+
from pathlib import Path
|
| 11 |
+
|
| 12 |
+
from loguru import logger
|
| 13 |
+
|
| 14 |
+
|
| 15 |
+
class TestLoguruPerformance:
|
| 16 |
+
"""Test Loguru performance optimizations."""
|
| 17 |
+
|
| 18 |
+
def test_lazy_evaluation_with_opt_lazy(self, tmp_path: Path):
|
| 19 |
+
"""Verify lazy evaluation doesn't execute expensive operations when filtered."""
|
| 20 |
+
log_file = tmp_path / "lazy.log"
|
| 21 |
+
logger.remove()
|
| 22 |
+
logger.add(log_file, level="ERROR") # Only ERROR and above
|
| 23 |
+
|
| 24 |
+
expensive_call_count = 0
|
| 25 |
+
|
| 26 |
+
def expensive_operation():
|
| 27 |
+
nonlocal expensive_call_count
|
| 28 |
+
expensive_call_count += 1
|
| 29 |
+
return "expensive result"
|
| 30 |
+
|
| 31 |
+
# This should NOT call expensive_operation() because level is INFO < ERROR
|
| 32 |
+
logger.opt(lazy=True).info("Result: {}", expensive_operation)
|
| 33 |
+
|
| 34 |
+
assert expensive_call_count == 0 # Not called!
|
| 35 |
+
|
| 36 |
+
# This SHOULD call expensive_operation() because level is ERROR
|
| 37 |
+
logger.opt(lazy=True).error("Error: {}", expensive_operation)
|
| 38 |
+
|
| 39 |
+
assert expensive_call_count == 1 # Called once
|
| 40 |
+
|
| 41 |
+
def test_log_level_filtering(self, tmp_path: Path):
|
| 42 |
+
"""Verify log level filtering works correctly."""
|
| 43 |
+
log_file = tmp_path / "filtering.log"
|
| 44 |
+
logger.remove()
|
| 45 |
+
logger.add(log_file, level="WARNING") # WARNING and above only
|
| 46 |
+
|
| 47 |
+
logger.debug("Debug message")
|
| 48 |
+
logger.info("Info message")
|
| 49 |
+
logger.warning("Warning message")
|
| 50 |
+
logger.error("Error message")
|
| 51 |
+
|
| 52 |
+
content = log_file.read_text()
|
| 53 |
+
|
| 54 |
+
# Should not contain DEBUG or INFO
|
| 55 |
+
assert "Debug message" not in content
|
| 56 |
+
assert "Info message" not in content
|
| 57 |
+
|
| 58 |
+
# Should contain WARNING and ERROR
|
| 59 |
+
assert "Warning message" in content
|
| 60 |
+
assert "Error message" in content
|
| 61 |
+
|
| 62 |
+
def test_string_formatting_overhead(self, tmp_path: Path):
|
| 63 |
+
"""Verify string formatting is efficient."""
|
| 64 |
+
log_file = tmp_path / "formatting.log"
|
| 65 |
+
logger.remove()
|
| 66 |
+
logger.add(log_file, level="INFO")
|
| 67 |
+
|
| 68 |
+
# Format strings should work efficiently
|
| 69 |
+
for i in range(100):
|
| 70 |
+
logger.info(f"Iteration {i}: Processing item")
|
| 71 |
+
|
| 72 |
+
content = log_file.read_text()
|
| 73 |
+
lines = content.strip().split("\n")
|
| 74 |
+
|
| 75 |
+
# Should have 100 log entries
|
| 76 |
+
assert len(lines) == 100
|
| 77 |
+
|
| 78 |
+
def test_batch_logging_performance(self, tmp_path: Path):
|
| 79 |
+
"""Verify Loguru can handle batch logging efficiently."""
|
| 80 |
+
log_file = tmp_path / "batch.log"
|
| 81 |
+
logger.remove()
|
| 82 |
+
logger.add(log_file, level="INFO")
|
| 83 |
+
|
| 84 |
+
# Log 1000 messages rapidly
|
| 85 |
+
for i in range(1000):
|
| 86 |
+
logger.info(f"Batch message {i}")
|
| 87 |
+
|
| 88 |
+
content = log_file.read_text()
|
| 89 |
+
lines = content.strip().split("\n")
|
| 90 |
+
|
| 91 |
+
assert len(lines) == 1000
|
| 92 |
+
|
| 93 |
+
def test_logger_with_many_bindings(self, tmp_path: Path):
|
| 94 |
+
"""Verify logger performs well with many bound fields."""
|
| 95 |
+
log_file = tmp_path / "bindings.log"
|
| 96 |
+
logger.remove()
|
| 97 |
+
logger.add(log_file, format="{message}", level="INFO")
|
| 98 |
+
|
| 99 |
+
# Bind many fields
|
| 100 |
+
bound_logger = logger.bind(
|
| 101 |
+
field1="value1",
|
| 102 |
+
field2="value2",
|
| 103 |
+
field3="value3",
|
| 104 |
+
field4="value4",
|
| 105 |
+
field5="value5",
|
| 106 |
+
request_id="test-123",
|
| 107 |
+
user_id=456,
|
| 108 |
+
session_id="session-789",
|
| 109 |
+
)
|
| 110 |
+
|
| 111 |
+
bound_logger.info("Message with many bindings")
|
| 112 |
+
|
| 113 |
+
content = log_file.read_text()
|
| 114 |
+
assert "Message with many bindings" in content
|
| 115 |
+
|
| 116 |
+
def test_exception_logging_overhead(self, tmp_path: Path):
|
| 117 |
+
"""Verify exception logging doesn't significantly impact performance."""
|
| 118 |
+
log_file = tmp_path / "exceptions.log"
|
| 119 |
+
logger.remove()
|
| 120 |
+
logger.add(log_file, level="ERROR")
|
| 121 |
+
|
| 122 |
+
# Log multiple exceptions
|
| 123 |
+
for i in range(10):
|
| 124 |
+
try:
|
| 125 |
+
raise ValueError(f"Test exception {i}")
|
| 126 |
+
except ValueError:
|
| 127 |
+
logger.exception(f"Caught exception {i}")
|
| 128 |
+
|
| 129 |
+
content = log_file.read_text()
|
| 130 |
+
|
| 131 |
+
# Should have logged all exceptions
|
| 132 |
+
assert content.count("Caught exception") == 10
|
| 133 |
+
|
| 134 |
+
def test_conditional_logging_performance(self, tmp_path: Path):
|
| 135 |
+
"""Verify conditional logging doesn't execute when disabled."""
|
| 136 |
+
log_file = tmp_path / "conditional.log"
|
| 137 |
+
logger.remove()
|
| 138 |
+
logger.add(log_file, level="ERROR")
|
| 139 |
+
|
| 140 |
+
call_count = 0
|
| 141 |
+
|
| 142 |
+
def count_calls():
|
| 143 |
+
nonlocal call_count
|
| 144 |
+
call_count += 1
|
| 145 |
+
return "result"
|
| 146 |
+
|
| 147 |
+
# Info logs should not execute the function
|
| 148 |
+
for _ in range(100):
|
| 149 |
+
logger.opt(lazy=True).info("Value: {}", count_calls)
|
| 150 |
+
|
| 151 |
+
assert call_count == 0 # Never called because INFO < ERROR
|
| 152 |
+
|
| 153 |
+
def test_logger_disable_and_enable(self, tmp_path: Path):
|
| 154 |
+
"""Verify logger can be disabled and enabled efficiently."""
|
| 155 |
+
log_file = tmp_path / "disable.log"
|
| 156 |
+
handler_id = logger.add(log_file, level="INFO")
|
| 157 |
+
|
| 158 |
+
# Log with handler enabled
|
| 159 |
+
logger.info("Message 1")
|
| 160 |
+
|
| 161 |
+
# Disable handler
|
| 162 |
+
logger.remove(handler_id)
|
| 163 |
+
logger.info("Message 2") # Should not be logged
|
| 164 |
+
|
| 165 |
+
# Re-enable handler
|
| 166 |
+
logger.add(log_file, level="INFO")
|
| 167 |
+
logger.info("Message 3")
|
| 168 |
+
|
| 169 |
+
content = log_file.read_text()
|
| 170 |
+
|
| 171 |
+
assert "Message 1" in content
|
| 172 |
+
assert "Message 2" not in content
|
| 173 |
+
assert "Message 3" in content
|
|
@@ -0,0 +1,71 @@
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
| 1 |
+
"""
|
| 2 |
+
Tests for Loguru logging setup and configuration.
|
| 3 |
+
|
| 4 |
+
These tests verify:
|
| 5 |
+
- JSON format output for production
|
| 6 |
+
- Colored text format output for development
|
| 7 |
+
- get_logger() function returns configured Loguru instance
|
| 8 |
+
"""
|
| 9 |
+
|
| 10 |
+
import json
|
| 11 |
+
from pathlib import Path
|
| 12 |
+
|
| 13 |
+
import pytest
|
| 14 |
+
from loguru import logger
|
| 15 |
+
|
| 16 |
+
|
| 17 |
+
class TestLoguruSetup:
|
| 18 |
+
"""Test Loguru setup and configuration."""
|
| 19 |
+
|
| 20 |
+
def test_text_output_format(self, tmp_path: Path):
|
| 21 |
+
"""Verify human-readable text output for development."""
|
| 22 |
+
# Configure logger with text output to file
|
| 23 |
+
log_file = tmp_path / "test.log"
|
| 24 |
+
logger.remove()
|
| 25 |
+
logger.add(
|
| 26 |
+
log_file,
|
| 27 |
+
format="{time:YYYY-MM-DD HH:mm:ss} | {level} | {message}",
|
| 28 |
+
colorize=False,
|
| 29 |
+
level="INFO",
|
| 30 |
+
)
|
| 31 |
+
|
| 32 |
+
logger.info("Development log message")
|
| 33 |
+
|
| 34 |
+
content = log_file.read_text()
|
| 35 |
+
assert "INFO" in content
|
| 36 |
+
assert "Development log message" in content
|
| 37 |
+
|
| 38 |
+
def test_get_logger_returns_configured_instance(self):
|
| 39 |
+
"""Verify get_logger() returns properly configured Loguru instance."""
|
| 40 |
+
from app.core.logging import get_logger
|
| 41 |
+
|
| 42 |
+
test_logger = get_logger(__name__)
|
| 43 |
+
|
| 44 |
+
# Should be able to log without errors
|
| 45 |
+
test_logger.info("Test message")
|
| 46 |
+
test_logger.bind(test_field="value").warning("Test with binding")
|
| 47 |
+
|
| 48 |
+
# Verify it's a Loguru logger (has bind method)
|
| 49 |
+
assert hasattr(test_logger, "bind")
|
| 50 |
+
assert callable(test_logger.bind)
|
| 51 |
+
|
| 52 |
+
def test_logger_bind_with_multiple_fields(self, tmp_path: Path):
|
| 53 |
+
"""Verify logger can bind multiple fields at once."""
|
| 54 |
+
log_file = tmp_path / "multi_bind.log"
|
| 55 |
+
logger.remove()
|
| 56 |
+
logger.add(log_file, serialize=True, level="INFO")
|
| 57 |
+
|
| 58 |
+
logger.bind(field1="value1", field2="value2", field3=123).info("Multi-bind test")
|
| 59 |
+
|
| 60 |
+
with open(log_file) as f:
|
| 61 |
+
log_entry = json.loads(f.readline())
|
| 62 |
+
assert log_entry["record"]["extra"]["field1"] == "value1"
|
| 63 |
+
assert log_entry["record"]["extra"]["field2"] == "value2"
|
| 64 |
+
assert log_entry["record"]["extra"]["field3"] == 123
|
| 65 |
+
|
| 66 |
+
def test_setup_logging_can_be_called(self):
|
| 67 |
+
"""Verify setup_logging() function can be called without error."""
|
| 68 |
+
from app.core.logging import setup_logging
|
| 69 |
+
|
| 70 |
+
# Should not raise any exceptions
|
| 71 |
+
setup_logging()
|
|
@@ -1,11 +1,16 @@
|
|
| 1 |
"""
|
| 2 |
Tests for middleware functionality.
|
|
|
|
|
|
|
|
|
|
| 3 |
"""
|
| 4 |
|
| 5 |
-
from
|
|
|
|
| 6 |
|
| 7 |
import pytest
|
| 8 |
from fastapi import Request, Response
|
|
|
|
| 9 |
|
| 10 |
from app.core.middleware import request_context_middleware
|
| 11 |
|
|
@@ -80,10 +85,10 @@ class TestRequestContextMiddleware:
|
|
| 80 |
|
| 81 |
# Mock the call_next function to raise an exception
|
| 82 |
async def mock_call_next(req):
|
| 83 |
-
raise
|
| 84 |
|
| 85 |
# Test that middleware doesn't suppress exceptions
|
| 86 |
-
with pytest.raises(
|
| 87 |
await request_context_middleware(request, mock_call_next)
|
| 88 |
|
| 89 |
# Verify request ID was still added
|
|
@@ -91,29 +96,65 @@ class TestRequestContextMiddleware:
|
|
| 91 |
assert request.state.request_id is not None
|
| 92 |
|
| 93 |
@pytest.mark.asyncio
|
| 94 |
-
async def
|
| 95 |
-
"""Test that middleware
|
| 96 |
-
|
| 97 |
-
|
| 98 |
-
|
| 99 |
-
|
| 100 |
-
|
| 101 |
-
|
| 102 |
-
|
| 103 |
-
|
| 104 |
-
|
| 105 |
-
|
| 106 |
-
|
| 107 |
-
|
| 108 |
-
|
| 109 |
-
|
| 110 |
-
|
| 111 |
-
|
| 112 |
-
|
| 113 |
-
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
| 114 |
|
| 115 |
-
|
| 116 |
-
|
| 117 |
-
|
| 118 |
-
|
| 119 |
-
mock_logger.log_response.assert_called_once()
|
|
|
|
| 1 |
"""
|
| 2 |
Tests for middleware functionality.
|
| 3 |
+
|
| 4 |
+
Tests verify core middleware behavior (request ID handling, exception handling).
|
| 5 |
+
Logging integration tests are in test_loguru_integration.py.
|
| 6 |
"""
|
| 7 |
|
| 8 |
+
from pathlib import Path
|
| 9 |
+
from unittest.mock import Mock
|
| 10 |
|
| 11 |
import pytest
|
| 12 |
from fastapi import Request, Response
|
| 13 |
+
from loguru import logger
|
| 14 |
|
| 15 |
from app.core.middleware import request_context_middleware
|
| 16 |
|
|
|
|
| 85 |
|
| 86 |
# Mock the call_next function to raise an exception
|
| 87 |
async def mock_call_next(req):
|
| 88 |
+
raise ValueError("Test exception")
|
| 89 |
|
| 90 |
# Test that middleware doesn't suppress exceptions
|
| 91 |
+
with pytest.raises(ValueError, match="Test exception"):
|
| 92 |
await request_context_middleware(request, mock_call_next)
|
| 93 |
|
| 94 |
# Verify request ID was still added
|
|
|
|
| 96 |
assert request.state.request_id is not None
|
| 97 |
|
| 98 |
@pytest.mark.asyncio
|
| 99 |
+
async def test_middleware_sets_context_var(self, tmp_path: Path):
|
| 100 |
+
"""Test that middleware sets request ID in context variable."""
|
| 101 |
+
from app.core.logging import request_id_var
|
| 102 |
+
|
| 103 |
+
log_file = tmp_path / "middleware_context.log"
|
| 104 |
+
logger.remove()
|
| 105 |
+
logger.add(log_file, format="{message}", level="INFO")
|
| 106 |
+
|
| 107 |
+
# Mock request
|
| 108 |
+
request = Mock(spec=Request)
|
| 109 |
+
request.headers = {"X-Request-ID": "context-test-456"}
|
| 110 |
+
request.state = Mock()
|
| 111 |
+
request.method = "GET"
|
| 112 |
+
request.url.path = "/test"
|
| 113 |
+
|
| 114 |
+
response = Mock(spec=Response)
|
| 115 |
+
response.headers = {}
|
| 116 |
+
response.status_code = 200
|
| 117 |
+
|
| 118 |
+
# Mock the call_next function
|
| 119 |
+
async def mock_call_next(req):
|
| 120 |
+
# Log inside request handling (context var should be set)
|
| 121 |
+
current_request_id = request_id_var.get()
|
| 122 |
+
logger.info(f"Processing request {current_request_id}")
|
| 123 |
+
return response
|
| 124 |
+
|
| 125 |
+
# Test the middleware
|
| 126 |
+
await request_context_middleware(request, mock_call_next)
|
| 127 |
+
|
| 128 |
+
# Verify context var was set
|
| 129 |
+
content = log_file.read_text()
|
| 130 |
+
assert "context-test-456" in content
|
| 131 |
+
|
| 132 |
+
@pytest.mark.asyncio
|
| 133 |
+
async def test_middleware_logging_works(self, tmp_path: Path):
|
| 134 |
+
"""Test that middleware logs requests and responses."""
|
| 135 |
+
log_file = tmp_path / "middleware_log.log"
|
| 136 |
+
logger.remove()
|
| 137 |
+
logger.add(log_file, format="{message}", level="INFO")
|
| 138 |
+
|
| 139 |
+
# Mock request and response
|
| 140 |
+
request = Mock(spec=Request)
|
| 141 |
+
request.headers = {}
|
| 142 |
+
request.state = Mock()
|
| 143 |
+
request.method = "POST"
|
| 144 |
+
request.url.path = "/api/data"
|
| 145 |
+
|
| 146 |
+
response = Mock(spec=Response)
|
| 147 |
+
response.headers = {}
|
| 148 |
+
response.status_code = 201
|
| 149 |
+
|
| 150 |
+
# Mock the call_next function
|
| 151 |
+
async def mock_call_next(req):
|
| 152 |
+
return response
|
| 153 |
+
|
| 154 |
+
# Test the middleware
|
| 155 |
+
await request_context_middleware(request, mock_call_next)
|
| 156 |
|
| 157 |
+
# Verify logs contain request and response
|
| 158 |
+
content = log_file.read_text()
|
| 159 |
+
assert "POST /api/data" in content
|
| 160 |
+
assert "201" in content
|
|
|