feat: Output timestamps in prover-stats raw logs

[spalladino]

Outputs block submission and proof submission timestamps along with raw logs if a proving timeout is set.

[AztecBot]

Benchmark results

Metrics with a significant change:

• protocol_circuit_simulation_time_in_ms (private-kernel-tail-to-public): 689 (-51%)
• avm_simulation_time_ms (FeeJuice:_increase_public_balance): 41.0 (-71%)
• avm_simulation_time_ms (FeeJuice:set_portal): 11.6 (+50%)
• avm_simulation_time_ms (Token:mint_public): 44.4 (-83%)
• avm_simulation_time_ms (Token:assert_minter_and_mint): 255 (+394%)
• avm_simulation_time_ms (Token:transfer_public): 14.5 (-49%)
• avm_simulation_time_ms (Token:_increase_public_balance): 36.5 (-31%)
• l2_block_processing_time_in_ms (4): 258 (-18%)
• l2_block_processing_time_in_ms (16): 818 (-31%)

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.

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,785 (+1%)	1,554	708	766	776 (+1%)
proof_construction_time_sha256_30_ms	11,581 (+1%)	3,079 (+1%)	1,375 (+1%)	1,430 (+2%)	1,463
proof_construction_time_sha256_100_ms	44,271 (+1%)	11,854 (+1%)	5,402 (-8%)	6,001 (-1%)	5,480 (+2%)
proof_construction_time_poseidon_hash_ms	78.0	34.0	34.0	57.0	86.0
proof_construction_time_poseidon_hash_30_ms	1,536 (+1%)	421 (+1%)	200	223 (-2%)	271 (+1%)
proof_construction_time_poseidon_hash_100_ms	5,681 (+1%)	1,523 (+1%)	684 (+2%)	754 (-1%)	750

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	4,612	8,260	15,524
l1_rollup_calldata_gas	52,828	97,596	186,920
l1_rollup_execution_gas	819,514	1,555,690	3,346,449
l2_block_processing_time_in_ms	⚠️ 258 (-18%)	442 (-3%)	⚠️ 818 (-31%)
l2_block_building_time_in_ms	9,407 (+1%)	18,454 (-2%)	36,577 (-1%)
l2_block_rollup_simulation_time_in_ms	9,406 (+1%)	18,454 (-2%)	36,577 (-1%)
l2_block_public_tx_process_time_in_ms	8,014 (+1%)	17,036 (-2%)	35,099 (-1%)

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	3,139 (+1%)	3,999 (-4%)
node_database_size_in_bytes	14,237,936	18,227,440
pxe_database_size_in_bytes	16,258	26,818

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	input_size_in_bytes	output_size_in_bytes	proving_time_in_ms
private-kernel-init	76.0 (+1%)	391 (-3%)	20,975	44,933	N/A
private-kernel-inner	140	712 (-2%)	71,787	45,067	N/A
private-kernel-reset-tiny	333 (-1%)	733 (-4%)	64,273	44,922	N/A
private-kernel-tail	152 (-2%)	141 (-1%)	50,551	57,178	N/A
base-parity	5.59	N/A	160	96.0	N/A
root-parity	35.2	N/A	73,964	96.0	N/A
base-rollup	2,119 (-2%)	N/A	189,128	664	N/A
block-root-rollup	41.6	N/A	58,217	2,448	N/A
public-kernel-setup	87.0 (-1%)	N/A	114,433	79,670	N/A
public-kernel-app-logic	99.8	N/A	114,251	79,670	N/A
public-kernel-tail	585 (-3%)	N/A	487,098	16,414	N/A
private-kernel-reset-small	306 (-3%)	N/A	66,345	45,629	N/A
private-kernel-tail-to-public	⚠️ 689 (-51%)	626 (-3%)	448,120	1,825	N/A
public-kernel-teardown	86.3 (-1%)	N/A	114,697	79,670	N/A
merge-rollup	19.8 (-1%)	N/A	38,182	664	N/A
undefined	N/A	N/A	N/A	N/A	99,399 (-2%)

