diff --git a/Cargo.lock b/Cargo.lock index 72a48265e0..5bf22e44bf 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -853,6 +853,19 @@ version = "1.0.1" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "b5320ae4c3782150d900b79807611a59a99fc9a1d61d686faafc24b93fc8d7ca" +[[package]] +name = "env_logger" +version = "0.10.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "85cdab6a89accf66733ad5a1693a4dcced6aeff64602b634530dd73c1f3ee9f0" +dependencies = [ + "humantime", + "is-terminal", + "log", + "regex", + "termcolor", +] + [[package]] name = "errno" version = "0.3.1" @@ -1093,6 +1106,12 @@ version = "1.1.1" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "02296996cb8796d7c6e3bc2d9211b7802812d36999a51bb754123ead7d37d026" +[[package]] +name = "humantime" +version = "2.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "9a3a5bfb195931eeb336b2a7b4d761daec841b97f947d34394601737a7bba5e4" + [[package]] name = "iai" version = "0.1.1" @@ -1298,10 +1317,12 @@ dependencies = [ "base64", "clap 4.4.6", "elf", + "env_logger", "groupmap", "hex", "kimchi", "libflate", + "log", "mina-curves", "mina-poseidon", "poly-commitment", @@ -1391,9 +1412,9 @@ checksum = "09fc20d2ca12cb9f044c93e3bd6d32d523e6e2ec3db4f7b2939cd99026ecd3f0" [[package]] name = "log" -version = "0.4.19" +version = "0.4.20" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "b06a4cde4c0f271a446782e3eff8de789548ce57dbc8eca9292c27f4a42004b4" +checksum = "b5e6163cb8c49088c2c36f57875e58ccd8c87c7427f7fbd50ea6710b2f3f2e8f" [[package]] name = "memchr" diff --git a/optimism/Cargo.toml b/optimism/Cargo.toml index ca3653e116..37fe645aee 100644 --- a/optimism/Cargo.toml +++ b/optimism/Cargo.toml @@ -33,3 +33,5 @@ libflate = "2" base64 = "0.21.5" strum = "0.24.0" strum_macros = "0.24.0" +log = "0.4.20" +env_logger = "0.10.0" diff --git a/optimism/src/cannon.rs b/optimism/src/cannon.rs index 6b0049c040..1337bdbd40 100644 --- a/optimism/src/cannon.rs +++ b/optimism/src/cannon.rs @@ -1,12 +1,15 @@ // Data structure and stuff for compatibility with Cannon use base64::{engine::general_purpose, Engine as _}; + use libflate::zlib::Decoder; use regex::Regex; use serde::{Deserialize, Deserializer, Serialize}; use std::io::Read; -pub const PAGE_SIZE: usize = 4096; +pub const PAGE_ADDRESS_SIZE: usize = 12; +pub const PAGE_SIZE: usize = 1 << PAGE_ADDRESS_SIZE; +pub const PAGE_ADDRESS_MASK: usize = PAGE_SIZE - 1; #[derive(Serialize, Deserialize, Debug)] pub struct Page { @@ -83,22 +86,6 @@ pub fn step_frequency_parser(s: &str) -> std::result::Result String { @@ -116,13 +103,13 @@ impl ToString for State { } } -#[derive(Debug)] +#[derive(Debug, Clone)] pub struct HostProgram { pub name: String, pub arguments: Vec, } -#[derive(Debug)] +#[derive(Debug, Clone)] pub struct VmConfiguration { pub input_state_file: String, pub output_state_file: String, @@ -135,3 +122,194 @@ pub struct VmConfiguration { pub pprof_cpu: bool, pub host: Option, } + +#[derive(Debug, Clone)] +pub struct Start { + pub time: std::time::Instant, + pub step: usize, +} + +impl Start { + pub fn create(step: usize) -> Start { + Start { + time: std::time::Instant::now(), + step, + } + } +} + +#[derive(Debug, PartialEq, Clone, Deserialize)] +pub struct Symbol { + pub name: String, + pub start: u32, + pub size: usize, +} + +#[derive(Debug, PartialEq, Clone, Deserialize)] +pub struct Meta { + #[serde(deserialize_with = "filtered_ordered")] + pub symbols: Vec, // Needs to be in ascending order w.r.t start address +} + +// Make sure that deserialized data are ordered in ascending order and that we +// have removed 0-size symbols +fn filtered_ordered<'de, D>(deserializer: D) -> Result, D::Error> +where + D: Deserializer<'de>, +{ + let v: Vec = Deserialize::deserialize(deserializer)?; + let mut filtered: Vec = v.into_iter().filter(|e| e.size != 0).collect(); + filtered.sort_by(|a, b| a.start.cmp(&b.start)); + Ok(filtered) +} + +impl Meta { + pub fn find_address_symbol(&self, address: u32) -> Option { + use std::cmp::Ordering; + + self.symbols + .binary_search_by( + |Symbol { + start, + size, + name: _, + }| { + if address < *start { + Ordering::Greater + } else { + let end = *start + *size as u32; + if address >= end { + Ordering::Less + } else { + Ordering::Equal + } + } + }, + ) + .map_or_else(|_| None, |idx| Some(self.symbols[idx].name.to_string())) + } +} + +#[cfg(test)] +mod tests { + + use super::*; + use std::fs::File; + use std::io::{BufReader, Write}; + + #[test] + fn sp_parser() { + use StepFrequency::*; + assert_eq!(step_frequency_parser("never"), Ok(Never)); + assert_eq!(step_frequency_parser("always"), Ok(Always)); + assert_eq!(step_frequency_parser("=123"), Ok(Exactly(123))); + assert_eq!(step_frequency_parser("%123"), Ok(Every(123))); + assert!(step_frequency_parser("@123").is_err()); + } + + // This sample is a subset taken from a Cannon-generated "meta.json" file + // Interestingly, it contains 0-size symbols - there are removed by + // deserialization. + const META_SAMPLE: &str = r#"{ + "symbols": [ + { + "name": "go.go", + "start": 0, + "size": 0 + }, + { + "name": "internal/cpu.processOptions", + "start": 69632, + "size": 1872 + }, + { + "name": "runtime.text", + "start": 69632, + "size": 0 + }, + { + "name": "runtime/internal/atomic.(*Uint8).Load", + "start": 71504, + "size": 28 + }, + { + "name": "runtime/internal/atomic.(*Uint8).Store", + "start": 71532, + "size": 28 + }, + { + "name": "runtime/internal/atomic.(*Uint8).And", + "start": 71560, + "size": 88 + }, + { + "name": "runtime/internal/atomic.(*Uint8).Or", + "start": 71648, + "size": 72 + }]}"#; + + fn deserialize_meta_sample() -> Meta { + serde_json::from_str::(META_SAMPLE).unwrap() + } + + #[test] + fn test_meta_deserialize_from_file() { + let path = "meta_test.json"; + let mut output = + File::create(path).unwrap_or_else(|_| panic!("Could not create file {path}")); + write!(output, "{}", META_SAMPLE) + .unwrap_or_else(|_| panic!("Could not write to file {path}")); + + let input = File::open(path).unwrap_or_else(|_| panic!("Could not open file {path}")); + let buffered = BufReader::new(input); + let read: Meta = serde_json::from_reader(buffered) + .unwrap_or_else(|_| panic!("Failed to deserialize metadata from file {path}")); + + let expected = Meta { + symbols: vec![ + Symbol { + name: "internal/cpu.processOptions".to_string(), + start: 69632, + size: 1872, + }, + Symbol { + name: "runtime/internal/atomic.(*Uint8).Load".to_string(), + start: 71504, + size: 28, + }, + Symbol { + name: "runtime/internal/atomic.(*Uint8).Store".to_string(), + start: 71532, + size: 28, + }, + Symbol { + name: "runtime/internal/atomic.(*Uint8).And".to_string(), + start: 71560, + size: 88, + }, + Symbol { + name: "runtime/internal/atomic.(*Uint8).Or".to_string(), + start: 71648, + size: 72, + }, + ], + }; + + assert_eq!(read, expected); + } + + #[test] + fn test_find_address_symbol() { + let meta = deserialize_meta_sample(); + + assert_eq!( + meta.find_address_symbol(69633), + Some("internal/cpu.processOptions".to_string()) + ); + assert_eq!( + meta.find_address_symbol(69632), + Some("internal/cpu.processOptions".to_string()) + ); + assert_eq!(meta.find_address_symbol(42), None); + } +} diff --git a/optimism/src/main.rs b/optimism/src/main.rs index 732ceddb3d..1b07d961f7 100644 --- a/optimism/src/main.rs +++ b/optimism/src/main.rs @@ -1,6 +1,6 @@ use clap::{arg, value_parser, Arg, ArgAction, Command}; use kimchi_optimism::{ - cannon::{State, VmConfiguration}, + cannon::{self, Meta, Start, State, VmConfiguration}, mips::witness, }; use std::{fs::File, io::BufReader, process::ExitCode}; @@ -113,29 +113,45 @@ fn cli() -> VmConfiguration { pub fn main() -> ExitCode { let configuration = cli(); - println!("configuration\n{:#?}", configuration); - - let file = File::open(configuration.input_state_file).expect("Error opening input state file "); + let file = + File::open(&configuration.input_state_file).expect("Error opening input state file "); let reader = BufReader::new(file); // Read the JSON contents of the file as an instance of `State`. let state: State = serde_json::from_reader(reader).expect("Error reading input state file"); - if let Some(host_program) = configuration.host { + let meta_file = File::open(&configuration.metadata_file).unwrap_or_else(|_| { + panic!( + "Could not open metadata file {}", + &configuration.metadata_file + ) + }); + + let meta: Meta = serde_json::from_reader(BufReader::new(meta_file)).unwrap_or_else(|_| { + panic!( + "Error deserializing metadata file {}", + &configuration.metadata_file + ) + }); + + if let Some(host_program) = &configuration.host { println!("Launching host program {}", host_program.name); - let _child = std::process::Command::new(host_program.name) - .args(host_program.arguments) + let _child = std::process::Command::new(&host_program.name) + .args(&host_program.arguments) .spawn() .expect("Could not spawn host process"); }; - let page_size = 1 << 12; + // Initialize some data used for statistical computations + let start = Start::create(state.step as usize); + + env_logger::Builder::from_env(env_logger::Env::default().default_filter_or("info")).init(); - let mut env = witness::Env::::create(page_size, state); + let mut env = witness::Env::::create(cannon::PAGE_SIZE, state); while !env.halt { - env.step(); + env.step(configuration.clone(), &meta, &start); } // TODO: Logic diff --git a/optimism/src/mips/witness.rs b/optimism/src/mips/witness.rs index 8fd8377561..ab0d3fec35 100644 --- a/optimism/src/mips/witness.rs +++ b/optimism/src/mips/witness.rs @@ -1,11 +1,15 @@ use crate::{ - cannon::State, + cannon::{ + Meta, Start, State, StepFrequency, VmConfiguration, PAGE_ADDRESS_MASK, PAGE_ADDRESS_SIZE, + PAGE_SIZE, + }, mips::{ interpreter::{self, ITypeInstruction, Instruction, JTypeInstruction, RTypeInstruction}, registers::Registers, }, }; use ark_ff::Field; +use log::info; use std::array; pub const NUM_GLOBAL_LOOKUP_TERMS: usize = 1; @@ -52,6 +56,41 @@ fn fresh_scratch_state() -> [Fp; N] { array::from_fn(|_| Fp::zero()) } +const KUNIT: usize = 1024; // a kunit of memory is 1024 things (bytes, kilobytes, ...) +const PREFIXES: &str = "KMGTPE"; // prefixes for memory quantities KiB, MiB, GiB, ... + +// Create a human-readable string representation of the memory size +fn memory_size(total: usize) -> String { + if total < KUNIT { + format!("{total} B") + } else { + // Compute the index in the prefixes string above + let mut idx = 0; + let mut d = KUNIT; + let mut n = total / KUNIT; + + while n >= KUNIT { + d *= KUNIT; + idx += 1; + n /= KUNIT; + } + + let value = total as f64 / d as f64; + + let prefix = + //////////////////////////////////////////////////////////////////////////// + // Famous last words: 1023 exabytes ought to be enough for anybody // + // // + // Corollary: unwrap() below shouldn't fail // + // // + // The maximum representation for usize corresponds to 16 exabytes anyway // + //////////////////////////////////////////////////////////////////////////// + PREFIXES.chars().nth(idx).unwrap(); + + format!("{:.1} {}iB", value, prefix) + } +} + impl Env { pub fn create(page_size: usize, state: State) -> Self { let initial_instruction_pointer = state.pc; @@ -225,9 +264,96 @@ impl Env { } } - pub fn step(&mut self) { + pub fn step(&mut self, config: VmConfiguration, metadata: &Meta, start: &Start) { println!("instruction: {:?}", self.decode_instruction()); + + self.pp_info(config.info_at, metadata, start); + + // Force stops at given iteration + if self.should_trigger_at(config.stop_at) { + self.halt = true; + return; + } + // TODO self.halt = true; } + + fn should_trigger_at(&self, at: StepFrequency) -> bool { + let m: u64 = self.instruction_counter as u64; + match at { + StepFrequency::Never => false, + StepFrequency::Always => true, + StepFrequency::Exactly(n) => n == m, + StepFrequency::Every(n) => m % n == 0, + } + } + + // Compute memory usage + fn memory_usage(&self) -> String { + let total = self.memory.len() * PAGE_SIZE; + memory_size(total) + } + + fn page_address(&self) -> (u32, usize) { + let address = self.instruction_pointer; + let page = address >> PAGE_ADDRESS_SIZE; + let page_address = (address & (PAGE_ADDRESS_MASK as u32)) as usize; + (page, page_address) + } + + fn get_opcode(&mut self) -> Option { + let (page_id, page_address) = self.page_address(); + for (page_index, memory) in self.memory.iter() { + if page_id == *page_index { + let memory_slice: [u8; 4] = memory[page_address..page_address + 4] + .try_into() + .expect("Couldn't read 4 bytes at given address"); + return Some(u32::from_be_bytes(memory_slice)); + } + } + None + } + + fn pp_info(&mut self, at: StepFrequency, meta: &Meta, start: &Start) { + if self.should_trigger_at(at) { + let elapsed = start.time.elapsed(); + let step = self.instruction_counter; + let pc = self.instruction_pointer; + + // Get the 32-bits opcode + let insn = self.get_opcode().unwrap(); + + // Approximate instruction per seconds + let how_many_steps = step - start.step; + let ips = how_many_steps as f64 / elapsed.as_secs() as f64; + + let pages = self.memory.len(); + + let mem = self.memory_usage(); + let name = meta + .find_address_symbol(pc) + .unwrap_or_else(|| "n/a".to_string()); + + info!( + "processing step {} pc {:#010x} insn {:#010x} ips {:.2} page {} mem {} name {}", + step, pc, insn, ips, pages, mem, name + ); + } + } +} + +#[cfg(test)] +mod tests { + + use super::*; + + #[test] + fn test_memory_size() { + assert_eq!(memory_size(1023_usize), "1023 B"); + assert_eq!(memory_size(1024_usize), "1.0 KiB"); + assert_eq!(memory_size(1024 * 1024_usize), "1.0 MiB"); + assert_eq!(memory_size(2100 * 1024 * 1024_usize), "2.1 GiB"); + assert_eq!(memory_size(std::usize::MAX), "16.0 EiB"); + } }