feat(tests): allow RUST_LOG with multiple tags for native executables by dimxy · Pull Request #2452 · GLEECBTC/komodo-defi-framework

dimxy · 2025-05-12T07:43:03Z

This PR removes unneeded RUST_LOG parsing for test mm2 startup code, native platform, in the test_mm_start fn (it failed when RUST_LOG had multiple tags). This code change allows to use arbitrary RUST_LOG, with multiple tags (like RUST_LOG=off or RUST_LOG="debug,libp2p_gossipsub=info,rustls=error,mm2_main::database=error,mm2_p2p=info,multistream_select=error") for native mm2 executable in docker and other tests.

The fix ensures the p2p module has info log level (needed for wait_for_log fn, used in tests).
The fix also refactors the check_seednodes test fn: instead of waiting for Completed IAmrelay debug message (not available if debug=off) it queries get_directly_connected_peers RPC to ensure a remote peer is connected.

This PR should be useful to hide unneeded debug logs, while developing tests running mm2 executables.
(Please note that some tests in docker_ordermatch_tests or tendermint_tests modules still need libp2p DEBUG logs.)

…ests, ensure info level for p2p for wait_for_log to work

borngraced

LGTM, minor suggestions.

borngraced · 2025-05-12T09:39:30Z

mm2src/mm2_test_helpers/src/for_tests.rs

-                .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)))


Suggested change

.envs(envs_fixed.iter().map(|(k, v)| (k, v)))

.envs(envs_fixed.iter()))

borngraced · 2025-05-12T09:50:51Z

mm2src/mm2_main/tests/integration_tests_common/mod.rs

+        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
+        };


Suggested change

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

};

// Actually filter is used for wasm only. For native RUST_LOG is parsed by env_logger directly, allowing setting multiple targets

let filter = var("RUST_LOG").map(|l| LogLevel::from_str(&log_var).ok());

dimxy · 2025-05-12T17:47:56Z

I suggest removing log dumps inside run_taker_node run_maker_node run_watcher_node in swap_watcher_tests.rs: (864e7e5).
They dump incomplete logs (before tests calling them finish), so in fact misleading.
Instead we should create log dumps in test functions, if needed.

mm2src/mm2_test_helpers/src/for_tests.rs

mariocynicys · 2025-05-12T13:34:39Z

mm2src/mm2_test_helpers/src/for_tests.rs

+                .env("RUST_LOG", read_rust_log().as_str())
+                .envs(envs_fixed.iter().map(|(k, v)| (k, v)))


if the rust_log was set, we would have two rust_logs set for the child process here. one from .env("RUST_LOG",...) and another from .envs(envs_fixed...). is this OK? can't we rely on our own only one of them, say the former.

I think it's okay as envs fn according to the doc 'Inserts or updates multiple explicit environment variable mappings.'

ummmm, i mean, there is no reason to provide it two times anyways.
if we can make it so fix_rust_log_if_present be remove_rust_log_if_present instead, we won't have repeated RUST_LOGs.

I believe, the second RUST_LOG var (if present) would overwrite the first one in the inner 'set' of env vars

mm2src/mm2_main/tests/integration_tests_common/mod.rs

mm2src/mm2_main/tests/docker_tests/docker_tests_inner.rs

…wasm code

mariocynicys · 2025-05-27T13:37:42Z

mm2src/mm2_main/tests/integration_tests_common/mod.rs

 #[test]
 #[cfg(not(target_arch = "wasm32"))]
 fn test_mm_start() { test_mm_start_impl(); }

