Improve routing logging

eclipse-zenoh · Feb 5, 2024 · ef1034e · ef1034e
1 parent 2c18758
commit ef1034e
Show file tree

Hide file tree

Showing 16 changed files with 88 additions and 111 deletions.
diff --git a/zenoh/src/net/routing/dispatcher/face.rs b/zenoh/src/net/routing/dispatcher/face.rs
@@ -204,7 +204,7 @@ impl Primitives for Face {
                 pull_data(&self.tables.tables, &self.state.clone(), msg.wire_expr);
             }
             _ => {
-                log::error!("Unsupported request");
+                log::error!("{} Unsupported request!", self);
             }
         }
     }

diff --git a/zenoh/src/net/routing/dispatcher/pubsub.rs b/zenoh/src/net/routing/dispatcher/pubsub.rs
@@ -39,13 +39,19 @@ pub(crate) fn declare_subscription(
     sub_info: &SubscriberInfo,
     node_id: NodeId,
 ) {
-    log::debug!("Declare subscription {}", face);
     let rtables = zread!(tables.tables);
     match rtables
         .get_mapping(face, &expr.scope, expr.mapping)
         .cloned()
     {
         Some(mut prefix) => {
+            log::debug!(
+                "{} Declare subscriber {} ({}{})",
+                face,
+                id,
+                prefix.expr(),
+                expr.suffix
+            );
             let res = Resource::get_resource(&prefix, &expr.suffix);
             let (mut res, mut wtables) =
                 if res.as_ref().map(|r| r.context.is_some()).unwrap_or(false) {
@@ -87,7 +93,12 @@ pub(crate) fn declare_subscription(
             }
             drop(wtables);
         }
-        None => log::error!("Declare subscription for unknown scope {}!", expr.scope),
+        None => log::error!(
+            "{} Declare subscriber {} for unknown scope {}!",
+            face,
+            id,
+            expr.scope
+        ),
     }
 }
 
@@ -99,7 +110,6 @@ pub(crate) fn undeclare_subscription(
     expr: &WireExpr,
     node_id: NodeId,
 ) {
-    log::debug!("Undeclare subscription {}", face);
     let res = if expr.is_empty() {
         None
     } else {
@@ -108,18 +118,30 @@ pub(crate) fn undeclare_subscription(
             Some(prefix) => match Resource::get_resource(prefix, expr.suffix.as_ref()) {
                 Some(res) => Some(res),
                 None => {
-                    log::error!("Undeclare unknown subscription!");
+                    if log::log_enabled!(log::Level::Error) {
+                        log::error!(
+                            "{} Undeclare unknown subscriber {}{}!",
+                            face,
+                            prefix.expr(),
+                            expr.suffix
+                        );
+                    }
                     return;
                 }
             },
             None => {
-                log::error!("Undeclare subscription with unknown scope!");
+                log::error!(
+                    "{} Undeclare subscriber with unknown scope {}",
+                    face,
+                    expr.scope
+                );
                 return;
             }
         }
     };
     let mut wtables = zwrite!(tables.tables);
     if let Some(mut res) = hat_code.undeclare_subscription(&mut wtables, face, id, res, node_id) {
+        log::debug!("{} Undeclare subscriber {} ({})", face, id, res.expr());
         disable_matches_data_routes(&mut wtables, &mut res);
         drop(wtables);
 
@@ -139,7 +161,7 @@ pub(crate) fn undeclare_subscription(
         Resource::clean(&mut res);
         drop(wtables);
     } else {
-        log::error!("Undeclare unknown subscription {}:{}", face, id);
+        log::error!("{} Undeclare unknown subscriber {}", face, id);
     }
 }
 
@@ -447,7 +469,8 @@ pub fn full_reentrant_route_data(
     match tables.get_mapping(face, &expr.scope, expr.mapping).cloned() {
         Some(prefix) => {
             log::trace!(
-                "Route data for res {}{}",
+                "{} Route data for res {}{}",
+                face,
                 prefix.expr(),
                 expr.suffix.as_ref()
             );
@@ -563,7 +586,7 @@ pub fn full_reentrant_route_data(
             }
         }
         None => {
-            log::error!("Route data with unknown scope {}!", expr.scope);
+            log::error!("{} Route data with unknown scope {}!", face, expr.scope);
         }
     }
 }
@@ -604,28 +627,31 @@ pub fn pull_data(tables_ref: &RwLock<Tables>, face: &Arc<FaceState>, expr: WireE
                         }
                         None => {
                             log::error!(
-                                "Pull data for unknown subscription {} (no info)!",
+                                "{} Pull data for unknown subscriber {} (no info)!",
+                                face,
                                 prefix.expr() + expr.suffix.as_ref()
                             );
                         }
                     },
                     None => {
                         log::error!(
-                            "Pull data for unknown subscription {} (no context)!",
+                            "{} Pull data for unknown subscriber {} (no context)!",
+                            face,
                             prefix.expr() + expr.suffix.as_ref()
                         );
                     }
                 }
             }
             None => {
                 log::error!(
-                    "Pull data for unknown subscription {} (no resource)!",
+                    "{} Pull data for unknown subscriber {} (no resource)!",
+                    face,
                     prefix.expr() + expr.suffix.as_ref()
                 );
             }
         },
         None => {
-            log::error!("Pull data with unknown scope {}!", expr.scope);
+            log::error!("{} Pull data with unknown scope {}!", face, expr.scope);
         }
     };
 }
