simplify ownership of tracer; add benchmark.

fvm/Cargo.toml

@@ -42,6 +42,14 @@ blake2b_simd = "1.0.0"
 minstant = { version = "0.1.1" }
 serde_json = { version = "1.0.79", optional = true }
 
+[dev-dependencies]
+criterion = "0.3.5"
+
+[[bench]]
+name = "gas_tracing"
+harness = false
+required-features = ["tracing"]
+
 [dependencies.wasmtime]
 version = "0.35.2"
 default-features = false

fvm/benches/gas_tracing.rs

@@ -0,0 +1,39 @@
+use std::time::Duration;
+
+use criterion::{criterion_group, criterion_main, BatchSize, BenchmarkId, Criterion, Throughput};
+use fvm::gas::tracer::{Consumption, Context, Event, GasTrace, Point};
+
+pub fn benchmark_gas_tracing(c: &mut Criterion) {
+ let mut group = c.benchmark_group("gas_tracing");
+
+ for size in [16, 32, 64, 128, 256].iter() {
+ group.warm_up_time(Duration::from_secs(5));
+ group.measurement_time(Duration::from_secs(20));
+ group.throughput(Throughput::Elements(*size as u64));
+
+ group.bench_with_input(BenchmarkId::from_parameter(size), size, |b, &size| {
+ b.iter_batched_ref(
+ || GasTrace::start(),
+ move |gt| {
+ let ctx = Context {
+ code_cid: Default::default(),
+ method_num: size,
+ };
+ let point = Point {
+ event: Event::Started,
+ label: "foo".to_string(),
+ };
+ let consumption = Consumption {
+ fuel_consumed: Some(1234 + size),
+ gas_consumed: Some((1111 + size) as i64),
+ };
+ gt.record(ctx, point, consumption);
+ },
+ BatchSize::SmallInput,
+ );
+ });
+ }
+}
+
+criterion_group!(benches, benchmark_gas_tracing);
+criterion_main!(benches);

fvm/src/call_manager/default.rs

@@ -56,7 +56,7 @@ pub struct InnerDefaultCallManager<M> {
  /// Stats related to the message execution.
  exec_stats: ExecutionStats,
  #[cfg(feature = "tracing")]
- gas_tracer: Option<std::cell::RefCell<crate::gas::tracer::GasTracer>>,
+ gas_trace: crate::gas::tracer::GasTrace,
 }
 
 #[doc(hidden)]
@@ -101,18 +101,17 @@ where
  exec_trace: vec![],
 
  #[cfg(feature = "tracing")]
- gas_tracer: {
- use crate::gas::tracer::Point;
- let mut tracer = crate::gas::tracer::GasTracer::new();
+ gas_trace: {
+ let mut tracer = crate::gas::tracer::GasTrace::start();
  tracer.record(
  Default::default(),
- Point {
+ crate::gas::tracer::Point {
  event: crate::gas::tracer::Event::Started,
  label: Default::default(),
  },
  Default::default(),
  );
- Some(std::cell::RefCell::new(tracer))
+ tracer
  },
  })))
  }
@@ -193,24 +192,20 @@ where
  #[cfg(feature = "tracing")]
  {
  use crate::gas::tracer::{Consumption, Point};
- let tracer = self.gas_tracer.take().unwrap();
- let traces = {
- let mut tracer = tracer.into_inner();
- tracer.record(
- Default::default(),
- Point {
- event: crate::gas::tracer::Event::Finished,
- label: Default::default(),
- },
- Consumption {
- fuel_consumed: None,
- gas_consumed: Some(self.gas_tracker.gas_used()),
- },
- );
- tracer.finish()
- };
+ let gas_used = self.gas_tracker.gas_used();
+ self.gas_trace.record(
+ Default::default(),
+ Point {
+ event: crate::gas::tracer::Event::Finished,
+ label: Default::default(),
+ },
+ Consumption {
+ fuel_consumed: None,
+ gas_consumed: Some(gas_used),
+ },
+ );
  let mut tf = TRACE_FILE.lock().unwrap();
- serde_json::to_writer(tf.deref_mut(), &traces).unwrap();
+ serde_json::to_writer(tf.deref_mut(), &self.gas_trace).unwrap();
  tf.flush().unwrap();
  }
 
@@ -233,16 +228,12 @@ where
 
  #[cfg(feature = "tracing")]
  fn record_trace(
- &self,
+ &mut self,
  context: crate::gas::tracer::Context,
  point: crate::gas::tracer::Point,
  consumption: crate::gas::tracer::Consumption,
  ) {
- self.gas_tracer
- .as_ref()
- .unwrap()
- .borrow_mut()
- .record(context, point, consumption)
+ self.gas_trace.record(context, point, consumption)
  }
 
  // Accessor methods so the trait can implement some common methods by default.
