Skip to content

Commit

Permalink
testing/gas profiling for it
Browse files Browse the repository at this point in the history
  • Loading branch information
igor-aptos committed Oct 4, 2024
1 parent 943e298 commit b1a2e70
Show file tree
Hide file tree
Showing 11 changed files with 373 additions and 72 deletions.
20 changes: 11 additions & 9 deletions aptos-move/aptos-gas-calibration/src/measurements.rs
Original file line number Diff line number Diff line change
Expand Up @@ -162,15 +162,17 @@ fn compile_and_run_samples_ir(
.equation_names
.push(format!("{}::{}", &identifier, func_identifier.0));

let elapsed = executor.exec_func_record_running_time(
&module_id,
&func_identifier.0,
vec![],
func_identifier.1.clone(),
iterations,
ExecFuncTimerDynamicArgs::NoArgs,
GasMeterType::UnmeteredGasMeter,
);
let elapsed = executor
.exec_func_record_running_time(
&module_id,
&func_identifier.0,
vec![],
func_identifier.1.clone(),
iterations,
ExecFuncTimerDynamicArgs::NoArgs,
GasMeterType::UnmeteredGasMeter,
)
.elapsed_micros;
gas_measurement.regular_meter.push(elapsed);

// record with abstract gas meter
Expand Down
20 changes: 11 additions & 9 deletions aptos-move/aptos-gas-calibration/src/measurements_helpers.rs
Original file line number Diff line number Diff line change
Expand Up @@ -94,15 +94,17 @@ pub fn execute_user_txn(
iterations: u64,
args: Vec<Vec<u8>>,
) -> u128 {
let elapsed = executor.exec_func_record_running_time(
module_name,
function_name,
vec![],
args,
iterations,
ExecFuncTimerDynamicArgs::NoArgs,
GasMeterType::UnmeteredGasMeter,
);
let elapsed = executor
.exec_func_record_running_time(
module_name,
function_name,
vec![],
args,
iterations,
ExecFuncTimerDynamicArgs::NoArgs,
GasMeterType::UnmeteredGasMeter,
)
.elapsed_micros;
println!("running time (microseconds): {}", elapsed);
elapsed
}
Expand Down
20 changes: 11 additions & 9 deletions aptos-move/aptos-vm-benchmarks/src/helper.rs
Original file line number Diff line number Diff line change
Expand Up @@ -64,15 +64,17 @@ pub fn execute_module_txn(

// sign user transaction and only records the body of the transaction
pub fn execute_user_txn(executor: &mut FakeExecutor, module_name: &ModuleId, function_name: &str) {
let elapsed = executor.exec_func_record_running_time(
module_name,
function_name,
vec![],
vec![],
10,
ExecFuncTimerDynamicArgs::NoArgs,
GasMeterType::UnmeteredGasMeter,
);
let elapsed = executor
.exec_func_record_running_time(
module_name,
function_name,
vec![],
vec![],
10,
ExecFuncTimerDynamicArgs::NoArgs,
GasMeterType::UnmeteredGasMeter,
)
.elapsed_micros;
println!("running time (microseconds): {}", elapsed);
}

Expand Down
124 changes: 102 additions & 22 deletions aptos-move/e2e-benchmark/src/main.rs
Original file line number Diff line number Diff line change
Expand Up @@ -3,7 +3,7 @@

use aptos_language_e2e_tests::{
account::Account,
executor::{ExecFuncTimerDynamicArgs, FakeExecutor, GasMeterType},
executor::{ExecFuncTimerDynamicArgs, FakeExecutor, GasMeterType, TimeAndGas},
};
use aptos_transaction_generator_lib::{
publishing::{
Expand Down Expand Up @@ -46,7 +46,7 @@ fn execute_and_time_entry_point(
publisher_address: &AccountAddress,
executor: &mut FakeExecutor,
iterations: u64,
) -> u128 {
) -> TimeAndGas {
let mut rng = StdRng::seed_from_u64(14);
let entry_fun = entry_point
.create_payload(
Expand Down Expand Up @@ -100,7 +100,7 @@ fn main() {
loop_type: LoopType::Arithmetic,
}),
// This is a cheap bcs (serializing vec<u8>), so not representative of what BCS native call should cost.
// (, EntryPoints::Loop { loop_count: Some(1000), loop_type: LoopType::BCS { len: 1024 }}),
// (, EntryPoints::Loop { loop_count: Some(1000), loop_type: LoopType::BcsToBytes { len: 1024 }}),
(125, EntryPoints::CreateObjects {
num_objects: 10,
object_payload_size: 0,
Expand All @@ -117,9 +117,9 @@ fn main() {
num_objects: 100,
object_payload_size: 10 * 1024,
}),
(65, EntryPoints::InitializeVectorPicture { length: 40 }),
(14, EntryPoints::VectorPicture { length: 40 }),
(14, EntryPoints::VectorPictureRead { length: 40 }),
(160, EntryPoints::InitializeVectorPicture { length: 128 }),
(34, EntryPoints::VectorPicture { length: 128 }),
(34, EntryPoints::VectorPictureRead { length: 128 }),
(29000, EntryPoints::InitializeVectorPicture {
length: 30 * 1024,
}),
Expand All @@ -144,14 +144,83 @@ fn main() {
(401, EntryPoints::TokenV2AmbassadorMint { numbered: true }),
(467, EntryPoints::LiquidityPoolSwap { is_stable: true }),
(415, EntryPoints::LiquidityPoolSwap { is_stable: false }),
(146, EntryPoints::CoinInitAndMint),
(154, EntryPoints::FungibleAssetMint),
(23, EntryPoints::IncGlobalMilestoneAggV2 {
milestone_every: 1,
}),
(12, EntryPoints::IncGlobalMilestoneAggV2 {
milestone_every: 2,
}),
(6871, EntryPoints::EmitEvents { count: 1000 }),
// long vectors with small elements
(15890, EntryPoints::VectorSplitOffAppend {
// baseline, only vector creation
vec_len: 3000,
element_len: 1,
index: 0,
repeats: 0,
}),
(38047, EntryPoints::VectorSplitOffAppend {
vec_len: 3000,
element_len: 1,
index: 100,
repeats: 1000,
}),
(25923, EntryPoints::VectorSplitOffAppend {
vec_len: 3000,
element_len: 1,
index: 2990,
repeats: 1000,
}),
(35590, EntryPoints::VectorRemoveInsert {
vec_len: 3000,
element_len: 1,
index: 100,
repeats: 1000,
}),
(28141, EntryPoints::VectorRemoveInsert {
vec_len: 3000,
element_len: 1,
index: 2998,
repeats: 1000,
}),
(53500, EntryPoints::VectorRangeMove {
vec_len: 3000,
element_len: 1,
index: 1000,
move_len: 500,
repeats: 1000,
}),
// vectors with large elements
(654, EntryPoints::VectorSplitOffAppend {
// baseline, only vector creation
vec_len: 100,
element_len: 100,
index: 0,
repeats: 0,
}),
(11147, EntryPoints::VectorSplitOffAppend {
vec_len: 100,
element_len: 100,
index: 10,
repeats: 1000,
}),
(5545, EntryPoints::VectorRangeMove {
vec_len: 100,
element_len: 100,
index: 50,
move_len: 10,
repeats: 1000,
}),
];

let mut failures = Vec::new();
let mut json_lines = Vec::new();

println!(
"{:>15} {:>15} {:>15} entry point",
"wall time (us)", "expected (us)", "diff(- is impr)"
"{:>13} {:>13} {:>13}{:>13} {:>13} {:>13} entry point",
"walltime(us)", "expected(us)", "dif(- is impr)", "gas/s", "exe gas", "io gas",
);

for (index, (expected_time, entry_point)) in entry_points.into_iter().enumerate() {
Expand All @@ -166,7 +235,7 @@ fn main() {
0,
package.publish_transaction_payload(),
);
println!("Published package: {:?}", entry_point.package_name());
// println!("Published package: {:?}", entry_point.package_name());
if let Some(init_entry_point) = entry_point.initialize_entry_point() {
execute_txn(
&mut executor,
Expand All @@ -178,13 +247,13 @@ fn main() {
Some(publisher.address()),
),
);
println!(
"Executed init entry point: {:?}",
entry_point.initialize_entry_point()
);
// println!(
// "Executed init entry point: {:?}",
// entry_point.initialize_entry_point()
// );
}

let elapsed_micros = execute_and_time_entry_point(
let measurement = execute_and_time_entry_point(
&entry_point,
&package,
publisher.address(),
Expand All @@ -197,33 +266,44 @@ fn main() {
100
},
);
let diff = (elapsed_micros as f32 - expected_time as f32) / (expected_time as f32) * 100.0;
let diff = (measurement.elapsed_micros as f32 - expected_time as f32)
/ (expected_time as f32)
* 100.0;
println!(
"{:15} {:15} {:14.1}% {:?}",
elapsed_micros, expected_time, diff, entry_point
"{:13} {:13} {:12.1}% {:13} {:13} {:13} {:?}",
measurement.elapsed_micros,
expected_time,
diff,
(measurement.execution_gas + measurement.io_gas) as u128 / measurement.elapsed_micros,
measurement.execution_gas,
measurement.io_gas,
entry_point
);

json_lines.push(json!({
"grep": "grep_json_aptos_move_vm_perf",
"transaction_type": format!("{:?}", entry_point),
"wall_time_us": elapsed_micros,
"wall_time_us": measurement.elapsed_micros,
"gps": (measurement.execution_gas + measurement.io_gas) as u128 / measurement.elapsed_micros,
"execution_gas": measurement.execution_gas,
"io_gas": measurement.io_gas,
"expected_wall_time_us": expected_time,
"test_index": index,
}));

if elapsed_micros as f32
if measurement.elapsed_micros as f32
> expected_time as f32 * (1.0 + ALLOWED_REGRESSION) + ABSOLUTE_BUFFER_US
{
failures.push(format!(
"Performance regression detected: {}us, expected: {}us, diff: {}%, for {:?}",
elapsed_micros, expected_time, diff, entry_point
measurement.elapsed_micros, expected_time, diff, entry_point
));
} else if elapsed_micros as f32 + ABSOLUTE_BUFFER_US
} else if measurement.elapsed_micros as f32 + ABSOLUTE_BUFFER_US
< expected_time as f32 * (1.0 - ALLOWED_IMPROVEMENT)
{
failures.push(format!(
"Performance improvement detected: {}us, expected {}us, diff: {}%, for {:?}. You need to adjust expected time!",
elapsed_micros, expected_time, diff, entry_point
measurement.elapsed_micros, expected_time, diff, entry_point
));
}
}
Expand Down
31 changes: 25 additions & 6 deletions aptos-move/e2e-tests/src/executor.rs
Original file line number Diff line number Diff line change
Expand Up @@ -18,7 +18,7 @@ use aptos_block_executor::txn_commit_hook::NoOpTransactionCommitHook;
use aptos_crypto::HashValue;
use aptos_framework::ReleaseBundle;
use aptos_gas_algebra::DynamicExpression;
use aptos_gas_meter::{StandardGasAlgebra, StandardGasMeter};
use aptos_gas_meter::{AptosGasMeter, GasAlgebra, StandardGasAlgebra, StandardGasMeter};
use aptos_gas_profiling::{GasProfiler, TransactionGasLog};
use aptos_gas_schedule::{AptosGasParameters, InitialGasSchedule, LATEST_GAS_FEATURE_VERSION};
use aptos_keygen::KeyGen;
Expand Down Expand Up @@ -134,6 +134,13 @@ pub enum GasMeterType {
UnmeteredGasMeter,
}

#[derive(Clone)]
pub struct TimeAndGas {
pub elapsed_micros: u128,
pub execution_gas: u64,
pub io_gas: u64,
}

pub enum ExecFuncTimerDynamicArgs {
NoArgs,
DistinctSigners,
Expand Down Expand Up @@ -944,7 +951,7 @@ impl FakeExecutor {
iterations: u64,
dynamic_args: ExecFuncTimerDynamicArgs,
gas_meter_type: GasMeterType,
) -> u128 {
) -> TimeAndGas {
let mut extra_accounts = match &dynamic_args {
ExecFuncTimerDynamicArgs::DistinctSigners
| ExecFuncTimerDynamicArgs::DistinctSignersAndFixed(_) => (0..iterations)
Expand Down Expand Up @@ -1041,18 +1048,30 @@ impl FakeExecutor {
println!("Shouldn't error, but ignoring for now... {}", err);
}
}
times.push(elapsed.as_micros());
times.push(TimeAndGas {
elapsed_micros: elapsed.as_micros(),
execution_gas: regular
.as_ref()
.map_or(0, |gas| gas.algebra().execution_gas_used().into()),
io_gas: regular
.as_ref()
.map_or(0, |gas| gas.algebra().io_gas_used().into()),
});
i += 1;
}

// take median of all running time iterations as a more robust measurement
times.sort();
times.sort_by_key(|v| v.elapsed_micros);
let length = times.len();
let mid = length / 2;
let mut running_time = times[mid];
let mut running_time = times[mid].clone();

if length % 2 == 0 {
running_time = (times[mid - 1] + times[mid]) / 2;
running_time = TimeAndGas {
elapsed_micros: (times[mid - 1].elapsed_micros + times[mid].elapsed_micros) / 2,
execution_gas: (times[mid - 1].execution_gas + times[mid].execution_gas) / 2,
io_gas: (times[mid - 1].io_gas + times[mid].io_gas) / 2,
};
}

running_time
Expand Down
2 changes: 1 addition & 1 deletion aptos-move/framework/aptos-stdlib/doc/big_vector.md
Original file line number Diff line number Diff line change
Expand Up @@ -502,7 +502,7 @@ Aborts if <code>i</code> is out of bounds.
<b>if</b> (self.end_index == i) {
<b>return</b> last_val
};
// because the lack of mem::swap, here we swap remove the requested value from the bucket
// because the lack of <a href="../../move-stdlib/doc/mem.md#0x1_mem_swap">mem::swap</a>, here we swap remove the requested value from the bucket
// and append the last_val <b>to</b> the bucket then swap the last bucket val back
<b>let</b> bucket = <a href="table_with_length.md#0x1_table_with_length_borrow_mut">table_with_length::borrow_mut</a>(&<b>mut</b> self.buckets, i / self.bucket_size);
<b>let</b> bucket_len = <a href="../../move-stdlib/doc/vector.md#0x1_vector_length">vector::length</a>(bucket);
Expand Down
18 changes: 18 additions & 0 deletions crates/transaction-generator-lib/src/args.rs
Original file line number Diff line number Diff line change
Expand Up @@ -44,6 +44,8 @@ pub enum TransactionTypeArg {
CreateObjects100,
CreateObjects100WithPayload10k,
CreateObjectsConflict100WithPayload10k,
VectorSplitOffAppendLen3000Size1,
VectorRemoveInsertLen3000Size1,
ResourceGroupsGlobalWriteTag1KB,
ResourceGroupsGlobalWriteAndReadTag1KB,
ResourceGroupsSenderWriteTag1KB,
Expand Down Expand Up @@ -215,6 +217,22 @@ impl TransactionTypeArg {
object_payload_size: 10 * 1024,
})
},
TransactionTypeArg::VectorSplitOffAppendLen3000Size1 => {
call_custom_module(EntryPoints::VectorSplitOffAppend {
vec_len: 3000,
element_len: 1,
index: 100,
repeats: 1000,
})
},
TransactionTypeArg::VectorRemoveInsertLen3000Size1 => {
call_custom_module(EntryPoints::VectorRemoveInsert {
vec_len: 3000,
element_len: 1,
index: 100,
repeats: 1000,
})
},
TransactionTypeArg::ResourceGroupsGlobalWriteTag1KB => {
call_custom_module(EntryPoints::ResourceGroupsGlobalWriteTag {
string_length: 1024,
Expand Down
Loading

0 comments on commit b1a2e70

Please sign in to comment.