feat(tests): allow RUST_LOG with multiple tags for native executables

mm2src/mm2_main/tests/docker_tests/docker_tests_inner.rs

@@ -5487,11 +5487,12 @@ fn test_peer_time_sync_validation() {
     let timeoffset_tolerable = TryInto::<i64>::try_into(MAX_TIME_GAP_FOR_CONNECTED_PEER).unwrap() - 1;
     let timeoffset_too_big = TryInto::<i64>::try_into(MAX_TIME_GAP_FOR_CONNECTED_PEER).unwrap() + 1;
 
-    let start_peers_with_time_offset = |offset: i64| -> (Json, Json) {
+    let start_peers_with_time_offset = |offset: i64, skip_seednodes_check: bool| -> (Json, Json) {
         let (_ctx, _, bob_priv_key) = generate_utxo_coin_with_random_privkey("MYCOIN", 10.into());
         let (_ctx, _, alice_priv_key) = generate_utxo_coin_with_random_privkey("MYCOIN1", 10.into());
         let coins = json!([mycoin_conf(1000), mycoin1_conf(1000)]);
-        let bob_conf = Mm2TestConf::seednode(&hex::encode(bob_priv_key), &coins);
+        let mut bob_conf = Mm2TestConf::seednode(&hex::encode(bob_priv_key), &coins);
+        bob_conf.conf["skip_seednodes_check"] = skip_seednodes_check.into();
         let mut mm_bob = block_on(MarketMakerIt::start_with_envs(
             bob_conf.conf,
             bob_conf.rpc_password,
@@ -5501,8 +5502,9 @@ fn test_peer_time_sync_validation() {
         .unwrap();
         let (_bob_dump_log, _bob_dump_dashboard) = mm_dump(&mm_bob.log_path);
         block_on(mm_bob.wait_for_log(22., |log| log.contains(">>>>>>>>> DEX stats "))).unwrap();
-        let alice_conf =
+        let mut alice_conf =
             Mm2TestConf::light_node(&hex::encode(alice_priv_key), &coins, &[mm_bob.ip.to_string().as_str()]);
+        alice_conf.conf["skip_seednodes_check"] = skip_seednodes_check.into();
         let mut mm_alice = block_on(MarketMakerIt::start_with_envs(
             alice_conf.conf,
             alice_conf.rpc_password,
@@ -5539,7 +5541,7 @@ fn test_peer_time_sync_validation() {
     };
 
     // check with small time offset:
-    let (bob_peers, alice_peers) = start_peers_with_time_offset(timeoffset_tolerable);
+    let (bob_peers, alice_peers) = start_peers_with_time_offset(timeoffset_tolerable, false);
     assert!(
         bob_peers["result"].as_object().unwrap().len() == 1,
         "bob must have one peer"
@@ -5550,7 +5552,7 @@ fn test_peer_time_sync_validation() {
     );
 
     // check with too big time offset:
-    let (bob_peers, alice_peers) = start_peers_with_time_offset(timeoffset_too_big);
+    let (bob_peers, alice_peers) = start_peers_with_time_offset(timeoffset_too_big, true); // skip_seednodes_check = true as there should not be connected peers
     assert!(
         bob_peers["result"].as_object().unwrap().is_empty(),
         "bob must have no peers"

mm2src/mm2_main/tests/integration_tests_common/mod.rs

@@ -1,5 +1,5 @@
 use common::executor::Timer;
-use common::log::LogLevel;
+#[cfg(target_arch = "wasm32")] use common::log::LogLevel;
 use common::{block_on, log, now_ms, wait_until_ms};
 use crypto::privkey::key_pair_from_seed;
 use mm2_main::{lp_main, lp_run, LpMainParams};
@@ -12,7 +12,7 @@ use mm2_test_helpers::structs::{CreateNewAccountStatus, HDAccountAddressId, HDAc
 use serde_json::{self as json, Value as Json};
 use std::collections::HashMap;
 use std::env::var;
-use std::str::FromStr;
+#[cfg(target_arch = "wasm32")] use std::str::FromStr;
 
 /// This is not a separate test but a helper used by `MarketMakerIt` to run the MarketMaker from the test binary.
 #[test]
@@ -21,15 +21,19 @@ fn test_mm_start() { test_mm_start_impl(); }
 
 pub fn test_mm_start_impl() {
     if let Ok(conf) = var("_MM2_TEST_CONF") {
-        if let Ok(log_var) = var("RUST_LOG") {
-            if let Ok(filter) = LogLevel::from_str(&log_var) {
-                log!("test_mm_start] Starting the MarketMaker...");
-                let conf: Json = json::from_str(&conf).unwrap();
-                let params = LpMainParams::with_conf(conf).log_filter(Some(filter));
-                let ctx = block_on(lp_main(params, &|_ctx| (), "TEST".into(), "TEST".into())).unwrap();
-                block_on(lp_run(ctx))
-            }
-        }
+        log!("test_mm_start] Starting the MarketMaker...");
+        let conf: Json = json::from_str(&conf).unwrap();
+        #[cfg(not(target_arch = "wasm32"))]
+        let filter = None;
+        #[cfg(target_arch = "wasm32")]
+        let filter = if let Ok(log_var) = var("RUST_LOG") {
+            LogLevel::from_str(&log_var).ok(); // Actually filter is used for wasm only. For native RUST_LOG is parsed by env_logger directly, allowing setting multiple targets
+        } else {
+            None
+        };
+        let params = LpMainParams::with_conf(conf).log_filter(filter);
+        let ctx = block_on(lp_main(params, &|_ctx| (), "TEST".into(), "TEST".into())).unwrap();
+        block_on(lp_run(ctx))
     }
 }
 

mm2src/mm2_test_helpers/src/for_tests.rs

@@ -1374,14 +1374,15 @@ impl MarketMakerIt {
             let executable = try_s!(env::args().next().ok_or("No program name"));
             let executable = try_s!(Path::new(&executable).canonicalize());
             let log = try_s!(fs::File::create(&log_path));
+            let envs_fixed = fix_rust_log_if_present(envs);
             let child = try_s!(Command::new(executable)
                 .arg("test_mm_start")
                 .arg("--nocapture")
                 .current_dir(&folder)
                 .env("_MM2_TEST_CONF", try_s!(json::to_string(&conf)))
                 .env("MM2_UNBUFFERED_OUTPUT", "1")
-                .env("RUST_LOG", "debug")
-                .envs(envs.to_vec())
+                .env("RUST_LOG", read_rust_log().as_str())
+                .envs(envs_fixed.iter().map(|(k, v)| (k, v)))
                 .stdout(try_s!(log.try_clone()))
                 .stderr(log)
                 .spawn());
@@ -1664,14 +1665,37 @@ impl MarketMakerIt {
         .map_err(|e| ERRL!("{:?}", e))
     }
 
-    /// Currently, we cannot wait for the `Completed IAmrelay handling for peer` log entry on WASM node,
-    /// because the P2P module logs to a global logger and doesn't log to the dashboard.
+    /// Check if the node is connected to at least one seednode,
+    /// the rpc is used instead of checking the log for DEBUG messages (to opt out p2p debug logging)
     #[cfg(not(target_arch = "wasm32"))]
     pub async fn check_seednodes(&mut self) -> Result<(), String> {
-        // wait for at least 1 node to be added to relay mesh
-        self.wait_for_log(22., |log| log.contains("Completed IAmrelay handling for peer"))
+        let timeout_sec = 22.;
+        let start = now_float();
+        loop {
+            let res = self.rpc(&json!({
+                "userpass": self.userpass,
+                "method": "get_directly_connected_peers",
+            }))
             .await
-            .map_err(|e| ERRL!("{}", e))
+            .unwrap();
+            if res.0.is_success() {       
+                let res_value = serde_json::from_str::<Json>(&res.1).unwrap();
+                if let Some(peers) = res_value["result"].as_object() {
+                    if peers.len() > 0 {
+                        return Ok(());
+                    }
+                }
+            }
+            if now_float() - start > timeout_sec {
+                return ERR!("Timeout expired waiting for connected peers");
+            }
+            if let Some(ref mut pc) = self.pc {
+                if !pc.running() {
+                    return ERR!("MM process terminated prematurely at: {:?}.", self.folder);
+                }
+            }
+            Timer::sleep(1.).await
+        }
     }
 
     /// Wait for the node to start listening to new P2P connections.
@@ -4094,3 +4118,38 @@ pub async fn active_swaps(mm: &MarketMakerIt) -> ActiveSwapsResponse {
     assert_eq!(response.0, StatusCode::OK, "'active_swaps' failed: {}", response.1);
     json::from_str(&response.1).unwrap()
 }
+
+/// Helper to read RUST_LOG env variable and ensure it contains module=info for certain modules needed for tests (wait_for_log to work correctly)
+#[cfg(not(target_arch = "wasm32"))]
+fn read_rust_log() -> String {
+
+    let rust_log = env::var("RUST_LOG").unwrap_or_else(|_| "debug".to_string()); // assume RUST_LOG=debug by default
+    ensure_needed_modules_logged(&rust_log)
+}
+
+/// Helper to ensure that RUST_LOG (if present in env_vars) contains module=info for certain modules needed for tests (wait_for_log to work correctly)
+#[cfg(not(target_arch = "wasm32"))]
+fn fix_rust_log_if_present(env_vars: &[(&str, &str)]) -> Vec<(String, String)> {
+    env_vars.iter().map(|(key, value)| {
+        if *key == "RUST_LOG" {
+            (key.to_string(), ensure_needed_modules_logged(value))
+        } else {
+            (key.to_string(), value.to_string())
+        }
+    })
+    .collect()
+}
+
+#[cfg(not(target_arch = "wasm32"))]
+fn ensure_needed_modules_logged(rust_log: &str) -> String {   
+    // Add module=info to the source
+    let add_module_info = |source: &str, module: &str| {
+        let mut updated = source.to_string();
+        if updated.len() > 0 {
+            updated.push(',');
+        }
+        updated.push_str(&(module.to_owned() + "=info"));
+        updated
+    };  
+    add_module_info(rust_log, "mm2_p2p")
+}