add debugging for x5_camera

Author: oxkitsune

Cargo.lock

@@ -54,6 +54,7 @@ pub struct RpcClient {
     request_writer: rustdds::no_key::DataWriter<RpcReqMsg>,
     response_reader: Arc<Mutex<DataReader<RpcRespMsg>>>,
     default_timeout: Duration,
+    service_topic: String,
 }
 
 #[derive(Debug, Deserialize, Default)]
@@ -99,6 +100,33 @@ fn normalize_service_topic(service_topic: &str) -> String {
     trimmed.to_owned()
 }
 
+fn rpc_debug_enabled() -> bool {
+    std::env::var("BOOSTER_RPC_DEBUG")
+        .map(|value| {
+            let value = value.trim();
+            value == "1"
+                || value.eq_ignore_ascii_case("true")
+                || value.eq_ignore_ascii_case("yes")
+                || value.eq_ignore_ascii_case("on")
+        })
+        .unwrap_or(false)
+}
+
+fn preview_for_log(value: &str, max_chars: usize) -> String {
+    let mut preview = String::new();
+    let mut chars = value.chars();
+    for _ in 0..max_chars {
+        match chars.next() {
+            Some(ch) => preview.push(ch),
+            None => return preview.replace('\n', "\\n"),
+        }
+    }
+    if chars.next().is_some() {
+        preview.push_str("...");
+    }
+    preview.replace('\n', "\\n")
+}
+
 impl RpcClient {
     pub fn for_topic(options: RpcClientOptions, service_topic: impl Into<String>) -> Result<Self> {
         Self::new(options.with_service_topic(service_topic))
@@ -120,6 +148,7 @@ impl RpcClient {
             request_writer: request_writer.into_inner(),
             response_reader: Arc::new(Mutex::new(response_reader)),
             default_timeout: options.default_timeout,
+            service_topic,
         })
     }
 
