mod batch;
pub mod identity;
pub mod journal;
mod otlp;
mod postgres;
use std::collections::HashMap;
use std::sync::Arc;
use std::time::{Duration, Instant, SystemTime};
use async_trait::async_trait;
use serde::{Deserialize, Serialize};
use crate::config::{
UndurablePolicy, UsageJournalBackend, UsageJournalConfig, UsageSinkConfig, UsageSinkKind,
};
use crate::credentials::CredentialSource;
use crate::usage::journal::{
DeliveryMode, DeliveryWorker, JournalError, PostgresJournal, PostgresJournalSettings,
UsageEvent, UsageJournal, WorkerHandle, WorkerSettings,
};
pub use batch::{BatchSettings, BatchedSink};
pub use journal::{ConsumerId, DRAIN_MARGIN, DrainReport};
pub use otlp::OtlpUsageSink;
pub use postgres::{PostgresSink, PostgresSinkSettings, tls_connector, validate_table_name};
#[derive(Debug, Clone, Copy, PartialEq, Eq, Serialize, Deserialize)]
#[serde(rename_all = "snake_case")]
#[allow(dead_code)] pub enum Status {
Ok,
UpstreamError,
ClientCancelled,
Partial,
Rejected,
}
impl Status {
pub fn as_str(self) -> &'static str {
match self {
Self::Ok => "ok",
Self::UpstreamError => "upstream_error",
Self::ClientCancelled => "client_cancelled",
Self::Partial => "partial",
Self::Rejected => "rejected",
}
}
pub fn is_error(self) -> bool {
matches!(self, Self::UpstreamError)
}
}
#[derive(Debug, Clone, PartialEq, Serialize)]
pub struct UsageRecord {
pub schema_version: u32,
pub request_id: String,
#[serde(skip_serializing_if = "Option::is_none")]
pub trace_id: Option<String>,
pub namespace: String,
pub subject: String,
#[serde(skip_serializing_if = "Option::is_none")]
pub signer_kid: Option<String>,
pub model: String,
pub target_provider: String,
pub target_model: String,
pub credential_source: &'static str,
pub credential_id: String,
pub status: Status,
pub input_tokens: u64,
pub cache_read_tokens: u64,
pub cache_write_tokens: u64,
pub output_tokens: u64,
pub cost_microdollars: u64,
pub catalog_version: u64,
#[serde(skip_serializing_if = "Option::is_none")]
pub price_book: Option<String>,
#[serde(skip_serializing_if = "Option::is_none")]
pub price_book_checksum: Option<String>,
#[serde(skip_serializing_if = "Option::is_none")]
pub price_catalog: Option<String>,
pub latency_ms: u64,
pub attempts: u32,
}
impl UsageRecord {
pub const SCHEMA_VERSION: u32 = 2;
pub fn credential_source_str(source: CredentialSource) -> &'static str {
match source {
CredentialSource::Platform => "platform",
CredentialSource::Byok => "byok",
}
}
}
#[derive(Debug, Clone)]
pub struct ObservedRecord {
pub record: UsageRecord,
pub observed_at: SystemTime,
}
impl ObservedRecord {
pub fn now(record: UsageRecord) -> Self {
Self {
record,
observed_at: SystemTime::now(),
}
}
}
#[derive(Debug, Clone, Copy, PartialEq, Eq)]
pub enum DropReason {
BufferFull,
SinkError,
Shutdown,
}
impl DropReason {
pub fn as_str(self) -> &'static str {
match self {
Self::BufferFull => "buffer_full",
Self::SinkError => "sink_error",
Self::Shutdown => "shutdown",
}
}
}
#[derive(Debug, thiserror::Error)]
#[error("{0}")]
pub struct SinkFailure(pub String);
impl SinkFailure {
pub fn new(message: impl Into<String>) -> Self {
Self(message.into())
}
}
#[derive(Debug, PartialEq, Eq)]
pub enum FlushOutcome {
Flushed { records: u64 },
Failed { records: u64, error: String },
TimedOut { abandoned: u64 },
}
impl FlushOutcome {
pub fn as_str(&self) -> &'static str {
match self {
Self::Flushed { .. } => "flushed",
Self::Failed { .. } => "failed",
Self::TimedOut { .. } => "timeout",
}
}
pub fn is_complete(&self) -> bool {
matches!(self, Self::Flushed { .. })
}
}
#[async_trait]
pub trait UsageSink: Send + Sync {
fn name(&self) -> &'static str;
async fn record(&self, record: &UsageRecord);
async fn record_batch(&self, batch: &[ObservedRecord]) -> Result<(), SinkFailure> {
for observed in batch {
self.record(&observed.record).await;
}
Ok(())
}
async fn flush(&self) -> FlushOutcome {
FlushOutcome::Flushed { records: 0 }
}
fn abandon(&self, reason: DropReason) -> u64 {
let _ = reason;
0
}
}
pub struct StdoutSink;
#[async_trait]
impl UsageSink for StdoutSink {
fn name(&self) -> &'static str {
"stdout"
}
async fn record(&self, record: &UsageRecord) {
match serde_json::to_string(record) {
Ok(line) => println!("{line}"),
Err(e) => tracing::error!(error = %e, "failed to serialize usage record"),
}
}
}
pub struct UsageFanout {
sinks: Vec<Box<dyn UsageSink>>,
}
impl UsageFanout {
pub fn new(sinks: Vec<Box<dyn UsageSink>>) -> Self {
Self { sinks }
}
pub async fn record(&self, record: &UsageRecord) {
for sink in &self.sinks {
sink.record(record).await;
}
}
pub async fn flush(&self, budget: Duration) -> FlushReport {
let deadline = Instant::now() + budget;
let mut sinks = Vec::with_capacity(self.sinks.len());
for sink in &self.sinks {
let remaining = deadline.saturating_duration_since(Instant::now());
let outcome = match tokio::time::timeout(remaining, sink.flush()).await {
Ok(outcome) => outcome,
Err(_) => FlushOutcome::TimedOut {
abandoned: sink.abandon(DropReason::Shutdown),
},
};
crate::telemetry::metrics::record_usage_flush(sink.name(), outcome.as_str());
sinks.push((sink.name(), outcome));
}
FlushReport { sinks }
}
}
#[derive(Debug)]
pub struct FlushReport {
pub sinks: Vec<(&'static str, FlushOutcome)>,
}
impl FlushReport {
pub fn is_complete(&self) -> bool {
self.sinks.iter().all(|(_, outcome)| outcome.is_complete())
}
pub fn log(&self) {
for (sink, outcome) in &self.sinks {
match outcome {
FlushOutcome::Flushed { records } => {
tracing::info!(sink, records, "usage sink flushed on shutdown")
}
FlushOutcome::Failed { records, error } => tracing::error!(
sink,
records,
error = %error,
reason = DropReason::SinkError.as_str(),
"usage sink rejected its buffered records on shutdown"
),
FlushOutcome::TimedOut { abandoned } => tracing::error!(
sink,
abandoned,
reason = DropReason::Shutdown.as_str(),
"usage sink flush exceeded its bound; buffered records were abandoned"
),
}
}
}
}
#[derive(Debug, thiserror::Error)]
pub enum UsageSinkError {
#[error("usage sink `{kind}`: {message}")]
Invalid { kind: &'static str, message: String },
#[error("postgres usage sink: {0}")]
Postgres(#[from] tokio_postgres::Error),
}
impl UsageSinkError {
fn invalid(kind: &'static str, message: impl Into<String>) -> Self {
Self::Invalid {
kind,
message: message.into(),
}
}
}
#[derive(Debug, Clone, Copy, PartialEq, Eq)]
pub enum Buffering {
Batched,
WriteThrough,
}
const JOURNAL_OWNED_BATCH_KEYS: [&str; 3] = ["buffer_capacity", "max_batch", "flush_interval_ms"];
fn journal_owned_batch_keys(configs: &[UsageSinkConfig]) -> Vec<&'static str> {
let mut named = Vec::new();
for config in configs {
if config.kind != UsageSinkKind::Postgres {
continue;
}
let defaults = UsageSinkConfig::default();
let set = [
config.buffer_capacity != defaults.buffer_capacity,
config.max_batch_explicit,
config.flush_interval_ms != defaults.flush_interval_ms,
];
for (key, was_set) in JOURNAL_OWNED_BATCH_KEYS.iter().zip(set) {
if was_set && !named.contains(key) {
named.push(*key);
}
}
}
named
}
pub struct UsageDelivery {
fanout: UsageFanout,
journal: Option<Arc<dyn UsageJournal>>,
on_undurable: UndurablePolicy,
#[cfg(test)]
unheard: std::sync::atomic::AtomicU64,
}
#[derive(Debug, thiserror::Error)]
#[error("the usage event for `{request_id}` could not be journaled ({reason}): {detail}")]
pub struct NotDurable {
pub request_id: String,
pub reason: &'static str,
pub detail: String,
}
impl UsageDelivery {
pub fn telemetry(fanout: UsageFanout) -> Self {
Self {
fanout,
journal: None,
on_undurable: UndurablePolicy::Serve,
#[cfg(test)]
unheard: std::sync::atomic::AtomicU64::new(0),
}
}
pub fn billing(journal: Arc<dyn UsageJournal>, on_undurable: UndurablePolicy) -> Self {
Self {
fanout: UsageFanout::new(Vec::new()),
journal: Some(journal),
on_undurable,
#[cfg(test)]
unheard: std::sync::atomic::AtomicU64::new(0),
}
}
pub fn mode(&self) -> DeliveryMode {
self.journal
.as_ref()
.map_or(DeliveryMode::TelemetryGrade, |journal| journal.mode())
}
pub fn appends(&self) -> bool {
self.journal.is_some()
}
pub async fn record(&self, record: &UsageRecord) -> Result<(), NotDurable> {
let Some(journal) = self.journal.as_ref() else {
self.fanout.record(record).await;
return Ok(());
};
let event = match UsageEvent::new(ObservedRecord::now(record.clone())) {
Ok(event) => event,
Err(error) => {
return self.undurable(record, "invalid_event", error.to_string());
}
};
match journal.append(&event).await {
Ok(appended) => {
crate::telemetry::metrics::record_usage_journal_append(
journal.name(),
if appended.is_new() {
"accepted"
} else {
"already_present"
},
);
Ok(())
}
Err(error) => {
let reason = match &error {
JournalError::AtCapacity { .. } => "at_capacity",
JournalError::Conflict { .. } => "conflict",
_ => "backend",
};
self.undurable(record, reason, error.to_string())
}
}
}
fn undurable(
&self,
record: &UsageRecord,
reason: &'static str,
detail: String,
) -> Result<(), NotDurable> {
let journal = self
.journal
.as_ref()
.map_or("none", |journal| journal.name());
crate::telemetry::metrics::record_usage_journal_append(journal, reason);
if self.on_undurable.refuses() {
return Err(NotDurable {
request_id: record.request_id.clone(),
reason,
detail,
});
}
tracing::error!(
request_id = %record.request_id,
reason,
detail = %detail,
"usage event was not journaled and the request was served anyway"
);
crate::telemetry::metrics::record_usage_journal_lost(journal, reason, 1);
Ok(())
}
pub fn count_unheard_refusal(&self, refusal: &NotDurable) {
let journal = self
.journal
.as_ref()
.map_or("none", |journal| journal.name());
tracing::error!(
request_id = %refusal.request_id,
reason = refusal.reason,
detail = %refusal.detail,
"a usage event could not be journaled and the caller was gone before it could be \
told, so the request stands charged with nothing recorded"
);
crate::telemetry::metrics::record_usage_journal_lost(journal, refusal.reason, 1);
#[cfg(test)]
self.unheard
.fetch_add(1, std::sync::atomic::Ordering::Relaxed);
}
#[cfg(test)]
pub fn unheard_refusals(&self) -> u64 {
self.unheard.load(std::sync::atomic::Ordering::Relaxed)
}
pub async fn record_terminal(&self, record: &UsageRecord) {
if let Err(error) = self.record(record).await {
let journal = self
.journal
.as_ref()
.map_or("none", |journal| journal.name());
tracing::error!(
request_id = %error.request_id,
reason = error.reason,
detail = %error.detail,
"a terminated request's usage event could not be journaled and cannot be refused"
);
crate::telemetry::metrics::record_usage_journal_lost(journal, error.reason, 1);
}
}
pub async fn flush(&self, budget: Duration) -> FlushReport {
self.fanout.flush(budget).await
}
}
pub struct UsageRuntime {
pub delivery: Arc<UsageDelivery>,
pub worker: Option<WorkerHandle>,
}
pub async fn build_runtime(
sinks: &[UsageSinkConfig],
journal: &UsageJournalConfig,
env: &HashMap<String, String>,
) -> Result<UsageRuntime, UsageSinkError> {
if journal.backend == UsageJournalBackend::None {
let sinks = build_sinks(sinks, env, Buffering::Batched).await?;
return Ok(UsageRuntime {
delivery: Arc::new(UsageDelivery::telemetry(UsageFanout::new(sinks))),
worker: None,
});
}
let dsn_env = journal.dsn_env.as_deref().unwrap_or_default();
let dsn = env
.get(dsn_env)
.filter(|dsn| !dsn.trim().is_empty())
.ok_or_else(|| {
UsageSinkError::invalid(
"journal",
format!("`{dsn_env}` is unset or empty in the environment"),
)
})?;
let store = PostgresJournal::connect(
dsn,
PostgresJournalSettings {
schema: journal.schema.clone(),
create_schema: journal.create_schema,
capacity: journal.capacity(),
connect_timeout: Duration::from_millis(journal.connect_timeout_ms),
operation_timeout: Duration::from_millis(journal.operation_timeout_ms),
connections: journal.connections,
},
)
.await
.map_err(|error| UsageSinkError::invalid("journal", error.to_string()))?;
let store: Arc<dyn UsageJournal> = Arc::new(store);
let capacity = store.capacity();
if capacity.policy.can_lose_events() {
tracing::warn!(
journal = store.name(),
policy = capacity.policy.as_str(),
max_events = capacity.max_events,
"the usage journal may drop accepted events when it fills; \
`capacity_policy = \"refuse\"` is the billing-grade setting"
);
}
let (advisory, durable): (Vec<UsageSinkConfig>, Vec<UsageSinkConfig>) = sinks
.iter()
.cloned()
.partition(|sink| sink.kind == UsageSinkKind::Otlp);
if !advisory.is_empty() {
tracing::info!(
journal = store.name(),
sinks = advisory.len(),
"usage telemetry sinks are exported alongside billing-grade delivery but are not \
acknowledged on, because they cannot report a failed write"
);
}
if durable
.iter()
.all(|sink| sink.kind == UsageSinkKind::Stdout)
{
tracing::warn!(
journal = store.name(),
retain_acknowledged_seconds = capacity.retain_acknowledged.as_secs(),
"the usage journal's only destination is `stdout`, so an acknowledgement means a \
log line was written and the event is forgotten once retention expires; a \
billing-grade destination should be one that stores the row"
);
}
let consumer = ConsumerId::parse(&journal.consumer)
.map_err(|error| UsageSinkError::invalid("journal", error.to_string()))?;
let owned = journal_owned_batch_keys(&durable);
if !owned.is_empty() {
tracing::warn!(
journal = store.name(),
keys = owned.join(", "),
claim_batch = journal.claim_batch,
poll_interval_ms = journal.poll_interval_ms,
"the usage journal owns sink batching; these `[[usage_sink]]` keys no \
longer apply and `[usage_journal]` claim_batch/poll_interval_ms \
replace them"
);
}
let acknowledged = build_sinks(&durable, env, Buffering::WriteThrough).await?;
let exported = if advisory.is_empty() {
Vec::new()
} else {
build_sinks(&advisory, env, Buffering::WriteThrough).await?
};
let worker = DeliveryWorker::new(
Arc::clone(&store),
Arc::new(acknowledged),
WorkerSettings {
consumer,
claim_batch: journal.claim_batch,
lease: Duration::from_secs(journal.lease_seconds),
poll_interval: Duration::from_millis(journal.poll_interval_ms),
maintain_interval: Duration::from_secs(60),
},
)
.also_telling(Arc::new(exported))
.spawn();
Ok(UsageRuntime {
delivery: Arc::new(UsageDelivery::billing(store, journal.on_undurable)),
worker: Some(worker),
})
}
pub async fn build_sinks(
configs: &[UsageSinkConfig],
env: &HashMap<String, String>,
buffering: Buffering,
) -> Result<Vec<Box<dyn UsageSink>>, UsageSinkError> {
if configs.is_empty() {
return Ok(vec![Box::new(StdoutSink)]);
}
let mut sinks: Vec<Box<dyn UsageSink>> = Vec::with_capacity(configs.len());
for config in configs {
match config.kind {
UsageSinkKind::Stdout => sinks.push(Box::new(StdoutSink)),
UsageSinkKind::Otlp => sinks.push(Box::new(OtlpUsageSink::new()?)),
UsageSinkKind::Postgres => {
let dsn_env = config.dsn_env.as_deref().unwrap_or_default();
let dsn = env
.get(dsn_env)
.filter(|dsn| !dsn.trim().is_empty())
.ok_or_else(|| {
UsageSinkError::invalid(
"postgres",
format!("`{dsn_env}` is unset or empty in the environment"),
)
})?;
let sink = PostgresSink::connect(
dsn,
PostgresSinkSettings {
table: config.table(),
create_table: config.create_table,
},
)
.await?;
match buffering {
Buffering::Batched => sinks.push(Box::new(BatchedSink::spawn(
Arc::new(sink),
config.batch_settings(),
))),
Buffering::WriteThrough => sinks.push(Box::new(sink)),
}
}
}
}
Ok(sinks)
}
#[cfg(test)]
mod tests {
use super::*;
pub(super) fn sample_record() -> UsageRecord {
UsageRecord {
schema_version: UsageRecord::SCHEMA_VERSION,
request_id: identity::next_request_id().to_string(),
trace_id: Some("4bf92f3577b34da6a3ce929d0e0e4736".to_string()),
namespace: "acme".to_string(),
subject: "GW_INBOUND_ACME_KEY".to_string(),
signer_kid: Some("verifier-1".to_string()),
model: "gpt-4o".to_string(),
target_provider: "openai".to_string(),
target_model: "gpt-4o-2024-08-06".to_string(),
credential_source: "byok",
credential_id: "openai-primary".to_string(),
status: Status::Ok,
input_tokens: 120,
cache_read_tokens: 12,
cache_write_tokens: 0,
output_tokens: 34,
cost_microdollars: 640,
catalog_version: 7,
price_book: Some("price/res_0190f2c1-6f6a-7c2e-9d3a-6f1c2b4d5e60@v7".to_string()),
price_book_checksum: Some(
"sha256:9f86d081884c7d659a2feaa0c55ad015a3bf4f1b2b0b822cd15d6c15b0f00a08"
.to_string(),
),
price_catalog: Some(
"sha256:2c26b46b68ffc68ff99b453c1d30413413422d706483bfa0f98a5e886266e7ae"
.to_string(),
),
latency_ms: 812,
attempts: 1,
}
}
struct StalledSink;
#[async_trait]
impl UsageSink for StalledSink {
fn name(&self) -> &'static str {
"stalled"
}
async fn record(&self, _record: &UsageRecord) {}
async fn record_batch(&self, _batch: &[ObservedRecord]) -> Result<(), SinkFailure> {
std::future::pending().await
}
}
fn billing(capacity: journal::Capacity, on_undurable: UndurablePolicy) -> UsageDelivery {
let journal = Arc::new(journal::oracle::InMemoryUsageJournal::with_capacity(
capacity,
));
UsageDelivery::billing(journal, on_undurable)
}
fn bounded(max_events: u64) -> journal::Capacity {
journal::Capacity {
max_events,
..journal::Capacity::BILLING_GRADE
}
}
#[tokio::test]
async fn telemetry_grade_delivery_cannot_refuse_a_request() {
let delivery = UsageDelivery::telemetry(UsageFanout::new(vec![Box::new(StdoutSink)]));
assert_eq!(delivery.mode(), DeliveryMode::TelemetryGrade);
delivery
.record(&sample_record())
.await
.expect("telemetry-grade delivery is infallible");
}
#[tokio::test]
async fn a_journaled_event_is_durable_before_the_request_is_answered() {
let delivery = billing(bounded(8), UndurablePolicy::Refuse);
let record = sample_record();
delivery.record(&record).await.expect("append");
delivery
.record(&record)
.await
.expect("an identical append is already durable");
}
#[tokio::test]
async fn a_full_journal_refuses_the_request_rather_than_billing_for_nothing() {
let delivery = billing(bounded(1), UndurablePolicy::Refuse);
delivery.record(&sample_record()).await.expect("append");
let error = delivery
.record(&sample_record())
.await
.expect_err("a full journal cannot make the next event durable");
assert_eq!(error.reason, "at_capacity");
assert!(error.to_string().contains(&error.request_id), "{error}");
}
#[tokio::test]
async fn a_deployment_that_chose_to_serve_anyway_is_served_and_the_loss_counted() {
let delivery = billing(bounded(1), UndurablePolicy::Serve);
delivery.record(&sample_record()).await.expect("append");
delivery
.record(&sample_record())
.await
.expect("`serve` does not refuse the request");
}
#[tokio::test]
async fn a_terminal_record_that_cannot_be_journaled_does_not_unwind_the_response() {
let delivery = billing(bounded(1), UndurablePolicy::Refuse);
delivery.record(&sample_record()).await.expect("append");
delivery.record_terminal(&sample_record()).await;
}
#[tokio::test]
async fn a_write_through_sink_has_nothing_to_flush() {
let fanout = UsageFanout::new(vec![Box::new(StdoutSink)]);
let report = fanout.flush(Duration::from_secs(5)).await;
assert!(report.is_complete());
assert_eq!(
report.sinks,
vec![("stdout", FlushOutcome::Flushed { records: 0 })]
);
}
#[tokio::test]
async fn a_stalled_sink_flush_ends_at_the_bound_with_its_buffer_accounted() {
let batched = BatchedSink::spawn(
Arc::new(StalledSink),
BatchSettings {
capacity: 16,
max_batch: 1,
flush_interval: Duration::from_millis(5),
},
);
let fanout = UsageFanout::new(vec![Box::new(batched)]);
for _ in 0..4 {
fanout.record(&sample_record()).await;
}
tokio::time::sleep(Duration::from_millis(20)).await;
let report = fanout.flush(Duration::from_millis(50)).await;
assert!(
!report.is_complete(),
"a stalled sink cannot report success"
);
let (sink, outcome) = &report.sinks[0];
assert_eq!(*sink, "stalled");
assert!(
matches!(outcome, FlushOutcome::TimedOut { abandoned } if *abandoned > 0),
"{outcome:?}"
);
}
#[tokio::test]
async fn no_configured_sink_keeps_the_stdout_default() {
let sinks = build_sinks(&[], &HashMap::new(), Buffering::Batched)
.await
.expect("defaults");
assert_eq!(sinks.len(), 1);
assert_eq!(sinks[0].name(), "stdout");
}
#[tokio::test]
async fn a_postgres_sink_whose_dsn_env_is_unset_fails_at_boot() {
let config = UsageSinkConfig {
kind: UsageSinkKind::Postgres,
dsn_env: Some("AXOND_TEST_MISSING_DSN".to_string()),
..UsageSinkConfig::default()
};
let err = build_sinks(&[config], &HashMap::new(), Buffering::Batched)
.await
.err()
.expect("missing dsn must fail at boot");
assert!(matches!(err, UsageSinkError::Invalid { .. }), "{err:?}");
}
#[test]
fn a_journal_names_the_sink_batching_keys_it_takes_over() {
let tuned = UsageSinkConfig {
kind: UsageSinkKind::Postgres,
buffer_capacity: 42,
flush_interval_ms: 250,
..UsageSinkConfig::default()
};
assert_eq!(
journal_owned_batch_keys(&[tuned]),
vec!["buffer_capacity", "flush_interval_ms"]
);
assert!(
journal_owned_batch_keys(&[
UsageSinkConfig {
kind: UsageSinkKind::Postgres,
..UsageSinkConfig::default()
},
UsageSinkConfig {
kind: UsageSinkKind::Stdout,
buffer_capacity: 7,
..UsageSinkConfig::default()
},
])
.is_empty()
);
}
#[tokio::test]
async fn write_through_sinks_are_not_wrapped_in_a_queue() {
let sinks = build_sinks(&[], &HashMap::new(), Buffering::WriteThrough)
.await
.expect("defaults");
let report = UsageFanout::new(sinks).flush(Duration::from_secs(5)).await;
assert_eq!(
report.sinks,
vec![("stdout", FlushOutcome::Flushed { records: 0 })],
"a write-through sink has no buffer to flush"
);
}
}