solana_program_log/

lib.rs

//! Lightweight log utility for Solana programs.
//!
//! Logging is the main mechanism for getting debugging information out of
//! running Solana programs, and there are several functions available for doing
//! so efficiently, depending on the type of data being logged.
//!
//! This crate provides a `Logger` struct and a collection of helper functions that
//! can be used to efficiently log messages in a Solana program.
//!
//! The `Logger` struct is a wrapper around a fixed-size buffer. Types that
//! implement the `Log` trait can be appended to this buffer. The struct is
//! generic over the buffer size, which should be chosen based on the expected
//! size of the log messages. When the buffer becomes full, the log message is
//! truncated, indicated by an `@` character at the end of the message.
//!
//! # Example
//!
//! Creating a `Logger` with a buffer size of `100` bytes, and appending a string and an
//! `u64` value:
//!
//! ```
//! use solana_program_log::Logger;
//!
//! let mut logger = Logger::<100>::default();
//! logger.append("balance=");
//! logger.append(1_000_000_000);
//! logger.log();
//!
//! // Clear the logger buffer.
//! logger.clear();
//!
//! logger.append(&["Hello ", "world!"]);
//! logger.log();
//! ```
//!
//! It also support adding precision to numeric types:
//!
//! ```
//! use solana_program_log::{Argument, Logger};
//!
//! let mut logger = Logger::<100>::default();
//!
//! let lamports = 1_000_000_000u64;
//!
//! logger.append("balance (SOL)=");
//! logger.append_with_args(lamports, &[Argument::Precision(9)]);
//! logger.log();
//! ```

#![no_std]
#![cfg_attr(docsrs, feature(doc_cfg))]
#![allow(clippy::arithmetic_side_effects)]

pub mod logger;
mod wrapper;

#[cfg(feature = "macro")]
#[doc(hidden)]
pub mod __macro_reexports {
    pub use solana_program_log_macro::log;
}

#[cfg(feature = "macro")]
pub use solana_program_log_macro::log_cu_usage;

#[cfg(feature = "macro")]
/// Companion `log!` macro.
///
/// The macro automates the creation of a `Logger` object to log a message.
/// It support a limited subset of the [`format!`](https://doc.rust-lang.org/std/fmt/) syntax.
/// The macro parses the format string at compile time and generates the calls to a `Logger`
/// object to generate the corresponding formatted message.
///
/// # Arguments
///
/// - `buffer_len`: The length of the buffer to use for the logger (default to `200`). This is an optional argument.
/// - `format_string`: The literal string to log. This string can contain placeholders `{}` to be replaced by the arguments.
/// - `args`: The arguments to replace the placeholders in the format string. The arguments must implement the `Log` trait.
///
/// # Examples
///
/// Log a static string:
///
/// ```
/// use solana_program_log::log;
///
/// log!("a simple log");
/// ```
///
/// Log a formatted value:
///
/// ```
/// use solana_program_log::log;
///
/// let lamports = 1_000_000_000u64;
/// log!("lamports={}", lamports);
/// ```
///
/// Increase the logger buffer size for larger messages:
///
/// ```
/// use solana_program_log::log;
///
/// let lamports = 1_000_000_000u64;
/// log!(500, "lamports={}", lamports);
/// ```
///
/// Apply precision formatting to integer values:
///
/// ```
/// use solana_program_log::log;
///
/// let lamports = 1_000_000_000u64;
/// log!("lamports (SOL)={:.9}", lamports);
/// ```
///
/// Truncate string values from the start or end:
///
/// ```
/// use solana_program_log::log;
///
/// let program_name = "solana-program";
/// log!("{:<.10}", program_name);
/// log!("{:>.10}", program_name);
/// ```
///
/// Pass any types that implements `Log`, including slices:
///
/// ```
/// use solana_program_log::log;
///
/// let balances = [1u64, 2u64];
/// log!("lamports={}", &balances);
/// ```
#[macro_export]
macro_rules! log {
    ( $len:literal, $message:literal $(, $args:expr )* $(,)? ) => {
        $crate::__macro_reexports::log!($crate, $len, $message $(, $args )*)
    };
    ( $message:literal $(, $args:expr )* $(,)? ) => {
        $crate::__macro_reexports::log!($crate, $message $(, $args )*)
    };
}