@@ -199,9 +228,23 @@ impl RpcClient {
     where
         R: DeserializeOwned + Send + 'static,
     {
+        let debug_enabled = rpc_debug_enabled();
         let request_id = Uuid::new_v4().to_string();
         let body = body.into();
         let header = serde_json::json!({ "api_id": api_id }).to_string();
+        let service_topic = self.service_topic.clone();
+
+        if debug_enabled {
+            tracing::debug!(
+                target: "booster_sdk::rpc",
+                service_topic = %service_topic,
+                api_id,
+                request_uuid = %request_id,
+                header = %preview_for_log(&header, 200),
+                body = %preview_for_log(&body, 300),
+                "send rpc request"
+            );
+        }
 
         let request = RpcReqMsg {
             uuid: request_id.clone(),
@@ -224,19 +267,48 @@ impl RpcClient {
                 .map_err(|err| DdsError::ReceiveFailed(err.to_string()))?;
             loop {
                 if Instant::now() >= deadline {
+                    if debug_enabled {
+                        tracing::warn!(
+                            target: "booster_sdk::rpc",
+                            service_topic = %service_topic,
+                            api_id,
+                            request_uuid = %request_id,
+                            timeout_ms = timeout.as_millis(),
+                            "rpc timeout"
+                        );
+                    }
                     return Err(RpcError::Timeout { timeout }.into());
                 }
 
                 match reader.take_next_sample() {
                     Ok(Some(sample)) => {
                         let response = sample.into_value();
-                        if response.uuid != request_id {
-                            continue;
-                        }
 
                         let status_code = parse_status_from_header(&response.header).unwrap_or(0);
+                        if debug_enabled {
+                            tracing::debug!(
+                                target: "booster_sdk::rpc",
+                                service_topic = %service_topic,
+                                api_id,
+                                request_uuid = %request_id,
+                                response_uuid = %response.uuid,
+                                status_code,
+                                header = %preview_for_log(&response.header, 200),
+                                body = %preview_for_log(&response.body, 300),
+                                "recv rpc response"
+                            );
+                        }
 
                         if status_code == -1 {
+                            if debug_enabled {
+                                tracing::debug!(
+                                    target: "booster_sdk::rpc",
+                                    service_topic = %service_topic,
+                                    api_id,
+                                    request_uuid = %request_id,
+                                    "ignoring intermediate status=-1"
+                                );
+                            }
                             continue;
                         }
 
@@ -260,6 +332,16 @@ impl RpcClient {
                     }
                     Ok(None) => std::thread::sleep(Duration::from_millis(5)),
                     Err(err) => {
+                        if debug_enabled {
+                            tracing::warn!(
+                                target: "booster_sdk::rpc",
+                                service_topic = %service_topic,
+                                api_id,
+                                request_uuid = %request_id,
+                                error = %err,
+                                "rpc receive error"
+                            );
+                        }
                         return Err(DdsError::ReceiveFailed(err.to_string()).into());
                     }
                 }

booster_sdk/src/dds/rpc.rs

@@ -53,7 +53,7 @@ pub fn rpc_request_topic(service_topic: &str) -> TopicSpec {
     TopicSpec {
         name: format!("{service_topic}Req"),
         type_name: TYPE_RPC_REQ,
-        qos: qos_reliable_keep_last(10),
+        qos: qos_best_effort_keep_last(10),
         kind: TopicKind::NoKey,
     }
 }
@@ -62,7 +62,7 @@ pub fn rpc_response_topic(service_topic: &str) -> TopicSpec {
     TopicSpec {
         name: format!("{service_topic}Resp"),
         type_name: TYPE_RPC_RESP,
-        qos: qos_reliable_keep_last(10),
+        qos: qos_best_effort_keep_last(10),
         kind: TopicKind::NoKey,
     }
 }

booster_sdk/src/dds/topics.rs

@@ -16,3 +16,4 @@ booster_sdk = { workspace = true }
 pyo3 = { workspace = true }
 tokio = { workspace = true }
 tracing = { workspace = true }
+tracing-subscriber = { workspace = true }

booster_sdk_py/Cargo.toml

@@ -1,17 +1,55 @@
 mod client;
 mod runtime;
 
+use std::sync::OnceLock;
+
 use booster_sdk::{client::ai::BOOSTER_ROBOT_USER_ID, types::BoosterError};
 use pyo3::{exceptions::PyException, prelude::*, types::PyModule};
+use tracing_subscriber::{EnvFilter, fmt};
 
 pyo3::create_exception!(booster_sdk_bindings, BoosterSdkError, PyException);
 
 pub(crate) fn to_py_err(err: BoosterError) -> PyErr {
     BoosterSdkError::new_err(err.to_string())
 }
 
+fn rpc_debug_enabled() -> bool {
+    std::env::var("BOOSTER_RPC_DEBUG")
+        .map(|value| {
+            let value = value.trim();
+            value == "1"
+                || value.eq_ignore_ascii_case("true")
+                || value.eq_ignore_ascii_case("yes")
+                || value.eq_ignore_ascii_case("on")
+        })
+        .unwrap_or(false)
+}
+
+fn init_tracing_for_python() {
+    static INIT: OnceLock<()> = OnceLock::new();
+    INIT.get_or_init(|| {
+        if !rpc_debug_enabled() {
+            return;
+        }
+
+        let env_filter = std::env::var("RUST_LOG")
+            .ok()
+            .and_then(|value| EnvFilter::try_new(value).ok())
+            .unwrap_or_else(|| EnvFilter::new("booster_sdk::rpc=debug"));
+
+        let _ = fmt()
+            .with_env_filter(env_filter)
+            .with_target(true)
+            .with_thread_ids(true)
+            .with_writer(std::io::stderr)
+            .try_init();
+    });
+}
+
 #[pymodule]
 fn booster_sdk_bindings(py: Python<'_>, m: &Bound<'_, PyModule>) -> PyResult<()> {
+    init_tracing_for_python();
+
     m.add("BoosterSdkError", py.get_type::<BoosterSdkError>())?;
     m.add("BOOSTER_ROBOT_USER_ID", BOOSTER_ROBOT_USER_ID)?;