* Studio: stop truncating long log lines as suspected base64 filter_sensitive_data carried a heuristic from the original Studio import that truncated any string >100 chars containing ',' or '/' to value[:20] + '...'. The block was dormant until #5246 wired filter_sensitive_data into the structlog processor chain to redact native-path leases. Once active, the heuristic ate normal log lines - llama_cpp_backend's GGUF size summary, mmproj selection, the full llama-server command line, and any traceback containing a path - all rendered as a 20-char prefix, defeating debugging of llama-server exceptions and GPU selection. Drop the base64 truncation. No call site in the codebase logs raw base64; if one ever does, it should truncate at the source rather than in a global filter. Native-path lease redaction added by #5246 is preserved. * Studio: regression test for filter_sensitive_data truncation Pins two properties in studio/backend/loggers/handlers.py: 1. Long log messages with ',' or '/' (the GGUF size summary, mmproj selection, full llama-server command, exception tracebacks) flow through filter_sensitive_data unchanged. Exercises the exact call sites that regressed when #5246 wired the processor in. 2. Native-path lease redaction still fires for both the inline native_path_lease=... regex form and the nativePathLease dict-key form, so a future cleanup of the truncation logic can't quietly strip #5246's redaction along with it.
117 lines
3.6 KiB
Python
117 lines
3.6 KiB
Python
# SPDX-License-Identifier: AGPL-3.0-only
|
|
# Copyright 2026-present the Unsloth AI Inc. team. All rights reserved. See /studio/LICENSE.AGPL-3.0
|
|
|
|
"""Logging handlers and middleware for structured logging.
|
|
|
|
This module provides FastAPI middleware and structlog processors for:
|
|
- Request/response logging with timing
|
|
- Sensitive data filtering in logs
|
|
- Structured logging configuration
|
|
- Error handling with detailed context
|
|
|
|
Key Components:
|
|
- LoggingMiddleware: FastAPI middleware for request/response logging
|
|
- filter_sensitive_data: Structlog processor for data sanitization
|
|
- get_logger: Factory function for structured loggers
|
|
"""
|
|
|
|
import re
|
|
import time
|
|
from typing import Callable
|
|
|
|
import structlog
|
|
from fastapi import Request, Response
|
|
from starlette.middleware.base import BaseHTTPMiddleware
|
|
|
|
from utils.native_path_leases import redact_native_paths
|
|
|
|
logger = structlog.get_logger(__name__)
|
|
_NATIVE_PATH_LEASE_RE = re.compile(
|
|
r"(?i)(\b(?:native_path_lease|nativePathLease)[\"']?\s*[:=]\s*[\"']?)[A-Za-z0-9_-]+\.[A-Za-z0-9_-]+"
|
|
)
|
|
|
|
|
|
class LoggingMiddleware(BaseHTTPMiddleware):
|
|
async def dispatch(self, request: Request, call_next: Callable) -> Response:
|
|
start_time = time.time()
|
|
|
|
try:
|
|
response = await call_next(request)
|
|
|
|
# Log response
|
|
process_time = (time.time() - start_time) * 1000
|
|
|
|
EXCLUDED_PATHS = {
|
|
"/api/train/status",
|
|
"/api/train/metrics",
|
|
"/api/train/hardware",
|
|
"/api/system",
|
|
}
|
|
is_excluded = (
|
|
request.url.path in EXCLUDED_PATHS
|
|
or request.url.path.startswith("/assets/")
|
|
or request.url.path.endswith(
|
|
(".png", ".jpg", ".jpeg", ".ico", ".woff", ".woff2", ".ttf")
|
|
)
|
|
)
|
|
|
|
if not is_excluded:
|
|
logger.info(
|
|
"request_completed",
|
|
method = request.method,
|
|
path = request.url.path,
|
|
status_code = response.status_code,
|
|
process_time_ms = round(process_time, 2),
|
|
)
|
|
|
|
return response
|
|
|
|
except Exception as e:
|
|
logger.error(
|
|
"request_failed",
|
|
path = request.url.path,
|
|
method = request.method,
|
|
error = str(e),
|
|
exc_info = True,
|
|
)
|
|
raise
|
|
|
|
|
|
def filter_sensitive_data(logger, method_name, event_dict):
|
|
"""Structlog processor to redact native path leases from logs."""
|
|
|
|
def filter_value(value):
|
|
if isinstance(value, str):
|
|
try:
|
|
value = redact_native_paths(value)
|
|
except Exception:
|
|
pass
|
|
value = _NATIVE_PATH_LEASE_RE.sub(r"\1<redacted native path lease>", value)
|
|
return value
|
|
elif isinstance(value, dict):
|
|
return {
|
|
k: "<redacted native path lease>"
|
|
if str(k).replace("_", "").lower() == "nativepathlease"
|
|
else filter_value(v)
|
|
for k, v in value.items()
|
|
}
|
|
elif isinstance(value, list):
|
|
return [filter_value(item) for item in value]
|
|
return value
|
|
|
|
return {
|
|
k: "<redacted native path lease>"
|
|
if str(k).replace("_", "").lower() == "nativepathlease"
|
|
else filter_value(v)
|
|
for k, v in event_dict.items()
|
|
}
|
|
|
|
|
|
def get_logger(name: str) -> structlog.BoundLogger:
|
|
"""Get a logger instance for a specific module.
|
|
Args:
|
|
name: Usually __name__ of the module
|
|
Returns:
|
|
A bound structured logger
|
|
"""
|
|
return structlog.get_logger(name)
|