-pub fn test_mm_start_impl() {
+#[cfg(not(target_arch = "wasm32"))]
+fn test_mm_start_impl() {
    if let Ok(conf) = var("_MM2_TEST_CONF") {


nit: we can merge these 2 funcs. as of now, doesn't seem that this indirection is useful.

mariocynicys · 2025-05-27T13:55:21Z

mm2src/mm2_test_helpers/src/for_tests.rs

+            .map(|s| {
+                if s.starts_with(&(module.to_owned() + "=off")) {
+                    module.to_owned() + "=info"
+                } else {
+                    s.to_owned()
+                }
+            })


nit: could be simplified to

// If the module is already set to off, remove it. .filter(|s| s == &&(module.to_owned() + "=off"))

since we will add module=info later anyway.

only .filter(|s| s != &&(module.to_owned() + "=off"))

mariocynicys · 2025-05-27T14:02:27Z

mm2src/mm2_main/tests/docker_tests/swap_watcher_tests.rs

-    let (_dump_log, _dump_dashboard) = mm.mm_dump();
-    log!("Log path: {}", mm.log_path.display());


why are we removing these. and other occurrences too.

removing _dump_log inside the run_watcher_node because _dump_log here, when dropped on run_watcher_node exit, dumps incomplete log.
Instead new _watcher_dump_log is added in the test fn itself (so it dumps the log when the test finishes).

mariocynicys · 2025-05-27T14:06:57Z

mm2src/mm2_main/tests/docker_tests/docker_tests_inner.rs

    );

    // check with too big time offset:
-    let (bob_peers, alice_peers) = start_peers_with_time_offset(timeoffset_too_big);


how did this used to work before even tho the default behavior is setting skip_seednodes_check = false?

It had worked before this PR because the node waited for log message 'Completed IAmrelay handling for peer' and this message always was added to the log when a peer connected (even if the peer was later rejected due to big time diff)

mariocynicys · 2025-05-27T14:16:04Z

mm2src/mm2_test_helpers/src/for_tests.rs

+            if let Some(ref mut pc) = self.pc {
+                if !pc.running() {
+                    return ERR!("MM process terminated prematurely at: {:?}.", self.folder);
+                }
+            }


didn't understand why we had this, but looks like it's some logic found in wait_for_log that was used before.

i think the fact that the rpc replied to us is enough to determine that mm2 is alive, so such a check isn't really needed.

I think I'd better catch the error from self.rpc() so we can progress and stop with the known "MM process terminated prematurely" error

mariocynicys · 2025-05-27T14:20:57Z

mm2src/mm2_test_helpers/src/for_tests.rs

+            let res = self.rpc(&json!({
+                "userpass": self.userpass,
+                "method": "get_directly_connected_peers",
+            }))


i guess that's a different check than what the funciton name tells, ha?

this queries connected peers, but in this function we wanna check connected seeds.
not sure if the old implementation used to check for seeds and not any peer (the log we used to wait for doesn't really point that it was waiting specifically for a seed).

it doesn't matter i think since in all test scenarios we have a seed peer connected to non-seed peer. we might just wanna rename the function to reflect the job it's doing.

renamed,
tyvm for the notes

…eers check, eliminate test_mm_start_impl, use combinator in rust_log parse

* dev: fix(DOCS): add note for macos to fix docker containers startup failure (#2544) refactor(toolchain): general stabilization for stable rust (#2528) # Conflicts: # mm2src/mm2_main/tests/integration_tests_common/mod.rs

feature(tests): allow RUST_LOG with multiple tags for native exe in t…

9cc04cf

…ests, ensure info level for p2p for wait_for_log to work

dimxy added improvement: tests status: pending review status: in progress and removed status: pending review labels May 12, 2025

borngraced approved these changes May 12, 2025

View reviewed changes

borngraced previously approved these changes May 12, 2025

View reviewed changes

refactor (borngraced): nits parsing envs

fa67138

dimxy dismissed borngraced’s stale review via fa67138 May 12, 2025 13:13

dimxy added 2 commits May 12, 2025 21:10

temp enable outer watcher log (to debug tests)

864e7e5

remove commented log code in watcher tests

fda8099

mariocynicys reviewed May 13, 2025

View reviewed changes

dimxy added 2 commits May 13, 2025 13:13

add lp_swap=info to log tags

9675bd8

review (mariocynicys): replace 'module=off' on 'info', remove unused …

31d9d69

…wasm code

dimxy added status: pending review and removed status: in progress labels May 13, 2025

mariocynicys reviewed May 27, 2025

View reviewed changes

shamardy marked this pull request as draft June 16, 2025 04:59

shamardy and others added 3 commits July 24, 2025 15:41

Merge remote-tracking branch 'origin/dev' into allow-rust-log-tags

a2dca34

Refactor test code (mariocynicys review): better name for connected p…

66a293d

…eers check, eliminate test_mm_start_impl, use combinator in rust_log parse

Merge branch 'dev' into allow-rust-log-tags

5c6569a

* dev: fix(DOCS): add note for macos to fix docker containers startup failure (#2544) refactor(toolchain): general stabilization for stable rust (#2528) # Conflicts: # mm2src/mm2_main/tests/integration_tests_common/mod.rs

	.envs(envs_fixed.iter().map(\|(k, v)\| (k, v)))
	.envs(envs_fixed.iter()))

		.env("RUST_LOG", read_rust_log().as_str())
		.envs(envs_fixed.iter().map(\|(k, v)\| (k, v)))

		let (_dump_log, _dump_dashboard) = mm.mm_dump();
		log!("Log path: {}", mm.log_path.display());

Conversation

dimxy commented May 12, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

borngraced left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

dimxy commented May 12, 2025

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

dimxy Jul 24, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

4 participants

dimxy commented May 12, 2025 •

edited

Loading

dimxy Jul 24, 2025 •

edited

Loading