Compare commits
3
Commits
| Author | SHA1 | Date | |
|---|---|---|---|
|
|
21df52b681 | ||
|
|
666f53d5c0 | ||
|
|
0699ba3280 |
@@ -400,13 +400,17 @@ class LLMProvider:
|
||||
output_tokens = usage.completion_tokens or 0 if usage else 0
|
||||
total_tokens = usage.total_tokens or 0 if usage else 0
|
||||
|
||||
if usage:
|
||||
get_metrics_collector().record_tokens(
|
||||
operation=scope,
|
||||
bank_id="llm",
|
||||
input_tokens=input_tokens,
|
||||
output_tokens=output_tokens,
|
||||
)
|
||||
# Record LLM metrics
|
||||
metrics = get_metrics_collector()
|
||||
metrics.record_llm_call(
|
||||
provider=self.provider,
|
||||
model=self.model,
|
||||
scope=scope,
|
||||
duration=duration,
|
||||
input_tokens=input_tokens,
|
||||
output_tokens=output_tokens,
|
||||
success=True,
|
||||
)
|
||||
|
||||
# Log slow calls
|
||||
if duration > 10.0 and usage:
|
||||
@@ -559,24 +563,28 @@ class LLMProvider:
|
||||
else:
|
||||
result = content
|
||||
|
||||
# Record token usage metrics
|
||||
# Record metrics and log slow calls
|
||||
duration = time.time() - start_time
|
||||
input_tokens = response.usage.input_tokens or 0 if response.usage else 0
|
||||
output_tokens = response.usage.output_tokens or 0 if response.usage else 0
|
||||
total_tokens = input_tokens + output_tokens
|
||||
|
||||
if response.usage:
|
||||
get_metrics_collector().record_tokens(
|
||||
operation="memory",
|
||||
bank_id="llm",
|
||||
input_tokens=input_tokens,
|
||||
output_tokens=output_tokens,
|
||||
)
|
||||
# Record LLM metrics
|
||||
metrics = get_metrics_collector()
|
||||
metrics.record_llm_call(
|
||||
provider=self.provider,
|
||||
model=self.model,
|
||||
scope="memory",
|
||||
duration=duration,
|
||||
input_tokens=input_tokens,
|
||||
output_tokens=output_tokens,
|
||||
success=True,
|
||||
)
|
||||
|
||||
# Log slow calls
|
||||
if duration > 10.0 and response.usage:
|
||||
if duration > 10.0:
|
||||
logger.info(
|
||||
f"slow llm call: model={self.provider}/{self.model}, "
|
||||
f"slow llm call: scope=memory, model={self.provider}/{self.model}, "
|
||||
f"input_tokens={input_tokens}, output_tokens={output_tokens}, "
|
||||
f"time={duration:.3f}s"
|
||||
)
|
||||
@@ -719,18 +727,22 @@ class LLMProvider:
|
||||
|
||||
# Extract token usage from Ollama response
|
||||
# Ollama returns prompt_eval_count (input) and eval_count (output)
|
||||
duration = time.time() - start_time
|
||||
input_tokens = result.get("prompt_eval_count", 0) or 0
|
||||
output_tokens = result.get("eval_count", 0) or 0
|
||||
total_tokens = input_tokens + output_tokens
|
||||
|
||||
# Record to metrics
|
||||
if input_tokens > 0 or output_tokens > 0:
|
||||
get_metrics_collector().record_tokens(
|
||||
operation="memory",
|
||||
bank_id="llm",
|
||||
input_tokens=input_tokens,
|
||||
output_tokens=output_tokens,
|
||||
)
|
||||
# Record LLM metrics
|
||||
metrics = get_metrics_collector()
|
||||
metrics.record_llm_call(
|
||||
provider=self.provider,
|
||||
model=self.model,
|
||||
scope="memory",
|
||||
duration=duration,
|
||||
input_tokens=input_tokens,
|
||||
output_tokens=output_tokens,
|
||||
success=True,
|
||||
)
|
||||
|
||||
# Validate against Pydantic model or return raw JSON
|
||||
if skip_validation:
|
||||
@@ -865,7 +877,7 @@ class LLMProvider:
|
||||
else:
|
||||
result = content
|
||||
|
||||
# Record token usage metrics
|
||||
# Record metrics and log slow calls
|
||||
duration = time.time() - start_time
|
||||
input_tokens = 0
|
||||
output_tokens = 0
|
||||
@@ -873,20 +885,26 @@ class LLMProvider:
|
||||
usage = response.usage_metadata
|
||||
input_tokens = usage.prompt_token_count or 0
|
||||
output_tokens = usage.candidates_token_count or 0
|
||||
get_metrics_collector().record_tokens(
|
||||
operation="memory",
|
||||
bank_id="llm",
|
||||
input_tokens=input_tokens,
|
||||
output_tokens=output_tokens,
|
||||
)
|
||||
|
||||
# Log slow calls
|
||||
if duration > 10.0:
|
||||
logger.info(
|
||||
f"slow llm call: model={self.provider}/{self.model}, "
|
||||
f"input_tokens={input_tokens}, output_tokens={output_tokens}, "
|
||||
f"time={duration:.3f}s"
|
||||
)
|
||||
# Record LLM metrics
|
||||
metrics = get_metrics_collector()
|
||||
metrics.record_llm_call(
|
||||
provider=self.provider,
|
||||
model=self.model,
|
||||
scope="memory",
|
||||
duration=duration,
|
||||
input_tokens=input_tokens,
|
||||
output_tokens=output_tokens,
|
||||
success=True,
|
||||
)
|
||||
|
||||
# Log slow calls
|
||||
if duration > 10.0 and input_tokens > 0:
|
||||
logger.info(
|
||||
f"slow llm call: scope=memory, model={self.provider}/{self.model}, "
|
||||
f"input_tokens={input_tokens}, output_tokens={output_tokens}, "
|
||||
f"time={duration:.3f}s"
|
||||
)
|
||||
|
||||
if return_usage:
|
||||
token_usage = TokenUsage(
|
||||
|
||||
@@ -18,6 +18,7 @@ from datetime import UTC, datetime, timedelta
|
||||
from typing import TYPE_CHECKING, Any
|
||||
|
||||
from ..config import get_config
|
||||
from ..metrics import get_metrics_collector
|
||||
|
||||
# Context variable for current schema (async-safe, per-task isolation)
|
||||
_current_schema: contextvars.ContextVar[str] = contextvars.ContextVar("current_schema", default="public")
|
||||
@@ -3162,16 +3163,20 @@ Guidelines:
|
||||
|
||||
# Steps 1-3: Run multi-fact-type search (12-way retrieval: 4 methods × 3 fact types)
|
||||
recall_start = time.time()
|
||||
search_result = await self.recall_async(
|
||||
bank_id=bank_id,
|
||||
query=query,
|
||||
budget=budget,
|
||||
max_tokens=4096,
|
||||
enable_trace=False,
|
||||
fact_type=["experience", "world", "opinion"],
|
||||
include_entities=True,
|
||||
request_context=request_context,
|
||||
)
|
||||
metrics = get_metrics_collector()
|
||||
with metrics.record_operation(
|
||||
"recall", bank_id=bank_id, source="reflect", budget=budget.value if budget else None
|
||||
):
|
||||
search_result = await self.recall_async(
|
||||
bank_id=bank_id,
|
||||
query=query,
|
||||
budget=budget,
|
||||
max_tokens=4096,
|
||||
enable_trace=False,
|
||||
fact_type=["experience", "world", "opinion"],
|
||||
include_entities=True,
|
||||
request_context=request_context,
|
||||
)
|
||||
recall_time = time.time() - recall_start
|
||||
|
||||
all_results = search_result.results
|
||||
|
||||
@@ -5,6 +5,7 @@ This module provides metrics for:
|
||||
- Operation latency (retain, recall, reflect) with percentiles
|
||||
- Token usage (input/output) per operation
|
||||
- Per-bank granularity via labels
|
||||
- LLM call latency and token usage with scope dimension
|
||||
"""
|
||||
|
||||
import logging
|
||||
@@ -14,8 +15,54 @@ from contextlib import contextmanager
|
||||
from opentelemetry import metrics
|
||||
from opentelemetry.exporter.prometheus import PrometheusMetricReader
|
||||
from opentelemetry.sdk.metrics import MeterProvider
|
||||
from opentelemetry.sdk.metrics.view import ExplicitBucketHistogramAggregation, View
|
||||
from opentelemetry.sdk.resources import Resource
|
||||
|
||||
# Custom bucket boundaries for operation duration (in seconds)
|
||||
# Fine granularity in 0-30s range where most operations complete
|
||||
DURATION_BUCKETS = (0.1, 0.25, 0.5, 0.75, 1.0, 2.0, 3.0, 5.0, 7.5, 10.0, 15.0, 20.0, 30.0, 60.0, 120.0)
|
||||
|
||||
# LLM duration buckets (finer granularity for faster LLM calls)
|
||||
LLM_DURATION_BUCKETS = (0.1, 0.25, 0.5, 1.0, 2.0, 3.0, 5.0, 10.0, 15.0, 30.0, 60.0, 120.0)
|
||||
|
||||
|
||||
def get_token_bucket(token_count: int) -> str:
|
||||
"""
|
||||
Convert a token count to a bucket label for use as a dimension.
|
||||
|
||||
This allows analyzing token usage patterns without high-cardinality issues.
|
||||
|
||||
Buckets:
|
||||
- "0-100": Very small requests/responses
|
||||
- "100-500": Small requests/responses
|
||||
- "500-1k": Medium requests/responses
|
||||
- "1k-5k": Large requests/responses
|
||||
- "5k-10k": Very large requests/responses
|
||||
- "10k-50k": Huge requests/responses
|
||||
- "50k+": Extremely large requests/responses
|
||||
|
||||
Args:
|
||||
token_count: Number of tokens
|
||||
|
||||
Returns:
|
||||
Bucket label string
|
||||
"""
|
||||
if token_count < 100:
|
||||
return "0-100"
|
||||
elif token_count < 500:
|
||||
return "100-500"
|
||||
elif token_count < 1000:
|
||||
return "500-1k"
|
||||
elif token_count < 5000:
|
||||
return "1k-5k"
|
||||
elif token_count < 10000:
|
||||
return "5k-10k"
|
||||
elif token_count < 50000:
|
||||
return "10k-50k"
|
||||
else:
|
||||
return "50k+"
|
||||
|
||||
|
||||
logger = logging.getLogger(__name__)
|
||||
|
||||
# Global meter instance
|
||||
@@ -48,8 +95,22 @@ def initialize_metrics(service_name: str = "hindsight-api", service_version: str
|
||||
# Create Prometheus metric reader
|
||||
prometheus_reader = PrometheusMetricReader()
|
||||
|
||||
# Create meter provider with Prometheus exporter
|
||||
provider = MeterProvider(resource=resource, metric_readers=[prometheus_reader])
|
||||
# Create view with custom bucket boundaries for duration histogram
|
||||
duration_view = View(
|
||||
instrument_name="hindsight.operation.duration",
|
||||
aggregation=ExplicitBucketHistogramAggregation(boundaries=DURATION_BUCKETS),
|
||||
)
|
||||
|
||||
# Create view with custom bucket boundaries for LLM duration histogram
|
||||
llm_duration_view = View(
|
||||
instrument_name="hindsight.llm.duration",
|
||||
aggregation=ExplicitBucketHistogramAggregation(boundaries=LLM_DURATION_BUCKETS),
|
||||
)
|
||||
|
||||
# Create meter provider with Prometheus exporter and custom views
|
||||
provider = MeterProvider(
|
||||
resource=resource, metric_readers=[prometheus_reader], views=[duration_view, llm_duration_view]
|
||||
)
|
||||
|
||||
# Set the global meter provider
|
||||
metrics.set_meter_provider(provider)
|
||||
@@ -71,20 +132,39 @@ class MetricsCollectorBase:
|
||||
"""Base class for metrics collectors."""
|
||||
|
||||
@contextmanager
|
||||
def record_operation(self, operation: str, bank_id: str, budget: str | None = None, max_tokens: int | None = None):
|
||||
"""Context manager to record operation duration and status."""
|
||||
raise NotImplementedError
|
||||
|
||||
def record_tokens(
|
||||
def record_operation(
|
||||
self,
|
||||
operation: str,
|
||||
bank_id: str,
|
||||
input_tokens: int = 0,
|
||||
output_tokens: int = 0,
|
||||
source: str = "api",
|
||||
budget: str | None = None,
|
||||
max_tokens: int | None = None,
|
||||
):
|
||||
"""Record token usage for an operation."""
|
||||
"""Context manager to record operation duration and status."""
|
||||
raise NotImplementedError
|
||||
|
||||
def record_llm_call(
|
||||
self,
|
||||
provider: str,
|
||||
model: str,
|
||||
scope: str,
|
||||
duration: float,
|
||||
input_tokens: int = 0,
|
||||
output_tokens: int = 0,
|
||||
success: bool = True,
|
||||
):
|
||||
"""
|
||||
Record metrics for an LLM call.
|
||||
|
||||
Args:
|
||||
provider: LLM provider name (openai, anthropic, gemini, groq, ollama, lmstudio)
|
||||
model: Model name
|
||||
scope: Scope identifier (e.g., "memory", "reflect", "entity_observation")
|
||||
duration: Call duration in seconds
|
||||
input_tokens: Number of input/prompt tokens
|
||||
output_tokens: Number of output/completion tokens
|
||||
success: Whether the call was successful
|
||||
"""
|
||||
raise NotImplementedError
|
||||
|
||||
|
||||
@@ -92,20 +172,28 @@ class NoOpMetricsCollector(MetricsCollectorBase):
|
||||
"""No-op metrics collector that does nothing. Used when metrics are disabled."""
|
||||
|
||||
@contextmanager
|
||||
def record_operation(self, operation: str, bank_id: str, budget: str | None = None, max_tokens: int | None = None):
|
||||
"""No-op context manager."""
|
||||
yield
|
||||
|
||||
def record_tokens(
|
||||
def record_operation(
|
||||
self,
|
||||
operation: str,
|
||||
bank_id: str,
|
||||
input_tokens: int = 0,
|
||||
output_tokens: int = 0,
|
||||
source: str = "api",
|
||||
budget: str | None = None,
|
||||
max_tokens: int | None = None,
|
||||
):
|
||||
"""No-op token recording."""
|
||||
"""No-op context manager."""
|
||||
yield
|
||||
|
||||
def record_llm_call(
|
||||
self,
|
||||
provider: str,
|
||||
model: str,
|
||||
scope: str,
|
||||
duration: float,
|
||||
input_tokens: int = 0,
|
||||
output_tokens: int = 0,
|
||||
success: bool = True,
|
||||
):
|
||||
"""No-op LLM call recording."""
|
||||
pass
|
||||
|
||||
|
||||
@@ -125,33 +213,52 @@ class MetricsCollector(MetricsCollectorBase):
|
||||
name="hindsight.operation.duration", description="Duration of Hindsight operations in seconds", unit="s"
|
||||
)
|
||||
|
||||
# Token usage counters
|
||||
self.tokens_input = self.meter.create_counter(
|
||||
name="hindsight.tokens.input", description="Number of input tokens consumed", unit="tokens"
|
||||
)
|
||||
|
||||
self.tokens_output = self.meter.create_counter(
|
||||
name="hindsight.tokens.output", description="Number of output tokens generated", unit="tokens"
|
||||
)
|
||||
|
||||
# Operation counter (success/failure)
|
||||
self.operation_total = self.meter.create_counter(
|
||||
name="hindsight.operation.total", description="Total number of operations executed", unit="operations"
|
||||
)
|
||||
|
||||
# LLM call latency histogram (in seconds)
|
||||
# Records duration of LLM API calls with provider, model, and scope dimensions
|
||||
self.llm_duration = self.meter.create_histogram(
|
||||
name="hindsight.llm.duration", description="Duration of LLM API calls in seconds", unit="s"
|
||||
)
|
||||
|
||||
# LLM token usage counters with bucket labels
|
||||
self.llm_tokens_input = self.meter.create_counter(
|
||||
name="hindsight.llm.tokens.input", description="Number of input tokens for LLM calls", unit="tokens"
|
||||
)
|
||||
|
||||
self.llm_tokens_output = self.meter.create_counter(
|
||||
name="hindsight.llm.tokens.output", description="Number of output tokens from LLM calls", unit="tokens"
|
||||
)
|
||||
|
||||
# LLM call counter (success/failure)
|
||||
self.llm_calls_total = self.meter.create_counter(
|
||||
name="hindsight.llm.calls.total", description="Total number of LLM API calls", unit="calls"
|
||||
)
|
||||
|
||||
@contextmanager
|
||||
def record_operation(self, operation: str, bank_id: str, budget: str | None = None, max_tokens: int | None = None):
|
||||
def record_operation(
|
||||
self,
|
||||
operation: str,
|
||||
bank_id: str,
|
||||
source: str = "api",
|
||||
budget: str | None = None,
|
||||
max_tokens: int | None = None,
|
||||
):
|
||||
"""
|
||||
Context manager to record operation duration and status.
|
||||
|
||||
Usage:
|
||||
with metrics.record_operation("recall", bank_id="user123", budget="mid", max_tokens=4096):
|
||||
with metrics.record_operation("recall", bank_id="user123", source="api", budget="mid", max_tokens=4096):
|
||||
# ... perform operation
|
||||
pass
|
||||
|
||||
Args:
|
||||
operation: Operation name (retain, recall, reflect)
|
||||
operation: Operation name (retain, recall, reflect, entity_observation)
|
||||
bank_id: Memory bank ID
|
||||
source: Source of the operation (api, reflect, internal)
|
||||
budget: Optional budget level (low, mid, high)
|
||||
max_tokens: Optional max tokens for the operation
|
||||
"""
|
||||
@@ -159,6 +266,7 @@ class MetricsCollector(MetricsCollectorBase):
|
||||
attributes = {
|
||||
"operation": operation,
|
||||
"bank_id": bank_id,
|
||||
"source": source,
|
||||
}
|
||||
if budget:
|
||||
attributes["budget"] = budget
|
||||
@@ -181,40 +289,56 @@ class MetricsCollector(MetricsCollectorBase):
|
||||
# Record operation count
|
||||
self.operation_total.add(1, attributes)
|
||||
|
||||
def record_tokens(
|
||||
def record_llm_call(
|
||||
self,
|
||||
operation: str,
|
||||
bank_id: str,
|
||||
provider: str,
|
||||
model: str,
|
||||
scope: str,
|
||||
duration: float,
|
||||
input_tokens: int = 0,
|
||||
output_tokens: int = 0,
|
||||
budget: str | None = None,
|
||||
max_tokens: int | None = None,
|
||||
success: bool = True,
|
||||
):
|
||||
"""
|
||||
Record token usage for an operation.
|
||||
Record metrics for an LLM call.
|
||||
|
||||
Args:
|
||||
operation: Operation name (retain, recall, reflect)
|
||||
bank_id: Memory bank ID
|
||||
input_tokens: Number of input tokens
|
||||
output_tokens: Number of output tokens
|
||||
budget: Optional budget level
|
||||
max_tokens: Optional max tokens for the operation
|
||||
provider: LLM provider name (openai, anthropic, gemini, groq, ollama, lmstudio)
|
||||
model: Model name
|
||||
scope: Scope identifier (e.g., "memory", "reflect", "entity_observation")
|
||||
duration: Call duration in seconds
|
||||
input_tokens: Number of input/prompt tokens
|
||||
output_tokens: Number of output/completion tokens
|
||||
success: Whether the call was successful
|
||||
"""
|
||||
attributes = {
|
||||
"operation": operation,
|
||||
"bank_id": bank_id,
|
||||
# Base attributes for all metrics
|
||||
base_attributes = {
|
||||
"provider": provider,
|
||||
"model": model,
|
||||
"scope": scope,
|
||||
"success": str(success).lower(),
|
||||
}
|
||||
if budget:
|
||||
attributes["budget"] = budget
|
||||
if max_tokens:
|
||||
attributes["max_tokens"] = str(max_tokens)
|
||||
|
||||
# Record duration
|
||||
self.llm_duration.record(duration, base_attributes)
|
||||
|
||||
# Record call count
|
||||
self.llm_calls_total.add(1, base_attributes)
|
||||
|
||||
# Record tokens with bucket labels for cardinality control
|
||||
if input_tokens > 0:
|
||||
self.tokens_input.add(input_tokens, attributes)
|
||||
input_attributes = {
|
||||
**base_attributes,
|
||||
"token_bucket": get_token_bucket(input_tokens),
|
||||
}
|
||||
self.llm_tokens_input.add(input_tokens, input_attributes)
|
||||
|
||||
if output_tokens > 0:
|
||||
self.tokens_output.add(output_tokens, attributes)
|
||||
output_attributes = {
|
||||
**base_attributes,
|
||||
"token_bucket": get_token_bucket(output_tokens),
|
||||
}
|
||||
self.llm_tokens_output.add(output_tokens, output_attributes)
|
||||
|
||||
|
||||
# Global metrics collector instance (defaults to no-op)
|
||||
|
||||
@@ -9,8 +9,6 @@ from hindsight_api.metrics import (
|
||||
MetricsCollector,
|
||||
NoOpMetricsCollector,
|
||||
get_metrics_collector,
|
||||
initialize_metrics,
|
||||
create_metrics_collector,
|
||||
)
|
||||
|
||||
|
||||
@@ -20,16 +18,16 @@ def get_groq_api_key() -> str | None:
|
||||
|
||||
|
||||
@pytest.mark.asyncio
|
||||
async def test_token_metrics_recorded_for_groq():
|
||||
async def test_llm_metrics_recorded_for_groq():
|
||||
"""
|
||||
Test that token metrics are recorded when making LLM calls via Groq.
|
||||
Test that LLM metrics are recorded when making LLM calls via Groq.
|
||||
Uses openai/gpt-oss-20b as recommended by Hindsight.
|
||||
"""
|
||||
api_key = get_groq_api_key()
|
||||
if not api_key:
|
||||
pytest.skip("Skipping: GROQ_API_KEY not set")
|
||||
|
||||
# Create a mock metrics collector to track record_tokens calls
|
||||
# Create a mock metrics collector to track record_llm_call calls
|
||||
mock_collector = MagicMock(spec=MetricsCollector)
|
||||
|
||||
with patch("hindsight_api.engine.llm_wrapper.get_metrics_collector", return_value=mock_collector):
|
||||
@@ -50,30 +48,35 @@ async def test_token_metrics_recorded_for_groq():
|
||||
scope="test_metrics",
|
||||
)
|
||||
|
||||
# Verify record_tokens was called - this is the main test
|
||||
assert mock_collector.record_tokens.called, "record_tokens should have been called"
|
||||
# Verify record_llm_call was called - this is the main test
|
||||
assert mock_collector.record_llm_call.called, "record_llm_call should have been called"
|
||||
|
||||
# Get the call arguments
|
||||
call_kwargs = mock_collector.record_tokens.call_args.kwargs
|
||||
call_kwargs = mock_collector.record_llm_call.call_args.kwargs
|
||||
|
||||
# Verify the call had correct structure
|
||||
assert call_kwargs["operation"] == "test_metrics", f"Expected operation='test_metrics', got {call_kwargs}"
|
||||
assert call_kwargs["bank_id"] == "llm", f"Expected bank_id='llm', got {call_kwargs}"
|
||||
assert call_kwargs["provider"] == "groq", f"Expected provider='groq', got {call_kwargs}"
|
||||
assert call_kwargs["model"] == "openai/gpt-oss-20b", f"Expected model='openai/gpt-oss-20b', got {call_kwargs}"
|
||||
assert call_kwargs["scope"] == "test_metrics", f"Expected scope='test_metrics', got {call_kwargs}"
|
||||
assert call_kwargs["duration"] > 0, f"Expected duration > 0, got {call_kwargs['duration']}"
|
||||
assert call_kwargs["input_tokens"] > 0, f"Expected input_tokens > 0, got {call_kwargs['input_tokens']}"
|
||||
# Output tokens may be 0 for some edge cases, but input should always be > 0
|
||||
assert call_kwargs["output_tokens"] >= 0, f"Expected output_tokens >= 0, got {call_kwargs['output_tokens']}"
|
||||
assert call_kwargs["success"] is True, f"Expected success=True, got {call_kwargs['success']}"
|
||||
|
||||
print(f"\nToken metrics recorded:")
|
||||
print(f" operation: {call_kwargs['operation']}")
|
||||
print(f"\nLLM metrics recorded:")
|
||||
print(f" provider: {call_kwargs['provider']}")
|
||||
print(f" model: {call_kwargs['model']}")
|
||||
print(f" scope: {call_kwargs['scope']}")
|
||||
print(f" duration: {call_kwargs['duration']:.3f}s")
|
||||
print(f" input_tokens: {call_kwargs['input_tokens']}")
|
||||
print(f" output_tokens: {call_kwargs['output_tokens']}")
|
||||
print(f" response: {response}")
|
||||
|
||||
|
||||
@pytest.mark.asyncio
|
||||
async def test_token_metrics_recorded_for_structured_output():
|
||||
async def test_llm_metrics_recorded_for_structured_output():
|
||||
"""
|
||||
Test that token metrics are recorded for structured output (JSON) calls.
|
||||
Test that LLM metrics are recorded for structured output (JSON) calls.
|
||||
"""
|
||||
api_key = get_groq_api_key()
|
||||
if not api_key:
|
||||
@@ -108,14 +111,14 @@ async def test_token_metrics_recorded_for_structured_output():
|
||||
assert response.greeting is not None
|
||||
assert response.language is not None
|
||||
|
||||
# Verify record_tokens was called
|
||||
assert mock_collector.record_tokens.called, "record_tokens should have been called"
|
||||
# Verify record_llm_call was called
|
||||
assert mock_collector.record_llm_call.called, "record_llm_call should have been called"
|
||||
|
||||
call_kwargs = mock_collector.record_tokens.call_args.kwargs
|
||||
call_kwargs = mock_collector.record_llm_call.call_args.kwargs
|
||||
assert call_kwargs["input_tokens"] > 0
|
||||
assert call_kwargs["output_tokens"] > 0
|
||||
|
||||
print(f"\nStructured output token metrics:")
|
||||
print(f"\nStructured output LLM metrics:")
|
||||
print(f" greeting: {response.greeting}")
|
||||
print(f" language: {response.language}")
|
||||
print(f" input_tokens: {call_kwargs['input_tokens']}")
|
||||
|
||||
@@ -0,0 +1,391 @@
|
||||
"""Tests for metrics instrumentation."""
|
||||
import pytest
|
||||
from unittest.mock import MagicMock, patch
|
||||
|
||||
from hindsight_api.metrics import (
|
||||
MetricsCollector,
|
||||
MetricsCollectorBase,
|
||||
NoOpMetricsCollector,
|
||||
get_metrics_collector,
|
||||
get_token_bucket,
|
||||
create_metrics_collector,
|
||||
initialize_metrics,
|
||||
)
|
||||
|
||||
|
||||
class TestNoOpMetricsCollector:
|
||||
"""Tests for the no-op metrics collector."""
|
||||
|
||||
def test_record_operation_is_noop(self):
|
||||
"""Test that record_operation does nothing."""
|
||||
collector = NoOpMetricsCollector()
|
||||
|
||||
# Should not raise any exception
|
||||
with collector.record_operation("recall", bank_id="test_bank", source="api"):
|
||||
pass
|
||||
|
||||
def test_nested_contexts_work(self):
|
||||
"""Test that nested context managers work correctly."""
|
||||
collector = NoOpMetricsCollector()
|
||||
|
||||
# Nested contexts should work without issues
|
||||
with collector.record_operation("reflect", bank_id="test_bank", source="api"):
|
||||
with collector.record_operation("recall", bank_id="test_bank", source="reflect"):
|
||||
pass
|
||||
|
||||
def test_exception_propagates(self):
|
||||
"""Test that exceptions inside context are propagated."""
|
||||
collector = NoOpMetricsCollector()
|
||||
|
||||
with pytest.raises(ValueError, match="test error"):
|
||||
with collector.record_operation("recall", bank_id="test_bank"):
|
||||
raise ValueError("test error")
|
||||
|
||||
def test_record_llm_call_is_noop(self):
|
||||
"""Test that record_llm_call does nothing."""
|
||||
collector = NoOpMetricsCollector()
|
||||
|
||||
# Should not raise any exception
|
||||
collector.record_llm_call(
|
||||
provider="openai",
|
||||
model="gpt-4",
|
||||
scope="memory",
|
||||
duration=1.5,
|
||||
input_tokens=100,
|
||||
output_tokens=50,
|
||||
success=True,
|
||||
)
|
||||
|
||||
|
||||
class TestMetricsCollector:
|
||||
"""Tests for the real metrics collector."""
|
||||
|
||||
@pytest.fixture
|
||||
def mock_meter(self):
|
||||
"""Create a mock meter for testing."""
|
||||
meter = MagicMock()
|
||||
# Create separate mocks for each histogram (operation_duration, llm_duration)
|
||||
histogram_mocks = [MagicMock(), MagicMock()]
|
||||
meter.create_histogram.side_effect = histogram_mocks
|
||||
# Create separate mocks for each counter
|
||||
# (operation_total, llm_tokens_input, llm_tokens_output, llm_calls_total)
|
||||
counter_mocks = [MagicMock() for _ in range(4)]
|
||||
meter.create_counter.side_effect = counter_mocks
|
||||
return meter
|
||||
|
||||
@pytest.fixture
|
||||
def collector(self, mock_meter):
|
||||
"""Create a MetricsCollector with a mock meter."""
|
||||
with patch("hindsight_api.metrics.get_meter", return_value=mock_meter):
|
||||
return MetricsCollector()
|
||||
|
||||
def test_record_operation_records_duration(self, collector):
|
||||
"""Test that record_operation records duration."""
|
||||
with collector.record_operation("recall", bank_id="test_bank", source="api"):
|
||||
pass
|
||||
|
||||
# Histogram should have been called
|
||||
collector.operation_duration.record.assert_called_once()
|
||||
call_args = collector.operation_duration.record.call_args
|
||||
|
||||
# First arg is duration (should be > 0)
|
||||
duration = call_args[0][0]
|
||||
assert duration >= 0
|
||||
|
||||
# Second arg is attributes dict
|
||||
attributes = call_args[0][1]
|
||||
assert attributes["operation"] == "recall"
|
||||
assert attributes["bank_id"] == "test_bank"
|
||||
assert attributes["source"] == "api"
|
||||
assert attributes["success"] == "true"
|
||||
|
||||
def test_record_operation_records_failure_on_exception(self, collector):
|
||||
"""Test that record_operation records failure when exception occurs."""
|
||||
with pytest.raises(RuntimeError):
|
||||
with collector.record_operation("retain", bank_id="test_bank", source="api"):
|
||||
raise RuntimeError("Test error")
|
||||
|
||||
# Should have recorded with success=false
|
||||
call_args = collector.operation_duration.record.call_args
|
||||
attributes = call_args[0][1]
|
||||
assert attributes["success"] == "false"
|
||||
|
||||
def test_record_operation_with_budget(self, collector):
|
||||
"""Test that budget is included in attributes when provided."""
|
||||
with collector.record_operation("recall", bank_id="test_bank", source="api", budget="mid"):
|
||||
pass
|
||||
|
||||
call_args = collector.operation_duration.record.call_args
|
||||
attributes = call_args[0][1]
|
||||
assert attributes["budget"] == "mid"
|
||||
|
||||
def test_record_operation_with_max_tokens(self, collector):
|
||||
"""Test that max_tokens is included in attributes when provided."""
|
||||
with collector.record_operation("recall", bank_id="test_bank", source="api", max_tokens=4096):
|
||||
pass
|
||||
|
||||
call_args = collector.operation_duration.record.call_args
|
||||
attributes = call_args[0][1]
|
||||
assert attributes["max_tokens"] == "4096"
|
||||
|
||||
def test_record_operation_source_values(self, collector):
|
||||
"""Test different source values: api, reflect, internal."""
|
||||
sources = ["api", "reflect", "internal"]
|
||||
|
||||
for source in sources:
|
||||
collector.operation_duration.record.reset_mock()
|
||||
|
||||
with collector.record_operation("recall", bank_id="test_bank", source=source):
|
||||
pass
|
||||
|
||||
call_args = collector.operation_duration.record.call_args
|
||||
attributes = call_args[0][1]
|
||||
assert attributes["source"] == source
|
||||
|
||||
def test_nested_contexts_track_separately(self, collector):
|
||||
"""Test that nested operations are tracked separately with different sources."""
|
||||
# Simulate reflect (api) calling recall (reflect)
|
||||
with collector.record_operation("reflect", bank_id="test_bank", source="api"):
|
||||
with collector.record_operation("recall", bank_id="test_bank", source="reflect"):
|
||||
pass
|
||||
|
||||
# Should have 2 calls to record
|
||||
assert collector.operation_duration.record.call_count == 2
|
||||
assert collector.operation_total.add.call_count == 2
|
||||
|
||||
# Check the calls
|
||||
calls = collector.operation_duration.record.call_args_list
|
||||
|
||||
# First call should be recall (inner context exits first)
|
||||
recall_attrs = calls[0][0][1]
|
||||
assert recall_attrs["operation"] == "recall"
|
||||
assert recall_attrs["source"] == "reflect"
|
||||
|
||||
# Second call should be reflect (outer context exits last)
|
||||
reflect_attrs = calls[1][0][1]
|
||||
assert reflect_attrs["operation"] == "reflect"
|
||||
assert reflect_attrs["source"] == "api"
|
||||
|
||||
|
||||
class TestGetMetricsCollector:
|
||||
"""Tests for the get_metrics_collector function."""
|
||||
|
||||
def test_returns_noop_by_default(self):
|
||||
"""Test that get_metrics_collector returns NoOpMetricsCollector by default."""
|
||||
# Reset global state
|
||||
import hindsight_api.metrics as metrics_module
|
||||
original_collector = metrics_module._metrics_collector
|
||||
|
||||
try:
|
||||
metrics_module._metrics_collector = NoOpMetricsCollector()
|
||||
collector = get_metrics_collector()
|
||||
assert isinstance(collector, NoOpMetricsCollector)
|
||||
finally:
|
||||
metrics_module._metrics_collector = original_collector
|
||||
|
||||
|
||||
class TestMetricsCollectorBase:
|
||||
"""Tests for the MetricsCollectorBase abstract class."""
|
||||
|
||||
def test_is_abstract(self):
|
||||
"""Test that MetricsCollectorBase methods are abstract."""
|
||||
# Create a class that inherits but doesn't implement
|
||||
class IncompleteCollector(MetricsCollectorBase):
|
||||
pass
|
||||
|
||||
collector = IncompleteCollector()
|
||||
|
||||
# Abstract methods should raise NotImplementedError
|
||||
with pytest.raises(NotImplementedError):
|
||||
with collector.record_operation("test", "test"):
|
||||
pass
|
||||
|
||||
with pytest.raises(NotImplementedError):
|
||||
collector.record_llm_call("test", "test", "test", 1.0)
|
||||
|
||||
|
||||
class TestGetTokenBucket:
|
||||
"""Tests for the get_token_bucket function."""
|
||||
|
||||
def test_bucket_0_100(self):
|
||||
"""Test tokens < 100 return '0-100' bucket."""
|
||||
assert get_token_bucket(0) == "0-100"
|
||||
assert get_token_bucket(50) == "0-100"
|
||||
assert get_token_bucket(99) == "0-100"
|
||||
|
||||
def test_bucket_100_500(self):
|
||||
"""Test tokens 100-499 return '100-500' bucket."""
|
||||
assert get_token_bucket(100) == "100-500"
|
||||
assert get_token_bucket(250) == "100-500"
|
||||
assert get_token_bucket(499) == "100-500"
|
||||
|
||||
def test_bucket_500_1k(self):
|
||||
"""Test tokens 500-999 return '500-1k' bucket."""
|
||||
assert get_token_bucket(500) == "500-1k"
|
||||
assert get_token_bucket(750) == "500-1k"
|
||||
assert get_token_bucket(999) == "500-1k"
|
||||
|
||||
def test_bucket_1k_5k(self):
|
||||
"""Test tokens 1000-4999 return '1k-5k' bucket."""
|
||||
assert get_token_bucket(1000) == "1k-5k"
|
||||
assert get_token_bucket(2500) == "1k-5k"
|
||||
assert get_token_bucket(4999) == "1k-5k"
|
||||
|
||||
def test_bucket_5k_10k(self):
|
||||
"""Test tokens 5000-9999 return '5k-10k' bucket."""
|
||||
assert get_token_bucket(5000) == "5k-10k"
|
||||
assert get_token_bucket(7500) == "5k-10k"
|
||||
assert get_token_bucket(9999) == "5k-10k"
|
||||
|
||||
def test_bucket_10k_50k(self):
|
||||
"""Test tokens 10000-49999 return '10k-50k' bucket."""
|
||||
assert get_token_bucket(10000) == "10k-50k"
|
||||
assert get_token_bucket(25000) == "10k-50k"
|
||||
assert get_token_bucket(49999) == "10k-50k"
|
||||
|
||||
def test_bucket_50k_plus(self):
|
||||
"""Test tokens >= 50000 return '50k+' bucket."""
|
||||
assert get_token_bucket(50000) == "50k+"
|
||||
assert get_token_bucket(100000) == "50k+"
|
||||
assert get_token_bucket(1000000) == "50k+"
|
||||
|
||||
|
||||
class TestLLMMetrics:
|
||||
"""Tests for LLM-specific metrics recording."""
|
||||
|
||||
@pytest.fixture
|
||||
def mock_meter(self):
|
||||
"""Create a mock meter for testing."""
|
||||
meter = MagicMock()
|
||||
# Create separate mocks for each histogram (operation_duration, llm_duration)
|
||||
histogram_mocks = [MagicMock(), MagicMock()]
|
||||
meter.create_histogram.side_effect = histogram_mocks
|
||||
# Create separate mocks for each counter
|
||||
# (operation_total, llm_tokens_input, llm_tokens_output, llm_calls_total)
|
||||
counter_mocks = [MagicMock() for _ in range(4)]
|
||||
meter.create_counter.side_effect = counter_mocks
|
||||
return meter
|
||||
|
||||
@pytest.fixture
|
||||
def collector(self, mock_meter):
|
||||
"""Create a MetricsCollector with a mock meter."""
|
||||
with patch("hindsight_api.metrics.get_meter", return_value=mock_meter):
|
||||
return MetricsCollector()
|
||||
|
||||
def test_record_llm_call_records_duration(self, collector):
|
||||
"""Test that record_llm_call records duration."""
|
||||
collector.record_llm_call(
|
||||
provider="openai",
|
||||
model="gpt-4",
|
||||
scope="memory",
|
||||
duration=1.5,
|
||||
input_tokens=100,
|
||||
output_tokens=50,
|
||||
success=True,
|
||||
)
|
||||
|
||||
# LLM duration histogram should be called
|
||||
collector.llm_duration.record.assert_called_once()
|
||||
call_args = collector.llm_duration.record.call_args
|
||||
|
||||
# First arg is duration
|
||||
assert call_args[0][0] == 1.5
|
||||
|
||||
# Second arg is attributes dict
|
||||
attributes = call_args[0][1]
|
||||
assert attributes["provider"] == "openai"
|
||||
assert attributes["model"] == "gpt-4"
|
||||
assert attributes["scope"] == "memory"
|
||||
assert attributes["success"] == "true"
|
||||
|
||||
def test_record_llm_call_records_failure(self, collector):
|
||||
"""Test that record_llm_call records failure status."""
|
||||
collector.record_llm_call(
|
||||
provider="anthropic",
|
||||
model="claude-3",
|
||||
scope="reflect",
|
||||
duration=0.5,
|
||||
success=False,
|
||||
)
|
||||
|
||||
# Check success is false
|
||||
call_args = collector.llm_duration.record.call_args
|
||||
attributes = call_args[0][1]
|
||||
assert attributes["success"] == "false"
|
||||
|
||||
def test_record_llm_call_records_tokens_with_buckets(self, collector):
|
||||
"""Test that record_llm_call records tokens with bucket labels."""
|
||||
collector.record_llm_call(
|
||||
provider="openai",
|
||||
model="gpt-4",
|
||||
scope="memory",
|
||||
duration=1.0,
|
||||
input_tokens=2500, # Should be "1k-5k" bucket
|
||||
output_tokens=150, # Should be "100-500" bucket
|
||||
success=True,
|
||||
)
|
||||
|
||||
# Input tokens should be recorded with bucket
|
||||
collector.llm_tokens_input.add.assert_called_once()
|
||||
input_call = collector.llm_tokens_input.add.call_args
|
||||
assert input_call[0][0] == 2500
|
||||
assert input_call[0][1]["token_bucket"] == "1k-5k"
|
||||
|
||||
# Output tokens should be recorded with bucket
|
||||
collector.llm_tokens_output.add.assert_called_once()
|
||||
output_call = collector.llm_tokens_output.add.call_args
|
||||
assert output_call[0][0] == 150
|
||||
assert output_call[0][1]["token_bucket"] == "100-500"
|
||||
|
||||
def test_record_llm_call_skips_zero_tokens(self, collector):
|
||||
"""Test that zero token values don't record."""
|
||||
collector.record_llm_call(
|
||||
provider="openai",
|
||||
model="gpt-4",
|
||||
scope="memory",
|
||||
duration=1.0,
|
||||
input_tokens=0,
|
||||
output_tokens=0,
|
||||
success=True,
|
||||
)
|
||||
|
||||
# Token counters should not be called
|
||||
collector.llm_tokens_input.add.assert_not_called()
|
||||
collector.llm_tokens_output.add.assert_not_called()
|
||||
|
||||
def test_record_llm_call_increments_call_counter(self, collector):
|
||||
"""Test that record_llm_call increments the call counter."""
|
||||
collector.record_llm_call(
|
||||
provider="gemini",
|
||||
model="gemini-pro",
|
||||
scope="entity_observation",
|
||||
duration=2.0,
|
||||
success=True,
|
||||
)
|
||||
|
||||
# Call counter should be incremented
|
||||
collector.llm_calls_total.add.assert_called_once()
|
||||
call_args = collector.llm_calls_total.add.call_args
|
||||
assert call_args[0][0] == 1
|
||||
assert call_args[0][1]["provider"] == "gemini"
|
||||
assert call_args[0][1]["model"] == "gemini-pro"
|
||||
assert call_args[0][1]["scope"] == "entity_observation"
|
||||
|
||||
def test_record_llm_call_different_scopes(self, collector):
|
||||
"""Test recording LLM calls with different scopes."""
|
||||
scopes = ["memory", "reflect", "entity_observation", "answer"]
|
||||
|
||||
for scope in scopes:
|
||||
collector.llm_duration.record.reset_mock()
|
||||
|
||||
collector.record_llm_call(
|
||||
provider="openai",
|
||||
model="gpt-4",
|
||||
scope=scope,
|
||||
duration=1.0,
|
||||
success=True,
|
||||
)
|
||||
|
||||
call_args = collector.llm_duration.record.call_args
|
||||
attributes = call_args[0][1]
|
||||
assert attributes["scope"] == scope
|
||||
@@ -12,17 +12,51 @@ curl http://localhost:8888/metrics
|
||||
|
||||
| Metric | Type | Labels | Description |
|
||||
|--------|------|--------|-------------|
|
||||
| `hindsight.operation.duration` | Histogram | operation, bank_id, budget, max_tokens, success | Duration of operations in seconds |
|
||||
| `hindsight.operation.total` | Counter | operation, bank_id, budget, max_tokens, success | Total number of operations executed |
|
||||
| `hindsight.operation.duration` | Histogram | operation, bank_id, source, budget, max_tokens, success | Duration of operations in seconds |
|
||||
| `hindsight.operation.total` | Counter | operation, bank_id, source, budget, max_tokens, success | Total number of operations executed |
|
||||
|
||||
The `operation` label values are: `retain`, `recall`, `reflect`.
|
||||
**Labels:**
|
||||
- `operation`: Operation type (`retain`, `recall`, `reflect`)
|
||||
- `bank_id`: Memory bank identifier
|
||||
- `source`: Where the operation was triggered from (`api`, `reflect`, `internal`)
|
||||
- `budget`: Budget level if specified (`low`, `mid`, `high`)
|
||||
- `max_tokens`: Max tokens if specified
|
||||
- `success`: Whether the operation succeeded (`true`, `false`)
|
||||
|
||||
### Token Metrics
|
||||
The `source` label allows distinguishing between:
|
||||
- `api`: Direct API calls from clients
|
||||
- `reflect`: Internal recall calls made during reflect operations
|
||||
- `internal`: Other internal operations
|
||||
|
||||
### LLM Metrics
|
||||
|
||||
| Metric | Type | Labels | Description |
|
||||
|--------|------|--------|-------------|
|
||||
| `hindsight.tokens.input` | Counter | operation, bank_id, budget, max_tokens | Input tokens consumed |
|
||||
| `hindsight.tokens.output` | Counter | operation, bank_id, budget, max_tokens | Output tokens generated |
|
||||
| `hindsight.llm.duration` | Histogram | provider, model, scope, success | Duration of LLM API calls in seconds |
|
||||
| `hindsight.llm.calls.total` | Counter | provider, model, scope, success | Total number of LLM API calls |
|
||||
| `hindsight.llm.tokens.input` | Counter | provider, model, scope, success, token_bucket | Input tokens for LLM calls |
|
||||
| `hindsight.llm.tokens.output` | Counter | provider, model, scope, success, token_bucket | Output tokens from LLM calls |
|
||||
|
||||
**Labels:**
|
||||
- `provider`: LLM provider (`openai`, `anthropic`, `gemini`, `groq`, `ollama`, `lmstudio`)
|
||||
- `model`: Model name (e.g., `gpt-4`, `claude-3-sonnet`)
|
||||
- `scope`: What the LLM call is for (`memory`, `reflect`, `entity_observation`, `answer`)
|
||||
- `success`: Whether the call succeeded (`true`, `false`)
|
||||
- `token_bucket`: Token count bucket for cardinality control (`0-100`, `100-500`, `500-1k`, `1k-5k`, `5k-10k`, `10k-50k`, `50k+`)
|
||||
|
||||
### Histogram Buckets
|
||||
|
||||
Custom bucket boundaries are configured for better percentile accuracy:
|
||||
|
||||
**Operation Duration Buckets (seconds):**
|
||||
```
|
||||
0.1, 0.25, 0.5, 0.75, 1.0, 2.0, 3.0, 5.0, 7.5, 10.0, 15.0, 20.0, 30.0, 60.0, 120.0
|
||||
```
|
||||
|
||||
**LLM Duration Buckets (seconds):**
|
||||
```
|
||||
0.1, 0.25, 0.5, 1.0, 2.0, 3.0, 5.0, 10.0, 15.0, 30.0, 60.0, 120.0
|
||||
```
|
||||
|
||||
## Prometheus Configuration
|
||||
|
||||
@@ -32,3 +66,30 @@ scrape_configs:
|
||||
static_configs:
|
||||
- targets: ['localhost:8888']
|
||||
```
|
||||
|
||||
## Example Queries
|
||||
|
||||
### Average operation latency by type
|
||||
```promql
|
||||
rate(hindsight_operation_duration_sum[5m]) / rate(hindsight_operation_duration_count[5m])
|
||||
```
|
||||
|
||||
### LLM calls per minute by provider
|
||||
```promql
|
||||
rate(hindsight_llm_calls_total[1m]) * 60
|
||||
```
|
||||
|
||||
### P95 LLM latency
|
||||
```promql
|
||||
histogram_quantile(0.95, rate(hindsight_llm_duration_bucket[5m]))
|
||||
```
|
||||
|
||||
### Total tokens consumed by model
|
||||
```promql
|
||||
sum by (model) (hindsight_llm_tokens_input_total + hindsight_llm_tokens_output_total)
|
||||
```
|
||||
|
||||
### Internal vs API recall operations
|
||||
```promql
|
||||
sum by (source) (rate(hindsight_operation_total{operation="recall"}[5m]))
|
||||
```
|
||||
|
||||
Reference in New Issue
Block a user