primitives - targeting - eval - add Logging for TypeError

Author: elpiel

Cargo.lock

@@ -14,6 +14,8 @@ serde = {version = "^1.0", features = ['derive']}
 serde_json = "^1.0"
 reqwest = { version = "0.10", features = ["json"] }
 url = { version = "^2.1", features = ["serde"]}
+# Logging
+slog = { version = "^2.5.2" , features = ["max_level_trace"] }
 # Async
 async-std = "1.6"
 # Other

adview-manager/Cargo.toml

@@ -13,6 +13,7 @@ use lazy_static::lazy_static;
 use rand::Rng;
 use reqwest::StatusCode;
 use serde::{Deserialize, Serialize};
+use slog::{error, Logger};
 use std::{cmp::Ordering, collections::VecDeque, convert::TryFrom, sync::Arc};
 use thiserror::Error;
 use units_for_slot::response::UnitsWithPrice;
@@ -279,16 +280,22 @@ pub struct Manager {
     /// It always trims to HISTORY_LIMIT, removing the oldest (firstly inserted) elements from the History
     history: Arc<RwLock<VecDeque<HistoryEntry>>>,
     client: reqwest::Client,
+    logger: Logger,
 }
 
 impl Manager {
-    pub fn new(options: Options, history: VecDeque<HistoryEntry>) -> Result<Self, Error> {
+    pub fn new(
+        options: Options,
+        history: VecDeque<HistoryEntry>,
+        logger: Logger,
+    ) -> Result<Self, Error> {
         let client = reqwest::Client::builder().build()?;
 
         Ok(Self {
             options,
             history: Arc::new(RwLock::new(history)),
             client,
+            logger,
         })
     }
 
@@ -488,11 +495,13 @@ impl Manager {
                                 .collect(),
                         };
 
-                        // TODO: Logging for `eval_multiple`
-                        targeting::eval_multiple(
+                        let on_type_error = |error, rule| error!(&self.logger, "Rule evaluation error for {:?}", campaign_id; "error" => ?error, "rule" => ?rule);
+
+                        targeting::eval_with_callback(
                             &campaign.targeting_rules,
                             &input::Input::Getter(campaign_input.clone()),
                             &mut output,
+                            Some(on_type_error)
                         );
 
                         output.show

adview-manager/src/lib.rs

@@ -21,8 +21,16 @@ pub mod targeting_tag;
 
 pub mod util {
     pub mod tests {
+        use slog::{o, Discard, Drain, Logger};
+
         pub mod prep_db;
         pub mod time;
+
+        pub fn discard_logger() -> Logger {
+            let drain = Discard.fuse();
+
+            Logger::root(drain, o!())
+        }
     }
 
     pub mod logging;

primitives/src/lib.rs

@@ -967,11 +967,11 @@ pub fn eval_multiple(
     rules: &[Rule],
     input: &Input,
     output: &mut Output,
-) -> Vec<Result<Option<Value>, Error>> {
+) -> Vec<Result<Option<Value>, (Error, Rule)>> {
     let mut results = vec![];
 
     for rule in rules {
-        results.push(rule.eval(input, output));
+        results.push(rule.eval(input, output).map_err(|err| (err, rule.clone())));
 
         if !output.show {
             break;
@@ -981,6 +981,29 @@ pub fn eval_multiple(
     results
 }
 
+pub fn eval_with_callback<F: Fn(Error, Rule)>(
+    rules: &[Rule],
+    input: &Input,
+    output: &mut Output,
+    on_type_error: Option<F>,
+) {
+    for result in eval_multiple(rules, input, output) {
+        match (result, on_type_error.as_ref()) {
+            (Ok(_), _) => {}
+            (Err((Error::UnknownVariable, _)), _) => {}
+            (Err((Error::TypeError, rule)), Some(on_type_error)) => {
+                on_type_error(Error::TypeError, rule)
+            }
+            // skip any other case, including Error::TypeError if there is no passed function
+            _ => {}
+        }
+
+        if !output.show {
+            return;
+        }
+    }
+}
+
 enum MathOperator {
     Division,
     Multiplication,

primitives/src/targeting/eval.rs

@@ -35,7 +35,7 @@ pub async fn record(
             } => {
                 let divisor = BigNum::from(10u64.pow(18));
                 // @Todo: Check this!
-                let pay_amount = get_payout(&channel, event, &session)
+                let pay_amount = get_payout(&logger, &channel, event, &session)
                     .expect("should have payout")
                     .map(|(_, payout)| payout)
                     .unwrap_or_default()

sentry/src/analytics_recorder.rs

@@ -144,7 +144,13 @@ impl EventAggregator {
         })?;
 
         events.iter().for_each(|ev| {
-            match event_reducer::reduce(&record.channel, &mut record.aggregate, ev, &session) {
+            match event_reducer::reduce(
+                &app.logger,
+                &record.channel,
+                &mut record.aggregate,
+                ev,
+                &session,
+            ) {
                 Ok(_) => {}
                 Err(err) => error!(&app.logger, "Event Reducer failed"; "error" => ?err ),
             }

sentry/src/event_aggregator.rs

@@ -1,9 +1,12 @@
-use crate::payout::get_payout;
-use crate::Session;
-use primitives::sentry::{AggregateEvents, Event, EventAggregate};
-use primitives::{BigNum, Channel, ValidatorId};
+use crate::{payout::get_payout, Session};
+use primitives::{
+    sentry::{AggregateEvents, Event, EventAggregate},
+    BigNum, Channel, ValidatorId,
+};
+use slog::Logger;
 
 pub(crate) fn reduce(
+    logger: &Logger,
     channel: &Channel,
     initial_aggr: &mut EventAggregate,
     ev: &Event,
@@ -13,8 +16,8 @@ pub(crate) fn reduce(
     match ev {
         Event::Impression { publisher, .. } => {
             let impression = initial_aggr.events.get(&event_type);
-            let payout = get_payout(&channel, &ev, session)?;
-            let merge = merge_impression_ev(
+            let payout = get_payout(logger, &channel, &ev, session)?;
+            let merge = merge_payable_event(
                 impression,
                 payout.unwrap_or_else(|| (*publisher, Default::default())),
             );
@@ -23,8 +26,8 @@ pub(crate) fn reduce(
         }
         Event::Click { publisher, .. } => {
             let clicks = initial_aggr.events.get(&event_type);
-            let payout = get_payout(&channel, &ev, session)?;
-            let merge = merge_impression_ev(
+            let payout = get_payout(logger, &channel, &ev, session)?;
+            let merge = merge_payable_event(
                 clicks,
                 payout.unwrap_or_else(|| (*publisher, Default::default())),
             );
@@ -46,38 +49,43 @@ pub(crate) fn reduce(
     Ok(())
 }
 
-fn merge_impression_ev(
-    impression: Option<&AggregateEvents>,
+/// payable_event is either an IMPRESSION or a CLICK
+fn merge_payable_event(
+    payable_event: Option<&AggregateEvents>,
     payout: (ValidatorId, BigNum),
 ) -> AggregateEvents {
-    let mut impression = impression.map(Clone::clone).unwrap_or_default();
+    let mut payable_event = payable_event.cloned().unwrap_or_default();
 
-    let event_count = impression
+    let event_count = payable_event
         .event_counts
         .get_or_insert_with(Default::default)
         .entry(payout.0)
         .or_insert_with(|| 0.into());
 
     *event_count += &1.into();
 
-    let event_payouts = impression
+    let event_payouts = payable_event
         .event_payouts
         .entry(payout.0)
         .or_insert_with(|| 0.into());
     *event_payouts += &payout.1;
 
-    impression
+    payable_event
 }
 
 #[cfg(test)]
 mod test {
     use super::*;
     use chrono::Utc;
-    use primitives::util::tests::prep_db::{DUMMY_CHANNEL, IDS};
+    use primitives::util::tests::{
+        discard_logger,
+        prep_db::{DUMMY_CHANNEL, IDS},
+    };
     use primitives::BigNum;
 
     #[test]
     fn test_reduce() {
+        let logger = discard_logger();
         let mut channel: Channel = DUMMY_CHANNEL.clone();
         channel.deposit_amount = 100.into();
         // make immutable again
@@ -104,7 +112,7 @@ mod test {
         };
 
         for i in 0..101 {
-            reduce(&channel, &mut event_aggr, &event, &session)
+            reduce(&logger, &channel, &mut event_aggr, &event, &session)
                 .expect(&format!("Should be able to reduce event #{}", i));
         }
 

sentry/src/event_reducer.rs

@@ -2,17 +2,18 @@ use crate::Session;
 use chrono::Utc;
 use primitives::{
     sentry::Event,
-    targeting::{get_pricing_bounds, input, Error, Error as EvalError, Input, Output, Rule, eval_multiple},
+    targeting::{eval_with_callback, get_pricing_bounds, input, Error, Output},
     BigNum, Channel, ValidatorId,
 };
+use slog::{error, Logger};
 use std::{
     cmp::{max, min},
     convert::TryFrom,
 };
 
 type Result = std::result::Result<Option<(ValidatorId, BigNum)>, Error>;
 
-pub fn get_payout(channel: &Channel, event: &Event, session: &Session) -> Result {
+pub fn get_payout(logger: &Logger, channel: &Channel, event: &Event, session: &Session) -> Result {
     let event_type = event.to_string();
 
     match event {
@@ -77,7 +78,9 @@ pub fn get_payout(channel: &Channel, event: &Event, session: &Session) -> Result
                         .collect(),
                 };
 
-                eval_and_log(&targeting_rules, &input, &mut output);
+                let on_type_error = |error, rule| error!(logger, "Rule evaluation error for {:?}", channel.id; "error" => ?error, "rule" => ?rule);
+
+                eval_with_callback(&targeting_rules, &input, &mut output, Some(on_type_error));
 
                 if output.show {
                     let price = match output.price.get(&event_type) {
@@ -97,31 +100,19 @@ pub fn get_payout(channel: &Channel, event: &Event, session: &Session) -> Result
     }
 }
 
-fn eval_and_log(/* logger: &Logger, channel_id: ChannelId,  */rules: &[Rule], input: &Input, output: &mut Output) {
-    for result in eval_multiple(rules, input, output) {
-        match result {
-            Ok(_) => {}
-            Err(EvalError::UnknownVariable) => {}
-            Err(EvalError::TypeError) => {
-                todo!();
-                // error!(logger, "`WARNING: rule for {:?} failing", channel_id; "rule" => rule, "err" => ?result)
-            }
-        }
-
-        if !output.show {
-            return;
-        }
-    }
-}
-
 #[cfg(test)]
 mod test {
     use super::*;
     use primitives::channel::{Pricing, PricingBounds};
-    use primitives::util::tests::prep_db::{DUMMY_CHANNEL, IDS};
+    use primitives::util::tests::{
+        discard_logger,
+        prep_db::{DUMMY_CHANNEL, IDS},
+    };
 
     #[test]
     fn get_event_payouts_pricing_bounds_impression_event() {
+        let logger = discard_logger();
+
         let mut channel = DUMMY_CHANNEL.clone();
         channel.deposit_amount = 100.into();
         channel.spec.min_per_impression = 8.into();
@@ -148,14 +139,15 @@ mod test {
             os: None,
         };
 
-        let payout = get_payout(&channel, &event, &session).expect("Should be OK");
+        let payout = get_payout(&logger, &channel, &event, &session).expect("Should be OK");
 
         let expected_option = Some((IDS["leader"], 8.into()));
         assert_eq!(expected_option, payout, "pricingBounds: impression event");
     }
 
     #[test]
     fn get_event_payouts_pricing_bounds_click_event() {
+        let logger = discard_logger();
         let mut channel = DUMMY_CHANNEL.clone();
         channel.deposit_amount = 100.into();
         channel.spec.min_per_impression = 8.into();
@@ -182,14 +174,15 @@ mod test {
             os: None,
         };
 
-        let payout = get_payout(&channel, &event, &session).expect("Should be OK");
+        let payout = get_payout(&logger, &channel, &event, &session).expect("Should be OK");
 
         let expected_option = Some((IDS["leader"], 23.into()));
         assert_eq!(expected_option, payout, "pricingBounds: click event");
     }
 
     #[test]
     fn get_event_payouts_pricing_bounds_close_event() {
+        let logger = discard_logger();
         let mut channel = DUMMY_CHANNEL.clone();
         channel.deposit_amount = 100.into();
         channel.spec.min_per_impression = 8.into();
@@ -211,7 +204,7 @@ mod test {
             os: None,
         };
 
-        let payout = get_payout(&channel, &event, &session).expect("Should be OK");
+        let payout = get_payout(&logger, &channel, &event, &session).expect("Should be OK");
 
         assert_eq!(None, payout, "pricingBounds: click event");
     }