From 6fa8de8bf9668b1bcdceca29d9f645fdfeb23ba1 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Micha=C5=82=20Strug?= Date: Tue, 17 Oct 2023 14:25:12 +0200 Subject: [PATCH 01/11] Added new command --- simulator/src/replay/cmd_alloc_dump.rs | 26 ++++++++++++++++++++++++++ simulator/src/replay/mod.rs | 4 ++++ simulator/src/scrypto_bindgen/mod.rs | 5 ++++- 3 files changed, 34 insertions(+), 1 deletion(-) create mode 100644 simulator/src/replay/cmd_alloc_dump.rs diff --git a/simulator/src/replay/cmd_alloc_dump.rs b/simulator/src/replay/cmd_alloc_dump.rs new file mode 100644 index 00000000000..2ea13558619 --- /dev/null +++ b/simulator/src/replay/cmd_alloc_dump.rs @@ -0,0 +1,26 @@ +use super::Error; +use clap::Parser; +use radix_engine::types::*; +use std::path::PathBuf; + +/// Run transactions in archive using RocksDB and dump memory allocations +#[derive(Parser, Debug)] +pub struct TxnAllocDump { + /// Path to the source Node state manager database + pub source: PathBuf, + /// Path to a folder for storing state + pub database_dir: PathBuf, + + /// The network to use, [mainnet | stokenet] + #[clap(short, long)] + pub network: Option, + /// The max version to execute + #[clap(short, long)] + pub max_version: Option, +} + +impl TxnAllocDump { + pub fn run(&self) -> Result<(), Error> { + Ok(()) + } +} diff --git a/simulator/src/replay/mod.rs b/simulator/src/replay/mod.rs index a412dc9721e..de7aba0ce95 100644 --- a/simulator/src/replay/mod.rs +++ b/simulator/src/replay/mod.rs @@ -2,12 +2,14 @@ pub mod ledger_transaction; pub mod ledger_transaction_execution; pub mod txn_reader; +mod cmd_alloc_dump; mod cmd_execute; mod cmd_execute_in_memory; mod cmd_prepare; mod cmd_sync; mod error; +pub use cmd_alloc_dump::*; pub use cmd_execute::*; pub use cmd_execute_in_memory::*; pub use cmd_prepare::*; @@ -30,6 +32,7 @@ pub enum Command { Execute(TxnExecute), ExecuteInMemory(TxnExecuteInMemory), Sync(TxnSync), + AllocDump(TxnAllocDump), } pub fn run() -> Result<(), Error> { @@ -40,5 +43,6 @@ pub fn run() -> Result<(), Error> { Command::Execute(cmd) => cmd.run(), Command::ExecuteInMemory(cmd) => cmd.run(), Command::Sync(cmd) => cmd.sync(), + Command::AllocDump(cmd) => cmd.run(), } } diff --git a/simulator/src/scrypto_bindgen/mod.rs b/simulator/src/scrypto_bindgen/mod.rs index 7eb38601ab1..1744d8020f7 100644 --- a/simulator/src/scrypto_bindgen/mod.rs +++ b/simulator/src/scrypto_bindgen/mod.rs @@ -117,7 +117,10 @@ where S: SubstateDatabase, { fn lookup_schema(&self, schema_hash: &SchemaHash) -> Option { - self.1.get_schema(self.0.as_node_id(), schema_hash).ok().map(|x| x.as_ref().clone()) + self.1 + .get_schema(self.0.as_node_id(), schema_hash) + .ok() + .map(|x| x.as_ref().clone()) } fn resolve_type_kind( From 6bf364ccd92e64246b6acf1ca693f8c035b2b198 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Micha=C5=82=20Strug?= Date: Wed, 18 Oct 2023 13:45:37 +0200 Subject: [PATCH 02/11] Moved info_alloc to radix-engine-profiling project --- radix-engine-profiling/Cargo.toml | 1 + radix-engine-profiling/src/info_alloc/mod.rs | 158 +++++++++++++++++++ radix-engine-profiling/src/lib.rs | 5 + radix-engine/Cargo.toml | 6 +- radix-engine/src/kernel/resources_tracker.rs | 92 +---------- 5 files changed, 168 insertions(+), 94 deletions(-) create mode 100644 radix-engine-profiling/src/info_alloc/mod.rs diff --git a/radix-engine-profiling/Cargo.toml b/radix-engine-profiling/Cargo.toml index 3003fb67fea..32f8523d442 100644 --- a/radix-engine-profiling/Cargo.toml +++ b/radix-engine-profiling/Cargo.toml @@ -23,3 +23,4 @@ default = [] resource_tracker = ["dep:shared_memory"] rocksdb = ["dep:plotters", "dep:linreg", "dep:blake2", "dep:rand", "radix-engine-stores/std", "radix-engine-store-interface/std", "radix-engine-interface/std"] +cpu_ram_metrics = [] diff --git a/radix-engine-profiling/src/info_alloc/mod.rs b/radix-engine-profiling/src/info_alloc/mod.rs new file mode 100644 index 00000000000..66b83688d4f --- /dev/null +++ b/radix-engine-profiling/src/info_alloc/mod.rs @@ -0,0 +1,158 @@ +use std::{ + alloc::{GlobalAlloc, Layout, System}, + sync::atomic::{AtomicIsize, Ordering}, +}; + +#[global_allocator] +pub static INFO_ALLOC: InfoAlloc = InfoAlloc::new(System); + +/// Heap allocations tracker +/// +/// This allocator information provider can count allocations up to isize::MAX (9_223_372_036_854_775_807), +/// in case of exceeding this value code will panic with message: 'Value out of range'. +pub struct InfoAlloc { + /// Heap allocator to use, default usage: System + allocator: T, + /// Sum of bytes allocated during measurements (for reallocations only additional memory is counted, no dealocation is counted) + sum_counter: AtomicIsize, + /// Current level of allocated bytes (allocation and deallocation are counted, incl. reallocation) + current_level: AtomicIsize, + /// Maximum level (peak) of allocated bytes (the max of this field and current_level) + max_level: AtomicIsize, +} + +impl InfoAlloc { + pub const fn new(allocator: T) -> Self { + InfoAlloc { + allocator, + sum_counter: AtomicIsize::new(0), + current_level: AtomicIsize::new(0), + max_level: AtomicIsize::new(0), + } + } + + /// Resets internal counters. Usually used to start measurement. + pub fn reset_counters(&self) { + self.sum_counter.store(0, Ordering::Release); + self.current_level.store(0, Ordering::Release); + self.max_level.store(0, Ordering::Release); + } + + #[inline] + fn increase_counters(&self, value: usize) { + let ivalue: isize = value.try_into().expect("Value out of range"); + + self.sum_counter.fetch_add(ivalue, Ordering::AcqRel); + + let old_value = self.current_level.fetch_add(ivalue, Ordering::AcqRel); + self.max_level + .fetch_max(old_value + ivalue, Ordering::AcqRel); + } + + #[inline] + fn decrease_counters(&self, value: usize) { + self.current_level.fetch_sub( + value.try_into().expect("Value out of range"), + Ordering::AcqRel, + ); + } + + #[inline] + fn realloc_decrease_counter(&self, old_size: usize, new_size: usize) { + let old_size: isize = old_size.try_into().expect("Value out of range"); + let new_size: isize = new_size.try_into().expect("Value out of range"); + self.current_level + .fetch_sub(old_size - new_size, Ordering::AcqRel); + + if new_size > old_size { + self.sum_counter + .fetch_add(new_size - old_size, Ordering::AcqRel); + + let current_level = self.current_level.load(Ordering::Acquire); + self.max_level.fetch_max(current_level, Ordering::AcqRel); + } + } + + /// Returns current counters values: sum fo all allocations, current allocation level, peak allocation level + /// Counters can have negative values because of memory allocations before calling to reset_counters() function + /// and deallocating them during measurements. In that case counter value is set to 0. + pub fn get_counters_value(&self) -> (usize, usize, usize) { + ( + self.sum_counter.load(Ordering::Acquire).max(0) as usize, + self.current_level.load(Ordering::Acquire).max(0) as usize, + self.max_level.load(Ordering::Acquire).max(0) as usize, + ) + } +} + +unsafe impl GlobalAlloc for InfoAlloc { + unsafe fn alloc(&self, layout: Layout) -> *mut u8 { + self.increase_counters(layout.size()); + self.allocator.alloc(layout) + } + + unsafe fn dealloc(&self, ptr: *mut u8, layout: Layout) { + self.decrease_counters(layout.size()); + self.allocator.dealloc(ptr, layout); + } + + unsafe fn realloc(&self, ptr: *mut u8, layout: Layout, new_size: usize) -> *mut u8 { + self.realloc_decrease_counter(layout.size(), new_size); + self.allocator.realloc(ptr, layout, new_size) + } +} + +#[test] +fn info_mem_check() { + INFO_ALLOC.reset_counters(); + + // allocate 10 bytes + let mut v = Vec::::with_capacity(10); + let (sum, current, peak) = INFO_ALLOC.get_counters_value(); + assert_eq!((sum, current, peak), (10, 10, 10)); + + // no allocation/deallocation occurs + v.push(10); + let (sum, current, peak) = INFO_ALLOC.get_counters_value(); + assert_eq!((sum, current, peak), (10, 10, 10)); + + // deallocate 9 bytes + v.shrink_to_fit(); + let (sum, current, peak) = INFO_ALLOC.get_counters_value(); + assert_eq!((sum, current, peak), (10, 1, 10)); + + // allocate 3 bytes + let _a = Box::new(1u8); + let _b = Box::new(1u8); + let _c = Box::new(1u8); + let (sum, current, peak) = INFO_ALLOC.get_counters_value(); + assert_eq!((sum, current, peak), (13, 4, 10)); + + // allocate 10 bytes + let mut v = Vec::::with_capacity(10); + let (sum, current, peak) = INFO_ALLOC.get_counters_value(); + assert_eq!((sum, current, peak), (23, 14, 14)); + + // no allocation/deallocation occurs + v.push(10); + + // deallocate 9 bytes + v.shrink_to_fit(); + let (sum, current, peak) = INFO_ALLOC.get_counters_value(); + assert_eq!((sum, current, peak), (23, 5, 14)); + + // allocate 10 bytes + let mut v = Vec::::with_capacity(10); + let (sum, current, peak) = INFO_ALLOC.get_counters_value(); + assert_eq!((sum, current, peak), (33, 15, 15)); + + // allocate 10 bytes (by default capacity of vector is extended by 2) + v.extend([1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11]); + let (sum, current, peak) = INFO_ALLOC.get_counters_value(); + assert_eq!((sum, current, peak), (43, 25, 25)); + + // deallocate 9 bytes + v.shrink_to_fit(); + let (sum, current, peak) = INFO_ALLOC.get_counters_value(); + assert_eq!((sum, current, peak), (43, 16, 25)); +} diff --git a/radix-engine-profiling/src/lib.rs b/radix-engine-profiling/src/lib.rs index b3d5faea99e..375d254b828 100644 --- a/radix-engine-profiling/src/lib.rs +++ b/radix-engine-profiling/src/lib.rs @@ -7,3 +7,8 @@ pub use qemu_plugin_interface::*; pub mod rocks_db_metrics; #[cfg(feature = "rocksdb")] pub use rocks_db_metrics::*; + +#[cfg(feature = "cpu_ram_metrics")] +pub mod info_alloc; +#[cfg(feature = "cpu_ram_metrics")] +pub use info_alloc::*; diff --git a/radix-engine/Cargo.toml b/radix-engine/Cargo.toml index 769ae7ffc1e..7599eeec2d9 100644 --- a/radix-engine/Cargo.toml +++ b/radix-engine/Cargo.toml @@ -19,7 +19,7 @@ lru = { version = "0.8.1", default-features = false, optional = true} moka = { version = "0.9.9", features = ["sync"], default-features = false, optional = true } strum = { version = "0.24", default-features = false, features = ["derive"] } perfcnt = { version = "0.8.0", optional = true } -radix-engine-profiling = { path = "../radix-engine-profiling", optional = true, features = ["resource_tracker"] } +radix-engine-profiling = { path = "../radix-engine-profiling", optional = true } resources-tracker-macro = { path = "../radix-engine-profiling/resources-tracker-macro" } paste = { version = "1.0.13" } radix-engine-macros = { path = "../radix-engine-macros", default-features = false } @@ -64,7 +64,7 @@ alloc = ["sbor/alloc", "native-sdk/alloc", "transaction/alloc", "radix-engine-in # Enables heap memory and CPU cycles resource tracing - available only for Linux OS on x86 arch. # Requires CAP_PERFMON capability for the process (sudo setcap cap_perfmon=eip ). -cpu_ram_metrics = ["std", "dep:perfcnt"] +cpu_ram_metrics = ["std", "dep:perfcnt", "dep:radix-engine-profiling", "radix-engine-profiling?/cpu_ram_metrics"] # Use `wasmer` as WASM engine, otherwise `wasmi` wasmer = ["dep:wasmer", "dep:wasmer-compiler-singlepass"] @@ -74,7 +74,7 @@ wasmer = ["dep:wasmer", "dep:wasmer-compiler-singlepass"] moka = ["dep:moka"] lru = ["dep:lru"] -resource_tracker = ["dep:radix-engine-profiling", "resources-tracker-macro/resource_tracker", "radix-engine-common/resource_tracker"] +resource_tracker = ["dep:radix-engine-profiling", "radix-engine-profiling?/resource_tracker", "resources-tracker-macro/resource_tracker", "radix-engine-common/resource_tracker"] # System/Application Database Checker db_checker = [] diff --git a/radix-engine/src/kernel/resources_tracker.rs b/radix-engine/src/kernel/resources_tracker.rs index 84f4923c3e9..f9008f1fe20 100644 --- a/radix-engine/src/kernel/resources_tracker.rs +++ b/radix-engine/src/kernel/resources_tracker.rs @@ -7,97 +7,7 @@ use perfcnt::{ linux::{HardwareEventType, PerfCounterBuilderLinux}, AbstractPerfCounter, PerfCounter, }; - -#[global_allocator] -static INFO_ALLOC: InfoAlloc = InfoAlloc::new(System); - -/// Heap allocations tracker -/// -/// This allocator information provider can count allocations up to isize::MAX (9_223_372_036_854_775_807), -/// in case of exceeding this value code will panic with message: 'Value out of range'. -pub struct InfoAlloc { - /// Heap allocator to use, default usage: System - allocator: T, - /// Sum of bytes allocated during measurements (no dealocation is counted) - sum_counter: AtomicIsize, - /// Current level of allocated bytes (allocation and deallocation are counted) - current_level: AtomicIsize, - /// Maximum level (peak) of allocated bytes (allocation and deallocation are counted) - max_level: AtomicIsize, -} - -impl InfoAlloc { - pub const fn new(allocator: T) -> Self { - InfoAlloc { - allocator, - sum_counter: AtomicIsize::new(0), - current_level: AtomicIsize::new(0), - max_level: AtomicIsize::new(0), - } - } - - /// Resets internal counters. Usually used to start measurement. - pub fn reset_counters(&self) { - self.sum_counter.store(0, Ordering::Release); - self.current_level.store(0, Ordering::Release); - self.max_level.store(0, Ordering::Release); - } - - #[inline] - fn increase_counters(&self, value: usize) { - let ivalue: isize = value.try_into().expect("Value out of range"); - - self.sum_counter.fetch_add(ivalue, Ordering::AcqRel); - - let old_value = self.current_level.fetch_add(ivalue, Ordering::AcqRel); - self.max_level - .fetch_max(old_value + ivalue, Ordering::AcqRel); - } - - #[inline] - fn decrease_counters(&self, value: usize) { - self.current_level.fetch_sub( - value.try_into().expect("Value out of range"), - Ordering::AcqRel, - ); - } - - #[inline] - fn realloc_decrease_counter(&self, value: usize) { - self.sum_counter.fetch_sub( - value.try_into().expect("Value out of range"), - Ordering::AcqRel, - ); - } - - /// Returns current counters values: sum fo all allocations, current allocation level, peak allocation level - /// Counters can have negative values because of memory allocations before calling to reset_counters() function - /// and deallocating them during measurements. In that case counter value is set to 0. - pub fn get_counters_value(&self) -> (usize, usize, usize) { - ( - self.sum_counter.load(Ordering::Acquire).max(0) as usize, - self.current_level.load(Ordering::Acquire).max(0) as usize, - self.max_level.load(Ordering::Acquire).max(0) as usize, - ) - } -} - -unsafe impl GlobalAlloc for InfoAlloc { - unsafe fn alloc(&self, layout: Layout) -> *mut u8 { - self.increase_counters(layout.size()); - self.allocator.alloc(layout) - } - - unsafe fn dealloc(&self, ptr: *mut u8, layout: Layout) { - self.decrease_counters(layout.size()); - self.allocator.dealloc(ptr, layout); - } - - unsafe fn realloc(&self, ptr: *mut u8, layout: Layout, new_size: usize) -> *mut u8 { - self.realloc_decrease_counter(layout.size()); - self.allocator.realloc(ptr, layout, new_size) - } -} +use radix_engine_profiling::info_alloc::*; /// CPU cycles tracker /// From 0ef164376dcdcc60344044a3d003307063bd0062 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Micha=C5=82=20Strug?= Date: Thu, 19 Oct 2023 17:30:07 +0200 Subject: [PATCH 03/11] Added multithread support to heap memory allocator logger --- radix-engine-profiling/Cargo.toml | 2 +- radix-engine-profiling/src/info_alloc/mod.rs | 125 ++++++++++++++----- radix-engine-profiling/src/lib.rs | 4 +- radix-engine/Cargo.toml | 2 +- 4 files changed, 101 insertions(+), 32 deletions(-) diff --git a/radix-engine-profiling/Cargo.toml b/radix-engine-profiling/Cargo.toml index 32f8523d442..2313ec3b26e 100644 --- a/radix-engine-profiling/Cargo.toml +++ b/radix-engine-profiling/Cargo.toml @@ -23,4 +23,4 @@ default = [] resource_tracker = ["dep:shared_memory"] rocksdb = ["dep:plotters", "dep:linreg", "dep:blake2", "dep:rand", "radix-engine-stores/std", "radix-engine-store-interface/std", "radix-engine-interface/std"] -cpu_ram_metrics = [] +ram_metrics = [] diff --git a/radix-engine-profiling/src/info_alloc/mod.rs b/radix-engine-profiling/src/info_alloc/mod.rs index 66b83688d4f..9327ccbc6c9 100644 --- a/radix-engine-profiling/src/info_alloc/mod.rs +++ b/radix-engine-profiling/src/info_alloc/mod.rs @@ -6,6 +6,10 @@ use std::{ #[global_allocator] pub static INFO_ALLOC: InfoAlloc = InfoAlloc::new(System); +thread_local! { + static INFO_ALLOC_DATA_TLS: InfoAllocData = InfoAllocData::new(); +} + /// Heap allocations tracker /// /// This allocator information provider can count allocations up to isize::MAX (9_223_372_036_854_775_807), @@ -13,6 +17,10 @@ pub static INFO_ALLOC: InfoAlloc = InfoAlloc::new(System); pub struct InfoAlloc { /// Heap allocator to use, default usage: System allocator: T, +} + +/// Allocation data stored in Thread Local Store (separate data for each thread) +pub struct InfoAllocData { /// Sum of bytes allocated during measurements (for reallocations only additional memory is counted, no dealocation is counted) sum_counter: AtomicIsize, /// Current level of allocated bytes (allocation and deallocation are counted, incl. reallocation) @@ -21,67 +29,83 @@ pub struct InfoAlloc { max_level: AtomicIsize, } -impl InfoAlloc { - pub const fn new(allocator: T) -> Self { - InfoAlloc { - allocator, +impl InfoAllocData { + fn new() -> Self { + Self { sum_counter: AtomicIsize::new(0), current_level: AtomicIsize::new(0), max_level: AtomicIsize::new(0), } } +} + +impl InfoAlloc { + pub const fn new(allocator: T) -> Self { + InfoAlloc { allocator } + } /// Resets internal counters. Usually used to start measurement. pub fn reset_counters(&self) { - self.sum_counter.store(0, Ordering::Release); - self.current_level.store(0, Ordering::Release); - self.max_level.store(0, Ordering::Release); + INFO_ALLOC_DATA_TLS.with(|val| { + val.sum_counter.store(0, Ordering::Release); + val.current_level.store(0, Ordering::Release); + val.max_level.store(0, Ordering::Release); + }); } #[inline] fn increase_counters(&self, value: usize) { let ivalue: isize = value.try_into().expect("Value out of range"); - self.sum_counter.fetch_add(ivalue, Ordering::AcqRel); + INFO_ALLOC_DATA_TLS.with(|val| { + val.sum_counter.fetch_add(ivalue, Ordering::AcqRel); - let old_value = self.current_level.fetch_add(ivalue, Ordering::AcqRel); - self.max_level - .fetch_max(old_value + ivalue, Ordering::AcqRel); + let old_value = val.current_level.fetch_add(ivalue, Ordering::AcqRel); + val.max_level + .fetch_max(old_value + ivalue, Ordering::AcqRel); + }); } #[inline] fn decrease_counters(&self, value: usize) { - self.current_level.fetch_sub( - value.try_into().expect("Value out of range"), - Ordering::AcqRel, - ); + INFO_ALLOC_DATA_TLS.with(|val| { + val.current_level.fetch_sub( + value.try_into().expect("Value out of range"), + Ordering::AcqRel, + ) + }); } #[inline] fn realloc_decrease_counter(&self, old_size: usize, new_size: usize) { let old_size: isize = old_size.try_into().expect("Value out of range"); let new_size: isize = new_size.try_into().expect("Value out of range"); - self.current_level - .fetch_sub(old_size - new_size, Ordering::AcqRel); - if new_size > old_size { - self.sum_counter - .fetch_add(new_size - old_size, Ordering::AcqRel); + INFO_ALLOC_DATA_TLS.with(|val| { + val.current_level + .fetch_sub(old_size - new_size, Ordering::AcqRel); - let current_level = self.current_level.load(Ordering::Acquire); - self.max_level.fetch_max(current_level, Ordering::AcqRel); - } + if new_size > old_size { + val.sum_counter + .fetch_add(new_size - old_size, Ordering::AcqRel); + + let current_level = val.current_level.load(Ordering::Acquire); + val.max_level.fetch_max(current_level, Ordering::AcqRel); + } + }); } /// Returns current counters values: sum fo all allocations, current allocation level, peak allocation level /// Counters can have negative values because of memory allocations before calling to reset_counters() function /// and deallocating them during measurements. In that case counter value is set to 0. pub fn get_counters_value(&self) -> (usize, usize, usize) { - ( - self.sum_counter.load(Ordering::Acquire).max(0) as usize, - self.current_level.load(Ordering::Acquire).max(0) as usize, - self.max_level.load(Ordering::Acquire).max(0) as usize, - ) + INFO_ALLOC_DATA_TLS.with(|val| { + ( + val.sum_counter.load(Ordering::Acquire).max(0) as usize, + val.current_level.load(Ordering::Acquire).max(0) as usize, + val.max_level.load(Ordering::Acquire).max(0) as usize, + ) + }) } } @@ -156,3 +180,48 @@ fn info_mem_check() { let (sum, current, peak) = INFO_ALLOC.get_counters_value(); assert_eq!((sum, current, peak), (43, 16, 25)); } + +#[test] +fn info_mem_multithread_check() { + use std::thread; + use std::time::Duration; + + let mut handles = vec![]; + + for i in 1..4 { + let handle = thread::spawn(move || { + INFO_ALLOC.reset_counters(); + + let _v = Vec::::with_capacity(i); + // causes context to switch to the next thread + // so we can ensure that counters are properly managed + // using local thread store + thread::sleep(Duration::from_millis(1)); + + let (sum, current, peak) = INFO_ALLOC.get_counters_value(); + assert_eq!((sum, current, peak), (i, i, i)); + }); + handles.push(handle); + } + + for handle in handles { + handle.join().unwrap(); + } +} + +#[test] +fn info_mem_negative_value() { + // allocate 10 bytes + let mut v = Vec::::with_capacity(10); + + INFO_ALLOC.reset_counters(); + + // realloc to 1 byte, this causes alloc counter to get negative value + // because reset counters was called after 10 bytes allocation: 0 - 9 = -9 + v.push(10); + v.shrink_to_fit(); + + let (sum, current, peak) = INFO_ALLOC.get_counters_value(); + // negative values are not returned + assert_eq!((sum, current, peak), (0, 0, 0)); +} diff --git a/radix-engine-profiling/src/lib.rs b/radix-engine-profiling/src/lib.rs index 375d254b828..0ab584b5614 100644 --- a/radix-engine-profiling/src/lib.rs +++ b/radix-engine-profiling/src/lib.rs @@ -8,7 +8,7 @@ pub mod rocks_db_metrics; #[cfg(feature = "rocksdb")] pub use rocks_db_metrics::*; -#[cfg(feature = "cpu_ram_metrics")] +#[cfg(feature = "ram_metrics")] pub mod info_alloc; -#[cfg(feature = "cpu_ram_metrics")] +#[cfg(feature = "ram_metrics")] pub use info_alloc::*; diff --git a/radix-engine/Cargo.toml b/radix-engine/Cargo.toml index 7599eeec2d9..59cba7833e2 100644 --- a/radix-engine/Cargo.toml +++ b/radix-engine/Cargo.toml @@ -64,7 +64,7 @@ alloc = ["sbor/alloc", "native-sdk/alloc", "transaction/alloc", "radix-engine-in # Enables heap memory and CPU cycles resource tracing - available only for Linux OS on x86 arch. # Requires CAP_PERFMON capability for the process (sudo setcap cap_perfmon=eip ). -cpu_ram_metrics = ["std", "dep:perfcnt", "dep:radix-engine-profiling", "radix-engine-profiling?/cpu_ram_metrics"] +cpu_ram_metrics = ["std", "dep:perfcnt", "dep:radix-engine-profiling", "radix-engine-profiling?/ram_metrics"] # Use `wasmer` as WASM engine, otherwise `wasmi` wasmer = ["dep:wasmer", "dep:wasmer-compiler-singlepass"] From 3a72f021ab77fd8c3de3e1b0302a6aa31607b010 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Micha=C5=82=20Strug?= Date: Thu, 19 Oct 2023 19:33:14 +0200 Subject: [PATCH 04/11] Added enable/disable functionality --- radix-engine-profiling/src/info_alloc/mod.rs | 34 +++++++++++++++++--- radix-engine/src/kernel/resources_tracker.rs | 2 ++ 2 files changed, 31 insertions(+), 5 deletions(-) diff --git a/radix-engine-profiling/src/info_alloc/mod.rs b/radix-engine-profiling/src/info_alloc/mod.rs index 9327ccbc6c9..42c612d845d 100644 --- a/radix-engine-profiling/src/info_alloc/mod.rs +++ b/radix-engine-profiling/src/info_alloc/mod.rs @@ -1,6 +1,6 @@ use std::{ alloc::{GlobalAlloc, Layout, System}, - sync::atomic::{AtomicIsize, Ordering}, + sync::atomic::{AtomicBool, AtomicIsize, Ordering}, }; #[global_allocator] @@ -17,6 +17,8 @@ thread_local! { pub struct InfoAlloc { /// Heap allocator to use, default usage: System allocator: T, + /// Determine if allocation data gathering is enabled + enabled: AtomicBool, } /// Allocation data stored in Thread Local Store (separate data for each thread) @@ -41,7 +43,18 @@ impl InfoAllocData { impl InfoAlloc { pub const fn new(allocator: T) -> Self { - InfoAlloc { allocator } + InfoAlloc { + allocator, + enabled: AtomicBool::new(false), + } + } + + pub fn set_enable(&self, enable: bool) { + self.enabled.store(enable, Ordering::Release); + } + + pub fn is_enabled(&self) -> bool { + self.enabled.load(Ordering::Acquire) } /// Resets internal counters. Usually used to start measurement. @@ -111,23 +124,30 @@ impl InfoAlloc { unsafe impl GlobalAlloc for InfoAlloc { unsafe fn alloc(&self, layout: Layout) -> *mut u8 { - self.increase_counters(layout.size()); + if self.is_enabled() { + self.increase_counters(layout.size()); + } self.allocator.alloc(layout) } unsafe fn dealloc(&self, ptr: *mut u8, layout: Layout) { - self.decrease_counters(layout.size()); + if self.is_enabled() { + self.decrease_counters(layout.size()); + } self.allocator.dealloc(ptr, layout); } unsafe fn realloc(&self, ptr: *mut u8, layout: Layout, new_size: usize) -> *mut u8 { - self.realloc_decrease_counter(layout.size(), new_size); + if self.is_enabled() { + self.realloc_decrease_counter(layout.size(), new_size); + } self.allocator.realloc(ptr, layout, new_size) } } #[test] fn info_mem_check() { + INFO_ALLOC.set_enable(true); INFO_ALLOC.reset_counters(); // allocate 10 bytes @@ -186,6 +206,8 @@ fn info_mem_multithread_check() { use std::thread; use std::time::Duration; + INFO_ALLOC.set_enable(true); + let mut handles = vec![]; for i in 1..4 { @@ -211,6 +233,8 @@ fn info_mem_multithread_check() { #[test] fn info_mem_negative_value() { + INFO_ALLOC.set_enable(true); + // allocate 10 bytes let mut v = Vec::::with_capacity(10); diff --git a/radix-engine/src/kernel/resources_tracker.rs b/radix-engine/src/kernel/resources_tracker.rs index f9008f1fe20..22dae0a1269 100644 --- a/radix-engine/src/kernel/resources_tracker.rs +++ b/radix-engine/src/kernel/resources_tracker.rs @@ -52,6 +52,7 @@ impl ResourcesTracker { }; ret.cpu.start_measurement(); + INFO_ALLOC.set_enable(true); INFO_ALLOC.reset_counters(); ret } @@ -60,6 +61,7 @@ impl ResourcesTracker { let cpu_cycles = self.cpu.end_measurement(); let (heap_allocations_sum, _heap_current_level, heap_peak_memory) = INFO_ALLOC.get_counters_value(); + INFO_ALLOC.set_enable(false); ResourcesUsage { heap_allocations_sum, heap_peak_memory, From 5c56b698d4bad18d33cddf3ba5e78279b9984668 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Micha=C5=82=20Strug?= Date: Fri, 20 Oct 2023 10:19:17 +0200 Subject: [PATCH 05/11] Added alloc-dump command to replay tool --- simulator/Cargo.lock | 1 + simulator/Cargo.toml | 1 + simulator/src/replay/cmd_alloc_dump.rs | 141 +++++++++++++++++++++++++ 3 files changed, 143 insertions(+) diff --git a/simulator/Cargo.lock b/simulator/Cargo.lock index f2dd589af81..fa29301cac5 100644 --- a/simulator/Cargo.lock +++ b/simulator/Cargo.lock @@ -1594,6 +1594,7 @@ dependencies = [ "quote", "radix-engine", "radix-engine-interface", + "radix-engine-profiling", "radix-engine-queries", "radix-engine-store-interface", "radix-engine-stores", diff --git a/simulator/Cargo.toml b/simulator/Cargo.toml index fe3ad17878c..fef20f9e2bc 100644 --- a/simulator/Cargo.toml +++ b/simulator/Cargo.toml @@ -13,6 +13,7 @@ radix-engine-store-interface = { path = "../radix-engine-store-interface" } radix-engine-stores = { path = "../radix-engine-stores", features = ["rocksdb"] } radix-engine-queries = { path = "../radix-engine-queries" } radix-engine-interface = { path = "../radix-engine-interface" } +radix-engine-profiling = { path = "../radix-engine-profiling", features = ["ram_metrics"] } transaction = { path = "../transaction" } flate2 = { version = "1.0.27" } tar = { version = "0.4.40" } diff --git a/simulator/src/replay/cmd_alloc_dump.rs b/simulator/src/replay/cmd_alloc_dump.rs index 2ea13558619..595f2ceae27 100644 --- a/simulator/src/replay/cmd_alloc_dump.rs +++ b/simulator/src/replay/cmd_alloc_dump.rs @@ -1,7 +1,27 @@ +use super::ledger_transaction_execution::*; +use super::txn_reader::TxnReader; use super::Error; +use crate::replay::ledger_transaction::PreparedLedgerTransactionInner; use clap::Parser; +use flate2::read::GzDecoder; +use flume; use radix_engine::types::*; +use radix_engine::vm::wasm::*; +use radix_engine::vm::ScryptoVm; +use radix_engine_interface::prelude::NetworkDefinition; +use radix_engine_profiling::info_alloc::*; +use radix_engine_store_interface::db_key_mapper::SpreadPrefixKeyMapper; +use radix_engine_store_interface::interface::CommittableSubstateDatabase; +use radix_engine_stores::rocks_db_with_merkle_tree::RocksDBWithMerkleTreeSubstateStore; +use std::fs::File; +use std::fs::OpenOptions; +use std::io::prelude::*; use std::path::PathBuf; +use std::thread; +use std::time::Duration; +use tar::Archive; +use transaction::prelude::IntentHash; +use transaction::prelude::TransactionHashBech32Encoder; /// Run transactions in archive using RocksDB and dump memory allocations #[derive(Parser, Debug)] @@ -10,6 +30,8 @@ pub struct TxnAllocDump { pub source: PathBuf, /// Path to a folder for storing state pub database_dir: PathBuf, + /// Path to the output file + pub output_file: PathBuf, /// The network to use, [mainnet | stokenet] #[clap(short, long)] @@ -21,6 +43,125 @@ pub struct TxnAllocDump { impl TxnAllocDump { pub fn run(&self) -> Result<(), Error> { + let network = match &self.network { + Some(n) => NetworkDefinition::from_str(n).map_err(Error::ParseNetworkError)?, + None => NetworkDefinition::mainnet(), + }; + + let cur_version = { + let database = RocksDBWithMerkleTreeSubstateStore::standard(self.database_dir.clone()); + let cur_version = database.get_current_version(); + if cur_version >= self.max_version.unwrap_or(u64::MAX) { + return Ok(()); + } + cur_version + }; + let to_version = self.max_version.clone(); + + let start = std::time::Instant::now(); + let (tx, rx) = flume::bounded(10); + + // txn reader + let mut txn_reader = if self.source.is_file() { + let tar_gz = File::open(&self.source).map_err(Error::IOError)?; + let tar = GzDecoder::new(tar_gz); + let archive = Archive::new(tar); + TxnReader::TransactionFile(archive) + } else if self.source.is_dir() { + TxnReader::StateManagerDatabaseDir(self.source.clone()) + } else { + return Err(Error::InvalidTransactionSource); + }; + let txn_read_thread_handle = + thread::spawn(move || txn_reader.read(cur_version, to_version, tx)); + + // txn executor + let mut database = RocksDBWithMerkleTreeSubstateStore::standard(self.database_dir.clone()); + let exists = self.output_file.exists(); + let mut output = OpenOptions::new() + .write(true) + .append(true) + .create(true) + .open(&self.output_file) + .map_err(Error::IOError)?; + if !exists { + writeln!( + output, + "TXID,Execution Cost Units,Heap allocations sum,Heap current level,Heap peak memory", + ) + .map_err(Error::IOError)?; + } + + let txn_write_thread_handle = thread::spawn(move || { + let scrypto_vm = ScryptoVm::::default(); + let iter = rx.iter(); + for tx_payload in iter { + let prepared = prepare_ledger_transaction(&tx_payload); + + INFO_ALLOC.set_enable(true); + INFO_ALLOC.reset_counters(); + + let receipt = execute_prepared_ledger_transaction( + &database, + &scrypto_vm, + &network, + &prepared, + ); + + let (heap_allocations_sum, heap_current_level, heap_peak_memory) = + INFO_ALLOC.get_counters_value(); + INFO_ALLOC.set_enable(false); + + let execution_cost_units = receipt + .fee_summary() + .map(|x| x.total_execution_cost_units_consumed.clone()); + let database_updates = receipt + .into_state_updates() + .create_database_updates::(); + database.commit(&database_updates); + if let PreparedLedgerTransactionInner::UserV1(tx) = prepared.inner { + writeln!( + output, + "{},{},{},{},{}", + TransactionHashBech32Encoder::new(&network) + .encode(&IntentHash(tx.signed_intent.intent.summary.hash)) + .unwrap(), + execution_cost_units.unwrap(), + heap_allocations_sum, + heap_current_level, + heap_peak_memory + ) + .map_err(Error::IOError)?; + } + + let new_state_root_hash = database.get_current_root_hash(); + let new_version = database.get_current_version(); + + if new_version < 1000 || new_version % 1000 == 0 { + print_progress(start.elapsed(), new_version, new_state_root_hash); + } + } + + let duration = start.elapsed(); + println!("Time elapsed: {:?}", duration); + println!("State version: {}", database.get_current_version()); + println!("State root hash: {}", database.get_current_root_hash()); + Ok::<(), Error>(()) + }); + + txn_read_thread_handle.join().unwrap()?; + txn_write_thread_handle.join().unwrap()?; + Ok(()) } } + +fn print_progress(duration: Duration, new_version: u64, new_root: Hash) { + let seconds = duration.as_secs() % 60; + let minutes = (duration.as_secs() / 60) % 60; + let hours = (duration.as_secs() / 60) / 60; + println!( + "New version: {}, {}, {:0>2}:{:0>2}:{:0>2}", + new_version, new_root, hours, minutes, seconds + ); +} From 6d15fd39f88faf487da7acc11a224aa89ea9252b Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Micha=C5=82=20Strug?= Date: Thu, 26 Oct 2023 18:38:38 +0200 Subject: [PATCH 06/11] Updated command options --- simulator/src/replay/cmd_alloc_dump.rs | 83 +++++++++++++++++++++----- 1 file changed, 68 insertions(+), 15 deletions(-) diff --git a/simulator/src/replay/cmd_alloc_dump.rs b/simulator/src/replay/cmd_alloc_dump.rs index 595f2ceae27..96e7887d5e8 100644 --- a/simulator/src/replay/cmd_alloc_dump.rs +++ b/simulator/src/replay/cmd_alloc_dump.rs @@ -20,6 +20,7 @@ use std::path::PathBuf; use std::thread; use std::time::Duration; use tar::Archive; +use transaction::prelude::HasSystemTransactionHash; use transaction::prelude::IntentHash; use transaction::prelude::TransactionHashBech32Encoder; @@ -39,6 +40,16 @@ pub struct TxnAllocDump { /// The max version to execute #[clap(short, long)] pub max_version: Option, + + /// Dump user type of transactions (enabled by default) + #[clap(short, action)] + pub dump_user_tx: bool, + /// Dump genesis type of transactions + #[clap(short)] + pub dump_genesis_tx: bool, + /// Dump round update type of transactions + #[clap(short)] + pub dump_round_update_tx: bool, } impl TxnAllocDump { @@ -58,6 +69,11 @@ impl TxnAllocDump { }; let to_version = self.max_version.clone(); + if !self.dump_user_tx && !self.dump_genesis_tx && !self.dump_round_update_tx { + println!("Nothing selected to dump."); + return Ok(()); + } + let start = std::time::Instant::now(); let (tx, rx) = flume::bounded(10); @@ -87,11 +103,16 @@ impl TxnAllocDump { if !exists { writeln!( output, - "TXID,Execution Cost Units,Heap allocations sum,Heap current level,Heap peak memory", + "TXType,TXID,Execution Cost Units,Heap allocations sum,Heap current level,Heap peak memory", ) .map_err(Error::IOError)?; } + let (dump_user, dump_genesis, dump_round) = ( + self.dump_user_tx, + self.dump_genesis_tx, + self.dump_round_update_tx, + ); let txn_write_thread_handle = thread::spawn(move || { let scrypto_vm = ScryptoVm::::default(); let iter = rx.iter(); @@ -119,25 +140,57 @@ impl TxnAllocDump { .into_state_updates() .create_database_updates::(); database.commit(&database_updates); - if let PreparedLedgerTransactionInner::UserV1(tx) = prepared.inner { - writeln!( - output, - "{},{},{},{},{}", - TransactionHashBech32Encoder::new(&network) - .encode(&IntentHash(tx.signed_intent.intent.summary.hash)) - .unwrap(), - execution_cost_units.unwrap(), - heap_allocations_sum, - heap_current_level, - heap_peak_memory - ) - .map_err(Error::IOError)?; + match prepared.inner { + PreparedLedgerTransactionInner::UserV1(tx) => { + if dump_user { + writeln!( + output, + "user,{},{},{},{},{}", + TransactionHashBech32Encoder::new(&network) + .encode(&IntentHash(tx.signed_intent.intent.summary.hash)) + .unwrap(), + execution_cost_units.unwrap(), + heap_allocations_sum, + heap_current_level, + heap_peak_memory + ) + .map_err(Error::IOError)? + } + } + PreparedLedgerTransactionInner::Genesis(tx) => { + if dump_genesis { + writeln!( + output, + "genesis,{},{},{},{},{}", + tx.system_transaction_hash().0, + execution_cost_units.unwrap_or_default(), + heap_allocations_sum, + heap_current_level, + heap_peak_memory + ) + .map_err(Error::IOError)? + } + } + PreparedLedgerTransactionInner::RoundUpdateV1(tx) => { + if dump_round { + writeln!( + output, + "round_update,{},{},{},{},{}", + tx.summary.hash, + execution_cost_units.unwrap_or_default(), + heap_allocations_sum, + heap_current_level, + heap_peak_memory + ) + .map_err(Error::IOError)? + } + } } - let new_state_root_hash = database.get_current_root_hash(); let new_version = database.get_current_version(); if new_version < 1000 || new_version % 1000 == 0 { + let new_state_root_hash = database.get_current_root_hash(); print_progress(start.elapsed(), new_version, new_state_root_hash); } } From 402d0ec16dec4499741da0ce85861e08a7663576 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Micha=C5=82=20Strug?= Date: Thu, 26 Oct 2023 19:02:00 +0200 Subject: [PATCH 07/11] Updated commands --- simulator/src/replay/cmd_alloc_dump.rs | 14 +++++++------- 1 file changed, 7 insertions(+), 7 deletions(-) diff --git a/simulator/src/replay/cmd_alloc_dump.rs b/simulator/src/replay/cmd_alloc_dump.rs index 96e7887d5e8..4e134b3fd5c 100644 --- a/simulator/src/replay/cmd_alloc_dump.rs +++ b/simulator/src/replay/cmd_alloc_dump.rs @@ -41,14 +41,14 @@ pub struct TxnAllocDump { #[clap(short, long)] pub max_version: Option, - /// Dump user type of transactions (enabled by default) - #[clap(short, action)] - pub dump_user_tx: bool, + /// Ignore dump of user type of transactions + #[clap(long)] + pub ignore_dump_user_tx: bool, /// Dump genesis type of transactions - #[clap(short)] + #[clap(short = 'g', long)] pub dump_genesis_tx: bool, /// Dump round update type of transactions - #[clap(short)] + #[clap(short = 'r', long)] pub dump_round_update_tx: bool, } @@ -69,7 +69,7 @@ impl TxnAllocDump { }; let to_version = self.max_version.clone(); - if !self.dump_user_tx && !self.dump_genesis_tx && !self.dump_round_update_tx { + if self.ignore_dump_user_tx && !self.dump_genesis_tx && !self.dump_round_update_tx { println!("Nothing selected to dump."); return Ok(()); } @@ -109,7 +109,7 @@ impl TxnAllocDump { } let (dump_user, dump_genesis, dump_round) = ( - self.dump_user_tx, + !self.ignore_dump_user_tx, self.dump_genesis_tx, self.dump_round_update_tx, ); From 97db48481320f3222277204d7e6c3d47e5041abf Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Micha=C5=82=20Strug?= Date: Fri, 27 Oct 2023 16:14:19 +0200 Subject: [PATCH 08/11] Updated realloc handling --- radix-engine-profiling/src/info_alloc/mod.rs | 25 ++++---------------- 1 file changed, 5 insertions(+), 20 deletions(-) diff --git a/radix-engine-profiling/src/info_alloc/mod.rs b/radix-engine-profiling/src/info_alloc/mod.rs index 42c612d845d..9bb865064ba 100644 --- a/radix-engine-profiling/src/info_alloc/mod.rs +++ b/radix-engine-profiling/src/info_alloc/mod.rs @@ -89,25 +89,6 @@ impl InfoAlloc { }); } - #[inline] - fn realloc_decrease_counter(&self, old_size: usize, new_size: usize) { - let old_size: isize = old_size.try_into().expect("Value out of range"); - let new_size: isize = new_size.try_into().expect("Value out of range"); - - INFO_ALLOC_DATA_TLS.with(|val| { - val.current_level - .fetch_sub(old_size - new_size, Ordering::AcqRel); - - if new_size > old_size { - val.sum_counter - .fetch_add(new_size - old_size, Ordering::AcqRel); - - let current_level = val.current_level.load(Ordering::Acquire); - val.max_level.fetch_max(current_level, Ordering::AcqRel); - } - }); - } - /// Returns current counters values: sum fo all allocations, current allocation level, peak allocation level /// Counters can have negative values because of memory allocations before calling to reset_counters() function /// and deallocating them during measurements. In that case counter value is set to 0. @@ -139,7 +120,11 @@ unsafe impl GlobalAlloc for InfoAlloc { unsafe fn realloc(&self, ptr: *mut u8, layout: Layout, new_size: usize) -> *mut u8 { if self.is_enabled() { - self.realloc_decrease_counter(layout.size(), new_size); + if new_size > layout.size() { + self.increase_counters(new_size - layout.size()); + } else { + self.decrease_counters(layout.size() - new_size); + } } self.allocator.realloc(ptr, layout, new_size) } From 9e98aab340047b73cb081c4e4a5eb37557943269 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Micha=C5=82=20Strug?= Date: Fri, 27 Oct 2023 16:14:50 +0200 Subject: [PATCH 09/11] Moved test to sub-module --- radix-engine-profiling/src/info_alloc/mod.rs | 185 ++++++++++--------- 1 file changed, 95 insertions(+), 90 deletions(-) diff --git a/radix-engine-profiling/src/info_alloc/mod.rs b/radix-engine-profiling/src/info_alloc/mod.rs index 9bb865064ba..d7d3dfb51d2 100644 --- a/radix-engine-profiling/src/info_alloc/mod.rs +++ b/radix-engine-profiling/src/info_alloc/mod.rs @@ -130,107 +130,112 @@ unsafe impl GlobalAlloc for InfoAlloc { } } -#[test] -fn info_mem_check() { - INFO_ALLOC.set_enable(true); - INFO_ALLOC.reset_counters(); - - // allocate 10 bytes - let mut v = Vec::::with_capacity(10); - let (sum, current, peak) = INFO_ALLOC.get_counters_value(); - assert_eq!((sum, current, peak), (10, 10, 10)); - - // no allocation/deallocation occurs - v.push(10); - let (sum, current, peak) = INFO_ALLOC.get_counters_value(); - assert_eq!((sum, current, peak), (10, 10, 10)); - - // deallocate 9 bytes - v.shrink_to_fit(); - let (sum, current, peak) = INFO_ALLOC.get_counters_value(); - assert_eq!((sum, current, peak), (10, 1, 10)); - - // allocate 3 bytes - let _a = Box::new(1u8); - let _b = Box::new(1u8); - let _c = Box::new(1u8); - let (sum, current, peak) = INFO_ALLOC.get_counters_value(); - assert_eq!((sum, current, peak), (13, 4, 10)); - - // allocate 10 bytes - let mut v = Vec::::with_capacity(10); - let (sum, current, peak) = INFO_ALLOC.get_counters_value(); - assert_eq!((sum, current, peak), (23, 14, 14)); - - // no allocation/deallocation occurs - v.push(10); - - // deallocate 9 bytes - v.shrink_to_fit(); - let (sum, current, peak) = INFO_ALLOC.get_counters_value(); - assert_eq!((sum, current, peak), (23, 5, 14)); - - // allocate 10 bytes - let mut v = Vec::::with_capacity(10); - let (sum, current, peak) = INFO_ALLOC.get_counters_value(); - assert_eq!((sum, current, peak), (33, 15, 15)); - - // allocate 10 bytes (by default capacity of vector is extended by 2) - v.extend([1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11]); - let (sum, current, peak) = INFO_ALLOC.get_counters_value(); - assert_eq!((sum, current, peak), (43, 25, 25)); - - // deallocate 9 bytes - v.shrink_to_fit(); - let (sum, current, peak) = INFO_ALLOC.get_counters_value(); - assert_eq!((sum, current, peak), (43, 16, 25)); -} +#[cfg(test)] +mod tests { + use super::*; + + #[test] + fn info_mem_check() { + INFO_ALLOC.set_enable(true); + INFO_ALLOC.reset_counters(); + + // allocate 10 bytes + let mut v = Vec::::with_capacity(10); + let (sum, current, peak) = INFO_ALLOC.get_counters_value(); + assert_eq!((sum, current, peak), (10, 10, 10)); + + // no allocation/deallocation occurs + v.push(10); + let (sum, current, peak) = INFO_ALLOC.get_counters_value(); + assert_eq!((sum, current, peak), (10, 10, 10)); + + // deallocate 9 bytes + v.shrink_to_fit(); + let (sum, current, peak) = INFO_ALLOC.get_counters_value(); + assert_eq!((sum, current, peak), (10, 1, 10)); + + // allocate 3 bytes + let _a = Box::new(1u8); + let _b = Box::new(1u8); + let _c = Box::new(1u8); + let (sum, current, peak) = INFO_ALLOC.get_counters_value(); + assert_eq!((sum, current, peak), (13, 4, 10)); + + // allocate 10 bytes + let mut v = Vec::::with_capacity(10); + let (sum, current, peak) = INFO_ALLOC.get_counters_value(); + assert_eq!((sum, current, peak), (23, 14, 14)); + + // no allocation/deallocation occurs + v.push(10); + + // deallocate 9 bytes + v.shrink_to_fit(); + let (sum, current, peak) = INFO_ALLOC.get_counters_value(); + assert_eq!((sum, current, peak), (23, 5, 14)); + + // allocate 10 bytes + let mut v = Vec::::with_capacity(10); + let (sum, current, peak) = INFO_ALLOC.get_counters_value(); + assert_eq!((sum, current, peak), (33, 15, 15)); + + // allocate 10 bytes (by default capacity of vector is extended by 2) + v.extend([1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11]); + let (sum, current, peak) = INFO_ALLOC.get_counters_value(); + assert_eq!((sum, current, peak), (43, 25, 25)); + + // deallocate 9 bytes + v.shrink_to_fit(); + let (sum, current, peak) = INFO_ALLOC.get_counters_value(); + assert_eq!((sum, current, peak), (43, 16, 25)); + } -#[test] -fn info_mem_multithread_check() { - use std::thread; - use std::time::Duration; + #[test] + fn info_mem_multithread_check() { + use std::thread; + use std::time::Duration; - INFO_ALLOC.set_enable(true); + INFO_ALLOC.set_enable(true); - let mut handles = vec![]; + let mut handles = vec![]; - for i in 1..4 { - let handle = thread::spawn(move || { - INFO_ALLOC.reset_counters(); + for i in 1..4 { + let handle = thread::spawn(move || { + INFO_ALLOC.reset_counters(); - let _v = Vec::::with_capacity(i); - // causes context to switch to the next thread - // so we can ensure that counters are properly managed - // using local thread store - thread::sleep(Duration::from_millis(1)); + let _v = Vec::::with_capacity(i); + // causes context to switch to the next thread + // so we can ensure that counters are properly managed + // using local thread store + thread::sleep(Duration::from_millis(1)); - let (sum, current, peak) = INFO_ALLOC.get_counters_value(); - assert_eq!((sum, current, peak), (i, i, i)); - }); - handles.push(handle); - } + let (sum, current, peak) = INFO_ALLOC.get_counters_value(); + assert_eq!((sum, current, peak), (i, i, i)); + }); + handles.push(handle); + } - for handle in handles { - handle.join().unwrap(); + for handle in handles { + handle.join().unwrap(); + } } -} -#[test] -fn info_mem_negative_value() { - INFO_ALLOC.set_enable(true); + #[test] + fn info_mem_negative_value() { + INFO_ALLOC.set_enable(true); - // allocate 10 bytes - let mut v = Vec::::with_capacity(10); + // allocate 10 bytes + let mut v = Vec::::with_capacity(10); - INFO_ALLOC.reset_counters(); + INFO_ALLOC.reset_counters(); - // realloc to 1 byte, this causes alloc counter to get negative value - // because reset counters was called after 10 bytes allocation: 0 - 9 = -9 - v.push(10); - v.shrink_to_fit(); + // realloc to 1 byte, this causes alloc counter to get negative value + // because reset counters was called after 10 bytes allocation: 0 - 9 = -9 + v.push(10); + v.shrink_to_fit(); - let (sum, current, peak) = INFO_ALLOC.get_counters_value(); - // negative values are not returned - assert_eq!((sum, current, peak), (0, 0, 0)); + let (sum, current, peak) = INFO_ALLOC.get_counters_value(); + // negative values are not returned + assert_eq!((sum, current, peak), (0, 0, 0)); + } } From d04e82e8829be6851cbad07289459bba00a88693 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Micha=C5=82=20Strug?= Date: Fri, 27 Oct 2023 16:28:44 +0200 Subject: [PATCH 10/11] Changed counters type to non-atomic types --- radix-engine-profiling/src/info_alloc/mod.rs | 47 +++++++++++--------- 1 file changed, 25 insertions(+), 22 deletions(-) diff --git a/radix-engine-profiling/src/info_alloc/mod.rs b/radix-engine-profiling/src/info_alloc/mod.rs index d7d3dfb51d2..47bd8a7fd4b 100644 --- a/radix-engine-profiling/src/info_alloc/mod.rs +++ b/radix-engine-profiling/src/info_alloc/mod.rs @@ -1,13 +1,14 @@ use std::{ alloc::{GlobalAlloc, Layout, System}, - sync::atomic::{AtomicBool, AtomicIsize, Ordering}, + cell::RefCell, + sync::atomic::{AtomicBool, Ordering}, }; #[global_allocator] pub static INFO_ALLOC: InfoAlloc = InfoAlloc::new(System); thread_local! { - static INFO_ALLOC_DATA_TLS: InfoAllocData = InfoAllocData::new(); + static INFO_ALLOC_DATA_TLS: RefCell = RefCell::new(InfoAllocData::new()); } /// Heap allocations tracker @@ -24,19 +25,19 @@ pub struct InfoAlloc { /// Allocation data stored in Thread Local Store (separate data for each thread) pub struct InfoAllocData { /// Sum of bytes allocated during measurements (for reallocations only additional memory is counted, no dealocation is counted) - sum_counter: AtomicIsize, + sum_counter: isize, /// Current level of allocated bytes (allocation and deallocation are counted, incl. reallocation) - current_level: AtomicIsize, + current_level: isize, /// Maximum level (peak) of allocated bytes (the max of this field and current_level) - max_level: AtomicIsize, + max_level: isize, } impl InfoAllocData { fn new() -> Self { Self { - sum_counter: AtomicIsize::new(0), - current_level: AtomicIsize::new(0), - max_level: AtomicIsize::new(0), + sum_counter: 0, + current_level: 0, + max_level: 0, } } } @@ -60,9 +61,10 @@ impl InfoAlloc { /// Resets internal counters. Usually used to start measurement. pub fn reset_counters(&self) { INFO_ALLOC_DATA_TLS.with(|val| { - val.sum_counter.store(0, Ordering::Release); - val.current_level.store(0, Ordering::Release); - val.max_level.store(0, Ordering::Release); + let mut val = val.borrow_mut(); + val.sum_counter = 0; + val.current_level = 0; + val.max_level = 0; }); } @@ -71,21 +73,21 @@ impl InfoAlloc { let ivalue: isize = value.try_into().expect("Value out of range"); INFO_ALLOC_DATA_TLS.with(|val| { - val.sum_counter.fetch_add(ivalue, Ordering::AcqRel); + let mut val = val.borrow_mut(); - let old_value = val.current_level.fetch_add(ivalue, Ordering::AcqRel); - val.max_level - .fetch_max(old_value + ivalue, Ordering::AcqRel); + val.sum_counter += ivalue; + + let old_value = val.current_level; + val.current_level += ivalue; + val.max_level = val.max_level.max(old_value + ivalue); }); } #[inline] fn decrease_counters(&self, value: usize) { INFO_ALLOC_DATA_TLS.with(|val| { - val.current_level.fetch_sub( - value.try_into().expect("Value out of range"), - Ordering::AcqRel, - ) + val.borrow_mut().current_level -= + TryInto::::try_into(value).expect("Value out of range") }); } @@ -94,10 +96,11 @@ impl InfoAlloc { /// and deallocating them during measurements. In that case counter value is set to 0. pub fn get_counters_value(&self) -> (usize, usize, usize) { INFO_ALLOC_DATA_TLS.with(|val| { + let val = val.borrow_mut(); ( - val.sum_counter.load(Ordering::Acquire).max(0) as usize, - val.current_level.load(Ordering::Acquire).max(0) as usize, - val.max_level.load(Ordering::Acquire).max(0) as usize, + val.sum_counter.max(0) as usize, + val.current_level.max(0) as usize, + val.max_level.max(0) as usize, ) }) } From fa0f32f25f2b970c3dd4badf6394cf0eb78c1d7b Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Micha=C5=82=20Strug?= Date: Fri, 27 Oct 2023 16:32:15 +0200 Subject: [PATCH 11/11] Renamed command parameters --- simulator/src/replay/cmd_alloc_dump.rs | 23 +++++++++++++---------- 1 file changed, 13 insertions(+), 10 deletions(-) diff --git a/simulator/src/replay/cmd_alloc_dump.rs b/simulator/src/replay/cmd_alloc_dump.rs index 4e134b3fd5c..277a640aaf5 100644 --- a/simulator/src/replay/cmd_alloc_dump.rs +++ b/simulator/src/replay/cmd_alloc_dump.rs @@ -41,15 +41,15 @@ pub struct TxnAllocDump { #[clap(short, long)] pub max_version: Option, - /// Ignore dump of user type of transactions + /// Exclude user type of transactions from output data #[clap(long)] - pub ignore_dump_user_tx: bool, - /// Dump genesis type of transactions + pub exclude_user_transaction: bool, + /// Include genesis type of transactions in output data #[clap(short = 'g', long)] - pub dump_genesis_tx: bool, - /// Dump round update type of transactions + pub include_generic_transaction: bool, + /// Include round update type of transactions in output data #[clap(short = 'r', long)] - pub dump_round_update_tx: bool, + pub include_round_update_transaction: bool, } impl TxnAllocDump { @@ -69,7 +69,10 @@ impl TxnAllocDump { }; let to_version = self.max_version.clone(); - if self.ignore_dump_user_tx && !self.dump_genesis_tx && !self.dump_round_update_tx { + if self.exclude_user_transaction + && !self.include_generic_transaction + && !self.include_round_update_transaction + { println!("Nothing selected to dump."); return Ok(()); } @@ -109,9 +112,9 @@ impl TxnAllocDump { } let (dump_user, dump_genesis, dump_round) = ( - !self.ignore_dump_user_tx, - self.dump_genesis_tx, - self.dump_round_update_tx, + !self.exclude_user_transaction, + self.include_generic_transaction, + self.include_round_update_transaction, ); let txn_write_thread_handle = thread::spawn(move || { let scrypto_vm = ScryptoVm::::default();