Stats on running time collected for app circuits

Function	input_size_in_bytes	output_size_in_bytes	witness_generation_time_in_ms
ContractClassRegisterer:register	1,344	11,731	349 (-1%)
ContractInstanceDeployer:deploy	1,408	11,731	18.3 (-3%)
MultiCallEntrypoint:entrypoint	1,920	11,731	425 (-2%)
FeeJuice:deploy	1,376	11,731	396 (-1%)
SchnorrAccount:constructor	1,312	11,731	60.9 (-1%)
SchnorrAccount:entrypoint	2,336	11,731	368 (-1%)
FeeJuice:claim	1,344	11,731	38.3
Token:privately_mint_private_note	1,280	11,731	74.9
FPC:fee_entrypoint_public	1,344	11,731	25.7 (-3%)
Token:transfer	1,312	11,731	212
Benchmarking:create_note	1,344	11,731	74.1 (-1%)
SchnorrAccount:verify_private_authwit	1,280	11,731	26.4
Token:unshield	1,376	11,731	485
FPC:fee_entrypoint_private	1,376	11,731	644

AVM Simulation

Time to simulate various public functions in the AVM.

Function	time_ms	bytecode_size_in_bytes
FeeJuice:_increase_public_balance	⚠️ 41.0 (-71%)	1,268
FeeJuice:set_portal	⚠️ 11.6 (+50%)	1,208
Token:constructor	254	10,758
FPC:constructor	67.2 (-1%)	7,939
FeeJuice:check_balance	35.2 (-2%)	1,093
Token:mint_public	⚠️ 44.4 (-83%)	2,293
Token:assert_minter_and_mint	⚠️ 255 (+394%)	1,551
AuthRegistry:set_authorized	46.4 (+3%)	543
FPC:prepare_fee	88.4 (-6%)	1,596
Token:transfer_public	⚠️ 14.5 (-49%)	8,779
FPC:pay_refund	40.7 (-5%)	2,098
Benchmarking:increment_balance	1,002 (-2%)	1,536
Token:_increase_public_balance	⚠️ 36.5 (-31%)	1,239
FPC:pay_refund_with_shielded_rebate	52.0 (+1%)	2,098

Public DB Access

Time to access various public DBs.

Function	time_ms
get-nullifier-index	0.156 (-1%)

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	2.17 (-2%)	3.86 (-1%)	N/A	N/A	N/A	N/A	N/A
batch_insert_into_append_only_tree_16_depth_hash_count	16.7	31.8	N/A	N/A	N/A	N/A	N/A
batch_insert_into_append_only_tree_16_depth_hash_ms	0.114 (-2%)	0.109 (-1%)	N/A	N/A	N/A	N/A	N/A
batch_insert_into_append_only_tree_32_depth_ms	N/A	N/A	11.3	17.4 (-3%)	30.7 (-2%)	58.6 (-3%)	113
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.108	0.101 (-2%)	0.0999 (-1%)	0.101 (-3%)	0.101 (+1%)
batch_insert_into_indexed_tree_20_depth_ms	N/A	N/A	14.3 (-1%)	25.9	43.9 (-2%)	81.9 (-2%)	162
batch_insert_into_indexed_tree_20_depth_hash_count	N/A	N/A	109	207	357	691	1,363
batch_insert_into_indexed_tree_20_depth_hash_ms	N/A	N/A	0.109 (-1%)	0.105	0.106 (-1%)	0.101 (-2%)	0.102 (-1%)
batch_insert_into_indexed_tree_40_depth_ms	N/A	N/A	16.1 (-1%)	N/A	N/A	N/A	N/A
batch_insert_into_indexed_tree_40_depth_hash_count	N/A	N/A	129	N/A	N/A	N/A	N/A
batch_insert_into_indexed_tree_40_depth_hash_ms	N/A	N/A	0.106 (-1%)	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	72,416	668,302

Transaction size based on fee payment method

| Metric | |
| - | |