mirror of
https://github.com/bytedance/deer-flow.git
synced 2026-07-26 16:07:53 +00:00
* feat(observability): add trace-id correlation and enhanced logging - add opt-in gateway request trace correlation via X-Trace-Id - enhance logging with configurable trace_id-aware formatting - propagate deerflow_trace_id into runtime context and Langfuse metadata - keep enhanced logging disabled by default to preserve existing behavior * fix: harden trace correlation wiring - Make logging enhancement a restart-required startup snapshot and remove per-request config reads from TraceMiddleware - Restrict trace ids to printable ASCII before writing them to response headers, logs, and Langfuse metadata - Gate implicit DeerFlowClient trace-id creation behind logging.enhance.enabled while preserving explicit caller opt-in - Bind embedded client trace context per stream step to avoid generator ContextVar leaks and cross-context reset errors - Rebind memory update trace ids in Timer/executor worker paths so enhanced logs keep the captured correlation id - Remove unrelated __run_journal context overwrite from the trace-correlation change set * fix(gateway): avoid eager app construction on package import * fix(gateway): avoid config load during app import Keep Gateway app construction import-safe when config.yaml is absent by disabling TraceMiddleware only for that construction-time fallback path. Startup lifespan still performs strict config loading before serving.
110 lines
3.9 KiB
Python
110 lines
3.9 KiB
Python
"""Logging setup helpers for DeerFlow."""
|
|
|
|
from __future__ import annotations
|
|
|
|
import json
|
|
import logging
|
|
from datetime import UTC, datetime
|
|
from typing import Any
|
|
|
|
from deerflow.config.app_config import apply_logging_level
|
|
from deerflow.trace_context import get_current_trace_id
|
|
|
|
DEFAULT_LOG_DATE_FORMAT = "%Y-%m-%d %H:%M:%S"
|
|
DEFAULT_LOG_FORMAT = "%(asctime)s - %(name)s - %(levelname)s - %(message)s"
|
|
TRACE_TEXT_LOG_FORMAT = "%(asctime)s - %(name)s - %(levelname)s - [trace_id=%(trace_id)s] - %(message)s"
|
|
_TRACE_FILTER_NAME = "deerflow_trace_context_filter"
|
|
|
|
|
|
class TraceContextFilter(logging.Filter):
|
|
"""Inject the current request trace id into every log record."""
|
|
|
|
name = _TRACE_FILTER_NAME
|
|
|
|
def filter(self, record: logging.LogRecord) -> bool:
|
|
record.trace_id = get_current_trace_id() or "-"
|
|
return True
|
|
|
|
|
|
class JsonTraceFormatter(logging.Formatter):
|
|
"""Small JSON formatter used when ``logging.enhance.format=json``."""
|
|
|
|
_deerflow_trace_formatter = True
|
|
|
|
def format(self, record: logging.LogRecord) -> str:
|
|
if not hasattr(record, "trace_id"):
|
|
record.trace_id = get_current_trace_id() or "-"
|
|
payload: dict[str, Any] = {
|
|
"timestamp": datetime.fromtimestamp(record.created, UTC).isoformat(),
|
|
"logger": record.name,
|
|
"level": record.levelname,
|
|
"trace_id": record.trace_id,
|
|
"message": record.getMessage(),
|
|
}
|
|
if record.exc_info:
|
|
payload["exc_info"] = self.formatException(record.exc_info)
|
|
if record.stack_info:
|
|
payload["stack_info"] = self.formatStack(record.stack_info)
|
|
return json.dumps(payload, ensure_ascii=False)
|
|
|
|
|
|
class TraceTextFormatter(logging.Formatter):
|
|
"""Marker subclass so trace formatting can be reverted cleanly in tests."""
|
|
|
|
_deerflow_trace_formatter = True
|
|
|
|
|
|
def _ensure_root_handler() -> None:
|
|
if logging.root.handlers:
|
|
return
|
|
logging.basicConfig(level=logging.INFO, format=DEFAULT_LOG_FORMAT, datefmt=DEFAULT_LOG_DATE_FORMAT)
|
|
|
|
|
|
def _has_trace_filter(handler: logging.Handler) -> bool:
|
|
return any(getattr(f, "name", None) == _TRACE_FILTER_NAME or isinstance(f, TraceContextFilter) for f in handler.filters)
|
|
|
|
|
|
def _install_trace_filter(handler: logging.Handler) -> None:
|
|
if not _has_trace_filter(handler):
|
|
handler.addFilter(TraceContextFilter())
|
|
|
|
|
|
def _remove_trace_filter(handler: logging.Handler) -> None:
|
|
handler.filters = [f for f in handler.filters if not (getattr(f, "name", None) == _TRACE_FILTER_NAME or isinstance(f, TraceContextFilter))]
|
|
|
|
|
|
def _default_formatter() -> logging.Formatter:
|
|
return logging.Formatter(DEFAULT_LOG_FORMAT, datefmt=DEFAULT_LOG_DATE_FORMAT)
|
|
|
|
|
|
def _trace_formatter(format_name: str | None) -> logging.Formatter:
|
|
if (format_name or "text").strip().lower() == "json":
|
|
return JsonTraceFormatter()
|
|
return TraceTextFormatter(TRACE_TEXT_LOG_FORMAT, datefmt=DEFAULT_LOG_DATE_FORMAT)
|
|
|
|
|
|
def configure_logging(config: object) -> None:
|
|
"""Configure DeerFlow logging from an AppConfig-like object.
|
|
|
|
With logging enhancement disabled this preserves the previous
|
|
``basicConfig + apply_logging_level`` behavior. With enhancement enabled,
|
|
root handlers gain a trace-context filter and a formatter that includes
|
|
only the additional ``trace_id`` field.
|
|
"""
|
|
_ensure_root_handler()
|
|
|
|
logging_config = getattr(config, "logging", None)
|
|
enhance = getattr(logging_config, "enhance", None)
|
|
enhanced = bool(getattr(enhance, "enabled", False))
|
|
|
|
for handler in logging.root.handlers:
|
|
if enhanced:
|
|
_install_trace_filter(handler)
|
|
handler.setFormatter(_trace_formatter(getattr(enhance, "format", "text")))
|
|
else:
|
|
_remove_trace_filter(handler)
|
|
if getattr(handler.formatter, "_deerflow_trace_formatter", False):
|
|
handler.setFormatter(_default_formatter())
|
|
|
|
apply_logging_level(getattr(config, "log_level", None))
|