Added timing and perfstat struct for open invite

src/tests.rs

@@ -4,6 +4,16 @@ BridgeLine::random() or private fields */
 use super::bridge_table::BridgeLine;
 use super::proto::*;
 use super::*;
+use std::time::{Duration, Instant};
+
+struct PerfStat {
+    // Report performance metrics for each test
+    req_len: usize,
+    resp_len: usize,
+    req_t: Duration,
+    resp_t: Duration,
+    resp_handle_t: Duration,
+}
 
 struct TestHarness {
     bdb: BridgeDb,
@@ -45,24 +55,39 @@ impl TestHarness {
         self.ba.advance_days(days);
     }
 
-    fn open_invite(&mut self) -> (usize, usize, (cred::Lox, bridge_table::BridgeLine)) {
+    fn open_invite(&mut self) -> (PerfStat, (cred::Lox, bridge_table::BridgeLine)) {
         // Issue an open invitation
         let inv = self.bdb.invite();
 
+        let req_start = Instant::now();
         // Use it to get a Lox credential
         let (req, state) = open_invite::request(&inv);
         let encoded: Vec<u8> = bincode::serialize(&req).unwrap();
+        let req_t = req_start.elapsed();
         let req_len = encoded.len();
-        let decoded: open_invite::Request = bincode::deserialize(&encoded[..]).unwrap();
 
+        let resp_start = Instant::now();
+        let decoded: open_invite::Request = bincode::deserialize(&encoded[..]).unwrap();
         let resp = self.ba.handle_open_invite(decoded).unwrap();
         let encoded_resp: Vec<u8> = bincode::serialize(&resp).unwrap();
+        let resp_t = resp_start.elapsed();
         let resp_len = encoded_resp.len();
+
+        let resp_handle_start = Instant::now();
         let decode_resp: open_invite::Response = bincode::deserialize(&encoded_resp[..]).unwrap();
+        let (cred, bridgeline) =
+            open_invite::handle_response(state, decode_resp, &self.ba.lox_pub).unwrap();
+        let resp_handle_t = resp_handle_start.elapsed();
+
         return (
-            req_len,
-            resp_len,
-            (open_invite::handle_response(state, decode_resp, &self.ba.lox_pub).unwrap()),
+            PerfStat {
+                req_len,
+                resp_len,
+                req_t,
+                resp_t,
+                resp_handle_t,
+            },
+            (cred, bridgeline),
         );
     }
 
@@ -152,15 +177,18 @@ fn test_open_invite() {
     let mut th = TestHarness::new();
 
     // Join an untrusted user
-    let (ser_req, ser_resp, (cred, bridgeline)) = th.open_invite();
+    let (perf_stat, (cred, bridgeline)) = th.open_invite();
 
     // Check that we can use the credential to read a bucket
     let (id, key) = bridge_table::from_scalar(cred.bucket).unwrap();
     let encbuckets = th.ba.enc_bridge_table();
     let bucket =
         bridge_table::BridgeTable::decrypt_bucket(id, &key, &encbuckets[id as usize]).unwrap();
-    println!("Request size = {:?}", ser_req);
-    println!("Response size = {:?}", ser_resp);
+    println!("Request size = {:?}", perf_stat.req_len);
+    println!("Request time = {:?}", perf_stat.req_t);
+    println!("Response size = {:?}", perf_stat.resp_len);
+    println!("Response time = {:?}", perf_stat.resp_t);
+    println!("Response handle time = {:?}", perf_stat.resp_handle_t);
     println!("cred = {:?}", cred);
     println!("bucket = {:?}", bucket);
     println!("bridgeline = {:?}", bridgeline);
@@ -173,7 +201,7 @@ fn test_open_invite() {
 fn test_trust_promotion() {
     let mut th = TestHarness::new();
 
-    let cred = th.open_invite().2 .0;
+    let cred = th.open_invite().1 .0;
     assert!(th.ba.verify_lox(&cred));
 
     // Time passes
@@ -196,7 +224,7 @@ fn test_trust_promotion() {
 fn test_level0_migration() {
     let mut th = TestHarness::new();
 
-    let cred = th.open_invite().2 .0;
+    let cred = th.open_invite().1 .0;
     assert!(th.ba.verify_lox(&cred));
 
     // Time passes
@@ -223,7 +251,7 @@ fn test_level_up() {
     let mut th = TestHarness::new();
 
     // Join an untrusted user
-    let cred = th.open_invite().2 .0;
+    let cred = th.open_invite().1 .0;
 
     // Time passes
     th.advance_days(47);
@@ -263,7 +291,7 @@ fn test_issue_invite() {
     let mut th = TestHarness::new();
 
     // Join an untrusted user
-    let cred = th.open_invite().2 .0;
+    let cred = th.open_invite().1 .0;
 
     // Time passes
     th.advance_days(47);
@@ -295,7 +323,7 @@ fn test_redeem_invite() {
     let mut th = TestHarness::new();
 
     // Join an untrusted user
-    let cred = th.open_invite().2 .0;
+    let cred = th.open_invite().1 .0;
 
     // Time passes
     th.advance_days(47);
@@ -385,7 +413,7 @@ fn test_blockage_migration() {
     let mut th = TestHarness::new();
 
     // Join an untrusted user
-    let cred = th.open_invite().2 .0;
+    let cred = th.open_invite().1 .0;
 
     // Time passes
     th.advance_days(47);