pub use {
    logger::{Argument, Logger},
    wrapper::*,
};

// Enabling the "std" feature when `target_os = "solana"` or
// `target_arch = "bpf"` has no effect.
#[cfg(all(not(any(target_os = "solana", target_arch = "bpf")), feature = "std"))]
extern crate std;

#[cfg(test)]
mod tests {
    use super::{Argument, Logger};

    /// Helper macro to generate test cases for numeric types.
    ///
    /// The test cases are generated for the given type and buffer size. The
    /// assert compares that the logger buffer length is less than or equal to
    /// the maximum length.
    macro_rules! generate_numeric_test_case {
        ( $value:expr, $max_len:expr, $($size:expr),+ $(,)? ) => {
            $(
                let mut logger = Logger::<$size>::default();
                logger.append($value);
                assert!((*logger).len() <= $max_len);
            )*
        };
    }

    /// Helper macro to generate test cases for `str` type.
    ///
    /// The test cases are generated for the given value and buffer size. The
    /// assert compares that the logger buffer length is equal to the minimum
    /// between the buffer size and the `str` length.
    macro_rules! generate_str_test_case {
        ( $str:expr, $($size:expr),+ $(,)? ) => {
            $(
                let mut logger = Logger::<$size>::default();
                logger.append(core::str::from_utf8($str).unwrap());
                assert_eq!((*logger).len(), core::cmp::min($str.len(), $size));
            )*
        };
    }

    #[test]
    fn test_logger() {
        let mut logger = Logger::<100>::default();
        logger.append("Hello ");
        logger.append("world!");

        assert!(&*logger == "Hello world!".as_bytes());

        logger.clear();

        logger.append("balance=");
        logger.append(1_000_000_000);

        assert!(&*logger == "balance=1000000000".as_bytes());
    }

    #[test]
    fn test_logger_truncated() {
        let mut logger = Logger::<8>::default();
        logger.append("Hello ");
        logger.append("world!");

        assert!(&*logger == "Hello w@".as_bytes());

        let mut logger = Logger::<12>::default();

        logger.append("balance=");
        logger.append(1_000_000_000);

        assert!(&*logger == "balance=100@".as_bytes());
    }

    #[test]
    fn test_logger_slice() {
        let mut logger = Logger::<20>::default();
        logger.append(&["Hello ", "world!"]);

        assert!(&*logger == "[\"Hello \", \"world!\"]".as_bytes());

        let mut logger = Logger::<20>::default();
        logger.append(&[123, 456]);

        assert!(&*logger == "[123, 456]".as_bytes());
    }

    #[test]
    fn test_logger_truncated_slice() {
        let mut logger = Logger::<5>::default();
        logger.append(&["Hello ", "world!"]);

        assert!(&*logger == "[\"He@".as_bytes());

        let mut logger = Logger::<4>::default();
        logger.append(&[123, 456]);

        assert!(&*logger == "[12@".as_bytes());
    }

    #[test]
    fn test_logger_signed() {
        let mut logger = Logger::<2>::default();
        logger.append(-2);

        assert!(&*logger == "-2".as_bytes());

        let mut logger = Logger::<5>::default();
        logger.append(-200_000_000);

        assert!(&*logger == "-200@".as_bytes());
    }

