chore(avm): basic stat collection

[fcarreiro]

Colelcts and prints stats for avm_prove when BB is compiled with in RelWithAssert mode or AVM_TRACK_STATS is defined.

Has no impact otherwise.

------- STATS -------
compute_logderivative_inverse/incl_main_tag_err_ms: 0
compute_logderivative_inverse/incl_mem_tag_err_ms: 0
compute_logderivative_inverse/kernel_output_lookup_ms: 0
compute_logderivative_inverse/lookup_byte_lengths_ms: 0
compute_logderivative_inverse/lookup_byte_operations_ms: 0
compute_logderivative_inverse/lookup_div_u16_0_ms: 0
compute_logderivative_inverse/lookup_div_u16_1_ms: 0
compute_logderivative_inverse/lookup_div_u16_2_ms: 0
compute_logderivative_inverse/lookup_div_u16_3_ms: 0
compute_logderivative_inverse/lookup_div_u16_4_ms: 0
compute_logderivative_inverse/lookup_div_u16_5_ms: 0
compute_logderivative_inverse/lookup_div_u16_6_ms: 0
compute_logderivative_inverse/lookup_div_u16_7_ms: 0
compute_logderivative_inverse/lookup_into_kernel_ms: 0
compute_logderivative_inverse/lookup_mem_rng_chk_hi_ms: 0
compute_logderivative_inverse/lookup_mem_rng_chk_lo_ms: 0
compute_logderivative_inverse/lookup_mem_rng_chk_mid_ms: 0
compute_logderivative_inverse/lookup_opcode_gas_ms: 0
compute_logderivative_inverse/lookup_pow_2_0_ms: 0
compute_logderivative_inverse/lookup_pow_2_1_ms: 0
compute_logderivative_inverse/lookup_u16_0_ms: 0
compute_logderivative_inverse/lookup_u16_10_ms: 0
compute_logderivative_inverse/lookup_u16_11_ms: 0
compute_logderivative_inverse/lookup_u16_12_ms: 0
compute_logderivative_inverse/lookup_u16_13_ms: 0
compute_logderivative_inverse/lookup_u16_14_ms: 0
compute_logderivative_inverse/lookup_u16_1_ms: 0
compute_logderivative_inverse/lookup_u16_2_ms: 0
compute_logderivative_inverse/lookup_u16_3_ms: 0
compute_logderivative_inverse/lookup_u16_4_ms: 0
compute_logderivative_inverse/lookup_u16_5_ms: 0
compute_logderivative_inverse/lookup_u16_6_ms: 0
compute_logderivative_inverse/lookup_u16_7_ms: 0
compute_logderivative_inverse/lookup_u16_8_ms: 0
compute_logderivative_inverse/lookup_u16_9_ms: 0
compute_logderivative_inverse/lookup_u8_0_ms: 0
compute_logderivative_inverse/lookup_u8_1_ms: 0
compute_logderivative_inverse/perm_main_alu_ms: 1
compute_logderivative_inverse/perm_main_bin_ms: 0
compute_logderivative_inverse/perm_main_conv_ms: 0
compute_logderivative_inverse/perm_main_mem_a_ms: 0
compute_logderivative_inverse/perm_main_mem_b_ms: 0
compute_logderivative_inverse/perm_main_mem_c_ms: 0
compute_logderivative_inverse/perm_main_mem_d_ms: 0
compute_logderivative_inverse/perm_main_mem_ind_addr_a_ms: 0
compute_logderivative_inverse/perm_main_mem_ind_addr_b_ms: 0
compute_logderivative_inverse/perm_main_mem_ind_addr_c_ms: 0
compute_logderivative_inverse/perm_main_mem_ind_addr_d_ms: 0
compute_logderivative_inverse/perm_main_pedersen_ms: 0
compute_logderivative_inverse/perm_main_pos2_perm_ms: 0
compute_logderivative_inverse/range_check_da_gas_hi_ms: 0
compute_logderivative_inverse/range_check_da_gas_lo_ms: 0
compute_logderivative_inverse/range_check_l2_gas_hi_ms: 0
compute_logderivative_inverse/range_check_l2_gas_lo_ms: 0
proving/log_derivative_inverse_round_ms: 82
proving/pcs_rounds_ms: 158
proving/relation_check_rounds_ms: 66
proving/wire_commitments_round_ms: 193

