diff --git a/crates/engine/src/ext.rs b/crates/engine/src/ext.rs index 8fa8f900f2..60bd8d0653 100644 --- a/crates/engine/src/ext.rs +++ b/crates/engine/src/ext.rs @@ -91,6 +91,9 @@ define_error_codes! { CodeNotFound = 7, /// The account that was called is either no contract (e.g. user account) or is a tombstone. NotCallable = 8, + /// The call to `seal_debug_message` had no effect because debug message + /// recording was disabled. + LoggingDisabled = 9, } /// The raw return code returned by the host side. @@ -317,10 +320,10 @@ impl Engine { unimplemented!("off-chain environment does not yet support `restore_to`"); } - /// Prints the given contents to the console log. - pub fn println(&mut self, content: &str) { - self.debug_info.record_println(String::from(content)); - println!("{}", content); + /// Records the given debug message and appends to stdout. + pub fn debug_message(&mut self, message: &str) { + self.debug_info.record_debug_message(String::from(message)); + print!("{}", message); } /// Conduct the BLAKE-2 256-bit hash and place the result into `output`. diff --git a/crates/engine/src/test_api.rs b/crates/engine/src/test_api.rs index 71d7b3e01c..b3dd43a5b0 100644 --- a/crates/engine/src/test_api.rs +++ b/crates/engine/src/test_api.rs @@ -33,41 +33,41 @@ pub struct EmittedEvent { } #[derive(Clone)] -pub struct RecordedPrintlns { - printlns: Vec, +pub struct RecordedDebugMessages { + debug_messages: Vec, } -impl RecordedPrintlns { +impl RecordedDebugMessages { // Creates a new `Engine instance. pub fn new() -> Self { Self { - printlns: Vec::new(), + debug_messages: Vec::new(), } } - // Records a new println. - pub fn record(&mut self, println: String) { - self.printlns.push(println); + // Records a new debug message. + pub fn record(&mut self, message: String) { + self.debug_messages.push(message); } - // Clears all recorded printlns. + // Clears all recorded debug messages. pub fn clear(&mut self) { - self.printlns.clear(); + self.debug_messages.clear(); } } -impl Default for RecordedPrintlns { +impl Default for RecordedDebugMessages { fn default() -> Self { Self::new() } } -impl IntoIterator for RecordedPrintlns { +impl IntoIterator for RecordedDebugMessages { type Item = String; type IntoIter = std::vec::IntoIter; fn into_iter(self) -> Self::IntoIter { - self.printlns.into_iter() + self.debug_messages.into_iter() } } @@ -76,7 +76,7 @@ pub struct DebugInfo { /// Emitted events recorder. emitted_events: Vec, /// Emitted print messages recorder. - emitted_printlns: RecordedPrintlns, + emitted_debug_messages: RecordedDebugMessages, /// The total number of reads to the storage. count_reads: HashMap, /// The total number of writes to the storage. @@ -96,7 +96,7 @@ impl DebugInfo { pub fn new() -> Self { Self { emitted_events: Vec::new(), - emitted_printlns: RecordedPrintlns::new(), + emitted_debug_messages: RecordedDebugMessages::new(), count_reads: HashMap::new(), count_writes: HashMap::new(), cells_per_account: HashMap::new(), @@ -108,7 +108,7 @@ impl DebugInfo { self.count_reads.clear(); self.count_writes.clear(); self.emitted_events.clear(); - self.emitted_printlns.clear(); + self.emitted_debug_messages.clear(); self.cells_per_account.clear(); } @@ -159,9 +159,9 @@ impl DebugInfo { .unwrap_or(None) } - /// Records a println. - pub fn record_println(&mut self, println: String) { - self.emitted_printlns.record(println); + /// Records a debug message. + pub fn record_debug_message(&mut self, message: String) { + self.emitted_debug_messages.record(message); } /// Records an event. @@ -215,9 +215,9 @@ impl Engine { self.exec_context.callee() } - /// Returns the contents of the past performed environmental `println` in order. - pub fn get_recorded_printlns(&self) -> RecordedPrintlns { - self.debug_info.emitted_printlns.clone() + /// Returns the contents of the past performed environmental `debug_message` in order. + pub fn get_emitted_debug_messages(&self) -> RecordedDebugMessages { + self.debug_info.emitted_debug_messages.clone() } /// Returns the recorded emitted events in order. diff --git a/crates/engine/src/tests.rs b/crates/engine/src/tests.rs index ed83e45557..798f5287de 100644 --- a/crates/engine/src/tests.rs +++ b/crates/engine/src/tests.rs @@ -115,10 +115,10 @@ fn transfer() { } #[test] -fn printlns() { +fn debug_messages() { let mut engine = Engine::new(); - engine.println("foobar"); - let mut recorded = engine.get_recorded_printlns().into_iter(); + engine.debug_message("foobar"); + let mut recorded = engine.get_emitted_debug_messages().into_iter(); assert_eq!(recorded.next(), Some("foobar".into())); assert_eq!(recorded.next(), None); } diff --git a/crates/env/Cargo.toml b/crates/env/Cargo.toml index 217c10e56e..a42f3086aa 100644 --- a/crates/env/Cargo.toml +++ b/crates/env/Cargo.toml @@ -62,4 +62,6 @@ std = [ "sha3", "blake2", ] +# Enable contract debug messages via `debug_print!` and `debug_println!`. +ink-debug = [] ink-experimental-engine = ["ink_engine"] diff --git a/crates/env/src/api.rs b/crates/env/src/api.rs index 945ab8e5d4..ce8444a664 100644 --- a/crates/env/src/api.rs +++ b/crates/env/src/api.rs @@ -553,10 +553,10 @@ where }) } -/// Prints the given contents to the environmental log. -pub fn debug_println(content: &str) { +/// Appends the given message to the debug message buffer. +pub fn debug_message(message: &str) { ::on_instance(|instance| { - EnvBackend::println(instance, content) + EnvBackend::debug_message(instance, message) }) } diff --git a/crates/env/src/backend.rs b/crates/env/src/backend.rs index feaffca187..150b7a8504 100644 --- a/crates/env/src/backend.rs +++ b/crates/env/src/backend.rs @@ -119,8 +119,15 @@ pub trait EnvBackend { where R: scale::Encode; - /// Prints the given contents to the console log. - fn println(&mut self, content: &str); + /// Emit a custom debug message. + /// + /// The message is appended to the debug buffer which is then supplied to the calling RPC + /// client. This buffer is also printed as a debug message to the node console if the + /// `debug` log level is enabled for the `runtime::contracts` target. + /// + /// If debug message recording is disabled in the contracts pallet, which is always the case + /// when the code is executing on-chain, then this will have no effect. + fn debug_message(&mut self, content: &str); /// Conducts the crypto hash of the given input and stores the result in `output`. fn hash_bytes(&mut self, input: &[u8], output: &mut ::Type) diff --git a/crates/env/src/engine/experimental_off_chain/impls.rs b/crates/env/src/engine/experimental_off_chain/impls.rs index 0781e0670f..bc37ac5b00 100644 --- a/crates/env/src/engine/experimental_off_chain/impls.rs +++ b/crates/env/src/engine/experimental_off_chain/impls.rs @@ -111,6 +111,7 @@ impl From for crate::Error { ext::Error::NewContractNotFunded => Self::NewContractNotFunded, ext::Error::CodeNotFound => Self::CodeNotFound, ext::Error::NotCallable => Self::NotCallable, + ext::Error::LoggingDisabled => Self::LoggingDisabled, } } } @@ -227,8 +228,8 @@ impl EnvBackend for EnvInstance { ) } - fn println(&mut self, content: &str) { - self.engine.println(content) + fn debug_message(&mut self, message: &str) { + self.engine.debug_message(message) } fn hash_bytes(&mut self, input: &[u8], output: &mut ::Type) diff --git a/crates/env/src/engine/experimental_off_chain/test_api.rs b/crates/env/src/engine/experimental_off_chain/test_api.rs index 8608270cbe..e44c9a5d23 100644 --- a/crates/env/src/engine/experimental_off_chain/test_api.rs +++ b/crates/env/src/engine/experimental_off_chain/test_api.rs @@ -23,7 +23,7 @@ use crate::{ Result, }; use core::fmt::Debug; -use ink_engine::test_api::RecordedPrintlns; +use ink_engine::test_api::RecordedDebugMessages; use std::panic::UnwindSafe; /// Record for an emitted event. @@ -129,10 +129,10 @@ where unimplemented!("off-chain environment does not yet support `set_block_entropy`"); } -/// Returns the contents of the past performed environmental `println` in order. -pub fn recorded_printlns() -> RecordedPrintlns { +/// Returns the contents of the past performed environmental debug messages in order. +pub fn recorded_debug_messages() -> RecordedDebugMessages { ::on_instance(|instance| { - instance.engine.get_recorded_printlns() + instance.engine.get_emitted_debug_messages() }) } diff --git a/crates/env/src/engine/off_chain/db/console.rs b/crates/env/src/engine/off_chain/db/debug_buf.rs similarity index 50% rename from crates/env/src/engine/off_chain/db/console.rs rename to crates/env/src/engine/off_chain/db/debug_buf.rs index 67486b4e8f..959c4d7365 100644 --- a/crates/env/src/engine/off_chain/db/console.rs +++ b/crates/env/src/engine/off_chain/db/debug_buf.rs @@ -14,53 +14,53 @@ use ink_prelude::string::String; -/// A debug console used to print console contents and store them. -pub struct Console { - /// The buffer to store the already pasted contents. - past_prints: Vec, +/// A debug buffer used to store debug messages and print them to stdout. +pub struct DebugBuffer { + /// The buffer to store the emitted debug messages. + past_debug_messages: Vec, } -impl Console { +impl DebugBuffer { /// Creates a new empty console. pub fn new() -> Self { Self { - past_prints: Vec::new(), + past_debug_messages: Vec::new(), } } - /// Resets the console to uninitialized state. + /// Resets the debug buffer to uninitialized state. pub fn reset(&mut self) { - self.past_prints.clear(); + self.past_debug_messages.clear(); } - /// Prints the contents to the actual console and stores them. - pub fn println(&mut self, contents: &str) { - self.past_prints.push(contents.to_string()); - println!("{}", contents); + /// Prints the message to stdout and stores it. + pub fn debug_message(&mut self, message: &str) { + self.past_debug_messages.push(message.to_string()); + print!("{}", message); } - /// Returns an iterator over the past console prints. - pub fn past_prints(&self) -> PastPrints { - PastPrints::new(self) + /// Returns an iterator over the past debug messages. + pub fn past_debug_messages(&self) -> DebugMessages { + DebugMessages::new(self) } } -/// Iterator over the past prints to the console. -pub struct PastPrints<'a> { - /// Iterator over the past printlns. +/// Iterator over the past debug messages. +pub struct DebugMessages<'a> { + /// Iterator over the past debug messages. iter: core::slice::Iter<'a, String>, } -impl<'a> PastPrints<'a> { - /// Creates a new iterator over the past console prints. - fn new(console: &'a Console) -> Self { +impl<'a> DebugMessages<'a> { + /// Creates a new iterator over the past debug messages. + fn new(console: &'a DebugBuffer) -> Self { Self { - iter: console.past_prints.iter(), + iter: console.past_debug_messages.iter(), } } } -impl<'a> Iterator for PastPrints<'a> { +impl<'a> Iterator for DebugMessages<'a> { type Item = &'a str; fn next(&mut self) -> Option { @@ -68,13 +68,13 @@ impl<'a> Iterator for PastPrints<'a> { } } -impl<'a> ExactSizeIterator for PastPrints<'a> { +impl<'a> ExactSizeIterator for DebugMessages<'a> { fn len(&self) -> usize { self.iter.len() } } -impl<'a> DoubleEndedIterator for PastPrints<'a> { +impl<'a> DoubleEndedIterator for DebugMessages<'a> { fn next_back(&mut self) -> Option { self.iter.next_back().map(AsRef::as_ref) } diff --git a/crates/env/src/engine/off_chain/db/mod.rs b/crates/env/src/engine/off_chain/db/mod.rs index 100a652127..42ff658b6a 100644 --- a/crates/env/src/engine/off_chain/db/mod.rs +++ b/crates/env/src/engine/off_chain/db/mod.rs @@ -15,7 +15,7 @@ mod accounts; mod block; mod chain_spec; -mod console; +mod debug_buf; mod events; mod exec_context; @@ -30,9 +30,9 @@ pub use self::{ }, block::Block, chain_spec::ChainSpec, - console::{ - Console, - PastPrints, + debug_buf::{ + DebugBuffer, + DebugMessages, }, events::{ EmittedEvent, diff --git a/crates/env/src/engine/off_chain/impls.rs b/crates/env/src/engine/off_chain/impls.rs index abf6790816..17909e7059 100644 --- a/crates/env/src/engine/off_chain/impls.rs +++ b/crates/env/src/engine/off_chain/impls.rs @@ -175,8 +175,8 @@ impl EnvBackend for EnvInstance { std::process::exit(flags.into_u32() as i32) } - fn println(&mut self, content: &str) { - self.console.println(content) + fn debug_message(&mut self, message: &str) { + self.debug_buf.debug_message(message) } fn hash_bytes(&mut self, input: &[u8], output: &mut ::Type) diff --git a/crates/env/src/engine/off_chain/mod.rs b/crates/env/src/engine/off_chain/mod.rs index 5dc11e5a0d..bb3ce8d41b 100644 --- a/crates/env/src/engine/off_chain/mod.rs +++ b/crates/env/src/engine/off_chain/mod.rs @@ -28,8 +28,8 @@ pub use self::{ call_data::CallData, db::{ AccountError, + DebugMessages, EmittedEvent, - PastPrints, }, typed_encoded::TypedEncodedError, }; @@ -40,7 +40,7 @@ use self::{ AccountsDb, Block, ChainSpec, - Console, + DebugBuffer, EmittedEventsRecorder, ExecContext, }, @@ -84,8 +84,8 @@ pub struct EnvInstance { chain_spec: ChainSpec, /// The blocks of the chain. blocks: Vec, - /// The console to print debug contents. - console: Console, + /// The debug buffer to collect debug messages and print them to stdout. + debug_buf: DebugBuffer, /// Handler for registered chain extensions. chain_extension_handler: ChainExtensionHandler, /// Emitted events recorder. @@ -102,7 +102,7 @@ impl EnvInstance { exec_context: Vec::new(), chain_spec: ChainSpec::uninitialized(), blocks: Vec::new(), - console: Console::new(), + debug_buf: DebugBuffer::new(), chain_extension_handler: ChainExtensionHandler::new(), emitted_events: EmittedEventsRecorder::new(), clear_storage_disabled: false, @@ -133,7 +133,7 @@ impl EnvInstance { self.exec_context.clear(); self.chain_spec.reset(); self.blocks.clear(); - self.console.reset(); + self.debug_buf.reset(); self.chain_extension_handler.reset(); self.emitted_events.reset(); self.clear_storage_disabled = false; diff --git a/crates/env/src/engine/off_chain/test_api.rs b/crates/env/src/engine/off_chain/test_api.rs index 855be01a29..41c979b9d5 100644 --- a/crates/env/src/engine/off_chain/test_api.rs +++ b/crates/env/src/engine/off_chain/test_api.rs @@ -215,8 +215,8 @@ where Ok(()) } -/// Returns the contents of the past performed environmental `println` in order. -pub fn recorded_printlns() -> impl Iterator { +/// Returns the contents of the past performed environmental debug messages in order. +pub fn recorded_debug_messages() -> impl Iterator { ::on_instance(|instance| { // We return a clone of the recorded strings instead of // references to them since this would require the whole `on_instance` @@ -224,8 +224,8 @@ pub fn recorded_printlns() -> impl Iterator { // ultimately allow leaking those `'static` references to the outside // and potentially lead to terrible bugs such as iterator invalidation. instance - .console - .past_prints() + .debug_buf + .past_debug_messages() .map(ToOwned::to_owned) .collect::>() .into_iter() diff --git a/crates/env/src/engine/on_chain/ext.rs b/crates/env/src/engine/on_chain/ext.rs index dfbd3dd167..d621247bef 100644 --- a/crates/env/src/engine/on_chain/ext.rs +++ b/crates/env/src/engine/on_chain/ext.rs @@ -76,6 +76,9 @@ define_error_codes! { CodeNotFound = 7, /// The account that was called is either no contract (e.g. user account) or is a tombstone. NotCallable = 8, + /// The call to `seal_debug_message` had no effect because debug message + /// recording was disabled. + LoggingDisabled = 9, } /// Thin-wrapper around a `u32` representing a pointer for Wasm32. @@ -308,8 +311,6 @@ mod sys { pub fn seal_set_rent_allowance(value_ptr: Ptr32<[u8]>, value_len: u32); - pub fn seal_println(str_ptr: Ptr32<[u8]>, str_len: u32); - pub fn seal_hash_keccak_256( input_ptr: Ptr32<[u8]>, input_len: u32, @@ -344,6 +345,9 @@ mod sys { #[link(wasm_import_module = "__unstable__")] extern "C" { + #[cfg(feature = "ink-debug")] + pub fn seal_debug_message(str_ptr: Ptr32<[u8]>, str_len: u32) -> ReturnCode; + pub fn seal_rent_params( output_ptr: Ptr32Mut<[u8]>, output_len_ptr: Ptr32Mut, @@ -645,11 +649,37 @@ pub fn random(subject: &[u8], output: &mut &mut [u8]) { extract_from_slice(output, output_len as usize); } -pub fn println(content: &str) { - let bytes = content.as_bytes(); - unsafe { sys::seal_println(Ptr32::from_slice(bytes), bytes.len() as u32) } +#[cfg(feature = "ink-debug")] +/// Call `seal_debug_message` with the supplied UTF-8 encoded message. +/// +/// If debug message recording is disabled in the contracts pallet, the first call to will +/// return LoggingDisabled error, and further calls will be a no-op to avoid the cost of calling +/// into the supervisor. +/// +/// # Note +/// +/// This depends on the the `seal_debug_message` interface which requires the +/// `"pallet-contracts/unstable-interface"` feature to be enabled in the target runtime. +pub fn debug_message(message: &str) { + static mut DEBUG_ENABLED: bool = true; + + // SAFETY: safe because executing in a single threaded context + if unsafe { DEBUG_ENABLED } { + let bytes = message.as_bytes(); + let ret_code = unsafe { + sys::seal_debug_message(Ptr32::from_slice(bytes), bytes.len() as u32) + }; + if let Err(Error::LoggingDisabled) = ret_code.into() { + // SAFETY: safe because executing in a single threaded context + unsafe { DEBUG_ENABLED = false } + } + } } +#[cfg(not(feature = "ink-debug"))] +/// A no-op. Enable the `ink-debug` feature for debug messages. +pub fn debug_message(_message: &str) {} + macro_rules! impl_hash_fn { ( $name:ident, $bytes_result:literal ) => { paste::item! { diff --git a/crates/env/src/engine/on_chain/impls.rs b/crates/env/src/engine/on_chain/impls.rs index eacc2d2769..0e426cf46f 100644 --- a/crates/env/src/engine/on_chain/impls.rs +++ b/crates/env/src/engine/on_chain/impls.rs @@ -110,6 +110,7 @@ impl From for Error { ext::Error::NewContractNotFunded => Self::NewContractNotFunded, ext::Error::CodeNotFound => Self::CodeNotFound, ext::Error::NotCallable => Self::NotCallable, + ext::Error::LoggingDisabled => Self::LoggingDisabled, } } } @@ -255,8 +256,8 @@ impl EnvBackend for EnvInstance { ext::return_value(flags, enc_return_value); } - fn println(&mut self, content: &str) { - ext::println(content) + fn debug_message(&mut self, content: &str) { + ext::debug_message(content) } fn hash_bytes(&mut self, input: &[u8], output: &mut ::Type) diff --git a/crates/env/src/error.rs b/crates/env/src/error.rs index 32d4a14550..babd7c2e74 100644 --- a/crates/env/src/error.rs +++ b/crates/env/src/error.rs @@ -46,6 +46,9 @@ pub enum Error { NotCallable, /// An unknown error has occurred. UnknownError, + /// The call to `seal_debug_message` had no effect because debug message + /// recording was disabled. + LoggingDisabled, } /// A result of environmental operations. diff --git a/crates/env/src/lib.rs b/crates/env/src/lib.rs index 9c2f21d513..ffe56c5dc5 100644 --- a/crates/env/src/lib.rs +++ b/crates/env/src/lib.rs @@ -102,3 +102,55 @@ pub use self::{ RentStatus, }, }; + +cfg_if::cfg_if! { + if #[cfg(any(feature = "ink-debug", feature = "std"))] { + /// Required by the `debug_print*` macros below, because there is no guarantee that + /// contracts will have a direct `ink_prelude` dependency. In the future we could introduce + /// an "umbrella" crate containing all the `ink!` crates which could also host these macros. + #[doc(hidden)] + pub use ink_prelude::format; + + /// Appends a formatted string to the `debug_message` buffer which will be: + /// - Returned to the caller when the contract is invoked via RPC (*not* via an extrinsic) + /// - Logged as a `debug!` message on the substrate node, which will be printed to the node + /// console's `stdout` when the log level is set to `debug`. + /// + /// # Note + /// + /// This depends on the the `seal_debug_message` interface which requires the + /// `"pallet-contracts/unstable-interface"` feature to be enabled in the target runtime. + #[macro_export] + macro_rules! debug_print { + ($($arg:tt)*) => ($crate::debug_message(&$crate::format!($($arg)*))); + } + + /// Appends a formatted string to the `debug_message` buffer, as per [`debug_print`] but + /// with a newline appended. + /// + /// # Note + /// + /// This depends on the the `seal_debug_message` interface which requires the + /// `"pallet-contracts/unstable-interface"` feature to be enabled in the target runtime. + #[macro_export] + macro_rules! debug_println { + () => ($crate::debug_print!("\n")); + ($($arg:tt)*) => ( + $crate::debug_print!("{}\n", $crate::format!($($arg)*)); + ) + } + } else { + #[macro_export] + /// Debug messages disabled. Enable the `ink-debug` feature for contract debugging. + macro_rules! debug_print { + ($($arg:tt)*) => (); + } + + #[macro_export] + /// Debug messages disabled. Enable the `ink-debug` feature for contract debugging. + macro_rules! debug_println { + () => (); + ($($arg:tt)*) => (); + } + } +} diff --git a/crates/lang/macro/src/lib.rs b/crates/lang/macro/src/lib.rs index 4c74e4b049..ad3d26fe9c 100644 --- a/crates/lang/macro/src/lib.rs +++ b/crates/lang/macro/src/lib.rs @@ -399,7 +399,7 @@ use proc_macro::TokenStream; /// # /// #[ink::contract] /// mod greeter { -/// use ink_prelude::format; +/// use ink_env::debug_println; /// /// #[ink(storage)] /// pub struct Greeter; @@ -408,8 +408,7 @@ use proc_macro::TokenStream; /// #[ink(constructor)] /// pub fn new() -> Self { /// let caller = Self::env().caller(); -/// let message = format!("thanks for instantiation {:?}", caller); -/// ink_env::debug_println(&message); +/// debug_println!("thanks for instantiation {:?}", caller); /// Greeter {} /// } /// @@ -417,8 +416,7 @@ use proc_macro::TokenStream; /// pub fn fund(&self) { /// let caller = self.env().caller(); /// let value = self.env().transferred_balance(); -/// let message = format!("thanks for the funding of {:?} from {:?}", value, caller); -/// ink_env::debug_println(&message); +/// debug_println!("thanks for the funding of {:?} from {:?}", value, caller); /// } /// } /// } diff --git a/examples/contract-transfer/lib.rs b/examples/contract-transfer/lib.rs index f705e3ca63..097b204ec5 100644 --- a/examples/contract-transfer/lib.rs +++ b/examples/contract-transfer/lib.rs @@ -58,11 +58,8 @@ pub mod give_me { /// - Panics in case the transfer failed for another reason. #[ink(message)] pub fn give_me(&mut self, value: Balance) { - ink_env::debug_println(&ink_prelude::format!("requested value: {}", value)); - ink_env::debug_println(&ink_prelude::format!( - "contract balance: {}", - self.env().balance() - )); + ink_env::debug_println!("requested value: {}", value); + ink_env::debug_println!("contract balance: {}", self.env().balance()); assert!(value <= self.env().balance(), "insufficient funds!"); @@ -88,11 +85,10 @@ pub mod give_me { /// allowed to receive value as part of the call. #[ink(message, payable, selector = "0xCAFEBABE")] pub fn was_it_ten(&self) { - let msg = ink_prelude::format!( + ink_env::debug_println!( "received payment: {}", self.env().transferred_balance() ); - ink_env::debug_println(&msg); assert!( self.env().transferred_balance() == 10, "payment was not ten"