@@ -392,7 +383,7 @@ where
  {
  use crate::gas::tracer::{Consumption, Context, Point};
  let gas_used = self.gas_tracker.gas_used();
- self.gas_tracer.as_mut().unwrap().get_mut().record(
+ self.gas_trace.record(
  Context {
  code_cid: state.code.clone(),
  method_num: method,
@@ -510,7 +501,7 @@ where
  {
  use crate::gas::tracer::{Consumption, Context, Point};
  let gas_used = cm.gas_tracker.gas_used();
- cm.gas_tracer.as_mut().unwrap().get_mut().record(
+ cm.gas_trace.record(
  Context {
  code_cid: state.code.clone(),
  method_num: method,

fvm/src/call_manager/mod.rs

@@ -125,7 +125,7 @@ pub trait CallManager: 'static {
  /// Record a gas trace.
  #[cfg(feature = "tracing")]
  fn record_trace(
- &self,
+ &mut self,
  context: crate::gas::tracer::Context,
  point: crate::gas::tracer::Point,
  consumption: crate::gas::tracer::Consumption,

fvm/src/gas/tracer.rs

@@ -6,25 +6,27 @@ use fvm_shared::MethodNum;
 use minstant::Instant;
 use serde::Serialize;
 
-#[derive(Debug)]
-pub struct GasTracer {
+#[derive(Debug, Serialize)]
+pub struct GasTrace {
+ #[serde(skip)]
  started: Instant,
+ #[serde(skip)]
  previous: Instant,
- traces: LinkedList<GasTrace>,
+ spans: LinkedList<GasSpan>,
 }
 
-impl GasTracer {
- pub fn new() -> GasTracer {
+impl GasTrace {
+ pub fn start() -> GasTrace {
  let now = Instant::now();
- GasTracer {
+ GasTrace {
  started: now,
  previous: now,
- traces: Default::default(),
+ spans: Default::default(),
  }
  }
 
  pub fn record(&mut self, context: Context, point: Point, consumption: Consumption) {
- let trace = GasTrace {
+ let trace = GasSpan {
  context,
  point,
  consumption,
@@ -38,16 +40,12 @@ impl GasTracer {
  }
  },
  };
- self.traces.push_back(trace)
- }
-
- pub fn finish(self) -> LinkedList<GasTrace> {
- self.traces
+ self.spans.push_back(trace)
  }
 }
 
 #[derive(Debug, Serialize)]
-pub struct GasTrace {
+pub struct GasSpan {
  /// Context annotates the trace with the source context.
  #[serde(flatten)]
  pub context: Context,
@@ -115,8 +113,8 @@ pub enum Event {
 
 #[test]
 fn test_tracer() {
- let mut tracer = GasTracer::new();
- tracer.record(
+ let mut trace = GasTrace::start();
+ trace.record(
  Context {
  code_cid: Default::default(),
  method_num: 0,
@@ -132,7 +130,7 @@ fn test_tracer() {
  );
 
  std::thread::sleep(Duration::from_millis(1000));
- tracer.record(
+ trace.record(
  Context {
  code_cid: Default::default(),
  method_num: 0,
@@ -146,10 +144,9 @@ fn test_tracer() {
  gas_consumed: None,
  },
  );
- let traces = tracer.finish();
- println!("{:?}", traces);
+ println!("{:?}", trace);
 
- let str = serde_json::to_string(&traces).unwrap();
+ let str = serde_json::to_string(&trace).unwrap();
  println!("{}", str);
 }
 

fvm/src/kernel/default.rs

@@ -142,7 +142,7 @@ where
 
  #[cfg(feature = "tracing")]
  fn record_trace(
- &self,
+ &mut self,
  point: crate::gas::tracer::Point,
  mut consumption: crate::gas::tracer::Consumption,
  ) {

fvm/src/kernel/mod.rs

@@ -68,7 +68,7 @@ pub trait Kernel:
 
  #[cfg(feature = "tracing")]
  fn record_trace(
- &self,
+ &mut self,
  point: crate::gas::tracer::Point,
  consumption: crate::gas::tracer::Consumption,
  );

testing/conformance/src/vm.rs

@@ -213,13 +213,13 @@ where
  })
  }
 
- fn finish(self) -> (FinishRet, ExecutionStats, Self::Machine) {
+ fn finish(self) -> (FinishRet, Self::Machine) {
  self.0.finish()
  }
 
  #[cfg(feature = "tracing")]
  fn record_trace(
- &self,
+ &mut self,
  context: fvm::gas::tracer::Context,
  point: fvm::gas::tracer::Point,
  consumption: fvm::gas::tracer::Consumption,
@@ -329,7 +329,7 @@ where
 
  #[cfg(feature = "tracing")]
  fn record_trace(
- &self,
+ &mut self,
  point: fvm::gas::tracer::Point,
  consumption: fvm::gas::tracer::Consumption,
  ) {