feat(ads-client): add telemetry with tracing

Author: Almaju

Cargo.lock

@@ -12,6 +12,7 @@ default = []
 chrono = "0.4"
 context_id = { path = "../context_id" }
 error-support = { path = "../support/error" }
+once_cell = "1.5"
 parking_lot = "0.12"
 rusqlite = { version = "0.37.0", features = [
   "functions",
@@ -21,13 +22,14 @@ rusqlite = { version = "0.37.0", features = [
 ] }
 serde = "1"
 serde_json = "1"
+sql-support = { path = "../support/sql" }
 thiserror = "2"
-once_cell = "1.5"
+tracing = "0.1"
+tracing-subscriber = { version = "0.3", features = ["registry", "std", "fmt"] }
 uniffi = { version = "0.29.0" }
 url = { version = "2", features = ["serde"] }
 uuid = { version = "1.3", features = ["v4"] }
 viaduct = { path = "../viaduct" }
-sql-support = { path = "../support/sql" }
 
 [dev-dependencies]
 mockall = "0.12"

components/ads-client/Cargo.toml

@@ -10,6 +10,8 @@ use serde::{Deserialize, Serialize};
 use std::collections::{HashMap, HashSet};
 use url::Url;
 
+use tracing::error;
+
 #[derive(Debug, Deserialize, PartialEq, uniffi::Record, Serialize)]
 pub struct AdResponse {
     #[serde(deserialize_with = "AdResponse::deserialize_ad_response", flatten)]
@@ -33,12 +35,7 @@ impl AdResponse {
                     if let Ok(ad) = serde_json::from_value::<MozAd>(item) {
                         ads.push(ad);
                     } else {
-                        #[cfg(not(test))]
-                        {
-                            use crate::instrument::{emit_telemetry_event, TelemetryEvent};
-                            // TODO: improve the telemetry event (should we include the invalid URL?)
-                            let _ = emit_telemetry_event(Some(TelemetryEvent::InvalidUrlError));
-                        }
+                        error!(target: "ads_client::telemetry", "InvalidUrlError");
                     }
                 }
                 if !ads.is_empty() {

components/ads-client/src/client/ad_response.rs

@@ -3,7 +3,7 @@
 * file, You can obtain one at http://mozilla.org/MPL/2.0/.
 */
 
-use error_support::{error, ErrorHandling, GetErrorHandling};
+use error_support::{ErrorHandling, GetErrorHandling};
 use viaduct::Response;
 
 pub type AdsClientApiResult<T> = std::result::Result<T, AdsClientApiError>;
@@ -92,21 +92,6 @@ pub enum FetchAdsError {
     HTTPError(#[from] HTTPError),
 }
 
-#[derive(Debug, thiserror::Error)]
-pub enum EmitTelemetryError {
-    #[error("URL parse error: {0}")]
-    UrlParse(#[from] url::ParseError),
-
-    #[error("Error sending request: {0}")]
-    Request(#[from] viaduct::ViaductError),
-
-    #[error("JSON error: {0}")]
-    Json(#[from] serde_json::Error),
-
-    #[error("Could not fetch ads, MARS responded with: {0}")]
-    HTTPError(#[from] HTTPError),
-}
-
 #[derive(Debug, thiserror::Error)]
 pub enum CallbackRequestError {
     #[error("Could not fetch ads, MARS responded with: {0}")]

components/ads-client/src/error.rs

@@ -3,63 +3,141 @@
 * file, You can obtain one at http://mozilla.org/MPL/2.0/.
 */
 
-use std::sync::LazyLock;
-
-use crate::error::{ComponentError, EmitTelemetryError};
-use parking_lot::RwLock;
-use serde::{Deserialize, Serialize};
+use once_cell::sync::Lazy;
+use serde_json::json;
+use tracing::field::{Field, Visit};
+use tracing_subscriber::layer::Context;
+use tracing_subscriber::Layer;
 use url::Url;
 use viaduct::Request;
 
-static DEFAULT_TELEMETRY_ENDPOINT: &str = "https://ads.mozilla.org/v1/log";
-static TELEMETRY_ENDPONT: LazyLock<RwLock<String>> =
-    LazyLock::new(|| RwLock::new(DEFAULT_TELEMETRY_ENDPOINT.to_string()));
+static TELEMETRY_ENDPOINT: Lazy<Url> = Lazy::new(|| {
+    Url::parse("https://ads.mozilla.org/v1/log")
+        .expect("hardcoded telemetry endpoint URL must be valid")
+});
 
-fn get_telemetry_endpoint() -> String {
-    TELEMETRY_ENDPONT.read().clone()
+pub fn telemetry_layer<S>() -> impl Layer<S>
+where
+    S: tracing::Subscriber + for<'a> tracing_subscriber::registry::LookupSpan<'a>,
+{
+    TelemetryLayer {
+        endpoint: TELEMETRY_ENDPOINT.clone(),
+    }
+    .with_filter(TelemetryFilter)
 }
 
-#[derive(Debug, Deserialize, Serialize)]
-#[serde(rename_all = "snake_case")]
-pub enum TelemetryEvent {
-    Init,
-    RenderError,
-    AdLoadError,
-    FetchError,
-    InvalidUrlError,
+struct TelemetryLayer {
+    endpoint: Url,
 }
 
-pub trait TrackError<T, ComponentError> {
-    fn emit_telemetry_if_error(self) -> Self;
-}
+impl<S> Layer<S> for TelemetryLayer
+where
+    S: tracing::Subscriber,
+{
+    fn on_event(&self, event: &tracing::Event<'_>, _ctx: Context<'_, S>) {
+        let mut visitor = EventVisitor::default();
+        event.record(&mut visitor);
+
+        let event_message = visitor
+            .fields
+            .get("message")
+            .unwrap_or_default()
+            .as_str()
+            .unwrap_or_default();
 
-impl<T> TrackError<T, ComponentError> for Result<T, ComponentError> {
-    /// Attempts to emit a telemetry event if the Error type can map to an event type.
-    fn emit_telemetry_if_error(self) -> Self {
-        if let Err(ref err) = self {
-            let error_type = map_error_to_event_type(err);
-            let _ = emit_telemetry_event(error_type);
+        let mut url = self.endpoint.clone();
+        url.set_query(Some(&format!("event={event_message}")));
+
+        if let Err(e) = Request::get(url).send() {
+            eprintln!("[TELEMETRY] Failed to send event: {}", e);
         }
-        self
     }
 }
 
-fn map_error_to_event_type(err: &ComponentError) -> Option<TelemetryEvent> {
-    match err {
-        ComponentError::RequestAds(_) => Some(TelemetryEvent::FetchError),
-        ComponentError::RecordImpression(_) => Some(TelemetryEvent::InvalidUrlError),
-        ComponentError::RecordClick(_) => Some(TelemetryEvent::InvalidUrlError),
-        ComponentError::ReportAd(_) => Some(TelemetryEvent::InvalidUrlError),
+struct TelemetryFilter;
+
+impl<S> tracing_subscriber::layer::Filter<S> for TelemetryFilter
+where
+    S: tracing::Subscriber,
+{
+    fn enabled(
+        &self,
+        meta: &tracing::Metadata<'_>,
+        _cx: &tracing_subscriber::layer::Context<'_, S>,
+    ) -> bool {
+        meta.target() == "ads_client::telemetry"
+    }
+}
+
+#[derive(Default)]
+struct EventVisitor {
+    fields: serde_json::Map<String, serde_json::Value>,
+}
+
+impl Visit for EventVisitor {
+    fn record_debug(&mut self, field: &Field, value: &dyn std::fmt::Debug) {
+        self.fields.insert(
+            field.name().to_string(),
+            serde_json::Value::String(format!("{:?}", value)),
+        );
+    }
+
+    fn record_str(&mut self, field: &Field, value: &str) {
+        self.fields.insert(field.name().to_string(), json!(value));
+    }
+
+    fn record_i64(&mut self, field: &Field, value: i64) {
+        self.fields.insert(field.name().to_string(), json!(value));
+    }
+
+    fn record_u64(&mut self, field: &Field, value: u64) {
+        self.fields.insert(field.name().to_string(), json!(value));
+    }
+
+    fn record_bool(&mut self, field: &Field, value: bool) {
+        self.fields.insert(field.name().to_string(), json!(value));
     }
 }
 
-pub fn emit_telemetry_event(event_type: Option<TelemetryEvent>) -> Result<(), EmitTelemetryError> {
-    let endpoint = get_telemetry_endpoint();
-    let mut url = Url::parse(&endpoint)?;
-    if let Some(event) = event_type {
-        let event_string = serde_json::to_string(&event)?;
-        url.set_query(Some(&format!("event={}", event_string)));
-        Request::get(url).send()?;
+#[cfg(test)]
+mod tests {
+    use super::*;
+    use mockito::mock;
+    use tracing::error;
+    use tracing_subscriber::prelude::*;
+
+    #[test]
+    fn test_telemetry_layer() {
+        let subscriber = tracing_subscriber::registry::Registry::default().with(telemetry_layer());
+        tracing::subscriber::with_default(subscriber, || {});
+    }
+
+    #[test]
+    fn test_telemetry_sends_to_mock_server() {
+        viaduct_dev::init_backend_dev();
+
+        let mock_server_url = mockito::server_url();
+        let telemetry_url = Url::parse(&format!("{}/v1/log", mock_server_url)).unwrap();
+
+        let mock_endpoint = mock("GET", "/v1/log")
+            .with_status(200)
+            .match_query(mockito::Matcher::Regex(
+                r#"event=test%20telemetry%20error"#.to_string(),
+            ))
+            .expect(1)
+            .create();
+
+        let telemetry_layer = TelemetryLayer {
+            endpoint: telemetry_url,
+        }
+        .with_filter(TelemetryFilter);
+        let subscriber = tracing_subscriber::registry::Registry::default().with(telemetry_layer);
+
+        tracing::subscriber::with_default(subscriber, || {
+            error!(target: "ads_client::telemetry", message = "test telemetry error");
+            error!(target: "ads_client::not_telemetry", message = "non-telemetry event");
+        });
+
+        mock_endpoint.assert();
     }
-    Ok(())
 }