Merge pull request #2043 from radixdlt/fix/scrypto-logging-macros

Improve logging macros to work with IDEs better

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::<u8>().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
+        }
     }
 }

radix-engine-tests/tests/vm/logging.rs

@@ -25,6 +25,26 @@ fn call<S: AsRef<str>>(function_name: &str, message: S) -> TransactionReceipt {
     receipt
 }
 
+fn call_log_macro<S: AsRef<str>>(
+    ledger: &mut LedgerSimulator<NoExtension, InMemorySubstateDatabase>,
+    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::<u8>(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::<u8>(1);
+
+            assert_eq!(output, 2);
+
+            let expected_logs: Vec<(Level, String)> = vec![];
+            assert_eq!(logs, expected_logs)
+        }
+    }
+}

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 {

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

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/