aead_vfs/Cargo.toml

@@ -11,8 +11,9 @@ license.workspace = true
 # See more keys and their definitions at https://doc.rust-lang.org/cargo/reference/manifest.html
 
 [features]
-default = [ "fs_locks" ]
-fs_locks = [ "multi_key_manager/fs_locks" ]
+default = ["fs_locks"]
+fs_locks = ["multi_key_manager/fs_locks"]
+speed_test = ["byte-slice-cast", "target"]
 
 [dependencies]
 multi_key_manager = { path = "../multi_key_manager", features = ["with_nonce"] }
@@ -20,4 +21,7 @@ multi_key_manager = { path = "../multi_key_manager", features = ["with_nonce"] }
 ring = { version = "0.16.20", features = ["std"] }
 serde = { version = "1.0.163", features = ["derive"] }
 rmp-serde = "1.1.1"
+byte-slice-cast = { version = "1.2.2", optional = true }
+log = { version = "0.4.18", features = ["release_max_level_info"] }
 #parking_lot = { version = "0.12.1", features = ["arc_lock"] }
+target = { version = "2.0.0", optional = true }

aead_vfs/src/aead.rs

 use crate::CvfsResult;
+use log::debug;
 use multi_key_manager::{file::File, OpeningNonce};
 use ring::aead::{Aad, NonceSequence, OpeningKey, SealingKey};
 use std::io::{Read, Seek, Write};
@@ -40,7 +41,7 @@ pub(crate) fn decrypt_file_buffered(
 
     //let mut key = keys.get_opening_master_key();
     let aad = Aad::empty();
-    println!(" > decrypt_file_buffered: {:?}", buf.len());
+    debug!(" > decrypt_file_buffered: {:?}", buf.len());
     let decrypted = key.open_in_place(aad, &mut buf)?;
     let decrypted_len = decrypted.len();
 

aead_vfs/src/lib.rs

@@ -16,6 +16,7 @@ use aead::{decrypt_file_buffered, encrypt_file_buffered};
 pub mod metadata;
 use metadata::{FileInfo, FileTag, Metadata};
 mod secure_file;
+use log::{debug, error, trace};
 use secure_file::ActiveFile;
 pub use {errors::CvfsResult, secure_file::SecureFileHandler};
 
@@ -69,7 +70,7 @@ pub fn open_dir<P: AsRef<Path>>(
     } else {
         let content =
             decrypt_file_buffered(&mut metadata_file, &mut keys.get_opening_master_key())?;
-        println!(" > CryptoVfsInner::open_dir");
+        trace!(" > CryptoVfsInner::open_dir");
         Metadata::restore_from_slice(&content)?
     };
 
@@ -155,10 +156,10 @@ impl CryptoVfsInner {
                     real_path.pop();
                 }
             }
-            println!("new block path: {:?}", real_path.display());
+            debug!("new block path: {:?}", real_path.display());
             FileInfo::new(real_block_name)
         });
