diff --git a/radix-engine-tests/assets/blueprints/logger/src/lib.rs b/radix-engine-tests/assets/blueprints/logger/src/lib.rs index c60d9fe332c..49079e46469 100644 --- a/radix-engine-tests/assets/blueprints/logger/src/lib.rs +++ b/radix-engine-tests/assets/blueprints/logger/src/lib.rs @@ -22,5 +22,26 @@ mod logger { pub fn assert_length_5(message: String) { assert_eq!(message.len(), 5); } + + fn mutate_in_place(input: &mut u8) -> u8 { + *input += 1; + *input + } + + // This function tests the logging macros. + // If the respective log level is disabled, the macro arguments will still be + // visible to development tools, but no action will be performed at runtime + // (even if an argument is an expression that mutates data or has side effects). + pub fn mutate_input_if_log_level_enabled(level: Level, number: String) -> u8 { + let mut number = number.parse::().unwrap(); + match level { + Level::Error => error!("Mutated input = {}", Self::mutate_in_place(&mut number)), + Level::Warn => warn!("Mutated input = {}", Self::mutate_in_place(&mut number)), + Level::Info => info!("Mutated input = {}", Self::mutate_in_place(&mut number)), + Level::Debug => debug!("Mutated input = {}", Self::mutate_in_place(&mut number)), + Level::Trace => trace!("Mutated input = {}", Self::mutate_in_place(&mut number)), + } + number + } } } diff --git a/radix-engine-tests/tests/vm/logging.rs b/radix-engine-tests/tests/vm/logging.rs index 8322152166c..b67caedfaf6 100644 --- a/radix-engine-tests/tests/vm/logging.rs +++ b/radix-engine-tests/tests/vm/logging.rs @@ -25,6 +25,26 @@ fn call>(function_name: &str, message: S) -> TransactionReceipt { receipt } +fn call_log_macro>( + ledger: &mut LedgerSimulator, + package_address: PackageAddress, + level: Level, + message: S, +) -> TransactionReceipt { + let manifest = ManifestBuilder::new() + .lock_fee_from_faucet() + .call_function( + package_address, + "Logger", + "mutate_input_if_log_level_enabled", + manifest_args!(level, message.as_ref().to_owned()), + ) + .build(); + let receipt = ledger.execute_manifest(manifest, vec![]); + + receipt +} + #[test] fn test_emit_log() { // Arrange @@ -110,3 +130,80 @@ fn test_assert_length_5() { }) } } + +#[test] +fn test_log_macros_enabled() { + // Arrange + let mut ledger = LedgerSimulatorBuilder::new().build(); + // PackageLoader compiles with all logs enabled (CompileProfile::FastWithTraceLogs) + let package_address = ledger.publish_package_simple(PackageLoader::get("logger")); + + let input = "2"; + let output_log = "Mutated input = 3"; + + for level in [ + Level::Error, + Level::Warn, + Level::Info, + Level::Debug, + Level::Trace, + ] { + // Act + let receipt = call_log_macro(&mut ledger, package_address, level, input); + + // Assert + { + receipt.expect_commit_success(); + + let logs = receipt.expect_commit(true).application_logs.clone(); + let output = receipt.expect_commit(true).output::(1); + + assert_eq!(output, 3); + + let expected_logs = vec![(level, output_log.to_owned())]; + assert_eq!(logs, expected_logs) + } + } +} + +#[test] +fn test_log_macros_disabled() { + use std::path::PathBuf; + + // Arrange + let mut ledger = LedgerSimulatorBuilder::new().build(); + let manifest_dir = PathBuf::from_str(env!("CARGO_MANIFEST_DIR")).unwrap(); + let package_dir = manifest_dir + .join("assets") + .join("blueprints") + .join("logger"); + // Disable all logging macros + let package = ledger.compile_with_option(package_dir, CompileProfile::FastWithNoLogs); + + let package_address = ledger.publish_package_simple(package); + let input = "2"; + + for level in [ + Level::Error, + Level::Warn, + Level::Info, + Level::Debug, + Level::Trace, + ] { + // Act + let receipt = call_log_macro(&mut ledger, package_address, level, input); + + // Assert + { + receipt.expect_commit_success(); + + let logs = receipt.expect_commit(true).application_logs.clone(); + let output = receipt.expect_commit(true).output::(1); + + assert_eq!(output, 2); + + let expected_logs: Vec<(Level, String)> = vec![]; + assert_eq!(logs, expected_logs) + } + } +} diff --git a/scrypto-compiler/src/lib.rs b/scrypto-compiler/src/lib.rs index be488684a10..054a6ad8c3f 100644 --- a/scrypto-compiler/src/lib.rs +++ b/scrypto-compiler/src/lib.rs @@ -1326,12 +1326,17 @@ impl ScryptoCompilerBuilder { self } - pub fn log_level(&mut self, log_level: Level) -> &mut Self { - // Firstly clear any log level previously set + pub fn disable_logs(&mut self) -> &mut Self { let all_features = ScryptoCompilerInputParams::log_level_to_scrypto_features(Level::Trace); all_features.iter().for_each(|log_level| { self.input_params.features.swap_remove(log_level); }); + self + } + + pub fn log_level(&mut self, log_level: Level) -> &mut Self { + // Firstly clear any log level previously set + self.disable_logs(); // Now set log level provided by the user if Level::Error <= log_level { diff --git a/scrypto-test/src/ledger_simulator/compile.rs b/scrypto-test/src/ledger_simulator/compile.rs index af064d5338b..d3d29ef5825 100644 --- a/scrypto-test/src/ledger_simulator/compile.rs +++ b/scrypto-test/src/ledger_simulator/compile.rs @@ -12,6 +12,8 @@ pub enum CompileProfile { Fast, /// Disables WASM optimization and enables all logs from error to trace level, by default used by Ledger Simulator. FastWithTraceLogs, + /// Disables WASM optimization and disables all logs. + FastWithNoLogs, } pub struct Compile; @@ -55,6 +57,10 @@ impl Compile { compiler_builder.optimize_with_wasm_opt(None); compiler_builder.log_level(Level::Trace); // all logs from error to trace } + CompileProfile::FastWithNoLogs => { + compiler_builder.optimize_with_wasm_opt(None); + compiler_builder.disable_logs(); + } } env_vars.iter().for_each(|(name, value)| { diff --git a/scrypto/src/macros.rs b/scrypto/src/macros.rs index 49b988c82b6..2518f82b125 100644 --- a/scrypto/src/macros.rs +++ b/scrypto/src/macros.rs @@ -17,7 +17,19 @@ macro_rules! error { #[cfg(not(feature = "log-error"))] #[macro_export] macro_rules! error { - ($($args: expr),+) => {{}}; + ($($args: expr),+) => {{ + // The operation below does nothing at runtime but consumes the expressions, + // allowing tools (e.g., rust-analyzer) to parse them correctly to identify + // syntactical errors or provide hints and completions. + // Using `false` ensures the expression is optimized out in case of expressions + // that mutate data or have side effects. + // As of now, the linter does not complain about unreachable code, but if it does + // in the future, we should address it proactively. + #[allow(unreachable_code)] + if false { + let _ = ::scrypto::prelude::sbor::rust::format!($($args),+); + } + }}; } /// Logs a `WARN` message. @@ -39,7 +51,12 @@ macro_rules! warn { #[cfg(not(feature = "log-warn"))] #[macro_export] macro_rules! warn { - ($($args: expr),+) => {{}}; + ($($args: expr),+) => {{ + // See `error` macro comment + if false { + let _ = ::scrypto::prelude::sbor::rust::format!($($args),+); + } + }}; } /// Logs an `INFO` message. @@ -61,7 +78,12 @@ macro_rules! info { #[cfg(not(feature = "log-info"))] #[macro_export] macro_rules! info { - ($($args: expr),+) => {{}}; + ($($args: expr),+) => {{ + // See `error` macro comment + if false { + let _ = ::scrypto::prelude::sbor::rust::format!($($args),+); + } + }}; } /// Logs a `DEBUG` message. @@ -83,7 +105,12 @@ macro_rules! debug { #[cfg(not(feature = "log-debug"))] #[macro_export] macro_rules! debug { - ($($args: expr),+) => {{}}; + ($($args: expr),+) => {{ + // See `error` macro comment + if false { + let _ = ::scrypto::prelude::sbor::rust::format!($($args),+); + } + }}; } /// Logs a `TRACE` message. @@ -105,7 +132,12 @@ macro_rules! trace { #[cfg(not(feature = "log-trace"))] #[macro_export] macro_rules! trace { - ($($args: expr),+) => {{}}; + ($($args: expr),+) => {{ + // See `error` macro comment + if false { + let _ = ::scrypto::prelude::sbor::rust::format!($($args),+); + } + }}; } // This is a TT-Muncher, a useful guide for this type of use case is here: https://adventures.michaelfbryan.com/posts/non-trivial-macros/