    #[test]
    fn test_logger_with_precision() {
        let mut logger = Logger::<10>::default();

        logger.append_with_args(200_000_000u64, &[Argument::Precision(2)]);
        assert!(&*logger == "2000000.00".as_bytes());

        logger.clear();

        logger.append_with_args(2_000_000_000u64, &[Argument::Precision(2)]);
        assert!(&*logger == "20000000.@".as_bytes());

        logger.clear();

        logger.append_with_args(2_000_000_000u64, &[Argument::Precision(5)]);
        assert!(&*logger == "20000.000@".as_bytes());

        logger.clear();

        logger.append_with_args(2_000_000_000u64, &[Argument::Precision(10)]);
        assert!(&*logger == "0.2000000@".as_bytes());

        logger.clear();

        logger.append_with_args(2u64, &[Argument::Precision(6)]);
        assert!(&*logger == "0.000002".as_bytes());

        logger.clear();

        logger.append_with_args(2u64, &[Argument::Precision(9)]);
        assert!(&*logger == "0.0000000@".as_bytes());

        logger.clear();

        logger.append_with_args(-2000000i32, &[Argument::Precision(6)]);
        assert!(&*logger == "-2.000000".as_bytes());

        logger.clear();

        logger.append_with_args(-2i64, &[Argument::Precision(9)]);
        assert!(&*logger == "-0.000000@".as_bytes());

        logger.clear();

        // This should have no effect since it is a string.
        logger.append_with_args("0123456789", &[Argument::Precision(2)]);
        assert!(&*logger == "0123456789".as_bytes());

        logger.clear();

        logger.append_with_args(2u8, &[Argument::Precision(8)]);
        assert!(&*logger == "0.00000002".as_bytes());

        logger.clear();

        logger.append_with_args(2u8, &[Argument::Precision(u8::MAX)]);
        assert!(&*logger == "0.0000000@".as_bytes());

        let mut logger = Logger::<20>::default();

        logger.append_with_args(2u8, &[Argument::Precision(u8::MAX)]);
        assert!(&*logger == "0.00000000000000000@".as_bytes());

        logger.clear();

        logger.append_with_args(20_000u16, &[Argument::Precision(10)]);
        assert!(&*logger == "0.0000020000".as_bytes());

        let mut logger = Logger::<3>::default();

        logger.append_with_args(2u64, &[Argument::Precision(u8::MAX)]);
        assert!(&*logger == "0.@".as_bytes());

        logger.clear();

        logger.append_with_args(2u64, &[Argument::Precision(1)]);
        assert!(&*logger == "0.2".as_bytes());

        logger.clear();

        logger.append_with_args(-2i64, &[Argument::Precision(1)]);
        assert!(&*logger == "-0@".as_bytes());

        let mut logger = Logger::<1>::default();

        logger.append_with_args(-2i64, &[Argument::Precision(1)]);
        assert!(&*logger == "@".as_bytes());

        let mut logger = Logger::<2>::default();

        logger.append_with_args(-2i64, &[Argument::Precision(1)]);
        assert!(&*logger == "-@".as_bytes());

        let mut logger = Logger::<20>::default();

        logger.append_with_args(u64::MAX, &[Argument::Precision(u8::MAX)]);
        assert!(&*logger == "0.00000000000000000@".as_bytes());

        // 255 precision + leading 0 + decimal point
        let mut logger = Logger::<257>::default();
        logger.append_with_args(u64::MAX, &[Argument::Precision(u8::MAX)]);
        assert!(logger.starts_with("0.00000000000000".as_bytes()));
        assert!(logger.ends_with("18446744073709551615".as_bytes()));

        logger.clear();

        logger.append_with_args(u32::MAX, &[Argument::Precision(u8::MAX)]);
        assert!(logger.starts_with("0.00000000000000".as_bytes()));
        assert!(logger.ends_with("4294967295".as_bytes()));

        logger.clear();

        logger.append_with_args(u16::MAX, &[Argument::Precision(u8::MAX)]);
        assert!(logger.starts_with("0.00000000000000".as_bytes()));
        assert!(logger.ends_with("65535".as_bytes()));

        logger.clear();

        logger.append_with_args(u8::MAX, &[Argument::Precision(u8::MAX)]);
        assert!(logger.starts_with("0.00000000000000".as_bytes()));
        assert!(logger.ends_with("255".as_bytes()));

        // 255 precision + sign + leading 0 + decimal point
        let mut logger = Logger::<258>::default();
        logger.append_with_args(i64::MIN, &[Argument::Precision(u8::MAX)]);
        assert!(logger.starts_with("-0.00000000000000".as_bytes()));
        assert!(logger.ends_with("9223372036854775808".as_bytes()));

        logger.clear();

        logger.append_with_args(i32::MIN, &[Argument::Precision(u8::MAX)]);
        assert!(logger.starts_with("-0.00000000000000".as_bytes()));
        assert!(logger.ends_with("2147483648".as_bytes()));

        logger.clear();

        logger.append_with_args(i16::MIN, &[Argument::Precision(u8::MAX)]);
        assert!(logger.starts_with("-0.00000000000000".as_bytes()));
        assert!(logger.ends_with("32768".as_bytes()));

        logger.clear();

        logger.append_with_args(i8::MIN, &[Argument::Precision(u8::MAX)]);
        assert!(logger.starts_with("-0.00000000000000".as_bytes()));
        assert!(logger.ends_with("128".as_bytes()));
    }

