Move open_next_file into BufferedFile to avoid deadlock.

Test: manual
Bug: 216512326
Bug: 222342112
Change-Id: Ic7f0a87f6433d5d1dc1e262e6c94d405cceec2d3

3 files changed, 126 insertions, 81 deletions

diff --git a/src/Android.bp b/src/Android.bp
index 9d1de4c..2e60932 100755
--- a/src/Android.bp
+++ b/src/Android.bp
@@ -21,6 +21,7 @@ rust_defaults {
         "liblog_rust",
         "liblogger",
         "libnum_traits",
+        "librustutils",
         "libthiserror",
         "libtokio",
         "libuwb_uci_packets",
diff --git a/src/rust/adaptation/mod.rs b/src/rust/adaptation/mod.rs
index 47186a0..cb8aa11 100644
--- a/src/rust/adaptation/mod.rs
+++ b/src/rust/adaptation/mod.rs
@@ -14,7 +14,8 @@ use android_hardware_uwb::aidl::android::hardware::uwb::{
 use android_hardware_uwb::binder::{BinderFeatures, Interface, Result as BinderResult, Strong};
 use async_trait::async_trait;
 use binder_tokio::{Tokio, TokioRuntime};
-use log::error;
+use log::{error, warn};
+use rustutils::system_properties;
 use std::sync::Arc;
 use tokio::runtime::Handle;
 use tokio::sync::mpsc;
@@ -23,6 +24,8 @@ use uwb_uci_packets::{Packet, UciCommandPacket, UciPacketChild, UciPacketPacket}
 type Result<T> = std::result::Result<T, UwbErr>;
 type SyncUciLogger = Arc<dyn UciLogger + Send + Sync>;
 
+const UCI_LOG_DEFAULT: UciLogMode = UciLogMode::Disabled;
+
 pub struct UwbClientCallback {
     rsp_sender: mpsc::UnboundedSender<HalCallback>,
     logger: SyncUciLogger,
@@ -104,7 +107,23 @@ pub struct UwbAdaptationImpl {
 impl UwbAdaptationImpl {
     pub async fn new(rsp_sender: mpsc::UnboundedSender<HalCallback>) -> Result<Self> {
         let hal = get_hal_service().await?;
-        let logger = UciLoggerImpl::new(UciLogMode::Disabled).await;
+        let mode = match system_properties::read("persist.uwb.uci_logger_mode") {
+            Ok(Some(logger_mode)) => match logger_mode.as_str() {
+                "disabled" => UciLogMode::Disabled,
+                "filtered" => UciLogMode::Filtered,
+                "enabled" => UciLogMode::Enabled,
+                str => {
+                    warn!("Logger mode not recognized! Value: {:?}", str);
+                    UCI_LOG_DEFAULT
+                }
+            },
+            Ok(None) => UCI_LOG_DEFAULT,
+            Err(e) => {
+                error!("Failed to get uci_logger_mode {:?}", e);
+                UCI_LOG_DEFAULT
+            }
+        };
+        let logger = UciLoggerImpl::new(mode).await;
         Ok(UwbAdaptationImpl { hal, rsp_sender, logger: Arc::new(logger) })
     }
 }
diff --git a/src/rust/uci/uci_logger.rs b/src/rust/uci/uci_logger.rs
index 7ecf0f7..883ecda 100644
--- a/src/rust/uci/uci_logger.rs
+++ b/src/rust/uci/uci_logger.rs
@@ -42,6 +42,7 @@ const FILE_NAME: &str = "uwb_uci.log";
 pub enum UciLogMode {
     Disabled,
     Filtered,
+    Enabled,
 }
 
 #[derive(Clone)]
@@ -78,6 +79,41 @@ struct BufferedFile {
     buffer: BytesMut,
 }
 
+impl BufferedFile {
+    async fn open_next_file(&mut self, path: &str) -> Result<(), UwbErr> {
+        info!("Open next file");
+        self.close_file().await;
+        if create_dir(LOG_DIR).await.is_err() {
+            error!("Failed to create dir");
+        }
+        if rename(path, path.to_owned() + ".last").await.is_err() {
+            error!("Failed to rename the file");
+        }
+        let mut file = File::create(path).await?;
+        file.write_all(b"ucilogging").await?;
+        if file.flush().await.is_err() {
+            error!("Failed to flush");
+        }
+        self.file = Some(file);
+        Ok(())
+    }
+
+    async fn close_file(&mut self) {
+        if let Some(file) = &mut self.file {
+            info!("UCI log file closing");
+            if file.write_all(&self.buffer).await.is_err() {
+                error!("Failed to write");
+            }
+            if file.flush().await.is_err() {
+                error!("Failed to flush");
+            }
+            self.file = None;
+            self.buffer.clear();
+        }
+        self.size_count = 0;
+    }
+}
+
 pub struct UciLoggerImpl {
     config: UciLogConfig,
     buf_file: Mutex<BufferedFile>,
@@ -147,7 +183,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 > self.config.max_file_size {
-            match self.open_next_file().await {
+            match buf_file.open_next_file(&self.config.path).await {
                 Ok(()) => info!("New file created"),
                 Err(e) => error!("Open next file failed: {:?}", e),
             }
@@ -161,82 +197,84 @@ impl UciLoggerImpl {
         buf_file.buffer.put_slice(&bytes); // full packet.
         buf_file.size_count += bytes.len() + PKT_LOG_HEADER_SIZE;
     }
-
-    async fn open_next_file(&self) -> Result<(), UwbErr> {
-        info!("Open next file");
-        self.close_file().await;
-        if create_dir(LOG_DIR).await.is_err() {
-            error!("Failed to create dir");
-        }
-        if rename(&self.config.path, self.config.path.clone() + ".last").await.is_err() {
-            error!("Failed to rename the file");
-        }
-        let mut file = File::create(&self.config.path).await?;
-        file.write_all(b"ucilogging").await?;
-        if file.flush().await.is_err() {
-            error!("Failed to flush");
-        }
-        self.buf_file.lock().await.file = Some(file);
-        Ok(())
-    }
 }
 
 #[async_trait]
 impl UciLogger for UciLoggerImpl {
     async fn log_uci_command(&self, cmd: UciCommandPacket) {
-        if let UciLogMode::Disabled = self.config.mode {
-            return;
-        }
-        // Only filter SET_APP_CONFIG_CMD
-        let filtered_cmd: UciCommandPacket = match cmd.specialize() {
-            UciCommandChild::SessionCommand(session_cmd) => match session_cmd.specialize() {
-                SessionCommandChild::SessionSetAppConfigCmd(set_config_cmd) => {
-                    let session_id = set_config_cmd.get_session_id();
-                    let tlvs = set_config_cmd.get_tlvs();
-                    let mut filtered_tlvs = Vec::new();
-                    for tlv in tlvs {
-                        if VENDOR_ID == tlv.cfg_id as u64 || STATIC_STS_IV == tlv.cfg_id as u64 {
-                            filtered_tlvs
-                                .push(AppConfigTlv { cfg_id: tlv.cfg_id, v: vec![0; tlv.v.len()] });
-                        } else {
-                            filtered_tlvs.push(tlv.clone());
+        match self.config.mode {
+            UciLogMode::Disabled => return,
+            UciLogMode::Enabled => self.log_uci_packet(cmd.into()).await,
+            UciLogMode::Filtered => {
+                let filtered_cmd: UciCommandPacket = match cmd.specialize() {
+                    UciCommandChild::SessionCommand(session_cmd) => {
+                        match session_cmd.specialize() {
+                            SessionCommandChild::SessionSetAppConfigCmd(set_config_cmd) => {
+                                let session_id = set_config_cmd.get_session_id();
+                                let tlvs = set_config_cmd.get_tlvs();
+                                let mut filtered_tlvs = Vec::new();
+                                for tlv in tlvs {
+                                    if VENDOR_ID == tlv.cfg_id as u64
+                                        || STATIC_STS_IV == tlv.cfg_id as u64
+                                    {
+                                        filtered_tlvs.push(AppConfigTlv {
+                                            cfg_id: tlv.cfg_id,
+                                            v: vec![0; tlv.v.len()],
+                                        });
+                                    } else {
+                                        filtered_tlvs.push(tlv.clone());
+                                    }
+                                }
+                                SessionSetAppConfigCmdBuilder { session_id, tlvs: filtered_tlvs }
+                                    .build()
+                                    .into()
+                            }
+                            _ => session_cmd.into(),
                         }
                     }
-                    SessionSetAppConfigCmdBuilder { session_id, tlvs: filtered_tlvs }.build().into()
-                }
-                _ => session_cmd.into(),
-            },
-            _ => cmd,
-        };
-        self.log_uci_packet(filtered_cmd.into()).await;
+                    _ => cmd,
+                };
+                self.log_uci_packet(filtered_cmd.into()).await;
+            }
+        }
     }
 
     async fn log_uci_response(&self, rsp: UciResponsePacket) {
-        if let UciLogMode::Disabled = self.config.mode {
-            return;
-        }
-        // Only filter GET_APP_CONFIG_RSP
-        let filtered_rsp: UciResponsePacket = match rsp.specialize() {
-            UciResponseChild::SessionResponse(session_rsp) => match session_rsp.specialize() {
-                SessionResponseChild::SessionGetAppConfigRsp(rsp) => {
-                    let status = rsp.get_status();
-                    let tlvs = rsp.get_tlvs();
-                    let mut filtered_tlvs = Vec::new();
-                    for tlv in tlvs {
-                        if VENDOR_ID == tlv.cfg_id as u64 || STATIC_STS_IV == tlv.cfg_id as u64 {
-                            filtered_tlvs
-                                .push(AppConfigTlv { cfg_id: tlv.cfg_id, v: vec![0; tlv.v.len()] });
-                        } else {
-                            filtered_tlvs.push(tlv.clone());
+        match self.config.mode {
+            UciLogMode::Disabled => return,
+            UciLogMode::Enabled => self.log_uci_packet(rsp.into()).await,
+            UciLogMode::Filtered => {
+                let filtered_rsp: UciResponsePacket = match rsp.specialize() {
+                    UciResponseChild::SessionResponse(session_rsp) => {
+                        match session_rsp.specialize() {
+                            SessionResponseChild::SessionGetAppConfigRsp(rsp) => {
+                                let status = rsp.get_status();
+                                let tlvs = rsp.get_tlvs();
+                                let mut filtered_tlvs = Vec::new();
+                                for tlv in tlvs {
+                                    if VENDOR_ID == tlv.cfg_id as u64
+                                        || STATIC_STS_IV == tlv.cfg_id as u64
+                                    {
+                                        filtered_tlvs.push(AppConfigTlv {
+                                            cfg_id: tlv.cfg_id,
+                                            v: vec![0; tlv.v.len()],
+                                        });
+                                    } else {
+                                        filtered_tlvs.push(tlv.clone());
+                                    }
+                                }
+                                SessionGetAppConfigRspBuilder { status, tlvs: filtered_tlvs }
+                                    .build()
+                                    .into()
+                            }
+                            _ => session_rsp.into(),
                         }
                     }
-                    SessionGetAppConfigRspBuilder { status, tlvs: filtered_tlvs }.build().into()
-                }
-                _ => session_rsp.into(),
-            },
-            _ => rsp,
-        };
-        self.log_uci_packet(filtered_rsp.into()).await;
+                    _ => rsp,
+                };
+                self.log_uci_packet(filtered_rsp.into()).await;
+            }
+        }
     }
 
     async fn log_uci_notification(&self, ntf: UciNotificationPacket) {
@@ -251,20 +289,7 @@ impl UciLogger for UciLoggerImpl {
         if self.config.mode == UciLogMode::Disabled {
             return;
         }
-        info!("UCI log file closing");
-        let mut buf_file = self.buf_file.lock().await;
-        let buffer = buf_file.buffer.clone();
-        if let Some(file) = &mut buf_file.file {
-            if file.write_all(&buffer).await.is_err() {
-                error!("Failed to write");
-            }
-            if file.flush().await.is_err() {
-                error!("Failed to flush");
-            }
-            buf_file.file = None;
-            buf_file.buffer.clear();
-        }
-        buf_file.size_count = 0;
+        self.buf_file.lock().await.close_file().await;
     }
 }