-        println!("CryptoVfsInner::create found entry: {entry:?}");
+        debug!("CryptoVfsInner::create found entry: {entry:?}");
 
         let id = match &mut entry.active {
             Some(active) => {
@@ -178,7 +179,7 @@ impl CryptoVfsInner {
                 real_path.push(&entry.real_block_name);
                 let active = ActiveFile::open_rwlocked(&real_path, id.clone(), &mut file_key)?;
 
-                println!("CryptoVfsInner::create made a file: {:?}", active);
+                debug!("CryptoVfsInner::create made a file: {:?}", active);
                 entry.active = Some(active);
 
                 id
@@ -224,7 +225,7 @@ impl Drop for CryptoVfsInner {
         if let Err(e) = self.flush_all() {
             let error = format!("aead_vfs::CryptoVfsInner was not flushed to disk: {e:?}");
             if panicking() {
-                eprintln!("{error}");
+                error!("{error}");
             } else {
                 panic!("{error}");
             }
@@ -250,6 +251,93 @@ pub fn random_u64() -> u64 {
     u64::from_le_bytes(r)
 }
 
+#[cfg(feature = "speed_test")]
+pub fn do_speed_test(n_mb: usize, cvfs: &mut CryptoVFS) -> CvfsResult<String> {
+    use byte_slice_cast::AsByteSlice;
+    use std::{
+        io::Write,
+        mem::size_of,
+        time::{Duration, Instant},
+    };
+
+    fn run(n_mb: usize, cvfs: &mut CryptoVFS) -> CvfsResult<(Duration, Duration, Duration)> {
+        /////////////////
+        let type_size = size_of::<u64>();
+        let allocation_start = Instant::now();
+        let len = 1024 * 1024 * n_mb / type_size;
+        let mut buffer = Vec::with_capacity(len);
+        let mut seed = 8739845878359807234u64;
+        for _i in 0..len {
+            buffer.push(seed);
+            seed = seed.rotate_left(13) + 23;
+        }
+        let allocation_elapsed = allocation_start.elapsed();
+
+        /////////////////
+        let random_name = format!("{}.bin", random_u64());
+        debug!("do_speed_test < delete {:?}", cvfs.delete(&random_name));
+        let mut fd = cvfs.create(&random_name)?;
+        let encryption_start = Instant::now();
+        let u8_buffer = buffer.as_byte_slice();
+        fd.write_all(u8_buffer)?;
+        debug!("do_speed_test < written");
+        drop(fd);
+        let encryption_elapsed = encryption_start.elapsed();
+
+        /////////////////
+        debug!("do_speed_test < cleanup");
+        let deletion_start = Instant::now();
+        cvfs.delete(&random_name)?;
+        let deletion_elapsed = deletion_start.elapsed();
+
+        Ok((allocation_elapsed, encryption_elapsed, deletion_elapsed))
+    }
+
+    fn stats<I: Iterator<Item = u128> + Clone>(it: I) -> (u128, f64) {
+        let mut avg = 0;
+        let mut len = 0;
+        for e in it.clone() {
+            avg += e;
+            len += 1;
+        }
+        avg /= len;
+        let favg = avg as f64;
+        let mut dev = 0.0;
+        for e in it {
+            dev += e as f64 - favg;
+        }
+        dev /= len as f64;
+        dev = dev.sqrt();
+        (avg, dev)
+    }
+
+    let runs: Vec<(Duration, Duration, Duration)> = (0..16)
+        .map(|_| run(n_mb, cvfs))
+        .collect::<CvfsResult<_>>()?;
+
+    let (alloc_avg, alloc_dev) = stats(runs.iter().map(|d| d.0.as_millis()));
+    let (enc_avg, enc_dev) = stats(runs.iter().map(|d| d.1.as_millis()));
+    let (del_avg, del_dev) = stats(runs.iter().map(|d| d.2.as_millis()));
+
+    let runtime = format!(
+        "{} {} ({} bit) -- CPU features {:?}",
+        target::arch(),
+        target::os(),
+        target::pointer_width(),
+        target::features()
+    );
+
+    Ok(format!(
+        r#" ::: CryptoVFS Speed Test :::
+        test size: {n_mb}MB
+        allocation time: {alloc_avg}ms  ±{alloc_dev:.3}ms
+        encryption time: {enc_avg}ms  ±{enc_dev:.3}ms
+        deletion time: {del_avg}ms  ±{del_dev:.3}ms
+        runtime: {runtime}
+        "#
+    ))
+}
+
 #[cfg(test)]
 mod tests {
     use super::*;

aead_vfs/src/metadata.rs

 use crate::{
     aead::encrypt_file_buffered, errors::CvfsErrors, errors::CvfsResult, secure_file::ActiveFile,
 };
+use log::debug;
 use multi_key_manager::{file::File, LiveKeyMaterial, LiveKeys, MutableNonce, OpeningNonce};
 use ring::aead::{BoundKey, SealingKey, UnboundKey};
 use serde::{Deserialize, Serialize};
@@ -56,7 +57,7 @@ impl Metadata {
 
         // flush the index
         let buf = rmp_serde::to_vec_named(&self.files)?;
-        //println!("Metadata serialised buffer len: {}", buf.len());
+        //trace!("Metadata serialised buffer len: {}", buf.len());
         assert!(buf.len() > 0, "unable to serialise files");
 
         let mut key = key_material.get_sealing_master_key();
@@ -64,7 +65,7 @@ impl Metadata {
 
         output.flush()?;
 
-        println!("Metadata::store_to_disk flush ok");
+        debug!("Metadata::store_to_disk flush ok");
 
         Ok(())
     }

aead_vfs/src/secure_file.rs

@@ -4,6 +4,7 @@ use crate::{
     metadata::FileTag,
     open_rwlocked, CryptoVfsInner,
 };
+use log::{debug, error, trace};
 use multi_key_manager::{file::File, LiveKeyMaterial, OpeningNonce};
 use ring::aead::{NonceSequence, OpeningKey, SealingKey};
 use std::{
@@ -74,7 +75,7 @@ impl Drop for ActiveFile {
         if self.modified_flag {
             let error = "aead_vfs::ActiveFile was not flushed by Metadata";
             if panicking() {
-                eprintln!("{error}");
+                error!("{error}");
             } else {
                 panic!("{error}");
             }
@@ -91,15 +92,16 @@ impl Write for ActiveFile {
         }
         let data_len = self.data.len();
         let target_range = self.offset..new_max_len;
-        println!(" < target_range: {target_range:?}");
+        debug!(" < target_range: {target_range:?}");
         let target = &mut self.data[target_range];
-        println!(
+        debug!(
             " < offset: {}, new: {new_max_len}, self.data: {data_len} target: {}, buffer: {}",
             self.offset,
             target.len(),
             buffer.len()
         );
-        println!(" < target: {:?}", target);
+        let debug_range = 0..(8.min(target.len()));
+        trace!(" < target: {:?}", &target[debug_range]);
         stdout_flush()?;
 
         // TODO try the more efficient method, while avoiding SIG-6
@@ -250,7 +252,7 @@ impl Read for SecureFileHandler {
 impl Drop for SecureFileHandler {
     fn drop(&mut self) {
         // ignore errors since we can not do much at this point
-        println!("SecureFileHandler::drop");
+        debug!("SecureFileHandler::drop");
         let _ = self.try_flush();
     }
 }

cli/Cargo.toml

@@ -10,5 +10,8 @@ edition = "2021"
 
 [dependencies]
 #aead_vfs = { path = "../aead_vfs" }
-aead_vfs = { path = "../aead_vfs", default-features = false }
+aead_vfs = { path = "../aead_vfs", default-features = false, features = [ "speed_test" ] }
+#call_logger = "0.0.5"
+log = "0.4.18"
+stderrlog = "0.5.4"
 structopt = { version = "0.3.26", features = ["color"] }

cli/Makefile

+build_aarch64_cli:
+	ANDROID_NDK_HOME=~/Android/Sdk/ndk/25.2.9519653/ cargo ndk -t arm64-v8a build --release
+	ll ../target/aarch64-linux-android/release/cli

cli/src/main.rs

 use aead_vfs::{open_dir, CvfsResult};
+use log::{error, info, warn};
 use std::{
     io::{Read, Write},
     process::exit,
@@ -15,21 +16,22 @@ struct Cli {
     path: String,
     /// The passphrase for the encryption
     passphrase: String,
-    /// The encrypted file
-    secure_file_path: String,
     /// Actions: create, read, store, delete, exists
     action: Action,
+    /// The encrypted file
+    secure_file_path: Option<String>,
     /// content for create and store
     content: Option<String>,
 }
 
-#[derive(Debug)]
+#[derive(Debug, Clone, Copy)]
 enum Action {
     Create,
     Read,
     Store,
     Delete,
     Exists,
+    SpeedTest,
 }
 impl std::str::FromStr for Action {
     type Err = String;
@@ -42,6 +44,7 @@ impl std::str::FromStr for Action {
             "store" => Store,
             "delete" => Delete,
             "exists" => Exists,
+            "speedtest" | "speed_test" => SpeedTest,
             unknown => return Err(format!("unknown Action: {unknown:?}")),
         })
     }
@@ -50,6 +53,17 @@ impl std::str::FromStr for Action {
 fn main() {
     let cli = Cli::from_args();
 
+    let level = if cli.debug {
+        log::LevelFilter::Trace
+    } else {
+        log::LevelFilter::Info
+    };
+    stderrlog::new()
+        .verbosity(level)
+        .show_level(true)
+        .init()
+        .unwrap();
+
     if let Err(e) = run(cli) {
         eprintln!("{e:#?}");
     }
@@ -58,50 +72,65 @@ fn run(cli: Cli) -> CvfsResult<()> {
     let mut vfs = open_dir(&cli.passphrase, &cli.path)?;
 
     if cli.debug {
-        println!("    ======================");
-        println!("{cli:#?}");
-        println!("    ======================");
-        println!("{vfs:#?}");
-        println!("    ======================");
+        info!("    ======================");
+        info!("{cli:#?}");
+        info!("    ======================");
+        info!("{vfs:#?}");
+        info!("    ======================");
     }
 
     use Action::*;
-    match (cli.action, cli.content) {
-        (Create, None) | (Store, None) => {
-            eprintln!("Must provide content argument");
+    match (cli.action, cli.secure_file_path, cli.content) {
+        (Create, None, _)
+        | (Read, None, _)
+        | (Store, None, _)
+        | (Delete, None, _)
+        | (Exists, None, _) => {
+            error!("Must provide a file argument with action: {:?}", cli.action);
             exit(23);
         }
-        (Create, Some(content)) => {
-            let mut a = vfs.create(&cli.secure_file_path)?;
+        (Create, _, None) | (Store, _, None) => {
+            error!("Must provide content argument");
+            exit(23);
+        }
+        (Create, Some(secure_file_path), Some(content)) => {
+            let mut a = vfs.create(&secure_file_path)?;
             a.set_len(content.len())?;
 
             a.write_all(content.as_bytes())?;
         }
-        (Read, _) => {
-            if vfs.exists(&cli.secure_file_path)? == false {
-                eprintln!("secure_file_path {:#?} not found", cli.secure_file_path);
+        (Read, Some(secure_file_path), _) => {
+            if vfs.exists(&secure_file_path)? == false {
+                eprintln!("secure_file_path {:#?} not found", secure_file_path);
                 exit(23);
             }
-            let mut fd = vfs.create(&cli.secure_file_path)?;
+            let mut fd = vfs.create(&secure_file_path)?;
             let mut buffer = String::new();
             fd.read_to_string(&mut buffer)?;
-            println!("{buffer}");
+            info!("{buffer}");
         }
-        (Store, Some(content)) => {
-            let mut fd = vfs.create(&cli.secure_file_path)?;
+        (Store, Some(secure_file_path), Some(content)) => {
+            let mut fd = vfs.create(&secure_file_path)?;
             fd.write_all(content.as_bytes())?;
         }
-        (Delete, _) => {
-            let _r = vfs.delete(&cli.secure_file_path)?;
+        (Delete, Some(secure_file_path), _) => {
+            let _r = vfs.delete(&secure_file_path)?;
         }
-        (Exists, _) => {
-            let r = vfs.exists(&cli.secure_file_path)?;
+        (Exists, Some(secure_file_path), _) => {
+            let r = vfs.exists(&secure_file_path)?;
             if r {
-                println!("exists");
+                info!("exists");
             } else {
-                println!("absent");
+                warn!("absent");
             }
         }
+        (SpeedTest, _, _) => {
+            let mb = 128;
+            info!("testing with {mb} MB");
+            info!("");
+            let result = aead_vfs::do_speed_test(mb, &mut vfs)?;
+            info!("{result}");
+        }
     }
 
     Ok(())

multi_key_manager/Cargo.toml

@@ -12,12 +12,13 @@ license.workspace = true
 # See more keys and their definitions at https://doc.rust-lang.org/cargo/reference/manifest.html
 
 [features]
-default = [ "fs_locks" ]
+default = ["fs_locks"]
 with_nonce = []
-fs_locks = [ "fs4" ]
+fs_locks = ["fs4"]
 
 [dependencies]
-argon2 = { version = "0.4.1", features = [ "rand" ] }
+argon2 = { version = "^0.4.1", features = [ "rand" ] }
+#argon2 = { version = "0.5.0", features = [ "rand" ] }
 #argon2 = { path = "../../rust-crypto_password-hashes/argon2", features = [ "rand" ] }
 # enable OsRng
 rand_core = { version = "0.6.4", features = [ "getrandom" ] }
@@ -28,6 +29,7 @@ serde = { version = "1.0.152", features = ["derive"] }
 
 # lock the keys file while it is in use
 fs4 = { version = "0.6.3", features = ["sync"], optional = true }
+log = { version = "0.4.18", features = ["release_max_level_info"] }
 
 #[target.'cfg(unix)'.dependencies]
 #libc = "0.2.139"

multi_key_manager/src/lib.rs

@@ -13,6 +13,7 @@ use argon2::{
     Argon2, ParamsBuilder,
 };
 use core::{hint::black_box, ops::BitXor};
+use log::{debug, error, trace};
 use ring::{
     aead::{BoundKey, Nonce, NonceSequence, OpeningKey, SealingKey, UnboundKey},
     error::Unspecified,
@@ -110,7 +111,7 @@ impl LiveKeys {
     /// Flush the keys to disk
     pub fn store_to_disk(&mut self) -> MultiKeyManagerResult<()> {
         //assert!(self.master_nonce.has_changed == false);
-        println!("LiveKeys::store_to_disk: {:?}", self.slots);
+        debug!("LiveKeys::store_to_disk: {:?}", self.slots);
         let mut output = &*self.file_backend;
 
         // maybe don't save the field names in the future
@@ -180,7 +181,7 @@ impl LiveKeys {
     }
 
     fn update_nonces(&mut self, new: u128) -> MultiKeyManagerResult<()> {
-        println!("LiveKeys::update_nonces");
+        debug!("LiveKeys::update_nonces");
         let ref old = self.master_nonce;
         for slot in &mut self.slots {
             slot.update_xored_nonce(old, new);
@@ -211,7 +212,7 @@ impl LiveKeyMaterial for LiveKeys {
         let key_material = self.master_key.secret_key;
         let nonce = self.get_opening_nonce();
 
-        println!(" >>> DBG: {:?}", nonce);
+        debug!(" >>> get_opening_master_key: {:?}", nonce);
 
         let unbound_key =
             UnboundKey::new(algorithm, &key_material).expect("unable to construct UnboundKey");
@@ -250,7 +251,7 @@ impl WithNonce for LiveKeys {
         let algorithm = &ring::aead::CHACHA20_POLY1305;
         let key_material = self.master_key.secret_key;
 
-        println!(" >>> DBG: {:?}", nonce);
+        debug!(" >>> get_opening_master_key_with_nonce: {:?}", nonce);
 
         let unbound_key =
             UnboundKey::new(algorithm, &key_material).expect("unable to construct UnboundKey");
@@ -285,14 +286,14 @@ impl MutableNonce {
 }
 impl NonceSequence for MutableNonce {
     fn advance(&mut self) -> Result<Nonce, Unspecified> {
-        println!("MutableNonce::advance from {}", self.counter);
+        debug!("MutableNonce::advance from {}", self.counter);
         //let nonce = self.counter.to_le_bytes();
         match self.counter.checked_add(1) {
             Some(c) => {
                 self.counter = c;
                 let nonce = c.to_le_bytes();
                 let n = Nonce::try_assume_unique_for_key(&nonce[..12]);
-                println!(
+                trace!(
                     "NonceSequence::advance -> try_assume_unique_for_key = {}",
                     n.is_ok()
                 );
@@ -314,14 +315,14 @@ pub struct BorrowedNonce<'a> {
 }
 impl<'a> NonceSequence for BorrowedNonce<'a> {
     fn advance(&mut self) -> Result<Nonce, Unspecified> {
-        println!("NonceSequence::advance from {}", self.counter);
+        debug!("NonceSequence::advance from {}", self.counter);
         //let nonce = self.counter.to_le_bytes();
         match self.counter.checked_add(1) {
             Some(c) => {
                 self.counter = c;
                 let nonce = c.to_le_bytes();
                 let n = Nonce::try_assume_unique_for_key(&nonce[..12]);
-                println!(
+                trace!(
                     "NonceSequence::advance -> try_assume_unique_for_key = {}",
                     n.is_ok()
                 );
@@ -337,7 +338,7 @@ impl<'a> Drop for BorrowedNonce<'a> {
             if let Err(e) = self.live_keys.update_nonces(self.counter) {
                 let error = format!("BorrowedNonce::drop failed: {:?}", e);
                 if panicking() {
-                    eprintln!("{error}");
+                    error!("{error}");
                 } else {
                     panic!("{error}");
                 }