Merge "Add some unit tests for uci packet logger." into tm-dev

3 files changed, 288 insertions, 83 deletions

diff --git a/src/rust/adaptation/mod.rs b/src/rust/adaptation/mod.rs
index 4478ebf..4f017fd 100644
--- a/src/rust/adaptation/mod.rs
+++ b/src/rust/adaptation/mod.rs
@@ -2,7 +2,7 @@
 
 use crate::error::UwbErr;
 use crate::uci::uci_hrcv;
-use crate::uci::uci_logger::{UciLogMode, UciLogger, UciLoggerImpl};
+use crate::uci::uci_logger::{RealFileFactory, UciLogMode, UciLogger, UciLoggerImpl};
 use crate::uci::HalCallback;
 use android_hardware_uwb::aidl::android::hardware::uwb::{
     IUwb::IUwbAsync,
@@ -133,7 +133,8 @@ impl UwbAdaptationImpl {
                 UCI_LOG_DEFAULT
             }
         };
-        let logger = UciLoggerImpl::new(mode).await;
+        let logger =
+            UciLoggerImpl::new(mode, Arc::new(Mutex::new(RealFileFactory::default()))).await;
         Ok(UwbAdaptationImpl { hal, rsp_sender, logger: Arc::new(logger), hal_death_recipient })
     }
 
diff --git a/src/rust/uci/mock_uci_logger.rs b/src/rust/uci/mock_uci_logger.rs
index 131d842..3a8d6f8 100644
--- a/src/rust/uci/mock_uci_logger.rs
+++ b/src/rust/uci/mock_uci_logger.rs
@@ -17,7 +17,9 @@
 extern crate libc;
 
 use crate::uci::uci_logger::UciLogger;
+use crate::uci::UwbErr;
 use async_trait::async_trait;
+use std::path::Path;
 use uwb_uci_packets::{UciCommandPacket, UciNotificationPacket, UciResponsePacket};
 
 #[cfg(test)]
@@ -45,3 +47,18 @@ impl UciLogger for MockUciLogger {
     async fn log_uci_notification(&self, _ntf: UciNotificationPacket) {}
     async fn close_file(&self) {}
 }
+
+#[cfg(test)]
+pub async fn create_dir(_path: impl AsRef<Path>) -> Result<(), UwbErr> {
+    Ok(())
+}
+
+#[cfg(test)]
+pub async fn remove_file(_path: impl AsRef<Path>) -> Result<(), UwbErr> {
+    Ok(())
+}
+
+#[cfg(test)]
+pub async fn rename(_from: impl AsRef<Path>, _to: impl AsRef<Path>) -> Result<(), UwbErr> {
+    Ok(())
+}
diff --git a/src/rust/uci/uci_logger.rs b/src/rust/uci/uci_logger.rs
index d0af648..801416d 100644
--- a/src/rust/uci/uci_logger.rs
+++ b/src/rust/uci/uci_logger.rs
@@ -16,13 +16,19 @@
 
 extern crate libc;
 
+#[cfg(test)]
+use crate::uci::mock_uci_logger::{create_dir, remove_file, rename};
 use crate::uci::UwbErr;
 use async_trait::async_trait;
 use bytes::{BufMut, BytesMut};
 use log::{error, info};
+use std::marker::Unpin;
+use std::sync::Arc;
 use std::time::SystemTime;
