Update ruff rules and document logging patterns
- Added logging-related ruff rules (G, LOG) to pyproject.toml - Temporarily ignored G001, G002 during migration - Created comprehensive logging patterns documentation - Documented structured logging configuration and patterns - Provided migration guide from standard to structured logging This completes Phase 5.5-5.6: Update ruff rules and document logging patterns
This commit is contained in:
181
docs/development/logging-patterns.md
Normal file
181
docs/development/logging-patterns.md
Normal file
@@ -0,0 +1,181 @@
|
||||
# Logging Patterns and Guidelines
|
||||
|
||||
## Overview
|
||||
|
||||
This document describes the logging patterns and guidelines for AITBC services. We use structured logging with `structlog` to provide consistent, parseable logs across all services.
|
||||
|
||||
## Structured Logging Configuration
|
||||
|
||||
### Setup
|
||||
|
||||
Logging is configured using `structlog` in `app_logging.py`:
|
||||
|
||||
```python
|
||||
from aitbc import get_logger
|
||||
|
||||
logger = get_logger(__name__)
|
||||
```
|
||||
|
||||
### Log Format
|
||||
|
||||
Logs are output in JSON format with the following fields:
|
||||
- `timestamp` - ISO 8601 timestamp
|
||||
- `logger` - Logger name (module name)
|
||||
- `level` - Log level (INFO, WARNING, ERROR, etc.)
|
||||
- `event` - Event description
|
||||
- Additional context fields as key-value pairs
|
||||
|
||||
### Log Levels
|
||||
|
||||
- **DEBUG** - Detailed diagnostic information
|
||||
- **INFO** - General informational messages
|
||||
- **WARNING** - Warning messages for potentially harmful situations
|
||||
- **ERROR** - Error messages for error events
|
||||
- **CRITICAL** - Critical messages for very severe error events
|
||||
|
||||
## Logging Patterns
|
||||
|
||||
### Basic Logging
|
||||
|
||||
```python
|
||||
logger.info("Event description", field1=value1, field2=value2)
|
||||
```
|
||||
|
||||
### Request Logging
|
||||
|
||||
Request ID correlation is automatically added by `RequestIDMiddleware`. The request ID is available in `request.state.request_id`:
|
||||
|
||||
```python
|
||||
logger = logger.bind(request_id=request.state.request_id)
|
||||
logger.info("Processing request", method=request.method, path=request.url.path)
|
||||
```
|
||||
|
||||
### Error Logging
|
||||
|
||||
Always include error context when logging errors:
|
||||
|
||||
```python
|
||||
try:
|
||||
# operation
|
||||
except Exception as e:
|
||||
logger.error("Operation failed", error=str(e), operation="some_operation")
|
||||
raise
|
||||
```
|
||||
|
||||
### Performance Logging
|
||||
|
||||
Performance metrics are automatically logged by `PerformanceLoggingMiddleware`. Manual performance logging:
|
||||
|
||||
```python
|
||||
import time
|
||||
|
||||
start_time = time.perf_counter()
|
||||
# operation
|
||||
duration = time.perf_counter() - start_time
|
||||
logger.info("Operation completed", duration_ms=duration * 1000, operation="some_operation")
|
||||
```
|
||||
|
||||
## Middleware
|
||||
|
||||
### Request ID Middleware
|
||||
|
||||
Adds a unique request ID to each request for correlation:
|
||||
|
||||
- Generates or retrieves request ID from `X-Request-ID` header
|
||||
- Binds request ID to logger context
|
||||
- Adds request ID to response headers
|
||||
- Logs request start and completion
|
||||
|
||||
### Performance Logging Middleware
|
||||
|
||||
Tracks request timing:
|
||||
|
||||
- Logs request duration in milliseconds
|
||||
- Adds `X-Process-Time` header to responses
|
||||
- Logs method, path, and status code
|
||||
|
||||
## Guidelines
|
||||
|
||||
### DO
|
||||
|
||||
- Use structured logging with key-value pairs
|
||||
- Include relevant context in log messages
|
||||
- Use appropriate log levels
|
||||
- Log errors with exception context
|
||||
- Use request ID for correlation
|
||||
|
||||
### DON'T
|
||||
|
||||
- Use string formatting in log messages (use key-value pairs instead)
|
||||
- Log sensitive information (passwords, tokens, etc.)
|
||||
- Use bare `except:` clauses
|
||||
- Log at DEBUG level in production unless necessary
|
||||
- Log the same information multiple times
|
||||
|
||||
## Examples
|
||||
|
||||
### Good
|
||||
|
||||
```python
|
||||
logger.info(
|
||||
"User logged in",
|
||||
user_id=user.id,
|
||||
email=user.email,
|
||||
ip_address=request.client.host,
|
||||
)
|
||||
```
|
||||
|
||||
### Bad
|
||||
|
||||
```python
|
||||
logging.info(f"User {user.email} logged in from {request.client.host}")
|
||||
```
|
||||
|
||||
## Migration Guide
|
||||
|
||||
To migrate from standard logging to structured logging:
|
||||
|
||||
1. Replace `import logging` with `from aitbc import get_logger`
|
||||
2. Replace `logging.getLogger(__name__)` with `get_logger(__name__)`
|
||||
3. Replace f-strings with key-value pairs
|
||||
4. Update log calls to use structured format
|
||||
|
||||
### Before
|
||||
|
||||
```python
|
||||
import logging
|
||||
|
||||
logger = logging.getLogger(__name__)
|
||||
logger.info(f"Processing request {request_id}")
|
||||
```
|
||||
|
||||
### After
|
||||
|
||||
```python
|
||||
from aitbc import get_logger
|
||||
|
||||
logger = get_logger(__name__)
|
||||
logger.info("Processing request", request_id=request_id)
|
||||
```
|
||||
|
||||
## Configuration
|
||||
|
||||
Log level can be configured via environment variable or settings:
|
||||
|
||||
```python
|
||||
from .app_logging import configure_logging
|
||||
|
||||
configure_logging(level="INFO") # or "DEBUG", "WARNING", "ERROR"
|
||||
```
|
||||
|
||||
## Ruff Rules
|
||||
|
||||
The following ruff rules are enforced for logging:
|
||||
- `G` - logging-string-format (enforce structured logging)
|
||||
- `LOG` - logging best practices
|
||||
|
||||
Some rules are temporarily ignored during migration:
|
||||
- `G001` - logging-string-format
|
||||
- `G002` - logging-string-format
|
||||
|
||||
These will be enforced after migration is complete.
|
||||
@@ -177,11 +177,15 @@ select = [
|
||||
"C4", # flake8-comprehensions
|
||||
"UP", # pyupgrade
|
||||
"E722", # bare except (explicitly enforce)
|
||||
"G", # logging-string-format (enforce f-strings in logging)
|
||||
"LOG", # logging best practices
|
||||
]
|
||||
ignore = [
|
||||
"E501", # line too long, handled by black
|
||||
"B008", # do not perform function calls in argument defaults
|
||||
"C901", # too complex
|
||||
"G001", # logging-string-format (allow for now, migration in progress)
|
||||
"G002", # logging-string-format (allow for now, migration in progress)
|
||||
]
|
||||
|
||||
[tool.ruff.lint.per-file-ignores]
|
||||
|
||||
Reference in New Issue
Block a user