feat(gtest): add logging to gtest remoting impl (#768)

Cargo.toml

@@ -65,6 +65,7 @@ insta = "1.42"
 itertools = "0.13"
 lalrpop = { version = "0.20", default-features = false }
 lalrpop-util = "0.20"
+log = { version = "0.4", default-features = false }
 logos = "0.13"
 mockall = "0.12"
 parity-scale-codec = { version = "=3.6.12", default-features = false }

examples/demo/app/tests/fixture/mod.rs

@@ -18,7 +18,7 @@ pub(crate) struct Fixture {
 impl Fixture {
     pub(crate) fn new() -> Self {
         let system = System::new();
-        system.init_logger();
+        system.init_logger_with_default_filter("gwasm=debug,gtest=info,sails_rs=debug");
         system.mint_to(ADMIN_ID, 100_000_000_000_000);
         let demo_code_id = system.submit_code_file(DEMO_WASM_PATH);
 

examples/demo/app/tests/gtest.rs

@@ -159,7 +159,7 @@ async fn counter_query_not_enough_gas() {
 #[tokio::test]
 async fn ping_pong_low_level_works() {
     let system = System::new();
-    system.init_logger();
+    system.init_logger_with_default_filter("gwasm=debug,gtest=info,sails_rs=debug");
     system.mint_to(ADMIN_ID, 100_000_000_000_000);
 
     let demo_program = Program::from_file(&system, DEMO_WASM_PATH);
@@ -381,7 +381,7 @@ async fn counter_add_works_via_next_mode() {
     // Arrange
     const DEMO_WASM_PATH: &str = "../../../target/wasm32-unknown-unknown/debug/demo.opt.wasm";
     let system = System::new();
-    system.init_logger();
+    system.init_logger_with_default_filter("gwasm=debug,gtest=info,sails_rs=debug");
     system.mint_to(fixture::ADMIN_ID, 100_000_000_000_000);
     let demo_code_id = system.submit_code_file(DEMO_WASM_PATH);
 
@@ -420,7 +420,7 @@ async fn counter_add_works_via_manual_mode() {
     // Arrange
     const DEMO_WASM_PATH: &str = "../../../target/wasm32-unknown-unknown/debug/demo.opt.wasm";
     let system = System::new();
-    system.init_logger();
+    system.init_logger_with_default_filter("gwasm=debug,gtest=info,sails_rs=debug");
     system.mint_to(fixture::ADMIN_ID, 100_000_000_000_000);
     let demo_code_id = system.submit_code_file(DEMO_WASM_PATH);
 

examples/no-svcs-prog/wasm/tests/tests.rs

@@ -10,7 +10,7 @@ const WASM_PATH: &str = "../../../target/wasm32-unknown-unknown/debug/no_svcs_pr
 #[tokio::test]
 async fn activating_program_succeeds() {
     let system = System::new();
-    system.init_logger();
+    system.init_logger_with_default_filter("gwasm=debug,gtest=info,sails_rs=debug");
     system.mint_to(ADMIN_ID, 100_000_000_000_000);
     let program_code_id = system.submit_code_file(WASM_PATH);
 

examples/rmrk/resource/wasm/tests/resources.rs

@@ -273,7 +273,7 @@ struct SystemFixture {
 impl SystemFixture {
     fn new() -> Self {
         let system = System::new();
-        system.init_logger();
+        system.init_logger_with_default_filter("gwasm=debug,gtest=info,sails_rs=debug");
         system.mint_to(ADMIN_ID, 100_000_000_000_000);
         system.mint_to(NON_ADMIN_ID, 100_000_000_000_000);
 

rs/Cargo.toml

@@ -32,14 +32,15 @@ gear-core = { workspace = true, features = [
 ], optional = true } # Needed for compilation of gstd in native mode
 gclient = { workspace = true, optional = true }
 gtest = { workspace = true, optional = true }
+log = { workspace = true, optional = true }
 
 [features]
 default = ["gstd"]
 debug = ["gstd?/debug"]
 ethexe = ["gstd?/ethexe"]
 gclient = ["dep:gclient"]
 gstd = ["dep:gstd", "dep:gear-core", "dep:sails-macros"]
-gtest = ["dep:gtest"]
+gtest = ["dep:gtest", "dep:log"]
 idl-gen = ["dep:sails-idl-gen"]
 mockall = ["dep:mockall"]
 wasm-builder = ["dep:gwasm-builder"]

rs/idl-gen/src/type_names.rs

@@ -267,7 +267,7 @@ impl TypeName for ByPathTypeName {
             .find(|possible_name| {
                 by_path_type_names
                     .get(possible_name)
-                    .map_or(false, |ref_count| *ref_count == 1)
+                    .is_some_and(|ref_count| *ref_count == 1)
             })
             .unwrap_or_else(|| self.possible_names.last().unwrap());
         if self.type_param_type_names.is_empty() {

rs/src/gtest/calls.rs

@@ -106,20 +106,27 @@ impl GTestRemoting {
 
 impl GTestRemoting {
     fn extract_events_and_replies(&self, run_result: &BlockRunResult) {
+        log::debug!(
+            "Process block #{} run result, mode {:?}",
+            run_result.block_info.height,
+            &self.block_run_mode
+        );
         let mut event_senders = self.event_senders.borrow_mut();
         let mut reply_senders = self.block_reply_senders.borrow_mut();
         // remove closed event senders
         event_senders.retain(|c| !c.is_closed());
         // iterate over log
         for entry in run_result.log().iter() {
             if entry.destination() == ActorId::zero() {
+                log::debug!("Extract event from entry {:?}", entry);
                 for sender in event_senders.iter() {
                     _ = sender.unbounded_send((entry.source(), entry.payload().to_vec()));
                 }
                 continue;
             }
             if let Some(message_id) = entry.reply_to() {
                 if let Some(sender) = reply_senders.remove(&message_id) {
+                    log::debug!("Extract reply from entry {:?}", entry);
                     let reply: result::Result<Vec<u8>, _> = match entry.reply_code() {
                         None => Err(RtlError::ReplyCodeIsMissing.into()),
                         Some(ReplyCode::Error(reason)) => {
@@ -160,6 +167,7 @@ impl GTestRemoting {
             gas_limit,
             value,
         );
+        log::debug!("Send message id: {message_id}, to: {target}");
         Ok(message_id)
     }
 
@@ -199,7 +207,8 @@ impl GTestRemoting {
     fn drain_reply_senders(&self) {
         let mut reply_senders = self.block_reply_senders.borrow_mut();
         // drain reply senders that not founded in block
-        for (_message_id, sender) in reply_senders.drain() {
+        for (message_id, sender) in reply_senders.drain() {
+            log::debug!("Reply is missing in block for message {}", message_id);
             _ = sender.send(Err(RtlError::ReplyIsMissing.into()));
         }
     }
@@ -234,6 +243,7 @@ impl Remoting for GTestRemoting {
             gas_limit,
             value,
         );
+        log::debug!("Send activation id: {message_id}, to program: {program_id}");
         Ok(self
             .message_reply_from_next_blocks(message_id)
             .map(move |result| result.map(|reply| (program_id, reply))))

templates/program-alt/tests/gtest.rs

@@ -6,8 +6,10 @@ const ACTOR_ID: u64 = 42;
 
 #[tokio::test]
 async fn do_something_works() {
-    let remoting = GTestRemoting::new(ACTOR_ID.into());
-    remoting.system().init_logger();
+    let system = System::new();
+    system.init_logger_with_default_filter("gwasm=debug,gtest=info,sails_rs=debug");
+    system.mint_to(ACTOR_ID, 100_000_000_000_000);
+    let remoting = GTestRemoting::new(system, ACTOR_ID.into());
 
     // Submit program code into the system
     let program_code_id = remoting.system().submit_code({{ crate_name }}::WASM_BINARY);

templates/program/tests/gtest.rs

@@ -7,11 +7,9 @@ const ACTOR_ID: u64 = 42;
 #[tokio::test]
 async fn do_something_works() {
     let system = System::new();
-    system.init_logger();
+    system.init_logger_with_default_filter("gwasm=debug,gtest=info,sails_rs=debug");
     system.mint_to(ACTOR_ID, 100_000_000_000_000);
-
     let remoting = GTestRemoting::new(system, ACTOR_ID.into());
-    remoting.system().init_logger();
 
     // Submit program code into the system
     let program_code_id = remoting.system().submit_code({{ crate_name }}::WASM_BINARY);
@@ -38,11 +36,9 @@ async fn do_something_works() {
 #[tokio::test]
 async fn get_something_works() {
     let system = System::new();
-    system.init_logger();
+    system.init_logger_with_default_filter("gwasm=debug,gtest=info,sails_rs=debug");
     system.mint_to(ACTOR_ID, 100_000_000_000_000);
-
     let remoting = GTestRemoting::new(system, ACTOR_ID.into());
-    remoting.system().init_logger();
 
     // Submit program code into the system
     let program_code_id = remoting.system().submit_code({{ crate_name }}::WASM_BINARY);