    #[test]
    fn test_logger_with_truncate() {
        let mut logger = Logger::<10>::default();

        logger.append_with_args("0123456789", &[Argument::TruncateEnd(10)]);
        assert!(&*logger == "0123456789".as_bytes());

        logger.clear();

        logger.append_with_args("0123456789", &[Argument::TruncateStart(10)]);
        assert!(&*logger == "0123456789".as_bytes());

        logger.clear();

        logger.append_with_args("0123456789", &[Argument::TruncateEnd(9)]);
        assert!(&*logger == "012345...".as_bytes());

        logger.clear();

        logger.append_with_args("0123456789", &[Argument::TruncateStart(9)]);
        assert!(&*logger == "...456789".as_bytes());

        let mut logger = Logger::<3>::default();

        logger.append_with_args("0123456789", &[Argument::TruncateEnd(9)]);
        assert!(&*logger == "..@".as_bytes());

        logger.clear();

        logger.append_with_args("0123456789", &[Argument::TruncateStart(9)]);
        assert!(&*logger == "..@".as_bytes());

        let mut logger = Logger::<1>::default();

        logger.append_with_args("test", &[Argument::TruncateStart(0)]);
        assert!(&*logger == "".as_bytes());

        logger.clear();

        logger.append_with_args("test", &[Argument::TruncateStart(1)]);
        assert!(&*logger == "@".as_bytes());

        let mut logger = Logger::<2>::default();

        logger.append_with_args("test", &[Argument::TruncateStart(2)]);
        assert!(&*logger == ".@".as_bytes());

        let mut logger = Logger::<3>::default();

        logger.append_with_args("test", &[Argument::TruncateStart(3)]);
        assert!(&*logger == "..@".as_bytes());

        let mut logger = Logger::<1>::default();

        logger.append_with_args("test", &[Argument::TruncateEnd(0)]);
        assert!(&*logger == "".as_bytes());

        logger.clear();

        logger.append_with_args("test", &[Argument::TruncateEnd(1)]);
        assert!(&*logger == "@".as_bytes());

        let mut logger = Logger::<2>::default();

        logger.append_with_args("test", &[Argument::TruncateEnd(2)]);
        assert!(&*logger == ".@".as_bytes());

        let mut logger = Logger::<3>::default();

        logger.append_with_args("test", &[Argument::TruncateEnd(3)]);
        assert!(&*logger == "..@".as_bytes());
    }

    #[test]
    fn test_logger_with_usize() {
        let mut logger = Logger::<20>::default();

        logger.append(usize::MIN);
        assert!(&*logger == "0".as_bytes());

        logger.clear();

        logger.append(usize::MAX);

        #[cfg(target_pointer_width = "32")]
        {
            assert!(&*logger == "4294967295".as_bytes());
            assert_eq!(logger.len(), 10);
        }
        #[cfg(target_pointer_width = "64")]
        {
            assert!(&*logger == "18446744073709551615".as_bytes());
            assert_eq!(logger.len(), 20);
        }
    }