[fcarreiro]

• #7299
• #7283 👈
• master

This stack of pull requests is managed by Graphite. Learn more about stacking.

Join @fcarreiro and the rest of your teammates on Graphite

[AztecBot]

Benchmark results

Metrics with a significant change:

• avm_simulation_time_ms (Token:mint_public): 72.3 (+34%)
• protocol_circuit_witness_generation_time_in_ms (private-kernel-init): 452 (+18%)
• protocol_circuit_witness_generation_time_in_ms (private-kernel-inner): 895 (+19%)

Detailed results

All benchmarks are run on txs on the `Benchmarking` contract on the repository. Each tx consists of a batch call to `create_note` and `increment_balance`, which guarantees that each tx has a private call, a nested private call, a public call, and a nested public call, as well as an emitted private note, an unencrypted log, and public storage read and write. This benchmark source data is available in JSON format on S3 [here](https://aztec-ci-artifacts.s3.us-east-2.amazonaws.com/benchmarks-v1/pulls/7283.json). ### Proof generation Each column represents the number of threads used in proof generation. | Metric | 1 threads | 4 threads | 16 threads | 32 threads | 64 threads | | - | - | - | - | - | - | proof_construction_time_sha256_ms | 5,756 (+1%) | 1,562 (+1%) | 713 (+1%) | 755 | 784 (+2%) | proof_construction_time_sha256_30_ms | 12,045 (+3%) | 3,191 (+2%) | 1,425 (+2%) | 1,434 (+1%) | 1,479 (+1%) | proof_construction_time_sha256_100_ms | 44,148 (+1%) | 11,923 (+2%) | 5,509 (+1%) | 5,463 (+1%) | 5,403 (+1%) | proof_construction_time_poseidon_hash_ms | 79.0 (+1%) | 34.0 | 34.0 (-23%) | 57.0 | 89.0 (+1%) | proof_construction_time_poseidon_hash_30_ms | 1,528 (+1%) | 420 (+1%) | 201 | 229 (+1%) | 264 (-1%) | proof_construction_time_poseidon_hash_100_ms | 5,797 (+1%) | 1,582 (+2%) | 727 | 797 (+4%) | 800 (+2%) | ### L2 block published to L1 Each column represents the number of txs on an L2 block published to L1. | Metric | 4 txs | 8 txs | 16 txs | | - | - | - | - | l1_rollup_calldata_size_in_bytes | 1,412 | 1,412 | 1,412 | l1_rollup_calldata_gas | 9,476 | 9,470 | 9,464 | l1_rollup_execution_gas | 611,215 | 611,360 | 611,505 | l2_block_processing_time_in_ms | 756 (-2%) | 1,440 (+2%) | 2,712 (-1%) | l2_block_building_time_in_ms | 21,609 (+3%) | 42,639 (+2%) | 86,833 (+6%) | l2_block_rollup_simulation_time_in_ms | 21,609 (+3%) | 42,638 (+2%) | 86,833 (+6%) | l2_block_public_tx_process_time_in_ms | 18,553 (+4%) | 39,385 (+2%) | 82,587 (+5%) | ### L2 chain processing Each column represents the number of blocks on the L2 chain where each block has 8 txs. | Metric | 3 blocks | 5 blocks | | - | - | - | node_history_sync_time_in_ms | 7,183 (+3%) | 10,114 (+3%) | node_database_size_in_bytes | 12,251,216 | 16,154,704 | pxe_database_size_in_bytes | 16,254 | 26,813 | ### Circuits stats Stats on running time and I/O sizes collected for every kernel circuit run across all benchmarks. | Circuit | simulation_time_in_ms | witness_generation_time_in_ms | proving_time_in_ms | input_size_in_bytes | output_size_in_bytes | proof_size_in_bytes | num_public_inputs | size_in_gates | | - | - | - | - | - | - | - | - | - | private-kernel-init | 102 (+1%) | :warning: 452 (**+18%**) | 12,400 (-2%) | 19,482 | 54,134 | 73,920 | 2,243 | 524,288 | private-kernel-inner | 312 (+1%) | :warning: 895 (**+19%**) | 49,143 | 80,694 | 54,134 | 73,920 | 2,243 | 2,097,152 | private-kernel-tail | 1,112 (+2%) | 2,627 (+3%) | 44,845 (-10%) | 61,457 | 62,057 | 14,912 | 399 | 2,097,152 | base-parity | 6.25 (+2%) | 1,511 | 2,626 (-1%) | 128 | 64.0 | 2,208 | 2.00 | 131,072 | root-parity | 49.0 | 65.6 (-1%) | 40,310 (-4%) | 27,100 | 64.0 | 2,720 | 18.0 | 2,097,152 | base-rollup | 6,771 (+3%) | 4,799 (-1%) | 89,614 (-2%) | 170,330 | 728 | 3,648 | 47.0 | 4,194,304 | root-rollup | 112 (+2%) | 79.8 (+3%) | 22,646 (-8%) | 25,253 | 620 | 3,456 | 41.0 | 1,048,576 | public-kernel-setup | 535 | 2,323 (-3%) | 42,643 (+1%) | 102,121 | 80,278 | 106,912 | 3,274 | 2,097,152 | public-kernel-app-logic | 510 (+2%) | 3,314 | 43,856 (+2%) | 102,121 | 80,278 | 106,912 | 3,274 | 2,097,152 | public-kernel-tail | 1,180 (+3%) | 26,017 (-4%) | 183,077 (+4%) | 399,014 | 10,014 | 14,912 | 399 | 8,388,608 | private-kernel-reset-small | 469 | 1,076 (+1%) | 26,077 (-10%) | 109,233 | 54,134 | 73,920 | 2,243 | 1,048,576 | public-kernel-teardown | 488 | 3,325 (-1%) | 42,649 | 102,121 | 80,278 | 106,912 | 3,274 | 2,097,152 | merge-rollup | 29.7 (+1%) | N/A | N/A | 16,486 | 728 | N/A | N/A | N/A | private-kernel-tail-to-public | N/A | 8,271 (-2%) | 51,074 (-2%) | N/A | N/A | 106,912 | 3,274 | 2,097,152 | Stats on running time collected for app circuits | Function | input_size_in_bytes | output_size_in_bytes | witness_generation_time_in_ms | proof_size_in_bytes | proving_time_in_ms | size_in_gates | num_public_inputs | | - | - | - | - | - | - | - | - | ContractClassRegisterer:register | 1,344 | 8,792 | 406 | N/A | N/A | N/A | N/A | ContractInstanceDeployer:deploy | 1,408 | 8,792 | 38.6 | N/A | N/A | N/A | N/A | MultiCallEntrypoint:entrypoint | 1,920 | 8,792 | 1,191 (+1%) | N/A | N/A | N/A | N/A | GasToken:deploy | 1,376 | 8,792 | 896 | N/A | N/A | N/A | N/A | SchnorrAccount:constructor | 1,312 | 8,792 | 486 | N/A | N/A | N/A | N/A | SchnorrAccount:entrypoint | 2,304 | 8,792 | 1,633 (+1%) | 14,720 | 54,028 (-1%) | 2,097,152 | 393 | Token:privately_mint_private_note | 1,280 | 8,792 | 625 (+2%) | N/A | N/A | N/A | N/A | FPC:fee_entrypoint_public | 1,344 | 8,792 | 268 (-1%) | 14,720 | 11,646 (+4%) | 524,288 | 393 | Token:transfer | 1,312 | 8,792 | 1,774 | 14,720 | 12,102 (-2%) | 524,288 | 393 | AuthRegistry:set_authorized (avm) | 19,226 | N/A | N/A | 91,264 | 1,345 (-1%) | N/A | N/A | FPC:prepare_fee (avm) | 26,668 | N/A | N/A | 91,328 | 2,765 (-4%) | N/A | N/A | Token:transfer_public (avm) | 42,918 | N/A | N/A | 91,328 | 3,783 (-1%) | N/A | N/A | AuthRegistry:consume (avm) | 33,104 | N/A | N/A | 91,264 | 2,746 (-2%) | N/A | N/A | FPC:pay_refund (avm) | 36,833 | N/A | N/A | 91,296 | 22,822 (-3%) | N/A | N/A | Benchmarking:create_note | 1,344 | 8,792 | 483 (+1%) | N/A | N/A | N/A | N/A | SchnorrAccount:verify_private_authwit | 1,280 | 8,792 | 71.5 | N/A | N/A | N/A | N/A | Token:unshield | 1,376 | 8,792 | 1,529 | N/A | N/A | N/A | N/A | FPC:fee_entrypoint_private | 1,376 | 8,792 | 2,115 | N/A | N/A | N/A | N/A | ### AVM Simulation Time to simulate various public functions in the AVM. | Function | time_ms | bytecode_size_in_bytes | | - | - | - | GasToken:_increase_public_balance | 66.0 (-3%) | 13,790 | GasToken:set_portal | 22.5 (+5%) | 3,339 | Token:constructor | 94.5 (+2%) | 23,692 | FPC:constructor | 63.9 (+3%) | 13,592 | GasToken:mint_public | 51.5 | 10,158 | Token:mint_public | :warning: 72.3 (**+34%**) | 19,034 | Token:assert_minter_and_mint | 173 (+1%) | 12,925 | AuthRegistry:set_authorized | 32.4 (-2%) | 7,812 | FPC:prepare_fee | 108 | 15,062 | Token:transfer_public | 56.4 (+29%) | 31,218 | FPC:pay_refund | 130 (-4%) | 25,260 | Benchmarking:increment_balance | 2,244 (+2%) | 15,267 | Token:_increase_public_balance | 56.4 (+3%) | 15,006 | FPC:pay_refund_with_shielded_rebate | 122 (+3%) | 26,347 | ### Public DB Access Time to access various public DBs. | Function | time_ms | | - | - | get-nullifier-index | 0.161 (+3%) | ### Tree insertion stats The duration to insert a fixed batch of leaves into each tree type. | Metric | 1 leaves | 16 leaves | 64 leaves | 128 leaves | 256 leaves | 512 leaves | 1024 leaves | | - | - | - | - | - | - | - | - | batch_insert_into_append_only_tree_16_depth_ms | 10.6 (+2%) | 17.2 (+3%) | N/A | N/A | N/A | N/A | N/A | batch_insert_into_append_only_tree_16_depth_hash_count | 16.8 | 31.7 | N/A | N/A | N/A | N/A | N/A | batch_insert_into_append_only_tree_16_depth_hash_ms | 0.614 (+2%) | 0.528 (+3%) | N/A | N/A | N/A | N/A | N/A | batch_insert_into_append_only_tree_32_depth_ms | N/A | N/A | 48.8 (+1%) | 76.3 | 131 (-2%) | 249 (+2%) | 469 (-1%) | batch_insert_into_append_only_tree_32_depth_hash_count | N/A | N/A | 95.9 | 159 | 287 | 543 | 1,055 | batch_insert_into_append_only_tree_32_depth_hash_ms | N/A | N/A | 0.499 (+1%) | 0.469 | 0.450 (-1%) | 0.452 (+2%) | 0.438 (-1%) | batch_insert_into_indexed_tree_20_depth_ms | N/A | N/A | 60.4 (+1%) | 112 | 183 (-1%) | 357 (+1%) | 691 (-1%) | batch_insert_into_indexed_tree_20_depth_hash_count | N/A | N/A | 109 | 207 | 355 | 691 | 1,363 | batch_insert_into_indexed_tree_20_depth_hash_ms | N/A | N/A | 0.509 (+1%) | 0.503 | 0.483 (-1%) | 0.483 (+1%) | 0.473 (-1%) | batch_insert_into_indexed_tree_40_depth_ms | N/A | N/A | 73.4 | N/A | N/A | N/A | N/A | batch_insert_into_indexed_tree_40_depth_hash_count | N/A | N/A | 133 | N/A | N/A | N/A | N/A | batch_insert_into_indexed_tree_40_depth_hash_ms | N/A | N/A | 0.523 | N/A | N/A | N/A | N/A | ### Miscellaneous Transaction sizes based on how many contract classes are registered in the tx. | Metric | 0 registered classes | 1 registered classes | | - | - | - | tx_size_in_bytes | 74,057 | 667,850 | Transaction size based on fee payment method | Metric | | | - | |

[fcarreiro]

Merge activity

• Jul 3, 10:34 AM EDT: @fcarreiro started a stack merge that includes this pull request via Graphite.
• Jul 3, 10:34 AM EDT: @fcarreiro merged this pull request with Graphite.