feat: implement Phase 2 two-tier architecture with Steward
Add comprehensive two-tier architecture where Steward analyzes requests and Tatlock executes with scoped tools. Includes full infrastructure for request preprocessing, tool tracking, benchmarking, and streaming. **Added:** - Steward agent for request analysis and capability recommendation - Household Registry for centralized capability management - Request preprocessing pipeline (Steward → Tatlock flow) - Tool usage tracking and benchmarking system - Streaming transparency (Steward reasoning visible in streams) - Structured logging with operation timing - Redis benchmark storage with 30-day expiry - Benchmark analysis CLI tools **Infrastructure:** - src/agents/steward/ - Steward agent implementation - src/agents/tatlock_core/ - Tatlock capability domain - src/core/preprocessing.py - Request preprocessing pipeline - src/core/tool_tracking.py - Tool call tracking - src/core/benchmarks.py - Benchmark recording system - src/core/household_registry.py - Capability registry - src/core/startup.py - Application startup coordination - src/core/logging_config.py - Structured logging setup **Integration:** - Responses API uses Steward for Tatlock requests - Chat Completions wraps Responses API for OpenAI compatibility - Streaming coordinator supports Steward + Tatlock flow - Tool scoping per request based on Steward recommendations **Testing:** - Integration tests for Steward-Tatlock flow - Benchmark and registry unit tests - Steward streaming tests See PHASE2_PLAN.md and PHASE2_COMPLETE.md for detailed documentation. 🤖 Generated with [Claude Code](https://claude.com/claude-code) Co-Authored-By: Claude Sonnet 4.5 <noreply@anthropic.com>
This commit is contained in:
Claude Sonnet 4.5
@@ -0,0 +1,337 @@
|
||||
"""
|
||||
Performance benchmark storage using Redis.
|
||||
|
||||
Tracks operation timing, tool usage, and recommendation accuracy across sessions.
|
||||
Provides time-series data for performance analysis and optimization.
|
||||
"""
|
||||
import json
|
||||
from datetime import datetime, timezone
|
||||
from typing import Any, Literal, Optional
|
||||
|
||||
import redis.asyncio as redis
|
||||
from pydantic import BaseModel, Field
|
||||
|
||||
from .config import config
|
||||
from .logging_config import get_logger
|
||||
|
||||
logger = get_logger(__name__)
|
||||
|
||||
|
||||
class PerformanceBenchmark(BaseModel):
|
||||
"""
|
||||
Performance benchmark record.
|
||||
|
||||
Stores timing and metadata for operations like Steward analysis,
|
||||
tool calls, and agent execution.
|
||||
"""
|
||||
timestamp: datetime = Field(default_factory=lambda: datetime.now(timezone.utc))
|
||||
operation: str # "steward_analysis", "tool_call", "tatlock_execution"
|
||||
duration_seconds: float
|
||||
success: bool
|
||||
|
||||
# Steward-specific fields
|
||||
recommendation_count: Optional[int] = None
|
||||
confidence: Optional[float] = None
|
||||
|
||||
# Tool-specific fields
|
||||
tool_name: Optional[str] = None
|
||||
was_recommended: Optional[bool] = None
|
||||
was_actually_used: Optional[bool] = None
|
||||
|
||||
# Context
|
||||
conversation_id: Optional[str] = None
|
||||
metadata: dict[str, Any] = Field(default_factory=dict)
|
||||
|
||||
def to_redis_dict(self) -> dict[str, Any]:
|
||||
"""Convert to dict suitable for Redis storage."""
|
||||
data = self.model_dump()
|
||||
data["timestamp"] = self.timestamp.isoformat()
|
||||
data["metadata"] = json.dumps(self.metadata)
|
||||
return data
|
||||
|
||||
@classmethod
|
||||
def from_redis_dict(cls, data: dict[str, Any]) -> "PerformanceBenchmark":
|
||||
"""Reconstruct from Redis dict."""
|
||||
data["timestamp"] = datetime.fromisoformat(data["timestamp"])
|
||||
data["metadata"] = json.loads(data.get("metadata", "{}"))
|
||||
return cls(**data)
|
||||
|
||||
|
||||
class BenchmarkStore:
|
||||
"""
|
||||
Redis-backed benchmark storage with automatic expiry.
|
||||
|
||||
Stores performance metrics in time-series format with 30-day retention.
|
||||
Provides querying capabilities for analysis and reporting.
|
||||
"""
|
||||
|
||||
def __init__(self, redis_client: Optional[redis.Redis] = None):
|
||||
"""
|
||||
Initialize benchmark store.
|
||||
|
||||
Args:
|
||||
redis_client: Optional Redis client. If None, creates from config.
|
||||
"""
|
||||
self._client = redis_client
|
||||
self._ttl_days = 30 # 30-day retention
|
||||
|
||||
async def _get_client(self) -> redis.Redis:
|
||||
"""Get or create Redis client."""
|
||||
if self._client is None:
|
||||
self._client = redis.from_url(
|
||||
config.redis_url,
|
||||
encoding="utf-8",
|
||||
decode_responses=True,
|
||||
socket_timeout=config.REDIS_TIMEOUT,
|
||||
socket_connect_timeout=config.REDIS_TIMEOUT,
|
||||
)
|
||||
return self._client
|
||||
|
||||
async def record(self, benchmark: PerformanceBenchmark) -> None:
|
||||
"""
|
||||
Record a performance benchmark.
|
||||
|
||||
Args:
|
||||
benchmark: Performance benchmark to record
|
||||
|
||||
Example:
|
||||
>>> await store.record(PerformanceBenchmark(
|
||||
... operation="steward_analysis",
|
||||
... duration_seconds=1.23,
|
||||
... success=True,
|
||||
... recommendation_count=3,
|
||||
... ))
|
||||
"""
|
||||
if not config.ENABLE_BENCHMARKS:
|
||||
return
|
||||
|
||||
try:
|
||||
client = await self._get_client()
|
||||
|
||||
# Generate key: benchmark:{operation}:{timestamp_ms}
|
||||
timestamp_ms = int(benchmark.timestamp.timestamp() * 1000)
|
||||
key = f"benchmark:{benchmark.operation}:{timestamp_ms}"
|
||||
|
||||
# Store as hash
|
||||
await client.hset(key, mapping=benchmark.to_redis_dict())
|
||||
|
||||
# Set expiry
|
||||
await client.expire(key, self._ttl_days * 24 * 60 * 60)
|
||||
|
||||
# Add to sorted set for time-based queries
|
||||
index_key = f"benchmark_index:{benchmark.operation}"
|
||||
await client.zadd(index_key, {key: timestamp_ms})
|
||||
await client.expire(index_key, self._ttl_days * 24 * 60 * 60)
|
||||
|
||||
logger.debug(
|
||||
"benchmark_recorded",
|
||||
operation=benchmark.operation,
|
||||
duration=benchmark.duration_seconds,
|
||||
success=benchmark.success,
|
||||
)
|
||||
|
||||
except Exception as e:
|
||||
logger.warning(
|
||||
"benchmark_recording_failed",
|
||||
error=str(e),
|
||||
operation=benchmark.operation,
|
||||
)
|
||||
# Don't fail the request if benchmarking fails
|
||||
|
||||
async def query(
|
||||
self,
|
||||
operation: str,
|
||||
start_time: Optional[datetime] = None,
|
||||
end_time: Optional[datetime] = None,
|
||||
limit: int = 100,
|
||||
) -> list[PerformanceBenchmark]:
|
||||
"""
|
||||
Query benchmarks by operation and time range.
|
||||
|
||||
Args:
|
||||
operation: Operation name to filter by
|
||||
start_time: Start of time range (inclusive)
|
||||
end_time: End of time range (inclusive)
|
||||
limit: Maximum number of results
|
||||
|
||||
Returns:
|
||||
List of benchmarks matching the query
|
||||
|
||||
Example:
|
||||
>>> from datetime import timedelta
|
||||
>>> now = datetime.now(timezone.utc)
|
||||
>>> yesterday = now - timedelta(days=1)
|
||||
>>> benchmarks = await store.query(
|
||||
... "steward_analysis",
|
||||
... start_time=yesterday,
|
||||
... limit=50
|
||||
... )
|
||||
"""
|
||||
if not config.ENABLE_BENCHMARKS:
|
||||
return []
|
||||
|
||||
try:
|
||||
client = await self._get_client()
|
||||
index_key = f"benchmark_index:{operation}"
|
||||
|
||||
# Convert time range to timestamps
|
||||
min_score = (
|
||||
int(start_time.timestamp() * 1000)
|
||||
if start_time
|
||||
else "-inf"
|
||||
)
|
||||
max_score = (
|
||||
int(end_time.timestamp() * 1000)
|
||||
if end_time
|
||||
else "+inf"
|
||||
)
|
||||
|
||||
# Query sorted set
|
||||
keys = await client.zrevrangebyscore(
|
||||
index_key,
|
||||
max_score,
|
||||
min_score,
|
||||
start=0,
|
||||
num=limit,
|
||||
)
|
||||
|
||||
# Fetch benchmark data
|
||||
benchmarks = []
|
||||
for key in keys:
|
||||
data = await client.hgetall(key)
|
||||
if data:
|
||||
benchmarks.append(PerformanceBenchmark.from_redis_dict(data))
|
||||
|
||||
return benchmarks
|
||||
|
||||
except Exception as e:
|
||||
logger.error(
|
||||
"benchmark_query_failed",
|
||||
error=str(e),
|
||||
operation=operation,
|
||||
)
|
||||
return []
|
||||
|
||||
async def get_statistics(
|
||||
self,
|
||||
operation: str,
|
||||
start_time: Optional[datetime] = None,
|
||||
end_time: Optional[datetime] = None,
|
||||
) -> dict[str, Any]:
|
||||
"""
|
||||
Get aggregate statistics for an operation.
|
||||
|
||||
Args:
|
||||
operation: Operation name
|
||||
start_time: Start of time range
|
||||
end_time: End of time range
|
||||
|
||||
Returns:
|
||||
Dictionary with statistics (count, avg_duration, success_rate, etc.)
|
||||
|
||||
Example:
|
||||
>>> stats = await store.get_statistics("steward_analysis")
|
||||
>>> print(f"Average duration: {stats['avg_duration']}s")
|
||||
>>> print(f"Success rate: {stats['success_rate']}%")
|
||||
"""
|
||||
benchmarks = await self.query(operation, start_time, end_time, limit=1000)
|
||||
|
||||
if not benchmarks:
|
||||
return {
|
||||
"count": 0,
|
||||
"avg_duration": 0.0,
|
||||
"min_duration": 0.0,
|
||||
"max_duration": 0.0,
|
||||
"success_rate": 0.0,
|
||||
}
|
||||
|
||||
durations = [b.duration_seconds for b in benchmarks]
|
||||
successes = sum(1 for b in benchmarks if b.success)
|
||||
|
||||
return {
|
||||
"count": len(benchmarks),
|
||||
"avg_duration": sum(durations) / len(durations),
|
||||
"min_duration": min(durations),
|
||||
"max_duration": max(durations),
|
||||
"success_rate": (successes / len(benchmarks)) * 100,
|
||||
"total_successes": successes,
|
||||
"total_failures": len(benchmarks) - successes,
|
||||
}
|
||||
|
||||
async def get_tool_accuracy(
|
||||
self,
|
||||
start_time: Optional[datetime] = None,
|
||||
end_time: Optional[datetime] = None,
|
||||
) -> dict[str, Any]:
|
||||
"""
|
||||
Analyze tool recommendation accuracy.
|
||||
|
||||
Compares recommended tools vs actually used tools to measure
|
||||
Steward's recommendation precision.
|
||||
|
||||
Args:
|
||||
start_time: Start of time range
|
||||
end_time: End of time range
|
||||
|
||||
Returns:
|
||||
Dictionary with accuracy metrics
|
||||
|
||||
Example:
|
||||
>>> accuracy = await store.get_tool_accuracy()
|
||||
>>> print(f"Precision: {accuracy['precision']}%")
|
||||
"""
|
||||
tool_calls = await self.query("tool_call", start_time, end_time, limit=1000)
|
||||
|
||||
if not tool_calls:
|
||||
return {
|
||||
"total_calls": 0,
|
||||
"recommended_and_used": 0,
|
||||
"recommended_not_used": 0,
|
||||
"not_recommended_but_used": 0,
|
||||
"precision": 0.0,
|
||||
}
|
||||
|
||||
recommended_and_used = sum(
|
||||
1 for b in tool_calls
|
||||
if b.was_recommended and b.was_actually_used
|
||||
)
|
||||
not_recommended_but_used = sum(
|
||||
1 for b in tool_calls
|
||||
if not b.was_recommended and b.was_actually_used
|
||||
)
|
||||
|
||||
total_used = sum(1 for b in tool_calls if b.was_actually_used)
|
||||
precision = (
|
||||
(recommended_and_used / total_used * 100) if total_used > 0 else 0.0
|
||||
)
|
||||
|
||||
return {
|
||||
"total_calls": len(tool_calls),
|
||||
"total_used": total_used,
|
||||
"recommended_and_used": recommended_and_used,
|
||||
"not_recommended_but_used": not_recommended_but_used,
|
||||
"precision": precision,
|
||||
}
|
||||
|
||||
async def close(self) -> None:
|
||||
"""Close Redis connection."""
|
||||
if self._client:
|
||||
await self._client.aclose()
|
||||
self._client = None
|
||||
|
||||
|
||||
# Global benchmark store instance
|
||||
_benchmark_store: Optional[BenchmarkStore] = None
|
||||
|
||||
|
||||
def get_benchmark_store() -> BenchmarkStore:
|
||||
"""
|
||||
Get global benchmark store instance.
|
||||
|
||||
Returns:
|
||||
BenchmarkStore instance
|
||||
"""
|
||||
global _benchmark_store
|
||||
if _benchmark_store is None:
|
||||
_benchmark_store = BenchmarkStore()
|
||||
return _benchmark_store
|
||||
+35
-1
@@ -69,9 +69,28 @@ class Config(BaseSettings):
|
||||
description="SearXNG request timeout in seconds"
|
||||
)
|
||||
|
||||
# Redis Configuration
|
||||
REDIS_HOST: str = Field(
|
||||
default="localhost",
|
||||
description="Redis server host"
|
||||
)
|
||||
REDIS_PORT: int = Field(
|
||||
default=6379,
|
||||
description="Redis server port"
|
||||
)
|
||||
REDIS_DB: int = Field(
|
||||
default=1,
|
||||
description="Redis database number"
|
||||
)
|
||||
REDIS_TIMEOUT: int = Field(
|
||||
default=5,
|
||||
description="Redis connection timeout in seconds"
|
||||
)
|
||||
|
||||
# Logging
|
||||
LOG_LEVEL: str = Field(default="INFO", description="Logging level")
|
||||
|
||||
ENABLE_BENCHMARKS: bool = Field(default=True, description="Enable performance benchmarking")
|
||||
|
||||
# CORS
|
||||
CORS_ORIGINS: list[str] = Field(
|
||||
default=["*"],
|
||||
@@ -81,6 +100,21 @@ class Config(BaseSettings):
|
||||
CORS_ALLOW_METHODS: list[str] = ["*"]
|
||||
CORS_ALLOW_HEADERS: list[str] = ["*"]
|
||||
|
||||
@property
|
||||
def redis_url(self) -> str:
|
||||
"""Construct Redis connection URL."""
|
||||
return f"redis://{self.REDIS_HOST}:{self.REDIS_PORT}/{self.REDIS_DB}"
|
||||
|
||||
@property
|
||||
def log_format(self) -> str:
|
||||
"""
|
||||
Determine log format based on environment.
|
||||
|
||||
- production: JSON format for machine parsing
|
||||
- development/testing: Console format for human readability
|
||||
"""
|
||||
return "json" if self.ENVIRONMENT == Environment.PRODUCTION else "console"
|
||||
|
||||
|
||||
@lru_cache
|
||||
def get_config() -> Config:
|
||||
|
||||
@@ -0,0 +1,268 @@
|
||||
"""
|
||||
Household registry for managing agent capabilities and toolsets.
|
||||
|
||||
Provides centralized registry of household members (agents) with their
|
||||
capabilities and tools. Supports two-tier abstraction: executive summaries
|
||||
for coordination and full toolsets for execution.
|
||||
"""
|
||||
from typing import Any, Optional
|
||||
|
||||
from pydantic import BaseModel, ConfigDict
|
||||
from pydantic_ai import Agent
|
||||
|
||||
from .logging_config import get_logger
|
||||
|
||||
logger = get_logger(__name__)
|
||||
|
||||
|
||||
class HouseholdCapability(BaseModel):
|
||||
"""
|
||||
Executive summary of a household member's capabilities.
|
||||
|
||||
This is what the Steward and Butler see for coordination.
|
||||
High-level description without implementation details.
|
||||
"""
|
||||
name: str # Unique identifier: "tatlock_core", "librarian", "developer"
|
||||
role: str # Display name: "Butler's Core Tools", "The Librarian"
|
||||
category: str # "core", "research", "technical", "automation"
|
||||
description: str # One-sentence description of capabilities
|
||||
domains: list[str] # Capability domains: ["computation", "information", "datetime"]
|
||||
cost: str # "low", "medium", "high" - resource cost estimate
|
||||
requires_network: bool # Whether network access is needed
|
||||
|
||||
|
||||
class HouseholdMember(BaseModel):
|
||||
"""
|
||||
Full specification of a household member.
|
||||
|
||||
Contains both the executive summary (for coordination) and
|
||||
implementation details (tools/agent).
|
||||
"""
|
||||
model_config = ConfigDict(arbitrary_types_allowed=True)
|
||||
|
||||
capability: HouseholdCapability
|
||||
tools: list[Any] # PydanticAI tool definitions (any type since Tool is a dataclass)
|
||||
agent: Optional[Any] = None # For expert agents (Phase 4)
|
||||
|
||||
|
||||
class HouseholdRegistry:
|
||||
"""
|
||||
Registry of household capabilities and implementations.
|
||||
|
||||
Manages household members and their tools. Provides:
|
||||
1. Executive summaries for Steward/Butler coordination
|
||||
2. Full toolsets for scoped execution
|
||||
3. Agent delegation (Phase 4)
|
||||
"""
|
||||
|
||||
def __init__(self):
|
||||
"""Initialize empty registry."""
|
||||
self._members: dict[str, HouseholdMember] = {}
|
||||
logger.info("household_registry_initialized")
|
||||
|
||||
def register(
|
||||
self,
|
||||
name: str,
|
||||
capability: HouseholdCapability,
|
||||
tools: list[Any],
|
||||
agent: Optional[Any] = None,
|
||||
) -> None:
|
||||
"""
|
||||
Register a household member.
|
||||
|
||||
Args:
|
||||
name: Unique identifier (must match capability.name)
|
||||
capability: Executive summary
|
||||
tools: PydanticAI tool definitions
|
||||
agent: Optional expert agent for delegation
|
||||
|
||||
Raises:
|
||||
ValueError: If name doesn't match capability.name
|
||||
|
||||
Example:
|
||||
>>> registry.register(
|
||||
... name="tatlock_core",
|
||||
... capability=HouseholdCapability(
|
||||
... name="tatlock_core",
|
||||
... role="Butler's Core Tools",
|
||||
... category="core",
|
||||
... description="Basic computation, time, and information tools",
|
||||
... domains=["computation", "datetime", "information"],
|
||||
... cost="low",
|
||||
... requires_network=True,
|
||||
... ),
|
||||
... tools=[calculator_tool, datetime_tool, search_tool],
|
||||
... )
|
||||
"""
|
||||
if name != capability.name:
|
||||
raise ValueError(
|
||||
f"Name mismatch: '{name}' != '{capability.name}'"
|
||||
)
|
||||
|
||||
self._members[name] = HouseholdMember(
|
||||
capability=capability,
|
||||
tools=tools,
|
||||
agent=agent,
|
||||
)
|
||||
|
||||
logger.info(
|
||||
"household_member_registered",
|
||||
name=name,
|
||||
role=capability.role,
|
||||
domains=capability.domains,
|
||||
tool_count=len(tools),
|
||||
has_agent=agent is not None,
|
||||
)
|
||||
|
||||
def unregister(self, name: str) -> None:
|
||||
"""
|
||||
Unregister a household member.
|
||||
|
||||
Args:
|
||||
name: Member name to remove
|
||||
|
||||
Example:
|
||||
>>> registry.unregister("tatlock_core")
|
||||
"""
|
||||
if name in self._members:
|
||||
member = self._members.pop(name)
|
||||
logger.info(
|
||||
"household_member_unregistered",
|
||||
name=name,
|
||||
role=member.capability.role,
|
||||
)
|
||||
|
||||
def get_member(self, name: str) -> Optional[HouseholdMember]:
|
||||
"""
|
||||
Get full household member specification.
|
||||
|
||||
Args:
|
||||
name: Member name
|
||||
|
||||
Returns:
|
||||
HouseholdMember if found, None otherwise
|
||||
"""
|
||||
return self._members.get(name)
|
||||
|
||||
def get_all_capabilities(self) -> list[HouseholdCapability]:
|
||||
"""
|
||||
Get executive summaries of all household members.
|
||||
|
||||
This is what the Steward sees when analyzing requests.
|
||||
Returns high-level capabilities without implementation details.
|
||||
|
||||
Returns:
|
||||
List of capability summaries
|
||||
|
||||
Example:
|
||||
>>> capabilities = registry.get_all_capabilities()
|
||||
>>> for cap in capabilities:
|
||||
... print(f"{cap.role}: {cap.description}")
|
||||
"""
|
||||
return [member.capability for member in self._members.values()]
|
||||
|
||||
def get_scoped_tools(self, names: list[str]) -> list[Any]:
|
||||
"""
|
||||
Get combined tools from specified household members.
|
||||
|
||||
Creates a scoped toolset containing only tools from
|
||||
the requested members. Used to give Tatlock only the
|
||||
tools recommended by the Steward.
|
||||
|
||||
Args:
|
||||
names: List of member names to include
|
||||
|
||||
Returns:
|
||||
Combined list of tool definitions
|
||||
|
||||
Example:
|
||||
>>> # Steward recommends only tatlock_core
|
||||
>>> tools = registry.get_scoped_tools(["tatlock_core"])
|
||||
>>> # Tatlock now has only core tools, not all household tools
|
||||
"""
|
||||
tools = []
|
||||
for name in names:
|
||||
member = self._members.get(name)
|
||||
if member:
|
||||
tools.extend(member.tools)
|
||||
else:
|
||||
logger.warning(
|
||||
"household_member_not_found",
|
||||
requested_name=name,
|
||||
available_names=list(self._members.keys()),
|
||||
)
|
||||
|
||||
logger.debug(
|
||||
"scoped_tools_created",
|
||||
requested_members=names,
|
||||
total_tools=len(tools),
|
||||
)
|
||||
|
||||
return tools
|
||||
|
||||
def list_members(self) -> list[str]:
|
||||
"""
|
||||
List all registered member names.
|
||||
|
||||
Returns:
|
||||
List of member names
|
||||
"""
|
||||
return list(self._members.keys())
|
||||
|
||||
def get_members_by_domain(self, domain: str) -> list[HouseholdCapability]:
|
||||
"""
|
||||
Get capabilities that support a specific domain.
|
||||
|
||||
Args:
|
||||
domain: Domain to filter by (e.g., "computation", "research")
|
||||
|
||||
Returns:
|
||||
List of capabilities supporting the domain
|
||||
|
||||
Example:
|
||||
>>> # Find all members that can do research
|
||||
>>> research_caps = registry.get_members_by_domain("research")
|
||||
"""
|
||||
return [
|
||||
member.capability
|
||||
for member in self._members.values()
|
||||
if domain in member.capability.domains
|
||||
]
|
||||
|
||||
def get_members_by_category(self, category: str) -> list[HouseholdCapability]:
|
||||
"""
|
||||
Get capabilities by category.
|
||||
|
||||
Args:
|
||||
category: Category to filter by (e.g., "core", "research", "technical")
|
||||
|
||||
Returns:
|
||||
List of capabilities in the category
|
||||
"""
|
||||
return [
|
||||
member.capability
|
||||
for member in self._members.values()
|
||||
if member.capability.category == category
|
||||
]
|
||||
|
||||
def __len__(self) -> int:
|
||||
"""Get number of registered members."""
|
||||
return len(self._members)
|
||||
|
||||
def __contains__(self, name: str) -> bool:
|
||||
"""Check if member is registered."""
|
||||
return name in self._members
|
||||
|
||||
|
||||
# Global registry instance
|
||||
household_registry = HouseholdRegistry()
|
||||
|
||||
|
||||
def get_household_registry() -> HouseholdRegistry:
|
||||
"""
|
||||
Get global household registry instance.
|
||||
|
||||
Returns:
|
||||
HouseholdRegistry instance
|
||||
"""
|
||||
return household_registry
|
||||
@@ -0,0 +1,252 @@
|
||||
"""
|
||||
Structured logging configuration using structlog.
|
||||
|
||||
Deeply integrates with FastAPI/uvicorn's built-in logging to provide
|
||||
seamless structured logs across the entire application stack.
|
||||
"""
|
||||
import logging
|
||||
import logging.config
|
||||
import sys
|
||||
from contextlib import asynccontextmanager
|
||||
from datetime import datetime, timezone
|
||||
from typing import Any, AsyncIterator
|
||||
|
||||
import structlog
|
||||
from structlog.types import EventDict, Processor
|
||||
|
||||
from .config import config
|
||||
|
||||
|
||||
def add_timestamp(logger: Any, method_name: str, event_dict: EventDict) -> EventDict:
|
||||
"""Add ISO 8601 timestamp to log entries."""
|
||||
event_dict["timestamp"] = datetime.now(timezone.utc).isoformat()
|
||||
return event_dict
|
||||
|
||||
|
||||
def add_log_level(logger: Any, method_name: str, event_dict: EventDict) -> EventDict:
|
||||
"""Add log level to event dict."""
|
||||
event_dict["level"] = method_name.upper()
|
||||
return event_dict
|
||||
|
||||
|
||||
def extract_from_record(logger: Any, method_name: str, event_dict: EventDict) -> EventDict:
|
||||
"""
|
||||
Extract extra fields from logging.LogRecord for standard library integration.
|
||||
|
||||
This allows standard Python logging calls to include structured data:
|
||||
logger.info("request received", extra={"user_id": "123", "path": "/api"})
|
||||
"""
|
||||
record = event_dict.get("_record")
|
||||
if record is not None:
|
||||
# Extract custom fields from record
|
||||
for key, value in record.__dict__.items():
|
||||
if key not in {
|
||||
"name", "msg", "args", "created", "filename", "funcName",
|
||||
"levelname", "levelno", "lineno", "module", "msecs",
|
||||
"message", "pathname", "process", "processName", "relativeCreated",
|
||||
"thread", "threadName", "exc_info", "exc_text", "stack_info",
|
||||
"taskName"
|
||||
}:
|
||||
event_dict[key] = value
|
||||
|
||||
return event_dict
|
||||
|
||||
|
||||
def configure_logging() -> None:
|
||||
"""
|
||||
Configure structured logging with deep FastAPI/uvicorn integration.
|
||||
|
||||
- Replaces all Python logging with structlog
|
||||
- FastAPI, uvicorn, and app logs all use same format
|
||||
- JSON format for production, pretty console for development
|
||||
- Preserves log levels and exception handling
|
||||
"""
|
||||
# Determine processors based on log format
|
||||
shared_processors: list[Processor] = [
|
||||
structlog.contextvars.merge_contextvars,
|
||||
structlog.stdlib.add_logger_name,
|
||||
add_log_level,
|
||||
add_timestamp,
|
||||
structlog.stdlib.PositionalArgumentsFormatter(),
|
||||
structlog.processors.StackInfoRenderer(),
|
||||
extract_from_record,
|
||||
]
|
||||
|
||||
if config.log_format == "json":
|
||||
# JSON format for production
|
||||
structlog.configure(
|
||||
processors=[
|
||||
structlog.stdlib.filter_by_level,
|
||||
*shared_processors,
|
||||
structlog.stdlib.ProcessorFormatter.wrap_for_formatter,
|
||||
],
|
||||
logger_factory=structlog.stdlib.LoggerFactory(),
|
||||
wrapper_class=structlog.stdlib.BoundLogger,
|
||||
cache_logger_on_first_use=True,
|
||||
)
|
||||
|
||||
formatter = structlog.stdlib.ProcessorFormatter(
|
||||
processors=[
|
||||
structlog.stdlib.ProcessorFormatter.remove_processors_meta,
|
||||
structlog.processors.format_exc_info,
|
||||
structlog.processors.JSONRenderer(),
|
||||
],
|
||||
foreign_pre_chain=shared_processors,
|
||||
)
|
||||
else:
|
||||
# Console format for development
|
||||
structlog.configure(
|
||||
processors=[
|
||||
structlog.stdlib.filter_by_level,
|
||||
*shared_processors,
|
||||
structlog.stdlib.ProcessorFormatter.wrap_for_formatter,
|
||||
],
|
||||
logger_factory=structlog.stdlib.LoggerFactory(),
|
||||
wrapper_class=structlog.stdlib.BoundLogger,
|
||||
cache_logger_on_first_use=True,
|
||||
)
|
||||
|
||||
formatter = structlog.stdlib.ProcessorFormatter(
|
||||
processors=[
|
||||
structlog.stdlib.ProcessorFormatter.remove_processors_meta,
|
||||
structlog.dev.ConsoleRenderer(colors=True),
|
||||
],
|
||||
foreign_pre_chain=shared_processors,
|
||||
)
|
||||
|
||||
# Configure Python's logging to use structlog
|
||||
handler = logging.StreamHandler(sys.stdout)
|
||||
handler.setFormatter(formatter)
|
||||
|
||||
# Set up root logger
|
||||
root_logger = logging.getLogger()
|
||||
root_logger.handlers.clear()
|
||||
root_logger.addHandler(handler)
|
||||
root_logger.setLevel(logging.getLevelName(config.LOG_LEVEL))
|
||||
|
||||
# Configure specific loggers
|
||||
for logger_name in [
|
||||
"uvicorn",
|
||||
"uvicorn.access",
|
||||
"uvicorn.error",
|
||||
"fastapi",
|
||||
"tatlock",
|
||||
]:
|
||||
logger = logging.getLogger(logger_name)
|
||||
logger.handlers.clear()
|
||||
logger.propagate = True
|
||||
logger.setLevel(logging.getLevelName(config.LOG_LEVEL))
|
||||
|
||||
|
||||
def get_logger(name: str) -> structlog.stdlib.BoundLogger:
|
||||
"""
|
||||
Get a structured logger instance.
|
||||
|
||||
Works seamlessly with both structlog and standard logging calls:
|
||||
- logger.info("message", key="value") - structlog style
|
||||
- logger.info("message", extra={"key": "value"}) - standard logging style
|
||||
|
||||
Args:
|
||||
name: Logger name (typically __name__)
|
||||
|
||||
Returns:
|
||||
Configured structlog BoundLogger
|
||||
|
||||
Example:
|
||||
>>> logger = get_logger(__name__)
|
||||
>>> logger.info("user_request", user_id="123", action="search")
|
||||
>>> logger.info("standard log", extra={"request_id": "abc"})
|
||||
"""
|
||||
return structlog.get_logger(name)
|
||||
|
||||
|
||||
@asynccontextmanager
|
||||
async def log_operation(
|
||||
operation: str,
|
||||
initial_context: dict[str, Any] | None = None,
|
||||
logger_name: str = "tatlock.operations"
|
||||
) -> AsyncIterator[dict[str, Any]]:
|
||||
"""
|
||||
Context manager for automatic operation timing and logging.
|
||||
|
||||
Args:
|
||||
operation: Operation name (e.g., "steward_analysis", "tool_call")
|
||||
initial_context: Initial metadata to log
|
||||
logger_name: Logger name for this operation
|
||||
|
||||
Yields:
|
||||
Context dict that can be updated during operation
|
||||
|
||||
Example:
|
||||
>>> async with log_operation("steward_analysis", {"user_id": "123"}) as ctx:
|
||||
... # Do work
|
||||
... ctx["recommendation_count"] = 3
|
||||
... # Automatically logs duration and context on exit
|
||||
"""
|
||||
logger = get_logger(logger_name)
|
||||
context = initial_context or {}
|
||||
context["operation"] = operation
|
||||
|
||||
start_time = datetime.now(timezone.utc)
|
||||
logger.info("operation_started", **context)
|
||||
|
||||
try:
|
||||
yield context
|
||||
|
||||
# Success case
|
||||
duration = (datetime.now(timezone.utc) - start_time).total_seconds()
|
||||
context["duration_seconds"] = duration
|
||||
context["success"] = True
|
||||
logger.info("operation_completed", **context)
|
||||
|
||||
except Exception as e:
|
||||
# Error case
|
||||
duration = (datetime.now(timezone.utc) - start_time).total_seconds()
|
||||
context["duration_seconds"] = duration
|
||||
context["success"] = False
|
||||
context["error"] = str(e)
|
||||
context["error_type"] = type(e).__name__
|
||||
logger.error("operation_failed", **context, exc_info=True)
|
||||
raise
|
||||
|
||||
|
||||
def get_uvicorn_log_config() -> dict[str, Any]:
|
||||
"""
|
||||
Get uvicorn logging configuration that integrates with structlog.
|
||||
|
||||
Use this when starting uvicorn:
|
||||
uvicorn.run(app, log_config=get_uvicorn_log_config())
|
||||
|
||||
Returns:
|
||||
Uvicorn-compatible logging configuration dict
|
||||
"""
|
||||
return {
|
||||
"version": 1,
|
||||
"disable_existing_loggers": False,
|
||||
"formatters": {
|
||||
"default": {
|
||||
"()": structlog.stdlib.ProcessorFormatter,
|
||||
"processors": [
|
||||
structlog.stdlib.ProcessorFormatter.remove_processors_meta,
|
||||
structlog.processors.JSONRenderer() if config.log_format == "json"
|
||||
else structlog.dev.ConsoleRenderer(colors=True),
|
||||
],
|
||||
},
|
||||
},
|
||||
"handlers": {
|
||||
"default": {
|
||||
"formatter": "default",
|
||||
"class": "logging.StreamHandler",
|
||||
"stream": "ext://sys.stdout",
|
||||
},
|
||||
},
|
||||
"loggers": {
|
||||
"uvicorn": {"handlers": ["default"], "level": config.LOG_LEVEL},
|
||||
"uvicorn.error": {"handlers": ["default"], "level": config.LOG_LEVEL},
|
||||
"uvicorn.access": {"handlers": ["default"], "level": config.LOG_LEVEL},
|
||||
},
|
||||
}
|
||||
|
||||
|
||||
# Initialize logging on module import
|
||||
configure_logging()
|
||||
@@ -0,0 +1,105 @@
|
||||
"""
|
||||
Request preprocessing pipeline.
|
||||
|
||||
Analyzes requests via the Steward and creates scoped toolsets for Tatlock.
|
||||
"""
|
||||
from dataclasses import dataclass
|
||||
from typing import Any, Optional
|
||||
|
||||
from src.agents.steward import analyze_request, format_steward_note
|
||||
from src.agents.steward.schemas import StewardRecommendation
|
||||
from src.core.household_registry import get_household_registry
|
||||
from src.core.logging_config import get_logger
|
||||
|
||||
logger = get_logger(__name__)
|
||||
|
||||
|
||||
@dataclass
|
||||
class EnrichedRequest:
|
||||
"""
|
||||
Request enriched with Steward's analysis.
|
||||
|
||||
Attributes:
|
||||
original_request: The user's original message
|
||||
steward_note: Formatted note for Tatlock (includes context analysis)
|
||||
scoped_tools: List of tools from recommended capabilities
|
||||
recommendation: Full Steward recommendation
|
||||
steward_reasoning: Plain text reasoning for streaming to user
|
||||
"""
|
||||
original_request: str
|
||||
steward_note: str
|
||||
scoped_tools: list[Any] # PydanticAI tool definitions
|
||||
recommendation: StewardRecommendation
|
||||
steward_reasoning: str
|
||||
|
||||
|
||||
async def preprocess_request(
|
||||
user_request: str,
|
||||
conversation_history: list[dict],
|
||||
conversation_id: Optional[str] = None,
|
||||
) -> EnrichedRequest:
|
||||
"""
|
||||
Analyze request via Steward and prepare scoped context for Tatlock.
|
||||
|
||||
This is the main preprocessing pipeline that:
|
||||
1. Calls Steward with full conversation history
|
||||
2. Gets capability recommendations
|
||||
3. Creates scoped toolset from recommended capabilities
|
||||
4. Formats a note for Tatlock with context analysis
|
||||
|
||||
Args:
|
||||
user_request: Current user message to analyze
|
||||
conversation_history: Full conversation history (all previous turns)
|
||||
conversation_id: Optional conversation ID for tracking
|
||||
|
||||
Returns:
|
||||
EnrichedRequest with scoped tools and Steward analysis
|
||||
|
||||
Example:
|
||||
>>> enriched = await preprocess_request(
|
||||
... "What's sqrt(144)?",
|
||||
... conversation_history=[],
|
||||
... )
|
||||
>>> print(enriched.recommendation.recommended_capabilities)
|
||||
['tatlock_core']
|
||||
>>> print(len(enriched.scoped_tools))
|
||||
5 # All tatlock_core tools
|
||||
"""
|
||||
logger.info(
|
||||
"preprocessing_request",
|
||||
request_preview=user_request[:100],
|
||||
history_length=len(conversation_history),
|
||||
conversation_id=conversation_id,
|
||||
)
|
||||
|
||||
# Call Steward with full conversation history
|
||||
recommendation = await analyze_request(
|
||||
user_request,
|
||||
conversation_history=conversation_history,
|
||||
conversation_id=conversation_id,
|
||||
)
|
||||
|
||||
# Format note for Tatlock (includes conversation context)
|
||||
steward_note = await format_steward_note(recommendation)
|
||||
|
||||
# Get scoped tools from household registry
|
||||
registry = get_household_registry()
|
||||
scoped_tools = registry.get_scoped_tools(
|
||||
recommendation.recommended_capabilities
|
||||
)
|
||||
|
||||
logger.info(
|
||||
"preprocessing_complete",
|
||||
recommended_capabilities=recommendation.recommended_capabilities,
|
||||
tool_count=len(scoped_tools),
|
||||
complexity=recommendation.estimated_complexity,
|
||||
has_context=recommendation.conversation_context.has_previous_context,
|
||||
)
|
||||
|
||||
return EnrichedRequest(
|
||||
original_request=user_request,
|
||||
steward_note=steward_note,
|
||||
scoped_tools=scoped_tools,
|
||||
recommendation=recommendation,
|
||||
steward_reasoning=recommendation.reasoning,
|
||||
)
|
||||
@@ -0,0 +1,70 @@
|
||||
"""
|
||||
Application startup module.
|
||||
|
||||
Handles initialization of household registry and other startup tasks.
|
||||
This module should be called during application startup to register
|
||||
all household members.
|
||||
"""
|
||||
from src.agents.tatlock_core import TATLOCK_CORE_CAPABILITY, tatlock_core_tools
|
||||
from src.core.household_registry import get_household_registry
|
||||
from src.core.logging_config import get_logger
|
||||
|
||||
logger = get_logger(__name__)
|
||||
|
||||
|
||||
def register_household_members():
|
||||
"""
|
||||
Register all household members with the registry.
|
||||
|
||||
This function should be called during application startup to make
|
||||
household capabilities available to the Steward.
|
||||
|
||||
Currently registers:
|
||||
- tatlock_core: Butler's core tools (calculator, datetime, web search)
|
||||
|
||||
Future phases will add:
|
||||
- librarian: Research and knowledge management
|
||||
- developer: Software development assistance
|
||||
- etc.
|
||||
"""
|
||||
registry = get_household_registry()
|
||||
|
||||
logger.info("household_registration_starting")
|
||||
|
||||
# Register Tatlock's core tools
|
||||
registry.register(
|
||||
name="tatlock_core",
|
||||
capability=TATLOCK_CORE_CAPABILITY,
|
||||
tools=tatlock_core_tools,
|
||||
agent=None, # No expert agent for core tools
|
||||
)
|
||||
|
||||
logger.info(
|
||||
"household_member_registered",
|
||||
name="tatlock_core",
|
||||
tool_count=len(tatlock_core_tools),
|
||||
)
|
||||
|
||||
logger.info(
|
||||
"household_registration_complete",
|
||||
total_members=len(registry),
|
||||
)
|
||||
|
||||
|
||||
def initialize_application():
|
||||
"""
|
||||
Initialize the application.
|
||||
|
||||
Performs all startup tasks:
|
||||
1. Register household members
|
||||
2. (Future) Initialize connections
|
||||
3. (Future) Load configuration
|
||||
|
||||
This should be called once during application startup.
|
||||
"""
|
||||
logger.info("application_initialization_starting")
|
||||
|
||||
# Register household members
|
||||
register_household_members()
|
||||
|
||||
logger.info("application_initialization_complete")
|
||||
@@ -0,0 +1,164 @@
|
||||
"""
|
||||
Tool call tracking and benchmarking.
|
||||
|
||||
Tracks which tools are recommended by the Steward versus which tools
|
||||
are actually used by Tatlock, recording benchmarks for analysis.
|
||||
"""
|
||||
from datetime import datetime, timezone
|
||||
from typing import Optional
|
||||
|
||||
from src.core.benchmarks import PerformanceBenchmark, get_benchmark_store
|
||||
from src.core.logging_config import get_logger
|
||||
|
||||
logger = get_logger(__name__)
|
||||
|
||||
|
||||
class ToolCallTracker:
|
||||
"""
|
||||
Tracks tool calls for benchmarking and accuracy analysis.
|
||||
|
||||
Compares Steward's recommendations with Tatlock's actual tool usage
|
||||
to measure recommendation accuracy.
|
||||
"""
|
||||
|
||||
def __init__(
|
||||
self,
|
||||
recommended_capabilities: list[str],
|
||||
conversation_id: Optional[str] = None
|
||||
):
|
||||
"""
|
||||
Initialize tool call tracker.
|
||||
|
||||
Args:
|
||||
recommended_capabilities: List of capability names recommended by Steward
|
||||
conversation_id: Optional conversation ID for tracking
|
||||
"""
|
||||
self.recommended_capabilities = set(recommended_capabilities)
|
||||
self.actual_calls: dict[str, list[float]] = {} # tool_name -> [durations]
|
||||
self.conversation_id = conversation_id
|
||||
|
||||
logger.debug(
|
||||
"tool_tracker_initialized",
|
||||
recommended=list(self.recommended_capabilities),
|
||||
conversation_id=conversation_id,
|
||||
)
|
||||
|
||||
async def track_call(self, tool_name: str, duration: float):
|
||||
"""
|
||||
Record a tool call with timing.
|
||||
|
||||
Args:
|
||||
tool_name: Name of the tool that was called
|
||||
duration: Duration of the call in seconds
|
||||
"""
|
||||
# Record the call
|
||||
if tool_name not in self.actual_calls:
|
||||
self.actual_calls[tool_name] = []
|
||||
self.actual_calls[tool_name].append(duration)
|
||||
|
||||
# Check if tool was recommended
|
||||
was_recommended = tool_name in self.recommended_capabilities
|
||||
|
||||
if not was_recommended:
|
||||
logger.warning(
|
||||
"tool_call_not_recommended",
|
||||
tool_name=tool_name,
|
||||
duration=duration,
|
||||
recommended=list(self.recommended_capabilities),
|
||||
)
|
||||
|
||||
# Record benchmark to Redis
|
||||
benchmark = PerformanceBenchmark(
|
||||
timestamp=datetime.now(timezone.utc),
|
||||
operation="tool_call",
|
||||
duration_seconds=duration,
|
||||
success=True, # If we got here, the call succeeded
|
||||
tool_name=tool_name,
|
||||
was_recommended=was_recommended,
|
||||
was_actually_used=True,
|
||||
conversation_id=self.conversation_id,
|
||||
metadata={
|
||||
"recommended_capabilities": list(self.recommended_capabilities),
|
||||
},
|
||||
)
|
||||
|
||||
await get_benchmark_store().record(benchmark)
|
||||
|
||||
logger.debug(
|
||||
"tool_call_tracked",
|
||||
tool_name=tool_name,
|
||||
duration=duration,
|
||||
was_recommended=was_recommended,
|
||||
)
|
||||
|
||||
async def finalize(self):
|
||||
"""
|
||||
Finalize tracking and log unused recommended tools.
|
||||
|
||||
Called after Tatlock completes its response to identify
|
||||
tools that were recommended but never used.
|
||||
"""
|
||||
# Find tools that were recommended but not used
|
||||
unused_tools = self.recommended_capabilities - set(self.actual_calls.keys())
|
||||
|
||||
if unused_tools:
|
||||
logger.info(
|
||||
"recommended_tools_unused",
|
||||
unused=list(unused_tools),
|
||||
used=list(self.actual_calls.keys()),
|
||||
conversation_id=self.conversation_id,
|
||||
)
|
||||
|
||||
# Record benchmarks for unused recommendations
|
||||
for tool_name in unused_tools:
|
||||
benchmark = PerformanceBenchmark(
|
||||
timestamp=datetime.now(timezone.utc),
|
||||
operation="tool_call",
|
||||
duration_seconds=0.0, # Not used
|
||||
success=True,
|
||||
tool_name=tool_name,
|
||||
was_recommended=True,
|
||||
was_actually_used=False,
|
||||
conversation_id=self.conversation_id,
|
||||
metadata={
|
||||
"recommended_capabilities": list(self.recommended_capabilities),
|
||||
"reason": "recommended_but_unused",
|
||||
},
|
||||
)
|
||||
await get_benchmark_store().record(benchmark)
|
||||
|
||||
# Log summary
|
||||
total_calls = sum(len(durations) for durations in self.actual_calls.values())
|
||||
logger.info(
|
||||
"tool_tracking_finalized",
|
||||
total_calls=total_calls,
|
||||
unique_tools_used=len(self.actual_calls),
|
||||
recommended_count=len(self.recommended_capabilities),
|
||||
unused_count=len(unused_tools),
|
||||
)
|
||||
|
||||
def get_summary(self) -> dict:
|
||||
"""
|
||||
Get tracking summary for debugging.
|
||||
|
||||
Returns:
|
||||
Dict with tracking statistics
|
||||
"""
|
||||
total_calls = sum(len(durations) for durations in self.actual_calls.values())
|
||||
unused = self.recommended_capabilities - set(self.actual_calls.keys())
|
||||
|
||||
return {
|
||||
"recommended_capabilities": list(self.recommended_capabilities),
|
||||
"tools_used": list(self.actual_calls.keys()),
|
||||
"tools_unused": list(unused),
|
||||
"total_calls": total_calls,
|
||||
"accuracy": {
|
||||
"recommended_and_used": len(
|
||||
self.recommended_capabilities & set(self.actual_calls.keys())
|
||||
),
|
||||
"recommended_but_unused": len(unused),
|
||||
"not_recommended_but_used": len(
|
||||
set(self.actual_calls.keys()) - self.recommended_capabilities
|
||||
),
|
||||
},
|
||||
}
|
||||
Reference in New Issue
Block a user