    #[test]
    fn test_logger_with_isize() {
        let mut logger = Logger::<20>::default();

        logger.append(isize::MIN);

        #[cfg(target_pointer_width = "32")]
        {
            assert!(&*logger == "-2147483648".as_bytes());
            assert_eq!(logger.len(), 11);
        }
        #[cfg(target_pointer_width = "64")]
        {
            assert!(&*logger == "-9223372036854775808".as_bytes());
            assert_eq!(logger.len(), 20);
        }

        logger.clear();

        logger.append(isize::MAX);

        #[cfg(target_pointer_width = "32")]
        {
            assert!(&*logger == "2147483647".as_bytes());
            assert_eq!(logger.len(), 10);
        }
        #[cfg(target_pointer_width = "64")]
        {
            assert!(&*logger == "9223372036854775807".as_bytes());
            assert_eq!(logger.len(), 19);
        }
    }

    #[test]
    fn test_logger_buffer_size_unsigned() {
        // Test case for an unsigned numeric type.
        macro_rules! unsigned_test_case {
            ( $( ($ty:ident, $max_len:literal) ),+ $(,)? ) => {
                    $(
                        generate_numeric_test_case!($ty::MAX, $max_len, 1,
                        2,
                        3,
                        4,
                        5,
                        6,
                        7,
                        8,
                        9,
                        10,
                        11,
                        12,
                        13,
                        14,
                        15,
                        16,
                        17,
                        18,
                        19,
                        20,
                        50,
                        100,
                        1000);
                )*
            };
        }

        unsigned_test_case!((u8, 3), (u16, 5), (u32, 10), (u64, 20), (usize, 20));
        #[cfg(not(target_arch = "bpf"))]
        unsigned_test_case!((u128, 39),);
    }

    #[test]
    fn test_logger_buffer_size_signed() {
        // Test case for a signed numeric type.
        macro_rules! signed_test_case {
            ( $( ($ty:ident, $max_len:literal) ),+ $(,)? ) => {
                    $(
                        generate_numeric_test_case!($ty::MIN, ($max_len + 1), 1,
                            2,
                            3,
                            4,
                            5,
                            6,
                            7,
                            8,
                            9,
                            10,
                            11,
                            12,
                            13,
                            14,
                            15,
                            16,
                            17,
                            18,
                            19,
                            20,
                            50,
                            100,
                            1000);
                    )*
            };
        }

        signed_test_case!((i8, 3), (i16, 5), (i32, 10), (i64, 20), (isize, 20));
        #[cfg(not(target_arch = "bpf"))]
        signed_test_case!((i128, 39),);
    }

    #[test]
    fn test_logger_buffer_size_str() {
        // Test case for a str type.
        macro_rules! str_test_case {
            ( $( $size:expr ),+ $(,)? ) => {
                    $(
                        generate_str_test_case!(&[b'x'; $size], 1,
                            2,
                            3,
                            4,
                            5,
                            6,
                            7,
                            8,
                            9,
                            10,
                            11,
                            12,
                            13,
                            14,
                            15,
                            16,
                            17,
                            18,
                            19,
                            20,
                            50,
                            100,
                            1000);
                    )*
            };
        }

        str_test_case!(1, 5, 10, 50, 100, 1000, 10000);
    }

    #[test]
    fn test_logger_bool() {
        let mut logger = Logger::<5>::default();
        logger.append(true);

        assert!(&*logger == "true".as_bytes());

        let mut logger = Logger::<5>::default();
        logger.append(false);

        assert!(&*logger == "false".as_bytes());

        let mut logger = Logger::<3>::default();
        logger.append(true);

        assert!(&*logger == "tr@".as_bytes());

        let mut logger = Logger::<4>::default();
        logger.append(false);

        assert!(&*logger == "fal@".as_bytes());
    }
}