diff --git a/zenoh/src/net/routing/dispatcher/queries.rs b/zenoh/src/net/routing/dispatcher/queries.rs
@@ -48,13 +48,18 @@ pub(crate) fn declare_queryable(
     qabl_info: &QueryableInfo,
     node_id: NodeId,
 ) {
-    log::debug!("Register queryable {}", face);
     let rtables = zread!(tables.tables);
     match rtables
         .get_mapping(face, &expr.scope, expr.mapping)
         .cloned()
     {
         Some(mut prefix) => {
+            log::debug!(
+                "{} Declare queryable ({}{})",
+                face,
+                prefix.expr(),
+                expr.suffix
+            );
             let res = Resource::get_resource(&prefix, &expr.suffix);
             let (mut res, mut wtables) =
                 if res.as_ref().map(|r| r.context.is_some()).unwrap_or(false) {
@@ -93,7 +98,11 @@ pub(crate) fn declare_queryable(
             }
             drop(wtables);
         }
-        None => log::error!("Declare queryable for unknown scope {}!", expr.scope),
+        None => log::error!(
+            "{} Declare queryable for unknown scope {}!",
+            face,
+            expr.scope
+        ),
     }
 }
 
@@ -108,6 +117,7 @@ pub(crate) fn undeclare_queryable(
     match rtables.get_mapping(face, &expr.scope, expr.mapping) {
         Some(prefix) => match Resource::get_resource(prefix, expr.suffix.as_ref()) {
             Some(mut res) => {
+                log::debug!("{} Undeclare queryable ({})", face, res.expr());
                 drop(rtables);
                 let mut wtables = zwrite!(tables.tables);
 
@@ -129,9 +139,18 @@ pub(crate) fn undeclare_queryable(
                 Resource::clean(&mut res);
                 drop(wtables);
             }
-            None => log::error!("Undeclare unknown queryable!"),
+            None => log::error!(
+                "{} Undeclare unknown queryable ({}{})!",
+                face,
+                prefix.expr(),
+                expr.suffix
+            ),
         },
-        None => log::error!("Undeclare queryable with unknown scope!"),
+        None => log::error!(
+            "{} Undeclare queryable with unknown scope {}!",
+            face,
+            expr.scope
+        ),
     }
 }
 
@@ -680,8 +699,9 @@ pub fn route_query(
         }
         None => {
             log::error!(
-                "Route query with unknown scope {}! Send final reply.",
-                expr.scope
+                "{} Route query with unknown scope {}! Send final reply.",
+                face,
+                expr.scope,
             );
             drop(rtables);
             face.primitives

diff --git a/zenoh/src/net/routing/dispatcher/resource.rs b/zenoh/src/net/routing/dispatcher/resource.rs
@@ -649,7 +649,11 @@ pub fn register_expr(
                 let mut fullexpr = prefix.expr();
                 fullexpr.push_str(expr.suffix.as_ref());
                 if res.expr() != fullexpr {
-                    log::error!("Resource {} remapped. Remapping unsupported!", expr_id);
+                    log::error!(
+                        "{} Resource {} remapped. Remapping unsupported!",
+                        face,
+                        expr_id
+                    );
                 }
             }
             None => {
@@ -697,15 +701,19 @@ pub fn register_expr(
                 drop(wtables);
             }
         },
-        None => log::error!("Declare resource with unknown scope {}!", expr.scope),
+        None => log::error!(
+            "{} Declare resource with unknown scope {}!",
+            face,
+            expr.scope
+        ),
     }
 }
 
 pub fn unregister_expr(tables: &TablesLock, face: &mut Arc<FaceState>, expr_id: ExprId) {
     let wtables = zwrite!(tables.tables);
     match get_mut_unchecked(face).remote_mappings.remove(&expr_id) {
         Some(mut res) => Resource::clean(&mut res),
-        None => log::error!("Undeclare unknown resource!"),
+        None => log::error!("{} Undeclare unknown resource!", face),
     }
     drop(wtables);
 }
diff --git a/zenoh/src/net/routing/hat/client/mod.rs b/zenoh/src/net/routing/hat/client/mod.rs
@@ -131,15 +131,15 @@ impl HatBaseTrait for HatCode {
         face.local_mappings.clear();
 
         let mut subs_matches = vec![];
-        for (id, mut res) in face
+        for (_id, mut res) in face
             .hat
             .downcast_mut::<HatFace>()
             .unwrap()
             .remote_subs
             .drain()
         {
             get_mut_unchecked(&mut res).session_ctxs.remove(&face.id);
-            undeclare_client_subscription(&mut wtables, &mut face_clone, id, &mut res);
+            undeclare_client_subscription(&mut wtables, &mut face_clone, &mut res);
 
             if res.context.is_some() {
                 for match_ in &res.context().matches {

diff --git a/zenoh/src/net/routing/hat/client/pubsub.rs b/zenoh/src/net/routing/hat/client/pubsub.rs
@@ -92,7 +92,6 @@ fn register_client_subscription(
     // Register subscription
     {
         let res = get_mut_unchecked(res);
-        log::debug!("Register subscription {} for {}", res.expr(), face);
         match res.session_ctxs.get_mut(&face.id) {
             Some(ctx) => match &ctx.subs {
                 Some(info) => {
@@ -192,10 +191,8 @@ fn propagate_forget_simple_subscription(tables: &mut Tables, res: &Arc<Resource>
 pub(super) fn undeclare_client_subscription(
     tables: &mut Tables,
     face: &mut Arc<FaceState>,
-    id: SubscriberId,
     res: &mut Arc<Resource>,
 ) {
-    log::debug!("Unregister client subscription {} for {}", id, face);
     if !face_hat_mut!(face).remote_subs.values().any(|s| *s == *res) {
         if let Some(ctx) = get_mut_unchecked(res).session_ctxs.get_mut(&face.id) {
             get_mut_unchecked(ctx).subs = None;
@@ -233,7 +230,7 @@ fn forget_client_subscription(
     id: SubscriberId,
 ) -> Option<Arc<Resource>> {
     if let Some(mut res) = face_hat_mut!(face).remote_subs.remove(&id) {
-        undeclare_client_subscription(tables, face, id, &mut res);
+        undeclare_client_subscription(tables, face, &mut res);
         Some(res)
     } else {
         None

diff --git a/zenoh/src/net/routing/hat/client/queries.rs b/zenoh/src/net/routing/hat/client/queries.rs
@@ -120,7 +120,6 @@ fn register_client_queryable(
     // Register queryable
     {
         let res = get_mut_unchecked(res);
-        log::debug!("Register queryable {} (face: {})", res.expr(), face,);
         get_mut_unchecked(res.session_ctxs.entry(face.id).or_insert_with(|| {
             Arc::new(SessionContext {
                 face: face.clone(),
@@ -187,7 +186,6 @@ pub(super) fn undeclare_client_queryable(
     face: &mut Arc<FaceState>,
     res: &mut Arc<Resource>,
 ) {
-    log::debug!("Unregister client queryable {} for {}", res.expr(), face);
     if let Some(ctx) = get_mut_unchecked(res).session_ctxs.get_mut(&face.id) {
         get_mut_unchecked(ctx).qabl = None;
         if ctx.qabl.is_none() {

diff --git a/zenoh/src/net/routing/hat/linkstate_peer/mod.rs b/zenoh/src/net/routing/hat/linkstate_peer/mod.rs
@@ -130,7 +130,6 @@ impl HatTables {
     }
 
     fn schedule_compute_trees(&mut self, tables_ref: Arc<TablesLock>) {
-        log::trace!("Schedule computations");
         if self.peers_trees_task.is_none() {
             let task = Some(async_std::task::spawn(async move {
                 async_std::task::sleep(std::time::Duration::from_millis(
@@ -146,7 +145,6 @@ impl HatTables {
                 pubsub::pubsub_tree_change(&mut tables, &new_childs);
                 queries::queries_tree_change(&mut tables, &new_childs);
 
-                log::trace!("Computations completed");
                 hat_mut!(tables).peers_trees_task = None;
             }));
             self.peers_trees_task = task;
@@ -252,15 +250,15 @@ impl HatBaseTrait for HatCode {
         face.local_mappings.clear();
 
         let mut subs_matches = vec![];
-        for (id, mut res) in face
+        for (_id, mut res) in face
             .hat
             .downcast_mut::<HatFace>()
             .unwrap()
             .remote_subs
             .drain()
         {
             get_mut_unchecked(&mut res).session_ctxs.remove(&face.id);
-            undeclare_client_subscription(&mut wtables, &mut face_clone, id, &mut res);
+            undeclare_client_subscription(&mut wtables, &mut face_clone, &mut res);
 
             if res.context.is_some() {
                 for match_ in &res.context().matches {
-Original file line number
+Diff line change
@@ Expand Up / @@ -204,7 +204,7 @@ impl Primitives for Face { @@
                     pull_data(&self.tables.tables, &self.state.clone(), msg.wire_expr);
                 }
                 _ => {
-                    log::error!("Unsupported request");
+                    log::error!("{} Unsupported request!", self);
                 }
             }
         }
@@ Expand Down @@