-use tokio::fs::{create_dir, remove_file, rename, File, OpenOptions};
-use tokio::io::AsyncWriteExt;
+use tokio::fs::OpenOptions;
+#[cfg(not(test))]
+use tokio::fs::{create_dir, remove_file, rename};
+use tokio::io::{AsyncWrite, AsyncWriteExt};
 use tokio::sync::Mutex;
 use tokio::{task, time};
 use uwb_uci_packets::{
@@ -44,6 +50,9 @@ const LOG_DIR: &str = "/data/misc/apexdata/com.android.uwb/log";
 const FILE_NAME: &str = "uwb_uci.log";
 const LOG_HEADER: &[u8] = b"ucilogging";
 
+type SyncFile = Arc<Mutex<dyn AsyncWrite + Send + Sync + Unpin>>;
+type SyncFactory = Arc<Mutex<dyn FileFactory + Send + Sync>>;
+
 #[derive(Clone, PartialEq, Eq)]
 pub enum UciLogMode {
     Disabled,
@@ -59,7 +68,7 @@ enum Type {
 }
 
 #[derive(Clone)]
-struct UciLogConfig {
+pub struct UciLogConfig {
     path: String,
     mode: UciLogMode,
 }
@@ -79,14 +88,14 @@ pub trait UciLogger {
 }
 
 struct BufferedFile {
-    file: Option<File>,
+    file: Option<SyncFile>,
     size_count: usize,
     buffer: BytesMut,
     deleter_handle: Option<task::JoinHandle<()>>,
 }
 
 impl BufferedFile {
-    async fn open_next_file(&mut self, path: &str) -> Result<(), UwbErr> {
+    async fn open_next_file(&mut self, factory: SyncFactory, path: &str) -> Result<(), UwbErr> {
         info!("Open next file");
         self.close_file().await;
         if create_dir(LOG_DIR).await.is_err() {
@@ -105,11 +114,8 @@ impl BufferedFile {
                 error!("Failed to remove file!");
             };
         }));
-        let mut file = create_file_using_open_options(path).await?;
-        file.write_all(b"ucilogging").await?;
-        if file.flush().await.is_err() {
-            error!("Failed to flush");
-        }
+        let mut file = factory.lock().await.create_file_using_open_options(path).await?;
+        write(&mut file, LOG_HEADER).await;
         self.file = Some(file);
         Ok(())
     }
@@ -128,55 +134,19 @@ impl BufferedFile {
 pub struct UciLoggerImpl {
     config: UciLogConfig,
     buf_file: Mutex<BufferedFile>,
+    file_factory: SyncFactory,
 }
 
 impl UciLoggerImpl {
-    pub async fn new(mode: UciLogMode) -> Self {
+    pub async fn new(mode: UciLogMode, file_factory: SyncFactory) -> Self {
         let config = UciLogConfig::new(mode);
-        let file = match OpenOptions::new()
-            .append(true)
-            .custom_flags(libc::O_NOFOLLOW)
-            .open(&config.path)
-            .await
-            .ok()
-        {
-            Some(f) => match f.metadata().await {
-                Ok(md) => match md.modified() {
-                    Ok(modified_date) => match SystemTime::now().duration_since(modified_date) {
-                        Ok(duration) => {
-                            if duration.as_secs() > UCI_LOG_LAST_FILE_STORE_TIME_SEC {
-                                Self::create_file(&config.path).await
-                            } else {
-                                Some(f)
-                            }
-                        }
-                        Err(e) => {
-                            error!("Failed to convert to duration {:?}", e);
-                            Some(f)
-                        }
-                    },
-                    Err(e) => {
-                        error!("Failed to get modified date {:?}", e);
-                        Some(f)
-                    }
-                },
-                Err(e) => {
-                    error!("Failed to get metadata {:?}", e);
-                    Some(f)
-                }
-            },
-            None => Self::create_file(&config.path).await,
-        };
-        let buf_file = BufferedFile {
-            size_count: match file {
-                Some(ref f) => f.metadata().await.unwrap().len().try_into().unwrap(),
-                None => 0,
-            },
-            file,
-            buffer: BytesMut::new(),
-            deleter_handle: None,
-        };
-        let ret = Self { config, buf_file: Mutex::new(buf_file) };
+        let mut factory = file_factory.lock().await;
+        factory.set_config(config.clone()).await;
+        let (file, size) = factory.new_file().await;
+        let buf_file =
+            BufferedFile { size_count: size, file, buffer: BytesMut::new(), deleter_handle: None };
+        let ret =
+            Self { config, buf_file: Mutex::new(buf_file), file_factory: file_factory.clone() };
         info!("UCI logger created");
         ret
     }
@@ -205,7 +175,7 @@ impl UciLoggerImpl {
         // Check whether exceeded the size limit
         let mut buf_file = self.buf_file.lock().await;
         if buf_file.size_count + bytes.len() + PKT_LOG_HEADER_SIZE > MAX_FILE_SIZE {
-            match buf_file.open_next_file(&self.config.path).await {
+            match buf_file.open_next_file(self.file_factory.clone(), &self.config.path).await {
                 Ok(()) => info!("New file created"),
                 Err(e) => error!("Open next file failed: {:?}", e),
             }
@@ -225,35 +195,14 @@ impl UciLoggerImpl {
         buf_file.buffer.put_slice(&bytes); // full packet.
         buf_file.size_count += bytes.len() + PKT_LOG_HEADER_SIZE;
     }
-    async fn create_file(path: &str) -> Option<File> {
-        if create_dir(LOG_DIR).await.is_err() {
-            error!("Failed to create dir");
-        }
-        if remove_file(path).await.is_err() {
-            error!("Failed to remove file!");
-        };
-        match create_file_using_open_options(path).await {
-            Ok(mut f) => {
-                write(&mut f, LOG_HEADER).await;
-                Some(f)
-            }
-            Err(e) => {
-                error!("Failed to create file {:?}", e);
-                None
-            }
-        }
-    }
-}
-
-async fn create_file_using_open_options(path: &str) -> Result<File, UwbErr> {
-    Ok(OpenOptions::new().write(true).create_new(true).open(path).await?)
 }
 
-async fn write(file: &mut File, buffer: &[u8]) {
-    if file.write_all(buffer).await.is_err() {
+async fn write(file: &mut SyncFile, buffer: &[u8]) {
+    let mut locked_file = file.lock().await;
+    if locked_file.write_all(buffer).await.is_err() {
         error!("Failed to write");
     }
-    if file.flush().await.is_err() {
+    if locked_file.flush().await.is_err() {
         error!("Failed to flush");
     }
 }
@@ -351,3 +300,241 @@ impl UciLogger for UciLoggerImpl {
         self.buf_file.lock().await.close_file().await;
     }
 }
+
+#[async_trait]
+pub trait FileFactory {
+    async fn new_file(&self) -> (Option<SyncFile>, usize);
+    async fn create_file_using_open_options(&self, path: &str) -> Result<SyncFile, UwbErr>;
+    async fn create_file_at_path(&self, path: &str) -> Option<SyncFile>;
+    async fn set_config(&mut self, config: UciLogConfig);
+}
+
+#[derive(Default)]
+pub struct RealFileFactory {
+    config: Option<UciLogConfig>,
+}
+
+#[async_trait]
+impl FileFactory for RealFileFactory {
+    async fn new_file(&self) -> (Option<SyncFile>, usize) {
+        match OpenOptions::new()
+            .append(true)
+            .custom_flags(libc::O_NOFOLLOW)
+            .open(&self.config.as_ref().unwrap().path)
+            .await
+            .ok()
+        {
+            Some(f) => {
+                let size = match f.metadata().await {
+                    Ok(md) => {
+                        let duration = match md.modified() {
+                            Ok(modified_date) => {
+                                match SystemTime::now().duration_since(modified_date) {
+                                    Ok(duration) => duration.as_secs(),
+                                    Err(e) => {
+                                        error!("Failed to convert to duration {:?}", e);
+                                        0
+                                    }
+                                }
+                            }
+                            Err(e) => {
+                                error!("Failed to convert to duration {:?}", e);
+                                0
+                            }
+                        };
+                        if duration > UCI_LOG_LAST_FILE_STORE_TIME_SEC {
+                            0
+                        } else {
+                            md.len().try_into().unwrap()
+                        }
+                    }
+                    Err(e) => {
+                        error!("Failed to get metadata {:?}", e);
+                        0
+                    }
+                };
+                match size {
+                    0 => {
+                        (self.create_file_at_path(&self.config.as_ref().unwrap().path).await, size)
+                    }
+                    _ => (Some(Arc::new(Mutex::new(f))), size),
+                }
+            }
+            None => (self.create_file_at_path(&self.config.as_ref().unwrap().path).await, 0),
+        }
+    }
+
+    async fn set_config(&mut self, config: UciLogConfig) {
+        self.config = Some(config);
+    }
+
+    async fn create_file_using_open_options(&self, path: &str) -> Result<SyncFile, UwbErr> {
+        Ok(Arc::new(Mutex::new(OpenOptions::new().write(true).create_new(true).open(path).await?)))
+    }
+    async fn create_file_at_path(&self, path: &str) -> Option<SyncFile> {
+        if create_dir(LOG_DIR).await.is_err() {
+            error!("Failed to create dir");
+        }
+        if remove_file(path).await.is_err() {
+            error!("Failed to remove file!");
+        }
+        match self.create_file_using_open_options(path).await {
+            Ok(mut f) => {
+                write(&mut f, LOG_HEADER).await;
+                Some(f)
+            }
+            Err(e) => {
+                error!("Failed to create file {:?}", e);
+                None
+            }
+        }
+    }
+}
+
+#[cfg(test)]
+mod tests {
+    use super::*;
+    use core::pin::Pin;
+    use core::task::{Context, Poll};
+    use log::debug;
+    use std::io::Error;
+    use uwb_uci_packets::{
+        AppConfigTlvType, DeviceState, DeviceStatusNtfBuilder, GetDeviceInfoCmdBuilder,
+        GetDeviceInfoRspBuilder, StatusCode,
+    };
+
+    struct MockLogFile;
+
+    impl MockLogFile {
+        #[allow(dead_code)]
+        async fn write_all(&mut self, _data: &[u8]) -> Result<(), UwbErr> {
+            debug!("Write to fake file");
+            Ok(())
+        }
+        #[allow(dead_code)]
+        async fn flush(&self) -> Result<(), UwbErr> {
+            debug!("Fake file flush success");
+            Ok(())
+        }
+    }
+
+    impl AsyncWrite for MockLogFile {
+        fn poll_write(
+            self: Pin<&mut Self>,
+            _cx: &mut Context<'_>,
+            _buf: &[u8],
+        ) -> Poll<Result<usize, Error>> {
+            Poll::Ready(Ok(0))
+        }
+
+        fn poll_flush(self: Pin<&mut Self>, _cx: &mut Context<'_>) -> Poll<Result<(), Error>> {
+            Poll::Ready(Ok(()))
+        }
+
+        fn poll_shutdown(self: Pin<&mut Self>, _cx: &mut Context<'_>) -> Poll<Result<(), Error>> {
+            Poll::Ready(Ok(()))
+        }
+    }
+
+    struct MockFileFactory;
+
+    #[async_trait]
+    impl FileFactory for MockFileFactory {
+        async fn new_file(&self) -> (Option<SyncFile>, usize) {
+            (Some(Arc::new(Mutex::new(MockLogFile {}))), 0)
+        }
+        async fn set_config(&mut self, _config: UciLogConfig) {}
+        async fn create_file_using_open_options(&self, _path: &str) -> Result<SyncFile, UwbErr> {
+            Ok(Arc::new(Mutex::new(MockLogFile {})))
+        }
+        async fn create_file_at_path(&self, _path: &str) -> Option<SyncFile> {
+            Some(Arc::new(Mutex::new(MockLogFile {})))
+        }
+    }
+
+    #[tokio::test]
+    async fn test_log_command() -> Result<(), UwbErr> {
+        let logger =
+            UciLoggerImpl::new(UciLogMode::Filtered, Arc::new(Mutex::new(MockFileFactory {})))
+                .await;
+        let cmd: UciCommandPacket = GetDeviceInfoCmdBuilder {}.build().into();
+        logger.log_uci_command(cmd).await;
+        let data = [0x20, 0x02, 0x00, 0x00, 0x00, 0x00, 0x00];
+        let buf_file = logger.buf_file.lock().await;
+        assert_eq!(1, buf_file.buffer[buf_file.buffer.len() - data.len() - 1]);
+        assert_eq!(data, buf_file.buffer[(buf_file.buffer.len() - data.len())..]);
+        Ok(())
+    }
+
+    #[tokio::test]
+    async fn test_log_response() -> Result<(), UwbErr> {
+        let logger =
+            UciLoggerImpl::new(UciLogMode::Filtered, Arc::new(Mutex::new(MockFileFactory {})))
+                .await;
+        let rsp = GetDeviceInfoRspBuilder {
+            status: StatusCode::UciStatusOk,
+            uci_version: 0,
+            mac_version: 0,
+            phy_version: 0,
+            uci_test_version: 0,
+            vendor_spec_info: vec![],
+        }
+        .build()
+        .into();
+        logger.log_uci_response(rsp).await;
+        let data = [
+            0x40, 0x02, 0x00, 0x0a, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
+            0x00, 0x00, 0x00,
+        ];
+        let buf_file = logger.buf_file.lock().await;
+        assert_eq!(2, buf_file.buffer[buf_file.buffer.len() - data.len() - 1]);
+        assert_eq!(data, buf_file.buffer[(buf_file.buffer.len() - data.len())..]);
+        Ok(())
+    }
+
+    #[tokio::test]
+    async fn test_log_notification() -> Result<(), UwbErr> {
+        let logger =
+            UciLoggerImpl::new(UciLogMode::Filtered, Arc::new(Mutex::new(MockFileFactory {})))
+                .await;
+        let ntf =
+            DeviceStatusNtfBuilder { device_state: DeviceState::DeviceStateReady }.build().into();
+        logger.log_uci_notification(ntf).await;
+        let data = [0x60, 0x01, 0x00, 0x01, 0x00, 0x00, 0x00, 0x01];
+        let buf_file = logger.buf_file.lock().await;
+        assert_eq!(3, buf_file.buffer[buf_file.buffer.len() - data.len() - 1]);
+        assert_eq!(data, buf_file.buffer[(buf_file.buffer.len() - data.len())..]);
+        Ok(())
+    }
+
+    #[tokio::test]
+    async fn test_disabled_log() -> Result<(), UwbErr> {
+        let logger =
+            UciLoggerImpl::new(UciLogMode::Disabled, Arc::new(Mutex::new(MockFileFactory {})))
+                .await;
+        let cmd: UciCommandPacket = GetDeviceInfoCmdBuilder {}.build().into();
+        logger.log_uci_command(cmd).await;
+        let buf_file = logger.buf_file.lock().await;
+        assert!(buf_file.buffer.is_empty());
+        Ok(())
+    }
+
+    #[tokio::test]
+    async fn test_filter_log() -> Result<(), UwbErr> {
+        let logger =
+            UciLoggerImpl::new(UciLogMode::Filtered, Arc::new(Mutex::new(MockFileFactory {})))
+                .await;
+        let rsp = SessionGetAppConfigRspBuilder {
+            status: StatusCode::UciStatusOk,
+            tlvs: vec![AppConfigTlv { cfg_id: AppConfigTlvType::VendorId, v: vec![0x02, 0x02] }],
+        }
+        .build()
+        .into();
+        logger.log_uci_response(rsp).await;
+        let data = [0x41, 0x04, 0x00, 0x06, 0x00, 0x00, 0x00, 0x00, 0x01, 0x27, 0x02, 0x00, 0x00];
+        let buf_file = logger.buf_file.lock().await;
+        assert_eq!(2, buf_file.buffer[buf_file.buffer.len() - data.len() - 1]);
+        assert_eq!(data, buf_file.buffer[(buf_file.buffer.len() - data.len())..]);
+        Ok(())
+    }
+}