Skip to main content

mockforge_foundation/
pillar_tracking.rs

1//! Pillar usage tracking utilities
2//!
3//! Provides helper functions for recording pillar usage events throughout the codebase.
4//! These events are used for analytics and understanding which pillars are most used.
5
6use crate::pillars::Pillar;
7use chrono::Utc;
8use once_cell::sync::Lazy;
9use serde_json::Value;
10use std::sync::atomic::{AtomicU64, Ordering};
11use std::sync::Arc;
12use std::time::{Duration, Instant};
13use tokio::sync::RwLock;
14
15/// Optional analytics database for recording pillar usage
16/// This is set globally and can be None if analytics is not enabled
17#[allow(clippy::type_complexity)]
18static ANALYTICS_DB: Lazy<Arc<RwLock<Option<Arc<dyn PillarUsageRecorder>>>>> =
19    Lazy::new(|| Arc::new(RwLock::new(None)));
20
21/// Tracks dropped/failed pillar events so we can emit a rate-limited
22/// aggregate WARN instead of one WARN per event under load.
23///
24/// Issue #79 — Srikanth's bench at `--rps 100` for 600s flooded the log
25/// with hundreds of `WARN ... Failed to record pillar usage event: pool
26/// timed out` lines (one per failed event). The events themselves are
27/// best-effort metrics — losing them under sustained load doesn't break
28/// anything functional — so the right behaviour is to drop with low-
29/// volume reporting rather than spam.
30static FAILED_EVENT_COUNT: AtomicU64 = AtomicU64::new(0);
31static LAST_FAILURE_WARN_AT: Lazy<RwLock<Instant>> = Lazy::new(|| RwLock::new(Instant::now()));
32
33/// How often we emit the aggregated "X pillar events dropped" warning.
34const FAILURE_WARN_INTERVAL: Duration = Duration::from_secs(60);
35
36/// In-flight task counter — used to short-circuit event submission when
37/// the recorder is already saturated, instead of spawning more tokio
38/// tasks that will pile up on the analytics-DB pool's acquire queue.
39///
40/// Issue #79 round 12 — round 11 silenced the per-event WARN spam, but
41/// the underlying `sqlx::pool::acquire` "slow acquire" WARNs still
42/// fired because every event spawned a task that waited on the pool's
43/// 30s acquire timeout. Capping concurrency at the entry point drops
44/// the over-pressure events immediately (counted toward `FAILED_EVENT_COUNT`
45/// for the aggregate WARN) and lets the pool serve the ones in flight
46/// without bunching up.
47static IN_FLIGHT_RECORDS: AtomicU64 = AtomicU64::new(0);
48
49/// How many recorder tasks may be in flight simultaneously. Picked at
50/// 2× the analytics SqlitePool's `max_connections(10)` so a healthy
51/// pool can fully utilise its connection budget; bursts beyond that
52/// get dropped instead of queued.
53const IN_FLIGHT_LIMIT: u64 = 20;
54
55/// Trait for recording pillar usage events
56/// This allows different implementations (analytics DB, API endpoint, etc.)
57#[async_trait::async_trait]
58pub trait PillarUsageRecorder: Send + Sync {
59    /// Record a pillar usage event
60    async fn record(
61        &self,
62        event: PillarUsageEvent,
63    ) -> Result<(), Box<dyn std::error::Error + Send + Sync>>;
64}
65
66/// Pillar usage event (simplified version for internal use)
67#[derive(Debug, Clone)]
68pub struct PillarUsageEvent {
69    /// Workspace ID where the event occurred
70    pub workspace_id: Option<String>,
71    /// Organization ID (if applicable)
72    pub org_id: Option<String>,
73    /// The pillar this event relates to
74    pub pillar: Pillar,
75    /// Name of the metric being recorded
76    pub metric_name: String,
77    /// Value of the metric (JSON)
78    pub metric_value: Value,
79    /// Timestamp when the event occurred
80    pub timestamp: chrono::DateTime<Utc>,
81}
82
83/// Initialize the pillar usage tracker with a recorder
84pub async fn init(recorder: Arc<dyn PillarUsageRecorder>) {
85    let mut db = ANALYTICS_DB.write().await;
86    *db = Some(recorder);
87}
88
89/// Record a reality pillar usage event
90///
91/// This should be called when:
92/// - Reality continuum blend ratio is used
93/// - Smart personas are activated
94/// - Chaos is enabled/used
95/// - Reality level changes
96pub async fn record_reality_usage(
97    workspace_id: Option<String>,
98    org_id: Option<String>,
99    metric_name: &str,
100    metric_value: Value,
101) {
102    record_pillar_usage(workspace_id, org_id, Pillar::Reality, metric_name, metric_value).await;
103}
104
105/// Record a contracts pillar usage event
106///
107/// This should be called when:
108/// - Contract validation is performed
109/// - Drift detection occurs
110/// - Contract sync happens
111/// - Validation mode changes
112pub async fn record_contracts_usage(
113    workspace_id: Option<String>,
114    org_id: Option<String>,
115    metric_name: &str,
116    metric_value: Value,
117) {
118    record_pillar_usage(workspace_id, org_id, Pillar::Contracts, metric_name, metric_value).await;
119}
120
121/// Record a DevX pillar usage event
122///
123/// This should be called when:
124/// - SDK is installed/used
125/// - Client code is generated
126/// - Playground session starts
127/// - CLI command is executed
128pub async fn record_devx_usage(
129    workspace_id: Option<String>,
130    org_id: Option<String>,
131    metric_name: &str,
132    metric_value: Value,
133) {
134    record_pillar_usage(workspace_id, org_id, Pillar::DevX, metric_name, metric_value).await;
135}
136
137/// Record a cloud pillar usage event
138///
139/// This should be called when:
140/// - Scenario is shared
141/// - Marketplace download occurs
142/// - Workspace is created/shared
143/// - Organization template is used
144pub async fn record_cloud_usage(
145    workspace_id: Option<String>,
146    org_id: Option<String>,
147    metric_name: &str,
148    metric_value: Value,
149) {
150    record_pillar_usage(workspace_id, org_id, Pillar::Cloud, metric_name, metric_value).await;
151}
152
153/// Record an AI *pillar telemetry* event (best-effort analytics).
154///
155/// NOTE (#869): this is NOT billing metering. It feeds the pillar usage
156/// dashboards only — it carries no token counts, is lossy under load,
157/// and never enforces or reports quota. Platform-token accounting lives
158/// in `mockforge-registry-server`'s `ai::quota::record_ai_usage`.
159///
160/// This should be called when:
161/// - AI mock generation occurs
162/// - AI contract diff is performed
163/// - Voice command is executed
164/// - LLM-assisted operation happens
165pub async fn track_ai_pillar_telemetry(
166    workspace_id: Option<String>,
167    org_id: Option<String>,
168    metric_name: &str,
169    metric_value: Value,
170) {
171    record_pillar_usage(workspace_id, org_id, Pillar::Ai, metric_name, metric_value).await;
172}
173
174/// Record a pillar usage event (internal helper)
175async fn record_pillar_usage(
176    workspace_id: Option<String>,
177    org_id: Option<String>,
178    pillar: Pillar,
179    metric_name: &str,
180    metric_value: Value,
181) {
182    let db = ANALYTICS_DB.read().await;
183    if let Some(recorder) = db.as_ref() {
184        let event = PillarUsageEvent {
185            workspace_id,
186            org_id,
187            pillar,
188            metric_name: metric_name.to_string(),
189            metric_value,
190            timestamp: Utc::now(),
191        };
192
193        // Issue #79 round 12 — short-circuit when the recorder is already
194        // saturated. Spawning more tasks just bunches them up on the
195        // analytics-DB pool's 30s acquire timeout, producing the
196        // `sqlx::pool::acquire` "slow acquire" WARN spam Srikanth still
197        // saw on v0.3.144. Cap in-flight tasks; over-cap submissions
198        // count toward the aggregated drop warning and return without
199        // spawning.
200        let current = IN_FLIGHT_RECORDS.load(Ordering::Relaxed);
201        if current >= IN_FLIGHT_LIMIT {
202            FAILED_EVENT_COUNT.fetch_add(1, Ordering::Relaxed);
203            maybe_flush_dropped_warning().await;
204            return;
205        }
206        IN_FLIGHT_RECORDS.fetch_add(1, Ordering::Relaxed);
207
208        // Record asynchronously without blocking
209        let recorder = recorder.clone();
210        tokio::spawn(async move {
211            let result = recorder.record(event).await;
212            IN_FLIGHT_RECORDS.fetch_sub(1, Ordering::Relaxed);
213            if let Err(e) = result {
214                // Issue #79 — under high load (Srikanth's `--rps 100`
215                // for 600s) the analytics DB pool gets saturated and
216                // every event spawns a task that times out and logs a
217                // WARN. Pillar tracking is best-effort metrics; losing
218                // events under load is acceptable, but spamming the log
219                // with one WARN per dropped event is not. Demote per-
220                // event failures to DEBUG and emit one aggregated WARN
221                // at most every FAILURE_WARN_INTERVAL.
222                tracing::debug!("Failed to record pillar usage event: {}", e);
223                FAILED_EVENT_COUNT.fetch_add(1, Ordering::Relaxed);
224                maybe_flush_dropped_warning().await;
225            }
226        });
227    }
228}
229
230/// Emit a single aggregated WARN summarising dropped pillar events when
231/// at least `FAILURE_WARN_INTERVAL` has elapsed since the last summary.
232/// The check is racy by design — under contention we'd rather skip a
233/// summary than serialize on a mutex. Counts not surfaced by one race
234/// roll into the next interval's summary.
235async fn maybe_flush_dropped_warning() {
236    let last = *LAST_FAILURE_WARN_AT.read().await;
237    if last.elapsed() < FAILURE_WARN_INTERVAL {
238        return;
239    }
240    // Race-aware swap: take the count we'll report, leave the rest for
241    // the next interval. Another task may have already flushed — we
242    // double-check the timestamp under the write lock and bail if so.
243    let mut last_w = LAST_FAILURE_WARN_AT.write().await;
244    if last_w.elapsed() < FAILURE_WARN_INTERVAL {
245        return;
246    }
247    let dropped = FAILED_EVENT_COUNT.swap(0, Ordering::Relaxed);
248    if dropped > 0 {
249        tracing::warn!(
250            dropped_events = dropped,
251            interval_secs = FAILURE_WARN_INTERVAL.as_secs(),
252            "pillar_tracking: dropped events in the last {}s due to analytics-DB pressure \
253             (analytics is best-effort; bench / serve behaviour is unaffected)",
254            FAILURE_WARN_INTERVAL.as_secs(),
255        );
256    }
257    *last_w = Instant::now();
258}
259
260#[cfg(test)]
261mod tests {
262    use super::*;
263    use serde_json::json;
264
265    struct TestRecorder {
266        events: Arc<RwLock<Vec<PillarUsageEvent>>>,
267    }
268
269    #[async_trait::async_trait]
270    impl PillarUsageRecorder for TestRecorder {
271        async fn record(
272            &self,
273            event: PillarUsageEvent,
274        ) -> Result<(), Box<dyn std::error::Error + Send + Sync>> {
275            let mut events = self.events.write().await;
276            events.push(event);
277            Ok(())
278        }
279    }
280
281    #[tokio::test]
282    async fn test_record_reality_usage() {
283        let events = Arc::new(RwLock::new(Vec::new()));
284        let recorder = Arc::new(TestRecorder {
285            events: events.clone(),
286        });
287        init(recorder).await;
288
289        record_reality_usage(
290            Some("workspace-1".to_string()),
291            None,
292            "blended_reality_ratio",
293            json!({"ratio": 0.5}),
294        )
295        .await;
296
297        // Give async task time to complete
298        tokio::time::sleep(tokio::time::Duration::from_millis(100)).await;
299
300        let recorded = events.read().await;
301        assert_eq!(recorded.len(), 1);
302        assert_eq!(recorded[0].pillar, Pillar::Reality);
303        assert_eq!(recorded[0].metric_name, "blended_reality_ratio");
304    }
305}