Compare commits

...
3 Commits
Author SHA1 Message Date
Nicolò Boschi 21df52b681 fix 2026-01-08 11:22:27 +01:00
Nicolò Boschi 666f53d5c0 feat: add metrics for llm call latency 2026-01-08 11:22:27 +01:00
Nicolò Boschi 0699ba3280 feat: add metrics for llm call latency 2026-01-08 11:22:27 +01:00
6 changed files with 727 additions and 125 deletions
@@ -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
+175 -51
View File
@@ -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)
+22 -19
View File
@@ -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']}")
+391
View File
@@ -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
+67 -6
View File
@@ -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]))
```