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}