#
pezkuwi_sdk_docs/reference_docs/
frame_logging.rs

    1//! # FRAME Logging
    2//!
    3//! This reference docs briefly explores how to do logging and printing runtimes, mainly
    4//! FRAME-based.
    5//!
    6//! > Please make sure to read [the section below](#using-logging-in-production) on using logging in
    7//! > production.
    8//!
    9//! ## Using `println!`
    10//!
    11//! To recap, as with standard Rust, you can use `println!` _in your tests_, but it will only print
    12//! out if executed with `--nocapture`, or if the test panics.
    13//!
    14//! ```
    15//! fn it_print() {
    16//! 	println!("Hello, world!");
    17//! }
    18//! ```
    19//!
    20//! within the pezpallet, if you want to use the standard `println!`, it needs to be wrapped in
    21//! [`pezsp_std::if_std`]. Of course, this means that this print code is only available to you in
    22//! the `std` compiler flag, and never present in a wasm build.
    23//!
    24//! ```
    25//! // somewhere in your pezpallet. This is not a real pezpallet code.
    26//! mod pezpallet {
    27//! 	struct Pezpallet;
    28//! 	impl Pezpallet {
    29//! 		fn print() {
    30//! 			pezsp_std::if_std! {
    31//! 				println!("Hello, world!");
    32//! 			}
    33//! 		}
    34//! 	}
    35//! }
    36//! ```
    37//!
    38//! ## Using `log`
    39//!
    40//! First, ensure you are familiar with the [`log`] crate. In short, each log statement has:
    41//!
    42//! 1. `log-level`, signifying how important it is.
    43//! 2. `log-target`, signifying to which component it belongs.
    44//!
    45//! Add log statements to your pezpallet as such:
    46//!
    47//! You can add the log crate to the `Cargo.toml` of the pezpallet.
    48//!
    49//! ```text
    50//! #[dependencies]
    51//! log = { version = "x.y.z", default-features = false }
    52//!
    53//! #[features]
    54//! std = [
    55//! 	// snip -- other pallets
    56//! 	"log/std"
    57//! ]
    58//! ```
    59//!
    60//! More conveniently, the `frame` umbrella crate re-exports the log crate as [`pezframe::log`].
    61//!
    62//! Then, the pezpallet can use this crate to emit log statements. In this statement, we use the
    63//! info level, and the target is `pezpallet-example`.
    64//!
    65//! ```
    66//! mod pezpallet {
    67//! 	struct Pezpallet;
    68//!
    69//! 	impl Pezpallet {
    70//! 		fn logs() {
    71//! 			pezframe::log::info!(target: "pezpallet-example", "Hello, world!");
    72//! 		}
    73//! 	}
    74//! }
    75//! ```
    76//!
    77//! This will in itself just emit the log messages, **but unless if captured by a logger, they will
    78//! not go anywhere**. [`pezsp_api`] provides a handy function to enable the runtime logging:
    79//!
    80//! ```
    81//! // in your test
    82//! fn it_also_prints() {
    83//! 	pezsp_api::init_runtime_logger();
    84//! 	// call into your pezpallet, and now it will print `log` statements.
    85//! }
    86//! ```
    87//!
    88//! Alternatively, you can use [`pezsp_tracing::try_init_simple`].
    89//!
    90//! `info`, `error` and `warn` logs are printed by default, but if you want lower level logs to also
    91//! be printed, you must to add the following compiler flag:
    92//!
    93//! ```text
    94//! RUST_LOG=pezpallet-example=trace cargo test
    95//! ```
    96//!
    97//! ## Enabling Logs in Production
    98//!
    99//! All logs from the runtime are emitted by default, but there is a feature flag in [`pezsp_api`],
    100//! called `disable-logging`, that can be used to disable all logs in the runtime. This is useful
    101//! for production chains to reduce the size and overhead of the wasm runtime.
    102#![doc = docify::embed!("../../bizinikiwi/primitives/api/src/lib.rs", init_runtime_logger)]
    103//!
    104//! Similar to the above, the proper `RUST_LOG` must also be passed to your compiler flag when
    105//! compiling the runtime.
    106//!
    107//! ## Log Target Prefixing
    108//!
    109//! Many [`crate::pezkuwi_sdk::frame_runtime`] pallets emit logs with log target `runtime::<name of
    110//! pezpallet>`, for example `runtime::system`. This then allows one to run a node with a wasm blob
    111//! compiled with `LOG_TARGET=runtime=debug`, which enables the log target of all pallets who's log
    112//! target starts with `runtime`.
    113//!
    114//! ## Low Level Primitives
    115//!
    116//! Under the hood, logging is another instance of host functions under the hood (as defined in
    117//! [`crate::reference_docs::wasm_meta_protocol`]). The runtime uses a set of host functions under
    118//! [`pezsp_io::logging`] and [`pezsp_io::misc`] to emit all logs and prints. You typically do not
    119//! need to use these APIs directly.
    120//!
    121//! ## Using Logging in Production
    122//!
    123//! Note that within FRAME, reading storage values __only for the purpose of logging__ is dangerous,
    124//! and can lead to consensus issues. This is because with the introduction of
    125//! [`crate::guides::enable_pov_reclaim`], the node side code will track the storage changes, and
    126//! tries to update the onchain record of the `proof_size` weight used (stored in
    127//! [`pezframe_system::BlockWeight`]) after the block is executed.
    128//!
    129//! If one node has a different log level enabled than the rest of the network, and the extra logs
    130//! impose additional storage reads, then the amount of `proof_size` weight reclaimed into
    131//! [`pezframe_system::BlockWeight`] will be different, causing a state root mismatch, which is
    132//! typically a fatal error emitted from [`pezframe_executive`].
    133//!
    134//! This also can also happen in a teyrchain context, and cause discrepancies between the relay
    135//! chain and the teyrchain, when execution the Teyrchain Validation Function (PVF) on the relay
    136//! chain.
    137//!
    138//! **In summary, you should only used storage values in logging (especially for levels lower than
    139//! `info` which is typically enabled by all parties) that are already read from storage, and will
    140//! be part of the storage proof of execution in any case**.
    141//!
    142//! A typical faulty code would look like this:
    143//!
    144//! ```ignore
    145//! /// This function will have a different storage footprint depending on the log level
    146//! fn faulty_logging() {
    147//! 	log::debug!(
    148//! 		"what I am about to print is only read when `RUST_LOG=debug` {:?}",
    149//! 		StorageValue::<T>::get()
    150//!  	);
    151//! }
    152//! ```
    153//!
    154//! Please read [this issue](https://github.com/pezkuwichain/pezkuwi-sdk/issues/298) for one
    155//! instance of the consensus issues caused by this mistake.