Optionaly show stats during fuzzing session

CHANGELOG.md

@@ -10,6 +10,7 @@ incremented upon a breaking change and the patch version will be incremented for
 
 ## [Unreleased]
 ### Added
+- feat/fuzzer-stats-logging, an optional stats output, triggered by `--run-with-stats`, during fuzzing sessions ([#144](https://github.com/Ackee-Blockchain/trident/pull/144))
 - feat/support of automatically obtaining fully qualified paths of Data Accounts Custom types for `accounts_snapshots.rs` ([#141](https://github.com/Ackee-Blockchain/trident/pull/141))
 - feat/allow direct accounts manipulation and storage ([#142](https://github.com/Ackee-Blockchain/trident/pull/142))
 - feat/support of non-corresponding instruction and context names ([#130](https://github.com/Ackee-Blockchain/trident/pull/130))

crates/cli/src/command/fuzz.rs

@@ -18,6 +18,9 @@ pub enum FuzzCommand {
         /// Trident will return exit code 1 in case of found crash files in the crash folder. This is checked before and after the fuzz test run.
         #[arg(short, long)]
         with_exit_code: bool,
+        /// Trident will show statistics during fuzzing session. It is recommended to turn `keep_output` and `verbose` on true.
+        #[arg(short, long)]
+        run_with_stats: bool,
     },
     /// Debug fuzz target with crash file
     Run_Debug {
@@ -50,9 +53,12 @@ pub async fn fuzz(root: Option<String>, subcmd: FuzzCommand) {
         FuzzCommand::Run {
             target,
             with_exit_code,
+            run_with_stats,
         } => {
             if with_exit_code {
                 commander.run_fuzzer_with_exit_code(target).await?;
+            } else if run_with_stats {
+                commander.run_fuzzer_with_stats(target).await?;
             } else {
                 commander.run_fuzzer(target).await?;
             }

crates/client/Cargo.toml

@@ -71,3 +71,4 @@ pathdiff = "0.2.1"
 solana-banks-client = "<1.18"
 indicatif = "0.17.8"
 regex = "1.10.3"
+solana-logger = "<1.18"

crates/client/derive/fuzz_test_executor/src/lib.rs

@@ -13,6 +13,10 @@ pub fn fuzz_test_executor(input: TokenStream) -> TokenStream {
                 let variant_name = &variant.ident;
                 quote! {
                     #enum_name::#variant_name (ix) => {
+                        #[cfg(fuzzing)]
+                        if client.allow_stats() {
+                            client.accumulate_executed_ix(self.to_context_string());
+                        }
                         let (mut signers, metas) = ix.get_accounts(client, &mut accounts.borrow_mut())
                             .map_err(|e| e.with_origin(Origin::Instruction(self.to_context_string())))
                             .expect("Accounts calculation expect");
@@ -41,12 +45,20 @@ pub fn fuzz_test_executor(input: TokenStream) -> TokenStream {
                         .map_err(|e| e.with_origin(Origin::Instruction(self.to_context_string())));
 
                         if tx_res.is_ok() {
+                            #[cfg(fuzzing)]
+                            if client.allow_stats() {
+                                client.accumulate_successful_ix(self.to_context_string());
+                            }
                             snaphot.capture_after(client).unwrap();
                             let (acc_before, acc_after) = snaphot.get_snapshot()
                                 .map_err(|e| e.with_origin(Origin::Instruction(self.to_context_string())))
                                 .expect("Snapshot deserialization expect"); // we want to panic if we cannot unwrap to cause a crash
 
                             if let Err(e) = ix.check(acc_before, acc_after, data).map_err(|e| e.with_origin(Origin::Instruction(self.to_context_string()))) {
+                                #[cfg(fuzzing)]
+                                if client.allow_stats() {
+                                    client.show_accumulated_stats();
+                                }
                                 eprintln!(
                                     "CRASH DETECTED! Custom check after the {} instruction did not pass!",
                                     self.to_context_string());
@@ -58,18 +70,21 @@ pub fn fuzz_test_executor(input: TokenStream) -> TokenStream {
             });
 
             quote! {
-               impl FuzzTestExecutor<FuzzAccounts> for FuzzInstruction {
-                   fn run_fuzzer(
-                       &self,
-                       program_id: Pubkey,
-                       accounts: &RefCell<FuzzAccounts>,
-                       client: &mut impl FuzzClient,
-                   ) -> core::result::Result<(), Box<dyn std::error::Error + 'static>> {
-                           match self {
-                               #(#display_match_arms)*
-                           }
-                           Ok(())
-                   }
+                impl FuzzTestExecutor<FuzzAccounts> for FuzzInstruction {
+                    fn run_fuzzer<C>(
+                        &self,
+                        program_id: Pubkey,
+                        accounts: &RefCell<FuzzAccounts>,
+                        client: &mut C,
+                   ) -> core::result::Result<(), Box<dyn std::error::Error + 'static>>
+                    where
+                        C: FuzzClient + StatsLogger,
+                    {
+                            match self {
+                                #(#display_match_arms)*
+                            }
+                            Ok(())
+                    }
                 }
             }
         }

crates/client/src/commander.rs

@@ -251,6 +251,47 @@ impl Commander {
         }
     }
 
+    /// Runs fuzzer on the given target and turn FUZZING_STATS env variable on true
+    /// Based on the variable, fuzzer will show statistics during fuzzing session
+    #[throws]
+    pub async fn run_fuzzer_with_stats(&self, target: String) {
+        let config = Config::new();
+
+        let hfuzz_run_args = std::env::var("HFUZZ_RUN_ARGS").unwrap_or_default();
+
+        // std::env::set_var("FUZZING_STATS", "true");
+
+        let cargo_target_dir = std::env::var("CARGO_TARGET_DIR")
+            .unwrap_or_else(|_| config.get_env_arg("CARGO_TARGET_DIR"));
+        let hfuzz_workspace = std::env::var("HFUZZ_WORKSPACE")
+            .unwrap_or_else(|_| config.get_env_arg("HFUZZ_WORKSPACE"));
+
+        let fuzz_args = config.get_fuzz_args(hfuzz_run_args);
+
+        let mut child = Command::new("cargo")
+            .env("HFUZZ_RUN_ARGS", fuzz_args)
+            .env("CARGO_TARGET_DIR", cargo_target_dir)
+            .env("HFUZZ_WORKSPACE", hfuzz_workspace)
+            .env("FUZZING_STATS", "true")
+            .arg("hfuzz")
+            .arg("run")
+            .arg(target)
+            .spawn()?;
+
+        tokio::select! {
+            res = child.wait() =>
+                match res {
+                    Ok(status) => if !status.success() {
+                        println!("Honggfuzz exited with an error!");
+                    },
+                    Err(_) => throw!(Error::FuzzingFailed),
+            },
+            _ = signal::ctrl_c() => {
+                tokio::time::sleep(tokio::time::Duration::from_millis(100)).await;
+            },
+        }
+    }
+
     /// Runs fuzzer on the given target.
     #[throws]
     pub async fn run_fuzzer_debug(&self, target: String, crash_file_path: String) {

crates/client/src/fuzzer/client_stats.rs

@@ -0,0 +1,26 @@
+use std::collections::HashMap;
+
+#[derive(Debug)]
+pub struct AccumulatedStats {
+    pub executed: u64,
+    pub successful: u64,
+}
+
+#[derive(Debug, Default)]
+pub struct Stats {
+    pub accumulated_stats: HashMap<String, AccumulatedStats>,
+    pub iterations: u64,
+}
+
+pub trait StatsLogger {
+    /// Accumulate number of invocations for corresponding instruction
+    fn accumulate_executed_ix(&mut self, ix: String);
+    /// Accumulate number of successful invocations for corresponding instruction
+    fn accumulate_successful_ix(&mut self, ix: String);
+    /// Show the Accumulated stats
+    fn show_accumulated_stats(&mut self);
+    /// Increase number of iterations
+    fn increase_iterrations(&mut self);
+    /// Return if show stats are enabled
+    fn allow_stats(&self) -> bool;
+}

crates/client/src/fuzzer/data_builder.rs

@@ -12,6 +12,7 @@ use std::cell::RefCell;
 use std::error::Error;
 use std::fmt::Display;
 
+use crate::client_stats::StatsLogger;
 use crate::error::*;
 
 pub struct FuzzData<T, U> {
@@ -52,47 +53,60 @@ impl<T, U> FuzzData<T, U>
 where
     T: FuzzTestExecutor<U> + Display,
 {
-    pub fn run_with_runtime(
+    pub fn run_with_runtime<C>(
         &self,
         program_id: Pubkey,
-        client: &mut impl FuzzClient,
-    ) -> core::result::Result<(), Box<dyn Error + 'static>> {
-        // solana_logger::setup_with_default("off");
-        // #[cfg(fuzzing_debug)]
-        // solana_logger::setup_with_default(
-        //     "solana_rbpf::vm=debug,\
-        //         solana_runtime::message_processor=debug,\
-        //         solana_runtime::system_instruction_processor=trace,\
-        //         solana_program_test=info,\
-        //         fuzz_target=info",
-        // );
-
+        client: &mut C,
+    ) -> core::result::Result<(), Box<dyn Error + 'static>>
+    where
+        C: FuzzClient + StatsLogger,
+    {
         #[cfg(fuzzing_debug)]
         {
+            solana_logger::setup_with_default(
+                "solana_rbpf::vm=debug,\
+                solana_runtime::message_processor=debug,\
+                solana_runtime::system_instruction_processor=trace,\
+                solana_program_test=info,\
+                fuzz_target=info",
+            );
             eprintln!("Instructions sequence:");
             for ix in self.iter() {
                 eprintln!("{}", ix);
             }
             eprintln!("------ End of Instructions sequence ------ ");
         }
-
+        #[cfg(fuzzing)]
+        if client.allow_stats() {
+            // the line below will prevent the fuzzing output from unnecessary messages like:
+            // [2024-03-13T11:57:20.158011532Z INFO  solana_program_test_anchor_fix] "fuzz_example0" builtin program
+            // I guess we can remove it once we do not need solana_program_test_anchor_fix.
+            // std::env::set_var("RUST_LOG", "solana_program_test_anchor_fix=off");
+            // solana_logger::setup_with_default("off");
+            client.increase_iterrations();
+        }
         for fuzz_ix in &mut self.iter() {
             #[cfg(fuzzing_debug)]
             eprintln!("Currently processing: {}", fuzz_ix);
-
             fuzz_ix.run_fuzzer(program_id, &self.accounts, client)?;
         }
+        #[cfg(fuzzing)]
+        if client.allow_stats() {
+            client.show_accumulated_stats();
+        }
         Ok(())
     }
 }
 
 pub trait FuzzTestExecutor<T> {
-    fn run_fuzzer(
+    fn run_fuzzer<C>(
         &self,
         program_id: Pubkey,
         accounts: &RefCell<T>,
-        client: &mut impl FuzzClient,
-    ) -> core::result::Result<(), Box<dyn Error + 'static>>;
+        client: &mut C,
+    ) -> core::result::Result<(), Box<dyn Error + 'static>>
+    where
+        C: FuzzClient + StatsLogger;
 }
 
 #[allow(unused_variables)]

crates/client/src/fuzzer/mod.rs

@@ -1,4 +1,5 @@
 pub mod accounts_storage;
+pub mod client_stats;
 pub mod data_builder;
 pub mod fuzzer_generator;
 #[cfg(feature = "fuzzing")]

crates/client/src/fuzzer/program_test_client_blocking.rs

@@ -10,12 +10,16 @@ use solana_sdk::{
 use spl_token::state::Mint;
 use tokio::runtime::Builder;
 
+use crate::client_stats::{AccumulatedStats, Stats, StatsLogger};
+use crate::constants::*;
 use crate::data_builder::FuzzClient;
 use crate::error::*;
 
 pub struct ProgramTestClientBlocking {
     ctx: ProgramTestContext,
     rt: tokio::runtime::Runtime,
+    stats: Stats,
+    allow_stats: bool,
 }
 
 impl ProgramTestClientBlocking {
@@ -26,9 +30,33 @@ impl ProgramTestClientBlocking {
     ) -> Result<Self, FuzzClientError> {
         let program_test = ProgramTest::new(program_name, program_id, entry);
         let rt: tokio::runtime::Runtime = Builder::new_current_thread().enable_all().build()?;
-
         let ctx = rt.block_on(program_test.start_with_context());
-        Ok(Self { ctx, rt })
+
+        let allow_stats = std::env::var("FUZZING_STATS").is_ok();
+        #[cfg(fuzzing)]
+        if allow_stats {
+            std::env::set_var("RUST_LOG", "solana_program_test_anchor_fix=off");
+            solana_logger::setup_with_default("off");
+        }
+
+        let stats = Stats::default();
+        Ok(Self {
+            ctx,
+            rt,
+            allow_stats,
+            stats,
+        })
+    }
+    pub fn new_clean(
+        &mut self,
+        program_name: &str,
+        program_id: Pubkey,
+        entry: Option<BuiltinFunctionWithContext>,
+    ) -> Result<(), FuzzClientError> {
+        let program_test = ProgramTest::new(program_name, program_id, entry);
+        let ctx = self.rt.block_on(program_test.start_with_context());
+        self.ctx = ctx;
+        Ok(())
     }
 }
 
@@ -172,3 +200,55 @@ impl FuzzClient for ProgramTestClientBlocking {
         Ok(self.rt.block_on(self.ctx.banks_client.get_rent())?)
     }
 }
+
+impl StatsLogger for ProgramTestClientBlocking {
+    fn accumulate_executed_ix(&mut self, ix: String) {
+        self.stats
+            .accumulated_stats
+            .entry(ix)
+            .and_modify(|e| e.executed = e.executed.checked_add(1).ok_or(u64::MAX).unwrap())
+            .or_insert(AccumulatedStats {
+                executed: 1,
+                successful: 0,
+            });
+    }
+    fn accumulate_successful_ix(&mut self, ix: String) {
+        self.stats
+            .accumulated_stats
+            .entry(ix)
+            .and_modify(|e| e.successful = e.successful.checked_add(1).ok_or(u64::MAX).unwrap())
+            .or_insert(AccumulatedStats {
+                executed: 0,
+                successful: 1,
+            });
+    }
+    fn show_accumulated_stats(&mut self) {
+        let stats = &self.stats;
+        let not_successful: Vec<(&String, &AccumulatedStats)> = stats
+            .accumulated_stats
+            .iter()
+            .filter(|e| e.1.successful == 0)
+            .collect();
+
+        if not_successful.is_empty() {
+            println!("{SUCCESS} Accumulated stats: {:#?}", self.stats);
+        } else {
+            eprintln!(
+                "{ERROR} The {:#?} instruction/s have 0 successful invocations",
+                not_successful
+            );
+        }
+    }
+
+    fn increase_iterrations(&mut self) {
+        self.stats.iterations = self
+            .stats
+            .iterations
+            .checked_add(1)
+            .ok_or(u64::MAX)
+            .unwrap();
+    }
+    fn allow_stats(&self) -> bool {
+        self.allow_stats
+    }
+}