Fixing incorrect measurement for fast(µs) opcodes (#1457)

Closes FuelLabs/fuel-core#1431

In the case of super-fast opcodes(< than 1 µs), the `elapse` method is
not accurate enough, which leads to unstable results from benchmarks.

The change aims to stabilize the results from measurements by
subtracting the time required to reset the VM from the total time of the
benchmark.

Author: kuroki-yosuke

CHANGELOG.md

@@ -9,6 +9,7 @@ and this project adheres to [Semantic Versioning](http://semver.org/).
 Description of the upcoming release here.
 
 ### Added
+- [#1457](https://github.com/FuelLabs/fuel-core/pull/1457): Fixing incorrect measurement for fast(µs) opcodes.
 - [#1449](https://github.com/FuelLabs/fuel-core/pull/1449): fix coin pagination in e2e test client
 - [#1447](https://github.com/FuelLabs/fuel-core/pull/1447): Add timeout for continuous e2e tests
 - [#1444](https://github.com/FuelLabs/fuel-core/pull/1444): Add "sanity" benchmarks for memory opcodes.

benches/benches/vm.rs

@@ -9,7 +9,6 @@ use criterion::{
     BenchmarkGroup,
     Criterion,
 };
-use std::time::Duration;
 
 use fuel_core_benches::*;
 use fuel_core_storage::transactional::Transaction;
@@ -41,25 +40,48 @@ where
                 db_txn
             };
 
-            let mut elapsed_time = Duration::default();
-            for _ in 0..iters {
+            let final_time;
+            loop {
+                // Measure the total time to revert the VM to the initial state.
+                // It should always do the same things regardless of the number of
+                // iterations because we use a `diff` from the `VmBenchPrepared` initialization.
                 let start = std::time::Instant::now();
-                match instruction {
-                    Instruction::CALL(call) => {
-                        let (ra, rb, rc, rd) = call.unpack();
-                        vm.prepare_call(ra, rb, rc, rd).unwrap();
-                    }
-                    _ => {
-                        black_box(vm.instruction(*instruction).unwrap());
+                for _ in 0..iters {
+                    vm.reset_vm_state(diff);
+                }
+                let time_to_reset = start.elapsed();
+
+                let start = std::time::Instant::now();
+                for _ in 0..iters {
+                    match instruction {
+                        Instruction::CALL(call) => {
+                            let (ra, rb, rc, rd) = call.unpack();
+                            vm.prepare_call(ra, rb, rc, rd).unwrap();
+                        }
+                        _ => {
+                            black_box(vm.instruction(*instruction).unwrap());
+                        }
                     }
+                    vm.reset_vm_state(diff);
+                }
+                let only_instruction = start.elapsed().checked_sub(time_to_reset);
+
+                // It may overflow when the benchmarks run in an unstable environment.
+                // If the hardware is busy during the measuring time to reset the VM,
+                // it will produce `time_to_reset` more than the actual time
+                // to run the instruction and reset the VM.
+                if let Some(result) = only_instruction {
+                    final_time = result;
+                    break
+                } else {
+                    println!("The environment is unstable. Rerunning the benchmark.");
                 }
-                elapsed_time += start.elapsed();
-                vm.reset_vm_state(diff);
             }
+
             db_txn.commit().unwrap();
             // restore original db
             *vm.as_mut().database_mut() = original_db;
-            elapsed_time
+            final_time
         })
     });
 }