From 64d3689844126656a2eb2d716130c9593f88ec37 Mon Sep 17 00:00:00 2001 From: ackintosh Date: Wed, 21 May 2025 07:53:16 +0900 Subject: [PATCH 1/2] Enable stdout logs --- .../lighthouse_network/tests/rpc_tests.rs | 24 +++++++++++-------- 1 file changed, 14 insertions(+), 10 deletions(-) diff --git a/beacon_node/lighthouse_network/tests/rpc_tests.rs b/beacon_node/lighthouse_network/tests/rpc_tests.rs index 9b43e8b5812..32b2c4e60b3 100644 --- a/beacon_node/lighthouse_network/tests/rpc_tests.rs +++ b/beacon_node/lighthouse_network/tests/rpc_tests.rs @@ -55,7 +55,7 @@ fn bellatrix_block_large(spec: &ChainSpec) -> BeaconBlock { fn test_tcp_status_rpc() { // Set up the logging. let log_level = "debug"; - let enable_logging = false; + let enable_logging = true; build_tracing_subscriber(log_level, enable_logging); let rt = Arc::new(Runtime::new().unwrap()); @@ -159,7 +159,7 @@ fn test_tcp_status_rpc() { fn test_tcp_blocks_by_range_chunked_rpc() { // Set up the logging. let log_level = "debug"; - let enable_logging = false; + let enable_logging = true; build_tracing_subscriber(log_level, enable_logging); let messages_to_send = 6; @@ -304,7 +304,7 @@ fn test_tcp_blocks_by_range_chunked_rpc() { fn test_blobs_by_range_chunked_rpc() { // Set up the logging. let log_level = "debug"; - let enable_logging = false; + let enable_logging = true; build_tracing_subscriber(log_level, enable_logging); let slot_count = 32; @@ -425,7 +425,7 @@ fn test_blobs_by_range_chunked_rpc() { fn test_tcp_blocks_by_range_over_limit() { // Set up the logging. let log_level = "debug"; - let enable_logging = false; + let enable_logging = true; build_tracing_subscriber(log_level, enable_logging); let messages_to_send = 5; @@ -529,7 +529,7 @@ fn test_tcp_blocks_by_range_over_limit() { fn test_tcp_blocks_by_range_chunked_rpc_terminates_correctly() { // Set up the logging. let log_level = "debug"; - let enable_logging = false; + let enable_logging = true; build_tracing_subscriber(log_level, enable_logging); let messages_to_send = 10; @@ -666,7 +666,7 @@ fn test_tcp_blocks_by_range_chunked_rpc_terminates_correctly() { fn test_tcp_blocks_by_range_single_empty_rpc() { // Set up the logging. let log_level = "trace"; - let enable_logging = false; + let enable_logging = true; build_tracing_subscriber(log_level, enable_logging); let rt = Arc::new(Runtime::new().unwrap()); @@ -787,7 +787,7 @@ fn test_tcp_blocks_by_range_single_empty_rpc() { fn test_tcp_blocks_by_root_chunked_rpc() { // Set up the logging. let log_level = "debug"; - let enable_logging = false; + let enable_logging = true; build_tracing_subscriber(log_level, enable_logging); let messages_to_send = 6; @@ -932,7 +932,7 @@ fn test_tcp_blocks_by_root_chunked_rpc() { fn test_tcp_blocks_by_root_chunked_rpc_terminates_correctly() { // Set up the logging. let log_level = "debug"; - let enable_logging = false; + let enable_logging = true; build_tracing_subscriber(log_level, enable_logging); let messages_to_send: u64 = 10; @@ -1143,7 +1143,7 @@ fn goodbye_test(log_level: &str, enable_logging: bool, protocol: Protocol) { #[allow(clippy::single_match)] fn tcp_test_goodbye_rpc() { let log_level = "debug"; - let enabled_logging = false; + let enabled_logging = true; goodbye_test(log_level, enabled_logging, Protocol::Tcp); } @@ -1152,13 +1152,15 @@ fn tcp_test_goodbye_rpc() { #[allow(clippy::single_match)] fn quic_test_goodbye_rpc() { let log_level = "debug"; - let enabled_logging = false; + let enabled_logging = true; goodbye_test(log_level, enabled_logging, Protocol::Quic); } // Test that the receiver delays the responses during response rate-limiting. #[test] fn test_delayed_rpc_response() { + // Set up the logging. + build_tracing_subscriber("debug", true); let rt = Arc::new(Runtime::new().unwrap()); let spec = Arc::new(E::default_spec()); @@ -1289,6 +1291,8 @@ fn test_delayed_rpc_response() { // once, thanks to the self-limiter on the sender side. #[test] fn test_active_requests() { + // Set up the logging. + build_tracing_subscriber("debug", true); let rt = Arc::new(Runtime::new().unwrap()); let spec = Arc::new(E::default_spec()); From 0b5f98caf000f8611c2a815db3b50b1a15a67d8f Mon Sep 17 00:00:00 2001 From: ackintosh Date: Wed, 21 May 2025 07:57:37 +0900 Subject: [PATCH 2/2] Add elapsed time to the debug log --- beacon_node/lighthouse_network/tests/rpc_tests.rs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/beacon_node/lighthouse_network/tests/rpc_tests.rs b/beacon_node/lighthouse_network/tests/rpc_tests.rs index 32b2c4e60b3..e644020fe42 100644 --- a/beacon_node/lighthouse_network/tests/rpc_tests.rs +++ b/beacon_node/lighthouse_network/tests/rpc_tests.rs @@ -1216,7 +1216,7 @@ fn test_delayed_rpc_response() { app_request_id: _, response, } => { - debug!(%request_id, "Sender received"); + debug!(%request_id, elapsed = ?request_sent_at.elapsed(), "Sender received response"); assert_eq!(response, rpc_response); match request_id {